Fwd: [seam-dev] Some profiling of blocking threads

Pete Muir pmuir at redhat.com
Thu Sep 25 06:58:04 EDT 2008 

Ryan, Ed,

Jay has been working on performance analysis for Seam.

> UIComponent$AttributesMap
> -----------------------------------------------------
>  - Issues related to this were responsible for about 20% of the  
> blocked threads
>  - Reported time spent blocked ranged from 30 ms - 848 ms with an  
> average estimated to be 400ms
>  - I need to rerun the tests to be more specific.
>  - One of the items that was strange with this block was that it  
> sometimes included completely unrelated actions or classes.
>    - after adjusting the filters, and rerunning the tests several  
> times I was able to narrow it down.
>
> * Investigation:
> Unfortunately this issue is in the RI JSF implementation itself.   
> The UIComponentBase implements its own Map (AttributeMap) ( see http://fisheye5.cenqua.com/browse/javaserverfaces-sources/jsf-api/src/javax/faces/component/UIComponentBase.java?r=1.158#l1521) 
> .  This is not an issue directly, but you will see calls to the  
> "getAttributesThatAreSet" method in the get, put, and remove methods  
> of the map.  This is implemented in the UIComponent class ( see: http://fisheye5.cenqua.com/browse/javaserverfaces-sources/jsf-api/src/javax/faces/component/UIComponent.java?r=1.153#l1191) 
> .  The real issue is the call to "this.getClass().getPackage();".   
> This call will eventually synchronize in the  
> "ClassLoader.getPackage" method on the "packages" object for the  
> whole classloader.  This is why other threads were also blocked on  
> this - like  
> org.jboss.seam.contexts.Contexts.isApplicationContextActive() which  
> is accessing a ThreadLocal object.
>
> We really have 3 options for this issue.
>  - We can work with the RI to get the handling of the package check  
> changed so that the values are some how cached in the component -  
> how often do packages change while running ;-)
>  - We can take a look and try to find excessive use of the  
> components interactions with the AttributeMap.
>  - We do nothing - but keep an eye on JSF 2 to make sure items like  
> this are handled better.

Naively, I would assume it should be possible to cache the value of  
this.getClass().getPackage().

HTH,

Pete

Begin forwarded message:

> From: "Jay Balunas" <tech4j at gmail.com>
> Date: 24 September 2008 22:05:51 BST
> To: "seam-dev at lists.jboss.org" <seam-dev at lists.jboss.org>
> Subject: [seam-dev] Some profiling of blocking threads
>
> I have been executing the 25 user performance tests through the  
> profiler to identify hot spots and areas of concern.  I am initially  
> looking at our blocking threads, and behavior around them that is  
> causing the problems.
>
> Test Description
> --------------------
>  - Use the 25 user wiki forum front page jmeter tests discussed in  
> the previous email.
>  - Uses same environment and procedures as defined in the previous  
> email.
>  - Tests are executed through the profiler with CPU recording turned  
> on.
>  - I have modified the default filters to allow the following packages
>       - org.jboss.seam
>       - javax.faces
>       - most of the java.util collections and map classes
>
> Profile Results
> -------------------
> This is not a complete analysis of the entire application or even  
> all of the blocking threads - I will continue to work on them and  
> feed more information back to list.
>
> These items were detected via the thread usage history page, that  
> shows all blocked and waiting threads and their stack traces.
>
> javax.naming.InitialContext.lookup
> -----------------------------------
>   - as expected a large number of blocked threads were waiting or  
> blocked while attempting to lookup the initial context.
>   - One interesting thing is that not all of these were blocked on a  
> Hashtable - others were blocked on, or were related to calls to  
> Properties and WeakHashMap objects.  This is likely caused by  
> further method invocations that have been filtered out.
>     - I will look further, but wanted to look at some of the other  
> areas that were blocked.
>
> UIComponent$AttributesMap
> -----------------------------------------------------
>  - Issues related to this were responsible for about 20% of the  
> blocked threads
>  - Reported time spent blocked ranged from 30 ms - 848 ms with an  
> average estimated to be 400ms
>  - I need to rerun the tests to be more specific.
>  - One of the items that was strange with this block was that it  
> sometimes included completely unrelated actions or classes.
>    - after adjusting the filters, and rerunning the tests several  
> times I was able to narrow it down.
>
> * Investigation:
> Unfortunately this issue is in the RI JSF implementation itself.   
> The UIComponentBase implements its own Map (AttributeMap) ( see http://fisheye5.cenqua.com/browse/javaserverfaces-sources/jsf-api/src/javax/faces/component/UIComponentBase.java?r=1.158#l1521) 
> .  This is not an issue directly, but you will see calls to the  
> "getAttributesThatAreSet" method in the get, put, and remove methods  
> of the map.  This is implemented in the UIComponent class ( see: http://fisheye5.cenqua.com/browse/javaserverfaces-sources/jsf-api/src/javax/faces/component/UIComponent.java?r=1.153#l1191) 
> .  The real issue is the call to "this.getClass().getPackage();".   
> This call will eventually synchronize in the  
> "ClassLoader.getPackage" method on the "packages" object for the  
> whole classloader.  This is why other threads were also blocked on  
> this - like  
> org.jboss.seam.contexts.Contexts.isApplicationContextActive() which  
> is accessing a ThreadLocal object.
>
> We really have 3 options for this issue.
>  - We can work with the RI to get the handling of the package check  
> changed so that the values are some how cached in the component -  
> how often do packages change while running ;-)
>  - We can take a look and try to find excessive use of the  
> components interactions with the AttributeMap.
>  - We do nothing - but keep an eye on JSF 2 to make sure items like  
> this are handled better.
>
> org.ajax4jsf.application.AjaxViewHandler
> --------------------------------------------
>  - This was not a large % of the blocked threads but caught my eye  
> as a potential trouble spot because it seemed directly related to  
> ajax calls.
>  - This was easier to track down and the root cause is in the  
> org.ajax4jsf.application.ViewHandlerWrapper class.
>  - see http://anonsvn.jboss.org/repos/richfaces/trunk/framework/api/src/main/java/org/ajax4jsf/application/ViewHandlerWrapper.java
>  - The problem is all the calls to "fillChain" which is a  
> synchronized method in the class.
>  - We need to find out how often the "_initialized" field is false -  
> is this once a request, once for each component, etc...
>  - it appears to be called many times - I will look further into this.
>
> -------------------------------------
> This is all I have had time for so far, but will continue to  
> investigate some of the other aspects of the application.  After  
> completing the analysis of the primary blocking thread issues I will  
> move on to other areas to profile.  These will focus on specific  
> issues raised by the team and the forums.  I will also add  
> performance tests and analysis for the dvd store example.
>
> Regards,
> Jay
>
>
> -- 
> blog: http://in.relation.to/Bloggers/Jay
> _______________________________________________
> seam-dev mailing list
> seam-dev at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/seam-dev

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.jboss.org/pipermail/seam-dev/attachments/20080925/80c12506/attachment.html

More information about the seam-dev mailing list