Issue1985

Title "hg diff --git <file>" is slow
Priority bug Status chatting
Superseder Nosy List abuehl, cyanite, dbrakhane, djc, gward, pmezard, tonfa
Assigned To Topics 1.4, performance, regression

Created on 2010-01-13.13:58:42 by gward, last changed 2010-01-23.17:47:11 by dbrakhane.

Messages
msg11461 (view) Author: gward Date: 2010-01-14.02:50:34
tonfa:
> It the 2x slowness acceptable ? It's the cost of having a more precise 
> rename detection algorithm.

Err, I guess it's OK.  But remember, I'm running diff on a single filename.  
I don't see why rename detection enters the picture.  If I was diff'ing two 
whole changesets, sure, that would make sense... but two revisions of a 
single file?

pmezard:
> Do you have a large working directory? If so, it could be related to
> issue1955 too.

Not especially: I found this in Mercurial's own source tree, with ~1100 
files and ~10 MB in the working dir.  Not big.
msg11457 (view) Author: pmezard Date: 2010-01-13.14:50:45
Do you have a large working directory? If so, it could be related to
issue1955 too.

I will work on the copies.copies() part when I have time
msg11456 (view) Author: tonfa Date: 2010-01-13.14:46:51
It the 2x slowness acceptable ? It's the cost of having a more precise 
rename detection algorithm.
msg11455 (view) Author: gward Date: 2010-01-13.14:45:12
Forgot to mention, I have configured diff.git=True, so all my tests are
effectively of "diff --git".  Have not tested traditional diff at all.

I see the same thing as Benoit: at the head of default, "diff <file>" is
much faster than in 1.4, but still 2x slower than 1.3.

Bisecting again, it looks like it got faster on default with this change:

changeset:   9991:a7d11deb47dd
user:        Benoit Boissinot <benoit.boissinot@ens-lyon.org>
date:        Thu Dec 03 01:01:49 2009 +0100
summary:     revlog: add fast path to ancestor

But it's still ~2x slower than 1.3.
msg11454 (view) Author: tonfa Date: 2010-01-13.14:30:35
Without --git, diff isn't affected, default isn't affected but there's still 
a 2x slowdown compared to 1.3.1.
msg11453 (view) Author: tonfa Date: 2010-01-13.14:26:28
Looks fixed in the default branch, could you bisect the fix?
msg11452 (view) Author: pmezard Date: 2010-01-13.14:26:00
With and without --git ?
msg11451 (view) Author: gward Date: 2010-01-13.14:02:23
Profiling at 9750:f153af9580fe gives this:

   CallCount    Recursive    Total(ms)   Inline(ms) module:lineno(function)
         250            0     35.0934     14.4947  
mercurial.ancestor:10(ancestor)
    +2068309            0     15.1728     10.7262  
+mercurial.revlog:1121(parents)
    +1029591            0      1.8502      1.8502   +<min>
    +1029965            0      1.8224      1.8224   +<method 'pop' of 'list'
objects>
    +1105347            0      1.6422      1.6422   +<method 'append' of
'list' objects>
       +1943            0      0.1111      0.0131  
+mercurial.context:467(parents)
     2068309            0     15.1728     10.7262  
mercurial.revlog:1121(parents)
    +2068309            0      4.4466      4.4466  
+mercurial.revlog:518(parentrevs)
     2069969            0      4.4512      4.4512  
mercurial.revlog:518(parentrevs)
     1029669            0      1.8503      1.8503   <min>
     1031427            0      1.8264      1.8264   <method 'pop' of 'list'
objects>
     1108251            0      1.6467      1.6467   <method 'append' of
'list' objects>
         125            0     35.2778      0.3138  
mercurial.revlog:1118(ancestor)
        +125            0     34.9623     14.4795  
+mercurial.ancestor:10(ancestor)
        +125            0      0.0010      0.0010   +mercurial.revlog:510(node)
        +250            0      0.0006      0.0006   +mercurial.revlog:505(rev)
          +1            0      0.0002      0.0000  
+mercurial.demandimport:72(__getattribute__)
        3563            0      0.2624      0.2624   <zlib.decompress>
          70            0      0.1148      0.1148  
<mercurial.parsers.parse_manifest>
        7882            0      0.3283      0.0869  
mercurial.revlog:950(_chunkraw)
       +7882            0      0.0917      0.0570   +mercurial.revlog:522(end)
       +7882            0      0.0479      0.0479   +mercurial.revlog:520(start)
       +7882            0      0.1018      0.0462  
+mercurial.revlog:936(_getchunk)

Profiling at the head of stable shows pretty much the same thing.
msg11450 (view) Author: gward Date: 2010-01-13.13:58:42
With Mercurial 1.4.x "hg diff <file>" is very slow.  Here is an example
right in Mercurial's own source tree:

  $ ./hg --time diff -r9000:10000 mercurial/dirstate.py > /dev/null
  Time: real 12.680 secs (user 11.810+0.000 sys 0.230+0.000)

Compare with 1.3.1:

  $ /usr/local/hg-1.3/./hg --time diff -r9000:10000 mercurial/dirstate.py >
/dev/null
  Time: real 0.330 secs (user 0.270+0.000 sys 0.050+0.000)

Bisection fingers this changeset for the slowdown:

changeset:   9750:f153af9580fe
user:        Matt Mackall <mpm@selenic.com>
date:        Sat Nov 07 14:07:45 2009 -0600
summary:     merge: first part of fix for issue1327
History
Date User Action Args
2010-01-23 17:47:11dbrakhanesetnosy: + dbrakhane
2010-01-14 02:50:34gwardsetnosy: tonfa, pmezard, djc, abuehl, gward, cyanite
messages: + msg11461
title: "hg diff <file>" is slow -> "hg diff --git <file>" is slow
2010-01-13 14:50:45pmezardsetnosy: tonfa, pmezard, djc, abuehl, gward, cyanite
messages: + msg11457
2010-01-13 14:46:51tonfasetnosy: tonfa, pmezard, djc, abuehl, gward, cyanite
messages: + msg11456
2010-01-13 14:45:12gwardsetnosy: tonfa, pmezard, djc, abuehl, gward, cyanite
messages: + msg11455
2010-01-13 14:30:35tonfasetnosy: tonfa, pmezard, djc, abuehl, gward, cyanite
messages: + msg11454
2010-01-13 14:27:02cyanitesetnosy: + cyanite
2010-01-13 14:26:28tonfasetnosy: tonfa, pmezard, djc, abuehl, gward
messages: + msg11453
2010-01-13 14:26:00pmezardsetnosy: + pmezard
messages: + msg11452
2010-01-13 14:22:49tonfasetnosy: + tonfa
2010-01-13 14:18:29abuehlsetnosy: + abuehl
2010-01-13 14:06:35djcsetnosy: + djc
2010-01-13 14:02:23gwardsetstatus: unread -> chatting
messages: + msg11451
2010-01-13 13:58:42gwardcreate