Network performance problems when pulling and cloning from HTTP server
Angel Ezquerra
ezquerra at gmail.com
Mon Nov 26 08:46:25 UTC 2012
On Sun, Nov 25, 2012 at 6:40 PM, Matt Mackall <mpm at selenic.com> wrote:
> On Fri, 2012-11-23 at 07:47 +0100, Angel Ezquerra wrote:
>> On Thu, Nov 22, 2012 at 11:05 PM, Augie Fackler <raf at durin42.com> wrote:
>> >
>> > On Nov 22, 2012, at 7:03 AM, Angel Ezquerra <ezquerra at gmail.com> wrote:
>> >
>> >> On Wed, Nov 21, 2012 at 10:24 PM, Matt Mackall <mpm at selenic.com> wrote:
>> >>> On Wed, 2012-11-21 at 08:02 +0100, Angel Ezquerra wrote:
>> >>>> On Nov 20, 2012 6:55 PM, "Bryan O'Sullivan" <bos at serpentine.com> wrote:
>> >>>>>
>> >>>>> On Tue, Nov 20, 2012 at 8:30 AM, Angel Ezquerra <ezquerra at gmail.com> wrote:
>> >>
>> >> Matt, thanks for pitching in.
>> >>
>> >> I understand now the need to get the hashes, usernames, dates and
>> >> descriptions. As for also getting the diffs, that would only happen
>> >> when using the --bundle option, right? That is, calling a plain "hg
>> >> incoming" (without --bundle) should be pretty fast regardless of the
>> >> contents of the changesets themselves. Is that correct?
>> >
>> > Sadly no, incoming pulls a complete bundle, then throws it on the floor when done. In fact, 'hg help incoming' tells you that '--bundle FILE' lets you save the requested bundle to a file so you can apply it later.
>> >
>> >>
>> >>>> In any case, may I ask why you are not surprised by this?
>> >>>
>> >>> You've hit the trifecta of ways to have suboptimal performance:
>> >>>
>> >>> a) Windows
>> >>> b) large files
>> >>> c) using a protocol designed for broadband and slower on a LAN
>> >>
>> >> By protocol you mean the underlying http or mercurial's own protocol?
>> >
>> > hg's own protocol, which can use http (or ssh) as a transport.
>> >
>> >
>> >>>>> Do you have the ability to serve the repo that shows poor performance using "hg serve"? If so, it would be helpful to "hg serve --profile", do a pull from a client, then stop the server and share the profile dump.
>> >>>> C:\mercurial_tests\tmp_bigfiles_not_large>hg serve --port 7000
>> >>>> --profile --verbose
>> >>>
>> >>> ..no profile. A profile looks like this:
>> >>>
>> >>> $ hg serve --profile
>> >>> listening at http://calx:8000/ (bound to *:8000)
>> >>> [do something]
>> >>> [hit ctrl-c]
>> >>> CallCount Recursive Total(s) Inline(s) module:lineno(function)
>> >>> 4 0 1.5059 1.5058 <select.select>
>> >>> 57 46 0.0052 0.0036 <__import__>
>> >>> 1 0 0.0025 0.0013 mimetypes:205(readfp)
>> >>> 684 0 0.0006 0.0005 mercurial.config:20(__setitem__)
>> >>> 665 0 0.0007 0.0005 mimetypes:78(add_type)
>> >>> 2 0 0.0004 0.0004 <_socket.gethostbyaddr>
>> >>> 80 0 0.0008 0.0003 mercurial.config:27(update)
>> >>> 971 0 0.0003 0.0003 <method 'split' of 'str' objects>
>> >>>
>> >>
>> >> Sorry, I did not know that.
>> >>
>> >> Unfortunately, I cannot get --profile to work. Whenever I use Ctrl+C
>> >> to stop the server it just exits without printing any profile
>> >> information.
>> >>
>> >> I am running this test server on our production mercurial (windows
>> >> 2003) server, which is already using the default port. If I do:
>> >>
>> >> hg server --profile
>> >>
>> >> without specifying a port, the server exists immediately, saying
>> >> "abort: cannot start server at ':8000'", and in that case it _does_
>> >> print some profile information. However, it does not print anything if
>> >> I set a port to something other than 8000 and then I use Ctrl+C.
>> >>
>> >> I thought that perhaps --profile did not work when the --port is set.
>> >> To verify this I stopped our production server tonight and tried again
>> >> to run "hg server --profile" (without setting the port). The result is
>> >> the same (i.e. no profile information is printed when I do Ctrl+C). I
>> >> tried killing the hg process using the windows task manager but I get
>> >> the same result (no profile printed).
>> >>
>> >> What else could I do?
>> >
>> > I just verified that ^C gives me profiler output on a Mac. I don't know enough about Windows to guess why this isn't working though.
>> >
>> >
>> > The fact that archives are fast and pulls are slow suggests (to me) that computing deltas is being expensive for your use case, but that's only intuition talking. Figuring out a way to get profiler output would be the best outcome.
>> >
>> > One thing that *might* give us an idea where you'd be burning some time would be 'hg bundle --all --profile foo.bundle'. That's not exactly the same as the web server, but it might show something surprising (and therefore be helpful without me having to guess about Windows things.)
>> >
>>
>> Thank you Augie,
>>
>> I did ran "hg bundle --all --profile foo.bundle" three times. The
>> second and third times I also added --time:
>>
>> C:\mercurial_tests\tmp_bigfiles_not_large>hg bundle --all --profile foo.bundle
>> 2 changesets found
>> CallCount Recursive Total(ms) Inline(ms) module:lineno(function)
>> 26 0 85.1904 79.0038
>> <mercurial\util.pyo>:863(read)
>> +571 0 6.1801 0.3268
>> +<mercurial\util.pyo>:850(splitbig)
>> +573 0 0.0032 0.0032 +<method 'pop' of
>> 'list' objects>
>> +570 0 0.0028 0.0028 +<method 'append'
>> of 'list' objects>
>> +1143 0 0.0004 0.0004 +<len>
>> +3 0 0.0000 0.0000 +<method 'insert'
>> of 'list' objects>
>> 161 0 37.0899 37.0899 <method 'compress'
>> of 'bz2.BZ2Compressor' objects>
>> 7 0 2.7092 2.7092 <method 'read' of
>> 'file' objects>
>> 8 0 2.5599 2.5598
>> <mercurial\revlog.pyo>:107(decompress)
>> +3 0 0.0002 0.0002 +<zlib.decompress>
>> 164 0 1.3976 1.3976 <method 'write' of
>> 'file' objects>
>> 1 0 124.4743 0.6509
>> <mercurial\changegroup.pyo>:60(writebundle)
>> +161 0 37.0899 37.0899 +<method
>> 'compress' of 'bz2.BZ2Compressor' objects>
>> +163 0 1.3973 1.3973 +<method 'write'
>> of 'file' objects>
>> +1 0 0.0978 0.0978 +<method 'flush'
>> of 'bz2.BZ2Compressor' objects>
>> +1 0 0.0029 0.0029 +<method 'close'
>> of 'file' objects>
>> +1 0 0.0004 0.0004 +<open>
>> 12 0 0.5223 0.5223 <method 'update'
>> of '_hashlib.HASH' objects>
>> 571 0 6.1801 0.3268
>> <mercurial\util.pyo>:850(splitbig)
>> +31 0 5.8525 0.0227
>> +<mercurial\localrepo.pyo>:1989(gengroup)
>> +574 0 0.0008 0.0008 +<len>
>> 1 0 0.0978 0.0978 <method 'flush' of
>> 'bz2.BZ2Compressor' objects>
>> 5 0 0.0475 0.0475 <imp.load_dynamic>
>> 62 44 0.0859 0.0359 <__import__>
>> +1 0 0.0005 0.0002
>> +<mercurial\changegroup.pyo>:8(<module>)
>> +1 0 0.0005 0.0002
>> +<mercurial\context.pyo>:8(<module>)
>> +1 0 0.0029 0.0002 +<hashlib.pyo>:55(<module>)
>> +1 0 0.0038 0.0001
>> +<mercurial\revlog.pyo>:12(<module>)
>> +1 0 0.0001 0.0001
>> +<encodings\utf_8.pyo>:8(<module>)
>> 7 0 0.0306 0.0306 <mercurial.osutil.posixfile>
>>
>>
>> C:\mercurial_tests\tmp_bigfiles_not_large>hg --time bundle --all
>> --profile bar.bundle
>> 2 changesets found
>> CallCount Recursive Total(ms) Inline(ms) module:lineno(function)
>> 26 0 82.8639 80.5234
>> <mercurial\util.pyo>:863(read)
>> +571 0 2.3341 0.3113
>> +<mercurial\util.pyo>:850(splitbig)
>> +573 0 0.0034 0.0034 +<method 'pop' of
>> 'list' objects>
>> +570 0 0.0026 0.0026 +<method 'append'
>> of 'list' objects>
>> +1143 0 0.0004 0.0004 +<len>
>> +3 0 0.0000 0.0000 +<method 'insert'
>> of 'list' objects>
>> 161 0 37.0936 37.0936 <method 'compress'
>> of 'bz2.BZ2Compressor' objects>
>> 164 0 1.2516 1.2516 <method 'write' of
>> 'file' objects>
>> 7 0 0.9041 0.9041 <method 'read' of
>> 'file' objects>
>> 1 0 121.9192 0.6125
>> <mercurial\changegroup.pyo>:60(writebundle)
>> +161 0 37.0936 37.0936 +<method
>> 'compress' of 'bz2.BZ2Compressor' objects>
>> +163 0 1.2501 1.2501 +<method 'write'
>> of 'file' objects>
>> +1 0 0.0923 0.0923 +<method 'flush'
>> of 'bz2.BZ2Compressor' objects>
>> +1 0 0.0031 0.0031 +<method 'close'
>> of 'file' objects>
>> +1 0 0.0007 0.0007 +<open>
>> 8 0 0.5515 0.5513
>> <mercurial\revlog.pyo>:107(decompress)
>> +3 0 0.0002 0.0002 +<zlib.decompress>
>> 12 0 0.5342 0.5342 <method 'update'
>> of '_hashlib.HASH' objects>
>> 571 0 2.3341 0.3113
>> <mercurial\util.pyo>:850(splitbig)
>> +31 0 2.0220 0.0190
>> +<mercurial\localrepo.pyo>:1989(gengroup)
>> +574 0 0.0008 0.0008 +<len>
>> 1 0 0.0923 0.0923 <method 'flush' of
>> 'bz2.BZ2Compressor' objects>
>> 31 0 2.0220 0.0190
>> <mercurial\localrepo.pyo>:1989(gengroup)
>> +31 0 1.9997 0.0002
>> +<mercurial\revlog.pyo>:1114(group)
>> +3 0 0.0030 0.0001
>> +<mercurial\localrepo.pyo>:624(file)
>> +4 0 0.0001 0.0000
>> +<mercurial\localrepo.pyo>:1953(gennodelst)
>> +6 0 0.0000 0.0000 +<len>
>> +1 0 0.0001 0.0000
>> +<mercurial\localrepo.pyo>:270(hook)
>> 62 44 0.0180 0.0077 <__import__>
>> +1 0 0.0004 0.0003
>> +<mercurial\changegroup.pyo>:8(<module>)
>> Time: real 121.989 secs (user 59.984+0.000 sys 61.062+0.000)
>>
>> C:\mercurial_tests\tmp_bigfiles_not_large>hg --time bundle --all
>> --profile bar.bundle2
>> 2 changesets found
>> CallCount Recursive Total(ms) Inline(ms) module:lineno(function)
>> 26 0 82.6152 80.2107
>> <mercurial\util.pyo>:863(read)
>> +571 0 2.3983 0.3247
>> +<mercurial\util.pyo>:850(splitbig)
>> +573 0 0.0033 0.0033 +<method 'pop' of
>> 'list' objects>
>> +570 0 0.0025 0.0025 +<method 'append'
>> of 'list' objects>
>> +1143 0 0.0004 0.0004 +<len>
>> +3 0 0.0000 0.0000 +<method 'insert'
>> of 'list' objects>
>> 161 0 37.0642 37.0642 <method 'compress'
>> of 'bz2.BZ2Compressor' objects>
>> 164 0 1.2536 1.2536 <method 'write' of
>> 'file' objects>
>> 7 0 0.8486 0.8486 <method 'read' of
>> 'file' objects>
>> 8 0 0.6593 0.6591
>> <mercurial\revlog.pyo>:107(decompress)
>> +3 0 0.0002 0.0002 +<zlib.decompress>
>> 1 0 121.6504 0.6175
>> <mercurial\changegroup.pyo>:60(writebundle)
>> +161 0 37.0642 37.0642 +<method
>> 'compress' of 'bz2.BZ2Compressor' objects>
>> +163 0 1.2519 1.2519 +<method 'write'
>> of 'file' objects>
>> +1 0 0.0952 0.0952 +<method 'flush'
>> of 'bz2.BZ2Compressor' objects>
>> +1 0 0.0030 0.0030 +<method 'close'
>> of 'file' objects>
>> +1 0 0.0008 0.0008 +<open>
>> 12 0 0.5229 0.5229 <method 'update'
>> of '_hashlib.HASH' objects>
>> 571 0 2.3983 0.3247
>> <mercurial\util.pyo>:850(splitbig)
>> +31 0 2.0729 0.0280
>> +<mercurial\localrepo.pyo>:1989(gengroup)
>> +574 0 0.0008 0.0008 +<len>
>> 1 0 0.0952 0.0952 <method 'flush' of
>> 'bz2.BZ2Compressor' objects>
>> 31 0 2.0729 0.0280
>> <mercurial\localrepo.pyo>:1989(gengroup)
>> +31 0 2.0412 0.0002
>> +<mercurial\revlog.pyo>:1114(group)
>> +6 0 0.0001 0.0001 +<len>
>> +4 0 0.0002 0.0001
>> +<mercurial\localrepo.pyo>:1953(gennodelst)
>> +3 0 0.0031 0.0001
>> +<mercurial\localrepo.pyo>:624(file)
>> +1 0 0.0002 0.0000
>> +<mercurial\localrepo.pyo>:270(hook)
>> 62 44 0.0172 0.0081 <__import__>
>> +1 0 0.0004 0.0002
>> +<mercurial\changegroup.pyo>:8(<module>)
>> Time: real 121.711 secs (user 60.844+0.000 sys 59.844+0.000)
>>
>> So it takes 121 seconds just to do the bundle.
>
> See this recent thread:
>
> http://mercurial.markmail.org/thread/dyafoufq3nczfu5m
I just went through that thread. I applied the "obvious fix" proposed
by Matt. I did the test on my own machine, rather than on our live
server. I ran the same "hg --time bundle --all --profile" command on a
clone of the same test repository before and after applyging the fix.
The results are as follows:
1. Before the "fix":
E:\aem\Workspaces\mercurial\hg-hackable>c:\Python26\python.exe hg
--repository "C:\mercurial_tests\tmp_bigfiles_not_large" --time bundle
--all --profile foo.bundle3
2 changesets found
CallCount Recursive Total(s) Inline(s) module:lineno(function)
161 0 35.7058 35.7058 <method 'compress'
of 'bz2.BZ2Compressor' objects>
26 0 12.0127 11.3850 mercurial.util:898(read)
+571 0 0.6271 0.0583
+mercurial.util:885(splitbig)
+570 0 0.0002 0.0002 +<method 'append'
of 'collections.deque' objects>
+573 0 0.0002 0.0002 +<method 'popleft'
of 'collections.deque' objects>
+1143 0 0.0002 0.0002 +<len>
+3 0 0.0000 0.0000 +<method
'appendleft' of 'collections.deque' objects>
12 0 0.3923 0.3923 <method 'update'
of '_hashlib.HASH' objects>
1 0 47.9594 0.0890
mercurial.changegroup:60(writebundle)
+161 0 35.7058 35.7058 +<method
'compress' of 'bz2.BZ2Compressor' objects>
+1 0 0.0808 0.0808 +<method 'flush'
of 'bz2.BZ2Compressor' objects>
+163 0 0.0679 0.0679 +<method 'write'
of 'file' objects>
+1 0 0.0012 0.0012 +<method 'close'
of 'file' objects>
+1 0 0.0007 0.0007 +<open>
7 0 0.0889 0.0889 <method 'read' of
'file' objects>
1 0 0.0808 0.0808 <method 'flush' of
'bz2.BZ2Compressor' objects>
166 0 0.0684 0.0684 <method 'write' of
'file' objects>
8 0 0.0662 0.0661
mercurial.revlog:78(decompress)
+3 0 0.0001 0.0001 +<zlib.decompress>
571 0 0.6271 0.0583 mercurial.util:885(splitbig)
+31 0 0.5683 0.0147
+mercurial.localrepo:2237(gengroup)
+574 0 0.0004 0.0004 +<len>
31 0 0.5683 0.0147
mercurial.localrepo:2237(gengroup)
+31 0 0.5516 0.0001
+mercurial.revlog:1128(group)
+4 0 0.0000 0.0000
+mercurial.localrepo:2201(gennodelst)
+3 0 0.0003 0.0000
+hgext.progress:266(progress)
+3 0 0.0016 0.0000
+mercurial.localrepo:792(file)
+6 0 0.0000 0.0000 +<len>
47 30 0.0102 0.0089 <__import__>
+1 0 0.0002 0.0002
+mercurial.changegroup:8(<module>)
time: real 48.029 secs (user 42.682+0.000 sys 4.945+0.000)
2. After the "fix":
E:\aem\Workspaces\mercurial\hg-hackable>c:\Python26\python.exe hg
--repository "C:\mercurial_tests\tmp_bigfiles_not_large" --time bundle
--all --profile foo.bundle4
2 changesets found
CallCount Recursive Total(s) Inline(s) module:lineno(function)
161 0 35.5525 35.5525 <method 'compress'
of 'bz2.BZ2Compressor' objects>
12 0 0.4669 0.4669 <method 'update'
of '_hashlib.HASH' objects>
7 0 0.1025 0.1025 <method 'read' of
'file' objects>
1 0 36.6386 0.0892
mercurial.changegroup:60(writebundle)
+161 0 35.5525 35.5525 +<method
'compress' of 'bz2.BZ2Compressor' objects>
+1 0 0.0811 0.0811 +<method 'flush'
of 'bz2.BZ2Compressor' objects>
+163 0 0.0686 0.0686 +<method 'write'
of 'file' objects>
+1 0 0.0013 0.0013 +<method 'close'
of 'file' objects>
+1 0 0.0008 0.0008 +<open>
1 0 0.0811 0.0811 <method 'flush' of
'bz2.BZ2Compressor' objects>
8 0 0.0794 0.0794
mercurial.revlog:78(decompress)
+3 0 0.0001 0.0001 +<zlib.decompress>
571 0 0.7520 0.0757 mercurial.util:885(splitbig)
+31 0 0.6762 0.0182
+mercurial.localrepo:2237(gengroup)
+574 0 0.0001 0.0001 +<len>
58 0 0.0705 0.0705 <method 'join' of
'str' objects>
164 0 0.0688 0.0688 <method 'write' of
'file' objects>
47 30 0.0298 0.0279 <__import__>
+1 0 0.0014 0.0002 +hashlib:55(<module>)
+1 0 0.0003 0.0002
+mercurial.context:8(<module>)
+1 0 0.0031 0.0001
+mercurial.revlog:12(<module>)
+1 0 0.0002 0.0001
+mercurial.changegroup:8(<module>)
+1 0 0.0001 0.0001 +encodings.utf_8:8(<module>)
31 0 0.6762 0.0182
mercurial.localrepo:2237(gengroup)
+31 0 0.6558 0.0001
+mercurial.revlog:1128(group)
+4 0 0.0001 0.0000
+mercurial.localrepo:2201(gennodelst)
+3 0 0.0001 0.0000
+hgext.progress:266(progress)
+3 0 0.0020 0.0000
+mercurial.localrepo:792(file)
+6 0 0.0000 0.0000 +<len>
26 0 0.8413 0.0164
mercurial.changegroup:142(read)
time: real 36.757 secs (user 35.927+0.000 sys 0.421+0.000)
In both cases the generated bundle file is identical (same md5 checksum).
As you can see the "fix" completelly removes the impact of
"chunkbuffer.read" from the profile, in a 12 second improvement (over
48 seconds total) when the fix is applied.
I am a bit surprised that the bundle command is 3 times faster than on
the live server. The server is supposed to be faster than my machine
(which is already pretty fast). My PC has an SSD but I also tried to
place the test repo on my non-SSD hard drive and I got very similar
numbers. Maybe the fact that the server is virtualized is impacting
its performance more than we thought.
Encouraged by this good result, I repeated the test but this time I
setup a (local) web server and I pulled from it. Again, I ran the test
twice, Once before applying the "fix" and once after. In both cases
both the server and the client are running the same code (i.e. they
both had the "fix" or they didn't). In both tests a single revision
was pulled, which I stripped from the clone between the first and
second tests.
The results are as follows (note that these are from the client point
of view, the server is not interesting since --profile does not work
fro hg serve on windows):
1. Before the "fix":
E:\aem\Workspaces\mercurial\hg-hackable>hg --time --repository
"e:\mercurial_tests\clone2" pull --profile http://localhost:7000
pulling from http://localhost:7000/
searching for changes
adding changesets
adding manifests
adding file changes
added 1 changesets with 2 changes to 2 files
(run 'hg update' to get a working copy)
caching new largefiles
0 largefiles cached
CallCount Recursive Total(s) Inline(s) module:lineno(function)
21 0 54.0433 44.1384 mercurial.util:898(read)
+2165 0 9.9011 0.0045
+mercurial.util:885(splitbig)
+2183 0 0.0019 0.0019 +<method 'popleft'
of 'collections.deque' objects>
+4347 0 0.0012 0.0012 +<len>
+2164 0 0.0006 0.0006 +<method 'append'
of 'collections.deque' objects>
+20 0 0.0000 0.0000 +<method
'appendleft' of 'collections.deque' objects>
22596 0 9.8360 9.8360 <method 'recv' of
'_socket.socket' objects>
137 0 7.0115 7.0115 <built-in method compress>
4 0 2.0120 2.0120 <method 'connect'
of '_socket.socket' objects>
40 0 1.7792 1.7792 <method 'write' of
'file' objects>
10 0 0.4011 0.4011 <method 'update'
of '_hashlib.HASH' objects>
2163 0 0.1523 0.1523 <built-in method decompress>
217 135 0.1694 0.1494 <__import__>
+1 0 0.0003 0.0002 +httplib:67(<module>)
+1 0 0.0016 0.0002 +threading:1(<module>)
+1 0 0.0105 0.0002
+mercurial.httpclient:38(<module>)
+1 0 0.0017 0.0002 +urlparse:26(<module>)
+1 0 0.0101 0.0002 +urllib:23(<module>)
2168 0 9.6893 0.1164 socket:333(read)
+21742 0 9.4646 9.4646 +<method 'recv' of
'_socket.socket' objects>
+21636 0 0.0697 0.0697 +<method 'write'
of 'cStringIO.StringO' objects>
+2065 0 0.0239 0.0239 +<method
'getvalue' of 'cStringIO.StringO' objects>
+21739 0 0.0057 0.0057 +<len>
+2168 0 0.0039 0.0039 +<max>
16 0 0.0820 0.0820 <method 'read' of
'file' objects>
4 0 7.1065 0.0737
mercurial.revlog:992(compress)
+137 0 7.0115 7.0115 +<built-in method compress>
+2 0 0.0209 0.0209 +<zlib.compress>
+2 0 0.0002 0.0002 +<built-in method flush>
+139 0 0.0001 0.0001 +<method 'append' of 'list'
objects>
time: real 66.187 secs (user 33.431+0.000 sys 19.188+0.000)
2. After the "fix":
E:\aem\Workspaces\mercurial\hg-hackable>hg --time --repository
"e:\mercurial_tests\clone2" pull --profile http://localhost:7000
pulling from http://localhost:7000/
searching for changes
adding changesets
adding manifests
adding file changes
added 1 changesets with 2 changes to 2 files
(run 'hg update' to get a working copy)
caching new largefiles
0 largefiles cached
CallCount Recursive Total(s) Inline(s) module:lineno(function)
25753 0 9.8353 9.8353 <method 'recv' of
'_socket.socket' objects>
137 0 6.8949 6.8949 <built-in method compress>
4 0 1.9975 1.9975 <method 'connect'
of '_socket.socket' objects>
40 0 1.7880 1.7880 <method 'write' of
'file' objects>
10 0 0.3564 0.3564 <method 'update'
of '_hashlib.HASH' objects>
2163 0 0.1490 0.1490 <built-in method decompress>
2168 0 9.6948 0.1135 socket:333(read)
+24899 0 9.4339 9.4339 +<method 'recv' of
'_socket.socket' objects>
+24893 0 0.0820 0.0820 +<method 'write'
of 'cStringIO.StringO' objects>
+2165 0 0.0533 0.0533 +<method
'getvalue' of 'cStringIO.StringO' objects>
+24896 0 0.0054 0.0054 +<len>
+2168 0 0.0029 0.0029 +<max>
24893 0 0.0820 0.0820 <method 'write' of
'cStringIO.StringO' objects>
16 0 0.0799 0.0799 <method 'read' of
'file' objects>
4 0 6.9667 0.0712
mercurial.revlog:992(compress)
+137 0 6.8949 6.8949 +<built-in method compress>
+2 0 0.0002 0.0002 +<built-in method flush>
+139 0 0.0001 0.0001 +<method 'append'
of 'list'objects>
+2 0 0.0001 0.0001 +<zlib.compress>
+2 0 0.0001 0.0001 +<zlib.compressobj>
329 0 0.0630 0.0630 <method 'join' of
'str' objects>
+13 0 0.0000 0.0000 +collections:61(<genexpr>)
+13 0 0.0000 0.0000 +collections:60(<genexpr>)
+12 0 0.0000 0.0000
+hgext.progress:45(<genexpr>)
+3 0 0.0000 0.0000
+mercurial.wireproto:159(<genexpr>)
2165 0 0.0533 0.0533 <method 'getvalue'
of 'cStringIO.StringO' objects>
217 135 0.0689 0.0516 <__import__>
+1 0 0.0003 0.0002 +httplib:67(<module>)
+1 0 0.0017 0.0002 +urlparse:26(<module>)
+1 0 0.0114 0.0002
+mercurial.httpclient:38(<module>)
time: real 21.857 secs (user 8.081+0.000 sys 0.640+0.000)
So again there is a noticeable improvement.
Now, according to the other thread this "fix" has a negative impact on
Linux, but on Windows in seems to be a pretty noticeable improvement.
>> The "hg process" is shown on the windows task manager as using from 60
>> to 350 MB of memory (it varies), while the CPU usage is mostly 25% and
>> quite constant, although I saw it reach 28% briefly. This server is
>> virtualized. I don't know how this can affect things but I'm sure this
>> makes the "CPU usage" that windows shows less than accurate :-/ That
>> being said, the server has "4 cores" so the 25% part could indicate
>> that a whole CPU is being used. However the CPU usage chart shows that
>> all CPUs get busier during the bundle, some of them reaching brief
>> peaks of 100% but being around 50-60% most of the time, which is odd.
>
> The stats above suggest full utilization of one core. As Mercurial is
> single-threaded, that's what we'd expect.
It is odd that the windows task manager does not show that. Maybe the
virtualization is confusing the windows task manager?
Anyway, please let me know if you'd like me to perform more tests on my end.
Cheers,
Angel
More information about the Mercurial
mailing list