Subject: Re: bug#11413: Racy failure in test case 'tap-more.sh'

From: Stefano Lattarini <[email-masked]>
Date: Sat, 05 May 2012 19:34:32 +0200

tags 11413 + patch
close 11413
thanks

On 05/05/2012 05:51 PM, Stefano Lattarini wrote:
> Severity: minor
> 
> I'm sporadically seeing the failure below in the test 'tap-more.sh'.
> 
> Anyone has an insight about what's going on?
>
Such an insight is offered by an older commit:

  commit 642699970e75580e0f11f5786302082e25d8f49c
  Author: Ralf Wildenhues <[email-masked]>
  Date:   Tue Mar 10 21:33:47 2009 +0100

      Use append mode to capture parallel test output.

      * tests/lisp8.test: Use append mode for output from `make -j',
      to avoid dropped lines.
      * tests/parallel-tests3.test: Likewise.

      Signed-off-by: Ralf Wildenhues <[email-masked]>

I've verified (with the help of the attached script) that such an issue
is indeed present on the affected systems (my Debian box and the Fedora
ppc64 system offered by the GCC compile farm), and I've pushed the
attached patch to fix it.  I'm thus closing this bug report.

Regards,
  Stefano
>From 45c1fcd986d38467662a1ec253d80304d7630f4f Mon Sep 17 00:00:00 2001
Message-Id: <45c1fcd98[email-masked]>
In-Reply-To: <952d91c05[email-masked]>
References: <952d91c05[email-masked]>
From: Stefano Lattarini <[email-masked]>
Date: Sat, 5 May 2012 19:22:40 +0200
Subject: [PATCH 2/2] tests: use append mode to capture parallel make output

This should fix the spurious failure reported in automake bug#11413.

This is due to the fact that the redirected output of parallel make
can racily loose lines.  For example, if GNU make (3.82) is run on
a Makefile like this:

  all = 0 1 2 3 4 5 6 7 8 9
  default: $(all)
  $(all):
        @sleep 0.$$(($RANDOM % 10)); echo $@

and has its standard output redirected in overwrite-mode to a regular
file, it looses a line of that output every 15 runs or so on a Fedora
17 system with 64 ppc64 cores and Linux 3.3.1.  Redirection in append
mode does not suffer of this problem.

See also similar commit 'Release-1-10-280-g6426999' of 2009-03-10,
"Use append mode to capture parallel test output", which tackled a
similar problem for 't/parallel-tests3.sh' and 't/lisp8.sh'.

* t/tap-more.sh: Use append mode for output from "make -j", to avoid
dropped lines.
* t/parallel-tests3.sh, t/lisp8.sh: Enhance comments.

Signed-off-by: Stefano Lattarini <[email-masked]>
---
 t/lisp8.sh           |    2 ++
 t/parallel-tests3.sh |    5 ++---
 t/tap-more.sh        |   14 ++++++++++++--
 3 files changed, 16 insertions(+), 5 deletions(-)

diff --git a/t/lisp8.sh b/t/lisp8.sh
index 299ecd0..738cbd6 100755
--- a/t/lisp8.sh
+++ b/t/lisp8.sh
@@ -37,6 +37,7 @@ $AUTOCONF
 $AUTOMAKE --add-missing
 ./configure
 
+# Use append mode here to avoid dropping output.  See automake bug#11413.
 : >stdout
 $MAKE -j >>stdout || { cat stdout; Exit 1; }
 
@@ -50,6 +51,7 @@ test -f elc-stamp
 
 rm -f am-*.elc
 
+# Use append mode here to avoid dropping output.  See automake bug#11413.
 : >stdout
 $MAKE -j >>stdout || { cat stdout; Exit 1; }
 
diff --git a/t/parallel-tests3.sh b/t/parallel-tests3.sh
index f06d093..98467e6 100755
--- a/t/parallel-tests3.sh
+++ b/t/parallel-tests3.sh
@@ -90,9 +90,8 @@ cd serial
 $MAKE ${j}1 check &
 cd ../parallel
 $sleep
-# Use append mode here to avoid dropping output.
-# Yes, this actually happens.
-: >stdout
+# Use append mode here to avoid dropping output.  See automake bug#11413.
+: > stdout
 $MAKE ${j}4 check >> stdout
 cd ..
 # Ensure the tests are really being run in parallel mode: if this is
diff --git a/t/tap-more.sh b/t/tap-more.sh
index 6f5d5fe..d275bd9 100755
--- a/t/tap-more.sh
+++ b/t/tap-more.sh
@@ -118,7 +118,12 @@ for try in 0 1; do
 
   # Success.
 
-  $run_make check >stdout || { cat stdout; Exit 1; }
+  # Use append mode here to avoid dropping output.  See automake bug#11413.
+  # Also, use 'echo' here to "nullify" the previous contents of 'stdout',
+  # since Solaris 10 /bin/sh would try to optimize a ':' away after the
+  # first iteration, even if it is redirected.
+  echo " " >stdout
+  $run_make check >>stdout || { cat stdout; Exit 1; }
   cat stdout
   count_test_results total=6 pass=4 fail=0 xpass=0 xfail=1 skip=1 error=0
   grep '^PASS: 1\.test 1 - mu$' stdout
@@ -138,7 +143,12 @@ for try in 0 1; do
   # a ':' away after the first iteration, even if it is redirected.
   echo dummy > not-skip
   echo dummy > bail-out
-  $run_make check >stdout && { cat stdout; Exit 1; }
+  # Use append mode here to avoid dropping output.  See automake bug#11413.
+  # Also, use 'echo' here to "nullify" the previous contents of 'stdout',
+  # since Solaris 10 /bin/sh would try to optimize a ':' away after the
+  # first iteration, even if it is redirected.
+  echo " " >stdout
+  $run_make check >>stdout && { cat stdout; Exit 1; }
   cat stdout
   count_test_results total=7 pass=4 fail=1 xpass=0 xfail=1 skip=0 error=1
   grep '^PASS: 1\.test 1 - mu$' stdout
-- 
1.7.9.5