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

6 messages, 4 authors, 2021-11-30 · open the first message on its own page

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

From: Junio C Hamano <hidden>
Date: 2021-11-30 05:13:17

Eric Sunshine [off-list ref] writes:
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.
If stdout and stderr are both going to the same place (e.g. the
user's terminal), this would probably is an improvement, but if the
standard output is going to a pipe talking to another process, which
may care when the output is flushed, this may hurt.

But as long as the calling code is using stdio, it cannot precisely
control when the buffered contents are flushed anyway, so as long as
the caller has working standard output, this may be OK.

Hits from "git grep -l vreportf" includes http-backend.c; where is
its standard output connected, and can it have some unflushed stuff
in its standard output buffer, I wonder?
quoted hunk
 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);
 }

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

From: Jeff King <hidden>
Date: 2021-11-30 07:14:34

On Mon, Nov 29, 2021 at 09:13:10PM -0800, Junio C Hamano wrote:
Eric Sunshine [off-list ref] writes:
quoted
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.
If stdout and stderr are both going to the same place (e.g. the
user's terminal), this would probably is an improvement, but if the
standard output is going to a pipe talking to another process, which
may care when the output is flushed, this may hurt.

But as long as the calling code is using stdio, it cannot precisely
control when the buffered contents are flushed anyway, so as long as
the caller has working standard output, this may be OK.
Yeah, I think this logic applies to the "happy" case. Any caller which
is depending on the time of flush is already racily buggy.

What I wonder about is the error case. What can happen if flushing
fails? There are two interesting cases I can think of:

  - flushing causes an error (which is quite likely, as we may
    vreportf() because of an error on stdout). We should be OK, as we do
    not care about the return value here, nor eventually checking
    ferror(stdout). We may overwrite errno, but at this point in
    vreportf(), we are committed to whatever error we're going to show
    (and obviously the stderr flush below could cause the same issues).

  - flushing causes us to block. This implies our stdout is connected to
    a pipe or socket, and the other side is not expecting to read. A
    plausible case here is a client sending us a big input which we find
    to be bogus (maybe index-pack checking an incoming pack). We call
    die() to complain about the input, but the client is still writing.
    In the current code, we'd write out our error and then exit; the
    client would get SIGPIPE or a write() error and abort. But with a
    flush here, we could block writing back to the client, and now we're
    in a deadlock; they are trying to write to us but we are no longer
    reading, and we are blocked trying to get out a little bit of
    irrelevant stdout data.

    I _think_ we're probably OK here. The scenario above means that the
    caller is already doing asynchronous I/O via stdio and is subject to
    deadlock. Because the segment of buffer we try to flush here _could_
    have been flushed already under the hood, which would have caused
    the same blocking. A careful caller might be using select() or
    similar to decide when it is OK to write, but I find it highly
    unlikely they'd be using stdio in that case.

Of the two, the deadlock case worries me more, just because it would be
quiet subtle and racy. As I said, I think we may be OK, but my reasoning
there is pretty hand-wavy.

-Peff

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

From: Jeff King <hidden>
Date: 2021-11-30 07:23:37

On Tue, Nov 30, 2021 at 02:14:25AM -0500, Jeff King wrote:
  - flushing causes us to block. This implies our stdout is connected to
    a pipe or socket, and the other side is not expecting to read. A
    plausible case here is a client sending us a big input which we find
    to be bogus (maybe index-pack checking an incoming pack). We call
    die() to complain about the input, but the client is still writing.
    In the current code, we'd write out our error and then exit; the
    client would get SIGPIPE or a write() error and abort. But with a
    flush here, we could block writing back to the client, and now we're
    in a deadlock; they are trying to write to us but we are no longer
    reading, and we are blocked trying to get out a little bit of
    irrelevant stdout data.

    I _think_ we're probably OK here. The scenario above means that the
    caller is already doing asynchronous I/O via stdio and is subject to
    deadlock. Because the segment of buffer we try to flush here _could_
    have been flushed already under the hood, which would have caused
    the same blocking. A careful caller might be using select() or
    similar to decide when it is OK to write, but I find it highly
    unlikely they'd be using stdio in that case.

Of the two, the deadlock case worries me more, just because it would be
quiet subtle and racy. As I said, I think we may be OK, but my reasoning
there is pretty hand-wavy.
Thinking on this a bit more: I guess as soon as we exit libc would call
the equivalent of fflush(NULL) anyway, and try that same flush. So in a
sense this is just ordering a bit differently, and not introducing any
new problems. (Unless libc is clever enough to avoid blocking, but that
doesn't seem like something we could or should rely on in general).

-Peff

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

From: Eric Sunshine <hidden>
Date: 2021-11-30 14:15:17

On Tue, Nov 30, 2021 at 2:14 AM Jeff King [off-list ref] wrote:
  - flushing causes us to block. This implies our stdout is connected to
    a pipe or socket, and the other side is not expecting to read. A
    plausible case here is a client sending us a big input which we find
    to be bogus (maybe index-pack checking an incoming pack). We call
    die() to complain about the input, but the client is still writing.
    In the current code, we'd write out our error and then exit; the
    client would get SIGPIPE or a write() error and abort. But with a
    flush here, we could block writing back to the client, and now we're
    in a deadlock; they are trying to write to us but we are no longer
    reading, and we are blocked trying to get out a little bit of
    irrelevant stdout data.

Of the two, the deadlock case worries me more, just because it would be
quiet subtle and racy. As I said, I think we may be OK, but my reasoning
there is pretty hand-wavy.
Flushing stdout only if it is attached to a terminal:

    if (isatty(1))
        fflush(stdout);

should address this potential-deadlock concern, I think(?). It's
rather ugly, though, and entering the realm of
too-much-special-casing; it feels like it has the potential of heading
down a rabbit hole where we find more cases which need to be handled
specially.

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

From: Ævar Arnfjörð Bjarmason <hidden>
Date: 2021-11-30 15:17:46

On Tue, Nov 30 2021, Jeff King wrote:
On Tue, Nov 30, 2021 at 02:14:25AM -0500, Jeff King wrote:
quoted
  - flushing causes us to block. This implies our stdout is connected to
    a pipe or socket, and the other side is not expecting to read. A
    plausible case here is a client sending us a big input which we find
    to be bogus (maybe index-pack checking an incoming pack). We call
    die() to complain about the input, but the client is still writing.
    In the current code, we'd write out our error and then exit; the
    client would get SIGPIPE or a write() error and abort. But with a
    flush here, we could block writing back to the client, and now we're
    in a deadlock; they are trying to write to us but we are no longer
    reading, and we are blocked trying to get out a little bit of
    irrelevant stdout data.

    I _think_ we're probably OK here. The scenario above means that the
    caller is already doing asynchronous I/O via stdio and is subject to
    deadlock. Because the segment of buffer we try to flush here _could_
    have been flushed already under the hood, which would have caused
    the same blocking. A careful caller might be using select() or
    similar to decide when it is OK to write, but I find it highly
    unlikely they'd be using stdio in that case.

Of the two, the deadlock case worries me more, just because it would be
quiet subtle and racy. As I said, I think we may be OK, but my reasoning
there is pretty hand-wavy.
Thinking on this a bit more: I guess as soon as we exit libc would call
the equivalent of fflush(NULL) anyway, and try that same flush. So in a
sense this is just ordering a bit differently, and not introducing any
new problems. (Unless libc is clever enough to avoid blocking, but that
doesn't seem like something we could or should rely on in general).
I think this change is probably OK too, but let's not forget about
warning() and error(). I.e. we are not always on a path to a fatal error
with vreportf(), that's just with die(), usage() and BUG().

So e.g. the warning you added recently (and we ejected before v2.34.0)
about encodings in "git log" would behave differently with this
change.

I think probably for the better, but we should also consider those
cases.

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

From: Jeff King <hidden>
Date: 2021-11-30 20:52:06

On Tue, Nov 30, 2021 at 04:10:37PM +0100, Ævar Arnfjörð Bjarmason wrote:
On Tue, Nov 30 2021, Jeff King wrote:
quoted
On Tue, Nov 30, 2021 at 02:14:25AM -0500, Jeff King wrote:
quoted
  - flushing causes us to block. This implies our stdout is connected to
    a pipe or socket, and the other side is not expecting to read. A
    plausible case here is a client sending us a big input which we find
    to be bogus (maybe index-pack checking an incoming pack). We call
    die() to complain about the input, but the client is still writing.
    In the current code, we'd write out our error and then exit; the
    client would get SIGPIPE or a write() error and abort. But with a
    flush here, we could block writing back to the client, and now we're
    in a deadlock; they are trying to write to us but we are no longer
    reading, and we are blocked trying to get out a little bit of
    irrelevant stdout data.

    I _think_ we're probably OK here. The scenario above means that the
    caller is already doing asynchronous I/O via stdio and is subject to
    deadlock. Because the segment of buffer we try to flush here _could_
    have been flushed already under the hood, which would have caused
    the same blocking. A careful caller might be using select() or
    similar to decide when it is OK to write, but I find it highly
    unlikely they'd be using stdio in that case.

Of the two, the deadlock case worries me more, just because it would be
quiet subtle and racy. As I said, I think we may be OK, but my reasoning
there is pretty hand-wavy.
Thinking on this a bit more: I guess as soon as we exit libc would call
the equivalent of fflush(NULL) anyway, and try that same flush. So in a
sense this is just ordering a bit differently, and not introducing any
new problems. (Unless libc is clever enough to avoid blocking, but that
doesn't seem like something we could or should rely on in general).
I think this change is probably OK too, but let's not forget about
warning() and error(). I.e. we are not always on a path to a fatal error
with vreportf(), that's just with die(), usage() and BUG().
My gut feeling is that warning() and error() would encounter a subset of
the problems that die() would. Because die() is actually changing the
program state in a much more drastic way (by exiting), whereas error and
warning would continue and eventually flush anyway. They might care more
about things like errno being touched if they continue on, but they
already must assume that vreportf() can affect errno (because of the
existing flush and write on stderr).

Likewise BUG() is an interesting one. It doesn't call exit(), but
instead abort(). So unlike die(), it doesn't actually flush, and the "we
would fflush(NULL) on exit anyway" caveat above does not apply.

I still suspect that any caller doing async I/O on stdio like this is
already flaky, though. It could have decided to flush and blocked during
any write.

-Peff
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help