[v4,1/1] vreportf(): avoid relying on stdio buffering
diff mbox series

Message ID f6d6c8122abbd6339cf83309ac3761bbdac44023.1572432276.git.gitgitgadget@gmail.com
State New
Headers show
Series
  • Fix t5516 flakiness in Visual Studio builds
Related show

Commit Message

Philippe Blain via GitGitGadget Oct. 30, 2019, 10:44 a.m. UTC
From: Johannes Schindelin <johannes.schindelin@gmx.de>

The MSVC runtime behavior differs from glibc's with respect to
`fprintf(stderr, ...)` in that the former writes out the message
character by character.

In t5516, this leads to a funny problem where a `git fetch` process as
well as the `git upload-pack` process spawned by it _both_ call `die()`
at the same time. The output can look like this:

	fatal: git uploadfata-lp: raemcokte :error:  upload-pnot our arcef k6: n4ot our ea4cr1e3f 36d45ea94fca1398e86a771eda009872d63adb28598f6a9
	8e86a771eda009872d6ab2886

Let's avoid this predicament altogether by rendering the entire message,
including the prefix and the trailing newline, into the buffer we
already have (and which is still fixed size) and then write it out via
`write_in_full()`.

We still clip the message to at most 4095 characters.

The history of `vreportf()` with regard to this issue includes the
following commits:

d048a96e (2007-11-09) - 'char msg[256]' is introduced to avoid interleaving
389d1767 (2009-03-25) - Buffer size increased to 1024 to avoid truncation
625a860c (2009-11-22) - Buffer size increased to 4096 to avoid truncation
f4c3edc0 (2015-08-11) - Buffer removed to avoid truncation
b5a9e435 (2017-01-11) - Reverts f4c3edc0 to be able to replace control
                        chars before sending to stderr
9ac13ec9 (2006-10-11) - Another attempt to solve interleaving.
                        This is seemingly related to d048a96e.
137a0d0e (2007-11-19) - Addresses out-of-order for display()
34df8aba (2009-03-10) - Switches xwrite() to fprintf() in recv_sideband()
                        to support UTF-8 emulation
eac14f89 (2012-01-14) - Removes the need for fprintf() for UTF-8 emulation,
                        so it's safe to use xwrite() again
5e5be9e2 (2016-06-28) - recv_sideband() uses xwrite() again

Note that we print nothing if the `vsnprintf()` call failed to render
the error message; There is little we can do in that case, and it should
not happen anyway.

The process may have written to `stderr` and there may be something left
in the buffer kept in the stdio layer. Call `fflush(stderr)` before
writing the message we prepare in this function.

Helped-by: Jeff King <peff@peff.net>
Helped-by: Alexandr Miloslavskiy <alexandr.miloslavskiy@syntevo.com>
Helped-by: SZEDER Gábor <szeder.dev@gmail.com>
Helped-by: Junio C Hamano <gitster@pobox.com>
Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
---
 usage.c | 20 ++++++++++++++++----
 1 file changed, 16 insertions(+), 4 deletions(-)

Comments

Junio C Hamano Nov. 2, 2019, 4:05 a.m. UTC | #1
"Johannes Schindelin via GitGitGadget" <gitgitgadget@gmail.com>
writes:

> From: Johannes Schindelin <johannes.schindelin@gmx.de>
>
> The MSVC runtime behavior differs from glibc's with respect to
> `fprintf(stderr, ...)` in that the former writes out the message
> character by character.
> ...
> Let's avoid this predicament altogether by rendering the entire message,
> including the prefix and the trailing newline, into the buffer we
> already have (and which is still fixed size) and then write it out via
> `write_in_full()`.
> ...
> The process may have written to `stderr` and there may be something left
> in the buffer kept in the stdio layer. Call `fflush(stderr)` before
> writing the message we prepare in this function.

Thanks.

This is for future reference and not a comment for you alone, but we
probably do not want to single out glibc like this proposed log
message does in its first paragraph, as if in the author's mind, the
world has only two systems.  It invites questions like "what about
various BSD variants?  how does musl behave?" that may lead to a
suggestion to further update it to "differs from most everybody
else", or we may end up saying "MSVC, X and Y share this problem
unlike all others".  Either way, at that point, the original
singling out of glibc becomes meaningless.

"Platform X has this issue and here is a way to avoid that on
everybody" is a good description of the motivation, and the mention
of the behaviour of MSVC runtime is what we want to see there.

        The MSVC runtime writes out the message character by
        character given `fprintf(stderr, ...)`.

It is not necessary to add "There may be other platforms that share
the same issue, but MSVC alone is already important enough so we do
not list them here".  It is trivially true and obvious ;-)

As I said, the above is for future reference for everybody; it's
cutting close to the final, so let's queue this (and the other one)
as-is.

Thanks for working on this fix.

> Helped-by: Jeff King <peff@peff.net>
> Helped-by: Alexandr Miloslavskiy <alexandr.miloslavskiy@syntevo.com>
> Helped-by: SZEDER Gábor <szeder.dev@gmail.com>
> Helped-by: Junio C Hamano <gitster@pobox.com>
> Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
> ---
>  usage.c | 20 ++++++++++++++++----
>  1 file changed, 16 insertions(+), 4 deletions(-)
>
> diff --git a/usage.c b/usage.c
> index 2fdb20086b..58fb5fff5f 100644
> --- a/usage.c
> +++ b/usage.c
> @@ -9,14 +9,26 @@
>  void vreportf(const char *prefix, const char *err, va_list params)
>  {
>  	char msg[4096];
> -	char *p;
> +	char *p, *pend = msg + sizeof(msg);
> +	size_t prefix_len = strlen(prefix);
>  
> -	vsnprintf(msg, sizeof(msg), err, params);
> -	for (p = msg; *p; p++) {
> +	if (sizeof(msg) <= prefix_len) {
> +		fprintf(stderr, "BUG!!! too long a prefix '%s'\n", prefix);
> +		abort();
> +	}
> +	memcpy(msg, prefix, prefix_len);
> +	p = msg + prefix_len;
> +	if (vsnprintf(p, pend - p, err, params) < 0)
> +		*p = '\0'; /* vsnprintf() failed, clip at prefix */
> +
> +	for (; p != pend - 1 && *p; p++) {
>  		if (iscntrl(*p) && *p != '\t' && *p != '\n')
>  			*p = '?';
>  	}
> -	fprintf(stderr, "%s%s\n", prefix, msg);
> +
> +	*(p++) = '\n'; /* we no longer need a NUL */
> +	fflush(stderr);
> +	write_in_full(2, msg, p - msg);
>  }
>  
>  static NORETURN void usage_builtin(const char *err, va_list params)

Patch
diff mbox series

diff --git a/usage.c b/usage.c
index 2fdb20086b..58fb5fff5f 100644
--- a/usage.c
+++ b/usage.c
@@ -9,14 +9,26 @@ 
 void vreportf(const char *prefix, const char *err, va_list params)
 {
 	char msg[4096];
-	char *p;
+	char *p, *pend = msg + sizeof(msg);
+	size_t prefix_len = strlen(prefix);
 
-	vsnprintf(msg, sizeof(msg), err, params);
-	for (p = msg; *p; p++) {
+	if (sizeof(msg) <= prefix_len) {
+		fprintf(stderr, "BUG!!! too long a prefix '%s'\n", prefix);
+		abort();
+	}
+	memcpy(msg, prefix, prefix_len);
+	p = msg + prefix_len;
+	if (vsnprintf(p, pend - p, err, params) < 0)
+		*p = '\0'; /* vsnprintf() failed, clip at prefix */
+
+	for (; p != pend - 1 && *p; p++) {
 		if (iscntrl(*p) && *p != '\t' && *p != '\n')
 			*p = '?';
 	}
-	fprintf(stderr, "%s%s\n", prefix, msg);
+
+	*(p++) = '\n'; /* we no longer need a NUL */
+	fflush(stderr);
+	write_in_full(2, msg, p - msg);
 }
 
 static NORETURN void usage_builtin(const char *err, va_list params)