[darcs-users] darcs benchmarking

Nathan Gray kolibrie at graystudios.org
Tue Dec 30 18:56:46 UTC 2008


On Mon, Nov 24, 2008 at 03:22:47PM -0500, Nathan Gray wrote:
> On Mon, Nov 24, 2008 at 10:53:46AM -0800, Jason Dagit wrote:
> > We've been building a benchmark suite and we're happy to receive additions,
> > especially cases that real users really care about.
> 
> I will try that one out this week.
> 
> > Hmm...you may be missing some important optimizations from after the darcs
> > sprint.  We did some good low level (meaning not algorithmic) speed-ups
> > during the sprint.
> 
> I'll pull the latest patches and run a benchmark on that.

Here are the results I got when using darcs-benchmark.  They are
rather disappointing.

First, even though I commented out some lines which check to see which
version of darcs is running, the benchmarks against darcs 1.0.9 all
fail:

-- get full, repo = big-zoo/small-repo, bin = darcs109...
iteration: 1..error: user error (darcs failed with error code 1
saying: /home/kolibrie/bin/darcs109 get sandbox sandbox_get +RTS -sstderr 
Invalid repository:  /var/projects/darcs-benchmark/_playground/sandbox
darcs109: /var/projects/darcs-benchmark/_playground/sandbox/_darcs/inventory: openBinaryFile: does not exist (No such file or directory)

    130,204 bytes allocated in the heap
      2,876 bytes copied during GC (scavenged)
         20 bytes copied during GC (not scavenged)
     43,848 bytes maximum residency (1 sample(s))

          1 collections in generation 0 (  0.00s)
          1 collections in generation 1 (  0.00s)

          1 Mb total memory in use

  INIT  time    0.00s  (  0.00s elapsed)
  MUT   time    0.00s  (  0.00s elapsed)
  GC    time    0.00s  (  0.00s elapsed)
  EXIT  time    0.00s  (  0.00s elapsed)
  Total time    0.00s  (  0.00s elapsed)

  %GC time       0.0%  (5.9% elapsed)

  Alloc rate    130,203,999,999 bytes per MUT second

  Productivity 100.0% of total user, 0.1% of total elapsed

)

It is important to me to be able to benchmark current darcs against
the version of darcs we are using in production, so I will know when I
can upgrade.

Another problem I discovered was that my repos are quite a bit
bigger than the repos in big-zoo:

  -rw-r--r-- 1 kolibrie kolibrie 124K 2008-11-24 15:44 small-repo_play.tar.gz
  -rw-r--r-- 1 kolibrie kolibrie  12M 2008-11-24 15:41 darcs-repo_play.tar.gz
  -rw-r--r-- 1 kolibrie kolibrie  74M 2008-11-24 15:44 ghc-hashed_play.tar.gz
  -rw-r--r-- 1 kolibrie kolibrie 145M 2008-12-23 14:49 systems2_play.tar.gz
  -rw-r--r-- 1 kolibrie kolibrie 383M 2008-11-25 14:57 cap2_play.tar.gz

The memory requirements and time requirements were so great that my
benchmark ran overnight and still did not finish.  So I changed
darcs-benchmark to run just one iteration, rather than three, and ran
it again while away on vacation.

It did not finish over my vacation, but hung on the test after
the test where it ran out of memory.

Memory usage is interesting.  What darcs-benchmark reports for memory usage
does not seem accurate.

During the benchmark, in another window, I had a loop running to log
stats about darcs processes every 60 seconds:

  while [ 1 ]; do ps axo pid,euser,pri,ni,vsize,rssize,s,%cpu,%mem,cputime,etime,comm,args |grep darcs >> process_stats_all.txt; sleep 60; done

So while darcs-benchmark reports that it took darcs 2.0.2 1219.6 seconds
to check my cap2 repository (which seems fairly accurate), it also
reports that it used 288MB (which seems quite a bit less than what was
actually used):

-- check, repo = big-zoo/cap2, bin = darcs202...
iteration: 1.. best = 1219.6s, 288M

My 'ps' loop logged that the process took at least 19 minutes and 30
seconds (which is less than a minute off from 1219 seconds), and used
659768 kB of memory (659MB is more than twice the 288MB reported by
darcs-benchmark):

pid   euser    pri  ni vsize rssize s %cpu %mem cputime        etime comm            args
14112 kolibrie  19   0  68256 35584 D 37.9  2.7 00:00:11       00:29 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0  85664 52992 D 38.4  4.1 00:00:34       01:29 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0  85664 52992 D 37.9  4.1 00:00:56       02:29 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 146080 113408 D 40.9  8.8 00:01:25      03:29 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 146080 113412 R 40.1  8.8 00:01:48      04:29 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 146080 113412 R 38.7  8.8 00:02:07      05:29 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 146080 113412 R 37.3  8.8 00:02:25      06:29 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 146080 113412 R 37.0  8.8 00:02:46      07:29 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 507552 470992 R 43.8 36.5 00:03:43      08:29 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 527008 489696 R 48.9 38.0 00:04:38      09:29 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 572064 534484 R 53.5 41.5 00:05:37      10:30 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 618144 580268 R 57.3 45.0 00:06:35      11:30 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 659104 621756 R 60.5 48.2 00:07:34      12:30 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 659104 621756 R 63.2 48.2 00:08:32      13:30 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 659104 621756 R 65.5 48.2 00:09:30      14:30 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 659104 621792 D 65.0 48.2 00:10:05      15:30 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 659816 622512 D 61.2 48.3 00:10:06      16:30 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 660608 623304 R 57.9 48.4 00:10:08      17:30 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 660136 623640 D 55.0 48.4 00:10:10      18:30 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS
14112 kolibrie  19   0 659768 623244 R 52.7 48.4 00:10:17      19:30 darcs202        /home/kolibrie/bin/darcs202 check --no-test +RTS -sstderr -RTS

Benchmarking darcs 2.1.0 had similar results:

-- check, repo = big-zoo/cap2, bin = darcs210...
iteration: 1.. best = 1208.8s, 288M

pid   euser    pri  ni vsize  rssize s %cpu %mem cputime       etime comm            args
14208 kolibrie  19   0 652748 620960 D 51.0 48.2 00:10:14      20:03 darcs210        /home/kolibrie/bin/darcs210 check --no-test +RTS -sstderr -RTS

Benchmarking darcs 2.1.1 ran out of memory at about 3GB:

-- check, repo = big-zoo/cap2, bin = darcs211...
iteration: 1..error: user error (darcs failed with error code 1
saying: /home/kolibrie/bin/darcs211 check --no-test +RTS -sstderr 
Repairing patch 51/26411 : Fri Jan  1 00:36:41 EST 1999  cvs
[snip]
Writing pristine 4/42
[snip]
Writing pristine 21990/22004
cleaning up... 33/75 : whxdata
[snip]
cleaning up... 2787/2906 : LinkInputList
darcs211: out of memory (requested 1048576 bytes)
)

pid   euser    pri  ni   vsize  rssize s %cpu %mem cputime     etime comm            args
14308 kolibrie  19   0 3015188 1080124 D 29.7 83.8 00:08:52    29:48 darcs211        /home/kolibrie/bin/darcs211 check --no-test +RTS -sstderr -RTS

Benchmarking darcs 2.2.0 got up to about 3GB in about three hours, then
hung for several days until I got back from vacation:

-- check, repo = big-zoo/cap2, bin = darcs220...
iteration: 1..Interrupted.

pid   euser    pri  ni   vsize rssize s %cpu %mem cputime      etime comm            args
14457 kolibrie  19   0 3139844 936592 S 11.2 72.7 00:20:59  03:06:24 darcs220        /home/kolibrie/bin/darcs220 check --no-test +RTS -sstderr -RTS
14457 kolibrie  19   0 3139844 936592 S 11.2 72.7 00:20:59  03:07:25 darcs220        /home/kolibrie/bin/darcs220 check --no-test +RTS -sstderr -RTS
14457 kolibrie  19   0 3139844 936592 S 11.1 72.7 00:20:59  03:08:25 darcs220        /home/kolibrie/bin/darcs220 check --no-test +RTS -sstderr -RTS
14457 kolibrie  19   0 3139844 936592 S 11.0 72.7 00:20:59  03:09:25 darcs220        /home/kolibrie/bin/darcs220 check --no-test +RTS -sstderr -RTS
14457 kolibrie  19   0 3139844 934284 S 11.0 72.5 00:20:59  03:10:25 darcs220        /home/kolibrie/bin/darcs220 check --no-test +RTS -sstderr -RTS
[snip]
14457 kolibrie  19   0 3139844 715228 S 0.2 55.5 00:21:31 6-15:14:43 darcs220        /home/kolibrie/bin/darcs220 check --no-test +RTS -sstderr -RTS

I ran a simple homegrown benchmark a few weeks ago that just looked at
CPU usage.  Perhaps I will run that again and track memory usage at
the same time.

-kolibrie



More information about the darcs-users mailing list