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

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/jav... >>> < >>> http://fisheye5cenqua.com/browse/javaserverfaces-sources/jsf-api/src/java...>). >>> 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/jav...). >>> 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(a)gmail.com <mailto:tech4j@gmail.com>> >>> *Date: *24 September 2008 22:05:51 BST >>> *To: *&quot;seam-dev(a)lists.jboss.org <mailto:seam-dev@lists.jboss.org>" < >>> seam-dev(a)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/jav... >>> < >>> http://fisheye5cenqua.com/browse/javaserverfaces-sources/jsf-api/src/java...>). >>> 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/jav...). >>> 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/jav... >>> - 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(a)lists.jboss.org <mailto:seam-dev@lists.jboss.org> >>> https://lists.jboss.org/mailman/listinfo/seam-dev >>> >> >> > _______________________________________________ seam-dev mailing list seam-dev(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/seam-dev