Add k5test expected_msg, expected_trace

In k5test.py, add the optional keyword argument "expected_msg" to
methods that run commands, to make it easier to look for substrings in
the command output.  Add the optional keyword "expected_trace" to run
the command with KRB5_TRACE enabled and look for an ordered series of
substrings in the trace output.

.gitignore

@@ -15,6 +15,7 @@ obj/
 skiptests
 testdir/
 testlog
+testtrace
 
 # Ignore the build directory
 /build/

src/config/post.in

@@ -156,7 +156,7 @@ clean: clean-$(WHAT)
 
 clean-unix::
 	$(RM) $(OBJS) $(DEPTARGETS_CLEAN) $(EXTRA_FILES)
-	$(RM) et-[ch]-*.et et-[ch]-*.[ch] testlog
+	$(RM) et-[ch]-*.et et-[ch]-*.[ch] testlog testtrace
 	-$(RM) -r testdir
 
 clean-windows::

src/util/k5test.py

@@ -223,8 +223,11 @@
   command-line debugging options.  Fail if the command does not return
   0.  Log the command output appropriately, and return it as a single
   multi-line string.  Keyword arguments can contain input='string' to
-  send an input string to the command, and expected_code=N to expect a
-  return code other than 0.
+  send an input string to the command, expected_code=N to expect a
+  return code other than 0, expected_msg=MSG to expect a substring in
+  the command output, and expected_trace=('a', 'b', ...) to expect an
+  ordered series of line substrings in the command's KRB5_TRACE
+  output.
 
 * realm.kprop_port(): Returns a port number based on realm.portbase
   intended for use by kprop and kpropd.
@@ -647,10 +650,31 @@ def _stop_or_shell(stop, shell, env, ind):
         subprocess.call(os.getenv('SHELL'), env=env)
 
 
-def _run_cmd(args, env, input=None, expected_code=0):
+# Read tracefile and look for the expected strings in successive lines.
+def _check_trace(tracefile, expected):
+    output('*** Trace output for previous command:\n')
+    i = 0
+    with open(tracefile, 'r') as f:
+        for line in f:
+            output(line)
+            if i < len(expected) and expected[i] in line:
+                i += 1
+    if i < len(expected):
+        fail('Expected string not found in trace output: ' + expected[i])
+
+
+def _run_cmd(args, env, input=None, expected_code=0, expected_msg=None,
+             expected_trace=None):
     global null_input, _cmd_index, _last_cmd, _last_cmd_output, _debug
     global _stop_before, _stop_after, _shell_before, _shell_after
 
+    if expected_trace is not None:
+        tracefile = 'testtrace'
+        if os.path.exists(tracefile):
+            os.remove(tracefile)
+        env = env.copy()
+        env['KRB5_TRACE'] = tracefile
+
     if (_match_cmdnum(_debug, _cmd_index)):
         return _debug_cmd(args, env, input)
 
@@ -679,6 +703,13 @@ def _run_cmd(args, env, input=None, expected_code=0):
     # Check the return code and return the output.
     if code != expected_code:
         fail('%s failed with code %d.' % (args[0], code))
+
+    if expected_msg is not None and expected_msg not in outdata:
+        fail('Expected string not found in command output: ' + expected_msg)
+
+    if expected_trace is not None:
+        _check_trace(tracefile, expected_trace)
+
     return outdata