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@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
(note: I've reverted hg.p.o to 2.6.3 in the meantime)
For the record, I've verified the following patch solves the problem (and passes the test suite): diff --git a/mercurial/changegroup.py b/mercurial/changegroup.py --- a/mercurial/changegroup.py +++ b/mercurial/changegroup.py @@ -354,11 +354,11 @@ class bundle10(object): progress(msgbundling, None) mfs.clear() + needed = set(cl.rev(x) for x in clnodes) def linknodes(filerevlog, fname): if fastpathlinkrev: ln, llr = filerevlog.node, filerevlog.linkrev - needed = set(cl.rev(x) for x in clnodes) def genfilenodes(): for r in filerevlog: linkrev = llr(r)
Nice, thanks. Could you send that patch to the Mercurial mailing list? http://mercurial.selenic.com/wiki/ContributingChanges I have a feeling we at FB saw this too but didn't realize it was a regression.
(And it's a bugfix so please flag it with stable.)
Sent. I hope my commit message isn't clueless, as I only have a very vague knowledge of the mercurial internals.
Fixed by http://selenic.com/repo/hg/rev/fd4f612f7cb6 Antoine Pitrou <solipsis@pitrou.net> bundle: fix performance regression when bundling file changes (issue4031) Somewhere before 2.7, a change [ec896f9e8894] was committed that entailed a large performance regression when bundling (and therefore remote cloning) repositories. For each file in the repository, it would recompute the set of needed changesets even though it is the same for all files. This computation would dominate bundle runtimes according to profiler output (by 10x or more). (please test the fix)
(applying the patch solved the perf issues on hg.python.org)