> -----Original Message-----
> From: Aleksander Slominski [mailto:aslom@cs.indiana.edu]
> Sent: Thursday, October 04, 2001 10:15 PM
> To: KUMAR,PANKAJ (HP-Cupertino,ex1)
> Cc: 'SoapRMI'
> Subject: Re: Benchmarking and Comparing Java based XML Processors ...
>
>
> "KUMAR,PANKAJ (HP-Cupertino,ex1)" wrote:
>
> > What started as a simple curiosity about various ways of
> accessing and
> > manipulating XML in Java and comparing their runtime
> efficiency and memory
> > utilization has now become something I felt I could share
> with others. I
> > call it XPB4J -- XML Processing Benchmark for Java.
> >
> > Besides the XPB4J software, what may be of interest is the
> perforamance
> > figures that I have collected and analyzed for a simple
> processing (
> > gathering certain structural statistics on XML data )
> using SAX API (
> > Xerces and Crimson), DOM API ( Xerces and Crimson), JDOM API (JDOM
> > software), Pull Parser API (XPP software), XSL stylesheets
> ( Xalan ) and
> > Cocoon framework ( Cocoon2).
> >
> > Find more about it at http://www.pankaj-k.net/xpb4j and
> drop me a line if
> > you found it useful in anyway.
>
> hi,
>
> it is very interesting benchmark! as the author of XPP2 i have few
> comments.first i could not find exact instruction on how to
> reproduce results
> - something like actual data samples and command line used
> would be very
> helpful (maybe script?).
>
> i have also some doubts about the way you are gathering time
> information,
> specifically in org.xperf.xpb.XPBDriver you have
>
> long total = 0;
> for (int j = 1; j < loopCount; j++)
> total += pm.execTime[j];
> long average = total/(loopCount - 1);
>
> that is not good as with typical timer resolution of 10 ms it
> will cut off
> time measurements and relative errors can be very high
> (unless you use very
> high resolution timer - there was some time ago JavaWorld
> article about
> accessing Windows timers through JNI ...)
>
> for example using your Data/rxgen.xml that is in zip file
> from your website -
> when running not 10 times but 1000 loopCount i get
> measurement of zero (which
> is obviously wrong unless parser is really fast. :-)) and
> taking average of
> zeros is not good to compute real average...
>
> i fixed this problem by doing thisin XPBDriver to collect
> total time for all
> runs without interruptions:
>
> private void process()
> {
>
> for (int i = 0; i < argPMethods.size(); i++)
> {
> PMethod pm = (PMethod)argPMethods.elementAt(i);
>
> try
> {
> long start = System.currentTimeMillis();
> pm.process(ardr.loopCount, ardr.uris, ardr.gcFlag,
> ardr.gcMeasuredFlag);
> long end = System.currentTimeMillis();
>
> totals[i] = end - start;
> }
> catch (Exception e)
> {
> System.err.println("processing failed for (" + pm.paName +
> ", " + pm.name +
> ") : " + e);
> e.printStackTrace(System.err);
> argPMethods.remove(i); // Exclude it from reporting !!
> --i;
> }
> }
> }
>
> and when formating results i am using floats :-)
>
>
> long total = 0;
> for (int j = 1; j < loopCount; j++) {
> total += pm.execTime[j];
> }
> float average = ((float)totals[i])/(loopCount - 1);
> //long average = total/(loopCount - 1);
> addField(sb, Float.toString(average), fsize);
>
> i have discovered what was causing XPP2 to run slowly. XPP2
> is designed to be
> reused in pool therefore it is by default very greedy for
> memory (will take
> about 10% of total input size) but that compensates very well
> when parser is
> reused hundreds of times :-) however in your PullProcessor
> you are not reuning
> parser instances..
>
> the other side-effect of this starategy is that when a lot
> of new instances
> of XPP2 is created a lot of meory is allocated therefore
> running GC slows down
> execution a lot and for XPP2 more than for other parsers
> (such as SAX).
> thereofre for speed test it is necessary to disable GC in args.xml
>
> and memory usage should be measured separetly IMHO
>
> by just doing this will show that for small input files XPP2
> is 50% faster
> than SAX- see below !!!
>
>
> \xpb4j-0.8>run -loopCount 1000
> C2_LIB is not set. Proceeding without Cocoon ...
> CLASSPATH in use:
> c:\jdk1.3\lib\tools.jar;;.\lib\crimson.jar;.\lib\jdom.jar;.\li
> b\PullParser2_0_2.jar;.\build\xpb4j.jar
> ----------------------- XMLBench 1.0 ----------------
> Garbage Collection Flag : false
> GC in measurement Window : false
> Iteration loop count : 1000
> Show Performance Metrics : true
> Enabled (PActivity, PMethod) tuples: (xstat, sax)
> (xstat, dom) (xstat,
> pull) (xs
> tat, jdom)
> Run URIs: Data\rxgen.xml
> -----------------------------------------------------
> Creating Processors ...
> ... Created Processors.
> Processing Started ...
> ... Processing Completed.
> Writing Performance Measurements to "pdata.xml" ...
> Writing Processing Results to "results.xml" ...
> Execution Time (in milli seconds)::
> method Run#0 Run#143 Run#286 Run#429 Run#572 Run#715
> Run#858 Average
>
> --------------------------------------------------------------
> ----------
> sax 40 10 10 0 10 0
> 10 6.7867866
>
> --------------------------------------------------------------
> ----------
> dom 120 0 10 10 10 10
> 10 7.7387385
>
> --------------------------------------------------------------
> ----------
> pull 50 0 0 0 10 10
> 10 4.32032
>
> --------------------------------------------------------------
> ----------
> jdom 100 10 10 10 10 10
> 10 9.112112
>
> --------------------------------------------------------------
> ----------
>
> when i enable GC results are dramtically different:- every
> test is slower by
> 300-1000% and results are changed considerabley !!!
>
>
> \xpb4j-0.8>run -loopCount 1000
> C2_LIB is not set. Proceeding without Cocoon ...
> CLASSPATH in use:
> c:\jdk1.3\lib\tools.jar;;.\lib\crimson.jar;.\lib\jdom.jar;.\li
> b\PullParser2_0_2.jar;.\build\xpb4j.jar
> ----------------------- XMLBench 1.0 ----------------
> Garbage Collection Flag : true
> GC in measurement Window : false
> Iteration loop count : 1000
> Show Performance Metrics : true
> Enabled (PActivity, PMethod) tuples: (xstat, sax)
> (xstat, dom) (xstat,
> pull) (xs
> tat, jdom)
> Run URIs: Data\rxgen.xml
> -----------------------------------------------------
> Creating Processors ...
> ... Created Processors.
> Processing Started ...
> executed class org.xperf.xpb.xstat.sax.SAXProcessor
> process in 40218 ms
> executed class org.xperf.xpb.xstat.dom.DOMProcessor
> process in 45916 ms
> executed class org.xperf.xpb.xstat.pull.PullProcessor
> process in 44884 ms
> executed class org.xperf.xpb.xstat.jdom.JDOMProcessor
> process in 53898 ms
> ... Processing Completed.
> Writing Performance Measurements to "pdata.xml" ...
> Writing Processing Results to "results.xml" ...
> Execution Time (in milli seconds)::
> method Run#0 Run#143 Run#286 Run#429 Run#572 Run#715
> Run#858 Average
>
> --------------------------------------------------------------
> ----------
> sax 30 10 0 20 0 10
> 10 40.25826
>
> --------------------------------------------------------------
> ----------
> dom 110 10 10 10 0 10
> 0 45.961964
>
> --------------------------------------------------------------
> ----------
> pull 30 0 10 0 10 10
> 0 44.92893
>
> --------------------------------------------------------------
> ----------
> jdom 100 10 0 10 10 10
> 0 53.95195
>
> --------------------------------------------------------------
> ----------
> Memory Used (in KB)::
> method Run#0 Run#15 Run#30 Run#45 Run#60 Run#75
> Run#90 Average
>
> --------------------------------------------------------------
> ----------
> sax 135 107 107 107 107 107 107
>
> --------------------------------------------------------------
> ----------
> dom 91 163 163 163 163 163 163
>
> --------------------------------------------------------------
> ----------
> pull 321 115 115 115 115 115 115
>
> --------------------------------------------------------------
> ----------
> jdom 413 186 186 186 186 186 186
>
> --------------------------------------------------------------
> ----------
>
> resuing XPP2 instances(ie. making XmlPullParser p a field
> of PullProcesor
> class) will result in decreasing memory usgae - now XPP2 is
> smaller by 50%
> than SAX2 and it is still for case when no parser instances
> are reused ! for
> identical test setup as above i get this memory numbers:
>
> Memory Used (in KB)::
> method Run#0 Run#143 Run#286 Run#429 Run#572 Run#715
> Run#858 Average
>
> --------------------------------------------------------------
> ----------
> sax 135 107 107 107 107 107 107
>
> --------------------------------------------------------------
> ----------
> dom 91 163 163 163 163 163 163
>
> --------------------------------------------------------------
> ----------
> pull 134 61 61 61 61 61 61
>
> --------------------------------------------------------------
> ----------
> jdom 413 186 186 186 186 186 186
>
> --------------------------------------------------------------
> ----------
>
>
>
>
>
>
>
>
> and finally as of memory usage - modifying default memory
> policy for XPP2 by
> doing this:
>
> p.setSoftLimit(1* 1024);
> p.setHardLimit(10* 1024);
>
> and using XPP2 for really big files shows that it can be
> smaller than SAX2 -
> for example running rxgen 10000 and using generated 3,670,178
> rxgen.xml file:
>
>
> \xpb4j-0.8>run2 -loopCount 10
> C2_LIB is not set. Proceeding without Cocoon ...
> CLASSPATH in use:
> ..\..\Forge\codes\xsoap\java\PullParser\build\lib\PullParser2_
>
> 1_1_ALPHA.jar;c:\jdk1.3\lib\tools.jar;;.\lib\crimson.jar;.\lib
> \jdom.jar;.\build\
> xpb4j.jar
> ----------------------- XMLBench 1.0 ----------------
> Garbage Collection Flag : true
> GC in measurement Window : false
> Iteration loop count : 10
> Show Performance Metrics : true
> Enabled (PActivity, PMethod) tuples: (xstat, sax)
> (xstat, dom) (xstat,
> pull) (xs
> tat, jdom)
> Run URIs: Data\rxgen.xml
> -----------------------------------------------------
> Creating Processors ...
> ... Created Processors.
> Processing Started ...
> executed class org.xperf.xpb.xstat.sax.SAXProcessor
> process in 6069 ms
> executed class org.xperf.xpb.xstat.dom.DOMProcessor
> process in 14070 ms
> executed class org.xperf.xpb.xstat.pull.PullProcessor
> process in 11617 ms
> executed class org.xperf.xpb.xstat.jdom.JDOMProcessor
> process in 20259 ms
> ... Processing Completed.
> Writing Performance Measurements to "pdata.xml" ...
> Writing Processing Results to "results.xml" ...
> Execution Time (in milli seconds)::
> method Run#0 Run#2 Run#4 Run#6 Run#8 Average
> --------------------------------------------------------
> sax 701 551 570 551 561 675.44446
> --------------------------------------------------------
> dom 1892 1432 1172 1672 1152 1563.3334
> --------------------------------------------------------
> pull 1222 1062 1061 1171 1162 1290.7778
> --------------------------------------------------------
> jdom 2914 1713 1833 2023 1723 2251.0
> --------------------------------------------------------
> Memory Used (in KB)::
> method Run#0 Run#2 Run#4 Run#6 Run#8 Average
> --------------------------------------------------------
> sax 533 497 497 497 497
> --------------------------------------------------------
> dom 13436 13088 13241 12468 13230
> --------------------------------------------------------
> pull 372 717 335 335 335
> --------------------------------------------------------
> jdom 13226 14147 14208 14340 13089
> --------------------------------------------------------
>
> not using setSoft/HardLimit will result in following memory
> utilization
>
>
> Memory Used (in KB)::
> method Run#0 Run#2 Run#4 Run#6 Run#8 Average
> --------------------------------------------------------
> sax 533 497 497 497 497
> --------------------------------------------------------
> dom 13429 13088 13241 12473 13230
> --------------------------------------------------------
> pull 946 959 1038 1038 1038
> --------------------------------------------------------
> jdom 13163 13820 14147 14367 13240
> --------------------------------------------------------
>
> also in PullProcessor you are allocating String for each
> content (readContent)
> but in SAX parser it is using only int len. version 2.1.x of
> XPP2 has now
> getContentLength() to avoid need to allocate String whne
> youonly coolect
> length/
>
> i hope you will update your tests to have separate
> performance run and memeory
> runs (maybe with extra x seconds pause) and post results.
>
> thanks,
>
> alek
>
>