Re: [PATCH 02/10] t7422: fix flaky test caused by buffered stdout

From: Jeff King <peff@peff.net>
Date: Jan 7, 2025, 02:39 UTC
Message-ID: <20250107023904.GB2363@coredump.intra.peff.net>
In-Reply-To: <Z3u6lj_bpM7N93Fd@pks.im>

On Mon, Jan 06, 2025 at 12:12:22PM +0100, Patrick Steinhardt wrote:

Show 6 quoted lines

> > isn't quite right. Even without input buffering on grep's part, it may
> > be too slow to read the data. And adding a sleep as above shows that it
> > still fails with your patch.
> 
> Great. I was hoping to nerd-snipe somebody into helping me out with the
> last sentence in my above paragraph :) Happy to see that you bit.

I think I am a sucker for SIGPIPE races.

Show 11 quoted lines

> >   - I swapped out "grep" for "head". What we are matching is not
> >     relevant; the important thing is that the reader closes the pipe
> >     immediately. So I guess in that sense we could probably even just
> >     pipe to "true" or similar.
> 
> I think the grep(1) is relevant though. The test explicitly verifies
> that `--recursive` propagates SIGPIPE, so we must make sure that we
> trigger the SIGPIPE when the child process produces output, not when the
> parent process produces it. That's why we grep for "X/S", where "X" is a
> submodule -- it means that we know that it is currently the subprocess
> doing its thing.

Hmm, I see what you mean. I don't think we can do that reliably, though, or that the perl byte-stuffing is actually helping.

As I wrote it, perl always gets SIGPIPE first (because either "head" exits while it is writing, or it fills up the pipe buffer and blocks, waiting for head to exit, and then sees the pipe close).

And thus when we run git-submodule, the pipe is reliably closed and we'll see SIGPIPE.

But with grep, that does not happen. The grep will run through all of the data from perl (since it does not contain X/S), and there will not be anything left in the pipe buffer by the time git-submodule starts. So all of that data did nothing (though it fools the "sleep 1 && grep" from losing the race because perl will block until grep starts, after the sleep is finished).

And so we're left with the same race as before. git-submodule writes the X/S line, grep reads it and then tries to exit while git-submodule is writing more. And either:

  a. grep may exit immediately, before git-submodule writes any more
     data. In which case git sees SIGPIPE, which is what we want.

  a. git-submodule may write all of its data before grep exits. It will
     not block, because all of the stuff perl put in the buffer is long
     since gone, having been read by grep already. The data goes into
     the pipe buffer, and git-submodule has no idea it is discarded when
     grep exits. The test fails.

It's hard to simulate this one with a sleep, because it requires either git-submodule to write quickly, or for grep to be slow after reading the matching line but before exiting.

For the latter you can do:

diff --git a/t/t7422-submodule-output.sh b/t/t7422-submodule-output.sh
index 976f91b0eb..e2961e57dc 100755
--- a/t/t7422-submodule-output.sh
+++ b/t/t7422-submodule-output.sh
@@ -174,7 +174,7 @@ test_expect_success !MINGW 'git submodule status --recursive propagates SIGPIPE'
 		perl -le "print q{foo} for (1..33000)" &&
 		git submodule status --recursive 2>err
 		echo $?>status
-	} | grep -q X/S &&
+	} | { grep -q X/S && sleep 1; } &&
 	test_must_be_empty err &&
 	test_match_signal 13 "$(cat status)"
 '

on top of your patch, which reliably fails the test. I know that looks
kind of ridiculous and fake, but you can imagine it as that first grep
just taking a long time to call exit() and close the pipe.

It's hard to make git-submodule faster, because its output is really
coming from recursive invocations of itself. But you could imagine a
world where we do the submodule recursion in a single process, buffering
it via stdio, and then write all of the lines at once. And then
git-submodule always wins the race (it issues a single write() syscall
and then exits), and the test fails.

To make the test reliable, you'd need to pause or fill the pipe buffer
_after_ writing X/S via git-submodule but before writing the rest of the
data. Or to perhaps convince git-submodule only to write the recursive
data, and then pre-stuff the pipe as I suggested earlier. But I'm not
sure how to do the latter. Even if we ask for:

  git submodule status --recursive -- X

it will print out the status of "X" before recursing into it to show
X/S, etc, which will give us SIGPIPE in the parent submodule process,
not the recursive one.

For the former, I guess you'd need some hook that runs when we recurse
into the submodule and dumps a bunch of garbage into the pipe buffer.
But I don't think there is any such hook that runs here. Unless perhaps
you abused core.fsmonitor or something, but I don't think that's
portable.

So I don't really see a way to do this robustly.

-Peff