[PATCH 0/3] Teach 'test_must_fail' to save the command's stderr to a file

[PATCH 0/3] Teach 'test_must_fail' to save the command's stderr to a file

[SZEDER Gábor]

To check that a git command fails with the expected error message, we 
usually execute a command like this:
        
  test_must_fail git command --option 2>output.err
	          
Alas, this command doesn't limit the redirection to the git command,
but it redirects the standard error of the 'test_must_fail' helper
function as well, causing various issues discussed in detail in the
second patch.  Therefore that patch introduces the 'test_must_fail
stderr=<file>' option to save the executed git command's standard
error to the given file.

The last patch converts one test script to use 'test_must_fail
stderr=<file>' to demonstrate its benefits: thereafter that script
will succeed with '-x'.  There are plenty more places to convert:

  $ git grep -E 'test_(must|might)_fail .* 2>' t/*.sh |wc -l
  430
  $ git grep --name-only -E 'test_(must|might)_fail .* 2>' t/*.sh |wc -l
  135

... and this doesn't even count commands spanning more lines, and
there are more in 'pu'.

I didn't convert more test scripts, because it's boring ;) but more
importantly because it could give us 135+ GSoC micro projects.

SZEDER Gábor (3):
  t: document 'test_must_fail ok=<signal-name>'
  t: teach 'test_must_fail' to save the command's stderr to a file
  t1404: use 'test_must_fail stderr=<file>'

 t/README                     | 20 +++++++++++++++++--
 t/t1404-update-ref-errors.sh | 46 ++++++++++++++++++++++----------------------
 t/test-lib-functions.sh      | 45 +++++++++++++++++++++++++++++++++----------
 3 files changed, 76 insertions(+), 35 deletions(-)

-- 
2.16.1.180.g07550b0b1b

[PATCH 1/3] t: document 'test_must_fail ok=<signal-name>'

[SZEDER Gábor]

Since 'test_might_fail' is implemented as a thin wrapper around
'test_must_fail', it also accepts the same options.  Mention this in
the docs as well.

Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>
---
 t/README                | 14 ++++++++++++--
 t/test-lib-functions.sh | 10 ++++++++++
 2 files changed, 22 insertions(+), 2 deletions(-)

diff --git a/t/README b/t/README
index b3f7b449c3..1a1361a806 100644
--- a/t/README
+++ b/t/README
@@ -655,7 +655,7 @@ library for your script to use.
 		test_expect_code 1 git merge "merge msg" B master
 	'
 
- - test_must_fail <git-command>
+ - test_must_fail [<options>] <git-command>
 
    Run a git command and ensure it fails in a controlled way.  Use
    this instead of "! <git-command>".  When git-command dies due to a
@@ -663,11 +663,21 @@ library for your script to use.
    treats it as just another expected failure, which would let such a
    bug go unnoticed.
 
- - test_might_fail <git-command>
+   Accepts the following options:
+
+     ok=<signal-name>[,<...>]:
+       Don't treat an exit caused by the given signal as error.
+       Multiple signals can be specified as a comma separated list.
+       Currently recognized signal names are: sigpipe, success.
+       (Don't use 'success', use 'test_might_fail' instead.)
+
+ - test_might_fail [<options>] <git-command>
 
    Similar to test_must_fail, but tolerate success, too.  Use this
    instead of "<git-command> || :" to catch failures due to segv.
 
+   Accepts the same options as test_must_fail.
+
  - test_cmp <expected> <actual>
 
    Check whether the content of the <actual> file matches the
diff --git a/t/test-lib-functions.sh b/t/test-lib-functions.sh
index 1701fe2a06..26b149ac1d 100644
--- a/t/test-lib-functions.sh
+++ b/t/test-lib-functions.sh
@@ -610,6 +610,14 @@ list_contains () {
 #
 # Writing this as "! git checkout ../outerspace" is wrong, because
 # the failure could be due to a segv.  We want a controlled failure.
+#
+# Accepts the following options:
+#
+#   ok=<signal-name>[,<...>]:
+#     Don't treat an exit caused by the given signal as error.
+#     Multiple signals can be specified as a comma separated list.
+#     Currently recognized signal names are: sigpipe, success.
+#     (Don't use 'success', use 'test_might_fail' instead.)
 
 test_must_fail () {
 	case "$1" in
@@ -656,6 +664,8 @@ test_must_fail () {
 #
 # Writing "git config --unset all.configuration || :" would be wrong,
 # because we want to notice if it fails due to segv.
+#
+# Accepts the same options as test_must_fail.
 
 test_might_fail () {
 	test_must_fail ok=success "$@"
-- 
2.16.1.180.g07550b0b1b

[PATCH 2/3] t: teach 'test_must_fail' to save the command's stderr to a file

[SZEDER Gábor]

To check that a git command fails and to inspect its error message we
usually execute a command like this throughout our test suite:

  test_must_fail git command --option 2>output.err

Note that this command doesn't limit the redirection to the git
command, but it redirects the standard error of the 'test_must_fail'
helper function as well.  This is wrong for several reasons:

  - If that git command were to succeed or die for an unexpected
    reason e.g. signal, then 'test_must_fail's helpful error message
    would end up in the given file instead of on the terminal or in
    't/test-results/$T.out', when the test is run with '-v' or
    '--verbose-log', respectively.

  - If the test is run with '-x', the trace of executed commands in
    'test_must_fail' will go to stderr as well (except for more recent
    Bash versions supporting $BASH_XTRACEFD), and then in turn will
    end up in the given file.

  - If the git command's error message is checked verbatim with
    'test_cmp', then the '-x' trace will cause the test to fail.

  - Though rather unlikely, if the git command's error message is
    checked with 'test_i18ngrep', then its pattern might match
    'test_must_fail's error message (or '-x' trace) instead of the
    given git command's, potentially hiding a bug.

Teach the 'test_must_fail' helper the 'stderr=<file>' option to save
the executed git command's standard error to that file, so we can
avoid all the bad side effects of redirecting the whole thing's
standard error.

The same issues apply to the 'test_might_fail' helper function as
well, but since it's implemented as a thin wrapper around
'test_must_fail', no modifications were necessary and 'test_might_fail
stderr=output.err git command' will just work.

Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>
---

Notes:
    I considered adding an analogous 'stdout=<file>' option as well, but in
    the end haven't, because:
    
      - 'test_must_fail' doesn't print anything to its standard output, so a
        plain '>out' redirection at the end of the line doesn't have any
        undesirable side effects.
    
      - We would need four conditions to cover all possible combinations of
        'stdout=' and 'stderr='.  Considering the above point, I don't think
        it's worth it.

 t/README                |  6 ++++++
 t/test-lib-functions.sh | 35 +++++++++++++++++++++++++----------
 2 files changed, 31 insertions(+), 10 deletions(-)

diff --git a/t/README b/t/README
index 1a1361a806..2528359e9d 100644
--- a/t/README
+++ b/t/README
@@ -430,6 +430,10 @@ Don't:
    use 'test_must_fail git cmd'.  This will signal a failure if git
    dies in an unexpected way (e.g. segfault).
 
+   Don't redirect 'test_must_fail's standard error like
+   'test_must_fail git cmd 2>err'.  Instead, run 'test_must_fail
+   stderr=err git cmd'.
+
    On the other hand, don't use test_must_fail for running regular
    platform commands; just use '! cmd'.  We are not in the business
    of verifying that the world given to us sanely works.
@@ -670,6 +674,8 @@ library for your script to use.
        Multiple signals can be specified as a comma separated list.
        Currently recognized signal names are: sigpipe, success.
        (Don't use 'success', use 'test_might_fail' instead.)
+     stderr=<file>:
+       Save <git-command>'s standard error to <file>.
 
  - test_might_fail [<options>] <git-command>
 
diff --git a/t/test-lib-functions.sh b/t/test-lib-functions.sh
index 26b149ac1d..d2f561477c 100644
--- a/t/test-lib-functions.sh
+++ b/t/test-lib-functions.sh
@@ -618,18 +618,33 @@ list_contains () {
 #     Multiple signals can be specified as a comma separated list.
 #     Currently recognized signal names are: sigpipe, success.
 #     (Don't use 'success', use 'test_might_fail' instead.)
+#   stderr=<file>:
+#     Save the git command's standard error to <file>.
 
 test_must_fail () {
-	case "$1" in
-	ok=*)
-		_test_ok=${1#ok=}
-		shift
-		;;
-	*)
-		_test_ok=
-		;;
-	esac
-	"$@"
+	_test_ok= _test_stderr=
+	while test $# -gt 0
+	do
+		case "$1" in
+		stderr=*)
+			_test_stderr=${1#stderr=}
+			shift
+			;;
+		ok=*)
+			_test_ok=${1#ok=}
+			shift
+			;;
+		*)
+			break
+			;;
+		esac
+	done
+	if test -n "$_test_stderr"
+	then
+		"$@" 2>"$_test_stderr"
+	else
+		"$@"
+	fi
 	exit_code=$?
 	if test $exit_code -eq 0 && ! list_contains "$_test_ok" success
 	then
-- 
2.16.1.180.g07550b0b1b

[PATCH 3/3] t1404: use 'test_must_fail stderr=<file>'

[SZEDER Gábor]

Instead of 'test_must_fail git cmd... 2>output.err', which redirects
the standard error of the 'test_must_fail' helper function as well,
causing various issues as discussed in the previous patch.

With this patch t1404 succeeds when run with '-x', even with shells
not supporting $BASH_XTRACEFD.

Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>
---
 t/t1404-update-ref-errors.sh | 46 ++++++++++++++++++++++----------------------
 1 file changed, 23 insertions(+), 23 deletions(-)

diff --git a/t/t1404-update-ref-errors.sh b/t/t1404-update-ref-errors.sh
index 3a887b5113..91250bc6a0 100755
--- a/t/t1404-update-ref-errors.sh
+++ b/t/t1404-update-ref-errors.sh
@@ -26,7 +26,7 @@ test_update_rejected () {
 		git pack-refs --all
 	fi &&
 	printf "create $prefix/%s $C\n" $create >input &&
-	test_must_fail git update-ref --stdin <input 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin <input &&
 	grep -F "$error" output.err &&
 	git for-each-ref $prefix >actual &&
 	test_cmp unchanged actual
@@ -102,7 +102,7 @@ df_test() {
 	else
 		printf "%s\n" "delete $delname" "create $addname $D"
 	fi >commands &&
-	test_must_fail git update-ref --stdin <commands 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin <commands &&
 	test_cmp expected-err output.err &&
 	printf "%s\n" "$C $delref" >expected-refs &&
 	git for-each-ref --format="%(objectname) %(refname)" $prefix/r >actual-refs &&
@@ -337,7 +337,7 @@ test_expect_success 'missing old value blocks update' '
 	fatal: cannot lock ref $Q$prefix/foo$Q: unable to resolve reference $Q$prefix/foo$Q
 	EOF
 	printf "%s\n" "update $prefix/foo $E $D" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -348,7 +348,7 @@ test_expect_success 'incorrect old value blocks update' '
 	fatal: cannot lock ref $Q$prefix/foo$Q: is at $C but expected $D
 	EOF
 	printf "%s\n" "update $prefix/foo $E $D" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -359,7 +359,7 @@ test_expect_success 'existing old value blocks create' '
 	fatal: cannot lock ref $Q$prefix/foo$Q: reference already exists
 	EOF
 	printf "%s\n" "create $prefix/foo $E" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -370,7 +370,7 @@ test_expect_success 'incorrect old value blocks delete' '
 	fatal: cannot lock ref $Q$prefix/foo$Q: is at $C but expected $D
 	EOF
 	printf "%s\n" "delete $prefix/foo $D" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -381,7 +381,7 @@ test_expect_success 'missing old value blocks indirect update' '
 	fatal: cannot lock ref $Q$prefix/symref$Q: unable to resolve reference $Q$prefix/foo$Q
 	EOF
 	printf "%s\n" "update $prefix/symref $E $D" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -393,7 +393,7 @@ test_expect_success 'incorrect old value blocks indirect update' '
 	fatal: cannot lock ref $Q$prefix/symref$Q: is at $C but expected $D
 	EOF
 	printf "%s\n" "update $prefix/symref $E $D" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -405,7 +405,7 @@ test_expect_success 'existing old value blocks indirect create' '
 	fatal: cannot lock ref $Q$prefix/symref$Q: reference already exists
 	EOF
 	printf "%s\n" "create $prefix/symref $E" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -417,7 +417,7 @@ test_expect_success 'incorrect old value blocks indirect delete' '
 	fatal: cannot lock ref $Q$prefix/symref$Q: is at $C but expected $D
 	EOF
 	printf "%s\n" "delete $prefix/symref $D" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -428,7 +428,7 @@ test_expect_success 'missing old value blocks indirect no-deref update' '
 	fatal: cannot lock ref $Q$prefix/symref$Q: reference is missing but expected $D
 	EOF
 	printf "%s\n" "option no-deref" "update $prefix/symref $E $D" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -440,7 +440,7 @@ test_expect_success 'incorrect old value blocks indirect no-deref update' '
 	fatal: cannot lock ref $Q$prefix/symref$Q: is at $C but expected $D
 	EOF
 	printf "%s\n" "option no-deref" "update $prefix/symref $E $D" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -452,7 +452,7 @@ test_expect_success 'existing old value blocks indirect no-deref create' '
 	fatal: cannot lock ref $Q$prefix/symref$Q: reference already exists
 	EOF
 	printf "%s\n" "option no-deref" "create $prefix/symref $E" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -464,7 +464,7 @@ test_expect_success 'incorrect old value blocks indirect no-deref delete' '
 	fatal: cannot lock ref $Q$prefix/symref$Q: is at $C but expected $D
 	EOF
 	printf "%s\n" "option no-deref" "delete $prefix/symref $D" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -477,13 +477,13 @@ test_expect_success 'non-empty directory blocks create' '
 	fatal: cannot lock ref $Q$prefix/foo$Q: there is a non-empty directory $Q.git/$prefix/foo$Q blocking reference $Q$prefix/foo$Q
 	EOF
 	printf "%s\n" "update $prefix/foo $C" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err &&
 	cat >expected <<-EOF &&
 	fatal: cannot lock ref $Q$prefix/foo$Q: unable to resolve reference $Q$prefix/foo$Q
 	EOF
 	printf "%s\n" "update $prefix/foo $D $C" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -496,13 +496,13 @@ test_expect_success 'broken reference blocks create' '
 	fatal: cannot lock ref $Q$prefix/foo$Q: unable to resolve reference $Q$prefix/foo$Q: reference broken
 	EOF
 	printf "%s\n" "update $prefix/foo $C" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err &&
 	cat >expected <<-EOF &&
 	fatal: cannot lock ref $Q$prefix/foo$Q: unable to resolve reference $Q$prefix/foo$Q: reference broken
 	EOF
 	printf "%s\n" "update $prefix/foo $D $C" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -516,13 +516,13 @@ test_expect_success 'non-empty directory blocks indirect create' '
 	fatal: cannot lock ref $Q$prefix/symref$Q: there is a non-empty directory $Q.git/$prefix/foo$Q blocking reference $Q$prefix/foo$Q
 	EOF
 	printf "%s\n" "update $prefix/symref $C" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err &&
 	cat >expected <<-EOF &&
 	fatal: cannot lock ref $Q$prefix/symref$Q: unable to resolve reference $Q$prefix/foo$Q
 	EOF
 	printf "%s\n" "update $prefix/symref $D $C" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -535,13 +535,13 @@ test_expect_success 'broken reference blocks indirect create' '
 	fatal: cannot lock ref $Q$prefix/symref$Q: unable to resolve reference $Q$prefix/foo$Q: reference broken
 	EOF
 	printf "%s\n" "update $prefix/symref $C" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err &&
 	cat >expected <<-EOF &&
 	fatal: cannot lock ref $Q$prefix/symref$Q: unable to resolve reference $Q$prefix/foo$Q: reference broken
 	EOF
 	printf "%s\n" "update $prefix/symref $D $C" |
-	test_must_fail git update-ref --stdin 2>output.err &&
+	test_must_fail stderr=output.err git update-ref --stdin &&
 	test_cmp expected output.err
 '
 
@@ -612,7 +612,7 @@ test_expect_success 'delete fails cleanly if packed-refs file is locked' '
 	# Now try to delete it while the `packed-refs` lock is held:
 	: >.git/packed-refs.lock &&
 	test_when_finished "rm -f .git/packed-refs.lock" &&
-	test_must_fail git update-ref -d $prefix/foo >out 2>err &&
+	test_must_fail stderr=err git update-ref -d $prefix/foo >out &&
 	git for-each-ref $prefix >actual &&
 	test_i18ngrep "Unable to create $Q.*packed-refs.lock$Q: File exists" err &&
 	test_cmp unchanged actual
-- 
2.16.1.180.g07550b0b1b

Re: [PATCH 2/3] t: teach 'test_must_fail' to save the command's stderr to a file

[Eric Sunshine]

On Thu, Feb 8, 2018 at 9:42 PM, SZEDER Gábor <szeder.dev@gmail.com> wrote:
> To check that a git command fails and to inspect its error message we
> usually execute a command like this throughout our test suite:
>
>   test_must_fail git command --option 2>output.err
>
> Note that this command doesn't limit the redirection to the git
> command, but it redirects the standard error of the 'test_must_fail'
> helper function as well.  This is wrong for several reasons:
>
>   [...snip rationale...]
>
> Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>
> ---
> diff --git a/t/README b/t/README
> @@ -430,6 +430,10 @@ Don't:
>     use 'test_must_fail git cmd'.  This will signal a failure if git
>     dies in an unexpected way (e.g. segfault).
>
> +   Don't redirect 'test_must_fail's standard error like
> +   'test_must_fail git cmd 2>err'.  Instead, run 'test_must_fail
> +   stderr=err git cmd'.

Perhaps not worth a re-roll, but it might be nice to cite a bit of the
rationale from the commit message for the "don't redirect" rule since
it's not necessarily obvious for readers of t/README why this
limitation exists (and it seems unlikely they would check this commit
message). The rationale here doesn't necessarily need to go into
exquisite detail of the commit message, but could be perhaps as simple
as:

    Don't redirect 'test_must_fail's standard error to a file (e.g.
    'test_must_fail git cmd 2>err') since error output from commands
    run internally by 'test_must_fail' may pollute file "err".
    Instead, run 'test_must_fail stderr=err git cmd'.

Re: [PATCH 3/3] t1404: use 'test_must_fail stderr=<file>'

[Eric Sunshine]

On Thu, Feb 8, 2018 at 9:42 PM, SZEDER Gábor <szeder.dev@gmail.com> wrote:
> Instead of 'test_must_fail git cmd... 2>output.err', which redirects
> the standard error of the 'test_must_fail' helper function as well,
> causing various issues as discussed in the previous patch.

ECANTPARSE: This either wants to say:

    "Instead of <foo>, do <bar>."

or:

    "'test_must_fail ... 2>...', which redirects ...
     causes various issues discussed..."

but fails to say either.

> With this patch t1404 succeeds when run with '-x', even with shells
> not supporting $BASH_XTRACEFD.
>
> Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>

Re: [PATCH 3/3] t1404: use 'test_must_fail stderr=<file>'

[SZEDER Gábor]

On Fri, Feb 9, 2018 at 4:16 AM, Eric Sunshine <sunshine@sunshineco.com> wrote:
> On Thu, Feb 8, 2018 at 9:42 PM, SZEDER Gábor <szeder.dev@gmail.com> wrote:
>> Instead of 'test_must_fail git cmd... 2>output.err', which redirects
>> the standard error of the 'test_must_fail' helper function as well,
>> causing various issues as discussed in the previous patch.
>
> ECANTPARSE: This either wants to say:
>
>     "Instead of <foo>, do <bar>."

The "do <bar>" part is in the subject line.

> or:
>
>     "'test_must_fail ... 2>...', which redirects ...
>      causes various issues discussed..."

Well, at this point I got the ECANTPARSE :)

> but fails to say either.
>
>> With this patch t1404 succeeds when run with '-x', even with shells
>> not supporting $BASH_XTRACEFD.
>>
>> Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>

Re: [PATCH 2/3] t: teach 'test_must_fail' to save the command's stderr to a file

[Jeff King]

On Fri, Feb 09, 2018 at 03:42:34AM +0100, SZEDER Gábor wrote:

> To check that a git command fails and to inspect its error message we
> usually execute a command like this throughout our test suite:
> 
>   test_must_fail git command --option 2>output.err
> 
> Note that this command doesn't limit the redirection to the git
> command, but it redirects the standard error of the 'test_must_fail'
> helper function as well.  This is wrong for several reasons:
> 
>   - If that git command were to succeed or die for an unexpected
>     reason e.g. signal, then 'test_must_fail's helpful error message
>     would end up in the given file instead of on the terminal or in
>     't/test-results/$T.out', when the test is run with '-v' or
>     '--verbose-log', respectively.
> 
>   - If the test is run with '-x', the trace of executed commands in
>     'test_must_fail' will go to stderr as well (except for more recent
>     Bash versions supporting $BASH_XTRACEFD), and then in turn will
>     end up in the given file.

I have to admit that I'm slightly negative on this approach, just
because:

  1. It requires every caller to do something special, rather than just
     using normal redirection. And the feature isn't as powerful as
     redirection. E.g., some callers do:

       test_must_fail foo >output 2>&1

     But:

       test_must_fail stderr=output foo >output

     is not quite right (stdout and stderr outputs may clobber each
     other, because they have independent position pointers).

  2. The "-x" problems aren't specific to test_must_fail at all. They're
     a general issue with shell functions.

I'm not entirely happy with saying "if you want to use -x, please use
bash". But given that it actually solves the problems everywhere with no
further effort, is it really that bad a solution?

For the error messages from test_must_fail, could we go in the same
direction, and send them to descriptor 4 rather than 2? We've already
staked out descriptor 4 as something magical that must be left alone
(see 9be795fb). If we can rely on that, then it becomes a convenient way
for functions to make sure their output is going to the script's stderr.

-Peff

Re: [PATCH 3/3] t1404: use 'test_must_fail stderr=<file>'

[Junio C Hamano]

SZEDER Gábor <szeder.dev@gmail.com> writes:

> On Fri, Feb 9, 2018 at 4:16 AM, Eric Sunshine <sunshine@sunshineco.com> wrote:
>> On Thu, Feb 8, 2018 at 9:42 PM, SZEDER Gábor <szeder.dev@gmail.com> wrote:
>>> Instead of 'test_must_fail git cmd... 2>output.err', which redirects
>>> the standard error of the 'test_must_fail' helper function as well,
>>> causing various issues as discussed in the previous patch.
>>
>> ECANTPARSE: This either wants to say:
>>
>>     "Instead of <foo>, do <bar>."
>
> The "do <bar>" part is in the subject line.

Please don't.  The title should not be a half-sentence that begins
the first paragraph.

Re: [PATCH 2/3] t: teach 'test_must_fail' to save the command's stderr to a file

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

>   2. The "-x" problems aren't specific to test_must_fail at all. They're
>      a general issue with shell functions.
>
> I'm not entirely happy with saying "if you want to use -x, please use
> bash". But given that it actually solves the problems everywhere with no
> further effort, is it really that bad a solution?
>
> For the error messages from test_must_fail, could we go in the same
> direction, and send them to descriptor 4 rather than 2? We've already
> staked out descriptor 4 as something magical that must be left alone
> (see 9be795fb). If we can rely on that, then it becomes a convenient way
> for functions to make sure their output is going to the script's stderr.

That sounds clever and rather attractive.  It isn't that much of an
layering violation for test-lib-functions.sh::test_must_fail to have
such an intimate knowledge on how test_-lib.sh::test_eval_ sets up
the file descriptors, either.

Re: [PATCH 2/3] t: teach 'test_must_fail' to save the command's stderr to a file

[Jeff King]

On Fri, Feb 09, 2018 at 10:36:19AM -0800, Junio C Hamano wrote:

> Jeff King <peff@peff.net> writes:
> 
> >   2. The "-x" problems aren't specific to test_must_fail at all. They're
> >      a general issue with shell functions.
> >
> > I'm not entirely happy with saying "if you want to use -x, please use
> > bash". But given that it actually solves the problems everywhere with no
> > further effort, is it really that bad a solution?
> >
> > For the error messages from test_must_fail, could we go in the same
> > direction, and send them to descriptor 4 rather than 2? We've already
> > staked out descriptor 4 as something magical that must be left alone
> > (see 9be795fb). If we can rely on that, then it becomes a convenient way
> > for functions to make sure their output is going to the script's stderr.
> 
> That sounds clever and rather attractive.  It isn't that much of an
> layering violation for test-lib-functions.sh::test_must_fail to have
> such an intimate knowledge on how test_-lib.sh::test_eval_ sets up
> the file descriptors, either.

Here's what it looks like as a patch.

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

Test helper functions like test_must_fail may write 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 any message from test_must_fail goes into
"output", making the --verbose output less useful. It also
means we might accidentally match it in the second line,
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 send this user-facing output directly to descriptor 4,
which always points to the original stderr (or /dev/null in
non-verbose mode). 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>
---
I've considered a patch to teach "make test-lint" to complain if it sees
" 4>" in any shell script, to try to enforce that rule automatically.
But maybe that's overkill (and also it felt funny to put it in
check-non-portable-shell.pl, but we can always change the name ;) ).

 t/test-lib-functions.sh | 12 ++++++------
 1 file changed, 6 insertions(+), 6 deletions(-)

diff --git a/t/test-lib-functions.sh b/t/test-lib-functions.sh
index 1701fe2a06..a156b81aa5 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
 }
 
@@ -710,7 +710,7 @@ test_cmp_bin() {
 # 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.1.464.gc4bae515b7

Re: [PATCH 2/3] t: teach 'test_must_fail' to save the command's stderr to a file

[Jeff King]

On Fri, Feb 09, 2018 at 01:57:10PM -0500, Jeff King wrote:

> Here's what it looks like as a patch.
> 
> -- >8 --
> Subject: [PATCH] t: send verbose test-helper output to fd 4

That applies on 'master'. If we go this route, we'd want this on
sg/test-i18ngrep, which is in 'next' right now:

-- >8 --
Subject: [PATCH] test_i18n_grep: send error messages to fd 4

These were newly added in 63b1a175ee (t: make
'test_i18ngrep' more informative on failure, 2018-02-08),
and so missed the conversion in commit X.

Signed-off-by: Jeff King <peff@peff.net>
---
(The X above is whatever you queue the original at).

 t/test-lib-functions.sh | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/t/test-lib-functions.sh b/t/test-lib-functions.sh
index cddddd2082..aabee13e5d 100644
--- a/t/test-lib-functions.sh
+++ b/t/test-lib-functions.sh
@@ -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
-- 
2.16.1.464.gc4bae515b7

Re: [PATCH 2/3] t: teach 'test_must_fail' to save the command's stderr to a file

[SZEDER Gábor]

On Fri, Feb 9, 2018 at 3:21 PM, Jeff King <peff@peff.net> wrote:
> On Fri, Feb 09, 2018 at 03:42:34AM +0100, SZEDER Gábor wrote:
>
>> To check that a git command fails and to inspect its error message we
>> usually execute a command like this throughout our test suite:
>>
>>   test_must_fail git command --option 2>output.err
>>
>> Note that this command doesn't limit the redirection to the git
>> command, but it redirects the standard error of the 'test_must_fail'
>> helper function as well.  This is wrong for several reasons:
>>
>>   - If that git command were to succeed or die for an unexpected
>>     reason e.g. signal, then 'test_must_fail's helpful error message
>>     would end up in the given file instead of on the terminal or in
>>     't/test-results/$T.out', when the test is run with '-v' or
>>     '--verbose-log', respectively.
>>
>>   - If the test is run with '-x', the trace of executed commands in
>>     'test_must_fail' will go to stderr as well (except for more recent
>>     Bash versions supporting $BASH_XTRACEFD), and then in turn will
>>     end up in the given file.
>
> I have to admit that I'm slightly negative on this approach

Well, now I'm not just slightly negative, see the patch series I will
send out in a minute :)

> just
> because:
>
>   1. It requires every caller to do something special, rather than just
>      using normal redirection. And the feature isn't as powerful as
>      redirection. E.g., some callers do:
>
>        test_must_fail foo >output 2>&1

Yeah, they do, but most of the time they shouldn't.

I've looked at uses of 'test_must_fail cmd... 2>&1', and also uses of
other test helper functions with stderr duplicated from stdout (and a
couple of cases of "plain" 'git cmd ... 2>&1' as well; that's where the
t6300-for-each-ref fix came from some days ago).

I think all but one of those cases would benefit from handling stdout
and stderr separately, and that one exception shouldn't use
'test_must_fail' for a platform command in the first place[1].

  - Many of these tests check error messages after they mingled stderr
    and stdout like this:

      test_must_fail git cmd >out 2>&1 &&
      (test_i18n)grep "relevant part of the error msg" out

    In these cases there is no need for 2>&1 as they don't care about
    stdout at all.  They could just grep the failed command's stderr,
    with the added benefit that they would ensure that the error message
    indeed goes to stderr.

  - A couple of these tests check the output more strictly:

      test_must_fail git cmd >actual 2>&1 &&
      echo "error message" >expect &&
      test_(i18n)cmp expect actual

    which also checks that nothing was printed on stdout, but does so
    implicitly.  Considering all the sloppy uses of 2>&1, it's hard to
    tell whether it was deliberate to check the empty stdout, or
    accidental, because the writer of the test used 'test_cmp' instead
    of 'grep' for its verbosity on failure, or simply mixed up the two.
    Therefore, I think it's better when it's written more explicitly:

      test_must_fail git cmd >out 2>err &&
      echo "exact error message" >expect &&
      test_cmp expect err &&
      test_must_be_empty out

    ... both when reading such a test and when looking at it's output on
    failure.

  - Then there are some cases that, for some reason, completely silence
    a git command with:

      test_must_fail git cmd >/dev/null 2>&1

    The output of a command could turn out to be useful when debugging a
    failing tests, so tests shouldn't do this, unless there is a very
    good reason (e.g. the command produces a lot of output).


  - Finally, a few tests check that something is surely missing from a
    git command's output, both from stdout and stderr:

      test_must_fail git cmd >out 2>&1 &&
      ! grep "should not be there" out

    Or that a command is completely silent:

      test_must_fail git cmd --quiet >out 2>&1 &&
      test_must_be_empty out

    Checking the emptiness of stdout and stderr separately would give
    more info on failure, as it would tell us right away where the
    unexpected output is coming from (though arguably the presence of
    words like "error" or "fatal" in the output of 'test_must_be_empty'
    would be a dead giveaway).
    BTW, we already have a couple of careful tests that do:

      git cmd >out 2>err &&
      test_must_be_empty out &&
      test_must_be_empty err

    (Which makes me think that extending 'test_must_be_empty' to check
    the emptiness of multiple files at once would be worth it: fewer
    lines, fewer characters to type, and it could report all non-empty
    files, not just the first.)

>      But:
>
>        test_must_fail stderr=output foo >output
>
>      is not quite right (stdout and stderr outputs may clobber each
>      other, because they have independent position pointers).

Relying on the combination of the unbuffered stderr and the
block-buffered stdout could be fragile to begin with, though in general
it doesn't really cause troubles if the data on stdout is less than the
buffer size or if there's no output on stderr after the stdout buffer is
flushed.  The stdout buffer size is pagesize on Linux (I don't know
offhand about others), which is large enough compared to the typical
amount of output git commands produce in our test scripts, so we could
get away with it.

>   2. The "-x" problems aren't specific to test_must_fail at all. They're
>      a general issue with shell functions.

Sure.  I tried to address 'test_must_fail' first, because, with about
90% of the cases, it is by far the worst offender among all test helper
functions with redirected stderr.  'test_expect_code' comes in second
far behind, and there are a mere handful of the combination of
'test_terminal' and 'perl'.

The 'test_expect_code 129 ... 2>&1' in t0012-help.sh's row of '$builtin
can handle -h' tests is particularly interesting, because it hides the
inconsistency that 76 commands send their help/usage text to stdout,
while 45 to stderr.

> I'm not entirely happy with saying "if you want to use -x, please use
> bash". But given that it actually solves the problems everywhere with no
> further effort, is it really that bad a solution?

Well, not that bad a workaround, but in my opinion the real solution is
to make '-x' tracing work reliably with /bin/sh.

Since we strive for POSIX shell compatibility in our test scripts, I
dutifully run the test suite with /bin/sh.  Switching shells for '-x' to
get more info about what went wrong (and then switching back) is a
hassle even when it happens to work, and rather annoying when it
doesn't.  I've lost count of the various ways of running tests with '-x'
and Bash that I naively thought would Just Work, but didn't because of
the subtleties of GIT-BUILD-OPTIONS and/or re-exec in case of
'--verbose-log'.  I find I still reached for various ad-hoc
debugging/tracing or 'test_pause' first, and kept '-x' only as last
resort.

If we start running tests with '-x' and Bash on Travis CI, then it won't
be able to (semi-)automatically catch non-POSIX constructs entering the
test scripts.  And I do want to run all tests with '-x', to get the most
information about rarely occurring transient errors.


[1] - 't/lib-git-p4.sh' contains the following command:

        test_must_fail kill $pid >/dev/null 2>&1