Hi git Experts,
I believe we've encountered a bug in git. I built the latest, git 2.16.3, and it still appears to be a problem. I'm not a git expert and my C is ridiculously rusty but I think a co-worker and I figured it out... apologies if we are incorrect in any assumptions (as I do not wish to waste anyone's time).
The location of the problem is in credential.c, run_credential_helper()... this code:
...
fp = xfdopen(helper.in, "w");
credential_write(c, fp);
fclose(fp);
..
Which I think needs to become something like this:
fp = xfdopen(helper.in, "w");
sigchain_push(SIGPIPE, SIG_IGN);
credential_write(c, fp);
fclose(fp);
sigchain_pop(SIGPIPE);
The basics are that we wrote a credential helper in Go and, for the store action, it simply exits 0. It is fast. This is similar to the example here:
https://git-scm.com/book/en/v2/Git-Tools-Credential-Storage#_a_custom_credential_cache
Which is, of course, in Ruby, not Go (so, not so fast). It exits if it is not a get cred helper action without reading stdin. Anyhow, for our credential helper the store operation completes very quickly. What we've found is that occasionally the git command will be killed off just after running the credential store operation. We can see that our credential helper is being fired up (it has a debug mode) and it quickly exits. We can see that git dies on the fclose(fp) by putting trace_printf() calls before and after that fclose in the git source code (ie: the trace message before the fclose() prints, the trace message after the fclose does not).
Our belief is that the write is buffered and written at the time of fclose()... and that the credential helper tool has already exited "sometimes" (as it is very fast, but even so this doesn't fail very often). For those times when our cred helper has exited "quickly enough", a SIGPIPE can be generated... and, as SIGPIPE is not ignored, git goes "kaboom!" and dies.
To catch this scenario we wrote a simple hack Perl tool to run a bunch of serial git ls-remote commands like so:
#!/usr/cisco/bin/perl -w
$ENV{'GIT_TRACE'} = 2;
$ENV{'GIT_TRACE_CURL'} = 2;
$ENV{'GIT_TRACE_PERFORMANCE'} = 1;
$ENV{'GIT_TRACE_PACKET'} = 1;
for ( my $i = 1; $i<=100000; $i++) {
print("Run: $i\n");
my $output = `/ws/brady-sjc/git/git-2.16.3/bin/git ls-remote https://hostname.company.com/git/path/repo.git HEAD 2>&1`;
if ( $? != 0 ) {
print("FAIL: output:\n$output\n");
exit(1);
}
}
exit(0);
The problem seemed to come up most commonly on older linux VM's... in this case running 2.6.18-416.el5 #1 SMP. The tool will iterate for a while and then, boom, it blows up (usually within 1000 iterations, sometimes a couple/few thousand but usually well before that).
Anyhow... we did a few things to test our theory that it is, indeed, SIGPIPE causing git to exit:
1) My co-worker modified our credential manager to read in the data sent by git before exiting... that solved the problem as we accept the data written so the child is still there and no SIGPIPE is generated... this is our current workaround (so we are OK, but would be good to fix this in the git code we think)
2) I modified the above code to use a signal handler in credential.c (instead of SIG_IGN) and put a trace_printf() and an exit(1) inside the signal handler... similar to the problem we're seeing it'll run a bunch successfully until, boom, timing is hit such that the child exits quickly enough and causes the SIGPIPE to occur at which point git is killed.... so using the cheesy Perl test script it ran through a couple hundred iterations fine and then a SIGPIPE was seen and it died in the signal handler I wrote... so clearly SIGPIPE is being generated but only occasionally (it is timing based, so occurs only now and then... and we almost never see it on some of our boxes)
3) I modified the git code (using our old cred helper which exits quickly) per the above recommended credential.c changes (you folks can likely do a better fix)... and re-run the Perl test script... no longer fails now that we are ignoring SIGPIPE (ran about 20,000+ iterations).
Note that the build-in credential manager was not failing... it reads the cred helper store data so it would not have the problem.
Let me know if you need any additional information... and thanks for your time and consideration.
Erik
brady@xxxxxxxxx
