[Cosmo-dev] Repeated performance test
Jared Rhine
jared at wordzoo.com
Tue Sep 12 08:02:27 PDT 2006
The kiloprop tester in Cosmo has been extended and wrapped. Individual
steps in the test ("create user, populate, propfind, delete collection") are
timed separately and run against multiple cosmo SVN revisions. The
ugly-for-now resulting report are available here:
http://osaf.us/perf-test/
As I massage the output, this should be able to go back into a table form; a
simple matter of looping properly. But since it is just text right now,
I've pasted the current results at the bottom of this message (reordered for
clarity).
These results are calculated by parsing the unaltered output of raw log
files POSTed to feedback.osafoundation.org (the same site which collects
desktop crash and desktop usage submissions). So other performance test
runs can be integrated and reported with little hassle.
All results are run on the same idle box; raw results can be debated, but
the relative times between the various Cosmo revisions should be valid. All
tests are still against Derby on the local box; indications are that
absolute performance will improve somewhat when a separate db box is added
to the mix. [Insert other caveats here; it's not hard to pick apart the test
method if you dive in]
Some small enhancements to kiloprop are being offered as a patch in bugzilla
#6684.
The code which runs these tests and outputs the results is available in the
osaf.us directory of the OSAF SVN sandbox repository. To kick off the run,
just `$ROOT/bin/run-test-set` is started. That script uses other scripts to
build fresh Cosmo instances straight out of SVN (the instance is rm -rf'ed
before building).
Conclusions:
* The basic results establishing a ~10x speed-up in propfind results has
been confirmed many times now.
* For a "real-world" calendar (Mitch-3) doing a propfind ("depth 1"), the
results are a little more modest, about 5x. JCR version (cosmo-trunk r2210)
took 32.5 to 37.5 seconds for 1 propfind; latest (simdesk-trunk r965) took
6.7 to 9 seconds.
* Publishing the Mitch-3 calendar (1300 events), one PUT at a time, takes
125 seconds on the latest Hibernate code. It was 190 seconds under JCR.
* A particular revision (cosmo simdesk-trunk r908 was indeed a very bad
performer, some attribute-fetching work was still being incorporated (6000
seconds to populate Mitch-3). I'll drop this release from future testing.
I'm happy to review the methodology, add tests, or rerun against any
available cosmo/snarf revisions available in svn.
---
simdesk-trunk-r965+simdesk-snarf-r967 with 50 resources
kiloprop.50-resources.createuser : 0.923 seconds
kiloprop.50-resources.delete_coll : 0.877 seconds
kiloprop.50-resources.populate : 2.633 seconds
kiloprop.50-resources.propfind.1-time : 0.311 seconds
kiloprop.50-resources.propfind.50-times : 0.768 seconds
kiloprop.populate-caldata.100 : 8.704 seconds
kiloprop.populate-caldata.mitch-3 : 126.870 seconds
kiloprop.propfind-caldata-100.depth-1.1-time : 0.386 seconds
kiloprop.propfind-caldata-100.depth-1.10-times : 1.238 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.1-time : 1.295 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.10-times : 9.002 seconds
simdesk-trunk-r965+simdesk-snarf-r967 with 500 resources
kiloprop.500-resources.createuser : 1.405 seconds
kiloprop.500-resources.delete_coll : 2.164 seconds
kiloprop.500-resources.populate : 160.514 seconds
kiloprop.500-resources.propfind.1-time : 0.316 seconds
kiloprop.500-resources.propfind.50-times : 0.854 seconds
kiloprop.populate-caldata.100 : 7.812 seconds
kiloprop.populate-caldata.mitch-3 : 124.462 seconds
kiloprop.propfind-caldata-100.depth-1.1-time : 0.377 seconds
kiloprop.propfind-caldata-100.depth-1.10-times : 1.000 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.1-time : 1.187 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.10-times : 6.689 seconds
simdesk-trunk-r941+simdesk-snarf-r870 with 50 resources
kiloprop.50-resources.createuser : 0.972 seconds
kiloprop.50-resources.delete_coll : 0.931 seconds
kiloprop.50-resources.populate : 2.017 seconds
kiloprop.50-resources.propfind.1-time : 0.310 seconds
kiloprop.50-resources.propfind.50-times : 0.762 seconds
kiloprop.populate-caldata.100 : 2.446 seconds
kiloprop.populate-caldata.mitch-3 : 13.267 seconds
kiloprop.propfind-caldata-100.depth-1.1-time : 0.295 seconds
kiloprop.propfind-caldata-100.depth-1.10-times : 0.370 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.1-time : 0.302 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.10-times : 0.360 seconds
simdesk-trunk-r941+simdesk-snarf-r870 with 500 resources
kiloprop.500-resources.createuser : 1.256 seconds
kiloprop.500-resources.delete_coll : 2.150 seconds
kiloprop.500-resources.populate : 12.345 seconds
kiloprop.500-resources.propfind.1-time : 0.299 seconds
kiloprop.500-resources.propfind.50-times : 0.712 seconds
kiloprop.populate-caldata.100 : 2.214 seconds
kiloprop.populate-caldata.mitch-3 : 13.497 seconds
kiloprop.propfind-caldata-100.depth-1.1-time : 0.298 seconds
kiloprop.propfind-caldata-100.depth-1.10-times : 0.347 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.1-time : 0.316 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.10-times : 0.368 seconds
simdesk-trunk-r908+simdesk-snarf-r870 with 50 resources
kiloprop.50-resources.createuser : 0.946 seconds
kiloprop.50-resources.delete_coll : 1.001 seconds
kiloprop.50-resources.populate : 4.660 seconds
kiloprop.50-resources.propfind.1-time : 0.563 seconds
kiloprop.50-resources.propfind.50-times : 4.489 seconds
kiloprop.populate-caldata.100 : 13.431 seconds
kiloprop.populate-caldata.mitch-3 : 6885.403 seconds
kiloprop.propfind-caldata-100.depth-1.1-time : 0.838 seconds
kiloprop.propfind-caldata-100.depth-1.10-times : 3.475 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.1-time : 26.517 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.10-times : 146.442 seconds
simdesk-trunk-r908+simdesk-snarf-r870 with 500 resources
kiloprop.500-resources.createuser : 1.359 seconds
kiloprop.500-resources.delete_coll : 11.672 seconds
kiloprop.500-resources.populate : 817.490 seconds
kiloprop.500-resources.propfind.1-time : 7.225 seconds
kiloprop.500-resources.propfind.50-times : 187.891 seconds
kiloprop.populate-caldata.100 : 11.898 seconds
kiloprop.populate-caldata.mitch-3 : 6178.745 seconds
kiloprop.propfind-caldata-100.depth-1.1-time : 0.698 seconds
kiloprop.propfind-caldata-100.depth-1.10-times : 5.347 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.1-time : 26.202 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.10-times : 139.901 seconds
cosmo-trunk-r2210+snarf-trunk-r2434 with 50 resources
kiloprop.50-resources.createuser : 1.572 seconds
kiloprop.50-resources.delete_coll : 0.907 seconds
kiloprop.50-resources.populate : 2.812 seconds
kiloprop.50-resources.propfind.1-time : 0.329 seconds
kiloprop.50-resources.propfind.50-times : 1.345 seconds
kiloprop.populate-caldata.100 : 12.782 seconds
kiloprop.populate-caldata.mitch-3 : 193.260 seconds
kiloprop.propfind-caldata-100.depth-1.1-time : 1.982 seconds
kiloprop.propfind-caldata-100.depth-1.10-times : 13.770 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.1-time : 37.585 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.10-times : 366.633 seconds
cosmo-trunk-r2210+snarf-trunk-r2434 with 500 resources
kiloprop.500-resources.createuser : 1.378 seconds
kiloprop.500-resources.delete_coll : 5.220 seconds
kiloprop.500-resources.populate : 91.539 seconds
kiloprop.500-resources.propfind.1-time : 0.414 seconds
kiloprop.500-resources.propfind.50-times : 5.187 seconds
kiloprop.populate-caldata.100 : 13.548 seconds
kiloprop.populate-caldata.mitch-3 : 190.212 seconds
kiloprop.propfind-caldata-100.depth-1.1-time : 1.761 seconds
kiloprop.propfind-caldata-100.depth-1.10-times : 15.811 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.1-time : 32.549 seconds
kiloprop.propfind-caldata-mitch-3.depth-1.10-times : 326.275 seconds
-- Jared
More information about the cosmo-dev
mailing list