racy test failure in tb/upload-pack-filters

racy test failure in tb/upload-pack-filters

[Jeff King]

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.

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

Re: racy test failure in tb/upload-pack-filters

[SZEDER Gábor]

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.

Oh, this is a good one! :)

> We can fix it by using test_i18ngrep, which just makes this grep a noop
> in the poison mode.

I wonder whether changing that die to

  die("%s: %s", _("remote error"), buffer + 4)

would be better.  

> 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

Re: racy test failure in tb/upload-pack-filters

[Jeff King]

On Wed, Aug 05, 2020 at 11:06:41AM +0200, SZEDER Gábor wrote:

> > We can fix it by using test_i18ngrep, which just makes this grep a noop
> > in the poison mode.
> 
> I wonder whether changing that die to
> 
>   die("%s: %s", _("remote error"), buffer + 4)
> 
> would be better.

That would definitely work, but it seems sad to have to make our code
uglier. Plus I think it would hurt translations that want to format
differently (e.g., would an RTL language want to swap the order?).

It also wouldn't help other poison uses that could be expecting a "%s"
to be filled.  Another option would be to make our poison code more
realistic by copying placeholders like "%s" into the poison string. That
would fix this problem, and allow some tests to relax a bit (e.g., if
I'm looking for an error message that contains a filename, I _could_
grep for just that filename, which would never actually be translated).

But I think that gets pretty tricky, as we'd have to understand the
whole set of placeholders (e.g., that "%s" is complete after two bytes,
but "%lu" needs three bytes).

Anyway, it seemed like limiting the damage to the tests themselves was
the least bad thing.

By the way, grepping for "remote error:" shows that when we get an error
over sideband 3 we produce the same message but _don't_ translate it.
That seems inconsistent.

-Peff

Re: racy test failure in tb/upload-pack-filters

[Martin Ågren]

On Wed, 5 Aug 2020 at 10:45, Jeff King <peff@peff.net> wrote:
>
>   $ GIT_TEST_GETTEXT_POISON=1 ./t5616-partial-clone.sh --stress
>   FAIL 19.1
>   FAIL 15.1
>   OK   26.1
>   OK   16.1
>   ...

[...]
> 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

Nice. :-)

> -- >8 --
> Subject: t5616: use test_i18ngrep for upload-pack errors

[...snipping lots of good stuff...]

> 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.

s/now/not/

Very nicely explained, as always.

> -       grep "filter '\''blob:none'\'' not supported" err
> +       test_i18ngrep "filter '\''blob:none'\'' not supported" err

Right, this is the one from the intro and the commit message.

> -       grep "tree filter allows max depth 0, but got 1" err
> +       test_i18ngrep "tree filter allows max depth 0, but got 1" err

This one isn't translated, so this hunk could be dropped. Or maybe you
wanted to knowingly cast a slightly wider net? (And this does fit the
subject of your patch.)

Martin

Re: racy test failure in tb/upload-pack-filters

[Jeff King]

On Wed, Aug 05, 2020 at 11:27:22AM +0200, Martin Ågren wrote:

> > 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.
> 
> s/now/not/

Oops, thanks.

> > -       grep "filter '\''blob:none'\'' not supported" err
> > +       test_i18ngrep "filter '\''blob:none'\'' not supported" err
> 
> Right, this is the one from the intro and the commit message.
> 
> > -       grep "tree filter allows max depth 0, but got 1" err
> > +       test_i18ngrep "tree filter allows max depth 0, but got 1" err
> 
> This one isn't translated, so this hunk could be dropped. Or maybe you
> wanted to knowingly cast a slightly wider net? (And this does fit the
> subject of your patch.)

Neither message is translated in itself, but the bug can happen with
either of them (because of the translation of the "remote error"
string). The tree-depth one was actually in the first failure I saw, but
when I re-ran it to produce output for the commit message, I got one of
the other tests.

-Peff

Re: racy test failure in tb/upload-pack-filters

[Martin Ågren]

On Wed, 5 Aug 2020 at 12:03, Jeff King <peff@peff.net> wrote:
>
> On Wed, Aug 05, 2020 at 11:27:22AM +0200, Martin Ågren wrote:
>
> > > -       grep "tree filter allows max depth 0, but got 1" err
> > > +       test_i18ngrep "tree filter allows max depth 0, but got 1" err
> >
> > This one isn't translated, so this hunk could be dropped. Or maybe you
> > wanted to knowingly cast a slightly wider net? (And this does fit the
> > subject of your patch.)
>
> Neither message is translated in itself, but the bug can happen with
> either of them (because of the translation of the "remote error"
> string). The tree-depth one was actually in the first failure I saw, but
> when I re-ran it to produce output for the commit message, I got one of
> the other tests.

Braino! Thanks for (re-)explaining so patiently. I even tried dropping
that hunk and running a fair amount of "--stress" -- never failed.
Without the other hunks, "--stress" hit the failure pretty much
instantly. Oh well, brute force doesn't always beat actual thinking.

Martin

Re: racy test failure in tb/upload-pack-filters

[Taylor Blau]

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

Re: racy test failure in tb/upload-pack-filters

[Taylor Blau]

On Wed, Aug 05, 2020 at 05:26:58AM -0400, Jeff King wrote:
> On Wed, Aug 05, 2020 at 11:06:41AM +0200, SZEDER Gábor wrote:
>
> > > We can fix it by using test_i18ngrep, which just makes this grep a noop
> > > in the poison mode.
> >
> > I wonder whether changing that die to
> >
> >   die("%s: %s", _("remote error"), buffer + 4)
> >
> > would be better.
>
> That would definitely work, but it seems sad to have to make our code
> uglier. Plus I think it would hurt translations that want to format
> differently (e.g., would an RTL language want to swap the order?).

This is reason enough to not do this; I know that we are pretty averse
to translation lego, and even though this one seems innocuous, I think
it may be a deal breaker for such languages.

> It also wouldn't help other poison uses that could be expecting a "%s"
> to be filled.  Another option would be to make our poison code more
> realistic by copying placeholders like "%s" into the poison string. That
> would fix this problem, and allow some tests to relax a bit (e.g., if
> I'm looking for an error message that contains a filename, I _could_
> grep for just that filename, which would never actually be translated).
>
> But I think that gets pretty tricky, as we'd have to understand the
> whole set of placeholders (e.g., that "%s" is complete after two bytes,
> but "%lu" needs three bytes).

Might be a good direction to go in, but I agree it's outside of the
scope of this patch.

> Anyway, it seemed like limiting the damage to the tests themselves was
> the least bad thing.
>
> By the way, grepping for "remote error:" shows that when we get an error
> over sideband 3 we produce the same message but _don't_ translate it.
> That seems inconsistent.
>
> -Peff

Thanks,
Taylor

Re: racy test failure in tb/upload-pack-filters

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

> By the way, grepping for "remote error:" shows that when we get an error
> over sideband 3 we produce the same message but _don't_ translate it.
> That seems inconsistent.

IOW

    die(_("remote error: %s"), buf + 1);

in sideband.c?  I think it makes sense.

IIRC, the current thinking is to let the remote side localize their
message before sending them over the wire and we'll worry about how
we let the receiving end tell what l10n it wants later.  So "remote
error:" prefix may have to be translated on receiving end and the
remainder of the line, which is already localized, can just be
interpolated.

[PATCH] sideband: mark "remote error:" prefix for translation

[Jeff King]

On Wed, Aug 05, 2020 at 09:28:42AM -0700, Junio C Hamano wrote:

> Jeff King <peff@peff.net> writes:
> 
> > By the way, grepping for "remote error:" shows that when we get an error
> > over sideband 3 we produce the same message but _don't_ translate it.
> > That seems inconsistent.
> 
> IOW
> 
>     die(_("remote error: %s"), buf + 1);
> 
> in sideband.c?  I think it makes sense.

Yes. Patch is below so we don't forget about it. I'm not sure if we
ought to be going further, though. The "remote:" prefix for sideband 2
isn't translated either. It would be easy to do so, but it's much more
lego-like. We don't have "remote: %s" ever as a string. We just have
"remote:", and then we maybe_colorize_sideband() the result.

Would that be annoying for translators, especially with RTL languages?
Do people actually want to see "remote:" (or "remote error:" for that
matter) translated, or does mixing translated and untranslated messages
on one line end up more confusing? I'm out of my element here, as I
wouldn't ever use the translations myself.

> IIRC, the current thinking is to let the remote side localize their
> message before sending them over the wire and we'll worry about how
> we let the receiving end tell what l10n it wants later.  So "remote
> error:" prefix may have to be translated on receiving end and the
> remainder of the line, which is already localized, can just be
> interpolated.

Yeah, that part makes sense. The local client shouldn't be translating
what it gets from the server (and won't, because it is filled in via the
%s). Adding a capability for preferred language would be easy, though I
imagine it might be irritating in practice.  As a server admin, I want
to see everything in the C locale; but what gets shown to users and what
might get dumped into server logs is not well specified in Git. I have a
feeling that just setting LANG based on the user's request would be a
bit broad.

Anyway, here's the patch. It doesn't seem to cause any test failures,
even with GETTEXT_POISON. :)

-- >8 --
Subject: [PATCH] sideband: mark "remote error:" prefix for translation

A Git client may produce a "remote error:" message (along with whatever
error the other side sent us) in two places:

  - when we see an ERR packet

  - when we're using a sideband and see sideband 3

We can't reliably translate the message the other side sent us, but we
can do so for our own prefix. However, we translate only the ERR-packet
case but not the sideband-3 case. Let's make them consistent (by marking
both for translation).

Signed-off-by: Jeff King <peff@peff.net>
---
I really just care about consistency between the two spots, so swapping
this to translate neither would be to me, too. I guess this does create
inconsistency with "remote: " though. Not sure if it's incremental
forward progress, or just a bad idea. ;)

 sideband.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/sideband.c b/sideband.c
index ef851113c4..0a60662fa6 100644
--- a/sideband.c
+++ b/sideband.c
@@ -147,7 +147,7 @@ int demultiplex_sideband(const char *me, char *buf, int len,
 	switch (band) {
 	case 3:
 		if (die_on_error)
-			die("remote error: %s", buf + 1);
+			die(_("remote error: %s"), buf + 1);
 		strbuf_addf(scratch, "%s%s", scratch->len ? "\n" : "",
 			    DISPLAY_PREFIX);
 		maybe_colorize_sideband(scratch, buf + 1, len);
-- 
2.28.0.520.g10e2ce7e11

Re: [PATCH] sideband: mark "remote error:" prefix for translation

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

> On Wed, Aug 05, 2020 at 09:28:42AM -0700, Junio C Hamano wrote:
>
>> Jeff King <peff@peff.net> writes:
>> 
>> > By the way, grepping for "remote error:" shows that when we get an error
>> > over sideband 3 we produce the same message but _don't_ translate it.
>> > That seems inconsistent.
>> 
>> IOW
>> 
>>     die(_("remote error: %s"), buf + 1);
>> 
>> in sideband.c?  I think it makes sense.
>
> Yes. Patch is below so we don't forget about it. I'm not sure if we
> ought to be going further, though. The "remote:" prefix for sideband 2
> isn't translated either. It would be easy to do so, but it's much more
> lego-like. We don't have "remote: %s" ever as a string. We just have
> "remote:", and then we maybe_colorize_sideband() the result.
>
> Would that be annoying for translators, especially with RTL languages?
> Do people actually want to see "remote:" (or "remote error:" for that
> matter) translated, or does mixing translated and untranslated messages
> on one line end up more confusing? I'm out of my element here, as I
> wouldn't ever use the translations myself.
>
>> IIRC, the current thinking is to let the remote side localize their
>> message before sending them over the wire and we'll worry about how
>> we let the receiving end tell what l10n it wants later.  So "remote
>> error:" prefix may have to be translated on receiving end and the
>> remainder of the line, which is already localized, can just be
>> interpolated.
>
> Yeah, that part makes sense. The local client shouldn't be translating
> what it gets from the server (and won't, because it is filled in via the
> %s). Adding a capability for preferred language would be easy, though I
> imagine it might be irritating in practice.  As a server admin, I want
> to see everything in the C locale; but what gets shown to users and what
> might get dumped into server logs is not well specified in Git. I have a
> feeling that just setting LANG based on the user's request would be a
> bit broad.
>
> Anyway, here's the patch. It doesn't seem to cause any test failures,
> even with GETTEXT_POISON. :)

;-)  Thanks.  Queued.