[RFC PATCH] vreportf: ensure sensible ordering of normal and error output

Subsystems: the rest

STALE1717d

10 messages, 3 authors, 2021-12-01 · open the first message on its own page

[RFC PATCH] vreportf: ensure sensible ordering of normal and error output

From: Eric Sunshine <hidden>
Date: 2021-11-30 04:40:30

The order in which the stdout and stderr streams are flushed is not
guaranteed to be the same across platforms or `libc` implementations.
This lack of determinism can lead to anomalous and potentially confusing
output if normal (stdout) output is flushed after error (stderr) output.
For instance, the following output which clearly indicates a failure due
to a fatal error:

    % git worktree add ../foo bar
    Preparing worktree (checking out 'bar')
    fatal: 'bar' is already checked out at '.../wherever'

has been reported[1] on Microsoft Windows to appear as:

    % git worktree add ../foo bar
    fatal: 'bar' is already checked out at '.../wherever'
    Preparing worktree (checking out 'bar')

which may confuse the reader into thinking that the command somehow
recovered and ran to completion despite the error.

Rather than attempting to address this issue on a case by case basis,
address it by making vreportf() -- which is the heart of error-reporting
functions die(), error(), warn(), etc. -- flush stdout before emitting
the error message to stderr.

[1]: https://lore.kernel.org/git/CA+34VNLj6VB1kCkA=MfM7TZR+6HgqNi5-UaziAoCXacSVkch4A@mail.gmail.com/T/

Signed-off-by: Eric Sunshine <redacted>
---

This is RFC because I naturally worry about potential fallout from
making a change to such a core function. I can't think of any case that
it wouldn't be advantageous to flush stdout before stderr, so this
change _seems_ safe, however, it may be that I'm just not imaginative
enough, hence my hesitancy.

 usage.c | 1 +
 1 file changed, 1 insertion(+)
diff --git a/usage.c b/usage.c
index c7d233b0de..0fc7640b25 100644
--- a/usage.c
+++ b/usage.c
@@ -27,6 +27,7 @@ void vreportf(const char *prefix, const char *err, va_list params)
 	}
 
 	*(p++) = '\n'; /* we no longer need a NUL */
+	fflush(stdout);
 	fflush(stderr);
 	write_in_full(2, msg, p - msg);
 }
-- 
2.34.1.75.gabe6bb3905

Re: [RFC PATCH] vreportf: ensure sensible ordering of normal and error output

From: Jeff King <hidden>
Date: 2021-11-30 07:21:35

On Mon, Nov 29, 2021 at 11:39:46PM -0500, Eric Sunshine wrote:
The order in which the stdout and stderr streams are flushed is not
guaranteed to be the same across platforms or `libc` implementations.
This lack of determinism can lead to anomalous and potentially confusing
output if normal (stdout) output is flushed after error (stderr) output.
For instance, the following output which clearly indicates a failure due
to a fatal error:

    % git worktree add ../foo bar
    Preparing worktree (checking out 'bar')
    fatal: 'bar' is already checked out at '.../wherever'

has been reported[1] on Microsoft Windows to appear as:

    % git worktree add ../foo bar
    fatal: 'bar' is already checked out at '.../wherever'
    Preparing worktree (checking out 'bar')

which may confuse the reader into thinking that the command somehow
recovered and ran to completion despite the error.

Rather than attempting to address this issue on a case by case basis,
address it by making vreportf() -- which is the heart of error-reporting
functions die(), error(), warn(), etc. -- flush stdout before emitting
the error message to stderr.
I left some thoughts on whether this flush is safe elsewhere in the
thread. But for this particular case, two things occur to me:

  - shouldn't status messages like this go to stderr anyway? I know some
    people follow the "unless it is an error, it should not to go
    stderr" philosophy. But I think in general our approach in Git is
    more "if it is the main output of the program, it goes to stdout; if
    it is chatter or progress for the user, it goes to stderr".

  - the reason it works consistently on glibc is that stdout to a
    terminal is line buffered by default, so the "preparing" line is
    flushed immediately. If that isn't the case on Windows, should we
    consider calling setlinebuf() preemptively when isatty(1)?

    That only covers most cases, of course (both to a terminal, or
    separated stdout/stderr). Even on Linux, if you do:

      git worktree add ../foo bar >out 2>&1

    you'll get the stderr result before stdout. That implies again to me
    that this kind of message really ought to be part of the stderr
    stream.

-Peff

Re: [RFC PATCH] vreportf: ensure sensible ordering of normal and error output

From: Eric Sunshine <hidden>
Date: 2021-11-30 14:06:07

On Tue, Nov 30, 2021 at 2:21 AM Jeff King [off-list ref] wrote:
On Mon, Nov 29, 2021 at 11:39:46PM -0500, Eric Sunshine wrote:
quoted
Rather than attempting to address this issue on a case by case basis,
address it by making vreportf() -- which is the heart of error-reporting
functions die(), error(), warn(), etc. -- flush stdout before emitting
the error message to stderr.
I left some thoughts on whether this flush is safe elsewhere in the
thread. But for this particular case, two things occur to me:

  - shouldn't status messages like this go to stderr anyway? I know some
    people follow the "unless it is an error, it should not to go
    stderr" philosophy. But I think in general our approach in Git is
    more "if it is the main output of the program, it goes to stdout; if
    it is chatter or progress for the user, it goes to stderr".
I considered this as well and agree that it would be a nicer localized
fix, but...

(1) I don't think the practice is documented anywhere, so people --
including me when I wrote builtin/worktree.c -- might not know about
it. Indeed, we don't seem to be entirely consistent about doing it
this way. Randomly picking submodule-helper.c, for instance, I see
status-like messages going to stdout:

    printf(_("Entering '%s'\n"), displaypath);
    printf(_("Synchronizing submodule url for '%s'\n"), ...);

    if (...)
        format = _("Cleared directory '%s'\n");
    else
        format = _("Could not remove submodule work tree '%s'\n");
    printf(format, displaypath);

(2) With git-worktree being four or five years old, for
backward-compatibility concerns, I worry that "that ship has sailed",
where 'that' is the freedom to relocate those status-like messages
from stdout to stderr. I don't want to break tooling which exists
around git-worktree.

I'd be happy to be wrong on the second point -- indeed, git-worktree
is still marked "experimental" in the man-page, but that may not mean
anything this late in the game -- and submit a patch which places
git-worktree's status-like messages on stderr instead of stdout.
Thoughts?
  - the reason it works consistently on glibc is that stdout to a
    terminal is line buffered by default, so the "preparing" line is
    flushed immediately. If that isn't the case on Windows, should we
    consider calling setlinebuf() preemptively when isatty(1)?
I'll let the Windows experts chime in on this (Dscho?). For all I
know, that might introduce a bad performance regression on that
platform under whatever terminal-like or pseudo-tty-like emulation
they are using.

Re: [RFC PATCH] vreportf: ensure sensible ordering of normal and error output

From: Eric Sunshine <hidden>
Date: 2021-11-30 15:03:25

On Tue, Nov 30, 2021 at 9:05 AM Eric Sunshine [off-list ref] wrote:
(2) With git-worktree being four or five years old, for
backward-compatibility concerns, I worry that "that ship has sailed",
where 'that' is the freedom to relocate those status-like messages
from stdout to stderr. I don't want to break tooling which exists
around git-worktree.

I'd be happy to be wrong on the second point -- indeed, git-worktree
is still marked "experimental" in the man-page, but that may not mean
anything this late in the game -- and submit a patch which places
git-worktree's status-like messages on stderr instead of stdout.
Thoughts?
If that ship has indeed sailed, then perhaps the best and safest thing
to do is admit that git-worktree is an outlier in terms of sending
status-like messages to stdout, and just sprinkle the necessary
fflush(stdout) around in builtin/worktree.c and live with that
localized ugliness. Thoughts?

Re: [RFC PATCH] vreportf: ensure sensible ordering of normal and error output

From: Jeff King <hidden>
Date: 2021-11-30 20:47:18

On Tue, Nov 30, 2021 at 09:05:54AM -0500, Eric Sunshine wrote:
quoted
  - shouldn't status messages like this go to stderr anyway? I know some
    people follow the "unless it is an error, it should not to go
    stderr" philosophy. But I think in general our approach in Git is
    more "if it is the main output of the program, it goes to stdout; if
    it is chatter or progress for the user, it goes to stderr".
I considered this as well and agree that it would be a nicer localized
fix, but...

(1) I don't think the practice is documented anywhere, so people --
including me when I wrote builtin/worktree.c -- might not know about
it. Indeed, we don't seem to be entirely consistent about doing it
this way. Randomly picking submodule-helper.c, for instance, I see
status-like messages going to stdout:

    printf(_("Entering '%s'\n"), displaypath);
    printf(_("Synchronizing submodule url for '%s'\n"), ...);

    if (...)
        format = _("Cleared directory '%s'\n");
    else
        format = _("Could not remove submodule work tree '%s'\n");
    printf(format, displaypath);
Yeah, we've definitely not been consistent here. There's no silver
bullet for this aside from vigilance during review, but probably laying
out guidelines could help.

Here's a past discussion (that actually goes the other way: somebody
complaining that stderr should be on stdout!) where I laid out my mental
model:

  https://lore.kernel.org/git/20110907215716.GJ13364@sigill.intra.peff.net/
(2) With git-worktree being four or five years old, for
backward-compatibility concerns, I worry that "that ship has sailed",
where 'that' is the freedom to relocate those status-like messages
from stdout to stderr. I don't want to break tooling which exists
around git-worktree.
IMHO it would be OK to change these. They are, after all, marked for
translation, so they're not reliably machine-readable anyway. It's
possible that some script could not be parsing them, but just trying to
redirect them. Or even keying on content in stderr as a sign of an error
(as tcl likes to do). But I don't think that's a guarantee we want to be
bound by.

See 68b939b2f0 (clone: send diagnostic messages to stderr, 2013-09-18)
for a similar case in the past.
I'd be happy to be wrong on the second point -- indeed, git-worktree
is still marked "experimental" in the man-page, but that may not mean
anything this late in the game -- and submit a patch which places
git-worktree's status-like messages on stderr instead of stdout.
Thoughts?
I'm in favor. :)

-Peff

Re: [RFC PATCH] vreportf: ensure sensible ordering of normal and error output

From: Eric Sunshine <hidden>
Date: 2021-12-01 02:36:57

On Tue, Nov 30, 2021 at 3:47 PM Jeff King [off-list ref] wrote:
On Tue, Nov 30, 2021 at 09:05:54AM -0500, Eric Sunshine wrote:
quoted
(1) I don't think the practice is documented anywhere, so people --
including me when I wrote builtin/worktree.c -- might not know about
it. Indeed, we don't seem to be entirely consistent about doing it
this way. Randomly picking submodule-helper.c, for instance, I see
status-like messages going to stdout:
Yeah, we've definitely not been consistent here. There's no silver
bullet for this aside from vigilance during review, but probably laying
out guidelines could help.

Here's a past discussion (that actually goes the other way: somebody
complaining that stderr should be on stdout!) where I laid out my mental
model:

  https://lore.kernel.org/git/20110907215716.GJ13364@sigill.intra.peff.net/
Thanks for the reference. I'll take a stab at adding a blurb about
this to CodingGuidelines.
quoted
(2) With git-worktree being four or five years old, for
backward-compatibility concerns, I worry that "that ship has sailed",
where 'that' is the freedom to relocate those status-like messages
from stdout to stderr. I don't want to break tooling which exists
around git-worktree.
IMHO it would be OK to change these. They are, after all, marked for
translation, so they're not reliably machine-readable anyway. It's
possible that some script could not be parsing them, but just trying to
redirect them. Or even keying on content in stderr as a sign of an error
(as tcl likes to do). But I don't think that's a guarantee we want to be
bound by.
That's a good point about them being marked for translation. It also
reminds me that we made some reasonably significant changes to this
exact message in 2c27002a0a (worktree: improve message when creating a
new worktree, 2018-04-24), and we didn't hear any complaints, let
alone complaints about tool breakage.
See 68b939b2f0 (clone: send diagnostic messages to stderr, 2013-09-18)
for a similar case in the past.
Nice. This and the above make me feel much more comfortable with the
idea of changing git-worktree to send these sorts of messages to
stderr rather than stdout.
quoted
I'd be happy to be wrong on the second point -- indeed, git-worktree
is still marked "experimental" in the man-page, but that may not mean
anything this late in the game -- and submit a patch which places
git-worktree's status-like messages on stderr instead of stdout.
Thoughts?
I'm in favor. :)
Thanks. I'll drop this RFC patch and resubmit with a patch which just
fixes git-worktree to be chatty on stderr instead of stdout.

Re: [RFC PATCH] vreportf: ensure sensible ordering of normal and error output

From: Eric Sunshine <hidden>
Date: 2021-12-01 05:38:54

On Tue, Nov 30, 2021 at 9:36 PM Eric Sunshine [off-list ref] wrote:
On Tue, Nov 30, 2021 at 3:47 PM Jeff King [off-list ref] wrote:
quoted
On Tue, Nov 30, 2021 at 09:05:54AM -0500, Eric Sunshine wrote:
quoted
(1) I don't think the practice is documented anywhere, so people --
including me when I wrote builtin/worktree.c -- might not know about
it. Indeed, we don't seem to be entirely consistent about doing it
this way. Randomly picking submodule-helper.c, for instance, I see
status-like messages going to stdout:
Yeah, we've definitely not been consistent here. There's no silver
bullet for this aside from vigilance during review, but probably laying
out guidelines could help.
Thanks for the reference. I'll take a stab at adding a blurb about
this to CodingGuidelines.
I just posted a patch which updates CodingGuidelines to talk a bit about this:
https://lore.kernel.org/git/20211201053214.2902-1-sunshine@sunshineco.com/

"breaking" command output message parsing (was: [RFC PATCH] vreportf: ensure sensible ordering of normal and error output)

From: Ævar Arnfjörð Bjarmason <hidden>
Date: 2021-12-01 13:59:12

On Tue, Nov 30 2021, Eric Sunshine wrote:
On Tue, Nov 30, 2021 at 9:05 AM Eric Sunshine [off-list ref] wrote:
quoted
(2) With git-worktree being four or five years old, for
backward-compatibility concerns, I worry that "that ship has sailed",
where 'that' is the freedom to relocate those status-like messages
from stdout to stderr. I don't want to break tooling which exists
around git-worktree.

I'd be happy to be wrong on the second point -- indeed, git-worktree
is still marked "experimental" in the man-page, but that may not mean
anything this late in the game -- and submit a patch which places
git-worktree's status-like messages on stderr instead of stdout.
Thoughts?
If that ship has indeed sailed, then perhaps the best and safest thing
to do is admit that git-worktree is an outlier in terms of sending
status-like messages to stdout, and just sprinkle the necessary
fflush(stdout) around in builtin/worktree.c and live with that
localized ugliness. Thoughts?
I really don't think that ship has sailed at all. We're at full liberty
to change these error messages, and have even done so for some plumbing
in the past (being sensitive to what sort of messages, sometimes they
are important).

See e.g. my 9144ba4cf52 (remote: add meaningful exit code on
missing/existing, 2020-10-27), that was a case where we knew about a
in-the-wild parser of the output, and git-remote is in the (I suppose
"pseudo-plumbing?") "Ancillary Commands" category.

I think the one grey area here is as in 9144ba4cf52 where we'd expect
people to reasonably script around these commands, and parsing the
output was the only way to accomplish something reasonable. E.g. in that
case automation around adding remotes & the handling of failure
scenarios. The case of [1] for "git pull" is another potential recent
one. I.e. someone grepping "Everything up-to-date".

From some brief skimming of the worktree.c code that doesn't seem to
apply, i.e. it's just chattyness.

I doubt anyone cares if it's blathering about "preparing a worktree" or
whatever, it just matters if "git worktree add" and the like fail with
non-zero, but perhaps there's cases of conflated states, as in that case
of "git remote" and "git pull".

1. https://lore.kernel.org/git/211130.86a6hleo84.gmgdl@evledraar.gmail.com/

Re: "breaking" command output message parsing (was: [RFC PATCH] vreportf: ensure sensible ordering of normal and error output)

From: Eric Sunshine <hidden>
Date: 2021-12-01 14:36:32

On Wed, Dec 1, 2021 at 8:59 AM Ævar Arnfjörð Bjarmason [off-list ref] wrote:
On Tue, Nov 30 2021, Eric Sunshine wrote:
quoted
On Tue, Nov 30, 2021 at 9:05 AM Eric Sunshine [off-list ref] wrote:
quoted
(2) With git-worktree being four or five years old, for
backward-compatibility concerns, I worry that "that ship has sailed",
where 'that' is the freedom to relocate those status-like messages
from stdout to stderr. I don't want to break tooling which exists
around git-worktree.

I'd be happy to be wrong on the second point -- indeed, git-worktree
is still marked "experimental" in the man-page, but that may not mean
anything this late in the game -- and submit a patch which places
git-worktree's status-like messages on stderr instead of stdout.
Thoughts?
If that ship has indeed sailed, then perhaps the best and safest thing
to do is admit that git-worktree is an outlier in terms of sending
status-like messages to stdout, and just sprinkle the necessary
fflush(stdout) around in builtin/worktree.c and live with that
localized ugliness. Thoughts?
I really don't think that ship has sailed at all. We're at full liberty
to change these error messages, and have even done so for some plumbing
in the past (being sensitive to what sort of messages, sometimes they
are important).
Just to be clear for other readers, I wasn't talking about changing
error messages but rather changing the destination of the "chatty"
messages from stdout to stderr. (I think you probably understand that
even though you typed "error message" above.)
From some brief skimming of the worktree.c code that doesn't seem to
apply, i.e. it's just chattyness.

I doubt anyone cares if it's blathering about "preparing a worktree" or
whatever, it just matters if "git worktree add" and the like fail with
non-zero, but perhaps there's cases of conflated states, as in that case
of "git remote" and "git pull".
Peff had already managed to allay my worries about that ship having
sailed[1], so that I decided[2] to drop the RFC patch and resubmit as
a patch which moves the git-worktree "chatty" messages from stdout to
stderr. Nevertheless, it's nice to hear an independent confirmation
about that ship.

[1]: https://lore.kernel.org/git/YaaN0pibKWgjcVk3@coredump.intra.peff.net/
[2]: https://lore.kernel.org/git/CAPig+cT+YfgBG3Aqszp+y7iy_megboECZy3NkMqUjBj7=Z661A@mail.gmail.com/

Re: [RFC PATCH] vreportf: ensure sensible ordering of normal and error output

From: Ævar Arnfjörð Bjarmason <hidden>
Date: 2021-12-01 21:25:08

On Tue, Nov 30 2021, Jeff King wrote:
On Tue, Nov 30, 2021 at 09:05:54AM -0500, Eric Sunshine wrote:
quoted
quoted
  - shouldn't status messages like this go to stderr anyway? I know some
    people follow the "unless it is an error, it should not to go
    stderr" philosophy. But I think in general our approach in Git is
    more "if it is the main output of the program, it goes to stdout; if
    it is chatter or progress for the user, it goes to stderr".
I considered this as well and agree that it would be a nicer localized
fix, but...

(1) I don't think the practice is documented anywhere, so people --
including me when I wrote builtin/worktree.c -- might not know about
it. Indeed, we don't seem to be entirely consistent about doing it
this way. Randomly picking submodule-helper.c, for instance, I see
status-like messages going to stdout:

    printf(_("Entering '%s'\n"), displaypath);
    printf(_("Synchronizing submodule url for '%s'\n"), ...);

    if (...)
        format = _("Cleared directory '%s'\n");
    else
        format = _("Could not remove submodule work tree '%s'\n");
    printf(format, displaypath);
Yeah, we've definitely not been consistent here. There's no silver
bullet for this aside from vigilance during review, but probably laying
out guidelines could help.

Here's a past discussion (that actually goes the other way: somebody
complaining that stderr should be on stdout!) where I laid out my mental
model:

  https://lore.kernel.org/git/20110907215716.GJ13364@sigill.intra.peff.net/
...and a third way (which git doesn't conform to at all), which is that
std*err* is really what we should be using for errors only.

You shouldn't write anything that isn't an error there, or at least
that's what I've seen some software in the wild assume.

I've run into occasional problems with git over the years because it
writes to stderr routinely for non-errors, which flies in the face
assumptions made by various third-party software that assumes the
"that's for errors" model of the world.

E.g. look at the (very useful) "chronic" utility, which is in
"moreutils" in Debian. From its manpage:

   -e  Stderr triggering. Triggers output when stderr output length is non-zero.
       Without -e chronic needs non-zero return value to trigger output.

       In this mode, chronic's return value will be 2 if the command's
       return value is 0 but the command printed to stderr.

Right now I'm failing to recall what, but I remember dealing with that
behavior from git in some other contexts.
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help