The first bugfix in the new branch. Luckily, the bug (detailedly described in the ChangeLog entry) is only in the Automake's own testsuite, not in the implementation.
I will push by tomorrow if there is no objection or review by then. Regards, Stefano
From 479d65dc01ead7f23fd3a604b638df829631ca01 Mon Sep 17 00:00:00 2001 Message-Id: <479d65dc01ead7f23fd3a604b638df829631ca01.1308772297.git.stefano.lattar...@gmail.com> From: Stefano Lattarini <stefano.lattar...@gmail.com> Date: Wed, 22 Jun 2011 21:46:39 +0200 Subject: [PATCH] parallel-tests: fix bug in Automake's own testsuite The new code for parsing the testsuite-generated `.log' files, as introduced in commit `v1.11-872-gc96b881', considers each `:test-result:' field anywhere in a `.log' file as a declaration of a test result, and accounts for it as such in the testsuite summary. Unfortunately, some test scripts in the Automake's own testsuite, which were checking the just-described new parsing semantics, ended up putting spurious `:test-result:' fields in their log files. These spurious fields did not refer to actual results of some Automake test, but were instead emitted by dummy testcases being run from within the Automake test scripts that were verifying the new code for parsing the testsuite-generated `.log' files. This situation was causing a botched summary and a wrong exit status for the Automake testsuite; for example: $ make check TESTS='check12-p.test'; echo exit: $? ... PASS: check12-p.test ===================================== 4 of 5 tests failed See tests/test-suite.log Please report to bug-autom...@gnu.org ===================================== make[2]: *** [test-suite.log] Error 1 make: *** [check-am] Error 2 exit: 2 This changes should fix the problem. * tests/defs (dump_log_files): New subroutine, display `.log' files created by the Automake test driver(s), mangling them to prevent the Automake's own testsuite harness from picking up spurious test results from them. * tests/check12.test: Use it when displaying the content of `.log' files created here by "$MAKE check" and similar, to avoid confusing Automake's own testsuite harness with spurious test results. Other related changes and simplifications. * tests/check-exported-srcdir.test: Likewise. * tests/parallel-tests-am_tests_environment.test: Likewise. * tests/parallel-tests-empty-testlogs.test: Likewise. * tests/parallel-tests-interrupt.test: Likewise. * tests/parallel-tests-reset-term.test: Likewise. * tests/tests-environment-and-log-compiler.test: Likewise. * tests/tests-environment-fd-redirect.test: Likewise. * tests/test-driver-custom.test: Likewise. * tests/test-driver-custom-no-html.test: Likewise. * tests/test-driver-custom-xfail-tests.test: Likewise. * tests/test-driver-custom-multitest.test: Likewise. * tests/test-driver-custom-multitest-recheck.test: Likewise. * Makefile.am (sc_tests_cat_log_file): New maintainer check. (sc_tests_make_check_verbose): Likewise. (syntax_check_rules): Add them. * tests/parallel-tests.test: Adjust to avoid triggering the new `sc_tests_make_check_verbose' maintainer check. --- ChangeLog | 55 +++++++++++++++++++++++ Makefile.am | 22 +++++++++ Makefile.in | 16 +++++++ tests/check-exported-srcdir.test | 17 ++----- tests/check12.test | 6 +- tests/defs | 19 ++++++++ tests/parallel-tests-am_tests_environment.test | 11 +++-- tests/parallel-tests-empty-testlogs.test | 8 ++-- tests/parallel-tests-interrupt.test | 17 +++++--- tests/parallel-tests-reset-term.test | 3 +- tests/parallel-tests.test | 9 +++- tests/test-driver-custom-multitest-recheck.test | 2 +- tests/test-driver-custom-multitest.test | 29 +++++++----- tests/test-driver-custom-no-html.test | 5 +- tests/test-driver-custom-xfail-tests.test | 6 +- tests/test-driver-custom.test | 8 +++- tests/tests-environment-and-log-compiler.test | 7 +-- tests/tests-environment-fd-redirect.test | 4 +- 18 files changed, 184 insertions(+), 60 deletions(-) diff --git a/ChangeLog b/ChangeLog index d6dbd13..725d7b3 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,58 @@ +2011-06-22 Stefano Lattarini <stefano.lattar...@gmail.com> + + parallel-tests: fix bug in Automake's own testsuite + The new code for parsing the testsuite-generated `.log' files, + as introduced in commit `v1.11-872-gc96b881', considers each + `:test-result:' field anywhere in a `.log' file as a declaration + of a test result, and accounts for it as such in the testsuite + summary. Unfortunately, some test scripts in the Automake's + own testsuite, which were checking the just-described new parsing + semantics, ended up putting spurious `:test-result:' fields in + their log files. These spurious fields did not refer to actual + results of some Automake test, but were instead emitted by dummy + testcases being run from within the Automake test scripts that + were verifying the new code for parsing the testsuite-generated + `.log' files. + This situation was causing a botched summary and a wrong exit + status for the Automake testsuite; for example: + $ make check TESTS='check12-p.test'; echo exit: $? + ... + PASS: check12-p.test + ===================================== + 4 of 5 tests failed + See tests/test-suite.log + Please report to bug-autom...@gnu.org + ===================================== + make[2]: *** [test-suite.log] Error 1 + make: *** [check-am] Error 2 + exit: 2 + This changes should fix the problem. + * tests/defs (dump_log_files): New subroutine, display `.log' + files created by the Automake test driver(s), mangling them to + prevent the Automake's own testsuite harness from picking up + spurious test results from them. + * tests/check12.test: Use it when displaying the content of `.log' + files created here by "$MAKE check" and similar, to avoid confusing + Automake's own testsuite harness with spurious test results. Other + related changes and simplifications. + * tests/check-exported-srcdir.test: Likewise. + * tests/parallel-tests-am_tests_environment.test: Likewise. + * tests/parallel-tests-empty-testlogs.test: Likewise. + * tests/parallel-tests-interrupt.test: Likewise. + * tests/parallel-tests-reset-term.test: Likewise. + * tests/tests-environment-and-log-compiler.test: Likewise. + * tests/tests-environment-fd-redirect.test: Likewise. + * tests/test-driver-custom.test: Likewise. + * tests/test-driver-custom-no-html.test: Likewise. + * tests/test-driver-custom-xfail-tests.test: Likewise. + * tests/test-driver-custom-multitest.test: Likewise. + * tests/test-driver-custom-multitest-recheck.test: Likewise. + * Makefile.am (sc_tests_cat_log_file): New maintainer check. + (sc_tests_make_check_verbose): Likewise. + (syntax_check_rules): Add them. + * tests/parallel-tests.test: Adjust to avoid triggering the new + `sc_tests_make_check_verbose' maintainer check. + 2011-06-21 Stefano Lattarini <stefano.lattar...@gmail.com> parallel-tests: allow each test to have multiple results diff --git a/Makefile.am b/Makefile.am index 6f7554d..186d38c 100644 --- a/Makefile.am +++ b/Makefile.am @@ -202,6 +202,8 @@ sc_tests_overriding_macros_on_cmdline \ sc_tests_plain_sleep \ sc_tests_plain_egrep_fgrep \ sc_tests_PATH_SEPARATOR \ +sc_tests_cat_log_file \ +sc_tests_make_check_verbose \ sc_tests_logs_duplicate_prefixes \ sc_tests_makefile_variable_order \ sc_mkdir_p \ @@ -569,6 +571,26 @@ sc_tests_plain_egrep_fgrep: exit 1; \ fi +## From within our test scripts, we should directly never display a `.log' file +## created by the Automake test driver(s), because that could confuse Automake's +## own testsuite harness into picking up spurious test results from it. +sc_tests_cat_log_file: + @if grep '\<cat [^<>]*\.log\>' tests/*.test; then \ + echo "Don't use \`cat' directly on generated log files." >&2; \ + echo "Use the \`dump_log_files' function instead, if possible." >&2; \ + exit 1; \ + fi +## "VERBOSE=yes $MAKE check" can end up displaying the content of the generated +## `test-suite.log' if some test fails, and this is problematic for the reasons +## explained above. +sc_tests_make_check_verbose: + @v='\bVERBOSE=' m='\$$MAKE.*check'; \ + if grep -E "$$m.*$$v|$$v.*$$m" tests/*.test; then \ + echo "Don't use \`VERBOSE=yes \$$MAKE check' and similar in test scripts." >&2; \ + echo "It can cause spurious errors in the testsuite summary." >&2; \ + exit 1; \ + fi + ## Rule to ensure that the testsuite has been run before. We don't depend on `check' ## here, because that would be very wasteful in the common case. We could run ## `make check RECHECK_LOGS=' and avoid toplevel races with AM_RECURSIVE_TARGETS. diff --git a/Makefile.in b/Makefile.in index a8c0c40..3fae3ae 100644 --- a/Makefile.in +++ b/Makefile.in @@ -326,6 +326,8 @@ sc_tests_overriding_macros_on_cmdline \ sc_tests_plain_sleep \ sc_tests_plain_egrep_fgrep \ sc_tests_PATH_SEPARATOR \ +sc_tests_cat_log_file \ +sc_tests_make_check_verbose \ sc_tests_logs_duplicate_prefixes \ sc_tests_makefile_variable_order \ sc_mkdir_p \ @@ -1290,6 +1292,20 @@ sc_tests_plain_egrep_fgrep: exit 1; \ fi +sc_tests_cat_log_file: + @if grep '\<cat [^<>]*\.log\>' tests/*.test; then \ + echo "Don't use \`cat' directly on generated log files." >&2; \ + echo "Use the \`dump_log_files' function instead, if possible." >&2; \ + exit 1; \ + fi +sc_tests_make_check_verbose: + @v='\bVERBOSE=' m='\$$MAKE.*check'; \ + if grep -E "$$m.*$$v|$$v.*$$m" tests/*.test; then \ + echo "Don't use \`VERBOSE=yes \$$MAKE check' and similar in test scripts." >&2; \ + echo "It can cause spurious errors in the testsuite summary." >&2; \ + exit 1; \ + fi + sc_ensure_testsuite_has_run: @if test ! -f tests/test-suite.log; then \ echo "Run \`env keep_testdirs=yes make check' before \`maintainer-check'" >&2; \ diff --git a/tests/check-exported-srcdir.test b/tests/check-exported-srcdir.test index 6d17320..76dd9b2 100755 --- a/tests/check-exported-srcdir.test +++ b/tests/check-exported-srcdir.test @@ -20,16 +20,6 @@ . ./defs || Exit 1 -show_info () -{ - if test x"$parallel_tests" = x"yes"; then - cat foo.log - cat test-suite.log - else - : - fi -} - mkdir SrcDir mv [!S]* SrcDir mkdir BuildDir @@ -57,7 +47,8 @@ $AUTOMAKE -a cd ../BuildDir ../SrcDir/configure -$MAKE check || { show_info; Exit 1; } -show_info +st=0 +$MAKE check || st=$? +dump_log_files foo.log test-suite.log -: +Exit $st diff --git a/tests/check12.test b/tests/check12.test index 4be4b80..6d1db92 100755 --- a/tests/check12.test +++ b/tests/check12.test @@ -135,7 +135,7 @@ for vpath in : false; do test -f spanner.sum # This checks will be run only by the autogenerated `check12-p.test'. if test x"$parallel_tests" = x"yes"; then - cat test-suite.log + dump_log_files test-suite.log grep '^PASS: a\.test (exit: 0)' a.log grep '^PASS: b\.test (exit: 0)' b.log else @@ -169,7 +169,7 @@ for vpath in : false; do B_EXIT_STATUS=1 $MAKE check && Exit 1 # This checks will be run only by the autogenerated `check12-p.test'. if test x"$parallel_tests" = x"yes"; then - cat test-suite.log + dump_log_files test-suite.log grep '^PASS: a\.test (exit: 0)' a.log grep '^FAIL: b\.test (exit: 1)' b.log grep '^FAIL: b\.test (exit: 1)' test-suite.log @@ -188,7 +188,7 @@ for vpath in : false; do grep 'FAIL:' spanner.sum && Exit 1 # This checks will be run only by the autogenerated `check12-p.test'. if test x"$parallel_tests" = x"yes"; then - cat test-suite.log + dump_log_files test-suite.log grep '^PASS: a\.test (exit: 0)' a.log grep '^FAIL: b\.test (exit: 23)' b.log grep '^FAIL: b\.test (exit: 23)' test-suite.log diff --git a/tests/defs b/tests/defs index fb0b535..53ac142 100644 --- a/tests/defs +++ b/tests/defs @@ -203,6 +203,25 @@ using_gmake () esac } +# dump_log_file LOG-FILE [LOG-FILES..] +# ------------------------------------ +# Display a (series of) `.log' files created by the Automake test +# driver(s), mangling them to prevent the Automake's own testsuite harness +# from picking up spurious test results from their content. The arguments +# can also refer to non-existing files if the '$parallel_tests' variable +# is != "yes" (they will just be skipped in this case); otherwise, any +# non-existing file will cause the test script to fail. +dump_log_files () +{ + for f in ${1+"$@"}; do + if test -f "$f"; then + sed 's/^/ | /' <"$f" + else + case $parallel_tests in yes) Exit 1;; *) continue;; esac + fi + done +} + commented_sed_unindent_prog=' /^$/b # Nothing to do for empty lines. x # Get x<indent> into pattern space. diff --git a/tests/parallel-tests-am_tests_environment.test b/tests/parallel-tests-am_tests_environment.test index 072e614..c3d4013 100755 --- a/tests/parallel-tests-am_tests_environment.test +++ b/tests/parallel-tests-am_tests_environment.test @@ -50,8 +50,9 @@ END minicheck () { - cat foo.log - cat bar.log + test -f foo.log + test -f bar.log + dump_log_files foo.log bar.log test -d quux.dir } @@ -69,10 +70,12 @@ $AUTOMAKE -a FOO=1; export FOO -TESTS_ENVIRONMENT='BAR=1' $MAKE check || { cat test-suite.log; Exit 1; } +TESTS_ENVIRONMENT='BAR=1' $MAKE check \ + || { dump_log_files test-suite.log; Exit 1; } minicheck miniclean -TESTS_ENVIRONMENT='BAR=2' $MAKE check && { cat test-suite.log; Exit 1; } +TESTS_ENVIRONMENT='BAR=2' $MAKE check \ + && { dump_log_files test-suite.log; Exit 1; } minicheck miniclean diff --git a/tests/parallel-tests-empty-testlogs.test b/tests/parallel-tests-empty-testlogs.test index 593dce3..a0645bd 100755 --- a/tests/parallel-tests-empty-testlogs.test +++ b/tests/parallel-tests-empty-testlogs.test @@ -69,16 +69,16 @@ for vpath in : false; do fi $srcdir/configure cd sub1 - VERBOSE=yes $MAKE check + $MAKE check no_test_has_run cd ../sub2 - VERBOSE=yes TESTS='' $MAKE -e check + TESTS='' $MAKE -e check no_test_has_run - VERBOSE=yes TEST_LOGS='' $MAKE -e check + TEST_LOGS='' $MAKE -e check no_test_has_run cd .. $MAKE check - cat sub2/foo.log + dump_log_files sub2/foo.log $MAKE distclean cd $srcdir done diff --git a/tests/parallel-tests-interrupt.test b/tests/parallel-tests-interrupt.test index 1c5d9ce..48475d6 100755 --- a/tests/parallel-tests-interrupt.test +++ b/tests/parallel-tests-interrupt.test @@ -47,7 +47,9 @@ cat > foo.test << 'END' exec 2>&9 echo "foo is starting to run" ls -l >&2 -cat foo.log-t >&2 || : > fail +# See comments in tests/defs:dump_log_file() for why we can't use +# plain 'cat' here. +sed 's/^/ | /' foo.log-t >&2 || : > fail grep '^foo is starting to run$' foo.log-t >&2 || : > fail cat pid >&2 || : > fail kill -$signum `cat pid` || : > fail @@ -70,12 +72,15 @@ for signum in $trapped_signals; do ls -l # These files shouldn't exist, but in case they do, their content might # provide helpful information about the causes of the failure(s). - cat foo.log-t || : - cat foo.log || : - cat test-suite.log || : + st=0 + for f in foo.log-t foo.log test-suite.log; do + if test -f $f; then + dump_log_files $f + st=1 + fi + done + test $st -eq 0 || Exit 1 test -f fail && Exit 1 - test -f foo.log-t && Exit 1 - test -f foo.log && Exit 1 done : diff --git a/tests/parallel-tests-reset-term.test b/tests/parallel-tests-reset-term.test index 3a222c0..ab57fb8 100755 --- a/tests/parallel-tests-reset-term.test +++ b/tests/parallel-tests-reset-term.test @@ -56,8 +56,7 @@ mkcheck () rc=1 fi cat stdout - cat foobar.log - cat test-suite.log + dump_log_files foobar.log test-suite.log return $rc } diff --git a/tests/parallel-tests.test b/tests/parallel-tests.test index da961e1..1198b90 100755 --- a/tests/parallel-tests.test +++ b/tests/parallel-tests.test @@ -138,8 +138,13 @@ grep baz.test stdout && Exit 1 grep '2.*tests.*failed' stdout # Test VERBOSE. -env VERBOSE=yes $MAKE -e check > stdout && { cat stdout; Exit 1; } -cat stdout +# FIXME: the useless quoting below is to please maintainer-check. +env VERBOSE'='yes $MAKE -e check > stdout && { cat stdout; Exit 1; } +# With VERBOSE set to "yes", the standard output from make is expected +# to contain the content of test-suite.log, so we need the following +# in order not to confuse the Automake testsuite summary with spurious +# results (as would be the case with a simpler "cat stdout"). +dump_log_files stdout grep 'this is.*bar.test' stdout grep 'this is.*baz.test' stdout diff --git a/tests/test-driver-custom-multitest-recheck.test b/tests/test-driver-custom-multitest-recheck.test index e0f010f..704dd3f 100755 --- a/tests/test-driver-custom-multitest-recheck.test +++ b/tests/test-driver-custom-multitest-recheck.test @@ -120,7 +120,7 @@ for vpath in : false; do : A "make recheck" in a clean tree should run no tests. do_recheck --pass - cat test-suite.log + dump_log_files test-suite.log test ! -r a.run test ! -r a.log test ! -r b.run diff --git a/tests/test-driver-custom-multitest.test b/tests/test-driver-custom-multitest.test index a1c1010..4e5b196 100755 --- a/tests/test-driver-custom-multitest.test +++ b/tests/test-driver-custom-multitest.test @@ -125,21 +125,24 @@ for vpath in : false; do $srcdir/configure - $MAKE check >stdout && { cat stdout; cat test-suite.log; Exit 1; } + st=0 + $MAKE check >stdout || st=1 cat stdout - cat test-suite.log + dump_log_files test-suite.log + test $st -eq 1 || Exit 1 + # Couple of sanity checks. These might need to be updated if the # `trivial-test-driver' script is changed. $FGREP INVALID.NAME stdout test-suite.log && Exit 1 test -f BAD.LOG && Exit 1 # These log files must all have been created by the testsuite. - cat pass.log - cat fail.log - cat fail2.log - cat pass-fail.log - cat pass4-skip.log - cat pass3-skip2-xfail.log - cat pass-xpass-fail-xfail-skip.log + dump_log_files pass.log + dump_log_files fail.log + dump_log_files fail2.log + dump_log_files pass-fail.log + dump_log_files pass4-skip.log + dump_log_files pass3-skip2-xfail.log + dump_log_files pass-xpass-fail-xfail-skip.log # For debugging. $EGREP '(PASS|FAIL|XPASS|XFAIL|SKIP)' stdout @@ -173,10 +176,12 @@ for vpath in : false; do grep '%% pass-xpass-fail-xfail-skip %%' test-suite.log test `grep -c '%% ' test-suite.log` -eq 4 - TESTS='pass.t pass3-skip2-xfail.t' $MAKE -e check >stdout \ - || { cat stdout; cat test-suite.log; Exit 1; } - cat test-suite.log + st=0 + TESTS='pass.t pass3-skip2-xfail.t' $MAKE -e check >stdout || st=1 cat stdout + dump_log_files test-suite.log + test $st -eq 0 || Exit 1 + # For debugging. $EGREP '(PASS|FAIL|XPASS|XFAIL|SKIP)' stdout test `grep -c '^PASS:' stdout` -eq 4 diff --git a/tests/test-driver-custom-no-html.test b/tests/test-driver-custom-no-html.test index 9aceae6..1785717 100755 --- a/tests/test-driver-custom-no-html.test +++ b/tests/test-driver-custom-no-html.test @@ -54,9 +54,8 @@ $AUTOCONF $AUTOMAKE ./configure -VERBOSE=yes $MAKE check -cat foo.log -cat test-suite.log +$MAKE check || { dump_log_files foo.log test-suite.log; Exit 1; } +dump_log_files foo.log test-suite.log $FGREP 'dummy title' test-suite.log # Sanity check: trying to produce HTML output should fail. diff --git a/tests/test-driver-custom-xfail-tests.test b/tests/test-driver-custom-xfail-tests.test index 4f8bb83..337e061 100755 --- a/tests/test-driver-custom-xfail-tests.test +++ b/tests/test-driver-custom-xfail-tests.test @@ -141,7 +141,7 @@ $AUTOMAKE ./configure -VERBOSE=yes $MAKE check +$MAKE check || { dump_log_files *.log */*.log; Exit 1; } test -f test-suite.log test -f sub1/test-suite.log test -f sub2/test-suite.log @@ -150,8 +150,8 @@ for dir in sub1 sub2; do cd $dir cp pass.test x1.test cp x2.test pass.test - $MAKE check && { cat test-suite.log; Exit 1; } - cat test-suite.log + $MAKE check && { dump_log_files test-suite.log; Exit 1; } + dump_log_files test-suite.log grep '^FAIL: pass\.test$' test-suite.log grep '^XPASS: x1\.test$' test-suite.log test `grep -c '^FAIL' test-suite.log` -eq 1 diff --git a/tests/test-driver-custom.test b/tests/test-driver-custom.test index b6a33d2..e284ae6 100755 --- a/tests/test-driver-custom.test +++ b/tests/test-driver-custom.test @@ -119,8 +119,12 @@ $AUTOMAKE ./configure $MAKE -VERBOSE=yes $MAKE check + +st=0 +$MAKE check || st=1 ls -l . sub +dump_log_files test-suite.log +test $st -eq 0 || Exit 1 test ! -r BAD.log @@ -133,7 +137,7 @@ echo 'noext-wrapper sub/test am _' > sub/test.exp st=0 for x in 1 2 3 4.c 5.suf sub/test; do - cat $x.log + dump_log_files $x.log diff $x.exp $x.log || st=1 done diff --git a/tests/tests-environment-and-log-compiler.test b/tests/tests-environment-and-log-compiler.test index 3753bb9..8313c33 100755 --- a/tests/tests-environment-and-log-compiler.test +++ b/tests/tests-environment-and-log-compiler.test @@ -66,10 +66,9 @@ $AUTOMAKE -a ./configure $MAKE -n check # For debugging. -VERBOSE=yes $MAKE check -cat a.log -cat b.log +$MAKE check +dump_log_files a.log b.log -VERBOSE=yes $MAKE distcheck +$MAKE distcheck : diff --git a/tests/tests-environment-fd-redirect.test b/tests/tests-environment-fd-redirect.test index b2b5ab4..4f6e3fa 100755 --- a/tests/tests-environment-fd-redirect.test +++ b/tests/tests-environment-fd-redirect.test @@ -80,8 +80,10 @@ for sh in "$SHELL" "$bin_ksh"; do END $AUTOMAKE -a CONFIG_SHELL="$sh" $sh ./configure CONFIG_SHELL="$sh" - VERBOSE=y $MAKE check >stdout || { cat stdout; Exit 1; } + st=0 + $MAKE check >stdout || st=1 cat stdout + dump_log_files test-suite.log foo.log bar.log grep '[ /]foo\.test: foofoofoo$' stdout grep '[ /]foo\.test: barbarbar$' stdout grep '[ /]bar\.test: 8888$' stdout -- 1.7.2.3