c6f339866011342f65a91f9bb84fa264c8981039
[mudpy.git] / 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_evaluate = (
344     (2, "> ", "evaluate 12345*67890"),
345     (2, r"\r\n838102050\r\n.*> ", "evaluate 1/0"),
346     (2, "Your expression raised an exception.*division by zero.*> ",
347      "evaluate mudpy"),
348     (2, "<module 'mudpy' from.*> ", "evaluate re"),
349     (2, "Your expression raised an exception.*name 're' is not defined.*> ",
350      "evaluate universe"),
351     (2, r"<mudpy\.misc\.Universe object at 0x.*> ", "evaluate actor"),
352     (2, "Your expression raised an exception.*name 'actor' is not defined.*> ",
353         "evaluate dir(mudpy)"),
354     (2, "__builtins__.*> ", "evaluate mudpy.__builtins__.open"),
355     (2, "not allowed.*> ", "evaluate (lambda x: x + 1)(2)"),
356     (2, "not allowed.*> ", ""),
357 )
358
359 test_debug_restricted = (
360     (0, "> ", "help evaluate"),
361     (0, r"That is not an available command\.", "evaluate"),
362     (0, '(not sure what "evaluate" means|Arglebargle, glop-glyf)', ""),
363 )
364
365 test_debug_disabled = (
366     (2, "> ", "help evaluate"),
367     (2, r"That is not an available command\.", "evaluate"),
368     (2, '(not sure what "evaluate" means|Arglebargle, glop-glyf)', ""),
369 )
370
371 test_show_log = (
372     (2, "> ", "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_custom_loglevel = (
378     (2, "> ", "set account.admin loglevel 2"),
379     (2, "You have successfully .*> ", "show log"),
380     (2, r"There are [0-9]+ log lines in memory and [0-9]+ at or above level "
381         r"[0-9]+\. The matching.*from [0-9]+ to [0-9]+ are:", ""),
382 )
383
384 test_invalid_loglevel = (
385     (2, "> ", "set account.admin loglevel two"),
386     (2, r'''Value "two" of type "<class 'str'>" cannot be coerced .*> ''', ""),
387 )
388
389 test_log_no_errors = (
390     (2, "> ", "show log 7"),
391     (2, r"None of the [0-9]+ lines in memory matches your request\.", ""),
392 )
393
394 final_cleanup = (
395     (0, "> ", "quit"),
396     (0, r"What would you like to do\?", "p"),
397     (0, r"permanently delete your account\?", "y"),
398     (0, r"Disconnecting\.\.\.", ""),
399     (2, "> ", "quit"),
400     (2, r"What would you like to do\?", "p"),
401     (2, r"permanently delete your account\?", "y"),
402     (2, r"Disconnecting\.\.\.", ""),
403 )
404
405 dialogue = odict((
406     (test_account0_setup, "first account setup"),
407     (test_account1_setup, "second account setup"),
408     (test_actor_appears, "actor spontaneous appearance"),
409     (test_explicit_punctuation, "explicit punctuation"),
410     (test_implicit_punctuation, "implicit punctuation"),
411     (test_typo_replacement, "typo replacement"),
412     (test_sentence_capitalization, "sentence capitalization"),
413     (test_chat_mode, "chat mode"),
414     (test_wrapping, "wrapping"),
415     (test_forbid_ansi_input, "raw escape input is filtered"),
416     (test_escape_macros, "replacement macros are escaped"),
417     (test_movement, "movement"),
418     (test_actor_disappears, "actor spontaneous disappearance"),
419     (test_abort_avatar_deletion, "abort avatar deletion"),
420     (test_avatar_creation_limit, "avatar creation limit"),
421     (test_avatar_deletion, "avatar deletion"),
422     (test_abort_account_deletion, "abort account deletion"),
423     (test_account_deletion, "account deletion"),
424     (test_admin_setup, "admin account setup"),
425     (test_preferences, "set and show preferences"),
426     (test_crlf_eol, "send crlf from the client as eol"),
427     (test_telnet_iac, "escape stray telnet iac bytes"),
428     (test_telnet_unknown_command, "strip unknown telnet command"),
429     (test_telnet_unknown_option, "log unknown telnet option"),
430     (test_admin_restriction, "restricted admin commands"),
431     (test_admin_help, "admin help"),
432     (test_help, "help command"),
433     (test_abbrev, "command abbreviation"),
434     (test_reload, "reload"),
435     (test_set_facet, "set facet"),
436     (test_set_refused, "refuse altering read-only element"),
437     (test_show_version, "show version and diagnostic info"),
438     (test_show_time, "show elapsed world clock increments"),
439     (test_show_files, "show a list of loaded files"),
440     (test_show_file, "show nodes from a specific file"),
441     (test_show_groups, "show groups"),
442     (test_show_group, "show group"),
443     (test_show_element, "show element"),
444     (test_evaluate, "show results of python expressions"),
445     (test_debug_restricted, "only admins can run debug commands"),
446     (test_debug_disabled, "debugging commands only in debug mode"),
447     (test_show_log, "show log"),
448     (test_custom_loglevel, "custom loglevel"),
449     (test_invalid_loglevel, "invalid loglevel"),
450     (test_log_no_errors, "no errors logged"),
451     (final_cleanup, "delete remaining accounts"),
452 ))
453
454 debug_tests = (
455     test_evaluate,
456 )
457
458 nondebug_tests = (
459     test_debug_disabled,
460 )
461
462
463 def start_service(config):
464     # Clean up any previously run daemon which didn't terminate
465     if os.path.exists(pidfile):
466         with open(pidfile) as pidfd:
467             pid = int(pidfd.read())
468         try:
469             # Stop the running service
470             os.kill(pid, 15)
471             time.sleep(1)
472         except ProcessLookupError:
473             # If there was no process, just remove the stale PID file
474             os.remove(pidfile)
475         # If there's a preexisting hung service, we can't proceed
476         assert not os.path.exists(pidfile)
477
478     # Clean up any previous test output
479     for f in pathlib.Path(".").glob("capture_*.log"):
480         # have to use .name here since remove() doesn't support passing a
481         # PosixPath argument until Python3.6
482         os.remove(f.name)
483     for d in ("data", "var"):
484         shutil.rmtree(d, ignore_errors=True)
485
486     # Start the service and wait for it to be ready for connections
487     service = subprocess.Popen(("mudpy", config),
488                                stdout=subprocess.PIPE,
489                                stderr=subprocess.PIPE)
490     time.sleep(1)
491     return(service)
492
493
494 def stop_service(service):
495     success = True
496
497     # The no-op case when no service was started
498     if service is None:
499         return(success)
500
501     # This handles when the service is running as a direct child process
502     service.terminate()
503     returncode = service.wait(10)
504     if returncode != 0:
505         tlog("\nERROR: Service exited with code %s." % returncode)
506         success = False
507
508     # This cleans up a daemonized and disassociated service
509     if os.path.exists(pidfile):
510         with open(pidfile) as pidfd:
511             pid = int(pidfd.read())
512         try:
513             # Stop the running service
514             os.kill(pid, 15)
515             time.sleep(1)
516         except ProcessLookupError:
517             # If there was no process, just remove the stale PID file
518             os.remove(pidfile)
519         # The PID file didn't disappear, so we have a hung service
520         if os.path.exists(pidfile):
521             tlog("\nERROR: Hung daemon with PID %s." % pid)
522             success = False
523
524     # Log the contents of stdout and stderr, if any
525     stdout, stderr = service.communicate()
526     tlog("\nRecording stdout as capture_stdout.log.")
527     with open("capture_stdout.log", "w") as serviceout:
528         serviceout.write(stdout.decode("utf-8"))
529     tlog("\nRecording stderr as capture_stderr.log.")
530     with open("capture_stderr.log", "w") as serviceerr:
531         serviceerr.write(stderr.decode("utf-8"))
532
533     return(success)
534
535
536 def tlog(message, quiet=False):
537     logfile = "capture_tests.log"
538     with open(logfile, "a") as logfd:
539         logfd.write(message + "\n")
540     if not quiet:
541         sys.stdout.write(message)
542     return True
543
544
545 def option_callback(telnet_socket, command, option):
546     if option == b'\x7f':
547         # We use this unassigned option value as a canary, so short-circuit
548         # any response to avoid endlessly looping
549         pass
550     elif command in (telnetlib.DO, telnetlib.DONT):
551         telnet_socket.send(telnetlib.IAC + telnetlib.WONT + option)
552     elif command in (telnetlib.WILL, telnetlib.WONT):
553         telnet_socket.send(telnetlib.IAC + telnetlib.DONT + option)
554
555
556 def check_debug():
557     if len(sys.argv) > 1:
558         config = yaml.safe_load(open(sys.argv[1]))
559         return config.get(".mudpy.limit.debug", False)
560     return False
561
562
563 def main():
564     captures = ["", "", ""]
565     lusers = [telnetlib.Telnet(), telnetlib.Telnet(), telnetlib.Telnet()]
566     success = True
567     start = time.time()
568     service = None
569     if len(sys.argv) > 1:
570         # Start the service if a config file was provided on the command line
571         service = start_service(sys.argv[1])
572         if not service:
573             tlog("\nERROR: Service did not start.\n")
574             sys.exit(1)
575     for luser in lusers:
576         luser.open("::1", 4000)
577         luser.set_option_negotiation_callback(option_callback)
578     selected_dialogue = odict(dialogue)
579     if check_debug():
580         for test in nondebug_tests:
581             del selected_dialogue[test]
582     else:
583         for test in debug_tests:
584             del selected_dialogue[test]
585     for test, description in selected_dialogue.items():
586         tlog("\nTesting %s..." % description)
587         test_start = time.time()
588         for conversant, question, answer in test:
589             tlog("luser%s waiting for: %s" % (conversant, question),
590                  quiet=True)
591             try:
592                 index, match, received = lusers[conversant].expect(
593                     [re.compile(question.encode("utf-8"), flags=re.DOTALL)], 5)
594                 captures[conversant] += received.decode("utf-8")
595             except ConnectionResetError:
596                 tlog("\nERROR: Unable to connect to server.")
597                 success = False
598                 break
599             except EOFError:
600                 tlog("\nERROR: luser%s premature disconnection expecting:\n\n"
601                      "%s\n\n"
602                      "Check the end of capture_%s.log for received data."
603                      % (conversant, question, conversant))
604                 success = False
605                 break
606             try:
607                 captures[conversant] += lusers[
608                     conversant].read_very_eager().decode("utf-8")
609             except Exception:
610                 pass
611             if index != 0:
612                 tlog("\nERROR: luser%s did not receive expected string:\n\n"
613                      "%s\n\n"
614                      "Check the end of capture_%s.log for received data."
615                      % (conversant, question, conversant))
616                 success = False
617                 break
618             if type(answer) is str:
619                 tlog("luser%s sending: %s" % (conversant, answer), quiet=True)
620                 lusers[conversant].write(("%s\r\0" % answer).encode("utf-8"))
621                 captures[conversant] += "%s\r\n" % answer
622             elif type(answer) is bytes:
623                 tlog("luser%s sending raw bytes: %s" % (conversant, answer),
624                      quiet=True)
625                 lusers[conversant].get_socket().send(answer)
626                 captures[conversant] += "!!!RAW BYTES: %s" % answer
627             else:
628                 tlog("\nERROR: answer provided with unsupported type %s"
629                      % type(answer))
630                 success = False
631                 break
632         if not success:
633             break
634         tlog("Completed in %.3f seconds." % (time.time() - test_start))
635     duration = time.time() - start
636     for conversant in range(len(captures)):
637         try:
638             captures[conversant] += lusers[
639                 conversant].read_very_eager().decode("utf-8")
640         except Exception:
641             pass
642         lusers[conversant].close()
643         logfile = "capture_%s.log" % conversant
644         tlog("\nRecording session %s as %s." % (conversant, logfile))
645         log = open(logfile, "w")
646         log.write(captures[conversant])
647         log.close()
648     if not stop_service(service):
649         success = False
650     tlog("\nRan %s tests in %.3f seconds." % (len(dialogue), duration))
651     if success:
652         tlog("\nSUCCESS\n")
653     else:
654         tlog("\nFAILURE\n")
655         sys.exit(1)
656
657
658 if __name__ == '__main__':
659     sys.exit(main())