{"thread":{"id":"47900","subject":"[PATCH] t: send verbose test-helper output to fd 4","startedAt":"2018-02-22T06:48:43Z","lastAt":"2018-03-03T06:56:55Z","messageCount":4,"participants":["Jeff King","Junio C Hamano","SZEDER Gábor"],"isPatch":true,"patchVersion":1,"patchTotal":null},"messages":[{"id":"339904","messageId":"20180222064836.GA10719@sigill.intra.peff.net","threadId":"47900","inReplyTo":null,"subject":"[PATCH] t: send verbose test-helper output to fd 4","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2018-02-22T06:48:37Z","receivedAt":"2018-02-22T06:48:43Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"This is a repost of the two patches from:\n\n  https://public-inbox.org/git/20180209185710.GA23403@sigill.intra.peff.net/\n\n(now just one patch, since sg/test-i18ngrep graduated and we can do it\nall in one step). The idea got positive feedback, but nobody commented\non patches and I didn't see them in \"What's cooking\".\n\n-- >8 --\nTest helper functions like test_must_fail may produce\nmessages to stderr when they see a problem. When the tests\nare run with \"--verbose\", this ends up on the test script's\nstderr, and the user can read it.\n\nBut there's a problem. Some tests record stderr as part of\nthe test, like:\n\n  test_must_fail git foo 2>output &&\n  test_i18ngrep expected.message output\n\nIn this case the error text goes into \"output\". This makes\nthe --verbose output less useful (it also means we might\naccidentally match it in the second, though in practice we\ntend to produce these messages only on error, so we'd abort\nthe test when the first command fails).\n\nLet's instead send this user-facing output directly to\ndescriptor 4, which always points to the original stderr (or\n/dev/null in non-verbose mode). And it's already forbidden\nto redirect descriptor 4, since we use it for BASH_XTRACEFD,\nas explained in 9be795fbce (t5615: avoid re-using descriptor\n4, 2017-12-08).\n\nSigned-off-by: Jeff King <peff@peff.net>\n---\n t/test-lib-functions.sh | 20 ++++++++++----------\n 1 file changed, 10 insertions(+), 10 deletions(-)\n\ndiff --git a/t/test-lib-functions.sh b/t/test-lib-functions.sh\nindex 67b5994afb..aabee13e5d 100644\n--- a/t/test-lib-functions.sh\n+++ b/t/test-lib-functions.sh\n@@ -625,22 +625,22 @@ test_must_fail () {\n \texit_code=$?\n \tif test $exit_code -eq 0 && ! list_contains \"$_test_ok\" success\n \tthen\n-\t\techo >&2 \"test_must_fail: command succeeded: $*\"\n+\t\techo >&4 \"test_must_fail: command succeeded: $*\"\n \t\treturn 1\n \telif test_match_signal 13 $exit_code && list_contains \"$_test_ok\" sigpipe\n \tthen\n \t\treturn 0\n \telif test $exit_code -gt 129 && test $exit_code -le 192\n \tthen\n-\t\techo >&2 \"test_must_fail: died by signal $(($exit_code - 128)): $*\"\n+\t\techo >&4 \"test_must_fail: died by signal $(($exit_code - 128)): $*\"\n \t\treturn 1\n \telif test $exit_code -eq 127\n \tthen\n-\t\techo >&2 \"test_must_fail: command not found: $*\"\n+\t\techo >&4 \"test_must_fail: command not found: $*\"\n \t\treturn 1\n \telif test $exit_code -eq 126\n \tthen\n-\t\techo >&2 \"test_must_fail: valgrind error: $*\"\n+\t\techo >&4 \"test_must_fail: valgrind error: $*\"\n \t\treturn 1\n \tfi\n \treturn 0\n@@ -678,7 +678,7 @@ test_expect_code () {\n \t\treturn 0\n \tfi\n \n-\techo >&2 \"test_expect_code: command exited with $exit_code, we wanted $want_code $*\"\n+\techo >&4 \"test_expect_code: command exited with $exit_code, we wanted $want_code $*\"\n \treturn 1\n }\n \n@@ -742,18 +742,18 @@ test_i18ngrep () {\n \t\tshift\n \t\t! grep \"$@\" && return 0\n \n-\t\techo >&2 \"error: '! grep $@' did find a match in:\"\n+\t\techo >&4 \"error: '! grep $@' did find a match in:\"\n \telse\n \t\tgrep \"$@\" && return 0\n \n-\t\techo >&2 \"error: 'grep $@' didn't find a match in:\"\n+\t\techo >&4 \"error: 'grep $@' didn't find a match in:\"\n \tfi\n \n \tif test -s \"$last_arg\"\n \tthen\n-\t\tcat >&2 \"$last_arg\"\n+\t\tcat >&4 \"$last_arg\"\n \telse\n-\t\techo >&2 \"<File '$last_arg' is empty>\"\n+\t\techo >&4 \"<File '$last_arg' is empty>\"\n \tfi\n \n \treturn 1\n@@ -764,7 +764,7 @@ test_i18ngrep () {\n # not output anything when they fail.\n verbose () {\n \t\"$@\" && return 0\n-\techo >&2 \"command failed: $(git rev-parse --sq-quote \"$@\")\"\n+\techo >&4 \"command failed: $(git rev-parse --sq-quote \"$@\")\"\n \treturn 1\n }\n \n-- \n2.16.2.580.g650ee5408b\n"},{"id":"339966","messageId":"xmqq371swzff.fsf@gitster-ct.c.googlers.com","threadId":"47900","inReplyTo":"20180222064836.GA10719@sigill.intra.peff.net","subject":"Re: [PATCH] t: send verbose test-helper output to fd 4","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2018-02-22T20:18:44Z","receivedAt":"2018-02-22T20:18:52Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King <peff@peff.net> writes:\n\n> This is a repost of the two patches from:\n>\n>   https://public-inbox.org/git/20180209185710.GA23403@sigill.intra.peff.net/\n>\n> (now just one patch, since sg/test-i18ngrep graduated and we can do it\n> all in one step). The idea got positive feedback, but nobody commented\n> on patches and I didn't see them in \"What's cooking\".\n\nThanks for clearly explaining the change.  Will queue.\n"},{"id":"340529","messageId":"CAM0VKjmtHEGmDi8x_AC8JoNj7rtcanSJX1n0b-f1CEX04Xn8CA@mail.gmail.com","threadId":"47900","inReplyTo":"20180222064836.GA10719@sigill.intra.peff.net","subject":"Re: [PATCH] t: send verbose test-helper output to fd 4","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2018-02-28T02:30:29Z","receivedAt":"2018-02-28T02:30:35Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"On Thu, Feb 22, 2018 at 7:48 AM, Jeff King <peff@peff.net> wrote:\n> This is a repost of the two patches from:\n>\n>   https://public-inbox.org/git/20180209185710.GA23403@sigill.intra.peff.net/\n>\n> (now just one patch, since sg/test-i18ngrep graduated and we can do it\n> all in one step). The idea got positive feedback, but nobody commented\n> on patches and I didn't see them in \"What's cooking\".\n>\n> -- >8 --\n> Test helper functions like test_must_fail may produce\n> messages to stderr when they see a problem. When the tests\n> are run with \"--verbose\", this ends up on the test script's\n> stderr, and the user can read it.\n>\n> But there's a problem. Some tests record stderr as part of\n> the test, like:\n>\n>   test_must_fail git foo 2>output &&\n>   test_i18ngrep expected.message output\n>\n> In this case the error text goes into \"output\". This makes\n> the --verbose output less useful (it also means we might\n> accidentally match it in the second, though in practice we\n> tend to produce these messages only on error, so we'd abort\n> the test when the first command fails).\n>\n> Let's instead send this user-facing output directly to\n> descriptor 4, which always points to the original stderr (or\n> /dev/null in non-verbose mode). And it's already forbidden\n> to redirect descriptor 4, since we use it for BASH_XTRACEFD,\n> as explained in 9be795fbce (t5615: avoid re-using descriptor\n> 4, 2017-12-08).\n>\n> Signed-off-by: Jeff King <peff@peff.net>\n> ---\n>  t/test-lib-functions.sh | 20 ++++++++++----------\n>  1 file changed, 10 insertions(+), 10 deletions(-)\n>\n> diff --git a/t/test-lib-functions.sh b/t/test-lib-functions.sh\n> index 67b5994afb..aabee13e5d 100644\n> --- a/t/test-lib-functions.sh\n> +++ b/t/test-lib-functions.sh\n> @@ -625,22 +625,22 @@ test_must_fail () {\n>         exit_code=$?\n>         if test $exit_code -eq 0 && ! list_contains \"$_test_ok\" success\n>         then\n> -               echo >&2 \"test_must_fail: command succeeded: $*\"\n> +               echo >&4 \"test_must_fail: command succeeded: $*\"\n>                 return 1\n>         elif test_match_signal 13 $exit_code && list_contains \"$_test_ok\" sigpipe\n>         then\n>                 return 0\n>         elif test $exit_code -gt 129 && test $exit_code -le 192\n>         then\n> -               echo >&2 \"test_must_fail: died by signal $(($exit_code - 128)): $*\"\n> +               echo >&4 \"test_must_fail: died by signal $(($exit_code - 128)): $*\"\n>                 return 1\n>         elif test $exit_code -eq 127\n>         then\n> -               echo >&2 \"test_must_fail: command not found: $*\"\n> +               echo >&4 \"test_must_fail: command not found: $*\"\n>                 return 1\n>         elif test $exit_code -eq 126\n>         then\n> -               echo >&2 \"test_must_fail: valgrind error: $*\"\n> +               echo >&4 \"test_must_fail: valgrind error: $*\"\n>                 return 1\n>         fi\n>         return 0\n> @@ -678,7 +678,7 @@ test_expect_code () {\n>                 return 0\n>         fi\n>\n> -       echo >&2 \"test_expect_code: command exited with $exit_code, we wanted $want_code $*\"\n> +       echo >&4 \"test_expect_code: command exited with $exit_code, we wanted $want_code $*\"\n>         return 1\n>  }\n\nThe parts above changing the fds used for error messages in\n'test_must_fail' and 'test_expect_code' will become unnecessary if we\ntake my patch from\n\n  https://public-inbox.org/git/20180225134015.26964-1-szeder.dev@gmail.com/\n\nbecause that patch also ensures that error messages from this function\nwill go to fd 4 even if the stderr of the functions is redirected in the\ntest.  Though, arguably, your patch makes it more readily visible that\nthose error messages go to fd 4, so maybe it's still worth having.\n\n> @@ -742,18 +742,18 @@ test_i18ngrep () {\n>                 shift\n>                 ! grep \"$@\" && return 0\n>\n> -               echo >&2 \"error: '! grep $@' did find a match in:\"\n> +               echo >&4 \"error: '! grep $@' did find a match in:\"\n>         else\n>                 grep \"$@\" && return 0\n>\n> -               echo >&2 \"error: 'grep $@' didn't find a match in:\"\n> +               echo >&4 \"error: 'grep $@' didn't find a match in:\"\n>         fi\n>\n>         if test -s \"$last_arg\"\n>         then\n> -               cat >&2 \"$last_arg\"\n> +               cat >&4 \"$last_arg\"\n>         else\n> -               echo >&2 \"<File '$last_arg' is empty>\"\n> +               echo >&4 \"<File '$last_arg' is empty>\"\n>         fi\n>\n>         return 1\n> @@ -764,7 +764,7 @@ test_i18ngrep () {\n>  # not output anything when they fail.\n>  verbose () {\n>         \"$@\" && return 0\n> -       echo >&2 \"command failed: $(git rev-parse --sq-quote \"$@\")\"\n> +       echo >&4 \"command failed: $(git rev-parse --sq-quote \"$@\")\"\n>         return 1\n>  }\n\nI'm not so sure about these changes to 'test_18ngrep' and 'verbose'.  It\nseems that they are the result of a simple s/>&2/>&4/ on\n'test-lib-functions.sh'?  The problem described in the commit message\ndoesn't really applies to them, because their _only_ output to stderr\nare the error messages intended to the user, so no sane test would\nredirect and check their stderr.  (OK, technically the command run by\n'verbose' could output anything to stderr, but 'verbose' was meant for\ncommands failing silently in the first place; that's why my patch linked\nabove left 'verbose' unchanged.)\n\nAlso note that there are a lot of other test helper functions that\noutput something primarily intended to the user on failure (e.g.\n'test_path_is_*' and the like), though those messages go stdout instead\nof stderr.  Perhaps the messages of those functions should go to stderr\nas well (or even fd 4)?\n"},{"id":"340876","messageId":"20180303065648.GA17312@sigill.intra.peff.net","threadId":"47900","inReplyTo":"CAM0VKjmtHEGmDi8x_AC8JoNj7rtcanSJX1n0b-f1CEX04Xn8CA@mail.gmail.com","subject":"Re: [PATCH] t: send verbose test-helper output to fd 4","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2018-03-03T06:56:49Z","receivedAt":"2018-03-03T06:56:55Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, Feb 28, 2018 at 03:30:29AM +0100, SZEDER Gábor wrote:\n\n> > -       echo >&2 \"test_expect_code: command exited with $exit_code, we wanted $want_code $*\"\n> > +       echo >&4 \"test_expect_code: command exited with $exit_code, we wanted $want_code $*\"\n> >         return 1\n> >  }\n> \n> The parts above changing the fds used for error messages in\n> 'test_must_fail' and 'test_expect_code' will become unnecessary if we\n> take my patch from\n> \n>   https://public-inbox.org/git/20180225134015.26964-1-szeder.dev@gmail.com/\n> \n> because that patch also ensures that error messages from this function\n> will go to fd 4 even if the stderr of the functions is redirected in the\n> test.  Though, arguably, your patch makes it more readily visible that\n> those error messages go to fd 4, so maybe it's still worth having.\n\nYeah, I could take it or leave it if we follow that other route.\n\n> >  # not output anything when they fail.\n> >  verbose () {\n> >         \"$@\" && return 0\n> > -       echo >&2 \"command failed: $(git rev-parse --sq-quote \"$@\")\"\n> > +       echo >&4 \"command failed: $(git rev-parse --sq-quote \"$@\")\"\n> >         return 1\n> >  }\n> \n> I'm not so sure about these changes to 'test_18ngrep' and 'verbose'.  It\n> seems that they are the result of a simple s/>&2/>&4/ on\n> 'test-lib-functions.sh'?  The problem described in the commit message\n> doesn't really applies to them, because their _only_ output to stderr\n> are the error messages intended to the user, so no sane test would\n> redirect and check their stderr.  (OK, technically the command run by\n> 'verbose' could output anything to stderr, but 'verbose' was meant for\n> commands failing silently in the first place; that's why my patch linked\n> above left 'verbose' unchanged.)\n\nYes, I agree it's not likely to help anybody. I did it mostly for\nconsistency. I.e., to say \"and we are meaning to send this directly to\nthe user\". It actually might make sense to wrap that concept in a helper\nfunction. Arguably \"say\" should do this redirection automatically (we do\nredirect it elsewhere, but mostly to try to accomplish the same thing).\n\n> Also note that there are a lot of other test helper functions that\n> output something primarily intended to the user on failure (e.g.\n> 'test_path_is_*' and the like), though those messages go stdout instead\n> of stderr.  Perhaps the messages of those functions should go to stderr\n> as well (or even fd 4)?\n\nYeah, I just missed those. I agree they should redirect to fd 4, too.\n\nI'm trying to clear my inbox before traveling, so I probably won't dig\ninto this further for a while. If you think this is the right direction,\ndo you want to add more \">&4\" redirects to helpers as part of your\nseries?\n\n-Peff\n"}]}