You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@subversion.apache.org by Neels Hofmeyr <ne...@elego.de> on 2013/10/30 15:29:39 UTC
Fw: [svnbench] Revision: 1536228 compiled Oct 28 2013, 00:22:05
on x86_64-unknown-linux-gnu
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@apache.org
To: neels@elego.de
Subject: [svnbench] Revision: 1536228 compiled Oct 28 2013, 00:22:05
on x86_64-unknown-linux-gnu
1.8.0@1492600 vs. trunk@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@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@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@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@1535913,5x5' is faster.
"2/3" means: '1.8.0,5x5' has 2 timings on record, the other has 3.)
Compare trunk@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@1535913,100x1' is faster.
"2/3" means: '1.8.0,100x1' has 2 timings on record, the other has 3.)
Compare trunk@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@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@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@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@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@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@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@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@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@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@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@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@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@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@last12.svg
wrote chart
file: /home/neels/svnbench/charts/.busy/compare_1.8.0_trunk@last12,5x5.svg
wrote chart
file: /home/neels/svnbench/charts/.busy/compare_1.8.0_trunk@last12,1x100.svg
wrote chart
file: /home/neels/svnbench/charts/.busy/compare_1.8.0_trunk@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@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