mudpy/tests/selftest.py

   1 # Copyright (c) 2004-2020 mudpy authors. Permission to use, copy,
   2 # modify, and distribute this software is granted under terms
   3 # provided in the LICENSE file distributed with this software.
   4
   5 import os
   6 import pathlib
   7 import re
   8 import shutil
   9 import subprocess
  10 import sys
  11 import telnetlib
  12 import time
  13
  14 # TODO(fungi) Clean this up once Python 3.5 is no longer supported
  15 if sys.version < "3.6":
  16     import collections
  17     odict = collections.OrderedDict
  18 else:
  19     odict = dict
  20
  21 pidfile = "var/mudpy.pid"
  22
  23 test_account0_setup = (
  24     (0, "Identify yourself:", "luser0"),
  25     (0, "Enter your choice:", "n"),
  26     (0, 'Enter a new password for "luser0":', "Test123"),
  27     (0, "Enter the same new password again:", "Test123"),
  28     (0, r"What would you like to do\?", "c"),
  29     (0, "Pick a birth gender for your new avatar:", "f"),
  30     (0, "Choose a name for her:", "1"),
  31     (0, r"What would you like to do\?", "a"),
  32     (0, r"Whom would you like to awaken\?", ""),
  33 )
  34
  35 test_account1_setup = (
  36     (1, "Identify yourself:", "luser1"),
  37     (1, "Enter your choice:", "n"),
  38     (1, 'Enter a new password for "luser1":', "Test456"),
  39     (1, "Enter the same new password again:", "Test456"),
  40     (1, r"What would you like to do\?", "c"),
  41     (1, "Pick a birth gender for your new avatar:", "m"),
  42     (1, "Choose a name for him:", "1"),
  43     (1, r"What would you like to do\?", "a"),
  44     (1, r"Whom would you like to awaken\?", ""),
  45 )
  46
  47 test_actor_appears = (
  48     (0, r"You suddenly realize that .* is here\.", ""),
  49 )
  50
  51 test_explicit_punctuation = (
  52     (0, "> ", "say Hello there!"),
  53     (0, r'You exclaim, "Hello there\!"', ""),
  54     (1, r'exclaims, "Hello there\!"', "say And you are?"),
  55     (1, r'You ask, "And you are\?"', ""),
  56     (0, r'asks, "And you are\?"', "say I'm me, of course."),
  57     (0, r'''You say, "I'm me, of course\."''', ""),
  58     (1, r'''says, "I'm me, of course\."''', "say I wouldn't be so sure..."),
  59     (1, r'''You muse, "I wouldn't be so sure\.\.\."''', ""),
  60     (0, r'''muses, "I wouldn't be so sure\.\.\."''', "say You mean,"),
  61     (0, 'You begin, "You mean,"', ""),
  62     (1, 'begins, "You mean,"', "say I know-"),
  63     (1, 'You begin, "I know-"', ""),
  64     (0, 'begins, "I know-"', "say Don't interrupt:"),
  65     (0, r'''You begin, "Don't interrupt:"''', ""),
  66     (1, r'''begins, "Don't interrupt:"''', "say I wasn't interrupting;"),
  67     (1, r'''You begin, "I wasn't interrupting;"''', ""),
  68     (0, r'''begins, "I wasn't interrupting;"''', ""),
  69 )
  70
  71 test_implicit_punctuation = (
  72     (0, '> ', "say Whatever"),
  73     (0, r'You say, "Whatever\."', ""),
  74     (1, r'says, "Whatever\."', ""),
  75 )
  76
  77 test_typo_replacement = (
  78     (1, '> ', "say That's what i think."),
  79     (1, r'''You say, "That's what I think\."''', ""),
  80     (0, r'''says, "That's what I think\."''', "say You know what i'd like."),
  81     (0, r'''You say, "You know what I'd like\."''', ""),
  82     (1, r'''says, "You know what I'd like\."''', "say Then i'll tell you."),
  83     (1, r'''You say, "Then I'll tell you\."''', ""),
  84     (0, r'''says, "Then I'll tell you\."''', "say Now i'm ready."),
  85     (0, r'''You say, "Now I'm ready\."''', ""),
  86     (1, r'''says, "Now I'm ready\."''', "say That's teh idea."),
  87     (1, r'''You say, "That's the idea\."''', ""),
  88     (0, r'''says, "That's the idea\."''', "say It's what theyre saying."),
  89     (0, r'''You say, "It's what they're saying\."''', ""),
  90     (1, r'''says, "It's what they're saying\."''', "say Well, youre right."),
  91     (1, r'''You say, "Well, you're right\."''', ""),
  92     (0, r'''says, "Well, you're right\."''', ""),
  93 )
  94
  95 test_sentence_capitalization = (
  96     (0, "> ", "say this sentence should start with a capital T."),
  97     (0, 'You say, "This sentence', ""),
  98     (1, 'says, "This sentence', ""),
  99 )
 100
 101 test_chat_mode = (
 102     (1, '> ', "chat"),
 103     (1, r'(?s)Entering chat mode .*> \(chat\) ', "Feeling chatty."),
 104     (1, r'You say, "Feeling chatty\."', "!chat"),
 105     (0, r'says, "Feeling chatty\."', ""),
 106     (1, '> ', "say Now less chatty."),
 107     (1, r'You say, "Now less chatty\."', ""),
 108     (0, r'says, "Now less chatty\."', ""),
 109 )
 110
 111 test_wrapping = (
 112     (0, '> ', "say " + 100 * "o"),
 113     (1, r'says,\r\n"O[o]+\."', ""),
 114 )
 115
 116 test_forbid_ansi_input = (
 117     (0, '> ', "say \x1b[35mfoo\x1b[0m"),
 118     (1, r'says, "\[35mfoo\[0m\."', ""),
 119 )
 120
 121 test_escape_macros = (
 122     (0, '> ', "say $(red)bar$(nrm)"),
 123     (1, r'says, "\$\(red\)bar\$\(nrm\)\."', ""),
 124 )
 125
 126 test_movement = (
 127     (0, "> ", "move north"),
 128     (0, r"You exit to the north\.", ""),
 129     (1, r"exits to the north\.", "move north"),
 130     (0, r"arrives from the south\.", "move south"),
 131     (0, r"You exit to the south\.", ""),
 132     (1, r"exits to the south\.", "move south"),
 133     (0, r"arrives from the north\.", "move east"),
 134     (0, r"You exit to the east\.", ""),
 135     (1, r"exits to the east\.", "move east"),
 136     (0, r"arrives from the west\.", "move west"),
 137     (0, r"You exit to the west\.", ""),
 138     (1, r"exits to the west\.", "move west"),
 139     (0, r"arrives from the east\.", "move up"),
 140     (0, r"You exit upward\.", ""),
 141     (1, r"exits upward\.", "move up"),
 142     (0, r"arrives from below\.", "move down"),
 143     (0, r"You exit downward\.", ""),
 144     (1, r"exits downward\.", "move down"),
 145     (0, r"arrives from above\.", ""),
 146 )
 147
 148 test_actor_disappears = (
 149     (1, "> ", "quit"),
 150     (0, r"You suddenly wonder where .* went\.", ""),
 151 )
 152
 153 test_abort_avatar_deletion = (
 154     (1, r"What would you like to do\?", "d"),
 155     (1, r"Whom would you like to delete\?", ""),
 156     (1, r"delete an unwanted avatar.*What would you like to do\?", ""),
 157 )
 158
 159 test_avatar_creation_limit = (
 160     (1, r"What would you like to do\?", "c"),
 161     (1, "Pick a birth gender for your new avatar:", "m"),
 162     (1, "Choose a name for him:", "3"),
 163     (1, r"What would you like to do\?", "c"),
 164     (1, "Pick a birth gender for your new avatar:", "m"),
 165     (1, "Choose a name for him:", "4"),
 166     (1, r"What would you like to do\?", "c"),
 167     (1, "Pick a birth gender for your new avatar:", "m"),
 168     (1, "Choose a name for him:", "7"),
 169     (1, r"What would you like to do\?", "c"),
 170     (1, "Pick a birth gender for your new avatar:", "m"),
 171     (1, "Choose a name for him:", "5"),
 172     (1, r"What would you like to do\?", "c"),
 173     (1, "Pick a birth gender for your new avatar:", "m"),
 174     (1, "Choose a name for him:", "2"),
 175     (1, r"What would you like to do\?", "c"),
 176     (1, "Pick a birth gender for your new avatar:", "m"),
 177     (1, "Choose a name for him:", "6"),
 178     (1, r"What would you like to do\?", "c"),
 179     (1, r"That is not a valid choice\.\.\.", ""),
 180 )
 181
 182 test_avatar_deletion = (
 183     (1, r"What would you like to do\?", "d"),
 184     (1, r"Whom would you like to delete\?", "1"),
 185     (1, r"create a new avatar.*What would you like to do\?", ""),
 186 )
 187
 188 test_abort_account_deletion = (
 189     (1, r"What would you like to do\?", "p"),
 190     (1, r"permanently delete your account\?", ""),
 191     (1, r"What would you like to do\?", ""),
 192 )
 193
 194 test_account_deletion = (
 195     (1, r"What would you like to do\?", "p"),
 196     (1, r"permanently delete your account\?", "y"),
 197     (1, r"Disconnecting\.\.\.", ""),
 198 )
 199
 200 test_admin_setup = (
 201     (2, "Identify yourself:", "admin"),
 202     (2, "Enter your choice:", "n"),
 203     (2, 'Enter a new password for "admin":', "Test789"),
 204     (2, "Enter the same new password again:", "Test789"),
 205     (2, r"What would you like to do\?", "c"),
 206     (2, "Pick a birth gender for your new avatar:", "m"),
 207     (2, "Choose a name for him:", "1"),
 208     (2, r"What would you like to do\?", "a"),
 209     (2, r"Whom would you like to awaken\?", ""),
 210 )
 211
 212 test_preferences = (
 213     (0, "> ", "preferences"),
 214     (0, r"\[32mprompt\x1b\[0m - <not set>.*> ", "preferences prompt $(foo)"),
 215     (0, r"\$\(foo\) ", "preferences prompt"),
 216     (0, r"\$\(foo\).*\$\(foo\) ", "preferences prompt $(time)>"),
 217     (0, "[0-9]> ", "preferences loglevel 0"),
 218     (0, "does not exist.*> ", "preferences prompt >"),
 219     (2, "> ", "preferences loglevel 0"),
 220     (2, "> ", "preferences"),
 221     (2, r"\[31mloglevel\x1b\[0m - 0.*> ", "preferences loglevel zero"),
 222     (2, r'''cannot be set to type "<class 'str'>"\..*> ''', ""),
 223 )
 224
 225 test_crlf_eol = (
 226     # Send a CR+LF at the end of the line instead of the default CR+NUL,
 227     # to make sure they're treated the same
 228     (2, "> ", b"say I use CR+LF as my EOL, not CR+NUL.\r\n"),
 229     (2, r'You say, "I use CR\+LF as my EOL, not CR\+NUL\.".*> ', ""),
 230 )
 231
 232 test_telnet_iac = (
 233     # Send a double (escaped) IAC byte within other text, which should get
 234     # unescaped and deduplicated to a single \xff in the buffer and then
 235     # the line of input discarded as a non-ASCII sequence
 236     (2, "> ", b"say argle\xff\xffbargle\r\0"),
 237     (2, r"Non-ASCII characters from admin: b'say.*argle\\xffbargle'.*> ", ""),
 238 )
 239
 240 test_telnet_unknown_command = (
 241     # Send an unsupported negotiation command #127 which should get filtered
 242     # from the line of input
 243     (2, "> ", b"say glop\xff\x7fglyf\r\0"),
 244     (2, r'Ignored unknown command 127 from admin\..*"Glopglyf\.".*> ', ""),
 245 )
 246
 247 test_telnet_unknown_option = (
 248     # Send an unassigned negotiation option #127 which should get logged
 249     (2, "> ", b"\xff\xfe\x7f\r\0"),
 250     (2, r'''Received "don't 127" from admin\..*> ''', ""),
 251 )
 252
 253 test_admin_restriction = (
 254     (0, "> ", "help halt"),
 255     (0, r"That is not an available command\.", "halt"),
 256     (0, '(not sure what "halt" means|Arglebargle, glop-glyf)', ""),
 257 )
 258
 259 test_admin_help = (
 260     (2, "> ", "help"),
 261     (2, r"halt.*Shut down the world\.", "help halt"),
 262     (2, "This will save all active accounts", ""),
 263 )
 264
 265 test_help = (
 266     (0, "> ", "help say"),
 267     (0, r"See also: .*chat.*> ", ""),
 268 )
 269
 270 test_abbrev = (
 271     (0, "> ", "h"),
 272     (0, r"h\[elp\].*m\[ove\].*> ", "he mo"),
 273     (0, r"Move in a specific direction\..*> ", "mov nor"),
 274     (0, r"You exit to the north\..*> ", "m s"),
 275     (0, r"You exit to the south\..*> ", ""),
 276 )
 277
 278 test_reload = (
 279     (2, "> ", "reload"),
 280     (2, r"Reloading all code modules, configs and data\."
 281         r".* User admin reloaded the world\.",
 282      "show element account.admin"),
 283     (2, r'These are the properties of the "account\.admin" element.*'
 284         r'  \x1b\[32mpasshash:\r\n\x1b\[31m\$.*> ', ""),
 285 )
 286
 287 test_set_facet = (
 288     (2, "> ", "set actor.avatar_admin_0 gender female"),
 289     (2, r'You have successfully \(re\)set the "gender" facet of element', ""),
 290 )
 291
 292 test_set_refused = (
 293     (2, "> ", "set mudpy.limit password_tries 10"),
 294     (2, r'The "mudpy\.limit" element is kept in read-only file', ""),
 295 )
 296
 297 test_show_version = (
 298     (2, "> ", "show version"),
 299     (2, r"Running mudpy .* on .* Python 3.*with.*pyyaml.*> ", ""),
 300 )
 301
 302 test_show_time = (
 303     (2, "> ", "show time"),
 304     (2, r"\r\n[0-9]+ increments elapsed.*> ", ""),
 305 )
 306
 307 test_show_files = (
 308     (2, "> ", "show files"),
 309     (2, r'These are the current files containing the universe:.*'
 310         r'  \x1b\[31m\(rw\) \x1b\[32m/.*/account\.yaml\x1b\[0m'
 311         r' \x1b\[33m\[private\]\x1b\[0m.*> ', ""),
 312 )
 313
 314 test_show_file = (
 315     (2, "> ", "show file %s" %
 316         os.path.join(os.getcwd(), "data/internal.yaml")),
 317     (2, r'These are the nodes in the.*file:.*internal\.counters.*> ', ""),
 318 )
 319
 320 test_show_groups = (
 321     (2, "> ", "show groups"),
 322     (2, r'These are the element groups:.*'
 323         r'  \x1b\[32maccount\x1b\[0m.*> ', ""),
 324 )
 325
 326 test_show_group = (
 327     (2, "> ", "show group account"),
 328     (2, r'These are the elements in the "account" group:.*'
 329         r'  \x1b\[32maccount\.admin\x1b\[0m.*> ', ""),
 330 )
 331
 332 test_show_element = (
 333     (2, "> ", "show element mudpy.limit"),
 334     (2, r'These are the properties of the "mudpy\.limit" element.*'
 335         r'  \x1b\[32mpassword_tries: \x1b\[31m3.*> ',
 336      "show element actor.avatar_admin_0"),
 337     (2, r'These are the properties of the "actor\.avatar_admin_0" element.*'
 338         r'  \x1b\[32mgender: \x1b\[31mfemale.*> ', ""),
 339 )
 340
 341 test_show_result = (
 342     (2, "> ", "show result 12345*67890"),
 343     (2, r"\r\n838102050\r\n.*> ", "show result 1/0"),
 344     (2, r"Your expression raised an exception.*division by zero.*> ",
 345      "show result mudpy"),
 346     (2, r"<module 'mudpy' from.*> ", "show result re"),
 347     (2, r"Your expression raised an exception.*name 're' is not defined.*> ",
 348      "show result universe"),
 349     (2, r"<mudpy\.misc\.Universe object at 0x.*> ", "show result actor"),
 350     (2, r"Your expression raised an exception.*name 'actor' is not "
 351         r"defined.*> ", ""),
 352 )
 353
 354 test_show_log = (
 355     (2, "> ", "show log"),
 356     (2, r"There are [0-9]+ log lines in memory and [0-9]+ at or above level "
 357         r"[0-9]+\. The matching.*from [0-9]+ to [0-9]+ are:", ""),
 358 )
 359
 360 test_custom_loglevel = (
 361     (2, "> ", "set account.admin loglevel 2"),
 362     (2, "You have successfully .*> ", "show log"),
 363     (2, r"There are [0-9]+ log lines in memory and [0-9]+ at or above level "
 364         r"[0-9]+\. The matching.*from [0-9]+ to [0-9]+ are:", ""),
 365 )
 366
 367 test_invalid_loglevel = (
 368     (2, "> ", "set account.admin loglevel two"),
 369     (2, r'''Value "two" of type "<class 'str'>" cannot be coerced .*> ''', ""),
 370 )
 371
 372 test_log_no_errors = (
 373     (2, "> ", "show log 7"),
 374     (2, r"None of the [0-9]+ lines in memory matches your request\.", ""),
 375 )
 376
 377 final_cleanup = (
 378     (0, "> ", "quit"),
 379     (0, r"What would you like to do\?", "p"),
 380     (0, r"permanently delete your account\?", "y"),
 381     (0, r"Disconnecting\.\.\.", ""),
 382     (2, "> ", "quit"),
 383     (2, r"What would you like to do\?", "p"),
 384     (2, r"permanently delete your account\?", "y"),
 385     (2, r"Disconnecting\.\.\.", ""),
 386 )
 387
 388 dialogue = odict((
 389     (test_account0_setup, "first account setup"),
 390     (test_account1_setup, "second account setup"),
 391     (test_actor_appears, "actor spontaneous appearance"),
 392     (test_explicit_punctuation, "explicit punctuation"),
 393     (test_implicit_punctuation, "implicit punctuation"),
 394     (test_typo_replacement, "typo replacement"),
 395     (test_sentence_capitalization, "sentence capitalization"),
 396     (test_chat_mode, "chat mode"),
 397     (test_wrapping, "wrapping"),
 398     (test_forbid_ansi_input, "raw escape input is filtered"),
 399     (test_escape_macros, "replacement macros are escaped"),
 400     (test_movement, "movement"),
 401     (test_actor_disappears, "actor spontaneous disappearance"),
 402     (test_abort_avatar_deletion, "abort avatar deletion"),
 403     (test_avatar_creation_limit, "avatar creation limit"),
 404     (test_avatar_deletion, "avatar deletion"),
 405     (test_abort_account_deletion, "abort account deletion"),
 406     (test_account_deletion, "account deletion"),
 407     (test_admin_setup, "admin account setup"),
 408     (test_preferences, "set and show preferences"),
 409     (test_crlf_eol, "send crlf from the client as eol"),
 410     (test_telnet_iac, "escape stray telnet iac bytes"),
 411     (test_telnet_unknown_command, "strip unknown telnet command"),
 412     (test_telnet_unknown_option, "log unknown telnet option"),
 413     (test_admin_restriction, "restricted admin commands"),
 414     (test_admin_help, "admin help"),
 415     (test_help, "help command"),
 416     (test_abbrev, "command abbreviation"),
 417     (test_reload, "reload"),
 418     (test_set_facet, "set facet"),
 419     (test_set_refused, "refuse altering read-only element"),
 420     (test_show_version, "show version and diagnostic info"),
 421     (test_show_time, "show elapsed world clock increments"),
 422     (test_show_files, "show a list of loaded files"),
 423     (test_show_file, "show nodes from a specific file"),
 424     (test_show_groups, "show groups"),
 425     (test_show_group, "show group"),
 426     (test_show_element, "show element"),
 427     (test_show_result, "show result of a python expression"),
 428     (test_show_log, "show log"),
 429     (test_custom_loglevel, "custom loglevel"),
 430     (test_invalid_loglevel, "invalid loglevel"),
 431     (test_log_no_errors, "no errors logged"),
 432     (final_cleanup, "delete remaining accounts"),
 433 ))
 434
 435
 436 def start_service(config):
 437     # Clean up any previously run daemon which didn't terminate
 438     if os.path.exists(pidfile):
 439         with open(pidfile) as pidfd:
 440             pid = int(pidfd.read())
 441         try:
 442             # Stop the running service
 443             os.kill(pid, 15)
 444             time.sleep(1)
 445         except ProcessLookupError:
 446             # If there was no process, just remove the stale PID file
 447             os.remove(pidfile)
 448         # If there's a preexisting hung service, we can't proceed
 449         assert not os.path.exists(pidfile)
 450
 451     # Clean up any previous test output
 452     for f in pathlib.Path(".").glob("capture_*.log"):
 453         # have to use .name here since remove() doesn't support passing a
 454         # PosixPath argument until Python3.6
 455         os.remove(f.name)
 456     for d in ("data", "var"):
 457         shutil.rmtree(d, ignore_errors=True)
 458
 459     # Start the service and wait for it to be ready for connections
 460     service = subprocess.Popen(("mudpy", config),
 461                                stdout=subprocess.PIPE,
 462                                stderr=subprocess.PIPE)
 463     time.sleep(1)
 464     return(service)
 465
 466
 467 def stop_service(service):
 468     success = True
 469
 470     # The no-op case when no service was started
 471     if service is None:
 472         return(success)
 473
 474     # This handles when the service is running as a direct child process
 475     service.terminate()
 476     returncode = service.wait(10)
 477     if returncode != 0:
 478         tlog("\nERROR: Service exited with code %s." % returncode)
 479         success = False
 480
 481     # This cleans up a daemonized and disassociated service
 482     if os.path.exists(pidfile):
 483         with open(pidfile) as pidfd:
 484             pid = int(pidfd.read())
 485         try:
 486             # Stop the running service
 487             os.kill(pid, 15)
 488             time.sleep(1)
 489         except ProcessLookupError:
 490             # If there was no process, just remove the stale PID file
 491             os.remove(pidfile)
 492         # The PID file didn't disappear, so we have a hung service
 493         if os.path.exists(pidfile):
 494             tlog("\nERROR: Hung daemon with PID %s." % pid)
 495             success = False
 496
 497     # Log the contents of stdout and stderr, if any
 498     stdout, stderr = service.communicate()
 499     tlog("\nRecording stdout as capture_stdout.log.")
 500     with open("capture_stdout.log", "w") as serviceout:
 501         serviceout.write(stdout.decode("utf-8"))
 502     tlog("\nRecording stderr as capture_stderr.log.")
 503     with open("capture_stderr.log", "w") as serviceerr:
 504         serviceerr.write(stderr.decode("utf-8"))
 505
 506     return(success)
 507
 508
 509 def tlog(message, quiet=False):
 510     logfile = "capture_tests.log"
 511     with open(logfile, "a") as logfd:
 512         logfd.write(message + "\n")
 513     if not quiet:
 514         sys.stdout.write(message)
 515     return True
 516
 517
 518 def option_callback(telnet_socket, command, option):
 519     if option == b'\x7f':
 520         # We use this unassigned option value as a canary, so short-circuit
 521         # any response to avoid endlessly looping
 522         pass
 523     elif command in (telnetlib.DO, telnetlib.DONT):
 524         telnet_socket.send(telnetlib.IAC + telnetlib.WONT + option)
 525     elif command in (telnetlib.WILL, telnetlib.WONT):
 526         telnet_socket.send(telnetlib.IAC + telnetlib.DONT + option)
 527
 528
 529 def main():
 530     captures = ["", "", ""]
 531     lusers = [telnetlib.Telnet(), telnetlib.Telnet(), telnetlib.Telnet()]
 532     success = True
 533     start = time.time()
 534     service = None
 535     if len(sys.argv) > 1:
 536         # Start the service if a config file was provided on the command line
 537         service = start_service(sys.argv[1])
 538         if not service:
 539             tlog("\nERROR: Service did not start.\n")
 540             sys.exit(1)
 541     for luser in lusers:
 542         luser.open("::1", 4000)
 543         luser.set_option_negotiation_callback(option_callback)
 544     selected_dialogue = odict(dialogue)
 545     for test, description in selected_dialogue.items():
 546         tlog("\nTesting %s..." % description)
 547         test_start = time.time()
 548         for conversant, question, answer in test:
 549             tlog("luser%s waiting for: %s" % (conversant, question),
 550                  quiet=True)
 551             try:
 552                 index, match, received = lusers[conversant].expect(
 553                     [re.compile(question.encode("utf-8"), flags=re.DOTALL)], 5)
 554                 captures[conversant] += received.decode("utf-8")
 555             except ConnectionResetError:
 556                 tlog("\nERROR: Unable to connect to server.")
 557                 success = False
 558                 break
 559             except EOFError:
 560                 tlog("\nERROR: luser%s premature disconnection expecting:\n\n"
 561                      "%s\n\n"
 562                      "Check the end of capture_%s.log for received data."
 563                      % (conversant, question, conversant))
 564                 success = False
 565                 break
 566             try:
 567                 captures[conversant] += lusers[
 568                     conversant].read_very_eager().decode("utf-8")
 569             except Exception:
 570                 pass
 571             if index != 0:
 572                 tlog("\nERROR: luser%s did not receive expected string:\n\n"
 573                      "%s\n\n"
 574                      "Check the end of capture_%s.log for received data."
 575                      % (conversant, question, conversant))
 576                 success = False
 577                 break
 578             if type(answer) is str:
 579                 tlog("luser%s sending: %s" % (conversant, answer), quiet=True)
 580                 lusers[conversant].write(("%s\r\0" % answer).encode("utf-8"))
 581                 captures[conversant] += "%s\r\n" % answer
 582             elif type(answer) is bytes:
 583                 tlog("luser%s sending raw bytes: %s" % (conversant, answer),
 584                      quiet=True)
 585                 lusers[conversant].get_socket().send(answer)
 586                 captures[conversant] += "!!!RAW BYTES: %s" % answer
 587             else:
 588                 tlog("\nERROR: answer provided with unsupported type %s"
 589                      % type(answer))
 590                 success = False
 591                 break
 592         if not success:
 593             break
 594         tlog("Completed in %.3f seconds." % (time.time() - test_start))
 595     duration = time.time() - start
 596     for conversant in range(len(captures)):
 597         try:
 598             captures[conversant] += lusers[
 599                 conversant].read_very_eager().decode("utf-8")
 600         except Exception:
 601             pass
 602         lusers[conversant].close()
 603         logfile = "capture_%s.log" % conversant
 604         tlog("\nRecording session %s as %s." % (conversant, logfile))
 605         log = open(logfile, "w")
 606         log.write(captures[conversant])
 607         log.close()
 608     if not stop_service(service):
 609         success = False
 610     tlog("\nRan %s tests in %.3f seconds." % (len(dialogue), duration))
 611     if success:
 612         tlog("\nSUCCESS\n")
 613     else:
 614         tlog("\nFAILURE\n")
 615         sys.exit(1)
 616
 617
 618 if __name__ == '__main__':
 619     sys.exit(main())