[svn.haxx.se] · SVN Dev · SVN Users · SVN Org · TSVN Dev · TSVN Users · Subclipse Dev · Subclipse Users · this month's index

Fw: [svnbench] Revision: 1536228 compiled Oct 28 2013, 00:22:05 on x86_64-unknown-linux-gnu

From: Neels Hofmeyr <neels_at_elego.de>
Date: Wed, 30 Oct 2013 15:29:39 +0100

Hi all,

I inadvertently disabled the benchmark mails during my last maintenance
some weeks ago. The benchmarks *have* been running and the charts were
there all the while. It's back to normal now.

The top of the charts show very slow timings, and I dimly remember to
have written some comment on that before...

ah here it is:

"
I'm slightly confused by the current charts for 1.8. They suggest
that trunk was drastically slower than 1.8 the closer you get to the
branch point. That makes no sense, it should start almost even.

Also, the first four very negative runs in the new 1.8 charts were all
launched manually, at a very different time of day and day of week than
the cronjob usually runs them. It seems "things" are at work.

After this and the previous misinterpretation of a hardware upgrade I
didn't know about, I believe by now that it is somewhat futile to run
benchmarks on a virtualized host. The benchmarks seem to run at a
quiet time of the week, so we do get some thin bit of substance in the
data. But if even the time of day can jolt the numbers beyond
recognition, that suggests that the benchmarks are running in the wrong
place...

What do you think? Is this madness or is it ok as it is?
"

Enjoy,
~Neels

=== forward ===

Date: Mon, 28 Oct 2013 00:36:34 +0000
From: neels_at_apache.org
To: neels_at_elego.de
Subject: [svnbench] Revision: 1536228 compiled Oct 28 2013, 00:22:05
on x86_64-unknown-linux-gnu

1.8.0_at_1492600 vs. trunk_at_1535913
Started at Mon Oct 28 00:26:03 UTC 2013

*DISCLAIMER* - This tests only file://-URL access on a GNU/Linux VM.
This is intended to measure changes in performance of the local working
copy layer, *only*. These results are *not* generally true for everyone.

Charts of this data are available at http://svn-qavm.apache.org/charts/

Averaged-total results across all runs:
---------------------------------------

Compare trunk_at_1535913 to 1.8.0
       N avg operation
     24/9 0.86| -6.981 TOTAL RUN
   1K/530 0.90| -0.003 add
    48/18 0.94| -0.045 checkout
   192/72 0.81| -0.303 commit
     24/9 0.87| -0.003 copy
     24/9 0.86| -0.037 delete
   120/45 1.10| +0.067 info
    48/18 0.88| -0.147 merge
   1K/516 0.84| -0.002 mkdir
    64/21 0.78| -0.002 propdel
   17K/6K 0.82| -0.002 proplist
   18K/6K 0.82| -0.002 propset
   1K/591 0.78| -0.002 ps
    48/18 0.85| -0.003 resolve
    48/18 0.81| -0.039 resolved
  336/126 0.89| -0.016 status
     24/9 0.82| -0.167 switch
  336/126 0.90| -0.060 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
 factor < 1 and seconds < 0 means 'trunk_at_1535913' is faster.
 "2/3" means: '1.8.0' has 2 timings on record, the other has 3.)

Above totals split into separate <dir-levels>x<dir-spread> runs:
----------------------------------------------------------------

Compare trunk_at_1535913,5x5 to 1.8.0,5x5
       N avg operation
      8/3 0.87|-18.079 TOTAL RUN
   1K/456 0.89| -0.003 add
     16/6 0.94| -0.111 checkout
    64/24 0.82| -0.794 commit
      8/3 0.88| -0.003 copy
      8/3 0.87| -0.089 delete
    40/15 1.13| +0.233 info
     16/6 0.89| -0.366 merge
   1K/470 0.84| -0.002 mkdir
    64/20 0.76| -0.002 propdel
   16K/6K 0.82| -0.002 proplist
   17K/6K 0.82| -0.002 propset
   1K/552 0.78| -0.002 ps
     16/6 0.87| -0.005 resolve
     16/6 0.81| -0.096 resolved
   112/42 0.90| -0.036 status
      8/3 0.83| -0.435 switch
   112/42 0.91| -0.142 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
 factor < 1 and seconds < 0 means 'trunk_at_1535913,5x5' is faster.
 "2/3" means: '1.8.0,5x5' has 2 timings on record, the other has 3.)

Compare trunk_at_1535913,100x1 to 1.8.0,100x1
       N avg operation
      8/3 0.82| -2.047 TOTAL RUN
   224/71 0.88| -0.002 add
     16/6 0.97| -0.003 checkout
    64/24 0.75| -0.086 commit
      8/3 0.88| -0.002 copy
      8/3 0.81| -0.018 delete
    40/15 0.87| -0.020 info
     16/6 0.79| -0.055 merge
   112/46 0.80| -0.003 mkdir
  872/337 0.78| -0.002 proplist
  704/273 0.81| -0.002 propset
    56/33 0.82| -0.002 ps
     16/6 0.84| -0.002 resolve
     16/6 0.81| -0.015 resolved
   112/42 0.87| -0.008 status
      8/3 0.79| -0.048 switch
   112/42 0.84| -0.029 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
 factor < 1 and seconds < 0 means 'trunk_at_1535913,100x1' is faster.
 "2/3" means: '1.8.0,100x1' has 2 timings on record, the other has 3.)

Compare trunk_at_1535913,1x100 to 1.8.0,1x100
       N avg operation
      8/3 0.77| -0.817 TOTAL RUN
      8/3 0.80| -0.016 add
     16/6 0.75| -0.019 checkout
    64/24 0.76| -0.028 commit
      8/3 0.84| -0.003 copy
      8/3 0.86| -0.003 delete
    40/15 0.80| -0.012 info
     16/6 0.78| -0.021 merge
  296/111 0.72| -0.002 proplist
  336/126 0.73| -0.003 propset
     16/6 0.79| -0.002 ps
     16/6 0.82| -0.002 resolve
     16/6 0.76| -0.004 resolved
   112/42 0.77| -0.004 status
      8/3 0.73| -0.019 switch
   112/42 0.80| -0.009 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
 factor < 1 and seconds < 0 means 'trunk_at_1535913,1x100' is faster.
 "2/3" means: '1.8.0,1x100' has 2 timings on record, the other has 3.)

More detail:
------------

Timings for 1.8.0,5x5
   N min max avg operation (unit is seconds)
   8 125.42 186.59 135.19 TOTAL RUN
  1K 0.01 3.48 0.03 add
  16 0.02 4.22 1.97 checkout
  64 0.59 14.33 4.31 commit
   8 0.02 0.05 0.02 copy
   8 0.58 1.02 0.69 delete
  40 0.64 6.21 1.81 info
  16 2.59 5.22 3.46 merge
  1K 0.01 0.03 0.01 mkdir
  64 0.01 0.02 0.01 propdel
 16K 0.01 0.03 0.01 proplist
 17K 0.01 0.17 0.01 propset
  1K 0.01 0.18 0.01 ps
  16 0.03 0.06 0.04 resolve
  16 0.30 1.06 0.51 resolved
 112 0.12 1.24 0.35 status
   8 2.38 3.00 2.50 switch
 112 0.21 4.37 1.51 update 

--
Timings for trunk_at_1535913,5x5
   N    min     max     avg   operation  (unit is seconds)
   3  110.64  124.61  117.11  TOTAL RUN
 456    0.01    2.62    0.03  add
   6    0.02    3.92    1.86  checkout
  24    0.57    8.36    3.52  commit
   3    0.02    0.02    0.02  copy
   3    0.60    0.61    0.60  delete
  15    0.60    6.61    2.04  info
   6    2.37    3.88    3.09  merge
 470    0.01    0.02    0.01  mkdir
  20    0.01    0.01    0.01  propdel
  6K    0.01    0.02    0.01  proplist
  6K    0.01    0.03    0.01  propset
 552    0.01    0.02    0.01  ps
   6    0.03    0.04    0.03  resolve
   6    0.29    0.56    0.41  resolved
  42    0.11    0.56    0.31  status
   3    2.05    2.08    2.07  switch
  42    0.20    3.85    1.37  update
--
Compare trunk_at_1535913,5x5 to 1.8.0,5x5
       N        min              max              avg         operation
      8/3    0.88|-14.780     0.67|-61.984     0.87|-18.079   TOTAL RUN
   1K/456    0.95| -0.001     0.75| -0.859     0.89| -0.003   add
     16/6    1.09| +0.002     0.93| -0.297     0.94| -0.111   checkout
    64/24    0.96| -0.022     0.58| -5.968     0.82| -0.794   commit
      8/3    1.13| +0.002     0.40| -0.033     0.88| -0.003   copy
      8/3    1.04| +0.022     0.60| -0.410     0.87| -0.089   delete
    40/15    0.95| -0.033     1.06| +0.399     1.13| +0.233   info
     16/6    0.91| -0.222     0.74| -1.344     0.89| -0.366   merge
   1K/470    0.92| -0.001     0.80| -0.005     0.84| -0.002   mkdir
    64/20    0.93| -0.001     0.40| -0.012     0.76| -0.002   propdel
   16K/6K    0.92| -0.001     0.70| -0.009     0.82| -0.002   proplist
   17K/6K    0.92| -0.001     0.16| -0.142     0.82| -0.002   propset
   1K/552    0.93| -0.001     0.10| -0.163     0.78| -0.002   ps
     16/6    0.99| -0.000     0.68| -0.019     0.87| -0.005   resolve
     16/6    0.96| -0.011     0.53| -0.502     0.81| -0.096   resolved
   112/42    0.95| -0.006     0.45| -0.675     0.90| -0.036   status
      8/3    0.86| -0.326     0.69| -0.926     0.83| -0.435   switch
   112/42    0.97| -0.007     0.88| -0.525     0.91| -0.142   update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
 factor < 1 and seconds < 0 means 'trunk_at_1535913,5x5' is faster.
 "2/3" means: '1.8.0,5x5' has 2 timings on record, the other has 3.)
Timings for 1.8.0,100x1
   N    min     max     avg   operation  (unit is seconds)
   8    9.77   19.83   11.09  TOTAL RUN
 224    0.01    0.15    0.02  add
  16    0.02    0.23    0.12  checkout
  64    0.10    0.92    0.34  commit
   8    0.02    0.04    0.02  copy
   8    0.08    0.18    0.10  delete
  40    0.10    0.29    0.15  info
  16    0.21    0.53    0.27  merge
 112    0.01    0.05    0.02  mkdir
 872    0.01    0.02    0.01  proplist
 704    0.01    0.03    0.01  propset
  56    0.01    0.03    0.01  ps
  16    0.01    0.03    0.01  resolve
  16    0.07    0.16    0.08  resolved
 112    0.03    0.16    0.06  status
   8    0.21    0.41    0.23  switch
 112    0.04    0.58    0.18  update
--
Timings for trunk_at_1535913,100x1
   N    min     max     avg   operation  (unit is seconds)
   3    8.91    9.17    9.05  TOTAL RUN
  71    0.01    0.14    0.02  add
   6    0.02    0.21    0.12  checkout
  24    0.09    0.48    0.25  commit
   3    0.02    0.02    0.02  copy
   3    0.08    0.08    0.08  delete
  15    0.10    0.19    0.13  info
   6    0.19    0.24    0.21  merge
  46    0.01    0.02    0.01  mkdir
   1    0.01    0.01    0.01  propdel
 337    0.01    0.01    0.01  proplist
 273    0.01    0.01    0.01  propset
  33    0.01    0.01    0.01  ps
   6    0.01    0.01    0.01  resolve
   6    0.06    0.07    0.07  resolved
  42    0.03    0.07    0.05  status
   3    0.19    0.19    0.19  switch
  42    0.04    0.28    0.15  update
--
Compare trunk_at_1535913,100x1 to 1.8.0,100x1
       N        min              max              avg         operation
      8/3    0.91| -0.866     0.46|-10.657     0.82| -2.047   TOTAL RUN
   224/71    0.91| -0.001     0.95| -0.008     0.88| -0.002   add
     16/6    1.06| +0.001     0.94| -0.012     0.97| -0.003   checkout
    64/24    0.97| -0.003     0.52| -0.442     0.75| -0.086   commit
      8/3    1.00| +0.000     0.50| -0.018     0.88| -0.002   copy
      8/3    0.93| -0.006     0.43| -0.105     0.81| -0.018   delete
    40/15    0.96| -0.004     0.65| -0.100     0.87| -0.020   info
     16/6    0.91| -0.019     0.46| -0.286     0.79| -0.055   merge
   112/46    0.92| -0.001     0.41| -0.027     0.80| -0.003   mkdir
  872/337    0.89| -0.001     0.42| -0.013     0.78| -0.002   proplist
  704/273    0.93| -0.001     0.43| -0.015     0.81| -0.002   propset
    56/33    0.92| -0.001     0.43| -0.015     0.82| -0.002   ps
     16/6    0.97| -0.000     0.45| -0.017     0.84| -0.002   resolve
     16/6    0.96| -0.003     0.42| -0.092     0.81| -0.015   resolved
   112/42    0.93| -0.002     0.46| -0.087     0.87| -0.008   status
      8/3    0.89| -0.022     0.46| -0.219     0.79| -0.048   switch
   112/42    0.97| -0.001     0.49| -0.293     0.84| -0.029   update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
 factor < 1 and seconds < 0 means 'trunk_at_1535913,100x1' is faster.
 "2/3" means: '1.8.0,100x1' has 2 timings on record, the other has 3.)
Timings for 1.8.0,1x100
   N    min     max     avg   operation  (unit is seconds)
   8    2.84    6.37    3.53  TOTAL RUN
   8    0.07    0.18    0.08  add
  16    0.02    0.23    0.08  checkout
  64    0.03    0.46    0.12  commit
   8    0.02    0.04    0.02  copy
   8    0.02    0.04    0.02  delete
  40    0.04    0.19    0.06  info
  16    0.07    0.22    0.10  merge
 296    0.01    0.02    0.01  proplist
 336    0.01    0.02    0.01  propset
  16    0.01    0.02    0.01  ps
  16    0.01    0.02    0.01  resolve
  16    0.01    0.04    0.02  resolved
 112    0.01    0.04    0.02  status
   8    0.05    0.13    0.07  switch
 112    0.02    0.23    0.05  update
--
Timings for trunk_at_1535913,1x100
   N    min     max     avg   operation  (unit is seconds)
   3    2.71    2.73    2.72  TOTAL RUN
   3    0.07    0.07    0.07  add
   6    0.02    0.10    0.06  checkout
  24    0.03    0.20    0.09  commit
   3    0.02    0.02    0.02  copy
   3    0.02    0.02    0.02  delete
  15    0.04    0.08    0.05  info
   6    0.06    0.10    0.08  merge
 111    0.01    0.01    0.01  proplist
 126    0.01    0.01    0.01  propset
   6    0.01    0.01    0.01  ps
   6    0.01    0.01    0.01  resolve
   6    0.01    0.02    0.01  resolved
  42    0.01    0.02    0.01  status
   3    0.05    0.05    0.05  switch
  42    0.02    0.09    0.04  update
--
Compare trunk_at_1535913,1x100 to 1.8.0,1x100
       N        min              max              avg         operation
      8/3    0.95| -0.133     0.43| -3.648     0.77| -0.817   TOTAL RUN
      8/3    0.97| -0.002     0.37| -0.116     0.80| -0.016   add
     16/6    1.08| +0.001     0.43| -0.131     0.75| -0.019   checkout
    64/24    0.96| -0.001     0.43| -0.261     0.76| -0.028   commit
      8/3    1.00| -0.000     0.50| -0.020     0.84| -0.003   copy
      8/3    0.95| -0.001     0.55| -0.016     0.86| -0.003   delete
    40/15    0.99| -0.000     0.42| -0.109     0.80| -0.012   info
     16/6    0.93| -0.004     0.44| -0.121     0.78| -0.021   merge
  296/111    0.91| -0.001     0.39| -0.011     0.72| -0.002   proplist
  336/126    0.92| -0.001     0.38| -0.014     0.73| -0.003   propset
     16/6    0.93| -0.001     0.39| -0.012     0.79| -0.002   ps
     16/6    0.98| -0.000     0.46| -0.013     0.82| -0.002   resolve
     16/6    0.97| -0.000     0.42| -0.024     0.76| -0.004   resolved
   112/42    0.90| -0.001     0.44| -0.021     0.77| -0.004   status
      8/3    0.93| -0.004     0.40| -0.075     0.73| -0.019   switch
   112/42    1.01| +0.000     0.41| -0.136     0.80| -0.009   update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
 factor < 1 and seconds < 0 means 'trunk_at_1535913,1x100' is faster.
 "2/3" means: '1.8.0,1x100' has 2 timings on record, the other has 3.)
Timings for 1.8.0
   N    min     max     avg   operation  (unit is seconds)
  24    2.84  186.59   49.94  TOTAL RUN
  1K    0.01    3.48    0.03  add
  48    0.02    4.22    0.72  checkout
 192    0.03   14.33    1.59  commit
  24    0.02    0.05    0.02  copy
  24    0.02    1.02    0.27  delete
 120    0.04    6.21    0.67  info
  48    0.07    5.22    1.27  merge
  1K    0.01    0.05    0.01  mkdir
  64    0.01    0.02    0.01  propdel
 17K    0.01    0.03    0.01  proplist
 18K    0.01    0.17    0.01  propset
  1K    0.01    0.18    0.01  ps
  48    0.01    0.06    0.02  resolve
  48    0.01    1.06    0.20  resolved
 336    0.01    1.24    0.14  status
  24    0.05    3.00    0.93  switch
 336    0.02    4.37    0.58  update
--
Timings for trunk_at_1535913
   N    min     max     avg   operation  (unit is seconds)
   9    2.71  124.61   42.96  TOTAL RUN
 530    0.01    2.62    0.03  add
  18    0.02    3.92    0.68  checkout
  72    0.03    8.36    1.29  commit
   9    0.02    0.02    0.02  copy
   9    0.02    0.61    0.23  delete
  45    0.04    6.61    0.74  info
  18    0.06    3.88    1.13  merge
 516    0.01    0.02    0.01  mkdir
  21    0.01    0.01    0.01  propdel
  6K    0.01    0.02    0.01  proplist
  6K    0.01    0.03    0.01  propset
 591    0.01    0.02    0.01  ps
  18    0.01    0.04    0.02  resolve
  18    0.01    0.56    0.16  resolved
 126    0.01    0.56    0.13  status
   9    0.05    2.08    0.77  switch
 126    0.02    3.85    0.52  update
--
Compare trunk_at_1535913 to 1.8.0
       N        min              max              avg         operation
     24/9    0.95| -0.133     0.67|-61.984     0.86| -6.981   TOTAL RUN
   1K/530    0.95| -0.001     0.75| -0.859     0.90| -0.003   add
    48/18    1.08| +0.001     0.93| -0.297     0.94| -0.045   checkout
   192/72    0.96| -0.001     0.58| -5.968     0.81| -0.303   commit
     24/9    1.02| +0.000     0.40| -0.033     0.87| -0.003   copy
     24/9    0.95| -0.001     0.60| -0.410     0.86| -0.037   delete
   120/45    0.99| -0.000     1.06| +0.399     1.10| +0.067   info
    48/18    0.93| -0.004     0.74| -1.344     0.88| -0.147   merge
   1K/516    0.92| -0.001     0.45| -0.025     0.84| -0.002   mkdir
    64/21    0.93| -0.001     0.53| -0.010     0.78| -0.002   propdel
   17K/6K    0.92| -0.001     0.70| -0.009     0.82| -0.002   proplist
   18K/6K    0.92| -0.001     0.16| -0.142     0.82| -0.002   propset
   1K/591    0.93| -0.001     0.10| -0.163     0.78| -0.002   ps
    48/18    0.98| -0.000     0.68| -0.019     0.85| -0.003   resolve
    48/18    0.97| -0.000     0.53| -0.502     0.81| -0.039   resolved
  336/126    0.90| -0.001     0.45| -0.675     0.89| -0.016   status
     24/9    0.93| -0.004     0.69| -0.926     0.82| -0.167   switch
  336/126    1.01| +0.000     0.88| -0.525     0.90| -0.060   update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
 factor < 1 and seconds < 0 means 'trunk_at_1535913' is faster.
 "2/3" means: '1.8.0' has 2 timings on record, the other has 3.)
Had started at Mon Oct 28 00:26:03 UTC 2013,
       done at Mon Oct 28 00:35:23 UTC 2013
wrote chart
file: /home/neels/svnbench/charts/.busy/compare_1.8.0_trunk_at_last12.svg
wrote chart
file: /home/neels/svnbench/charts/.busy/compare_1.8.0_trunk_at_last12,5x5.svg
wrote chart
file: /home/neels/svnbench/charts/.busy/compare_1.8.0_trunk_at_last12,1x100.svg
wrote chart
file: /home/neels/svnbench/charts/.busy/compare_1.8.0_trunk_at_last12,100x1.svg
--
Neels Hofmeyr
Senior Developer
elego Software Solutions GmbH, http://www.elego.de/
Gustav-Meyer-Allee 25, Gebäude 12.3 (BIG)
13355 Berlin, Germany
Fon: +49 30 2345 8696, mailto:neels_at_elego.de
Fax: +49 30 2345 8695
Sitz der Gesellschaft: Berlin, USt-IdNr.: DE 163214194
Handelsregister: Amtsgericht Charlottenburg HRB 77719
Geschäftsführer: Olaf Wagner, Michael Diers

Received on 2013-10-30 15:41:04 CET

This is an archived mail posted to the Subversion Dev mailing list.

This site is subject to the Apache Privacy Policy and the Apache Public Forum Archive Policy.