You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@commons.apache.org by "Craig R. McClanahan" <cr...@apache.org> on 2003/08/02 23:37:06 UTC
[BeanUtils] Interesting Microbenchmarks
TheServerSide (www.theserverside.com) recently published a case study that
attempted to analyze the performance characteristics of a variety of
middleware configurations, including two J2EE app servers and Microsoft's
.NET platform. One of the hot spots that showed up in the Java based
figures was identified as heavy use of reflection (the test app was Struts
based and therefore uses commons-beanutils), but the report did not detail
these findings.
Despite the fact that the test condtions were very artificial (the
database was tuned in a way that it was never the hotspot, which is unlike
virtually any high-use web application in production), it prompted a bit
of discussion over whether using reflection was a good idea. This in turn
prompted me to write a couple of simple microbenchmarks to measure the
behavior of the most commonly used BeanUtils and PropertyUtils methods for
copying sets of properties -- copyProperties() and populate().
Legend:
======
"bean" - A plain old Java object (POJO) with eight properties,
one of each of the standard primitive types and one
String (org.apache.commons.beanutils.BenchBean)
"dyna" - An instance of org.apache.commons.beanutils.BasicDynaBean
with exactly the same properties and types. The property
types for primitives in a DynaBean are the wrapper classes
such as java.lang.Integer.
"map" - An instance of HashMap with eight entries pointing at
exactly the same values. The values for primitives
of the corresponding wrapper class types.
"strs" - An instance of HashMap with eight entries pointing at
the same values, but all Strings (simulating request
parameters that are used to populate a form bean in Struts).
"Dura #1" - Duration for 100,000 loops on my 1ghz desktop (milliseconds)
"Dura #2" - Duration for 50,000 loops on my 500mhz laptop (milliseconds)
I tested all the legal combinations of an origin object (bean, dyna,
map, or strs) to a destination object (bean or dyna). The tests were run
on a 1 gigahertz PC running Linux (Red Hat 9) with Sun's JDK 1.4.2, and on
a 500mhz laptop running Win2K with Sun's 1.4.2. The loop count was set to
100,000 in the PC case, and 50,000 in the laptop case, so the overall
execution times should be roughly the same (since the desktop is roughly
twice as fast). Execution time was measured in milliseconds. For each
test, I ran an untimed execution of the specified number of iterations (to
prime HotSpot), followed by a timed execution of the same number of
iterations.
To run these for yourselves, check out the HEAD branch of beanutils (or
grab a source nightly distro dated 20030803 or later), and run "ant
bench".
Results for BeanUtils (which performs type conversions):
=======================================================
Method Dest Orig Dura #1 Dura #2
-------------- ---- ---- ------- -------
copyProperties bean bean 17,703 17,075
copyProperties dyna bean 17,463 17,074
copyProperties bean dyna 15,413 15,042
copyProperties dyna dyna 13,020 12,077
copyProperties bean map 15,626 15,192
copyProperties dyna map 12,999 12,237
copyProperties bean strs 16,302 16,093
copyProperties dyna strs 13,940 13,129
populate bean map 7,438 7,481
populate dyna map 5,082 5,368
populate bean strs 5,768 5,739
populate dyna strs 3,865 3,746
Results for PropertyUtils (no type conversions):
===============================================
Method Dest Orig Dura #1 Dura #2
-------------- ---- ---- ------- -------
copyProperties bean bean 5,595 5,107
copyProperties dyna bean 4,567 4,126
copyProperties bean dyna 3,791 3,675
copyProperties dyna dyna 844 681
copyProperties bean map 3,938 3,755
copyProperties dyna map 931 772
Observations:
============
* The absoute numbers are not particularly interesting, other than the
fact that they confirm my belief that copying properties (whether
using reflection or not) is very unlikely to be a bottleneck -- even
on bargain basement hardware (in today's world), we're talking about
copying all the properties in anything from 0.8 microseconds up to
177 microseconds.
* This is a very limited test case, with only one pattern of properties.
I suspect it will be on the worst case side in terms of the number
of conversions required, compared to how most people use these methods
in real applications.
* Increasing the number of properties being copied will (of course)
increase the execution times, but I suspect it will not change the
ratios between alternatives much. I've done a few informal tests
with more and fewer properties, but this will be worth investigating
in more detail as well.
* Only the cases where a "bean" was the destination or origin use
reflection at all. The "map" case is just doing HashMap gets and puts,
while the "dyna" case is really the "map" case plus type safety
checks.
* In all scenarios, using "dyna" was faster than using "bean", ranging
from statistically insignificant to pretty substantial percentages.
For Struts based apps in particular, that means using DynaActionForm
for form beans, with the current BeanUtils code, will give better
performance than using standard ActionForm bean classes. It also
seems that BasicDynaBean would make a pretty good Data Transfer Object
for moving data between tiers, adding type safety without giving up
the performance of using just a HashMap.
* One would expect using a "map" as the origin would be roughly
the same as using a "dyna", because they both iterate over keys and
values in a HashMap internally. The fact that using "dyna" was often
faster is somewhat anomalous, and is likely based on differing amounts
of optimization inside the BeanUtils and PropertyUtils loops and
getter/setter implementations.
* Of particular interest to Struts users is the code that populates
the form bean. The two lines that describe this use case (populate
to "bean" from "strs", and populate to "dyna" from "strs") indicate
that this operation is already highly optimized, running much
faster than the more general purpose copyProperties() method with the
same argument types.
* From casual observation of the current source, I suspect the longer
times for "bean" objects have more to do with the way that
PropertyDescriptor and Method instances are cached and searched in
PropertyUtils than they have with the time of the reflection-based
execution of the property getters and setters. There is lots of room
here to optimize.
* It will be very useful to have people try these microbenchmarks in a
variety of different environments, and create variations of them with
different kinds of origin and destination beans, to provide a wider
set of profiles when we attempt optimization on the underlying code.
Please feel free to post patches to the microbenchmark sources, so that
everyone can execute exactly the same set of tests.
* It will also be interesting to try this on different JDK generations,
to confirm whether the improvements in reflection performance that have
been described for recent versions shows through in the results here.
Craig McClanahan
---------------------------------------------------------------------
To unsubscribe, e-mail: commons-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: commons-dev-help@jakarta.apache.org
Re: [BeanUtils] Interesting Microbenchmarks
Posted by Phil Steitz <ph...@steitz.com>.
Craig R. McClanahan wrote:
<snip>
It will also be interesting to try this on different JDK
generations, to confirm whether the improvements in reflection
performance that have been described for recent versions shows through
in the results here.
</snip>
Here are some results comparing JDK versions. All tests were run on an
IBM ThinkPad T23, 1ghz, 512MB RAM, Red Hat Linux 8.0 (kernel 2.4.18-14).
All JDKs are Sun. I did not recompile the sources or tests on 1.3 or 1.2
-- i.e. all tests use classes compiled under 1.4.2.(built using CVS HEAD
on 8/2, after PropertyUtils optimization commit by craigmcc, 2003/08/02
17:43:52).
Results for BeanUtils (which performs type conversions):
=======================================================
Method Dest Orig 1.4.2 1.3.1_08 1.2.2_016
-------------- ---- ---- ------ -------- ---------
copyProperties bean bean 18445 36050 108544
copyProperties dyna bean 19441 28543 104344
copyProperties bean dyna 16329 26175 88336
copyProperties dyna dyna 13255 13824 61661
copyProperties bean map 16444 26712 91759
copyProperties dyna map 13554 14270 65854
copyProperties bean strs 17395 27974 99046
copyProperties dyna strs 14415 16582 71543
populate bean map 7815 18596 69910
populate dyna map 5732 8561 52778
populate bean strs 5845 16332 62717
populate dyna strs 4061 6243 46365
Results for PropertyUtils (no type conversions):
===============================================
Method Dest Orig 1.4.2 1.3.1_08 1.2.2_016
-------------- ---- ---- ------ -------- ---------
copyProperties bean bean 5439 19971 61233
copyProperties dyna bean 4331 12948 50071
copyProperties bean dyna 3237 10546 37851
copyProperties dyna dyna 697 1038 13146
copyProperties bean map 3408 10685 41619
copyProperties dyna map 776 1254 16328
-Phil
Re: [BeanUtils] Interesting Microbenchmarks
Posted by Phil Steitz <ph...@steitz.com>.
Craig R. McClanahan wrote:
<snip>
It will also be interesting to try this on different JDK
generations, to confirm whether the improvements in reflection
performance that have been described for recent versions shows through
in the results here.
</snip>
Here are some results comparing JDK versions. All tests were run on an
IBM ThinkPad T23, 1ghz, 512MB RAM, Red Hat Linux 8.0 (kernel 2.4.18-14).
All JDKs are Sun. I did not recompile the sources or tests on 1.3 or 1.2
-- i.e. all tests use classes compiled under 1.4.2.(built using CVS HEAD
on 8/2, after PropertyUtils optimization commit by craigmcc, 2003/08/02
17:43:52).
Results for BeanUtils (which performs type conversions):
=======================================================
Method Dest Orig 1.4.2 1.3.1_08 1.2.2_016
-------------- ---- ---- ------ -------- ---------
copyProperties bean bean 18445 36050 108544
copyProperties dyna bean 19441 28543 104344
copyProperties bean dyna 16329 26175 88336
copyProperties dyna dyna 13255 13824 61661
copyProperties bean map 16444 26712 91759
copyProperties dyna map 13554 14270 65854
copyProperties bean strs 17395 27974 99046
copyProperties dyna strs 14415 16582 71543
populate bean map 7815 18596 69910
populate dyna map 5732 8561 52778
populate bean strs 5845 16332 62717
populate dyna strs 4061 6243 46365
Results for PropertyUtils (no type conversions):
===============================================
Method Dest Orig 1.4.2 1.3.1_08 1.2.2_016
-------------- ---- ---- ------ -------- ---------
copyProperties bean bean 5439 19971 61233
copyProperties dyna bean 4331 12948 50071
copyProperties bean dyna 3237 10546 37851
copyProperties dyna dyna 697 1038 13146
copyProperties bean map 3408 10685 41619
copyProperties dyna map 776 1254 16328
-Phil
---------------------------------------------------------------------
To unsubscribe, e-mail: commons-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: commons-dev-help@jakarta.apache.org
Re: [BeanUtils] Interesting Microbenchmarks
Posted by "Craig R. McClanahan" <cr...@apache.org>.
On Mon, 4 Aug 2003, Vic Cekvenich wrote:
> Date: Mon, 04 Aug 2003 18:30:09 -0400
> From: Vic Cekvenich <vi...@baseBeans.com>
> Reply-To: Struts Developers List <st...@jakarta.apache.org>
> To: struts-dev@jakarta.apache.org
> Subject: Re: [BeanUtils] Interesting Microbenchmarks
>
> I think jPetStore is using DynaBeans.... and that is what they saw -
> Reflection time.
> I myself do not use DynaBeans (or think they are a good idea for a few
> other reasons, like unit testing and reuse).
>
The problem with that theory is that DynaBeans do not use reflection --
they just wrap a HashMap with type safety checks. (And, at least in the
limited microbenchmark I published, they are faster).
> .V
Craig
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org
Re: [BeanUtils] Interesting Microbenchmarks
Posted by Vic Cekvenich <vi...@baseBeans.com>.
I think jPetStore is using DynaBeans.... and that is what they saw -
Reflection time.
I myself do not use DynaBeans (or think they are a good idea for a few
other reasons, like unit testing and reuse).
.V
Craig R. McClanahan wrote:
> The most important factor in page rendering time (which is not the same as
> the CPU consumption being discussed on the ServerSide thread) is the
> quality of the JSP page compiler. Tomcat 4.0.6 (your platform) uses the
> original version of Jasper, whereas the current generation (4.1.27 and
> 5.0.6) uses a completely rewritten "Jasper2". On some apps I'm familiar
> with, just this change resulted in 6x-8x improvements in rendering
> speed. The difference is startling, even in a single user environment.
>
> You're right ... reflection gets a bum rap when it gets blamed for long
> render times unless your CPU is maxed out. Even then, it's typically an
> insignificantly small factor in the big scheme of things.
>
> Craig
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org
RE: [BeanUtils] Interesting Microbenchmarks
Posted by "Craig R. McClanahan" <cr...@apache.org>.
The most important factor in page rendering time (which is not the same as
the CPU consumption being discussed on the ServerSide thread) is the
quality of the JSP page compiler. Tomcat 4.0.6 (your platform) uses the
original version of Jasper, whereas the current generation (4.1.27 and
5.0.6) uses a completely rewritten "Jasper2". On some apps I'm familiar
with, just this change resulted in 6x-8x improvements in rendering
speed. The difference is startling, even in a single user environment.
You're right ... reflection gets a bum rap when it gets blamed for long
render times unless your CPU is maxed out. Even then, it's typically an
insignificantly small factor in the big scheme of things.
Craig
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org
RE: [BeanUtils] Interesting Microbenchmarks
Posted by Kurt Post <kp...@cfl.rr.com>.
I stand corrected. Changing to Tomcat 4.1.x made a huge difference.
With tomcat 4.0.3 pages rendering was taking more the 2 seconds during which
CPU was pegged at 100%. After repeatedly reloading test pages, the CPU fan
on my machine was running at hurricane speed.
With Tomcat 4.1.24, page render times for all test pages were usually so
fast that the displayed time came out at 0 ms (10 ms is the res of the
system timer). The only difference between the page of html:checkbox tags
vs. the page full of html:messages tags was that the html:checkbox page was
a little bit more likely to show a render time of 10 ms which happened about
one out of four times. The html:messages page showed a render time of 10 ms
about one out of every 6 times.
Looking at what the new JSP compiler cranks out it looks like its doing tag
pooling now as well as optimizing generated code for the case when a
BodyTagSUpport tag does not have any body content.
Very cool, that's one less problem to worry about :)
Kurt
-----Original Message-----
From: Kurt Post [mailto:kpost@cfl.rr.com]
Sent: Monday, August 04, 2003 5:47 PM
To: Struts Developers List; dgraham@apache.org
Subject: RE: [BeanUtils] Interesting Microbenchmarks
But doesn't the big speed improvement of switching from html:checkbox to
html:messages kind of eliminate the tomcat differences. Both of these tags
are BodyTagSupport tags and thus the JSP compiler generates the same code
with only the object names and attribute names being different.
If you have two different tag invocations ( <html:checkbox value="someval"/>
and <html:messages id="junk"/>) and a page full of one of them renders 100
times faster then a page full of the other, can't you eliminate the app
server as the cause for this difference?
-----Original Message-----
From: David Graham [mailto:grahamdavid1980@yahoo.com]
Sent: Monday, August 04, 2003 5:23 PM
To: Struts Developers List
Subject: RE: [BeanUtils] Interesting Microbenchmarks
It would be more interesting if you ran the tests on the latest Tomcat
production build because of the *large* JSP performance improvements
between the 4.0.x and 4.1.x series.
David
--- Kurt Post <kp...@cfl.rr.com> wrote:
> I am creating a web app that has several survey pages where there are a
> total of 120 or more radio buttons and check boxes on one page. I have
> been
> seeing average page render times on the order of 2 to 2.5 seconds (some
> times as bad as 5 seconds) with a single user hitting the site. I was
> going
> to put off my investigation into this problem until the site was in a
> more
> finished form. But since this topic has come up and because I needed
> something to keep me busy until I go on vacation Wednesday, I decided to
> look into it now.
>
> After running some tests which I'll describe below, I'm starting to feel
> like the performance problem reported in TheServerSide case study was
> caused
> by excessive garbage collection and not by the use of reflection to
> display
> and update form values. Also their choice to use incremental garbage
> collection in their tests probably made the struts app look far worse
> then
> it would have if it had been run with standard garbage collection.
>
> Like others who have posted on this subject recently, my initial guess
> was
> that reflection was a likely cause of the performance bottleneck. But
> there
> was one thing that seemed to contradict my theory. While it was true
> that
> it took 2 seconds or more to render the page to the browser; when I
> clicked
> the submit button after checking all check boxes, the form bean was
> updated
> and the main page was rendered almost instantly. So I decided to figure
> out
> just how much time was being spent doing reflection. My testing showed
> that
> time spent on reflection to render the page was consuming so little time
> that it couldn't even be measured. In my opinion, the big performance
> problem is caused by garbage collection firing much more often then you
> would expect. Perhaps making changes which reduce the number of objects
> being created and destroyed for each tag invocation is the best way to
> improve performance.
>
>
> How I Tested For Time Spent On Reflection
> -----------------------------------------
>
> To prepare for the tests, I made two test JSP pages. Both pages
> consisted
> of 150 html:checkbox tags arranged in 15 rows with 10 checkboxes per
> row.
> The first test page contained html:checkbox elements with property
> values
> similar to "survey(questionName).selectedValues[5]". On the second test
> page, I removed all property attributes from the html:checkbox elements
> thus
> leaving them with just a value="<some value>" attribute. Finally,
> struts-html.tld was modified to make the html:checkbox "property"
> attribute
> optional.
>
> Looking at CheckboxTag.java and RequestUtils.java, you can see that if
> the
> "property" attribute is not supplied to the html:checkbox tag, then
> "RequestUtils.lookup(pageCOntext, name, property, null)" in
> CheckbopxTag.java will simply return the form bean which is retrieved
> via a
> call to pageCOntext.findAttribute(). The beanutils are never called if
> property == null.
>
> So how much faster was the second test page (which did not use
> reflection)
> rendered then the first test page which did us e reflection? The time
> difference was too small to be measured. Both test pages took anywhere
> from
> 2 seconds to six seconds to render with the average time being around
> 3.2
> seconds.
>
>
> So Reflection Wasn't The Problem - More Experiments To Get At The
> Problem
>
-------------------------------------------------------------------------
>
> With reflection eliminated, my next suspicion was that the app server
> (tomcat 4.0.6 bundled with NetBeans 3.5) was the problem. I had read
> that
> many performance enhancements had been added since tomcat 4.0.6.
> Looking at
> the .java code produced by the JSP compiler, I could see room for
> optimization but there was nothing that could explain the terrible page
> rendering times I was seeing.
>
> So to test it out, I copied the second test page and replaced all
> html:checkbox tags with html:messages tags. In the context of my test
> page,
> the html:messages tag would simply look for messages at
> Globals.ERROR_KEY.
> Since nothing would be found at that key, the tag would just render
> nothing.
>
> This test page which had 150 html:messages tags on it typically rendered
> in
> 10 to 20 milliseconds.
>
> Finally just for the heck of it, I made a test JSP page which just
> contained
> 150 <input type="checkbox"...> tags. This page typically render in 0 to
> 10
> milliseconds.
>
>
> Effect Of Changing To Incremental Garbage Collection
> ----------------------------------------------------
>
> Up until now, all tests were performed with "java -server ...". By now
> I
> was getting convinced that the problem was that garbage collection was
> happening every time one of the first two test pages were being rendered
> and
> that is what was killing the performance. Turning on GC logging
> confirmed
> that. So, I decided to turn on incremental garbage collection. Wow,
> what a
> difference. Things started taking twice as long! Looking at the GC
> log, I
> could see that the GC was firing pretty much constantly (like you would
> expect) but that many of those incremental GC's were taking .2 to .9
> seconds. The result was much worse performance on the first two test
> pages
> and even the third test page (with html:messages tags on it was almost
> twice
> as slow. The last test page which just contained no struts tags except
> for
> html:form and html:submit still took from 0 to 10 milliseconds but I
> thick
> this was just due to limitations in accuracy of the system timer.
>
>
> Test Environment
> ----------------
> Intel P4 2.8 GHZ 512MB
> Window XP
> JDK 1.4.1.4.1_04-b01
> Tomcat 4.0.6 running under NetBeans 3.5 (normal execution, not debug)
> Struts 1.1
>
>
> Kurt
>
> -----Original Message-----
> From: Craig R. McClanahan [mailto:craigmcc@apache.org]
> Sent: Saturday, August 02, 2003 5:37 PM
> To: commons-dev@jakarta.apache.org
> Cc: struts-dev@jakarta.apache.org
> Subject: [BeanUtils] Interesting Microbenchmarks
>
>
> TheServerSide (www.theserverside.com) recently published a case study
> that
> attempted to analyze the performance characteristics of a variety of
> middleware configurations, including two J2EE app servers and
> Microsoft's
> .NET platform. One of the hot spots that showed up in the Java based
> figures was identified as heavy use of reflection (the test app was
> Struts
> based and therefore uses commons-beanutils), but the report did not
> detail
> these findings.
>
> Despite the fact that the test condtions were very artificial (the
> database was tuned in a way that it was never the hotspot, which is
> unlike
> virtually any high-use web application in production), it prompted a bit
> of discussion over whether using reflection was a good idea. This in
> turn
> prompted me to write a couple of simple microbenchmarks to measure the
> behavior of the most commonly used BeanUtils and PropertyUtils methods
> for
> copying sets of properties -- copyProperties() and populate().
>
> Legend:
> ======
>
> "bean" - A plain old Java object (POJO) with eight properties,
> one of each of the standard primitive types and one
> String (org.apache.commons.beanutils.BenchBean)
>
> "dyna" - An instance of org.apache.commons.beanutils.BasicDynaBean
> with exactly the same properties and types. The property
> types for primitives in a DynaBean are the wrapper classes
> such as java.lang.Integer.
>
> "map" - An instance of HashMap with eight entries pointing at
> exactly the same values. The values for primitives
> of the corresponding wrapper class types.
>
> "strs" - An instance of HashMap with eight entries pointing at
> the same values, but all Strings (simulating request
> parameters that are used to populate a form bean in Struts).
>
>
=== message truncated ===
__________________________________
Do you Yahoo!?
Yahoo! SiteBuilder - Free, easy-to-use web site design software
http://sitebuilder.yahoo.com
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org
RE: [BeanUtils] Interesting Microbenchmarks
Posted by Kurt Post <kp...@cfl.rr.com>.
But doesn't the big speed improvement of switching from html:checkbox to
html:messages kind of eliminate the tomcat differences. Both of these tags
are BodyTagSupport tags and thus the JSP compiler generates the same code
with only the object names and attribute names being different.
If you have two different tag invocations ( <html:checkbox value="someval"/>
and <html:messages id="junk"/>) and a page full of one of them renders 100
times faster then a page full of the other, can't you eliminate the app
server as the cause for this difference?
-----Original Message-----
From: David Graham [mailto:grahamdavid1980@yahoo.com]
Sent: Monday, August 04, 2003 5:23 PM
To: Struts Developers List
Subject: RE: [BeanUtils] Interesting Microbenchmarks
It would be more interesting if you ran the tests on the latest Tomcat
production build because of the *large* JSP performance improvements
between the 4.0.x and 4.1.x series.
David
--- Kurt Post <kp...@cfl.rr.com> wrote:
> I am creating a web app that has several survey pages where there are a
> total of 120 or more radio buttons and check boxes on one page. I have
> been
> seeing average page render times on the order of 2 to 2.5 seconds (some
> times as bad as 5 seconds) with a single user hitting the site. I was
> going
> to put off my investigation into this problem until the site was in a
> more
> finished form. But since this topic has come up and because I needed
> something to keep me busy until I go on vacation Wednesday, I decided to
> look into it now.
>
> After running some tests which I'll describe below, I'm starting to feel
> like the performance problem reported in TheServerSide case study was
> caused
> by excessive garbage collection and not by the use of reflection to
> display
> and update form values. Also their choice to use incremental garbage
> collection in their tests probably made the struts app look far worse
> then
> it would have if it had been run with standard garbage collection.
>
> Like others who have posted on this subject recently, my initial guess
> was
> that reflection was a likely cause of the performance bottleneck. But
> there
> was one thing that seemed to contradict my theory. While it was true
> that
> it took 2 seconds or more to render the page to the browser; when I
> clicked
> the submit button after checking all check boxes, the form bean was
> updated
> and the main page was rendered almost instantly. So I decided to figure
> out
> just how much time was being spent doing reflection. My testing showed
> that
> time spent on reflection to render the page was consuming so little time
> that it couldn't even be measured. In my opinion, the big performance
> problem is caused by garbage collection firing much more often then you
> would expect. Perhaps making changes which reduce the number of objects
> being created and destroyed for each tag invocation is the best way to
> improve performance.
>
>
> How I Tested For Time Spent On Reflection
> -----------------------------------------
>
> To prepare for the tests, I made two test JSP pages. Both pages
> consisted
> of 150 html:checkbox tags arranged in 15 rows with 10 checkboxes per
> row.
> The first test page contained html:checkbox elements with property
> values
> similar to "survey(questionName).selectedValues[5]". On the second test
> page, I removed all property attributes from the html:checkbox elements
> thus
> leaving them with just a value="<some value>" attribute. Finally,
> struts-html.tld was modified to make the html:checkbox "property"
> attribute
> optional.
>
> Looking at CheckboxTag.java and RequestUtils.java, you can see that if
> the
> "property" attribute is not supplied to the html:checkbox tag, then
> "RequestUtils.lookup(pageCOntext, name, property, null)" in
> CheckbopxTag.java will simply return the form bean which is retrieved
> via a
> call to pageCOntext.findAttribute(). The beanutils are never called if
> property == null.
>
> So how much faster was the second test page (which did not use
> reflection)
> rendered then the first test page which did us e reflection? The time
> difference was too small to be measured. Both test pages took anywhere
> from
> 2 seconds to six seconds to render with the average time being around
> 3.2
> seconds.
>
>
> So Reflection Wasn't The Problem - More Experiments To Get At The
> Problem
>
-------------------------------------------------------------------------
>
> With reflection eliminated, my next suspicion was that the app server
> (tomcat 4.0.6 bundled with NetBeans 3.5) was the problem. I had read
> that
> many performance enhancements had been added since tomcat 4.0.6.
> Looking at
> the .java code produced by the JSP compiler, I could see room for
> optimization but there was nothing that could explain the terrible page
> rendering times I was seeing.
>
> So to test it out, I copied the second test page and replaced all
> html:checkbox tags with html:messages tags. In the context of my test
> page,
> the html:messages tag would simply look for messages at
> Globals.ERROR_KEY.
> Since nothing would be found at that key, the tag would just render
> nothing.
>
> This test page which had 150 html:messages tags on it typically rendered
> in
> 10 to 20 milliseconds.
>
> Finally just for the heck of it, I made a test JSP page which just
> contained
> 150 <input type="checkbox"...> tags. This page typically render in 0 to
> 10
> milliseconds.
>
>
> Effect Of Changing To Incremental Garbage Collection
> ----------------------------------------------------
>
> Up until now, all tests were performed with "java -server ...". By now
> I
> was getting convinced that the problem was that garbage collection was
> happening every time one of the first two test pages were being rendered
> and
> that is what was killing the performance. Turning on GC logging
> confirmed
> that. So, I decided to turn on incremental garbage collection. Wow,
> what a
> difference. Things started taking twice as long! Looking at the GC
> log, I
> could see that the GC was firing pretty much constantly (like you would
> expect) but that many of those incremental GC's were taking .2 to .9
> seconds. The result was much worse performance on the first two test
> pages
> and even the third test page (with html:messages tags on it was almost
> twice
> as slow. The last test page which just contained no struts tags except
> for
> html:form and html:submit still took from 0 to 10 milliseconds but I
> thick
> this was just due to limitations in accuracy of the system timer.
>
>
> Test Environment
> ----------------
> Intel P4 2.8 GHZ 512MB
> Window XP
> JDK 1.4.1.4.1_04-b01
> Tomcat 4.0.6 running under NetBeans 3.5 (normal execution, not debug)
> Struts 1.1
>
>
> Kurt
>
> -----Original Message-----
> From: Craig R. McClanahan [mailto:craigmcc@apache.org]
> Sent: Saturday, August 02, 2003 5:37 PM
> To: commons-dev@jakarta.apache.org
> Cc: struts-dev@jakarta.apache.org
> Subject: [BeanUtils] Interesting Microbenchmarks
>
>
> TheServerSide (www.theserverside.com) recently published a case study
> that
> attempted to analyze the performance characteristics of a variety of
> middleware configurations, including two J2EE app servers and
> Microsoft's
> .NET platform. One of the hot spots that showed up in the Java based
> figures was identified as heavy use of reflection (the test app was
> Struts
> based and therefore uses commons-beanutils), but the report did not
> detail
> these findings.
>
> Despite the fact that the test condtions were very artificial (the
> database was tuned in a way that it was never the hotspot, which is
> unlike
> virtually any high-use web application in production), it prompted a bit
> of discussion over whether using reflection was a good idea. This in
> turn
> prompted me to write a couple of simple microbenchmarks to measure the
> behavior of the most commonly used BeanUtils and PropertyUtils methods
> for
> copying sets of properties -- copyProperties() and populate().
>
> Legend:
> ======
>
> "bean" - A plain old Java object (POJO) with eight properties,
> one of each of the standard primitive types and one
> String (org.apache.commons.beanutils.BenchBean)
>
> "dyna" - An instance of org.apache.commons.beanutils.BasicDynaBean
> with exactly the same properties and types. The property
> types for primitives in a DynaBean are the wrapper classes
> such as java.lang.Integer.
>
> "map" - An instance of HashMap with eight entries pointing at
> exactly the same values. The values for primitives
> of the corresponding wrapper class types.
>
> "strs" - An instance of HashMap with eight entries pointing at
> the same values, but all Strings (simulating request
> parameters that are used to populate a form bean in Struts).
>
>
=== message truncated ===
__________________________________
Do you Yahoo!?
Yahoo! SiteBuilder - Free, easy-to-use web site design software
http://sitebuilder.yahoo.com
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org
RE: [BeanUtils] Interesting Microbenchmarks
Posted by David Graham <gr...@yahoo.com>.
It would be more interesting if you ran the tests on the latest Tomcat
production build because of the *large* JSP performance improvements
between the 4.0.x and 4.1.x series.
David
--- Kurt Post <kp...@cfl.rr.com> wrote:
> I am creating a web app that has several survey pages where there are a
> total of 120 or more radio buttons and check boxes on one page. I have
> been
> seeing average page render times on the order of 2 to 2.5 seconds (some
> times as bad as 5 seconds) with a single user hitting the site. I was
> going
> to put off my investigation into this problem until the site was in a
> more
> finished form. But since this topic has come up and because I needed
> something to keep me busy until I go on vacation Wednesday, I decided to
> look into it now.
>
> After running some tests which I'll describe below, I'm starting to feel
> like the performance problem reported in TheServerSide case study was
> caused
> by excessive garbage collection and not by the use of reflection to
> display
> and update form values. Also their choice to use incremental garbage
> collection in their tests probably made the struts app look far worse
> then
> it would have if it had been run with standard garbage collection.
>
> Like others who have posted on this subject recently, my initial guess
> was
> that reflection was a likely cause of the performance bottleneck. But
> there
> was one thing that seemed to contradict my theory. While it was true
> that
> it took 2 seconds or more to render the page to the browser; when I
> clicked
> the submit button after checking all check boxes, the form bean was
> updated
> and the main page was rendered almost instantly. So I decided to figure
> out
> just how much time was being spent doing reflection. My testing showed
> that
> time spent on reflection to render the page was consuming so little time
> that it couldn't even be measured. In my opinion, the big performance
> problem is caused by garbage collection firing much more often then you
> would expect. Perhaps making changes which reduce the number of objects
> being created and destroyed for each tag invocation is the best way to
> improve performance.
>
>
> How I Tested For Time Spent On Reflection
> -----------------------------------------
>
> To prepare for the tests, I made two test JSP pages. Both pages
> consisted
> of 150 html:checkbox tags arranged in 15 rows with 10 checkboxes per
> row.
> The first test page contained html:checkbox elements with property
> values
> similar to "survey(questionName).selectedValues[5]". On the second test
> page, I removed all property attributes from the html:checkbox elements
> thus
> leaving them with just a value="<some value>" attribute. Finally,
> struts-html.tld was modified to make the html:checkbox "property"
> attribute
> optional.
>
> Looking at CheckboxTag.java and RequestUtils.java, you can see that if
> the
> "property" attribute is not supplied to the html:checkbox tag, then
> "RequestUtils.lookup(pageCOntext, name, property, null)" in
> CheckbopxTag.java will simply return the form bean which is retrieved
> via a
> call to pageCOntext.findAttribute(). The beanutils are never called if
> property == null.
>
> So how much faster was the second test page (which did not use
> reflection)
> rendered then the first test page which did us e reflection? The time
> difference was too small to be measured. Both test pages took anywhere
> from
> 2 seconds to six seconds to render with the average time being around
> 3.2
> seconds.
>
>
> So Reflection Wasn't The Problem - More Experiments To Get At The
> Problem
>
-------------------------------------------------------------------------
>
> With reflection eliminated, my next suspicion was that the app server
> (tomcat 4.0.6 bundled with NetBeans 3.5) was the problem. I had read
> that
> many performance enhancements had been added since tomcat 4.0.6.
> Looking at
> the .java code produced by the JSP compiler, I could see room for
> optimization but there was nothing that could explain the terrible page
> rendering times I was seeing.
>
> So to test it out, I copied the second test page and replaced all
> html:checkbox tags with html:messages tags. In the context of my test
> page,
> the html:messages tag would simply look for messages at
> Globals.ERROR_KEY.
> Since nothing would be found at that key, the tag would just render
> nothing.
>
> This test page which had 150 html:messages tags on it typically rendered
> in
> 10 to 20 milliseconds.
>
> Finally just for the heck of it, I made a test JSP page which just
> contained
> 150 <input type="checkbox"...> tags. This page typically render in 0 to
> 10
> milliseconds.
>
>
> Effect Of Changing To Incremental Garbage Collection
> ----------------------------------------------------
>
> Up until now, all tests were performed with "java -server ...". By now
> I
> was getting convinced that the problem was that garbage collection was
> happening every time one of the first two test pages were being rendered
> and
> that is what was killing the performance. Turning on GC logging
> confirmed
> that. So, I decided to turn on incremental garbage collection. Wow,
> what a
> difference. Things started taking twice as long! Looking at the GC
> log, I
> could see that the GC was firing pretty much constantly (like you would
> expect) but that many of those incremental GC's were taking .2 to .9
> seconds. The result was much worse performance on the first two test
> pages
> and even the third test page (with html:messages tags on it was almost
> twice
> as slow. The last test page which just contained no struts tags except
> for
> html:form and html:submit still took from 0 to 10 milliseconds but I
> thick
> this was just due to limitations in accuracy of the system timer.
>
>
> Test Environment
> ----------------
> Intel P4 2.8 GHZ 512MB
> Window XP
> JDK 1.4.1.4.1_04-b01
> Tomcat 4.0.6 running under NetBeans 3.5 (normal execution, not debug)
> Struts 1.1
>
>
> Kurt
>
> -----Original Message-----
> From: Craig R. McClanahan [mailto:craigmcc@apache.org]
> Sent: Saturday, August 02, 2003 5:37 PM
> To: commons-dev@jakarta.apache.org
> Cc: struts-dev@jakarta.apache.org
> Subject: [BeanUtils] Interesting Microbenchmarks
>
>
> TheServerSide (www.theserverside.com) recently published a case study
> that
> attempted to analyze the performance characteristics of a variety of
> middleware configurations, including two J2EE app servers and
> Microsoft's
> .NET platform. One of the hot spots that showed up in the Java based
> figures was identified as heavy use of reflection (the test app was
> Struts
> based and therefore uses commons-beanutils), but the report did not
> detail
> these findings.
>
> Despite the fact that the test condtions were very artificial (the
> database was tuned in a way that it was never the hotspot, which is
> unlike
> virtually any high-use web application in production), it prompted a bit
> of discussion over whether using reflection was a good idea. This in
> turn
> prompted me to write a couple of simple microbenchmarks to measure the
> behavior of the most commonly used BeanUtils and PropertyUtils methods
> for
> copying sets of properties -- copyProperties() and populate().
>
> Legend:
> ======
>
> "bean" - A plain old Java object (POJO) with eight properties,
> one of each of the standard primitive types and one
> String (org.apache.commons.beanutils.BenchBean)
>
> "dyna" - An instance of org.apache.commons.beanutils.BasicDynaBean
> with exactly the same properties and types. The property
> types for primitives in a DynaBean are the wrapper classes
> such as java.lang.Integer.
>
> "map" - An instance of HashMap with eight entries pointing at
> exactly the same values. The values for primitives
> of the corresponding wrapper class types.
>
> "strs" - An instance of HashMap with eight entries pointing at
> the same values, but all Strings (simulating request
> parameters that are used to populate a form bean in Struts).
>
>
=== message truncated ===
__________________________________
Do you Yahoo!?
Yahoo! SiteBuilder - Free, easy-to-use web site design software
http://sitebuilder.yahoo.com
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org
RE: [BeanUtils] Interesting Microbenchmarks
Posted by Kurt Post <kp...@cfl.rr.com>.
I am creating a web app that has several survey pages where there are a
total of 120 or more radio buttons and check boxes on one page. I have been
seeing average page render times on the order of 2 to 2.5 seconds (some
times as bad as 5 seconds) with a single user hitting the site. I was going
to put off my investigation into this problem until the site was in a more
finished form. But since this topic has come up and because I needed
something to keep me busy until I go on vacation Wednesday, I decided to
look into it now.
After running some tests which I'll describe below, I'm starting to feel
like the performance problem reported in TheServerSide case study was caused
by excessive garbage collection and not by the use of reflection to display
and update form values. Also their choice to use incremental garbage
collection in their tests probably made the struts app look far worse then
it would have if it had been run with standard garbage collection.
Like others who have posted on this subject recently, my initial guess was
that reflection was a likely cause of the performance bottleneck. But there
was one thing that seemed to contradict my theory. While it was true that
it took 2 seconds or more to render the page to the browser; when I clicked
the submit button after checking all check boxes, the form bean was updated
and the main page was rendered almost instantly. So I decided to figure out
just how much time was being spent doing reflection. My testing showed that
time spent on reflection to render the page was consuming so little time
that it couldn't even be measured. In my opinion, the big performance
problem is caused by garbage collection firing much more often then you
would expect. Perhaps making changes which reduce the number of objects
being created and destroyed for each tag invocation is the best way to
improve performance.
How I Tested For Time Spent On Reflection
-----------------------------------------
To prepare for the tests, I made two test JSP pages. Both pages consisted
of 150 html:checkbox tags arranged in 15 rows with 10 checkboxes per row.
The first test page contained html:checkbox elements with property values
similar to "survey(questionName).selectedValues[5]". On the second test
page, I removed all property attributes from the html:checkbox elements thus
leaving them with just a value="<some value>" attribute. Finally,
struts-html.tld was modified to make the html:checkbox "property" attribute
optional.
Looking at CheckboxTag.java and RequestUtils.java, you can see that if the
"property" attribute is not supplied to the html:checkbox tag, then
"RequestUtils.lookup(pageCOntext, name, property, null)" in
CheckbopxTag.java will simply return the form bean which is retrieved via a
call to pageCOntext.findAttribute(). The beanutils are never called if
property == null.
So how much faster was the second test page (which did not use reflection)
rendered then the first test page which did us e reflection? The time
difference was too small to be measured. Both test pages took anywhere from
2 seconds to six seconds to render with the average time being around 3.2
seconds.
So Reflection Wasn't The Problem - More Experiments To Get At The Problem
-------------------------------------------------------------------------
With reflection eliminated, my next suspicion was that the app server
(tomcat 4.0.6 bundled with NetBeans 3.5) was the problem. I had read that
many performance enhancements had been added since tomcat 4.0.6. Looking at
the .java code produced by the JSP compiler, I could see room for
optimization but there was nothing that could explain the terrible page
rendering times I was seeing.
So to test it out, I copied the second test page and replaced all
html:checkbox tags with html:messages tags. In the context of my test page,
the html:messages tag would simply look for messages at Globals.ERROR_KEY.
Since nothing would be found at that key, the tag would just render nothing.
This test page which had 150 html:messages tags on it typically rendered in
10 to 20 milliseconds.
Finally just for the heck of it, I made a test JSP page which just contained
150 <input type="checkbox"...> tags. This page typically render in 0 to 10
milliseconds.
Effect Of Changing To Incremental Garbage Collection
----------------------------------------------------
Up until now, all tests were performed with "java -server ...". By now I
was getting convinced that the problem was that garbage collection was
happening every time one of the first two test pages were being rendered and
that is what was killing the performance. Turning on GC logging confirmed
that. So, I decided to turn on incremental garbage collection. Wow, what a
difference. Things started taking twice as long! Looking at the GC log, I
could see that the GC was firing pretty much constantly (like you would
expect) but that many of those incremental GC's were taking .2 to .9
seconds. The result was much worse performance on the first two test pages
and even the third test page (with html:messages tags on it was almost twice
as slow. The last test page which just contained no struts tags except for
html:form and html:submit still took from 0 to 10 milliseconds but I thick
this was just due to limitations in accuracy of the system timer.
Test Environment
----------------
Intel P4 2.8 GHZ 512MB
Window XP
JDK 1.4.1.4.1_04-b01
Tomcat 4.0.6 running under NetBeans 3.5 (normal execution, not debug)
Struts 1.1
Kurt
-----Original Message-----
From: Craig R. McClanahan [mailto:craigmcc@apache.org]
Sent: Saturday, August 02, 2003 5:37 PM
To: commons-dev@jakarta.apache.org
Cc: struts-dev@jakarta.apache.org
Subject: [BeanUtils] Interesting Microbenchmarks
TheServerSide (www.theserverside.com) recently published a case study that
attempted to analyze the performance characteristics of a variety of
middleware configurations, including two J2EE app servers and Microsoft's
.NET platform. One of the hot spots that showed up in the Java based
figures was identified as heavy use of reflection (the test app was Struts
based and therefore uses commons-beanutils), but the report did not detail
these findings.
Despite the fact that the test condtions were very artificial (the
database was tuned in a way that it was never the hotspot, which is unlike
virtually any high-use web application in production), it prompted a bit
of discussion over whether using reflection was a good idea. This in turn
prompted me to write a couple of simple microbenchmarks to measure the
behavior of the most commonly used BeanUtils and PropertyUtils methods for
copying sets of properties -- copyProperties() and populate().
Legend:
======
"bean" - A plain old Java object (POJO) with eight properties,
one of each of the standard primitive types and one
String (org.apache.commons.beanutils.BenchBean)
"dyna" - An instance of org.apache.commons.beanutils.BasicDynaBean
with exactly the same properties and types. The property
types for primitives in a DynaBean are the wrapper classes
such as java.lang.Integer.
"map" - An instance of HashMap with eight entries pointing at
exactly the same values. The values for primitives
of the corresponding wrapper class types.
"strs" - An instance of HashMap with eight entries pointing at
the same values, but all Strings (simulating request
parameters that are used to populate a form bean in Struts).
"Dura #1" - Duration for 100,000 loops on my 1ghz desktop (milliseconds)
"Dura #2" - Duration for 50,000 loops on my 500mhz laptop (milliseconds)
I tested all the legal combinations of an origin object (bean, dyna,
map, or strs) to a destination object (bean or dyna). The tests were run
on a 1 gigahertz PC running Linux (Red Hat 9) with Sun's JDK 1.4.2, and on
a 500mhz laptop running Win2K with Sun's 1.4.2. The loop count was set to
100,000 in the PC case, and 50,000 in the laptop case, so the overall
execution times should be roughly the same (since the desktop is roughly
twice as fast). Execution time was measured in milliseconds. For each
test, I ran an untimed execution of the specified number of iterations (to
prime HotSpot), followed by a timed execution of the same number of
iterations.
To run these for yourselves, check out the HEAD branch of beanutils (or
grab a source nightly distro dated 20030803 or later), and run "ant
bench".
Results for BeanUtils (which performs type conversions):
=======================================================
Method Dest Orig Dura #1 Dura #2
-------------- ---- ---- ------- -------
copyProperties bean bean 17,703 17,075
copyProperties dyna bean 17,463 17,074
copyProperties bean dyna 15,413 15,042
copyProperties dyna dyna 13,020 12,077
copyProperties bean map 15,626 15,192
copyProperties dyna map 12,999 12,237
copyProperties bean strs 16,302 16,093
copyProperties dyna strs 13,940 13,129
populate bean map 7,438 7,481
populate dyna map 5,082 5,368
populate bean strs 5,768 5,739
populate dyna strs 3,865 3,746
Results for PropertyUtils (no type conversions):
===============================================
Method Dest Orig Dura #1 Dura #2
-------------- ---- ---- ------- -------
copyProperties bean bean 5,595 5,107
copyProperties dyna bean 4,567 4,126
copyProperties bean dyna 3,791 3,675
copyProperties dyna dyna 844 681
copyProperties bean map 3,938 3,755
copyProperties dyna map 931 772
Observations:
============
* The absoute numbers are not particularly interesting, other than the
fact that they confirm my belief that copying properties (whether
using reflection or not) is very unlikely to be a bottleneck -- even
on bargain basement hardware (in today's world), we're talking about
copying all the properties in anything from 0.8 microseconds up to
177 microseconds.
* This is a very limited test case, with only one pattern of properties.
I suspect it will be on the worst case side in terms of the number
of conversions required, compared to how most people use these methods
in real applications.
* Increasing the number of properties being copied will (of course)
increase the execution times, but I suspect it will not change the
ratios between alternatives much. I've done a few informal tests
with more and fewer properties, but this will be worth investigating
in more detail as well.
* Only the cases where a "bean" was the destination or origin use
reflection at all. The "map" case is just doing HashMap gets and puts,
while the "dyna" case is really the "map" case plus type safety
checks.
* In all scenarios, using "dyna" was faster than using "bean", ranging
from statistically insignificant to pretty substantial percentages.
For Struts based apps in particular, that means using DynaActionForm
for form beans, with the current BeanUtils code, will give better
performance than using standard ActionForm bean classes. It also
seems that BasicDynaBean would make a pretty good Data Transfer Object
for moving data between tiers, adding type safety without giving up
the performance of using just a HashMap.
* One would expect using a "map" as the origin would be roughly
the same as using a "dyna", because they both iterate over keys and
values in a HashMap internally. The fact that using "dyna" was often
faster is somewhat anomalous, and is likely based on differing amounts
of optimization inside the BeanUtils and PropertyUtils loops and
getter/setter implementations.
* Of particular interest to Struts users is the code that populates
the form bean. The two lines that describe this use case (populate
to "bean" from "strs", and populate to "dyna" from "strs") indicate
that this operation is already highly optimized, running much
faster than the more general purpose copyProperties() method with the
same argument types.
* From casual observation of the current source, I suspect the longer
times for "bean" objects have more to do with the way that
PropertyDescriptor and Method instances are cached and searched in
PropertyUtils than they have with the time of the reflection-based
execution of the property getters and setters. There is lots of room
here to optimize.
* It will be very useful to have people try these microbenchmarks in a
variety of different environments, and create variations of them with
different kinds of origin and destination beans, to provide a wider
set of profiles when we attempt optimization on the underlying code.
Please feel free to post patches to the microbenchmark sources, so that
everyone can execute exactly the same set of tests.
* It will also be interesting to try this on different JDK generations,
to confirm whether the improvements in reflection performance that have
been described for recent versions shows through in the results here.
Craig McClanahan
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: struts-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: struts-dev-help@jakarta.apache.org