Threads stuck at 100% CPU utilization in HashMap during JSF saveState()

Question

We have an issue in our production environment, 4 Threads is at 100% CPU Usage from the HTOP command. To further investigate the issue I generated a Thread dump in order to find what thread is eating the CPU.

Here is what i found out. The 4 threads has the same stack trace all of which are in RUNNABLE state. Unfortunately I am stuck at my investigation since the stack trace has no reference to my internal code it is more on Richfaces side. I think it is the part where JSF render a page.

The stack trace.

"ajp-0.0.0.0-8009-47" daemon prio=10 tid=0x00007fb8040af000 nid=0x172c runnable [0x00007fb8b3bf8000]
   java.lang.Thread.State: RUNNABLE
    at java.util.HashMap.hash(HashMap.java:351)
    at java.util.HashMap.putForCreate(HashMap.java:512)
    at java.util.HashMap.putAllForCreate(HashMap.java:534)
    at java.util.HashMap.<init>(HashMap.java:320)
    at org.ajax4jsf.component.UIDataAdaptorBase.createChildStateCopy(UIDataAdaptorBase.java:894)
    at org.ajax4jsf.component.UIDataAdaptorBase.saveState(UIDataAdaptorBase.java:1554)
    at org.richfaces.component.UIDataTable.saveState(UIDataTable.java:181)
    at org.richfaces.component.html.HtmlDataTable.saveState(HtmlDataTable.java:1361)
    at javax.faces.component.UIComponentBase.processSaveState(UIComponentBase.java:1103)
    at javax.faces.component.UIComponentBase.processSaveState(UIComponentBase.java:1119)
    at javax.faces.component.UIComponentBase.processSaveState(UIComponentBase.java:1119)
    at javax.faces.component.UIComponentBase.processSaveState(UIComponentBase.java:1119)
    at javax.faces.component.UIComponentBase.processSaveState(UIComponentBase.java:1119)
    at javax.faces.component.UIComponentBase.processSaveState(UIComponentBase.java:1119)
    at javax.faces.component.UIComponentBase.processSaveState(UIComponentBase.java:1119)
    at javax.faces.component.UIComponentBase.processSaveState(UIComponentBase.java:1119)
    at org.ajax4jsf.component.AjaxViewRoot.processSaveState(AjaxViewRoot.java:751)
    at org.ajax4jsf.application.AjaxStateManager.getComponentStateToSave(AjaxStateManager.java:179)
    at org.ajax4jsf.application.AjaxStateManager.buildViewState(AjaxStateManager.java:515)
    at org.ajax4jsf.application.AjaxStateManager$SeamStateManagerWrapper.saveView(AjaxStateManager.java:106)
    at org.jboss.seam.jsf.SeamStateManager.saveView(SeamStateManager.java:89)
    at org.ajax4jsf.application.AjaxStateManager.saveSerializedView(AjaxStateManager.java:470)
    at com.sun.facelets.FaceletViewHandler.renderView(FaceletViewHandler.java:615)
    at org.ajax4jsf.application.ViewHandlerWrapper.renderView(ViewHandlerWrapper.java:100)
    at org.ajax4jsf.application.AjaxViewHandler.renderView(AjaxViewHandler.java:176)
    at com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:110)
    at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:100)
    at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:139)
    at javax.faces.webapp.FacesServlet.service(FacesServlet.java:266)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.josso.servlet.agent.GenericServletSSOAgentFilter.doFilter(GenericServletSSOAgentFilter.java:558)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:83)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:73)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:73)
    at org.jboss.seam.web.IdentityFilter.doFilter(IdentityFilter.java:40)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.web.MultipartFilter.doFilter(MultipartFilter.java:90)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.web.ExceptionFilter.doFilter(ExceptionFilter.java:64)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.web.RedirectFilter.doFilter(RedirectFilter.java:45)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.ajax4jsf.webapp.BaseXMLFilter.doXmlFilter(BaseXMLFilter.java:206)
    at org.ajax4jsf.webapp.BaseFilter.handleRequest(BaseFilter.java:290)
    at org.ajax4jsf.webapp.BaseFilter.processUploadsAndHandleRequest(BaseFilter.java:388)
    at org.ajax4jsf.webapp.BaseFilter.doFilter(BaseFilter.java:515)
    at org.jboss.seam.web.Ajax4jsfFilter.doFilter(Ajax4jsfFilter.java:56)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.web.LoggingFilter.doFilter(LoggingFilter.java:60)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.servlet.SeamFilter.doFilter(SeamFilter.java:158)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:190)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:433)
    at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:92)
    at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
    at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
    at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:436)
    at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:384)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
    at java.lang.Thread.run(Thread.java:722)

Another thing is, Is there any way i can tap into the stack trace, lets say i wanted to generate a logs so that i can tell which page in my application this stack trace is being generated? Or maybe I can use a phase listener?

Any help would be appreciated. Thank you.

I am using Seam 2.2, Richfaces 3.3.3 final, JSF 1.2.

Lanham

might be concurrency issue -- a shared HashMap is being read/write by multiple threads without proper synchronization. – Gottwald

Thanks man, I think you are right. Is there a way i can find out which page it is being called? So I can start looking there. – Lanham

Usually done by Thread.setName(), using a string embedding URL, IP, etc. Not sure how to do it in seam though. – Gottwald

Thank you, maybe i will find a way to do that. – Lanham

Answer 1

This,

java.lang.Thread.State: RUNNABLE
    at java.util.HashMap.hash(HashMap.java:351)
    at java.util.HashMap.putForCreate(HashMap.java:512)
    at java.util.HashMap.putAllForCreate(HashMap.java:534)
    at java.util.HashMap.<init>(HashMap.java:320)

and this,

java.lang.Thread.State: RUNNABLE
    at java.util.HashMap.getEntry(HashMap.java:446)
    at java.util.HashMap.get(HashMap.java:405)

are known threadsafety problems with java.util.HashMap when one thread invokes a get() while another thread does at the same time a put(). The thread will during calculating the hash then stuck in an infinite loop . The technical solution to this problem is using a ConcurrentMap implementation instead. See also a.o. this dzone article.

However, in your specific case,

    at java.util.HashMap.<init>(HashMap.java:320)
    at org.ajax4jsf.component.UIDataAdaptorBase.createChildStateCopy(UIDataAdaptorBase.java:894)
    at org.ajax4jsf.component.UIDataAdaptorBase.saveState(UIDataAdaptorBase.java:1554)
    at org.richfaces.component.UIDataTable.saveState(UIDataTable.java:181)
    at org.richfaces.component.html.HtmlDataTable.saveState(HtmlDataTable.java:1361)
    at javax.faces.component.UIComponentBase.processSaveState(UIComponentBase.java:1103)

this problem appears to manifest when the state of your <rich:dataTable> component is about to be saved. This in turn suggests that the very same instance of the component is being accessed by multiple threads. This is not right, the UIComponent class is in first place never designed to be threadsafe. This in turn indicates that the component instance in question is not request scoped as required by the JSF specification. This can for example happen when you're using binding to bind the component to a session scoped or perhaps even an application scoped bean or, worse, a static field.

<x:someComponent ... binding="#{nonRequestScopedBean.someComponent}">

You should in your codebase look for such a component and fix it accordingly by making sure that the bean is request scoped, or by using a different solution for the requirement/problem for which you thought that using binding this way would be the right solution.

See also:

• How does the 'binding' attribute work in JSF? When and how should it be used?

Ethyne

Thank you so much for the clear explanation, this is very helpful to clarify things up. I will look for any binding components which is not request scope. Another question, Is there a way which i can trace which page this stack trace came from? It will help me narrow down my search for that data table which is generating this error. Btw, we are using a lot a4j:keepAlive tag in our pages, I think it may be related.Thanks again. – Lanham

Unfortunately no, the JSF page name is not included in the exception. Performing a project-wide search on the character sequence "<rich:dataTable" in all *.xhtml files should get you started. – Ethyne

Thank you. I have search for "rich:dataTable" with bindings but didn't found any. But we have a lot of "rich:dataTable" value attribute pointed to Seam Session Scope Components. As far as I can understand Session Scope Components are synchronized by default so I think it is safe that this components are thread safe or maybe I am wrong. – Lanham

It's also possible that some bean is doing a viewRoot.findComponent("formId:tableId") and then assigning it as a property of a too broad scoped bean. The key is not necessarily binding, but that an UIComponent instance is being shared across multiple threads. Using binding the wrong way is only the most common cause of this. – Ethyne

Thank you I will look into this also. – Lanham

Answer 2

after long analysis my issue is resolved.

as we are using jsf 2.1.7 version , UI repeat implemented using hashmap in 2.1.7 version. hence when we use the nested ui repeat cpu is high. i have replaced ui repeat with JSTL for each now the application is working.

other way also you can use, you need to change the JSF 2.2.4 OR LATER VERSION.

Dhar