From: Rob Browning <rlb@defaultvalue.org>
Date: Thu, 31 Dec 2015 20:55:36 +0000 (-0600)
Subject: Capture and check top level wvtest watch messages
X-Git-Tag: 0.28-rc1~41
X-Git-Url: https://arthur.barton.de/cgi-bin/gitweb.cgi?p=bup.git;a=commitdiff_plain;h=a25e07f4ff51afe998b38b4b1e918736fc53a210

Capture and check top level wvtest watch messages

During wvtest watch, report top level protocol messages to stderr so
that they can be safely captured for examination by report.  Continue
printing those message to stdout too, so that "wvtest watch
... 2>test-top.log" will still display them.

Adjust "make check" to include the top level messages when looking for
failures.  Otherwise a non-zero exit status from a t/test-*.sh test that
produced no wvtest failure output of its own was just ignored.  This can
be demonstrated by adding an "exit 1" to the top of an existing test and
running "make -j check".

Thanks to Greg Troxel for reporting the problem.

Signed-off-by: Rob Browning <rlb@defaultvalue.org>
Tested-by: Rob Browning <rlb@defaultvalue.org>
---

diff --git a/Makefile b/Makefile
index b1e1214..ab52afd 100644
--- a/Makefile
+++ b/Makefile
@@ -188,7 +188,8 @@ stupid:
 test: all
 	if test -e t/tmp/test-log; then rm -r t/tmp/test-log; fi
 	mkdir -p t/tmp/test-log
-	./wvtest watch --no-counts $(MAKE) runtests-python runtests-cmdline
+	./wvtest watch --no-counts \
+	  $(MAKE) runtests-python runtests-cmdline 2>t/tmp/test-log/$$$$.log
 	./wvtest report t/tmp/test-log/*.log
 
 check: test
diff --git a/wvtest b/wvtest
index 7541ebd..6d8445a 100755
--- a/wvtest
+++ b/wvtest
@@ -84,8 +84,12 @@ sub endsect()
     }
 }
 
-sub run()
+sub run
 {
+    # dup_msgs should be true when "watching".  In that case all top
+    # level wvtest protocol messages should be duplicated to stderr so
+    # that they can be safely captured for report to process later.
+    my ($dup_msgs) = @_;
     my $show_counts = 1;
     GetOptionsFromArray(\@ARGV, 'counts!', \$show_counts)
         or pod2usage();
@@ -94,7 +98,11 @@ sub run()
     # always flush
     $| = 1;
 
-    print STDERR "Testing \"all\" in @ARGV:\n";
+    {
+        my $msg = "Testing \"all\" in @ARGV:\n";
+        print $msg;
+        print STDERR $msg if $dup_msgs;
+    }
 
     $pid = open(my $fh, "-|");
     if (!$pid) {
@@ -110,7 +118,8 @@ sub run()
     local $SIG{INT} = sub { bigkill($pid); };
     local $SIG{TERM} = sub { bigkill($pid); };
     local $SIG{ALRM} = sub {
-        print STDERR "Alarm timed out!  No test results for too long.\n";
+        print STDERR resultline('Alarm timed out!  No test results for too long.\n',
+                                'FAILED');
         bigkill($pid);
     };
 
@@ -181,18 +190,27 @@ sub run()
     }
 
     if ($code != 0) {
-        print resultline("Program returned non-zero exit code ($ret)", "FAILED");
+        my $msg = resultline("Program returned non-zero exit code ($ret)",
+                             'FAILED');
+        print $msg;
+        print STDERR "$msg\n" if $dup_msgs;
     }
 
     print "\n";
     if ($show_counts) {
         my $gtotal = $gpasses + $gfails;
-        printf("WvTest: %d test%s, %d failure%s\n",
-               $gtotal, $gtotal==1 ? "" : "s",
-               $gfails, $gfails==1 ? "" : "s");
+        my $msg = sprintf("WvTest: %d test%s, %d failure%s\n",
+                          $gtotal, $gtotal == 1 ? "" : "s", $gfails,
+                          $gfails == 1 ? "" : "s");
+        print $msg;
+        print STDERR $msg if $dup_msgs;
+    }
+    {
+        my $msg = sprintf("WvTest: result code $ret, total time %s\n",
+                          mstime(time() - $allstart, 2000, 5000));
+        print $msg;
+        print STDERR $msg if $dup_msgs;
     }
-    printf("WvTest: result code $ret, total time %s\n",
-           mstime(time() - $allstart, 2000, 5000));
     return ($ret ? $ret : ($gfails ? 125 : 0));
 }
 
@@ -250,8 +268,8 @@ pod2usage(-msg => "$0: no action specified", -verbose => 1) if (@ARGV < 1);
 
 my $action = $ARGV[0];
 shift @ARGV;
-if ($action eq 'run') { exit run(); }
-elsif ($action  eq 'watch') { run(); }
+if ($action eq 'run') { exit run(0); }
+elsif ($action  eq 'watch') { run(1); }
 elsif ($action  eq 'report') { exit report(); }
 else { pod2usage(-msg => "$0: invalid action $action", -verbose => 1); }
 
@@ -287,9 +305,12 @@ B<report> as described in the EXAMPLES below.
   # Fine if ./tests doesn't produce any output in parallel.
   wvtest run ./tests
 
-  # Use watch and report for parallel tests.
+  # Use watch and report for parallel tests.  Note that watch's stderr will
+  # include copies of any top level messages - reporting non-zero
+  # test command exits, etc., and so must be included in the report arguments.
   wvtest watch --no-counts \
-    sh -c '(test-1 2>&1 | tee test-1.log)& (test-2 2>&1 | tee test-2.log)&'
-  wvtest report test-1.log test-2.log
+    "sh -c '(test-1 2>&1 | tee test-1.log)& (test-2 2>&1 | tee test-2.log)&'" \
+    2>test-3.log \
+  wvtest report test-1.log test-2.log test-3.log
 
 =cut