mudpy/tests/selftest.py

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