Re: [PATCH v2 2/6] t/test-lib: don't print shell traces to stdout

[Junio C Hamano <gitster@pobox.com>]

Patrick Steinhardt <ps@pks.im> writes:

> We have several flags like "--verbose", "--verbose-only" or "-x" that
> cause us to generate shell traces. The generated tracing output is split
> up in these cases so that the test's stdout is printed to file
> descriptor 3 whereas its stderr is printed to file descriptor 4.
> Depending on which options have been given, we then end up either:
>
>   - Redirecting both file descriptors to a file.
>
>   - Redirecting them to stdout and stderr, respectively.
>
>   - Closing them in case we're running in none-verbose mode.
>
> The second case causes problems though when passing output to a TAP
> parser. We print the test's stdout to the console's stdout, and that
> results in broken TAP output.
>
> Fix the issue by instead redirecting the test's stdout to the shell's
> stderr. This makes it impossible to discern stdout from stderr, but
> going by my own experience I never came across a usecase where I would
> have needed this distinction.

OK, so both stdout and stderr go to stderr, mixing everything into a
single stream.  Do we need to worry about funny buffering making the
test output harder to verify?  I mean, we only have to care about
the ordering of lines within the original standard output (or
standard error) stream independently, but now if the test thinks it
wrote A to its stderr, then B to its stdout, and then C to its
stderr, would we get them in the single output stream as A followed
by B followed by C, or can sometimes buffered output can give us A
then C then finally B?

Just an idle thought.  What makes me more confused is that the
updated t0000 tests seem to say that we now check standard output
and standard error separately.

> Signed-off-by: Patrick Steinhardt <ps@pks.im>
> ---
>  t/t0000-basic.sh | 35 +++++++++++++++++++----------------
>  t/test-lib.sh    |  4 ++--
>  2 files changed, 21 insertions(+), 18 deletions(-)
>
> diff --git a/t/t0000-basic.sh b/t/t0000-basic.sh
> index 35c5c2b4f9b..16b785f3b91 100755
> --- a/t/t0000-basic.sh
> +++ b/t/t0000-basic.sh
> @@ -219,41 +219,44 @@ test_expect_success 'subtest: --verbose option' '
>  	test_expect_success "failing test" false
>  	test_done
>  	EOF
> -	mv t1234-verbose/out t1234-verbose/out+ &&
> -	grep -v "^Initialized empty" t1234-verbose/out+ >t1234-verbose/out &&
> -	check_sub_test_lib_test t1234-verbose <<-\EOF
> -	> expecting success of 1234.1 '\''passing test'\'': true
> +	mv t1234-verbose/err t1234-verbose/err+ &&
> +	grep -v "^Initialized empty" t1234-verbose/err+ >t1234-verbose/err &&
> +	check_sub_test_lib_test_err t1234-verbose \
> +		<<-\EOF_OUT 3<<-\EOF_ERR
>  	> ok 1 - passing test
> +	> ok 2 - test with output
> +	> not ok 3 - failing test
> +	> #	false
> +	> # failed 1 among 3 test(s)
> +	> 1..3
> +	EOF_OUT
> +	> expecting success of 1234.1 '\''passing test'\'': true
>  	> Z
>  	> expecting success of 1234.2 '\''test with output'\'': echo foo
>  	> foo
> -	> ok 2 - test with output
>  	> Z
>  	> expecting success of 1234.3 '\''failing test'\'': false
> -	> not ok 3 - failing test
> -	> #	false
>  	> Z
> -	> # failed 1 among 3 test(s)
> -	> 1..3
> -	EOF
> +	EOF_ERR
>  '
>  
>  test_expect_success 'subtest: --verbose-only option' '
>  	run_sub_test_lib_test_err \
>  		t1234-verbose \
>  		--verbose-only=2 &&
> -	check_sub_test_lib_test t1234-verbose <<-\EOF
> +	check_sub_test_lib_test_err t1234-verbose <<-\EOF_OUT 3<<-\EOF_ERR
>  	> ok 1 - passing test
> -	> Z
> -	> expecting success of 1234.2 '\''test with output'\'': echo foo
> -	> foo
>  	> ok 2 - test with output
> -	> Z
>  	> not ok 3 - failing test
>  	> #	false
>  	> # failed 1 among 3 test(s)
>  	> 1..3
> -	EOF
> +	EOF_OUT
> +	> Z
> +	> expecting success of 1234.2 '\''test with output'\'': echo foo
> +	> foo
> +	> Z
> +	EOF_ERR
>  '
>  
>  test_expect_success 'subtest: skip one with GIT_SKIP_TESTS' '
> diff --git a/t/test-lib.sh b/t/test-lib.sh
> index af722d383d9..6ce8570226c 100644
> --- a/t/test-lib.sh
> +++ b/t/test-lib.sh
> @@ -707,7 +707,7 @@ then
>  	exec 3>>"$GIT_TEST_TEE_OUTPUT_FILE" 4>&3
>  elif test "$verbose" = "t"
>  then
> -	exec 4>&2 3>&1
> +	exec 4>&2 3>&2
>  else
>  	exec 4>/dev/null 3>/dev/null
>  fi
> @@ -949,7 +949,7 @@ maybe_setup_verbose () {
>  	test -z "$verbose_only" && return
>  	if match_pattern_list $test_count "$verbose_only"
>  	then
> -		exec 4>&2 3>&1
> +		exec 4>&2 3>&2
>  		# Emit a delimiting blank line when going from
>  		# non-verbose to verbose.  Within verbose mode the
>  		# delimiter is printed by test_expect_*.  The choice