# Git pull stuck when Trace2 target set to Unix Stream Socket 6 messages from 2020-04-13 to 2020-04-13. Participants: Son Luong Ngoc, Taylor Blau, Jeff King, Jeff Hostetler. Thread: https://gitlist.dev/t/53214 ## Son Luong Ngoc, 2020-04-13 12:05 Subject: Git pull stuck when Trace2 target set to Unix Stream Socket Message-ID: URL: https://gitlist.dev/e/CAL3xRKceuniEOq%2BPqN15FC4-mxsWJd4%2Be2fu1Ku9q_%2B8JmR9pw%40mail.gmail.com ``` Hey folks, I am trying to write a simple git trace2 event collector and I notice that when git doing git pull with trace events being sent to a unix stream socket, the entire operation halted. Reproduce as follow: ˋˋˋ cd git/git git config trace2.eventTarget af_unix:stream:/tmp/git_trace.sock git config trace2.eventBrief false (rm /tmp/git_trace.sock | ) && nc -lkU /tmp/git_trace.sock # In a different terminal git pull # Pull stuck and never complete ˋˋˋ This does not happen when you set eventBrief to true ˋˋˋ git config trace2.eventBrief true ˋˋˋ Worth to note that if eventTarget is a file instead of a socket, everything works fine. Cheers, Son Luong. ``` ## Taylor Blau, 2020-04-13 16:00 Subject: Re: Git pull stuck when Trace2 target set to Unix Stream Socket Message-ID: <20200413160051.GB59601@syl.local> URL: https://gitlist.dev/e/20200413160051.GB59601%40syl.local In-Reply-To: ``` On Mon, Apr 13, 2020 at 02:05:00PM +0200, Son Luong Ngoc wrote: > Hey folks, > > I am trying to write a simple git trace2 event collector and I notice > that when git doing git pull with trace events being sent to a unix > stream socket, the entire operation halted. > > Reproduce as follow: > ˋˋˋ > cd git/git > git config trace2.eventTarget af_unix:stream:/tmp/git_trace.sock > git config trace2.eventBrief false > (rm /tmp/git_trace.sock | ) && nc -lkU /tmp/git_trace.sock I doubt that this is important (for a reason that I'll point out below), but it looks like your invocation here is malformed with the trailing pipe character. Did you mean to redirect the output of rm away? If so, '2>&1 >/dev/null' will do what you want. > # In a different terminal > git pull # Pull stuck and never complete > ˋˋˋ Odd. From my memory, trace2 will give up trying to connect to the socket (disabling itself and optionally printing a warning) if 'socket(2)' or 'connect(2)' set the error bit. My guess above is that you don't have a listening socket (because your shell is waiting for you to close the '|'), so there's no connection to be made. > This does not happen when you set eventBrief to true > ˋˋˋ > git config trace2.eventBrief true > ˋˋˋ Odd. What version of Git are you using? Your description makes it sound like it may be a bug, so I'd be curious to hear Jeff's interpretation of things, too. > Worth to note that if eventTarget is a file instead of a socket, > everything works fine. > > Cheers, > Son Luong. Thanks, Taylor ``` ## Jeff King, 2020-04-13 17:18 Subject: Re: Git pull stuck when Trace2 target set to Unix Stream Socket Message-ID: <20200413171812.GA8183@coredump.intra.peff.net> URL: https://gitlist.dev/e/20200413171812.GA8183%40coredump.intra.peff.net In-Reply-To: ``` On Mon, Apr 13, 2020 at 02:05:00PM +0200, Son Luong Ngoc wrote: > I am trying to write a simple git trace2 event collector and I notice > that when git doing git pull with trace events being sent to a unix > stream socket, the entire operation halted. > > Reproduce as follow: > ˋˋˋ > cd git/git > git config trace2.eventTarget af_unix:stream:/tmp/git_trace.sock > git config trace2.eventBrief false > (rm /tmp/git_trace.sock | ) && nc -lkU /tmp/git_trace.sock > > # In a different terminal > git pull # Pull stuck and never complete > ˋˋˋ I think the issue is the use of netcat as the server side. Your git-pull involves multiple simultaneously-running Git processes. But "nc -k" will only accept() a new client once the old one has disconnected. So we'd deadlock any time we have this situation: - process A opens a stream to the socket, and keeps it open - process A spawns process B and waits for it to finish - process B tries to open a stream to the socket, which will block waiting for netcat to accept() Now A cannot make forward progress until B finishes, but B will not make forward progress until A closes the socket. I was able to reproduce the issue locally, and process "A" was git-pull and process "B" was git-merge. Switching to using datagrams ("nc -u" and "af_unix:dgram") makes the problem go away, because the connections are able to interleave their packets. > This does not happen when you set eventBrief to true > ˋˋˋ > git config trace2.eventBrief true > ˋˋˋ I don't know why this would matter (and it didn't seem to in my tests). > Worth to note that if eventTarget is a file instead of a socket, > everything works fine. That makes sense, since their file writes can be interleaved. -Peff ``` ## Son Luong Ngoc, 2020-04-13 17:19 Subject: Re: Git pull stuck when Trace2 target set to Unix Stream Socket Message-ID: URL: https://gitlist.dev/e/D350F464-61DE-4EB6-BBE1-514A0C051F38%40gmail.com In-Reply-To: <20200413160051.GB59601@syl.local> ``` Hi Taylor, Thanks for the swift reply. > On Apr 13, 2020, at 18:00, Taylor Blau wrote: > I doubt that this is important (for a reason that I'll point out below), > but it looks like your invocation here is malformed with the trailing > pipe character. > > Did you mean to redirect the output of rm away? If so, '2>&1 >/dev/null' > will do what you want. It was an emailing mistake. I meant to write > rm /tmp/git_trace.sock || true So that the command is reproducible on repeated run. I must have deleted the remaining part by mistake. > Odd. From my memory, trace2 will give up trying to connect to the socket > (disabling itself and optionally printing a warning) if 'socket(2)' or > 'connect(2)' set the error bit. My guess above is that you don't have a > listening socket (because your shell is waiting for you to close the > '|'), so there's no connection to be made. There is definitely connection still, as I can still receive more events after interupting the stuck git command by Ctrl-C. > Odd. What version of Git are you using? Your description makes it > sound like it may be a bug, so I'd be curious to hear Jeff's > interpretation of things, too. 2.26.0 built from Master git/git For more info, I have created a paste to demonstrate the bug https://gist.github.com/sluongng/e14563e4ce3cc9545781ecd5a95169f6 In which, I run `git pull origin` and `git version` on a relatively stale https://gitlab.com/gitlab-org/gitlab.git local copy. You can get more information from the trace in that paste. I have annotated the moment which the stuck happened with `It stucks HERE` phrase so look for it. Cheers, Son Luong. ``` ## Taylor Blau, 2020-04-13 17:23 Subject: Re: Git pull stuck when Trace2 target set to Unix Stream Socket Message-ID: <20200413172316.GA63249@syl.local> URL: https://gitlist.dev/e/20200413172316.GA63249%40syl.local In-Reply-To: ``` On Mon, Apr 13, 2020 at 07:19:03PM +0200, Son Luong Ngoc wrote: > Hi Taylor, > > Thanks for the swift reply. > > > On Apr 13, 2020, at 18:00, Taylor Blau wrote: > > I doubt that this is important (for a reason that I'll point out below), > > but it looks like your invocation here is malformed with the trailing > > pipe character. > > > > Did you mean to redirect the output of rm away? If so, '2>&1 >/dev/null' > > will do what you want. > It was an emailing mistake. I meant to write > > rm /tmp/git_trace.sock || true For what it's worth, 'rm -f' would suffice, too, but it doesn't matter. > So that the command is reproducible on repeated run. > I must have deleted the remaining part by mistake. > > > Odd. From my memory, trace2 will give up trying to connect to the socket > > (disabling itself and optionally printing a warning) if 'socket(2)' or > > 'connect(2)' set the error bit. My guess above is that you don't have a > > listening socket (because your shell is waiting for you to close the > > '|'), so there's no connection to be made. > There is definitely connection still, as I can still receive more events after interupting the stuck git command by Ctrl-C. > > > Odd. What version of Git are you using? Your description makes it > > sound like it may be a bug, so I'd be curious to hear Jeff's > > interpretation of things, too. > 2.26.0 built from Master git/git > > For more info, I have created a paste to demonstrate the bug > https://gist.github.com/sluongng/e14563e4ce3cc9545781ecd5a95169f6 > In which, I run `git pull origin` and `git version` on a relatively stale https://gitlab.com/gitlab-org/gitlab.git local copy. > > You can get more information from the trace in that paste. > I have annotated the moment which the stuck happened with `It stucks HERE` phrase so look for it. Hmm. It sounds like maybe there is a bug. If Jeff doesn't have time to take a look, I'll try to figure out what's going on here. > Cheers, > Son Luong. Thanks, Taylor ``` ## Jeff Hostetler, 2020-04-13 18:42 Subject: Re: Git pull stuck when Trace2 target set to Unix Stream Socket Message-ID: URL: https://gitlist.dev/e/dde14102-1eeb-71dc-5333-30b21a1ef17a%40jeffhostetler.com In-Reply-To: <20200413171812.GA8183@coredump.intra.peff.net> ``` On 4/13/2020 1:18 PM, Jeff King wrote: > On Mon, Apr 13, 2020 at 02:05:00PM +0200, Son Luong Ngoc wrote: > >> I am trying to write a simple git trace2 event collector and I notice >> that when git doing git pull with trace events being sent to a unix >> stream socket, the entire operation halted. >> >> Reproduce as follow: >> ˋˋˋ >> cd git/git >> git config trace2.eventTarget af_unix:stream:/tmp/git_trace.sock >> git config trace2.eventBrief false >> (rm /tmp/git_trace.sock | ) && nc -lkU /tmp/git_trace.sock >> >> # In a different terminal >> git pull # Pull stuck and never complete >> ˋˋˋ > > I think the issue is the use of netcat as the server side. > > Your git-pull involves multiple simultaneously-running Git processes. > But "nc -k" will only accept() a new client once the old one has > disconnected. So we'd deadlock any time we have this situation: > > - process A opens a stream to the socket, and keeps it open > > - process A spawns process B and waits for it to finish > > - process B tries to open a stream to the socket, which will block > waiting for netcat to accept() > > Now A cannot make forward progress until B finishes, but B will not make > forward progress until A closes the socket. > > I was able to reproduce the issue locally, and process "A" was git-pull > and process "B" was git-merge. Thanks for the great explanation. Yes, each Git command will open its own connection to the socket, so you need your server to be able to process multiple incoming requests, such as the usual listen() loop. There is a "trace2.destinationdebug" aka GIT_TRACE2_DST_DEBUG which when set to a positive integer will print warning messages when attempting to open the trace2 files or sockets. This might help you track down issues. (These aren't on by default.) You might find it easier to set the trace2 path to that of an existing directory. Then each Git command will create a file, so you don't have to worry about interleaved output or having your server be alive at all times. You could just let the files accumulate in that directory and have a cron job process and delete them periodically. Jeff ```