test-lib: silence "-x" cleanup under bash
authorJeff King <peff@peff.net>
Fri, 8 Dec 2017 10:47:08 +0000 (05:47 -0500)
committerJunio C Hamano <gitster@pobox.com>
Fri, 8 Dec 2017 17:03:38 +0000 (09:03 -0800)
When the test suite's "-x" option is used with bash, we end
up seeing cleanup cruft in the output:

  $ bash t0001-init.sh -x
  [...]
  ++ diff -u expected actual
  + test_eval_ret_=0
  + want_trace
  + test t = t
  + test t = t
  + set +x
  ok 42 - re-init from a linked worktree

This ranges from mildly annoying (for a successful test) to
downright confusing (when we say "last command exited with
error", but it's really 5 commands back).

We normally are able to suppress this cleanup. As the
in-code comment explains, we can't convince the shell not to
print it, but we can redirect its stderr elsewhere.

But since d88785e424 (test-lib: set BASH_XTRACEFD
automatically, 2016-05-11), that doesn't hold for bash. It
sends the "set -x" output directly to descriptor 4, not to
stderr.

We can fix this by also redirecting descriptor 4, and
paying close attention to which commands redirected and
which are not (see the updated comment).

Two alternatives I considered and rejected:

  - unsetting and setting BASH_XTRACEFD; doing so closes the
    descriptor, which we must avoid

  - we could keep everything in a single block as before,
    redirect 4>/dev/null there, but retain 5>&4 as a copy.
    And then selectively restore 4>&5 for commands which
    should be allowed to trace. This would work, but the
    descriptor swapping seems unnecessarily confusing.

Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
t/test-lib.sh

index 116bd6a..7914453 100644 (file)
@@ -601,26 +601,40 @@ test_eval_inner_ () {
 }
 
 test_eval_ () {
-       # We run this block with stderr redirected to avoid extra cruft
-       # during a "-x" trace. Once in "set -x" mode, we cannot prevent
+       # If "-x" tracing is in effect, then we want to avoid polluting stderr
+       # with non-test commands. But once in "set -x" mode, we cannot prevent
        # the shell from printing the "set +x" to turn it off (nor the saving
        # of $? before that). But we can make sure that the output goes to
        # /dev/null.
        #
-       # The test itself is run with stderr put back to &4 (so either to
-       # /dev/null, or to the original stderr if --verbose was used).
+       # There are a few subtleties here:
+       #
+       #   - we have to redirect descriptor 4 in addition to 2, to cover
+       #     BASH_XTRACEFD
+       #
+       #   - the actual eval has to come before the redirection block (since
+       #     it needs to see descriptor 4 to set up its stderr)
+       #
+       #   - likewise, any error message we print must be outside the block to
+       #     access descriptor 4
+       #
+       #   - checking $? has to come immediately after the eval, but it must
+       #     be _inside_ the block to avoid polluting the "set -x" output
+       #
+
+       test_eval_inner_ "$@" </dev/null >&3 2>&4
        {
-               test_eval_inner_ "$@" </dev/null >&3 2>&4
                test_eval_ret_=$?
                if want_trace
                then
                        set +x
-                       if test "$test_eval_ret_" != 0
-                       then
-                               say_color error >&4 "error: last command exited with \$?=$test_eval_ret_"
-                       fi
                fi
-       } 2>/dev/null
+       } 2>/dev/null 4>&2
+
+       if test "$test_eval_ret_" != 0 && want_trace
+       then
+               say_color error >&4 "error: last command exited with \$?=$test_eval_ret_"
+       fi
        return $test_eval_ret_
 }