Thanks Ryan :-)

On 25 Sep 2008, at 16:27, Ryan Lubke wrote:

Thanks,

Jim and I will look into it.

Pete Muir wrote:

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 <http://fisheye5cenqua.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@gmail.com <mailto:tech4j@gmail.com>>

*Date: *24 September 2008 22:05:51 BST

*To: *"seam-dev@lists.jboss.org <mailto:seam-dev@lists.jboss.org>" <seam-dev@lists.jboss.org <mailto:seam-dev@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 <http://fisheye5cenqua.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@lists.jboss.org <mailto:seam-dev@lists.jboss.org>

https://lists.jboss.org/mailman/listinfo/seam-dev

_______________________________________________
seam-dev mailing list
seam-dev@lists.jboss.org
https://lists.jboss.org/mailman/listinfo/seam-dev