test-lib.sh: support -x option for shell-tracing

Usually running a test under "-v" makes it clear which
command is failing. However, sometimes it can be useful to
also see a complete trace of the shell commands being run in
the test. You can do so without any support from the test
suite by running "sh -x tXXXX-foo.sh". However, this
produces quite a large bit of output, as we see a trace of
the entire test suite.

This patch instead introduces a "-x" option to the test
scripts (i.e., "./tXXXX-foo.sh -x"). When enabled, this
turns on "set -x" only for the tests themselves. This can
still be a bit verbose, but should keep things to a more
manageable level. You can even use "--verbose-only" to see
the trace only for a specific test.

The implementation is a little invasive. We turn on the "set
-x" inside the "eval" of the test code. This lets the eval
itself avoid being reported in the trace (which would be
long, and redundant with the verbose listing we already
showed). And then after the eval runs, we do some trickery
with stderr to avoid showing the "set +x" to the user.

We also show traces for test_cleanup functions (since they
can impact the test outcome, too). However, we do avoid
running the noop ":" cleanup (the default if the test does
not use test_cleanup at all), as it creates unnecessary
noise in the "set -x" output.

Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>

diff --git a/t/README b/t/README
index 52c77ae936d9cb3ecc4ff42a2c4667fca4373577..9952261299e62c88d04954a2a8e738cd6a2adb30 100644 (file)
--- a/t/README
+++ b/t/README
@@ -82,6 +82,12 @@ appropriately before running "make".
        numbers matching <pattern>.  The number matched against is
        simply the running count of the test within the file.
 
        numbers matching <pattern>.  The number matched against is
        simply the running count of the test within the file.
 

+-x::
+       Turn on shell tracing (i.e., `set -x`) during the tests
+       themselves. Implies `--verbose`. Note that this can cause
+       failures in some tests which redirect and test the
+       output of shell functions. Use with caution.
+

 -d::
 --debug::
        This may help the person who is developing a new test.
 -d::
 --debug::
        This may help the person who is developing a new test.

diff --git a/t/test-lib.sh b/t/test-lib.sh
index 0f4a67bfc63a989883007911f889ba5aed1c0aac..cf19339ccebd0ee5f55822ebe11386101f358f41 100644 (file)
--- a/t/test-lib.sh
+++ b/t/test-lib.sh
@@ -233,6 +233,10 @@ do
        --root=*)
                root=$(expr "z$1" : 'z[^=]*=\(.*\)')
                shift ;;
        --root=*)
                root=$(expr "z$1" : 'z[^=]*=\(.*\)')
                shift ;;

+       -x)
+               trace=t
+               verbose=t
+               shift ;;

        *)
                echo "error: unknown test option '$1'" >&2; exit 1 ;;
        esac
        *)
                echo "error: unknown test option '$1'" >&2; exit 1 ;;
        esac


@@ -517,10 +521,39 @@ maybe_setup_valgrind () {
        fi
 }
 
        fi
 }
 

+# This is a separate function because some tests use
+# "return" to end a test_expect_success block early
+# (and we want to make sure we run any cleanup like
+# "set +x").
+test_eval_inner_ () {
+       # Do not add anything extra (including LF) after '$*'
+       eval "
+               test \"$trace\" = t && set -x
+               $*"
+}
+

 test_eval_ () {
 test_eval_ () {

-       # This is a separate function because some tests use
-       # "return" to end a test_expect_success block early.
-       eval </dev/null >&3 2>&4 "$*"
+       # We run this block with stderr redirected to avoid extra cruft
+       # during a "-x" trace. 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).
+       {
+               test_eval_inner_ "$@" </dev/null >&3 2>&4
+               test_eval_ret_=$?
+               if test "$trace" = t
+               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
+       return $test_eval_ret_

 }
 
 test_run_ () {
 }
 
 test_run_ () {


@@ -531,7 +564,8 @@ test_run_ () {
        eval_ret=$?
        teardown_malloc_check
 
        eval_ret=$?
        teardown_malloc_check
 

-       if test -z "$immediate" || test $eval_ret = 0 || test -n "$expecting_failure"
+       if test -z "$immediate" || test $eval_ret = 0 ||
+          test -n "$expecting_failure" && test "$test_cleanup" != ":"

        then
                setup_malloc_check
                test_eval_ "$test_cleanup"
        then
                setup_malloc_check
                test_eval_ "$test_cleanup"