Subject: Re: [PATCH v19 03/10] receive-pack: add new proc-receive hook

From: SZEDER Gábor <[email-masked]>
Date: Sun, 17 Jan 2021 23:21:51 +0100

This patch added a whole lot of test cases, and two of them '86 -
proc-receive: not support push options (builtin protocol)' and '95 -
proc-receive: not support push options (builtin protocol/porcelain)'
are prone to rare failures.

On Thu, Aug 27, 2020 at 11:45:44AM -0400, Jiang Xin wrote:
> diff --git a/t/t5411/test-0026-push-options.sh b/t/t5411/test-0026-push-options.sh
> new file mode 100644
> index 0000000000..d0c4da8b23
> --- /dev/null
> +++ b/t/t5411/test-0026-push-options.sh

> +# Refs of upstream : master(A)
> +# Refs of workbench: master(A)  tags/v123
> +# git push -o ...  :                       refs/for/master/topic
> +test_expect_success "proc-receive: not support push options ($PROTOCOL)" '
> +	test_must_fail git -C workbench push \
> +		-o issue=123 \
> +		-o reviewer=user1 \
> +		origin \
> +		HEAD:refs/for/master/topic \
> +		>out 2>&1 &&

Three relevant things are happening here:

  - 'git push' is executed with its standard output and error
    redirected to the file 'out'.

  - 'git push' executes 'git receive-pack' internally, which inherits
    the open file descriptors, so its output and error goes into that
    same 'out' file.

  - 'git push' is expected to fail when it finds out that the other
    side doesn't support push options, but it does so with a simple
    die() right away, without waiting for its child 'git receive-pack'
    process to finish.

> +	make_user_friendly_and_stable_output <out >actual &&
> +	test_i18ngrep "fatal: the receiving end does not support push options" \
> +		actual &&
> +	git -C "$upstream" show-ref >out &&

Here the shell opens and truncates the file 'out' to write 'git
show-ref's output, i.e. it is still the same 'out' file that was used
earlier.

Consequently, it is possible that 'git receive-pack' is still running,
its open file descriptors to 'out' are still valid, and its "fatal:
the remote end hung up unexpectedly" error message about the suddenly
disappeared 'git push' can partially overwrite the output from 'git
show-ref'.

> +	make_user_friendly_and_stable_output <out >actual &&
> +	cat >expect <<-EOF &&
> +	<COMMIT-A> refs/heads/master
> +	EOF
> +	test_cmp expect actual
> +'

The supposedly stable output can then unexpectedly include that error
message, and the test fails with something like this:

  + test_cmp expect actual
  --- expect      2021-01-17 21:55:23.430750004 +0000
  +++ actual      2021-01-17 21:55:23.430750004 +0000
  @@ -1 +1 @@
  -<COMMIT-A> refs/heads/main
  +<COMMIT-A> refs/heads/maifatal: the remote end hung up unexpectedly
  error: last command exited with $?=1
  not ok 86 - proc-receive: not support push options (builtin protocol)

> diff --git a/t/t5411/test-0027-push-options--porcelain.sh b/t/t5411/test-0027-push-options--porcelain.sh
> new file mode 100644
> index 0000000000..c89a1e7c57
> --- /dev/null
> +++ b/t/t5411/test-0027-push-options--porcelain.sh

> +test_expect_success "proc-receive: not support push options ($PROTOCOL/porcelain)" '
> +	test_must_fail git -C workbench push \
> +		--porcelain \
> +		-o issue=123 \
> +		-o reviewer=user1 \
> +		origin \
> +		HEAD:refs/for/master/topic \
> +		>out 2>&1 &&
> +	make_user_friendly_and_stable_output <out >actual &&
> +	test_i18ngrep "fatal: the receiving end does not support push options" \
> +		actual &&
> +	git -C "$upstream" show-ref >out &&
> +	make_user_friendly_and_stable_output <out >actual &&
> +	cat >expect <<-EOF &&
> +	<COMMIT-A> refs/heads/master
> +	EOF
> +	test_cmp expect actual
> +'

This test is almost identical to the one above, and the same sequence
of events leads to a similar failure.

I saw these tests fail in Travis CI's s390x environment a couple of
times, and, alas, that is the only environment where I was able to
reproduce the failure with '--stress' with an unmodified Git.

The diff below adds a couple of strategically-placed delays to
reliably demonstrate these failures:

  ---  >8  ---

diff --git a/pkt-line.c b/pkt-line.c
index d633005ef7..3b26631948 100644
--- a/pkt-line.c
+++ b/pkt-line.c
@@ -307,6 +307,7 @@ static int get_packet_data(int fd, char **src_buf, size_t *src_size,
 		if (options & PACKET_READ_GENTLE_ON_EOF)
 			return -1;
 
+		sleep(1);
 		die(_("the remote end hung up unexpectedly"));
 	}
 
diff --git a/t/t5411/test-0026-push-options.sh b/t/t5411/test-0026-push-options.sh
index e88edb16a4..a1e896f404 100644
--- a/t/t5411/test-0026-push-options.sh
+++ b/t/t5411/test-0026-push-options.sh
@@ -21,6 +21,7 @@ test_expect_success "proc-receive: not support push options ($PROTOCOL)" '
 	test_i18ngrep "fatal: the receiving end does not support push options" \
 		actual &&
 	git -C "$upstream" show-ref >out &&
+	sleep 2 &&
 	make_user_friendly_and_stable_output <out >actual &&
 	cat >expect <<-EOF &&
 	<COMMIT-A> refs/heads/main
diff --git a/t/t5411/test-0027-push-options--porcelain.sh b/t/t5411/test-0027-push-options--porcelain.sh
index 3a6561b5ea..f97cef440f 100644
--- a/t/t5411/test-0027-push-options--porcelain.sh
+++ b/t/t5411/test-0027-push-options--porcelain.sh
@@ -22,6 +22,7 @@ test_expect_success "proc-receive: not support push options ($PROTOCOL/porcelain
 	test_i18ngrep "fatal: the receiving end does not support push options" \
 		actual &&
 	git -C "$upstream" show-ref >out &&
+	sleep 2 &&
 	make_user_friendly_and_stable_output <out >actual &&
 	cat >expect <<-EOF &&
 	<COMMIT-A> refs/heads/main

  ---  8<  ---

I think these are the only two tests that can cause this racy
behavior: by instrumenting finish_command() I found that in all other
tests where 'git push' is expected to fail it errors out gracefully
and waits for its 'git receive-pack' child process.