Failing "Test PIPE" in test 182 in 2.64

[Stepan Kasal]

Hello,
  I observed a test failure with Autoconf 2.64.
The failing code is located under the comment "Test PIPE" in
autotest.at.
iIn the command below that comment, micro-suite seems to exit with
exit code 0.
The check below fails as this is not allowed.

Please give me some hints how I could debug this.

Thanks,
        Stepan

[Ralf Wildenhues]

Hi Stepan,

* Stepan Kasal wrote on Fri, Oct 30, 2009 at 08:16:03PM CET:
>   I observed a test failure with Autoconf 2.64.

Which shell is /bin/sh, and which is selected as CONFIG_SHELL?

> The failing code is located under the comment "Test PIPE" in
> autotest.at.
> iIn the command below that comment, micro-suite seems to exit with
> exit code 0.
> The check below fails as this is not allowed.
>
> Please give me some hints how I could debug this.

There are probably too many things that can go wrong here (we've had
several bug reports about the parallel autotest tests; they have not
all been analyzed, and it's just as likely that some of the tests are
too strict, or some non-bash shells have unknown bugs).

Anyway, it's important to know which of the tests failed, and to see the
exact output from before that.  Did the `$CONFIG_SHELL ./micro-suite -d
-3 5- | sed 5q' get to test 5?  Was this GNU sed, and which version?

Cheers,
Ralf

[Stepan Kasal]

Hello Ralf,

thank you very much.  I tried some experiments today.
I believe we are on the trace of a subtle autotest bug here.
But without more hints from you, I'm not able to proceed; see below.

> Which shell is /bin/sh, and which is selected as CONFIG_SHELL?
> [...]  Did the `$CONFIG_SHELL ./micro-suite -d
> -3 5- | sed 5q' get to test 5?  Was this GNU sed, and which version?

this is an up-to date Fedora GNU/Linux, with:
        GNU bash, version 4.0.35(1)-release (i386-redhat-linux-gnu)
        GNU sed version 4.2.1
Moreover, the build happens in a chrooted tree; the underlying
system might be a bit older, like RHEL-5.x.

My analysis showed there are two thigs that together cause the test
to fail:
1) command "(/bin/sh micro-test -3 5-; echo $? >status) | sed 5q"
   quietly finishes its work, writing 0 to status, as if the shell
   ignored sigpipe.
2) The test's code to handle "shells that ignore sigpipe" does not
   seem to be correct.

Of these two causes, the latter one can be easily fixed, see the
attached autoconf-ignore-sigpipe-fix.patch (against 2.64).
But: shouldn't the test smell something when latest bash seems to
ignore sigpipe?  I would say yes, so the above fix should be enhanced
to report a problem in this situation.

But the more puzzling part is the first one.  I took micro-test.at
from the test case (also attached to this mail) and tried:

mkdir micro
cd micro
autom4te_perllibdir='..'/lib AUTOM4TE_CFG='../lib/autom4te.cfg' \
        ../bin/autom4te -B ../lib --language=autotest \
        $sources/micro-suite.at -o micro-suite
(/bin/sh ./micro-suite -d -3 5-; echo boo; echo $? >status) | sed 5q
cat micro-suite.dir/7/micro-suite.log
cat status

The tracing of this looked roughly like this
----------8<-----------
+ mkdir micro
+ cd micro
+ autom4te_perllibdir=../lib
+ AUTOM4TE_CFG=../lib/autom4te.cfg
+ ../bin/autom4te -B ../lib --language=autotest
/builddir/build/SOURCES/micro-suite.at -o micro-suite
+ sh ./micro-suite -d -3 5-
+ sed 5q
## -------------------------------------------------------------- ##
## GNU Nonsense 1.0 test suite: suite to test parallel execution. ##
## -------------------------------------------------------------- ##
  1: test number 1                                   ok
  2: test number 2                                   ok
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1769: echo: write error: Broken pipe
cat: write error: Broken pipe
./micro-suite: line 1775: echo: write error: Broken pipe
./micro-suite: line 1851: echo: write error: Broken pipe
+ echo 0
+ cat status
0
----------8<-----------

This shows clearly that the testsuite (non-parallel run) finished its
work.

Then I tried:

----------8<-----------
cat >foo <<END
echo 1
echo 2
echo 3
sleep 1
echo 4
END
(/bin/sh foo; echo $? >foostatus ) | sed 2q
cat foostatus
----------8<-----------

and got the correct output:

----------8<-----------
+ cat
+ /bin/sh foo
+ sed 2q
1
2
foo: line 5: echo: write error: Broken pipe
+ cat foostatus
cat: foostatus: No such file or directory
----------8<-----------

Lastly, I modified my micro-suite experiment this way:
----------8<-----------
(/bin/sh ./micro-suite -d -3 5-; echo boo; echo $? >status) | sed 5q
cat micro-suite.dir/7/micro-suite.log
cat status
----------8<-----------

and observed that the "echo boo" triggered sigpipe, so that file
"status" was not created in this case, observe:

----------8<-----------
+ autom4te_perllibdir=../lib
+ AUTOM4TE_CFG=../lib/autom4te.cfg
+ ../bin/autom4te -B ../lib --language=autotest
/builddir/build/SOURCES/micro-suite.at -o micro-suite
+ /bin/sh ./micro-suite -d -3 5-
+ sed 5q
## -------------------------------------------------------------- ##
## GNU Nonsense 1.0 test suite: suite to test parallel execution. ##
## -------------------------------------------------------------- ##
  1: test number 1                                   ok
  2: test number 2                                   ok
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1769: echo: write error: Broken pipe
cat: write error: Broken pipe
./micro-suite: line 1775: echo: write error: Broken pipe
./micro-suite: line 1851: echo: write error: Broken pipe
+ echo boo
/var/tmp/rpm-tmp.MGWMDC: line 51: echo: write error: Broken pipe
+ cat micro-suite.dir/7/micro-suite.log
#                             -*- compilation -*-
7. micro-suite.at:22: testing ...
/micro-suite.at:22: sleep 1
7. micro-suite.at:22: 7. test number 7 (micro-suite.at:22): ok (0m0.000s 0m0.002s)
+ cat status
cat: status: No such file or directory
----------8<-----------

Hypothesis:
I conclude that micro-suite somehow managed to set a trap for SIGPIPE
that caused that the testsuite was not interrupted.
This does not happen on my ancient ix86 machine, but it happens in
the build environment, that is a chroot on a x86_64, probably new and
fast.

Proof: well, I saw some sigpipe traps in the expanded micro-suite,
but I do not understand the details, so I was not sure how to
eliminate the one that might cause this problem.

I would be very grateful for some hints that would allow me to
proceed hunting this bug.  (Ralf?)

Happy piping,
        Stepan

2009-11-04  Stepan Kasal  <skasal@...>

        * tests/autotest.at (parallel autotest and signal handling):
        Do not check exist status if the shell ignores sigpipe.

--- autoconf-2.64/tests/autotest.at.orig 2009-11-04 14:18:18.000000000 +0100
+++ autoconf-2.64/tests/autotest.at 2009-11-04 15:00:09.000000000 +0100
@@ -1297,13 +1297,13 @@
 AT_CHECK([($CONFIG_SHELL ./micro-suite -d -3 5-; echo $? >status) | sed 5q],
  [], [stdout], [stderr])
 AT_CHECK([grep '5.*ok' stdout], [1])
-# Apparently some shells don't get around to creating 'status' any more.
-# And ksh93 on FreeBSD uses 256 + 13 instead of 128 + 13
-AT_CHECK([test ! -s status || grep 141 status || grep 269 status],
- [], [ignore])
 AT_CHECK([if test -f micro-suite.dir/7/micro-suite.log; then ]dnl
  [  echo "shell ignores SIGPIPE" > sigpipe-stamp ]dnl
  [else :; fi])
+# Apparently some shells don't get around to creating 'status' any more.
+# And ksh93 on FreeBSD uses 256 + 13 instead of 128 + 13
+AT_CHECK([test -s sigpipe-stamp || test ! -s status || grep 141 status || grep 269 status],
+ [], [ignore])
 
 AT_CHECK([$CONFIG_SHELL ./micro-suite -d -3 5- --jobs=2 | sed 5q], [], [stdout], [ignore])
 AT_CHECK([grep '5.*ok' stdout], [1])

m4_define([AT_PACKAGE_NAME],      [GNU Nonsense])
m4_define([AT_PACKAGE_TARNAME],   [nonsense])
m4_define([AT_PACKAGE_VERSION],   [1.0])
m4_define([AT_PACKAGE_STRING],    [GNU Nonsense 1.0])
m4_define([AT_PACKAGE_BUGREPORT], [bug-autoconf@...])

AT_INIT([suite to test parallel execution])
AT_SETUP([test number 1])
echo ======= >&2
trap -p >&2
AT_CHECK([sleep 2])
AT_CLEANUP
AT_SETUP([test number 2])
AT_CHECK([sleep 1])
AT_CLEANUP
AT_SETUP([test number 3])
AT_CHECK([sleep 1])
AT_CLEANUP
AT_SETUP([killer test])
AT_CHECK([kill -$signal $suite_pid])
AT_CLEANUP
m4_for([count], [5], [7], [],
   [AT_SETUP([test number count])
    AT_CHECK([sleep 1])
    AT_CLEANUP
])

[Stepan Kasal]

Hello,

a correction to my previous mail: one of the exhibits shown was
slightly incorrect, see below.

the output of the commands

> mkdir micro
> cd micro
> autom4te_perllibdir='..'/lib AUTOM4TE_CFG='../lib/autom4te.cfg' \
>         ../bin/autom4te -B ../lib --language=autotest \
>         $sources/micro-suite.at -o micro-suite
> (/bin/sh ./micro-suite -d -3 5-; echo boo; echo $? >status) | sed 5q
> cat micro-suite.dir/7/micro-suite.log
> cat status

is actually:

----------8<-----------
+ mkdir micro
+ cd micro
+ autom4te_perllibdir=../lib
+ AUTOM4TE_CFG=../lib/autom4te.cfg
+ ../bin/autom4te -B ../lib --language=autotest /builddir/build/SOURCES/micro-suite.at -o micro-suite
+ /bin/sh ./micro-suite -d -3 5-
+ sed 5q
## -------------------------------------------------------------- ##
## GNU Nonsense 1.0 test suite: suite to test parallel execution. ##
## -------------------------------------------------------------- ##
  1: test number 1                                   ok
  2: test number 2                                   ok
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1553: printf: write error: Broken pipe
./micro-suite: line 1769: echo: write error: Broken pipe
cat: write error: Broken pipe
./micro-suite: line 1775: echo: write error: Broken pipe
./micro-suite: line 1851: echo: write error: Broken pipe
+ echo 0
+ cat micro-suite.dir/7/micro-suite.log
#                             -*- compilation -*-
7. micro-suite.at:22: testing ...
/micro-suite.at:22: sleep 1
7. micro-suite.at:22: 7. test number 7 (micro-suite.at:22): ok     (0m0.000s 0m0.001s)
+ cat status
0
----------8<-----------

Stepan