Hi Gábor, On Mon, 13 Jan 2020, SZEDER Gábor wrote: > On Mon, Jan 13, 2020 at 08:29:22AM +0000, Johannes Schindelin via GitGitGadget wrote: > > From: Johannes Schindelin > > > > As noticed by Gábor Szeder, if we want to run `git add -p` with > > redirected input through `test_must_fail` in the test suite, we must > > expect that a SIGPIPE can happen due to `stdin` coming to its end. > > I don't think this issue is related to the redirected input: I > modified that flaky test to send "unlimited" data to 'git add's stdin, > i.e.: > > /usr/bin/yes | test_must_fail force_color git add -p > > and the test with --stress still failed with SIGPIPE all the same and > just as fast. > > After looking into it, the issue seems to be sending data to the > broken diffFilter process. Ouch. Thank you for investigating. For my education, how did you debug this? I could not find a way to identify *what* caused that SIGPIPE... > So in that test the diff is "filtered" through 'echo too-short', which > exits real fast, and doesn't read its standard input at all (well, apart > from e.g. the usual kernel buffering that might happen on a pipe between > the two processes). Making sure that the diffFilter process reads all > the data before exiting, i.e. changing it to: > > test_config interactive.diffFilter "cat >/dev/null ; echo too-short" && > > made the test reliable, with over 2000 --stress repetitions, and that > with only a single "y" on 'git add's stdin. Ah, my diff filter simply ignores the `stdin`... That's easy enough to fix, and since real-world diff filters probably won't just blatantly ignore the input, I think it is legitimate to change the test. > Now, merely tweaking the test is clearly insufficient, because we not > only want the test to be realiable, but we want 'git add' to die > gracefully when users out there mess up their configuration. I think it is sufficient to tweak the test, but I agree that a better error message might be good when users out there mess up their configuration. > Ignoring SIGPIPE can surely accomplish that, but I'm not sure about > the scope. I mean your patch seems to ignore SIGPIPE basically for > almost the whole 'git add -(i|p)' process, but perhaps it should be > limited only to the surroundings of the pipe_command() call running > the diffFilter, and be done as part of the next patch adding the 'if > (diff_filter)' block. Right. Very heavy-handed, and probably inviting unwanted side effects. > Furthermore, I'm worried that by simply ignoring SIGPIPE we might just > ignore a more fundamental issue in pipe_command(): shouldn't that > function be smart enough not to write() to a fd that has no one on the > other side to read it in the first place?! > > So, when the diffFilter process exits unexpectedly early, then the > poll() call in pipe_command() -> pump_io() -> pump_io_round() returns > with success and usually sets 'revents' for the child process' stdin > to 12 (i.e. 'POLLOUT | POLLERR'; gah, how I hate unnamed constants :). > Unfortunately, at that point we don't take any special action on > POLLERR, but call xwrite() to try to write to the dead fd anyway, > which then promptly triggers SIGPIPE. (This is what usually happens > when stepping through the statements of those functions in a debugger, > and the diffFilter process has all the time in the world to exit.) > > We could handle POLLERR with a patch like this: > > --- >8 --- > > Subject: run-command: handle POLLERR in pump_io_round() to reduce risk of SIGPIPE > > diff --git a/run-command.c b/run-command.c > index 3449db319b..57093f0acc 100644 > --- a/run-command.c > +++ b/run-command.c > @@ -1416,25 +1416,31 @@ static int pump_io_round(struct io_pump *slots, int nr, struct pollfd *pfd) > if (poll(pfd, pollsize, -1) < 0) { > if (errno == EINTR) > return 1; > die_errno("poll failed"); > } > > for (i = 0; i < nr; i++) { > struct io_pump *io = &slots[i]; > > if (io->fd < 0) > continue; > > - if (!(io->pfd->revents & (POLLOUT|POLLIN|POLLHUP|POLLERR|POLLNVAL))) > + if (io->pfd->revents & POLLERR) { > + io->error = ECONNRESET; /* What should we report to the caller? */ > + close(io->fd); > + io->fd = -1; > + continue; > + } > + if (!(io->pfd->revents & (POLLOUT|POLLIN|POLLHUP|POLLNVAL))) > continue; > > if (io->type == POLLOUT) { > ssize_t len = xwrite(io->fd, > io->u.out.buf, io->u.out.len); > if (len < 0) { > io->error = errno; > close(io->fd); > io->fd = -1; > } else { > io->u.out.buf += len; > io->u.out.len -= len; > > --- >8 --- > > Unfortunately #1, this changes the error 'git add -p' dies with from: > > error: mismatched output from interactive.diffFilter > > to: > > error: failed to run 'echo too-short' > > It might affect other commands as well, but FWIW the test suite > doesn't catch any. Hmm. My first impression is that the error message could be a bit better, but that it is probably a good thing to have. It would have helped _me_ understand the issue at hand. > Unfortunately #2, the above patch doesn't completely eliminates the > SIGPIPE, but only (greatly) reduces its probability. It is possible > that: > > - poll() returns with success and indicating a writable fd without > any error, i.e. 'revents = 4'. > > - the bogus diffFilter exits, closing its stdin. > > - 'git add' attempts to xwrite() to the now closed fd, and triggers > a SIGPIPE right away. > > This happens much rarer, 'GIT_TEST_ADD_I_USE_BUILTIN=1 > ./t3701-add-interactive.sh -r 39,49 --stress-jobs=<4*nr-of-cores> > --stress' tends to take over 200 repetitions. The patch below > reproduces it fairly reliably by adding two strategically-placed > sleep()s, with a bit of extra debug output: > > --- >8 --- > > diff --git a/add-patch.c b/add-patch.c > index d8dafa8168..0fd017bbd3 100644 > --- a/add-patch.c > +++ b/add-patch.c > @@ -421,6 +421,7 @@ static int parse_diff(struct add_p_state *s, const struct pathspec *ps) > filter_cp.git_cmd = 0; > filter_cp.use_shell = 1; > strbuf_reset(&s->buf); > + fprintf(stderr, "about to run diffFilter\n"); > if (pipe_command(&filter_cp, > colored->buf, colored->len, > &s->buf, colored->len, > diff --git a/run-command.c b/run-command.c > index 57093f0acc..49ae88a922 100644 > --- a/run-command.c > +++ b/run-command.c > @@ -1419,6 +1419,7 @@ static int pump_io_round(struct io_pump *slots, int nr, struct pollfd *pfd) > die_errno("poll failed"); > } > > + sleep(2); > for (i = 0; i < nr; i++) { > struct io_pump *io = &slots[i]; > > @@ -1435,8 +1436,11 @@ static int pump_io_round(struct io_pump *slots, int nr, struct pollfd *pfd) > continue; > > if (io->type == POLLOUT) { > - ssize_t len = xwrite(io->fd, > + ssize_t len; > + fprintf(stderr, "attempting to xwrite() %lu bytes to a fd with revents flags 0x%hx\n", io->u.out.len, io->pfd->revents); > + len = xwrite(io->fd, > io->u.out.buf, io->u.out.len); > + fprintf(stderr, "after xwrite()\n"); > if (len < 0) { > io->error = errno; > close(io->fd); > diff --git a/t/t3701-add-interactive.sh b/t/t3701-add-interactive.sh > index 12ee321707..acffc9af37 100755 > --- a/t/t3701-add-interactive.sh > +++ b/t/t3701-add-interactive.sh > @@ -561,7 +561,7 @@ test_expect_success 'detect bogus diffFilter output' ' > git reset --hard && > > echo content >test && > - test_config interactive.diffFilter "echo too-short" && > + test_config interactive.diffFilter "sleep 1 ; echo too-short" && > printf y >y && > test_must_fail force_color git add -p ' > > --- >8 --- > > and 'GIT_TEST_ADD_I_USE_BUILTIN=1 ./t3701-add-interactive.sh -r 39,49' > fails with: > > + test_must_fail force_color git add -p > about to run diffFilter > attempting to xwrite() 224 bytes to a fd with revents flags 0x4 > test_must_fail: died by signal 13: force_color git add -p > > I don't understand why we get SIGPIPE right away instead of some error > that we can act upon (ECONNRESET?). Isn't it buffered? In any case, I would take the above-mentioned patch, even if it makes it "only" less likely to hit `SIGPIPE`. > FWIW, it fails the same way not only on my box, but on Travis CI's Linux > and OSX images as well. > > https://travis-ci.org/szeder/git/jobs/636446843#L2937 > > > Cc'ing Peff for all things SIGPIPE :) who also happens to be the > author of both pipe_command() and that now flaky test. I'll go with Peff's suggestion to use `sed 1d` instead of `echo too-short`. Thanks, Dscho