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 b1e1214440f88c43c183278e7246841f48c6fe6c..ab52afd1e3c087824ff59e09a2723c08592a7d05 100644 (file)
--- 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
 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
        ./wvtest report t/tmp/test-log/*.log
 
 check: test

diff --git a/wvtest b/wvtest
index 7541ebd63b951f30e047336a60d5db7161785e1a..6d8445a8ff302afcafbe2de082372f34491c500f 100755 (executable)
--- 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();
     my $show_counts = 1;
     GetOptionsFromArray(\@ARGV, 'counts!', \$show_counts)
         or pod2usage();


@@ -94,7 +98,11 @@ sub run()
     # always flush
     $| = 1;
 
     # 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) {
 
     $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 {
     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);
     };
 
         bigkill($pid);
     };
 


@@ -181,18 +190,27 @@ sub run()
     }
 
     if ($code != 0) {
     }
 
     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;
     }
 
     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));
 }
 
     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;
 
 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); }
 
 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
 
   # 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 \
   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
 
 =cut