]> git.ipfire.org Git - thirdparty/automake.git/commitdiff
tap: new `--stderr-prefix' option to prefix test script's stderr
authorRichard Hansen <rhansen@rhansen.org>
Mon, 3 Feb 2025 23:26:57 +0000 (18:26 -0500)
committerKarl Berry <karl@freefriends.org>
Sun, 23 Feb 2025 01:36:59 +0000 (17:36 -0800)
* lib/tap-driver.sh: Add a new `--stderr-prefix' option to instruct
the TAP driver to prefix each line of the test script's standard error
with the given string.  This is useful when `--merge' is enabled and
standard error lines might be confused with test results.
* doc/automake.texi: Document the new `--stderr-prefix' option.
* t/tap-stderr-prefix.tap: New test.
* t/list-of-tests.mk (handwritten_TESTS): Add it.

doc/automake.texi
lib/tap-driver.sh
t/list-of-tests.mk
t/tap-stderr-prefix.tap [new file with mode: 0644]

index 03d99856c216652886b9f8e77e6d25545f1e1420..9fa94689fd7018c4978411ec7b1932bd1695a77f 100644 (file)
@@ -10524,9 +10524,65 @@ relative to test results; this can be of great help in debugging
 (especially if your test scripts are shell scripts run with shell
 tracing active).  As a downside, this option might cause the test
 harness to get confused if anything that appears on standard error
-looks like a test result.
+looks like a test result.  Use @option{--stderr-prefix} to prefix each
+line of standard error to avoid this problem.
 @item --no-merge
 Revert the effects of @option{--merge}.
+@item --stderr-prefix @var{STRING}
+Prefix each line of the test script's standard error with
+@code{@var{STRING}}.  Defaults to the empty string.  This option makes
+it possible to avoid parsing ambiguity when @option{--merge} is in use,
+but it can also be used without @option{--merge} to make it easier to
+read test log files.  When used with @option{--merge}, users will
+typically want to start @code{@var{STRING}} with @samp{#}, which starts
+a TAP comment.  The @samp{#} character is difficult to portably include
+in a @command{make} variable, so the following quadrigraph
+substitutions, copied from Autoconf (@pxref{Quadrigraphs, , , autoconf,
+The Autoconf Manual}), are performed on @code{@var{STRING}}:
+
+@table @samp
+@item @@%:@@
+Replaced with @samp{#}.
+@item @@&t@@
+Replaced with the empty string.  This makes it possible to include the
+literal characters @samp{@@%:@@} in the prefix (@samp{@@%@@&t@@:@@}, for
+example).
+@end table
+
+For example, in shell, @samp{--stderr-prefix "@@%:@@[stderr] "} will
+prefix each line of the test script's standard error with
+@samp{#[stderr] }.
+
+When prefixing standard error lines, the test program's standard error
+lines can be processed out of order relative to the test program's
+standard output lines, even when @option{--merge} is used.  This can be
+due to many factors, including:
+
+@itemize @bullet
+@item
+Output buffering in the test program: The test program might be
+accumulating output data and writing it to the operating system in
+batches, not as soon as it is available.  You can try
+@uref{man:setvbuf(3),,setvbuf(3)} to change the buffering mode in the
+test program, or you can add regular flushes.  OS-specific utilities to
+control buffering may be available, such as
+@uref{man:stdbuf(1),,stdbuf(1)} on GNU/Linux systems.
+
+@item
+Concurrent processing of standard output and standard error: Due to a
+limitation of the shell command language, the TAP driver processes
+standard output in a different thread or process than standard error.
+Thus, processing order is influenced by how the operating system
+schedules the two threads or processes for execution.
+
+@item
+Line-based processing: When prefixing standard error, the TAP driver
+waits until a complete line is read from the test program before
+processing the line.  This reduces the chances that characters from a
+standard output line are mixed with characters from a standard error
+line.
+@end itemize
+
 @item --diagnostic-string @var{STRING}
 Change the string that introduces TAP diagnostics from the default value
 of ``@code{#}'' to @code{@var{STRING}}.  This can be useful if your
@@ -10614,6 +10670,58 @@ PASS: baz.test 1
 ...
 % @kbd{echo exit status: $?}
 exit status: 0
+
+% @kbd{cat stderr-demo.test}
+#!/bin/sh
+echo 'ok 1'
+# These sleeps help highlight the reordering of standard output and
+# standard error lines that can happen if --merge is not used.
+sleep 1
+# Note that this is a diagnostic message written to standard error, so
+# it should not affect the tests.  However, it will break the tests if
+# --merge is used without --stderr-prefix because "Bail out!" will be
+# interpreted as a TAP directive.
+echo 'Bail out! (this should not actually bail out)' >&2
+sleep 1
+echo 'ok 2'
+echo '1..2'
+
+% @kbd{make check TESTS=stderr-demo.test}
+...
+PASS: stderr-demo.test 1
+PASS: stderr-demo.test 2
+...
+
+% @kbd{cat stderr-demo.log}
+Bail out! (this should not actually bail out)
+ok 1
+PASS: stderr-demo.test 1
+ok 2
+PASS: stderr-demo.test 2
+1..2
+
+% @kbd{make check TESTS=stderr-demo.test \
+      TEST_LOG_DRIVER_FLAGS='--merge'}
+...
+PASS: stderr-demo.test 1
+ERROR: stderr-demo.test - Bail out! (this should not actually bail out)
+...
+
+% @kbd{make check TESTS=stderr-demo.test \
+      TEST_LOG_DRIVER_FLAGS='--merge --stderr-prefix "@@%:@@[stderr] "'}
+...
+PASS: stderr-demo.test 1
+PASS: stderr-demo.test 2
+...
+
+% @kbd{cat stderr-demo.log}
+ok 1
+PASS: stderr-demo.test 1
+#[stderr] Bail out! (this should not actually bail out)
+ok 2
+PASS: stderr-demo.test 2
+1..2
+
 @end example
 
 @node Incompatibility with other TAP parsers and drivers
index 2e30ec3b1a2afff9e576fc2cdd0d68d575ae0c8f..d36ff7a00e087c1b275b298d5031cc5d6048e2e8 100755 (executable)
@@ -23,7 +23,7 @@
 # bugs to <bug-automake@gnu.org> or send patches to
 # <automake-patches@gnu.org>.
 
-scriptversion=2025-02-03.02; # UTC
+scriptversion=2025-02-03.03; # UTC
 
 # Make unconditional expansion of undefined variables an error.  This
 # helps a lot in preventing typo-related bugs.
@@ -52,7 +52,8 @@ Usage:
                 [--expect-failure {yes|no}] [--color-tests {yes|no}]
                 [--enable-hard-errors {yes|no}] [--ignore-exit]
                 [--diagnostic-string STRING] [--merge|--no-merge]
-                [--comments|--no-comments] [--] TEST-COMMAND
+                [--stderr-prefix STRING] [--comments|--no-comments]
+                [--] TEST-COMMAND
 The '--test-name', '-log-file' and '--trs-file' options are mandatory.
 
 Report bugs to <bug-automake@gnu.org>.
@@ -69,6 +70,7 @@ trs_file=  # Where to save the metadata of the test run.
 expect_failure=0
 color_tests=0
 merge=0
+stderr_prefix=
 ignore_exit=0
 comments=0
 diag_string='#'
@@ -84,6 +86,7 @@ while test $# -gt 0; do
   --enable-hard-errors) shift;; # No-op.
   --merge) merge=1;;
   --no-merge) merge=0;;
+  --stderr-prefix) stderr_prefix=$2; shift;;
   --ignore-exit) ignore_exit=1;;
   --comments) comments=1;;
   --no-comments) comments=0;;
@@ -94,6 +97,44 @@ while test $# -gt 0; do
   shift
 done
 
+# Quadrigraph substitutions for `--stderr-prefix'.  Note that the empty
+# substitution MUST be done last, otherwise `@%@&t@:@' will become `#', not
+# `@%:@'.
+for q_r in '@%:@ #' '@&t@ '; do
+  q=${q_r%% *} # quadrigraph
+  r=${q_r#* } # replacement
+  while true; do
+    case $stderr_prefix in
+    *"$q"*) stderr_prefix=${stderr_prefix%%"$q"*}$r${stderr_prefix#*"$q"};;
+    *) break;;
+    esac
+  done
+done
+
+# Prefixes each line of its stdin with the first argument and writes the result
+# to stdout.  If the final line of stdin is non-empty and does not end with a
+# terminating newline, a newline is added.
+prefix_lines() {
+  # Implementation note: This function is used to prefix the test script's
+  # stderr lines.  Preserving the order of the test script's stdout and stderr
+  # lines is important for debugging, so this function is sensitive to input and
+  # output buffering.  A shell loop is used to prefix the lines instead of
+  # `$AM_TAP_AWK' (which would probably be more efficient) because `mawk'
+  # aggressively buffers its input (except with the `-Winteractive' command-line
+  # option), which would defeat the purpose of the `--merge' option.  `sed' or
+  # `perl' could be used instead of a shell loop, but those would add a
+  # dependency to this script.
+
+  # <https://stackoverflow.com/a/6399568> explains `IFS='.  The `||' check
+  # ensures that stdin's final line is written to stdout even if it is missing a
+  # terminating newline.
+  while IFS= read -r line || test -n "$line"; do
+    # `printf' is preferred over `echo' because `echo' might process backslash
+    # escapes or behave unexpectedly if its argument looks like an option.
+    printf %s\\n "$1$line"
+  done
+}
+
 test $# -gt 0 || usage_error "missing test command"
 
 case $expect_failure in
@@ -139,18 +180,61 @@ fi
     # <https://lists.gnu.org/archive/html/bug-autoconf/2011-09/msg00004.html>
     # <http://mail.opensolaris.org/pipermail/ksh93-integration-discuss/2009-February/004121.html>
     trap : 1 3 2 13 15
+    # Duplicate the stdout fd (which connects to awk's stdin) to fd 4 so that we
+    # can reuse fd 1 for pipelines and command substitutions below.
+    exec 4>&1
     # Determine where to send the test script's stderr.  Only the test's stderr
     # should go here; if `exec 2>&$stderr_fd' were run, this script's stderr
     # (e.g., `set -x' output, if turned on to help with debugging) would mix
     # with the test script's stderr and go to the log (via `awk', if `--merge'
     # is enabled), not the terminal.
     if test $merge -gt 0; then
-      stderr_fd=1  # send stderr to awk, which will copy it to the log
+      stderr_fd=4  # send stderr to awk, which will copy it to the log
     else
       stderr_fd=3  # send stderr directly to the log file
     fi
-    "$@" 2>&$stderr_fd 3>&-
-    echo $?
+    if test -n "$stderr_prefix"; then
+      # Set to the test script's numeric exit status.
+      status=$(
+        exec 5>&1
+        {
+          {
+            "$@" 5>&-
+            # Capturing the status in a variable then writing the variable value
+            # to awk below may seem like unnecessary steps: Why not just write
+            # the status directly to awk here?  This avoids a race condition:
+            # The awk script below *requires* the final line of its input to be
+            # the test program's exit status.  Writing to fd 4 here would not
+            # provide that guarantee because this `echo' is running concurrently
+            # with `prefix_lines', which is writing to fd 4 if `--merge' is
+            # enabled.  Thus, a prefixed and merged stderr line could be written
+            # to fd 4 /after/ this status is written, which would break the awk
+            # script if the status was written directly to awk here.
+            printf %s\\n "$?" 1>&5
+          } |
+          # Each line of the test program's stdout is read then written
+          # unchanged to stdout.  This is an attempt to subvert buffering so
+          # that stderr and stdout lines are processed in approximately the same
+          # order as written by the test program.  (A less racy approach would
+          # be to use a select or poll loop over both stderr and stdout, but
+          # there is no portable (POSIX) way to do that from a shell script.)
+          #
+          # This also adds a terminating newline to the test program's final
+          # stdout line if missing.
+          while IFS= read -r line || test -n "$line"; do
+            printf %s\\n "$line"
+          done
+        } 2>&1 1>&4 3>&- 4>&- | prefix_lines "$stderr_prefix" 1>&$stderr_fd
+      )
+    else
+      # Avoid using `prefix_lines' for stderr if `$stderr_prefix' is the empty
+      # string.  This ensures that the test program's stderr and stdout are sent
+      # to awk in the order they were written by the test program.  (Only
+      # relevant if `--merge' is enabled.)
+      "$@" 2>&$stderr_fd 3>&- 4>&-
+      status=$?
+    fi
+    printf %s\\n "$status"
   ) | LC_ALL=C ${AM_TAP_AWK-awk} \
         -v me="$me" \
         -v test_script_name="$test_name" \
index afa63782281f2ce3569b92ef6e57daaaac9be5e3..6099d49a4c195d42aeee872e8de144b3aa8986b3 100644 (file)
@@ -1187,6 +1187,7 @@ t/tap-planskip-whitespace.sh \
 t/tap-planskip-badexit.sh \
 t/tap-planskip-bailout.sh \
 t/tap-planskip-later-errors.sh \
+t/tap-stderr-prefix.tap \
 t/tap-test-number-0.sh \
 t/tap-recheck-logs.sh \
 t/tap-result-comment.sh \
diff --git a/t/tap-stderr-prefix.tap b/t/tap-stderr-prefix.tap
new file mode 100644 (file)
index 0000000..7189889
--- /dev/null
@@ -0,0 +1,129 @@
+#! /bin/sh
+# Copyright (C) 2025 Free Software Foundation, Inc.
+#
+# This program is free software; you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation; either version 2, or (at your option)
+# any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program.  If not, see <https://www.gnu.org/licenses/>.
+
+# TAP support:
+#  - The Automake TAP driver has an option that instructs it to prefix the
+#    test script's stderr with a given string.
+
+. test-init.sh
+plan_ later
+
+dumpf() (
+    set +x
+    diag_string_='#' diag_ "####### Contents of $1:"
+    diag_ <$1
+    diag_string_='#' diag_ "#######"
+)
+
+cat >Makefile.am <<END || bailout_ "failed to create Makefile.am"
+TESTS = all.test
+END
+dumpf Makefile.am
+
+. tap-setup.sh
+
+# Tests without --stderr-prefix.  Historically, the TAP driver has not added
+# a final newline to either stdout or stderr if the test program did not write
+# one itself, so that is not tested here.
+
+cat >all.test <<END || bailout_ "failed to create all.test"
+#!/bin/sh
+echo 1..2
+echo ok 1
+echo 'Bail out!' >&2
+echo ok 2
+END
+chmod a+x all.test || bailout_ "failed to make all.test executable"
+
+# Test without --stderr-prefix, without --merge.
+command_ok_ "no merge, no prefix: make check passes" -- \
+    run_make -O AM_TEST_LOG_DRIVER_FLAGS= check
+dumpf all.log
+command_ok_ "no merge, no prefix: result counts are correct" -- \
+    count_test_results total=2 pass=2 fail=0 xpass=0 xfail=0 skip=0 error=0
+command_ok_ "no merge, no prefix: stderr in log" -- \
+    grep -q '^Bail out!$' all.log
+
+# Test without --stderr-prefix, with --merge.
+command_ok_ "--merge: make check fails" -- \
+    run_make -e FAIL AM_TEST_LOG_DRIVER_FLAGS=--merge check
+dumpf all.log
+# Don't bother checking the counts -- they're meaningless due to the merged
+# stderr "corrupting" the TAP output.  It is sufficient to just test that
+# `make check' returned non-zero.
+command_ok_ "--merge: stderr in log" -- \
+    grep -q '^Bail out!$' all.log
+
+
+# Tests with --stderr-prefix.  If the final stderr line does not have a
+# terminating newline, the TAP driver should still print the line with the
+# prefix; a newline is also added to avoid "corrupting" the final prefixed
+# stderr line with a subsequent stdout line in the log.
+
+cat >all.test <<END || bailout_ "failed to create all.test"
+#!/bin/sh
+echo 1..2
+echo ok 1
+echo 'Bail out!' >&2
+echo ok 2
+printf %s 'final stderr line without newline terminator' >&2
+echo "# This comment is written to stdout after the newline-less stderr line"
+echo "# to ensure that a stdout line written after the final stderr line does"
+echo "# not get written to the same line in the log as the final stderr line."
+END
+chmod a+x all.test || bailout_ "failed to make all.test executable"
+
+# Included in the prefix:
+#   1. quadrigraph for # (@%:@)
+#   2. literal # (difficult to include in a Makefile variable, but easy to
+#      pass in a command-line make variable assignment)
+#   3. a string that expands to @%:@ (quadrigraph for #) after quadrigraph
+#      replacement, accomplished by embedding a quadrigraph for the empty
+#      string inside the quadrigraph for #
+# The end result should be: ##@%:@
+PFXFLAG='--stderr-prefix "@%:@#@%@&t@:@ "'
+
+# Test with --stderr-prefix, without --merge.
+command_ok_ "$PFXFLAG: make check passes" -- \
+    run_make -O AM_TEST_LOG_DRIVER_FLAGS="$PFXFLAG" check
+dumpf all.log
+command_ok_ "$PFXFLAG: result counts are correct" -- \
+    count_test_results total=2 pass=2 fail=0 xpass=0 xfail=0 skip=0 error=0
+command_ok_ "$PFXFLAG: prefixed stderr in log" -- \
+    grep -q '^##@%:@ Bail out!$' all.log
+command_ok_ "$PFXFLAG: missing final newline is added" -- \
+    grep -q '^##@%:@ final stderr line without newline terminator$' all.log
+
+# Test with --stderr-prefix, with --merge.
+command_ok_ "$PFXFLAG --merge: make check passes" -- \
+    run_make -O AM_TEST_LOG_DRIVER_FLAGS="$PFXFLAG --merge" check
+dumpf all.log
+command_ok_ "$PFXFLAG --merge: result counts are correct" -- \
+    count_test_results total=2 pass=2 fail=0 xpass=0 xfail=0 skip=0 error=0
+command_ok_ "$PFXFLAG --merge: prefixed stderr in log" -- \
+    grep -q '^##@%:@ Bail out!$' all.log
+# Note: When --stderr-prefix is enabled, the TAP driver intentionally waits to
+# read a complete line before writing it to the log.  This reduces the chances
+# of mixing stderr and stdout in a single log line.  If you look at the log
+# for this test, the final stderr line appears last despite being written by
+# the test program before the stderr comment lines.  This is because the TAP
+# driver patiently waited for a newline that never came.
+command_ok_ "$PFXFLAG --merge: missing final newline is added" -- \
+    grep -q '^##@%:@ final stderr line without newline terminator$' all.log
+
+plan_ now
+
+: