From 925bdc928e3debdc6dbf28b5648711eb1c5583d3 Mon Sep 17 00:00:00 2001
From: Jeff King <peff@peff.net>
Date: Fri, 21 Oct 2016 06:42:10 -0400
Subject: [PATCH 1/4] test-lib: handle TEST_OUTPUT_DIRECTORY with spaces
We are careful in test_done to handle a results directory
with a space in it, but the "--tee" code path does not.
Doing:
export TEST_OUTPUT_DIRECTORY='/tmp/path with spaces'
./t000-init.sh --tee
results in errors. Let's consistently double-quote our path
variables so that this works.
Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
t/test-lib.sh | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/t/test-lib.sh b/t/test-lib.sh
index 39c70f0326..01bb58ef00 100644
--- a/t/test-lib.sh
+++ b/t/test-lib.sh
@@ -58,8 +58,8 @@ done,*)
mkdir -p "$TEST_OUTPUT_DIRECTORY/test-results"
BASE="$TEST_OUTPUT_DIRECTORY/test-results/$(basename "$0" .sh)"
(GIT_TEST_TEE_STARTED=done ${SHELL_PATH} "$0" "$@" 2>&1;
- echo $? > $BASE.exit) | tee $BASE.out
- test "$(cat $BASE.exit)" = 0
+ echo $? >"$BASE.exit") | tee "$BASE.out"
+ test "$(cat "$BASE.exit")" = 0
exit
;;
esac
From 452320f1f53a579f891eba678993508e7cbf3339 Mon Sep 17 00:00:00 2001
From: Jeff King <peff@peff.net>
Date: Fri, 21 Oct 2016 06:48:00 -0400
Subject: [PATCH 2/4] test-lib: add --verbose-log option
The "--verbose" option redirects output from arbitrary
test commands to stdout. This is useful for examining the
output manually, like:
./t5547-push-quarantine.sh -v | less
But it also means that the output is intermingled with the
TAP directives, which can confuse a TAP parser like "prove".
This has always been a potential problem, but became an
issue recently when one test happened to output the word
"ok" on a line by itself, which prove interprets as a test
success:
$ prove t5547-push-quarantine.sh :: -v
t5547-push-quarantine.sh .. 1/? To dest.git
* [new branch] HEAD -> master
To dest.git
! [remote rejected] reject -> reject (pre-receive hook declined)
error: failed to push some refs to 'dest.git'
fatal: git cat-file d08c8eba97f4e683ece08654c7c8d2ba0c03b129: bad file
t5547-push-quarantine.sh .. Failed -1/4 subtests
Test Summary Report
-------------------
t5547-push-quarantine.sh (Wstat: 0 Tests: 5 Failed: 0)
Parse errors: Tests out of sequence. Found (2) but expected (3)
Tests out of sequence. Found (3) but expected (4)
Tests out of sequence. Found (4) but expected (5)
Bad plan. You planned 4 tests but ran 5.
Files=1, Tests=5, 0 wallclock secs ( 0.01 usr + 0.01 sys = 0.02 CPU)
Result: FAIL
One answer is "if it hurts, don't do it", but that's not
quite the whole story. The Travis tests use "--verbose
--tee" so that they can get the benefit of prove's parallel
options, along with a verbose log in case there is a
failure. We just need the verbose output to go to the log,
but keep stdout clean.
Getting this right turns out to be surprisingly difficult.
Here's the progression of alternatives I considered:
1. Add an option to write verbose output to stderr. This is
hard to capture, though, because we want each test to
have its own log (because they're all run in parallel
and the jumbled output would be useless).
2. Add an option to write verbose output to a file in
test-results. This works, but the log is missing all of
the non-verbose output, which gives context.
3. Like (2), but teach say_color() to additionally output
to the log. This mostly works, but misses any output
that happens outside of the say() functions (which isn't
a lot, but is a potential maintenance headache).
4. Like (2), but make the log file the same as the "--tee"
file. That almost works, but now we have two processes
opening the same file. That gives us two separate
descriptors, each with their own idea of the current
position. They'll each start writing at offset 0, and
overwrite each other's data.
5. Like (4), but in each case open the file for appending.
That atomically positions each write at the end of the
file.
It's possible we may still get sheared writes between
the two processes, but this is already the case when
writing to stdout. It's not a problem in practice
because the test harness generally waits for snippets to
finish before writing the TAP output.
We can ignore buffering issues with tee, because POSIX
mandates that it does not buffer. Likewise, POSIX
specifies "tee -a", so it should be available
everywhere.
This patch implements option (5), which seems to work well
in practice.
Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
t/README | 6 ++++++
t/test-lib.sh | 22 +++++++++++++++++++---
2 files changed, 25 insertions(+), 3 deletions(-)
diff --git a/t/README b/t/README
index 76a0daa3ac..243332cf5e 100644
--- a/t/README
+++ b/t/README
@@ -153,6 +153,12 @@ appropriately before running "make".
As the names depend on the tests' file names, it is safe to
run the tests with this option in parallel.
+--verbose-log::
+ Write verbose output to the same logfile as `--tee`, but do
+ _not_ write it to stdout. Unlike `--tee --verbose`, this option
+ is safe to use when stdout is being consumed by a TAP parser
+ like `prove`. Implies `--tee` and `--verbose`.
+
--with-dashes::
By default tests are run without dashed forms of
commands (like git-commit) in the PATH (it only uses
diff --git a/t/test-lib.sh b/t/test-lib.sh
index 01bb58ef00..d685858afd 100644
--- a/t/test-lib.sh
+++ b/t/test-lib.sh
@@ -54,11 +54,21 @@ case "$GIT_TEST_TEE_STARTED, $* " in
done,*)
# do not redirect again
;;
-*' --tee '*|*' --va'*)
+*' --tee '*|*' --va'*|*' --verbose-log '*)
mkdir -p "$TEST_OUTPUT_DIRECTORY/test-results"
BASE="$TEST_OUTPUT_DIRECTORY/test-results/$(basename "$0" .sh)"
+
+ # Make this filename available to the sub-process in case it is using
+ # --verbose-log.
+ GIT_TEST_TEE_OUTPUT_FILE=$BASE.out
+ export GIT_TEST_TEE_OUTPUT_FILE
+
+ # Truncate before calling "tee -a" to get rid of the results
+ # from any previous runs.
+ >"$GIT_TEST_TEE_OUTPUT_FILE"
+
(GIT_TEST_TEE_STARTED=done ${SHELL_PATH} "$0" "$@" 2>&1;
- echo $? >"$BASE.exit") | tee "$BASE.out"
+ echo $? >"$BASE.exit") | tee -a "$GIT_TEST_TEE_OUTPUT_FILE"
test "$(cat "$BASE.exit")" = 0
exit
;;
@@ -242,6 +252,9 @@ do
trace=t
verbose=t
shift ;;
+ --verbose-log)
+ verbose_log=t
+ shift ;;
*)
echo "error: unknown test option '$1'" >&2; exit 1 ;;
esac
@@ -315,7 +328,10 @@ fi
exec 5>&1
exec 6<&0
-if test "$verbose" = "t"
+if test "$verbose_log" = "t"
+then
+ exec 3>>"$GIT_TEST_TEE_OUTPUT_FILE" 4>&3
+elif test "$verbose" = "t"
then
exec 4>&2 3>&1
else
From 041c72de109075d630f77bc2ad225f6339f33c9a Mon Sep 17 00:00:00 2001
From: Jeff King <peff@peff.net>
Date: Fri, 21 Oct 2016 06:48:12 -0400
Subject: [PATCH 3/4] travis: use --verbose-log test option
Because we run the tests via "prove", the output from
"--verbose" may interfere with our TAP output. Using
"--verbose-log" solves this while letting us retain our
on-disk log.
Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
.travis.yml | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/.travis.yml b/.travis.yml
index adab5b89bb..35f0fcb183 100644
--- a/.travis.yml
+++ b/.travis.yml
@@ -29,7 +29,7 @@ env:
- LINUX_GIT_LFS_VERSION="1.2.0"
- DEFAULT_TEST_TARGET=prove
- GIT_PROVE_OPTS="--timer --jobs 3 --state=failed,slow,save"
- - GIT_TEST_OPTS="--verbose --tee"
+ - GIT_TEST_OPTS="--verbose-log"
- GIT_TEST_CLONE_2GB=YesPlease
# t9810 occasionally fails on Travis CI OS X
# t9816 occasionally fails with "TAP out of sequence errors" on Travis CI OS X
From 614fe015212d057c0571885c42a29a995973107d Mon Sep 17 00:00:00 2001
From: Jeff King <peff@peff.net>
Date: Sat, 22 Oct 2016 00:45:06 -0400
Subject: [PATCH 4/4] test-lib: bail out when "-v" used under "prove"
When there is a TAP harness consuming the output of our test
scripts, the "--verbose" breaks the output by mingling
test command output with TAP. Because the TAP::Harness
module used by "prove" is fairly lenient, this _usually_
works, but it violates the spec, and things get very
confusing if the commands happen to output a line that looks
like TAP (e.g., the word "ok" on its own line).
Let's detect this situation and complain. Just calling
error() isn't great, though; prove will tell us that the
script failed, but the message doesn't make it through to
the user. Instead, we can use the special TAP signal "Bail
out!". This not only shows the message to the user, but
instructs the harness to stop running the tests entirely.
This is exactly what we want here, as the problem is in the
command-line options, and every test script would produce
the same error.
The result looks like this (the first "Bailout called" line
is in red if prove uses color on your terminal):
$ make GIT_TEST_OPTS='--verbose --tee'
rm -f -r 'test-results'
*** prove ***
Bailout called. Further testing stopped: verbose mode forbidden under TAP harness; try --verbose-log
FAILED--Further testing stopped: verbose mode forbidden under TAP harness; try --verbose-log
Makefile:39: recipe for target 'prove' failed
make: *** [prove] Error 255
Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
t/test-lib.sh | 10 ++++++++++
1 file changed, 10 insertions(+)
diff --git a/t/test-lib.sh b/t/test-lib.sh
index d685858afd..21ebe95139 100644
--- a/t/test-lib.sh
+++ b/t/test-lib.sh
@@ -317,6 +317,16 @@ say () {
say_color info "$*"
}
+if test -n "$HARNESS_ACTIVE"
+then
+ if test "$verbose" = t || test -n "$verbose_only"
+ then
+ printf 'Bail out! %s\n' \
+ 'verbose mode forbidden under TAP harness; try --verbose-log'
+ exit 1
+ fi
+fi
+
test "${test_description}" != "" ||
error "Test script did not set test_description."