Performance problem 'hg log -v'

Guido Ostkamp hg at ostkamp.fastmail.fm
Tue Sep 11 17:03:00 CDT 2007


Hello,

I've another question regarding the performance of the 'hg log -v' call.

I used the command on a file that is in the working copy, but not 
maintained in the repository, so

    hg log -v <some-file-in-working-copy-but-not-in-repository>

This command took ages. Here the output:

     CallCount     Total(s)    Inline(s) module:lineno(function)
         54976     20.2802      2.5474   mercurial.revlog:901(revision)
        +64058      4.7575      1.1449   +mercurial.revlog:851(chunk)
        +54976      2.4838      0.5502   +mercurial.revlog:510(parents)
        +54976      1.5185      0.5238   +mercurial.revlog:46(hash)
        +54976      5.1832      0.4705   +mercurial.util:1242(o)
        +54976      2.3518      0.3270   +mercurial.revlog:478(_loadindex)
         54980      3.0234      2.2126   mercurial.util:1334(__call__)
        +54980      0.5979      0.4438   +posixpath:56(join)
        +54980      0.2129      0.2117   +mercurial.util:709(__call__)
         54973      5.2141      1.8723   mercurial.changelog:139(extract)
       +109946      2.3296      0.5575   +mercurial.util:40(tolocal)
       +109946      0.2842      0.2842   +<method 'split' of 'str' objects>
        +54973      0.1630      0.1630   +<binascii.unhexlify>
        +15140      0.2991      0.1364   +mercurial.changelog:123(decode_extra)
        +54973      0.1141      0.1141   +<method 'index' of 'str' objects>
        512943      3.9084      1.5562   mercurial.revlog:242(__getitem__)
       +512943      2.0854      1.1699   +struct:77(unpack)
           +58      0.2668      0.0005   +mercurial.revlog:237(load)
         54979      1.6912      1.5303   mercurial.util:1236(<lambda>)
        +54979      0.1609      0.1609   +<method 'join' of 'str' objects>
         56416      1.5107      1.5107   <zlib.decompress>
         55034      1.7918      1.2565   mercurial.revlog:137(loadblock)
        +55034      0.2714      0.2714   +<method 'seek' of 'file' objects>
        +55034      0.1938      0.1938   +<method 'read' of 'file' objects>
       +110068      0.0701      0.0701   +<len>
            +2      0.0000      0.0000   +<max>
        512945      2.0855      1.1700   struct:77(unpack)
       +512945      0.9155      0.9155   +<method 'unpack' of 'Struct' objects>
            +1      0.0000      0.0000   +struct:35(_compile)
         64058      4.7575      1.1449   mercurial.revlog:851(chunk)
        +64058      1.0611      0.5784   +mercurial.revlog:515(start)
        +64058      0.7265      0.2887   +mercurial.revlog:519(length)
        +64058      1.7066      0.1959   +mercurial.revlog:75(decompress)
        +64056      0.0450      0.0450   +<len>
          +241      0.0727      0.0034   +mercurial.revlog:852(loadcache)
        512945      0.9155      0.9155   <method 'unpack' of 'Struct' objects>

real    0m34.234s
user    0m30.026s
sys     0m4.181s

Of course, because the file is not under Mercurials control (not in .hg), 
I got no further output.

Any idea what's causing this slow behaviour?

The much easier command

    hg status -v <some-file-in-working-copy-but-not-in-repository>

is ready within a rather short time

    real    0m1.750s
    user    0m1.466s
    sys     0m0.279s

and tells me the file is not under control. Is there possibly a check 
missing and hg searches all revlogs, although it is clear that it is not 
under control?

Regards

Guido


More information about the Mercurial-devel mailing list