[darcs-users] darcs2 performance regression

[Gwern Branwen]

On 2008.04.30 09:37:22 -0700, Simon Marlow <simonmarhaskell at gmail.com> scribbled 1.2K characters:
> I've switched to using darcs2 locally (no repo changes yet, just to see
> how well it works as a drop-in replacement).  It seems to be noticeably
> slower for many of the operations I do day to day.
>
> Here's an example, doing 'darcs whatsnew' on the GHC testsuite
> repository (http://darcs.haskell.org/testsuite):
>
> $ time /usr/bin/darcs w -s
> M ./tests/ghc-regress/ghc-e/should_run/Makefile +3
> M ./tests/ghc-regress/ghc-e/should_run/all.T -1 +1
> A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs
> A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout
> 0.97s real   0.24s user   0.09s system   34% /usr/bin/darcs w -s
> $ time darcs2 w -s
> M ./tests/ghc-regress/ghc-e/should_run/Makefile +3
> M ./tests/ghc-regress/ghc-e/should_run/all.T -1 +1
> A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs
> A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout
> 8.03s real   6.98s user   0.46s system   92% darcs w -s
>
> 8x slower!  (and no progress messages)
>
> yesterday I noticed that an amend-record in the GHC repo was quite slow,
> and the progress message reported that it was reading the inventory.
>
> I hope this is of use to someone...
>
> Cheers,
> 	Simon

That's interesting to know. Could you perhaps paste the output of whatsnew (or even better, attach a patch)? I want to test the whatsnew against a local version I have of darcs (one which has the 4096 patch lispy mentioned and also uses mmap in one place, which could help a lot), but when I guess at those changes, I have a very quick whatsnew:

gwern at localhost:2962~/testsuite>time whatsnew [ 6:24PM]
hunk ./tests/ghc-regress/ghc-e/should_run/Makefile 22
+
+
+
hunk ./tests/ghc-regress/ghc-e/should_run/all.T 9
+
addfile ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs
hunk ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs 1
+foo bar
addfile ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout
hunk ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout 1
+foo bar
darcs whatsnew  0.07s user 0.07s system 85% cpu 0.163 total
gwern at localhost:2963~/testsuite>time whatsnew -s [ 6:24PM]
M ./tests/ghc-regress/ghc-e/should_run/Makefile +3
M ./tests/ghc-regress/ghc-e/should_run/all.T +1
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout
darcs whatsnew -s  0.08s user 0.05s system 93% cpu 0.138 total
gwern at localhost:2966~/testsuite>time whatsnew -s [ 6:26PM]
M ./tests/ghc-regress/ghc-e/should_run/Makefile +3
M ./tests/ghc-regress/ghc-e/should_run/all.T +1
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout
darcs whatsnew -s  0.10s user 0.03s system 81% cpu 0.159 total
gwern at localhost:2966~/testsuite>time whatsnew -s [ 6:29PM]
M ./tests/ghc-regress/ghc-e/should_run/Makefile +3
M ./tests/ghc-regress/ghc-e/should_run/all.T +1
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout
darcs whatsnew -s  0.06s user 0.07s system 62% cpu 0.207 total
gwern at localhost:2966~/testsuite>time whatsnew -s [ 6:29PM]
M ./tests/ghc-regress/ghc-e/should_run/Makefile +3
M ./tests/ghc-regress/ghc-e/should_run/all.T +1
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout
darcs whatsnew -s  0.08s user 0.05s system 94% cpu 0.137 total
gwern at localhost:2966~/testsuite>time whatsnew -s [ 6:29PM]
M ./tests/ghc-regress/ghc-e/should_run/Makefile +3
M ./tests/ghc-regress/ghc-e/should_run/all.T +1
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout
darcs whatsnew -s  0.09s user 0.05s system 63% cpu 0.221 total

-----

I'm not going to claim the whatsnew -s issue is solved by 4096+mmap, since perhaps my computer is just different or something, but I went and downloaded Kowey's static i386 darcs binary to provide a comparison:

gwern at localhost:2977~/testsuite>time ~/darcs-1.0.9-i386-linux whatsnew -s [ 6:33PM]
M ./tests/ghc-regress/ghc-e/should_run/Makefile +3
M ./tests/ghc-regress/ghc-e/should_run/all.T +1
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout
~/darcs-1.0.9-i386-linux whatsnew -s  0.08s user 0.03s system 95% cpu 0.115 total
gwern at localhost:2978~/testsuite>time ~/darcs-1.0.9-i386-linux whatsnew -s [ 6:33PM]
M ./tests/ghc-regress/ghc-e/should_run/Makefile +3
M ./tests/ghc-regress/ghc-e/should_run/all.T +1
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.hs
A ./tests/ghc-regress/ghc-e/should_run/ghc-e006.stdout
~/darcs-1.0.9-i386-linux whatsnew -s  0.07s user 0.04s system 95% cpu 0.115 total

--
gwern
355 1071 Audiotel Tzanhanim of WA2000 top security mixm enigma
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 189 bytes
Desc: not available
Url : http://lists.osuosl.org/pipermail/darcs-users/attachments/20080430/7598f63b/attachment-0001.pgp