On Thu, Feb 07, 2008 at 06:47:08AM -0700, zooko wrote: > > Please make sure this is not a memory problem, since otherwise the > > timing is fairly worthless (and the issue is really in memory > > usage)... Also, checking what kind of load is on the machine (with say > > top) could help -- is it CPU-intensive or IO-intensive workload? Or is > > it mostly idling? > > Wait, why would the timing be worthless?
Well, it would make the timing worth a whole lot less than a measurement of the memory use. Knowing whether it's a memory-use issue vs a cpu-use (or system-call-use) problem makes a big difference. > The timing is a measure of how long it takes darcs and hg to do a > task which I need to do (import ciphercycles tarball) on a machine > that I need to use to do it. Hg works fine in this situation. > > Anyway, I'm re-running it now, with "strace -r -tt" for detailed > timing information. top shows that darcs is using 94 M virt, 88 M > res, and consistently using about 40% to 50% CPU (it is sharing CPU > with a ghc compile). The darcs status-update-line output (you know, > the nice new keep-the-user-informed feature of darcs-2) currently > says "Writing pristine 2049/2058 : > e07cd73fa2a129ece7aa452f7fe29b6c6185e8e1", and has said this same > thing for at least ten minutes. > > > time strace -o tar.strace.log.txt -r -tt tar xjvf > ciphercycles-20070205.tar.bz2 > > 0m2.7s > > time strace -o darcsinit.log.txt -r -tt darcs init --hashed > > 0m0.3s > > time strace -o darcsadd.log.txt -r -tt darcs add -r > ciphercycles-20070205 > > 0m7.8s > > time strace -o darcsrecord.log.txt -r -tt darcs record --all -- > [EMAIL PROTECTED] -m'init import of ciphercycles-20070205' > > 34m20.0s > > (Hm, perhaps sharing the CPU with ghc compile made it take twice as > long. Or perhaps doing the strace logging slowed it down.) > > > And now for Mercurial: > > time strace -o tar.strace.log.txt -r -tt tar xjvf > ciphercycles-20070205.tar.bz2 > > 0m2.3s > > time strace -o hginit.strace.log.txt -r -tt hg init > > 0m0.2s > > time strace -o hgaddremove.strace.log.txt -r -tt hg addremove > > 0m1.9s > > time strace -o hgcommit.strace.log.txt -r -tt hg commit -m'init > import of ciphercycles-20070205' > > 0m5.5s > > > Here is a .tar.bz2 containing all of the strace logs produced -- > https://zooko.com/stracelogs.tar.bz2 . They contain fine-grained > (microsecond) timing of each system call, so they should be a good > help diagnosing why darcs is thousands of times slower than hg for > this. Here's the first clue: > > wc -l straceit*/*.strace.log.txt > > 12662 straceit/darcsadd.strace.log.txt > 323 straceit/darcsinit.strace.log.txt > 1912200 straceit/darcsrec.strace.log.txt > 14150 straceithg/hgaddremove.strace.log.txt > 59911 straceithg/hgcommit.strace.log.txt > 3614 straceithg/hginit.strace.log.txt > 15736 straceithg/tar.strace.log.txt > 15448 straceit/tar.strace.log.txt > 2034044 total > > > So darcs made 1.9 million system calls to do darcs record while hg > made 60,000 system calls to do hg commit. Thanks, that's a good clue! -- David Roundy Department of Physics Oregon State University _______________________________________________ darcs-devel mailing list darcs-devel@darcs.net http://lists.osuosl.org/mailman/listinfo/darcs-devel