RFH: spawning pager takes long time when when unconnected from network

RFH: spawning pager takes long time when when unconnected from network

[Eric Raible]

Hello All -

I've got a weird one which I haven't been able to figure out.
The problem is that git sometimes takes a long time (~5-10 seconds)
before producing output when it needs to internally spawn a pager.

This only occurs when I'm not plugged in to a network.
When I'm plugged in everything operates at the normal speed.

This would be slow: git diff some-branch
This would be fast: git diff some-branch | less

Unsetting core.pager (IOW setting core.pager="") is also fast.

Tracking this down has been problematic, because I suspect it's
got to do with the relative timing of the two processes, and I
don't know the code well enough to figure out an effective debugging
strategy.

Any ideas or things to try?

Thanks - Eric

Re: RFH: spawning pager takes long time when when unconnected from network

[Eric Raible]

Sorry, I meant to send that to gmane.comp.version-control.msysgit,
since that's what I'm running (1.6.1.2.549.g547e.dirty).

- Eric

Re: RFH: spawning pager takes long time when when unconnected from network

[Johannes Sixt]

Eric Raible schrieb:
> I've got a weird one which I haven't been able to figure out.
> The problem is that git sometimes takes a long time (~5-10 seconds)
> before producing output when it needs to internally spawn a pager.
> 
> This only occurs when I'm not plugged in to a network.
> When I'm plugged in everything operates at the normal speed.
> 
> This would be slow: git diff some-branch
> This would be fast: git diff some-branch | less
> 
> Unsetting core.pager (IOW setting core.pager="") is also fast.

Do you have a directory in your PATH that points to a disconnected network
drive? Do you use the default pager settings, or did you customize the pager?

-- Hannes

Re: RFH: spawning pager takes long time when when unconnected from network

[Eric Raible]

Johannes Sixt <j.sixt <at> viscovery.net> writes:

> Do you have a directory in your PATH that points to a disconnected network
> drive? Do you use the default pager settings, or did you customize the pager?

All components in my path are local.

Every time I toggle between core.pager=less and core.ager=less (to disable it)
it's slow the first time on either setting, then fast on subsequent runs.

It feels seems like something is trying to read something from the network,
timing out, and caching the result.  But as far as I know everything is
local on my machine.

There are two ways of avoiding the delay: explicitly piping to less
(so that stdout is not a tty), or setting core.pager="".

This started happening a few weeks ago (I update my git build often)
when pager wasn't specified.  I suppose I could bisect it, but I'm
kinda swamped with $dayjob at the moment.

Re: RFH: spawning pager takes long time when when unconnected from network

[Johannes Schindelin]

Hi,

On Tue, 10 Feb 2009, Eric Raible wrote:

> Johannes Sixt <j.sixt <at> viscovery.net> writes:
> 
> > Do you have a directory in your PATH that points to a disconnected network
> > drive? Do you use the default pager settings, or did you customize the pager?
> 
> All components in my path are local.

Could you run it with GIT_TRACE=<file>?

Ciao,
Dscho

Re: RFH: spawning pager takes long time when when unconnected from network

[Eric Raible]

On Tue, Feb 10, 2009 at 2:24 AM, Johannes Schindelin
<Johannes.Schindelin@gmx.de> wrote:
> Hi,
>
> On Tue, 10 Feb 2009, Eric Raible wrote:
>
>> Johannes Sixt <j.sixt <at> viscovery.net> writes:
>>
>> > Do you have a directory in your PATH that points to a disconnected network
>> > drive? Do you use the default pager settings, or did you customize the pager?
>>
>> All components in my path are local.
>
> Could you run it with GIT_TRACE=<file>?
>
> Ciao,
> Dscho
>

The first thing I tried was to set GIT_TRACE=1, and it doesn't give much:
trace: built-in: git 'diff' 'ss' '--name-only'
trace: run_command: 'sh' '-c' 'less'

The long pause in question begins after the above output is produced
but before the list of files is shown.  The output is identical when setting
GIT_TRACE to a file.

When I pipe the git diff to less or set core.pager="",
then obviously it doesn't call run_command.

Since I can't really reproduce this in the debugger
(because the "bug" is an intermittent delay of 3-10 seconds), I tried
littering the code with trace_printf's.  Didn't really help, partially because
after the dup2 (which is part of spawning the pager process)
they don't on stdout any longer.  Now that I know about setting
GIT_TRACE to a file perhaps this is worth trying again.

But once it started to look like the delay was in the xdiff machinery,
I figured I was chasing a side-effect, and that the real problem was
some interaction between the two processes.  That's when I sent
my first RFH  to the list.

- Eric

Re: RFH: spawning pager takes long time when when unconnected from network

[Johannes Schindelin]

Hi,

On Tue, 10 Feb 2009, Eric Raible wrote:

> On Tue, Feb 10, 2009 at 2:24 AM, Johannes Schindelin
> <Johannes.Schindelin@gmx.de> wrote:
>
> > On Tue, 10 Feb 2009, Eric Raible wrote:
> >
> >> Johannes Sixt <j.sixt <at> viscovery.net> writes:
> >>
> >> > Do you have a directory in your PATH that points to a disconnected network
> >> > drive? Do you use the default pager settings, or did you customize the pager?
> >>
> >> All components in my path are local.
> >
> > Could you run it with GIT_TRACE=<file>?
> 
> The first thing I tried was to set GIT_TRACE=1, and it doesn't give much:
> trace: built-in: git 'diff' 'ss' '--name-only'
> trace: run_command: 'sh' '-c' 'less'
> 
> The long pause in question begins after the above output is produced
> but before the list of files is shown.  The output is identical when setting
> GIT_TRACE to a file.
> 
> When I pipe the git diff to less or set core.pager="",
> then obviously it doesn't call run_command.

You could also try to set it to /bin/false, just so you know if the delay 
is caused by the shell startup.

> Since I can't really reproduce this in the debugger (because the "bug" 
> is an intermittent delay of 3-10 seconds), I tried littering the code 
> with trace_printf's.  Didn't really help, partially because after the 
> dup2 (which is part of spawning the pager process) they don't on stdout 
> any longer.  Now that I know about setting GIT_TRACE to a file perhaps 
> this is worth trying again.
> 
> But once it started to look like the delay was in the xdiff machinery,
> I figured I was chasing a side-effect, and that the real problem was
> some interaction between the two processes.  That's when I sent
> my first RFH  to the list.

In my experience, such intermittent delays are often triggered by some 
(mostly unnecessary) calls to either DNS (which might hang for quite some 
time) or domain controllers (same).  These can be triggered by shell 
startup looking for the user or host name.

However, I am just fishing here, as I cannot begin to get an idea what is 
happening on your side.

Also, it does not help that the platform is Windows, an OS I am mostly 
unfamiliar with.  But there have to be profiling tools for that platform 
where you should be able to see what function is blocking (I assume it is 
a blocking call, of course).

Ciao,
Dscho

Re: RFH: spawning pager takes long time when when unconnected from network

[Jeff King]

On Tue, Feb 10, 2009 at 02:53:31AM -0800, Eric Raible wrote:

> The first thing I tried was to set GIT_TRACE=1, and it doesn't give much:
> trace: built-in: git 'diff' 'ss' '--name-only'
> trace: run_command: 'sh' '-c' 'less'
> 
> The long pause in question begins after the above output is produced
> but before the list of files is shown.  The output is identical when setting
> GIT_TRACE to a file.

Does your shell run a .profile or similar, and if so, is there anything
in it that might touch the network?

-Peff

Re: RFH: spawning pager takes long time when when unconnected from network

[Andreas Ericsson]

Eric Raible wrote:
> On Tue, Feb 10, 2009 at 2:24 AM, Johannes Schindelin
> <Johannes.Schindelin@gmx.de> wrote:
>> Hi,
>>
>> On Tue, 10 Feb 2009, Eric Raible wrote:
>>
>>> Johannes Sixt <j.sixt <at> viscovery.net> writes:
>>>
>>>> Do you have a directory in your PATH that points to a disconnected network
>>>> drive? Do you use the default pager settings, or did you customize the pager?
>>> All components in my path are local.
>> Could you run it with GIT_TRACE=<file>?
>>
>> Ciao,
>> Dscho
>>
> 
> The first thing I tried was to set GIT_TRACE=1, and it doesn't give much:
> trace: built-in: git 'diff' 'ss' '--name-only'
> trace: run_command: 'sh' '-c' 'less'
> 
> The long pause in question begins after the above output is produced
> but before the list of files is shown.  The output is identical when setting
> GIT_TRACE to a file.
> 

Might be a stupid question, but do you have anything network mounted
anywhere in your $PATH?

Do you get the same delay with an absolute path to less in core.pager?

-- 
Andreas Ericsson                   andreas.ericsson@op5.se
OP5 AB                             www.op5.se
Tel: +46 8-230225                  Fax: +46 8-230231

Re: RFH: spawning pager takes long time when when unconnected from network

[Eric Raible]

On Tue, Feb 10, 2009 at 3:03 AM, Johannes Schindelin
<Johannes.Schindelin@gmx.de> wrote:
> Hi,
>
> You could also try to set it to /bin/false, just so you know if the delay
> is caused by the shell startup.
>
> In my experience, such intermittent delays are often triggered by some
> (mostly unnecessary) calls to either DNS (which might hang for quite some
> time) or domain controllers (same).  These can be triggered by shell
> startup looking for the user or host name.
>
> However, I am just fishing here, as I cannot begin to get an idea what is
> happening on your side.
>
> Also, it does not help that the platform is Windows, an OS I am mostly
> unfamiliar with.  But there have to be profiling tools for that platform
> where you should be able to see what function is blocking (I assume it is
> a blocking call, of course).
>
> Ciao,
> Dscho

Toggling core.pager btwn /bin/false and less is slow the first time,
then quick subsequent times.  Setting core.pager to "echo no pager"
gives the same behavior.

What would be handy is a windows version of strace, but the one
that I found doesn't seem functional.  gdb is useless for this
(so far, anyway).    I think it's time to sleep on this.

Thanks - Eric

Re: RFH: spawning pager takes long time when when unconnected from network

[Eric Raible]

On Tue, Feb 10, 2009 at 3:07 AM, Jeff King <peff@peff.net> wrote:
>> The long pause in question begins after the above output is produced
>> but before the list of files is shown.  The output is identical when setting
>> GIT_TRACE to a file.
>
> Does your shell run a .profile or similar, and if so, is there anything
> in it that might touch the network?
>
> -Peff
>

My shell is the standard vanilla msysgit shell, with no customizations.
It does of course seem that something is touching the network, but I
have no idea what that might be.  Nothing in my path, that's for sure.

- Eric

Re: RFH: spawning pager takes long time when when unconnected from network

[Jay Soffian]

On Tue, Feb 10, 2009 at 6:55 AM, Eric Raible <raible@gmail.com> wrote:
> My shell is the standard vanilla msysgit shell, with no customizations.
> It does of course seem that something is touching the network, but I
> have no idea what that might be.  Nothing in my path, that's for sure.

If you plug into the network, but statically assign yourself a bogus
IP so that you don't get anywhere, does the same thing happen? If so,
then perhaps you can sniff your network interface to see what the
traffic is.

j.