[PATCH] t: send verbose test-helper output to fd 4

[PATCH] t: send verbose test-helper output to fd 4

[Jeff King]

This is a repost of the two patches from:

  https://public-inbox.org/git/20180209185710.GA23403@sigill.intra.peff.net/

(now just one patch, since sg/test-i18ngrep graduated and we can do it
all in one step). The idea got positive feedback, but nobody commented
on patches and I didn't see them in "What's cooking".

-- >8 --
Test helper functions like test_must_fail may produce
messages to stderr when they see a problem. When the tests
are run with "--verbose", this ends up on the test script's
stderr, and the user can read it.

But there's a problem. Some tests record stderr as part of
the test, like:

  test_must_fail git foo 2>output &&
  test_i18ngrep expected.message output

In this case the error text goes into "output". This makes
the --verbose output less useful (it also means we might
accidentally match it in the second, though in practice we
tend to produce these messages only on error, so we'd abort
the test when the first command fails).

Let's instead send this user-facing output directly to
descriptor 4, which always points to the original stderr (or
/dev/null in non-verbose mode). And it's already forbidden
to redirect descriptor 4, since we use it for BASH_XTRACEFD,
as explained in 9be795fbce (t5615: avoid re-using descriptor
4, 2017-12-08).

Signed-off-by: Jeff King <peff@peff.net>
---
 t/test-lib-functions.sh | 20 ++++++++++----------
 1 file changed, 10 insertions(+), 10 deletions(-)

diff --git a/t/test-lib-functions.sh b/t/test-lib-functions.sh
index 67b5994afb..aabee13e5d 100644
--- a/t/test-lib-functions.sh
+++ b/t/test-lib-functions.sh
@@ -625,22 +625,22 @@ test_must_fail () {
 	exit_code=$?
 	if test $exit_code -eq 0 && ! list_contains "$_test_ok" success
 	then
-		echo >&2 "test_must_fail: command succeeded: $*"
+		echo >&4 "test_must_fail: command succeeded: $*"
 		return 1
 	elif test_match_signal 13 $exit_code && list_contains "$_test_ok" sigpipe
 	then
 		return 0
 	elif test $exit_code -gt 129 && test $exit_code -le 192
 	then
-		echo >&2 "test_must_fail: died by signal $(($exit_code - 128)): $*"
+		echo >&4 "test_must_fail: died by signal $(($exit_code - 128)): $*"
 		return 1
 	elif test $exit_code -eq 127
 	then
-		echo >&2 "test_must_fail: command not found: $*"
+		echo >&4 "test_must_fail: command not found: $*"
 		return 1
 	elif test $exit_code -eq 126
 	then
-		echo >&2 "test_must_fail: valgrind error: $*"
+		echo >&4 "test_must_fail: valgrind error: $*"
 		return 1
 	fi
 	return 0
@@ -678,7 +678,7 @@ test_expect_code () {
 		return 0
 	fi
 
-	echo >&2 "test_expect_code: command exited with $exit_code, we wanted $want_code $*"
+	echo >&4 "test_expect_code: command exited with $exit_code, we wanted $want_code $*"
 	return 1
 }
 
@@ -742,18 +742,18 @@ test_i18ngrep () {
 		shift
 		! grep "$@" && return 0
 
-		echo >&2 "error: '! grep $@' did find a match in:"
+		echo >&4 "error: '! grep $@' did find a match in:"
 	else
 		grep "$@" && return 0
 
-		echo >&2 "error: 'grep $@' didn't find a match in:"
+		echo >&4 "error: 'grep $@' didn't find a match in:"
 	fi
 
 	if test -s "$last_arg"
 	then
-		cat >&2 "$last_arg"
+		cat >&4 "$last_arg"
 	else
-		echo >&2 "<File '$last_arg' is empty>"
+		echo >&4 "<File '$last_arg' is empty>"
 	fi
 
 	return 1
@@ -764,7 +764,7 @@ test_i18ngrep () {
 # not output anything when they fail.
 verbose () {
 	"$@" && return 0
-	echo >&2 "command failed: $(git rev-parse --sq-quote "$@")"
+	echo >&4 "command failed: $(git rev-parse --sq-quote "$@")"
 	return 1
 }
 
-- 
2.16.2.580.g650ee5408b

Re: [PATCH] t: send verbose test-helper output to fd 4

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

> This is a repost of the two patches from:
>
>   https://public-inbox.org/git/20180209185710.GA23403@sigill.intra.peff.net/
>
> (now just one patch, since sg/test-i18ngrep graduated and we can do it
> all in one step). The idea got positive feedback, but nobody commented
> on patches and I didn't see them in "What's cooking".

Thanks for clearly explaining the change.  Will queue.

Re: [PATCH] t: send verbose test-helper output to fd 4

[SZEDER Gábor]

On Thu, Feb 22, 2018 at 7:48 AM, Jeff King <peff@peff.net> wrote:
> This is a repost of the two patches from:
>
>   https://public-inbox.org/git/20180209185710.GA23403@sigill.intra.peff.net/
>
> (now just one patch, since sg/test-i18ngrep graduated and we can do it
> all in one step). The idea got positive feedback, but nobody commented
> on patches and I didn't see them in "What's cooking".
>
> -- >8 --
> Test helper functions like test_must_fail may produce
> messages to stderr when they see a problem. When the tests
> are run with "--verbose", this ends up on the test script's
> stderr, and the user can read it.
>
> But there's a problem. Some tests record stderr as part of
> the test, like:
>
>   test_must_fail git foo 2>output &&
>   test_i18ngrep expected.message output
>
> In this case the error text goes into "output". This makes
> the --verbose output less useful (it also means we might
> accidentally match it in the second, though in practice we
> tend to produce these messages only on error, so we'd abort
> the test when the first command fails).
>
> Let's instead send this user-facing output directly to
> descriptor 4, which always points to the original stderr (or
> /dev/null in non-verbose mode). And it's already forbidden
> to redirect descriptor 4, since we use it for BASH_XTRACEFD,
> as explained in 9be795fbce (t5615: avoid re-using descriptor
> 4, 2017-12-08).
>
> Signed-off-by: Jeff King <peff@peff.net>
> ---
>  t/test-lib-functions.sh | 20 ++++++++++----------
>  1 file changed, 10 insertions(+), 10 deletions(-)
>
> diff --git a/t/test-lib-functions.sh b/t/test-lib-functions.sh
> index 67b5994afb..aabee13e5d 100644
> --- a/t/test-lib-functions.sh
> +++ b/t/test-lib-functions.sh
> @@ -625,22 +625,22 @@ test_must_fail () {
>         exit_code=$?
>         if test $exit_code -eq 0 && ! list_contains "$_test_ok" success
>         then
> -               echo >&2 "test_must_fail: command succeeded: $*"
> +               echo >&4 "test_must_fail: command succeeded: $*"
>                 return 1
>         elif test_match_signal 13 $exit_code && list_contains "$_test_ok" sigpipe
>         then
>                 return 0
>         elif test $exit_code -gt 129 && test $exit_code -le 192
>         then
> -               echo >&2 "test_must_fail: died by signal $(($exit_code - 128)): $*"
> +               echo >&4 "test_must_fail: died by signal $(($exit_code - 128)): $*"
>                 return 1
>         elif test $exit_code -eq 127
>         then
> -               echo >&2 "test_must_fail: command not found: $*"
> +               echo >&4 "test_must_fail: command not found: $*"
>                 return 1
>         elif test $exit_code -eq 126
>         then
> -               echo >&2 "test_must_fail: valgrind error: $*"
> +               echo >&4 "test_must_fail: valgrind error: $*"
>                 return 1
>         fi
>         return 0
> @@ -678,7 +678,7 @@ test_expect_code () {
>                 return 0
>         fi
>
> -       echo >&2 "test_expect_code: command exited with $exit_code, we wanted $want_code $*"
> +       echo >&4 "test_expect_code: command exited with $exit_code, we wanted $want_code $*"
>         return 1
>  }

The parts above changing the fds used for error messages in
'test_must_fail' and 'test_expect_code' will become unnecessary if we
take my patch from

  https://public-inbox.org/git/20180225134015.26964-1-szeder.dev@gmail.com/

because that patch also ensures that error messages from this function
will go to fd 4 even if the stderr of the functions is redirected in the
test.  Though, arguably, your patch makes it more readily visible that
those error messages go to fd 4, so maybe it's still worth having.

> @@ -742,18 +742,18 @@ test_i18ngrep () {
>                 shift
>                 ! grep "$@" && return 0
>
> -               echo >&2 "error: '! grep $@' did find a match in:"
> +               echo >&4 "error: '! grep $@' did find a match in:"
>         else
>                 grep "$@" && return 0
>
> -               echo >&2 "error: 'grep $@' didn't find a match in:"
> +               echo >&4 "error: 'grep $@' didn't find a match in:"
>         fi
>
>         if test -s "$last_arg"
>         then
> -               cat >&2 "$last_arg"
> +               cat >&4 "$last_arg"
>         else
> -               echo >&2 "<File '$last_arg' is empty>"
> +               echo >&4 "<File '$last_arg' is empty>"
>         fi
>
>         return 1
> @@ -764,7 +764,7 @@ test_i18ngrep () {
>  # not output anything when they fail.
>  verbose () {
>         "$@" && return 0
> -       echo >&2 "command failed: $(git rev-parse --sq-quote "$@")"
> +       echo >&4 "command failed: $(git rev-parse --sq-quote "$@")"
>         return 1
>  }

I'm not so sure about these changes to 'test_18ngrep' and 'verbose'.  It
seems that they are the result of a simple s/>&2/>&4/ on
'test-lib-functions.sh'?  The problem described in the commit message
doesn't really applies to them, because their _only_ output to stderr
are the error messages intended to the user, so no sane test would
redirect and check their stderr.  (OK, technically the command run by
'verbose' could output anything to stderr, but 'verbose' was meant for
commands failing silently in the first place; that's why my patch linked
above left 'verbose' unchanged.)

Also note that there are a lot of other test helper functions that
output something primarily intended to the user on failure (e.g.
'test_path_is_*' and the like), though those messages go stdout instead
of stderr.  Perhaps the messages of those functions should go to stderr
as well (or even fd 4)?

Re: [PATCH] t: send verbose test-helper output to fd 4

[Jeff King]

On Wed, Feb 28, 2018 at 03:30:29AM +0100, SZEDER Gábor wrote:

> > -       echo >&2 "test_expect_code: command exited with $exit_code, we wanted $want_code $*"
> > +       echo >&4 "test_expect_code: command exited with $exit_code, we wanted $want_code $*"
> >         return 1
> >  }
> 
> The parts above changing the fds used for error messages in
> 'test_must_fail' and 'test_expect_code' will become unnecessary if we
> take my patch from
> 
>   https://public-inbox.org/git/20180225134015.26964-1-szeder.dev@gmail.com/
> 
> because that patch also ensures that error messages from this function
> will go to fd 4 even if the stderr of the functions is redirected in the
> test.  Though, arguably, your patch makes it more readily visible that
> those error messages go to fd 4, so maybe it's still worth having.

Yeah, I could take it or leave it if we follow that other route.

> >  # not output anything when they fail.
> >  verbose () {
> >         "$@" && return 0
> > -       echo >&2 "command failed: $(git rev-parse --sq-quote "$@")"
> > +       echo >&4 "command failed: $(git rev-parse --sq-quote "$@")"
> >         return 1
> >  }
> 
> I'm not so sure about these changes to 'test_18ngrep' and 'verbose'.  It
> seems that they are the result of a simple s/>&2/>&4/ on
> 'test-lib-functions.sh'?  The problem described in the commit message
> doesn't really applies to them, because their _only_ output to stderr
> are the error messages intended to the user, so no sane test would
> redirect and check their stderr.  (OK, technically the command run by
> 'verbose' could output anything to stderr, but 'verbose' was meant for
> commands failing silently in the first place; that's why my patch linked
> above left 'verbose' unchanged.)

Yes, I agree it's not likely to help anybody. I did it mostly for
consistency. I.e., to say "and we are meaning to send this directly to
the user". It actually might make sense to wrap that concept in a helper
function. Arguably "say" should do this redirection automatically (we do
redirect it elsewhere, but mostly to try to accomplish the same thing).

> Also note that there are a lot of other test helper functions that
> output something primarily intended to the user on failure (e.g.
> 'test_path_is_*' and the like), though those messages go stdout instead
> of stderr.  Perhaps the messages of those functions should go to stderr
> as well (or even fd 4)?

Yeah, I just missed those. I agree they should redirect to fd 4, too.

I'm trying to clear my inbox before traveling, so I probably won't dig
into this further for a while. If you think this is the right direction,
do you want to add more ">&4" redirects to helpers as part of your
series?

-Peff