git@vger.kernel.org mailing list mirror (one of many)
 help / color / mirror / code / Atom feed
From: Taylor Blau <me@ttaylorr.com>
To: Jeff King <peff@peff.net>
Cc: "Taylor Blau" <me@ttaylorr.com>,
	"SZEDER Gábor" <szeder.dev@gmail.com>,
	"Junio C Hamano" <gitster@pobox.com>,
	git@vger.kernel.org
Subject: Re: racy test failure in tb/upload-pack-filters
Date: Wed, 5 Aug 2020 11:08:50 -0400	[thread overview]
Message-ID: <20200805150850.GA9546@syl.lan> (raw)
In-Reply-To: <20200805084240.GA1802257@coredump.intra.peff.net>

On Wed, Aug 05, 2020 at 04:42:40AM -0400, Jeff King wrote:
> I hit a test failure in the CI job against 'next' tonight, which proved
> to be an interesting puzzle. Skip to the scissors line for the
> explanation and the fix. Read on if you want to guess. :)
>
> Here's what I saw:
>
> Running t5616 with --stress works fine:
>
>   $ ./t5616-partial-clone.sh  --stress
>   ...lots of runs...
>   OK   29.12
>   ...etc...
>   [I get bored and hit ^C]
>
> If I run it with GETTEXT_POISON, it doesn't fail:
>
>   $ GIT_TEST_GETTEXT_POISON=1 ./t5616-partial-clone.sh
>   ...
>   ok 17 - upload-pack fails banned object filters
>
> but if I do both together, it fails almost instantly:
>
>   $ GIT_TEST_GETTEXT_POISON=1 ./t5616-partial-clone.sh --stress
>   FAIL 19.1
>   FAIL 15.1
>   OK   26.1
>   OK   16.1
>   ...
>
> But here's the really interesting part. The failure log looks like this:
>
>   ...
>   + grep filter 'blob:none' not supported err
>   error: last command exited with $?=1
>   not ok 19 - upload-pack fails banned object filters with fallback
>   #
>   #		test_config -C srv.bare uploadpackfilter.allow false &&
>   #		test_must_fail ok=sigpipe git clone --no-checkout --filter=blob:none \
>   #			"file://$(pwd)/srv.bare" pc3 2>err &&
>   #		grep "filter 'blob:none' not supported" err
>   #
>
> OK, so what's in that file?
>
>   $ cd trash\ directory.t5616-partial-clone.stress-failed/
>   $ cat err
>   # GETTEXT POISON #fatal: # GETTEXT POISON #
>   fatal: filter 'blob:none' not supported
>
> What, it's there!? Is it somehow confusing grep?
>
>   $ grep "filter 'blob:none' not supported" err
>   fatal: filter 'blob:none' not supported
>   $ echo $?
>   0
>
> Nope. So what's going on? Turn to page 17 for the exciting conclusion!
>
> -- >8 --
> Subject: t5616: use test_i18ngrep for upload-pack errors
>
> The tests added to t5616 in 6dd3456a8c (upload-pack.c: allow banning
> certain object filter(s), 2020-08-03) can fail racily, but only with
> GETTEXT_POISON enabled.
>
> The tests in question look something like this:
>
>   test_must_fail ok=sigpipe git clone --filter=blob:none ... 2>err &&
>   grep "filter blob:none not supported' err
>
> The remote upload-pack process writes that error message both as an ERR
> packet, but also via a die() message. In theory we should see the
> message twice in the "err" file. The client relays the message from the
> packet to its stderr (with a "remote error:" prefix), and because this
> is a local-system clone, upload-pack's stderr goes to the same place.
>
> But because clone may be writing to the pipe when upload-pack calls
> die(), it may get SIGPIPE and fail to relay the message. That's why we
> need our "ok=sigpipe" trick. But our grep should still work reliably in
> that case. Either:
>
>   - we got SIGPIPE on the client, which means upload-pack completed its
>     die(), and we'll see that version of the message.
>
>   - the client didn't get SIGPIPE, and so it successfully relays the
>     message.
>
> In theory we'd see both copies of the message in the second case. But
> now always! As soon as the client sees ERR, it exits and we run grep.
> But we have no guarantee that the upload-pack process has exited at this
> point, or even written its die() message. We might only see the client
> version of the message.
>
> Normally that's OK. We only need to see one or the other to pass the
> test. But now consider GETTEXT_POISON. upload-pack doesn't translate the
> die() message nor the ERR packet. But once the client receives it, it
> calls:
>
>   die(_("remote error: %s"), buffer + 4);
>
> That message _is_ marked for translation. Normally we'd just replace the
> "remote error:" portion of it, but in GETTEXT_POISON mode, we replace
> the whole thing with "# GETTEXT POISON #" and don't include the "%s"
> part at all. So the whole text from the ERR packet is dropped, and so we
> may racily see a test failure if upload-pack's die() call wasn't yet
> written.

Yikes. I knew I should have thought more about switching from
'test_i18ngrep' back to normal 'grep', but I wouldn't have expected
something like this ;).

I agree with your find and fix, and thanks for the enjoyable read in the
meantime.

  Acked-by: Taylor Blau <me@ttaylorr.com>

> We can fix it by using test_i18ngrep, which just makes this grep a noop
> in the poison mode.
>
> Signed-off-by: Jeff King <peff@peff.net>
> ---
>  t/t5616-partial-clone.sh | 8 ++++----
>  1 file changed, 4 insertions(+), 4 deletions(-)
>
> diff --git a/t/t5616-partial-clone.sh b/t/t5616-partial-clone.sh
> index 4247102b00..9164ad3e63 100755
> --- a/t/t5616-partial-clone.sh
> +++ b/t/t5616-partial-clone.sh
> @@ -239,7 +239,7 @@ test_expect_success 'upload-pack fails banned object filters' '
>  	test_config -C srv.bare uploadpackfilter.blob:none.allow false &&
>  	test_must_fail ok=sigpipe git clone --no-checkout --filter=blob:none \
>  		"file://$(pwd)/srv.bare" pc3 2>err &&
> -	grep "filter '\''blob:none'\'' not supported" err
> +	test_i18ngrep "filter '\''blob:none'\'' not supported" err
>  '
>
>  test_expect_success 'upload-pack fails banned combine object filters' '
> @@ -249,14 +249,14 @@ test_expect_success 'upload-pack fails banned combine object filters' '
>  	test_config -C srv.bare uploadpackfilter.blob:none.allow false &&
>  	test_must_fail ok=sigpipe git clone --no-checkout --filter=tree:1 \
>  		--filter=blob:none "file://$(pwd)/srv.bare" pc3 2>err &&
> -	grep "filter '\''blob:none'\'' not supported" err
> +	test_i18ngrep "filter '\''blob:none'\'' not supported" err
>  '
>
>  test_expect_success 'upload-pack fails banned object filters with fallback' '
>  	test_config -C srv.bare uploadpackfilter.allow false &&
>  	test_must_fail ok=sigpipe git clone --no-checkout --filter=blob:none \
>  		"file://$(pwd)/srv.bare" pc3 2>err &&
> -	grep "filter '\''blob:none'\'' not supported" err
> +	test_i18ngrep "filter '\''blob:none'\'' not supported" err
>  '
>
>  test_expect_success 'upload-pack limits tree depth filters' '
> @@ -265,7 +265,7 @@ test_expect_success 'upload-pack limits tree depth filters' '
>  	test_config -C srv.bare uploadpackfilter.tree.maxDepth 0 &&
>  	test_must_fail ok=sigpipe git clone --no-checkout --filter=tree:1 \
>  		"file://$(pwd)/srv.bare" pc3 2>err &&
> -	grep "tree filter allows max depth 0, but got 1" err
> +	test_i18ngrep "tree filter allows max depth 0, but got 1" err
>  '
>
>  test_expect_success 'partial clone fetches blobs pointed to by refs even if normally filtered out' '
> --
> 2.28.0.506.gf082c28967
Thanks,
Taylor

      parent reply	other threads:[~2020-08-05 19:48 UTC|newest]

Thread overview: 11+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2020-08-05  8:42 racy test failure in tb/upload-pack-filters Jeff King
2020-08-05  9:06 ` SZEDER Gábor
2020-08-05  9:26   ` Jeff King
2020-08-05 15:10     ` Taylor Blau
2020-08-05 16:28     ` Junio C Hamano
2020-08-07  8:56       ` [PATCH] sideband: mark "remote error:" prefix for translation Jeff King
2020-08-07 20:18         ` Junio C Hamano
2020-08-05  9:27 ` racy test failure in tb/upload-pack-filters Martin Ågren
2020-08-05 10:03   ` Jeff King
2020-08-05 11:35     ` Martin Ågren
2020-08-05 15:08 ` Taylor Blau [this message]

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

  List information: http://vger.kernel.org/majordomo-info.html

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20200805150850.GA9546@syl.lan \
    --to=me@ttaylorr.com \
    --cc=git@vger.kernel.org \
    --cc=gitster@pobox.com \
    --cc=peff@peff.net \
    --cc=szeder.dev@gmail.com \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
Code repositories for project(s) associated with this public inbox

	https://80x24.org/mirrors/git.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).