You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@subversion.apache.org by ne...@apache.org on 2013/09/09 02:39:19 UTC
[svnbench] Revision: 1520942 compiled Sep 9 2013, 00:22:04 on
x86_64-unknown-linux-gnu
1.7.0@1181106 vs. trunk@1520893
Started at Mon Sep 9 00:26:26 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@1520893 to 1.7.0
N avg operation
66/9 0.55|-33.902 TOTAL RUN
4K/530 1.24| +0.005 add
132/18 0.78| -0.185 checkout
528/72 0.66| -0.668 commit
66/9 0.92| -0.002 copy
66/9 0.79| -0.061 delete
330/45 0.14| -3.748 info
132/18 0.54| -0.966 merge
3K/516 0.81| -0.002 mkdir
176/21 0.74| -0.003 propdel
49K/6K 0.71| -0.003 proplist
50K/6K 0.73| -0.003 propset
4K/591 0.72| -0.003 ps
132/18 2.01| +0.009 resolve
132/18 0.83| -0.033 resolved
924/126 0.71| -0.052 status
66/9 0.72| -0.300 switch
924/126 0.79| -0.137 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
factor < 1 and seconds < 0 means 'trunk@1520893' is faster.
"2/3" means: '1.7.0' has 2 timings on record, the other has 3.)
Above totals split into separate <dir-levels>x<dir-spread> runs:
----------------------------------------------------------------
Compare trunk@1520893,5x5 to 1.7.0,5x5
N avg operation
22/3 0.55|-93.853 TOTAL RUN
3K/456 1.25| +0.005 add
44/6 0.80| -0.447 checkout
176/24 0.67| -1.720 commit
22/3 0.88| -0.003 copy
22/3 0.80| -0.144 delete
110/15 0.13|-11.091 info
44/6 0.56| -2.459 merge
3K/470 0.79| -0.002 mkdir
176/20 0.72| -0.003 propdel
46K/6K 0.71| -0.003 proplist
47K/6K 0.73| -0.003 propset
3K/552 0.71| -0.003 ps
44/6 3.85| +0.024 resolve
44/6 0.82| -0.092 resolved
308/42 0.71| -0.126 status
22/3 0.75| -0.699 switch
308/42 0.84| -0.260 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
factor < 1 and seconds < 0 means 'trunk@1520893,5x5' is faster.
"2/3" means: '1.7.0,5x5' has 2 timings on record, the other has 3.)
Compare trunk@1520893,100x1 to 1.7.0,100x1
N avg operation
22/3 0.58| -6.455 TOTAL RUN
616/71 1.04| +0.001 add
44/6 0.59| -0.080 checkout
176/24 0.53| -0.224 commit
22/3 0.92| -0.002 copy
22/3 0.71| -0.032 delete
110/15 0.48| -0.135 info
44/6 0.37| -0.352 merge
308/46 0.97| -0.000 mkdir
2K/337 0.69| -0.004 proplist
1K/273 0.71| -0.004 propset
154/33 0.72| -0.004 ps
44/6 1.40| +0.004 resolve
44/6 0.96| -0.003 resolved
308/42 0.70| -0.022 status
22/3 0.52| -0.171 switch
308/42 0.52| -0.137 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
factor < 1 and seconds < 0 means 'trunk@1520893,100x1' is faster.
"2/3" means: '1.7.0,100x1' has 2 timings on record, the other has 3.)
Compare trunk@1520893,1x100 to 1.7.0,1x100
N avg operation
22/3 0.66| -1.398 TOTAL RUN
22/3 1.34| +0.016 add
44/6 0.67| -0.028 checkout
176/24 0.60| -0.059 commit
22/3 1.00| -0.000 copy
22/3 0.69| -0.008 delete
110/15 0.75| -0.016 info
44/6 0.46| -0.088 merge
814/111 0.65| -0.003 proplist
924/126 0.67| -0.004 propset
44/6 0.66| -0.004 ps
44/6 0.99| -0.000 resolve
44/6 0.72| -0.005 resolved
308/42 0.64| -0.007 status
22/3 0.63| -0.030 switch
308/42 0.73| -0.014 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
factor < 1 and seconds < 0 means 'trunk@1520893,1x100' is faster.
"2/3" means: '1.7.0,1x100' has 2 timings on record, the other has 3.)
More detail:
------------
Timings for 1.7.0,5x5
N min max avg operation (unit is seconds)
22 191.95 255.84 206.63 TOTAL RUN
3K 0.01 2.21 0.02 add
44 0.02 5.15 2.29 checkout
176 1.07 17.29 5.26 commit
22 0.01 0.13 0.02 copy
22 0.61 0.96 0.72 delete
110 6.32 32.08 12.72 info
44 5.31 8.49 5.57 merge
3K 0.01 0.04 0.01 mkdir
176 0.01 0.02 0.01 propdel
46K 0.01 0.03 0.01 proplist
47K 0.01 0.13 0.01 propset
3K 0.01 0.05 0.01 ps
44 0.01 0.01 0.01 resolve
44 0.40 0.70 0.51 resolved
308 0.17 0.96 0.44 status
22 2.70 3.02 2.79 switch
308 0.21 4.98 1.65 update
--
Timings for trunk@1520893,5x5
N min max avg operation (unit is seconds)
3 111.13 114.85 112.77 TOTAL RUN
456 0.01 2.64 0.03 add
6 0.02 3.75 1.84 checkout
24 0.57 8.60 3.54 commit
3 0.02 0.02 0.02 copy
3 0.53 0.60 0.58 delete
15 0.61 3.32 1.63 info
6 2.36 3.91 3.11 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.02 0.01 propset
552 0.01 0.02 0.01 ps
6 0.03 0.04 0.03 resolve
6 0.30 0.55 0.42 resolved
42 0.12 0.55 0.32 status
3 2.06 2.14 2.09 switch
42 0.20 3.89 1.39 update
--
Compare trunk@1520893,5x5 to 1.7.0,5x5
N min max avg operation
22/3 0.58|-80.822 0.45|-140.986 0.55|-93.853 TOTAL RUN
3K/456 1.06| +0.000 1.19| +0.430 1.25| +0.005 add
44/6 0.99| -0.000 0.73| -1.403 0.80| -0.447 checkout
176/24 0.53| -0.502 0.50| -8.693 0.67| -1.720 commit
22/3 1.41| +0.006 0.17| -0.110 0.88| -0.003 copy
22/3 0.87| -0.080 0.62| -0.361 0.80| -0.144 delete
110/15 0.10| -5.719 0.10|-28.761 0.13|-11.091 info
44/6 0.44| -2.957 0.46| -4.584 0.56| -2.459 merge
3K/470 0.97| -0.000 0.52| -0.020 0.79| -0.002 mkdir
176/20 0.90| -0.001 0.35| -0.014 0.72| -0.003 propdel
46K/6K 0.87| -0.001 0.51| -0.016 0.71| -0.003 proplist
47K/6K 0.89| -0.001 0.15| -0.107 0.73| -0.003 propset
3K/552 0.90| -0.001 0.38| -0.030 0.71| -0.003 ps
44/6 3.05| +0.017 4.39| +0.031 3.85| +0.024 resolve
44/6 0.75| -0.101 0.79| -0.151 0.82| -0.092 resolved
308/42 0.70| -0.051 0.58| -0.408 0.71| -0.126 status
22/3 0.76| -0.639 0.71| -0.886 0.75| -0.699 switch
308/42 0.96| -0.009 0.78| -1.095 0.84| -0.260 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
factor < 1 and seconds < 0 means 'trunk@1520893,5x5' is faster.
"2/3" means: '1.7.0,5x5' has 2 timings on record, the other has 3.)
Timings for 1.7.0,100x1
N min max avg operation (unit is seconds)
22 12.78 22.57 15.53 TOTAL RUN
616 0.01 0.13 0.02 add
44 0.02 0.74 0.20 checkout
176 0.11 1.41 0.48 commit
22 0.01 0.03 0.02 copy
22 0.09 0.22 0.11 delete
110 0.14 0.80 0.26 info
44 0.45 0.91 0.56 merge
308 0.01 0.03 0.01 mkdir
2K 0.01 0.03 0.01 proplist
1K 0.01 0.03 0.01 propset
154 0.01 0.03 0.01 ps
44 0.01 0.02 0.01 resolve
44 0.05 0.17 0.07 resolved
308 0.04 0.21 0.07 status
22 0.33 0.65 0.36 switch
308 0.04 0.86 0.29 update
--
Timings for trunk@1520893,100x1
N min max avg operation (unit is seconds)
3 8.93 9.18 9.07 TOTAL RUN
71 0.01 0.14 0.02 add
6 0.02 0.22 0.12 checkout
24 0.09 0.49 0.25 commit
3 0.02 0.02 0.02 copy
3 0.08 0.08 0.08 delete
15 0.09 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@1520893,100x1 to 1.7.0,100x1
N min max avg operation
22/3 0.70| -3.843 0.41|-13.396 0.58| -6.455 TOTAL RUN
616/71 1.08| +0.001 1.12| +0.016 1.04| +0.001 add
44/6 1.02| +0.000 0.29| -0.521 0.59| -0.080 checkout
176/24 0.82| -0.020 0.35| -0.925 0.53| -0.224 commit
22/3 1.27| +0.004 0.54| -0.016 0.92| -0.002 copy
22/3 0.84| -0.015 0.37| -0.137 0.71| -0.032 delete
110/15 0.65| -0.050 0.23| -0.617 0.48| -0.135 info
44/6 0.42| -0.265 0.26| -0.671 0.37| -0.352 merge
308/46 0.97| -0.000 0.57| -0.014 0.97| -0.000 mkdir
2K/337 0.86| -0.001 0.34| -0.020 0.69| -0.004 proplist
1K/273 0.88| -0.001 0.37| -0.021 0.71| -0.004 propset
154/33 0.85| -0.001 0.37| -0.020 0.72| -0.004 ps
44/6 1.49| +0.004 0.71| -0.005 1.40| +0.004 resolve
44/6 1.33| +0.015 0.40| -0.102 0.96| -0.003 resolved
308/42 0.72| -0.011 0.35| -0.135 0.70| -0.022 status
22/3 0.56| -0.144 0.29| -0.464 0.52| -0.171 switch
308/42 0.95| -0.002 0.33| -0.578 0.52| -0.137 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
factor < 1 and seconds < 0 means 'trunk@1520893,100x1' is faster.
"2/3" means: '1.7.0,100x1' has 2 timings on record, the other has 3.)
Timings for 1.7.0,1x100
N min max avg operation (unit is seconds)
22 3.06 7.30 4.08 TOTAL RUN
22 0.04 0.09 0.05 add
44 0.02 0.27 0.08 checkout
176 0.03 0.56 0.15 commit
22 0.01 0.03 0.02 copy
22 0.02 0.05 0.03 delete
110 0.04 0.19 0.06 info
44 0.12 0.31 0.16 merge
814 0.01 0.02 0.01 proplist
924 0.01 0.02 0.01 propset
44 0.01 0.02 0.01 ps
44 0.01 0.02 0.01 resolve
44 0.01 0.04 0.02 resolved
308 0.01 0.05 0.02 status
22 0.06 0.15 0.08 switch
308 0.02 0.27 0.05 update
--
Timings for trunk@1520893,1x100
N min max avg operation (unit is seconds)
3 2.67 2.69 2.68 TOTAL RUN
3 0.07 0.07 0.07 add
6 0.02 0.10 0.06 checkout
24 0.02 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.09 0.07 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@1520893,1x100 to 1.7.0,1x100
N min max avg operation
22/3 0.87| -0.388 0.37| -4.618 0.66| -1.398 TOTAL RUN
22/3 1.82| +0.029 0.73| -0.024 1.34| +0.016 add
44/6 1.00| +0.000 0.36| -0.172 0.67| -0.028 checkout
176/24 0.73| -0.009 0.36| -0.354 0.60| -0.059 commit
22/3 1.22| +0.003 0.62| -0.012 1.00| -0.000 copy
22/3 0.97| -0.001 0.40| -0.028 0.69| -0.008 delete
110/15 1.00| -0.000 0.41| -0.111 0.75| -0.016 info
44/6 0.52| -0.055 0.29| -0.221 0.46| -0.088 merge
814/111 0.87| -0.001 0.36| -0.012 0.65| -0.003 proplist
924/126 0.89| -0.001 0.51| -0.010 0.67| -0.004 propset
44/6 0.90| -0.001 0.34| -0.014 0.66| -0.004 ps
44/6 1.32| +0.002 0.57| -0.008 0.99| -0.000 resolve
44/6 0.84| -0.002 0.42| -0.023 0.72| -0.005 resolved
308/42 0.85| -0.001 0.35| -0.030 0.64| -0.007 status
22/3 0.83| -0.010 0.34| -0.096 0.63| -0.030 switch
308/42 1.09| +0.001 0.35| -0.174 0.73| -0.014 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
factor < 1 and seconds < 0 means 'trunk@1520893,1x100' is faster.
"2/3" means: '1.7.0,1x100' has 2 timings on record, the other has 3.)
Timings for 1.7.0
N min max avg operation (unit is seconds)
66 3.06 255.84 75.41 TOTAL RUN
4K 0.01 2.21 0.02 add
132 0.02 5.15 0.86 checkout
528 0.03 17.29 1.96 commit
66 0.01 0.13 0.02 copy
66 0.02 0.96 0.29 delete
330 0.04 32.08 4.35 info
132 0.12 8.49 2.10 merge
3K 0.01 0.04 0.01 mkdir
176 0.01 0.02 0.01 propdel
49K 0.01 0.03 0.01 proplist
50K 0.01 0.13 0.01 propset
4K 0.01 0.05 0.01 ps
132 0.01 0.02 0.01 resolve
132 0.01 0.70 0.20 resolved
924 0.01 0.96 0.18 status
66 0.06 3.02 1.08 switch
924 0.02 4.98 0.66 update
--
Timings for trunk@1520893
N min max avg operation (unit is seconds)
9 2.67 114.85 41.51 TOTAL RUN
530 0.01 2.64 0.03 add
18 0.02 3.75 0.67 checkout
72 0.02 8.60 1.29 commit
9 0.02 0.02 0.02 copy
9 0.02 0.60 0.22 delete
45 0.04 3.32 0.60 info
18 0.06 3.91 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.02 0.01 propset
591 0.01 0.02 0.01 ps
18 0.01 0.04 0.02 resolve
18 0.01 0.55 0.17 resolved
126 0.01 0.55 0.13 status
9 0.05 2.14 0.78 switch
126 0.02 3.89 0.52 update
--
Compare trunk@1520893 to 1.7.0
N min max avg operation
66/9 0.87| -0.388 0.45|-140.986 0.55|-33.902 TOTAL RUN
4K/530 1.06| +0.000 1.19| +0.430 1.24| +0.005 add
132/18 1.00| +0.000 0.73| -1.403 0.78| -0.185 checkout
528/72 0.73| -0.009 0.50| -8.693 0.66| -0.668 commit
66/9 1.22| +0.003 0.17| -0.110 0.92| -0.002 copy
66/9 0.97| -0.001 0.62| -0.361 0.79| -0.061 delete
330/45 1.00| -0.000 0.10|-28.761 0.14| -3.748 info
132/18 0.52| -0.055 0.46| -4.584 0.54| -0.966 merge
3K/516 0.97| -0.000 0.52| -0.020 0.81| -0.002 mkdir
176/21 0.90| -0.001 0.49| -0.011 0.74| -0.003 propdel
49K/6K 0.87| -0.001 0.51| -0.016 0.71| -0.003 proplist
50K/6K 0.89| -0.001 0.15| -0.107 0.73| -0.003 propset
4K/591 0.90| -0.001 0.38| -0.030 0.72| -0.003 ps
132/18 1.32| +0.002 2.14| +0.021 2.01| +0.009 resolve
132/18 0.84| -0.002 0.79| -0.151 0.83| -0.033 resolved
924/126 0.85| -0.001 0.58| -0.408 0.71| -0.052 status
66/9 0.83| -0.010 0.71| -0.886 0.72| -0.300 switch
924/126 1.09| +0.001 0.78| -1.095 0.79| -0.137 update
(legend: "1.23|+0.45" means: slower by factor 1.23 and by 0.45 seconds;
factor < 1 and seconds < 0 means 'trunk@1520893' is faster.
"2/3" means: '1.7.0' has 2 timings on record, the other has 3.)
Had started at Mon Sep 9 00:26:26 UTC 2013,
done at Mon Sep 9 00:37:18 UTC 2013
wrote chart file: /home/neels/svnbench/charts/.busy/compare_1.7.0_trunk@last12.svg
wrote chart file: /home/neels/svnbench/charts/.busy/compare_1.7.0_trunk@last12,5x5.svg
wrote chart file: /home/neels/svnbench/charts/.busy/compare_1.7.0_trunk@last12,1x100.svg
wrote chart file: /home/neels/svnbench/charts/.busy/compare_1.7.0_trunk@last12,100x1.svg
Re: [svnbench] Revision: 1520942 compiled Sep 9 2013, 00:22:04
on x86_64-unknown-linux-gnu
Posted by Neels Hofmeyr <ne...@elego.de>.
neels@apache.org:
> Charts of this data are available at
> http://svn-qavm.apache.org/charts/
Hi all,
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?
Thanks,
~Neels