The five new tests added to 't9300-fast-import.sh' in 30e215a65c
(fast-import: checkpoint: dump branches/tags/marks even if
object_count==0, 2017-09-28), all with the prefix "V:" in their test
description, run 'git fast-import' in the background and then 'kill'
it as part of a 'test_when_finished' cleanup command. When this test
script is executed with Bash, some or even all of these tests tend to
pollute the test script's stderr, and messages about terminated
processes end up on the terminal:
$ bash ./t9300-fast-import.sh
<... snip ...>
ok 179 - V: checkpoint helper does not get stuck with extra output
/<...>/test-lib-functions.sh: line 388: 28383 Terminated git fast-import $options 0<&8 1>&9
ok 180 - V: checkpoint updates refs after reset
./t9300-fast-import.sh: line 3210: 28401 Terminated git fast-import $options 0<&8 1>&9
ok 181 - V: checkpoint updates refs and marks after commit
ok 182 - V: checkpoint updates refs and marks after commit (no new objects)
./test-lib.sh: line 634: line 3250: 28485 Terminated git fast-import $options 0<&8 1>&9
ok 183 - V: checkpoint updates tags after tag
./t9300-fast-import.sh: line 3264: 28510 Terminated git fast-import $options 0<&8 1>&9
After a background child process terminates, its parent Bash process
always outputs a message like those above to stderr, even when in
non-interactive mode.
But how do some of these messages end up on the test script's stderr,
why don't we get them from all five tests, and why do they come from
different file/line locations? Well, after sending the TERM signal to
the background child process, it takes a little while until that
process receives the signal and terminates, and then it takes another
while until the parent process notices it. During this time the
parent Bash process is continuing execution, and by the time it
notices that its child terminated it might have already left
'test_eval_inner_' and its stderr is not redirected to /dev/null
anymore. That's why such a message can appear on the test script's
stderr, while other times, when the child terminates fast and/or the
parent shell is slow enough, the message ends up in /dev/null, just
like any other output of the test does. Bash always adds the file
name and line number of the code location it was about to execute when
it notices the termination of its child process as a prefix to that
message, hence the varying and sometimes totally unrelated location
prefixes in those messages (e.g. line 388 in 'test-lib-functions.sh'
is 'test_verify_prereq', and I saw such a message pointing to
'say_color' as well).
Prevent these messages from appearing on the test script's stderr by
'wait'-ing on the pid of the background 'git fast-import' process
after sending it the TERM signal. This ensures that the executing
shell's stderr is still redirected when the shell notices the
termination of its child process in the background, and that these
messages get a consistent file/line location prefix.
Note that this is not an issue when the test script is run with Bash
and '-v', because then these messages are supposed to go to the test
script's stderr anyway, and indeed all of them do; though the
sometimes seemingly random file/line prefixes could be confusing
still. Similarly, it's not an issue with Bash and '--verbose-log'
either, because then all messages go to the log file as they should.
Finally, it's not an issue with some other shells (I tried dash, ksh,
ksh93 and mksh) even without any of the verbose options, because they
don't print messages like these in non-interactive mode in the first
place.
Signed-off-by: SZEDER Gábor <szeder.dev@xxxxxxxxx>
---
t/t9300-fast-import.sh | 5 ++++-
1 file changed, 4 insertions(+), 1 deletion(-)
diff --git a/t/t9300-fast-import.sh b/t/t9300-fast-import.sh
index 9e7f96223d..fac33e524c 100755
--- a/t/t9300-fast-import.sh
+++ b/t/t9300-fast-import.sh
@@ -3147,7 +3147,10 @@ background_import_then_checkpoint () {
echo $! >V.pid
# We don't mind if fast-import has already died by the time the test
# ends.
- test_when_finished "exec 8>&-; exec 9>&-; kill $(cat V.pid) || true"
+ test_when_finished "
+ exec 8>&-; exec 9>&-;
+ kill $(cat V.pid) && wait $(cat V.pid)
+ true"
# Start in the background to ensure we adhere strictly to (blocking)
# pipes writing sequence. We want to assume that the write below could
--
2.18.0.408.g42635c01bc
