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