"hg log -q" performance (was: API question: ancestors of B that are not ancestors of A)
Greg Ward
greg-hg at gerg.ca
Wed Dec 9 16:53:32 CST 2009
On Wed, Dec 9, 2009 at 5:34 PM, Matt Mackall <mpm at selenic.com> wrote:
>> $ time hg log --follow -q -rtip:0 -P 104325
>> 104339:cf603b1018fb
>> 104336:9d06300772ae
>> [...several hundred more...]
>> 101660:7f617f192df1
>> hg log --follow -q -rtip:0 -P 104325 128.85s user 0.50s system 98%
>> cpu 2:11.68 total
>
> Hmm, that's odd. We can probably improve that. How long do 'hg log -q
>> /dev/null' take?
"hg log -q > /dev/null": ~47 sec, 99% cpu.
"hg log --follow -q > /dev/null": ~108 sec, 99% cpu.
So I profiled "log -q" of the last ~24000 changesets:
"""
time hg --profile log -q -r 80000:tip > /dev/null
CallCount Recursive Total(ms) Inline(ms) module:lineno(function)
24340 0 17.5399 1.8263 mercurial.cmdutil:805(_show)
+24340 0 4.7440 0.3199
+mercurial.templatefilters:11(stringify)
+24340 0 0.2121 0.1857
+mercurial.templater:185(__call__)
+97360 0 0.1663 0.1663
+mercurial.templater:172(__contains__)
+24340 0 0.1862 0.1557 +mercurial.ui:228(write)
+24340 0 0.1273 0.1273 +<method 'update'
of 'dict' objects>
121700 0 3.2390 1.0202
mercurial.templater:53(process)
+121700 0 1.9259 0.7851
+mercurial.templater:99(_process)
+97360 0 0.1153 0.1153 +<isinstance>
+24340 0 0.0878 0.0878 +<hasattr>
+24340 0 0.0501 0.0501
+mercurial.templater:175(load)
+24340 0 0.0397 0.0397 +<method 'pop' of
'list' objects>
316426 0 1.7139 0.9783
mercurial.revlog:269(__getitem__)
+316426 0 0.6586 0.6586 +<_struct.unpack>
+28 0 0.0769 0.0001 +mercurial.revlog:264(load)
24340 0 9.5049 0.8450
mercurial.changelog:160(read)
+24340 0 6.9379 0.8438
+mercurial.revlog:971(revision)
+48680 0 1.1508 0.2880
+mercurial.encoding:31(tolocal)
+48680 0 0.1409 0.1409 +<method 'split'
of 'str' objects>
+13214 0 0.2308 0.1247
+mercurial.changelog:26(decodeextra)
+24340 0 0.0674 0.0674 +<binascii.unhexlify>
24340 0 6.9379 0.8438
mercurial.revlog:971(revision)
+24340 0 0.7640 0.2530
+mercurial.revlog:514(parents)
+24340 0 0.5593 0.2439 +mercurial.revlog:50(hash)
+24340 0 1.2927 0.1897
+mercurial.revlog:950(_chunkraw)
+24340 0 0.8916 0.1283
+mercurial.revlog:480(_loadindex)
+24341 0 2.0217 0.1102
+mercurial.revlog:957(_chunk)
121700 0 1.9259 0.7851
mercurial.templater:99(_process)
+73020 0 0.2438 0.2438 +<built-in method search>
+24340 0 0.2622 0.1196
+mercurial.templater:102(get)
+24340 0 0.5085 0.0942
+mercurial.templater:83(_filter)
+48680 0 0.0686 0.0686 +<built-in method groups>
+48680 0 0.0576 0.0576 +<built-in method span>
48680 0 4.1351 0.6834
mercurial.util:206(increasingchunks)
+121700 0 3.2390 1.0202
+mercurial.templater:53(process)
+97360 0 0.0968 0.0968 +<method 'append'
of 'list' objects>
+97360 0 0.0765 0.0765 +<len>
+24340 0 0.0395 0.0395 +<method 'join' of
'str' objects>
316427 0 0.6586 0.6586 <_struct.unpack>
24338 0 0.6195 0.6195 <zlib.decompress>
97362 0 1.1141 0.6086 mercurial.revlog:520(start)
+97362 0 0.5056 0.3006
+mercurial.revlog:269(__getitem__)
hg --profile log -q -r 80000:tip > /dev/null 17.88s user 3.20s system
98% cpu 21.383 total
"""
This is with current hg-crew.
Greg
More information about the Mercurial-devel
mailing list