Re: [PATCH v2 1/1] vreportf: Fix interleaving issues, remove 4096 limitation

[Johannes Schindelin <Johannes.Schindelin@gmx.de>]

Hi Peff,

On Fri, 25 Oct 2019, Jeff King wrote:

> On Fri, Oct 25, 2019 at 04:02:36PM +0200, Johannes Schindelin wrote:
>
> > ... and indeed, I verified that this patch fixes the problem:
> >
> > -- snip --
> > diff --git a/usage.c b/usage.c
> > index 2fdb20086bd..7f5bdfb0f40 100644
> > --- a/usage.c
> > +++ b/usage.c
> > @@ -10,13 +10,16 @@ void vreportf(const char *prefix, const char *err, va_list params)
> >  {
> >  	char msg[4096];
> >  	char *p;
> > -
> > -	vsnprintf(msg, sizeof(msg), err, params);
> > +	size_t off = strlcpy(msg, prefix, sizeof(msg));
> > +	int ret = vsnprintf(msg + off, sizeof(msg) - off, err, params);
> >  	for (p = msg; *p; p++) {
> >  		if (iscntrl(*p) && *p != '\t' && *p != '\n')
> >  			*p = '?';
> >  	}
> > -	fprintf(stderr, "%s%s\n", prefix, msg);
> > +	if (ret > 0) {
> > +		msg[off + ret] = '\n'; /* we no longer need a NUL */
> > +		write_in_full(2, msg, off + ret + 1);
> > +	}
> >  }
>
> Heh. This is quite similar to what I posted in:
>
>   https://public-inbox.org/git/20190828145412.GB14432@sigill.intra.peff.net/
>
> though I missed the cleverness with "we no longer need a NUL" to get an
> extra byte. ;)

:-)

I also use `xwrite()` instead of `write()`...

> > > except truncation to 4096. Then I would expect a patch to increase
> > > buffer size to 8192 in the next couple years. And if you also try to
> > > solve truncation, it will get you very close to my code.
> >
> > My point is: I don't want to "fix" truncation. I actually think of it as
> > a feature. An error message that is longer than the average news article
> > I read is too long, period.
>
> Yeah. As the person responsible for many of the "avoid truncation" works
> referenced in the original patch, I have come to the conclusion that it
> is not worth the complexity. Even when we do manage to produce a
> gigantic error message correctly, it's generally not very readable.
>
> That's basically what I came here to say, and I was pleased to find that
> you had already argued for it quite well. So I'll just add my support
> for the direction you've taken the conversation.

Thank you for affirming. I have to admit that I would have loved for my
argument to work on its own, and not require the additional force of a
second opinion. In my mind, there is little opinion required here.

> I _do_ wish we could do the truncation more intelligently. I'd much
> rather see:
>
>   error: unable to open 'absurdly-long-file-name...': permission denied
>
> than:
>
>   error: unable to open 'absurdly-long-file-name-that-goes-on-forever-and-ev
>
> But I don't think it's possible without reimplementing snprintf
> ourselves.

Indeed. I _did_ start to implement `strbuf_vaddf()` from scratch, over
ten years ago:

https://public-inbox.org/git/alpine.LSU.1.00.0803061727120.3941@racer.site/

I am not sure whether we want to resurrect it, it would need to grow
support _at least_ for `%PRIuMAX` and `%PRIdMAX`, but that should not be
hard.

Back to the issue at hand: I did open a GitGitGadget PR with my proposed
change, in the hopes that I could somehow fast-track this fix into the
CI/PR builds over at https://github.com/gitgitgadget/git, but there are
problems: it seems that now there is an at least occasional broken pipe
in the same test when run on macOS.

There _also_ seems to be something spooky going on in t3510.12 and .13,
where the expected output differs from the actual output only by a
re-ordering of the lines:

-- snip --
[...]
+++ diff -u expect advice
--- expect	2019-10-25 22:17:44.982884700 +0000
+++ advice	2019-10-25 22:17:45.278884500 +0000
@@ -1,3 +1,3 @@
 error: cherry-pick is already in progress
-hint: try "git cherry-pick (--continue | --skip | --abort | --quit)"
 fatal: cherry-pick failed
+hint: try "git cherry-pick (--continue | --skip | --abort | --quit)"
-- snap --

For details, see:
https://dev.azure.com/gitgitgadget/git/_build/results?buildId=19336&view=ms.vss-test-web.build-test-results-tab
and
https://dev.azure.com/Git-for-Windows/git/_build/results?buildId=44549&view=ms.vss-test-web.build-test-results-tab
(You need to click on a test case title to open the logs, then inspect
the Attachments to get to the full trace)

So much as I would love to see the flakiness of t5516 be fixed as soon
as possible, I fear we will have to look at the underlying issue a bit
closer: there are two processes writing to `stderr` concurrently. I
don't know whether there would be a good way for the `stderr` of the
`upload-pack` process to be consumed by the `fetch` process, and to be
printed by the latter.

Ciao,
Dscho