threads / discuss / 53214

Git pull stuck when Trace2 target set to Unix Stream Socket

Subject: Git pull stuck when Trace2 target set to Unix Stream Socket

## tl;dr

6 messages between Apr 13, 2020 and Apr 13, 2020.

replies: 5people: 4as markdown or json

Son Luong Ngoc· Apr 13, 2020, 12:05 UTC · lore
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· Apr 13, 2020, 16:00 UTC · re: Son Luong Ngoc · lore

Re: Git pull stuck when Trace2 target set to Unix Stream Socket

On Mon, Apr 13, 2020 at 02:05:00PM +0200, Son Luong Ngoc wrote:
Show 12 quoted lines
> 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.

Show 5 quoted lines
> Worth to note that if eventTarget is a file instead of a socket,
> everything works fine.
>
> Cheers,
> Son Luong.

Thanks, Taylor

Son Luong Ngoc· Apr 13, 2020, 17:19 UTC · re: Taylor Blau · lore

Re: Git pull stuck when Trace2 target set to Unix Stream Socket

Hi Taylor,
Thanks for the swift reply.
Show 7 quoted lines
> On Apr 13, 2020, at 18:00, Taylor Blau <me@ttaylorr.com> 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.

Show 5 quoted lines
> 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· Apr 13, 2020, 17:23 UTC · re: Son Luong Ngoc · lore

Re: Git pull stuck when Trace2 target set to Unix Stream Socket

On Mon, Apr 13, 2020 at 07:19:03PM +0200, Son Luong Ngoc wrote:
Show 13 quoted lines
> Hi Taylor,
>
> Thanks for the swift reply.
>
> > On Apr 13, 2020, at 18:00, Taylor Blau <me@ttaylorr.com> 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.
Show 21 quoted lines
> 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 King· Apr 13, 2020, 17:18 UTC · re: Son Luong Ngoc · lore

Re: Git pull stuck when Trace2 target set to Unix Stream Socket

On Mon, Apr 13, 2020 at 02:05:00PM +0200, Son Luong Ngoc wrote:
Show 14 quoted lines
> 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
Jeff Hostetler· Apr 13, 2020, 18:42 UTC · re: Jeff King · lore

Re: Git pull stuck when Trace2 target set to Unix Stream Socket

On 4/13/2020 1:18 PM, Jeff King wrote:
Show 35 quoted lines
> 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

← back to recent threads