[Bug 4031] New: huge regression in bundle performance
mercurial-bugs at selenic.com
mercurial-bugs at selenic.com
Fri Sep 6 21:25:07 CDT 2013
http://bz.selenic.com/show_bug.cgi?id=4031
Priority: normal
Bug ID: 4031
CC: mercurial-devel at selenic.com
Assignee: bugzilla at selenic.com
Summary: huge regression in bundle performance
Severity: bug
Classification: Unclassified
OS: Linux
Reporter: pitrou at free.fr
Hardware: PC
Status: UNCONFIRMED
Version: 2.7
Component: Mercurial
Product: Mercurial
After upgrading hg.python.org to 2.7, we witnessed worrying increases in CPU
activity.
(see here:
http://hg.python.org/munin/localdomain/localhost.localdomain/cpu.html - the
upgrade was done on Sep 1st around 19h).
Investigating points to bundling speed. Bundling the CPython repo (and cloning
it using either hgweb or "hg clone --pull") became horrendously slow, and the
serving hg process would eat 100% CPU for tens of minutes (as can be seen on
the graphes).
Bisecting shows the regression in "hg bundle" performance to occur at the
following changeset:
changeset: 19396:ec896f9e8894
user: Matt Mackall <mpm at selenic.com>
date: Wed Jun 19 14:17:03 2013 -0500
summary: changegroup: fix fastpath during commit
Here is a profile run of "hg bundle" with 2.7. I stopped it before the end (as
you can see, only 17% of the files were bundled after 10 minutes):
$ time hg --debug --profile bundle -a ~/cpy.bundle
[...]
bundling: Doc/library/ttk.rst 1682/9933 files (16.93%)
bundling: Doc/library/tty.rst 1683/9933 files (16.94%)
bundling: Doc/library/turtle-star.pdf 1684/9933 files (16.95%)
bundling: Doc/library/turtle-star.png 1685/9933 files (16.96%)
bundling: Doc/library/turtle-star.ps 1686/9933 files (16.97%)
^C CallCount Recursive Total(s) Inline(s) module:lineno(function)
144792142 0 332.9991 205.7596
mercurial.changelog:182(rev)
144792141 0 127.2395 127.2395
mercurial.revlog:296(rev)
144375042 0 485.4131 153.7092
mercurial.changegroup:361(<genexpr>)
144373356 0 331.7038 204.9294
mercurial.changelog:182(rev)
145145552 0 127.6158 127.6158 mercurial.revlog:296(rev)
1687 0 542.9073 57.2158
mercurial.changegroup:358(linknodes)
144375042 0 485.4131 153.7092
mercurial.changegroup:361(<genexpr>)
31012 0 0.2772 0.1031
mercurial.changegroup:362(genfilenodes)
1686 0 0.0013 0.0013 <method 'get' of 'dict'
objects>
405870 0 15.0286 15.0286 <method 'compress' of
'bz2.BZ2Compressor' objects>
664271 0 8.5781 8.5781 <method 'write' of 'file'
objects>
431324 0 7.8296 7.8296 <zlib.decompress>
41018 0 4.6015 4.6015 <mercurial.bdiff.bdiff>
338244 0 2.8564 2.8564 <method 'update' of
'_hashlib.HASH' objects>
405871 0 603.5276 2.5226 mercurial.util:951(read)
604743 0 599.8229 0.9020
mercurial.util:938(splitbig)
1211025 0 0.3627 0.3627 <len>
606283 0 0.2324 0.2324 <method 'append' of
'list' objects>
405870 0 0.2053 0.2053 <method 'join' of 'str'
objects>
604742 0 0.2017 0.2017 <method 'append' of
'collections.deque' objects>
169306 0 23.8471 2.4474
mercurial.revlog:880(revision)
357857 0 7.6280 0.6135
mercurial.revlog:853(_chunk)
169122 0 0.5953 0.5953
<mercurial.mpatch.patches>
169122 0 1.8819 0.4760
mercurial.revlog:846(_chunkraw)
169122 0 5.0975 0.4283
mercurial.revlog:944(_checkhash)
162020 0 0.4248 0.2991
mercurial.changelog:207(flags)
803871 0 7.6448 2.1306
mercurial.revlog:846(_chunkraw)
803871 0 2.2051 1.5831
mercurial.revlog:832(_getchunk)
803871 0 2.4746 1.3434
mercurial.revlog:329(end)
803871 0 0.8346 0.8346
mercurial.revlog:327(start)
interrupted!
real 10m29.000s
user 7m44.741s
sys 2m37.094s
By contrast, here is the profile of a successful "hg bundle" run with 2.6.3:
bundling: setup.py 9933/9933 files (100.00%)
bundling: setup.py 9933/9933 files (100.00%)
CallCount Recursive Total(s) Inline(s) module:lineno(function)
750034 0 72.8346 72.8346 <method 'compress' of
'bz2.BZ2Compressor' objects>
1195728 0 20.3457 20.3457 <method 'write' of 'file'
objects>
713223 0 13.8080 13.8080 <zlib.decompress>
49570 0 11.2885 11.2885 <mercurial.bdiff.bdiff>
233670 0 4.8232 4.8232 <method 'update' of
'_hashlib.HASH' objects>
750018 0 101.6833 4.8060 mercurial.util:951(read)
1100262 0 94.5480 1.7170
mercurial.util:938(splitbig)
2210455 0 0.6890 0.6890 <len>
750018 0 0.4648 0.4648 <method 'join' of 'str'
objects>
1110194 0 0.4363 0.4363 <method 'append' of
'list' objects>
1100261 0 0.3937 0.3937 <method 'append' of
'collections.deque' objects>
1440432 0 83.6890 3.9859
mercurial.changegroup:234(revchunk)
360108 0 27.1468 1.9565
mercurial.localrepo:2168(lookup)
350173 0 46.7079 0.9656
mercurial.revlog:867(revdiff)
360108 0 1.2599 0.6709
mercurial.revlog:321(parents)
360108 0 0.8004 0.5030
mercurial.changegroup:254(builddeltaheader)
360108 0 0.6690 0.4076
mercurial.changegroup:34(chunkheader)
1143568 0 11.2400 3.2241
mercurial.revlog:841(_chunkraw)
1143568 0 3.2960 2.2438
mercurial.revlog:827(_getchunk)
1143568 0 3.5130 1.9007
mercurial.revlog:329(end)
1143568 0 1.2069 1.2069
mercurial.revlog:327(start)
194657 0 31.9097 2.4732
mercurial.revlog:875(revision)
666634 0 14.6111 1.1395
mercurial.revlog:848(_chunk)
116835 0 1.0296 1.0296
<mercurial.mpatch.patches>
116835 0 1.5347 0.3567
mercurial.revlog:841(_chunkraw)
116835 0 6.3601 0.2993
mercurial.revlog:939(_checkhash)
666634 0 0.2225 0.2225 <method 'append' of
'list' objects>
1 0 182.4890 2.4295
mercurial.changegroup:60(writebundle)
750034 0 72.8346 72.8346 <method 'compress' of
'bz2.BZ2Compressor' objects>
379977 0 105.2491 0.9591
mercurial.changegroup:24(getchunk)
real 3m15.489s
user 2m36.006s
sys 0m21.933s
--
You are receiving this mail because:
You are on the CC list for the bug.
More information about the Mercurial-devel
mailing list