unstable autotest --trace with FreeBSD sh and pipes (was: FW: [GNU Autoconf 2.65] testsuite: 35 239 271 272 273 274 275 276 277 278 279 280 failed)

[Ralf Wildenhues]

The testsuite passed on FreeBSD with the two patches applied.

* Ralf Wildenhues wrote on Sun, Feb 28, 2010 at 03:09:51PM CET:
> I'm seeing spurious testsuite failures when I pass '-v -d -x NNN' as
> TESTSUITEFLAGS, NNN being numbers, on FreeBSD.  Haven't investigated
> further yet.

Happens with -x but not without.  Example:

> 37. tools.at:1257: testing ...
> + set +x
> + echo AC_INIT
> + sleep 2
> ../../autoconf/tests/tools.at:1263: echo AC_INIT | autom4te 
> --language=autoconf -o configure -
> + echo
> + + echoautom4te AC_INIT --language=autoconf
> --- /dev/null   2010-02-28 14:26:41.507176860 +0000
> +++ /tmp/autoconf/tests/testsuite.dir/at-groups/37/stderr        2010-02-28 
> 14:26:43.177096541 +0000
> @@ -0,0 +1 @@
> + -o configure -
> 37. tools.at:1257:  FAILED (tools.at:1263)

The trace lines for the two commands in the pipeline are intermingled.
Ugh.

A different example:

> ../../autoconf/tests/c.at:34: at_check_env
> + at_check_env
> + test -f state-ls.before
> + test -f state-ls.after
> + diff -u state-ls.before state-ls.after
> + test -f state-env.before
> + test -f state-env.after
> + + /usr/bin/grep/usr/bin/grep -E 
> ^[abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ_][abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOP
>  -vQRSTUVWXYZ_0123456789]*= 
> ^(a[cs]_.*|(exec_)?prefix|DEFS|CONFIG_STATUS|CC|CFLAGS|CPP|GCC|CXX|CXXFLAGS|CXXCPP|GXX|F77|FFLAGS|F
> + + /usr/bin/grep/usr/bin/grep -E 
> ^[abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ_][abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOP
>  -vQRSTUVWXYZ_0123456789]*= 
> ^(a[cs]_.*|(exec_)?prefix|DEFS|CONFIG_STATUS|CC|CFLAGS|CPP|GCC|CXX|CXXFLAGS|CXXCPP|GXX|F77|FFLAGS|F
> + diff -u clean-state-env.before clean-state-env.after
> --- /dev/null   2010-02-28 15:05:05.573142672 +0000
> +++ /tmp/autoconf/tests/testsuite.dir/at-groups/241/stderr       2010-02-28 
> 15:05:05.957464682 +0000
> @@ -0,0 +1,2 @@
> +LIBS|G77|ERL|ERLC|ERLCFLAGS|ERLANG_PATH_ERL|ERLANG_ROOT_DIR|ERLANG_LIB_DIR|ERLANG_LIB_DIR_.*|ERLANG_LIB_VER_.*|ERLANG_INSTALL_LIB_DIR|ERLANG_INSTALL_LIB_DIR_.*|ERLANG_ERTS_VER|OBJC|OBJCPP|OBJCFLAGS|OBJCXX|OBJCXXCPP|OBJCXXFLAGS|OPENMP_CFLAGS|LIBS|LIBOBJS|LTLIBOBJS|LDFLAGS|INSTALL(_(DATA|PROGRAM|SCRIPT))?|CYGWIN|ISC|MINGW32|MINIX|EMXOS2|XENIX|EXEEXT|OBJEXT|X_(CFLAGS|(EXTRA_|PRE_)?LIBS)|x_(includes|libraries)|(have|no)_x|(host|build|target)(_(alias|cpu|vendor|os))?|cross_compiling|U|interpval|PATH_SEPARATOR|F77_DUMMY_MAIN|f77_(case|underscore)|FC(_DUMMY_MAIN|FLAGS|LIBS|FLAGS_f)?|ALLOCA|GETLOADAVG_LIBS|KMEM_GROUP|NEED_SETGID|POW_LIB|AWK|LEX|LEXLIB|LEX_OUTPUT_ROOT|LN_S|M4|MKDIR_P|RANLIB|SET_MAKE|YACC|GREP|[EF]GREP|SED|address@hidden|.[*#?$].|argv|ARGC|LINENO|OLDPWD|PIPESTATUS|RANDOM|SECONDS)=
>  state-env.before
> +LIBS|G77|ERL|ERLC|ERLCFLAGS|ERLANG_PATH_ERL|ERLANG_ROOT_DIR|ERLANG_LIB_DIR|ERLANG_LIB_DIR_.*|ERLANG_LIB_VER_.*|ERLANG_INSTALL_LIB_DIR|ERLANG_INSTALL_LIB_DIR_.*|ERLANG_ERTS_VER|OBJC|OBJCPP|OBJCFLAGS|OBJCXX|OBJCXXCPP|OBJCXXFLAGS|OPENMP_CFLAGS|LIBS|LIBOBJS|LTLIBOBJS|LDFLAGS|INSTALL(_(DATA|PROGRAM|SCRIPT))?|CYGWIN|ISC|MINGW32|MINIX|EMXOS2|XENIX|EXEEXT|OBJEXT|X_(CFLAGS|(EXTRA_|PRE_)?LIBS)|x_(includes|libraries)|(have|no)_x|(host|build|target)(_(alias|cpu|vendor|os))?|cross_compiling|U|interpval|PATH_SEPARATOR|F77_DUMMY_MAIN|f77_(case|underscore)|FC(_DUMMY_MAIN|FLAGS|LIBS|FLAGS_f)?|ALLOCA|GETLOADAVG_LIBS|KMEM_GROUP|NEED_SETGID|POW_LIB|AWK|LEX|LEXLIB|LEX_OUTPUT_ROOT|LN_S|M4|MKDIR_P|RANLIB|SET_MAKE|YACC|GREP|[EF]GREP|SED|address@hidden|.[*#?$].|argv|ARGC|LINENO|OLDPWD|PIPESTATUS|RANDOM|SECONDS)=
>  state-env.after



I know this will make you weep, killing off some of that precious m4
time you worked so hard for; but just matching for | gives lots of false
positives that have ||, even [^|]|[^|] has quite a few false positives
from egrep and sed 's|||' commands which I don't know how to avoid.
One alternative could be to test for this shell early in testsuite and
just turn off at_traceon=: if we find it, but that would need some way
to actually detect this shell.

Anyway, this patch fixes the failures I observed, and let's
  make check TESTSUITEFLAGS='-v -x'

pass on this system.

I haven't tried consolidating the m4_index with the m4_bregexp, nor
dared to think about shell asynchronous lists 'cmd1 & cmd2', which
are even harder to match given file descriptor redirections like >&2.

Cheers,
Ralf

commit bd3ee9163b94219b567832514a9a59058e9ce0ea
Author: Ralf Wildenhues <address@hidden>
Date:   Sun Feb 28 17:18:11 2010 +0100

    Fix Autotest tracing of shell pipelines for FreeBSD sh.
    
    * lib/autotest/general.m4 (_AT_DECIDE_TRACEABLE): Do not trace
    commands that contain [^|]|[^|], a likely shell pipeline.
    * tests/local.at (_AT_CHECK_ENV): Turn off tracing for egrep |
    grep pipeline.
    * doc/autoconf.texi (File Descriptors): Document limitation.
    * tests/autotest.at (Trace output): New test.
    
    Signed-off-by: Ralf Wildenhues <address@hidden>

diff --git a/ChangeLog b/ChangeLog
index bf091b9..b0bdfa0 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,5 +1,13 @@
 2010-02-28  Ralf Wildenhues  <address@hidden>
 
+       Fix Autotest tracing of shell pipelines for FreeBSD sh.
+       * lib/autotest/general.m4 (_AT_DECIDE_TRACEABLE): Do not trace
+       commands that contain [^|]|[^|], a likely shell pipeline.
+       * tests/local.at (_AT_CHECK_ENV): Turn off tracing for egrep |
+       grep pipeline.
+       * doc/autoconf.texi (File Descriptors): Document limitation.
+       * tests/autotest.at (Trace output): New test.
+
        Fix `autom4te cache creation' testsuite failure on FreeBSD.
        * tests/tools.at (autom4te cache creation): Normalize exit
        status of failed redirection to 1, may be 2 with FreeBSD sh.
diff --git a/doc/autoconf.texi b/doc/autoconf.texi
index 3dfeda2..759f424 100644
--- a/doc/autoconf.texi
+++ b/doc/autoconf.texi
@@ -14764,6 +14764,9 @@ File Descriptors
 @samp{: `cd /zorglub` 2>/dev/null} expect the error message to
 escape, while @samp{: `cd /zorglub 2>/dev/null`} works properly.
 
+FreeBSD 6.2 sh may mix the trace output lines from the statements in a
+shell pipeline.
+
 It is worth noting that Zsh (but not Ash nor Bash) makes it possible
 in assignments though: @samp{foo=`cd /zorglub` 2>/dev/null}.
 
diff --git a/lib/autotest/general.m4 b/lib/autotest/general.m4
index 71e3090..7942164 100644
--- a/lib/autotest/general.m4
+++ b/lib/autotest/general.m4
@@ -2034,6 +2034,8 @@ m4_cond([m4_eval(m4_index([$1], [`]) >= 0)], [1],
                [[a ${...} parameter expansion]],
        [m4_eval(m4_index([$1], m4_newline) >= 0)], [1],
                [[an embedded newline]],
+       [m4_eval(m4_bregexp([$1], [[^|]|[^|]]) >= 0)], [1],
+               [[a shell pipeline]],
        []))]dnl No reason.
 [m4_if(m4_index(_m4_defn([at_reason]), [a]), [0],]dnl
 dnl We know at build time that tracing COMMANDS is never safe.
diff --git a/tests/autotest.at b/tests/autotest.at
index 8a08897..88078ac 100644
--- a/tests/autotest.at
+++ b/tests/autotest.at
@@ -349,6 +349,12 @@ AT_CHECK_AT_TEST([unquoted output],
      [${a}"`echo 'b  '`\`\backtick]m4_newline)],
   [], [], [], [], [AT_KEYWORDS([AT@&address@hidden)])
 
+AT_CHECK_AT_TEST([Trace output],
+  [AT_CHECK([echo some longer longer longer command piped | ]dnl
+           [sed 's,into some other longer longer longer command,,'],
+           [], [some longer longer longer command piped
+])])
+
 AT_CHECK_AT([Logging],
   [[AT_INIT([artificial test suite])
     dnl intentionally write failing tests, to see what gets logged
diff --git a/tests/local.at b/tests/local.at
index dcfdf60..c26d071 100644
--- a/tests/local.at
+++ b/tests/local.at
@@ -243,6 +243,9 @@ m4_define([AT_CHECK_CONFIGURE],
 # In this case just don't pay attention to the env.  It would be great
 # to keep the error message but we can't: that would break AT_CHECK.
 #
+# FreeBSD sh may intermingle the trace output from the egrep and grep
+# commands in the pipe, so turn off tracing for these.
+#
 # Some tests might exit prematurely when they find a problem, in
 # which case `env-after' is probably missing.  Don't check it then.
 #
@@ -287,6 +290,7 @@ test -f state-ls.after \
   && { $at_diff state-ls.before state-ls.after || return 1; }
 # Compare variable space dumps.
 if test -f state-env.before && test -f state-env.after; then
+  set +x
   for act_file in state-env.before state-env.after
   do
     $EGREP -v '^(m4_join([|],
@@ -316,6 +320,7 @@ if test -f state-env.before && test -f state-env.after; then
       # There may be variables spread on several lines; remove latter lines.
       $GREP '^m4_defn([m4_re_word])=' >clean-$act_file
   done
+  $at_traceon
   $at_diff clean-state-env.before clean-state-env.after
 fi
 } [#]at_check_env])