Speeding up Mercurial on NFS

[Martin Geisler]

Matt Mackall <mpm at selenic.com> writes:

> On Tue, 2011-01-11 at 12:11 +0100, Martin Geisler wrote:
>
>> I agree with you that a single disk should max out like you
>> describe... but the above numbers are for a normal 7200 RPM 1 TB SATA
>> disk and a quad core i7 930.
>
> Then you're getting lucky with disk layout and read-ahead. It's very
> easy for an 'aged' directory tree to take much longer than 5 seconds
> to walk on spinning media.

Yeah, the directory is not aged in any way, it's just a clone of
OpenOffice that I made at some point.

>> > By comparison, threaded NFS lookups is all about saturating the
>> > pipe because the (cached on server) lookup is much faster than the
>> > request round trip.
>> >
>> > How many files are you walking here?
>> 
>> There are 70k files -- it is the working copy of OpenOffice,
>> changeset 67e476e04669. You sometimes talk about walking a repo with
>> 207k files, is that a public repo?
>
> Might have been Netbeans?

I just cloned it and they "only" have 98k files and 186k changesets.

>> Okay, here are tests without the delay -- raw speed on the local
>> loopback. I unmount the NFS filesystem after each test but do not
>> clear any other caches:
>> 
>>   threads  pywalker  walker
>>     1      2230 ms   1931 ms
>>     2      1857 ms   1164 ms
>>     4      2594 ms    818 ms
>>     8      2757 ms    833 ms
>>    16      2796 ms    991 ms
>>    32      2776 ms    987 ms
>> 
>> The eight (hyper-threading) cores were never maxed out while I ran
>> the tests, they only peaked up to about 50% utilization.
>
> Hmmm, how are you measuring that utilization? HT can make such numbers
> muddled. You might try comparing to a raw CPU eater (eg python -c
> 'while 1: pass') to make sure you're measuring what you think you're
> measuring.

Oh, I just looked at the graph in the Gnome System Monitor and saw that
the spikes went no further than ~50% or so. It shows 8 curves, one for
each "virtual" core.

> In principle, you should be able to match those numbers even with the
> .2ms delay. In practice, details like lock contention[1] and CPU cache
> footprint will start to matter. But not until you're at 100%
> utilization.
>
> This is where you compare to a local cache-hot walk to see how much
> more it's possible to squeeze out of this. If the local walk is 10x
> faster, there's probably a lot of room to squeeze. If it's only 2x
> faster, it may be all 'network overhead'. And the resulting CPU load
> may give you some indication whether the slack utilization with NFS is
> your fault or not. You should also consider measuring user vs sys
> times too.

Okay, as a start I have timings for a cache-hot local walk here:

   threads  pywalker  walker
     1       565 ms   259 ms
     2      1330 ms   204 ms
     4      1707 ms   440 ms
     8      1834 ms   636 ms
    16      1947 ms   739 ms
    32      1969 ms   765 ms

The CPU load was low, none of the cores went above about 40% in the
System Monitor.

I read the numbers to mean that a single threaded walk takes about 8
times longer when NFS is involved (from 259 ms to 1931 ms) and we saw
above that throwing more threads at the problem can bring that down to a
factor of 3-4 (down to 818 ms with 4 threads).

>> At first I thought this was because of how I walk the tree: each
>> worker thread scans a directory and inserts each subdirectory into a
>> queue. It then returns and grabs the next directory from the queue.
>> This gives a breadth-first traversal of the directory tree.
>
> ...and if your queue is ever empty, you're losing. Should be simple to
> instrument the queue length.

Sure! Here is a plot of the queue length over time. I just recorded the
length after each push and plotted this on the y-axis. The x-axis shows
the push-number and you can see that there are about 7200 directories in
total in the OpenOffice working copy.

The queue if never close to being empty until the very end.

-------------- next part --------------
A non-text attachment was scrubbed...
Name: tasks-8.png
Type: image/png
Size: 34027 bytes
Desc: not available
URL: <http://selenic.com/pipermail/mercurial-devel/attachments/20110112/501f2976/attachment.png>
-------------- next part --------------


-- 
Martin Geisler

aragost Trifork
Professional Mercurial support
http://aragost.com/en/services/mercurial/blog/