Most Http Requests going into endless loop

Hello,

We are currently using JSF 1.1 with Oracle ADF Faces and running on a JBoss 4.0.3 application server running Java 1.5. We have been developing a large application for months with the usual various small problems. This week we've had a large number of continuous users on the system and have experienced a phenomenon where our Http Request threads will one-by-one fall into endless loops consuming alot of resources. This has happened with up to 30 threads before we were forced to restart the server.

All the threads are stuck in the same piece of JSF code. And looking at the thread dump stack traces, some are in the ApplyRequestValues Phase while others are in the RenderResponse Phase.

Here are two dumps from two threads, each one stuck in a different phase but you can see they are hung at the same spot in the code, apparently in an endless loop because the CPU times for these threads just keep increasing. Like they are continuously reading from the map, endlessly.

Thread: http-0.0.0.0-8080-1 : priority:5, demon:true, threadId:79, threadState:RUNNABLE, threadLockName:null

java.util.HashMap.get(HashMap.java:329)

com.sun.faces.el.impl.JsfParser.parse(JsfParser.java:15)

com.sun.faces.el.ValueBindingImpl.getNode(ValueBindingImpl.java:66)

com.sun.faces.el.ValueBindingImpl.isReadOnly(ValueBindingImpl.java:145)

oracle.adfinternal.view.faces.renderkit.core.xhtml.EditableValueRenderer.getReadOnly(EditableValueRenderer.java:211)

oracle.adfinternal.view.faces.renderkit.core.xhtml.EditableValueRenderer.wasSubmitted(EditableValueRenderer.java:109)

oracle.adfinternal.view.faces.renderkit.core.xhtml.EditableValueRenderer.decode(EditableValueRenderer.java:48)

oracle.adfinternal.view.faces.renderkit.core.xhtml.InputLabelAndMessageRenderer.decode(InputLabelAndMessageRenderer.java:34)

oracle.adf.view.faces.component.UIXComponentBase.__rendererDecode(UIXComponentBase.java:937)

oracle.adf.view.faces.component.UIXComponentBase.decode(UIXComponentBase.java:577)

oracle.adf.view.faces.component.UIXComponentBase.processDecodes(UIXComponentBase.java:676)

oracle.adf.view.faces.component.UIXEditableValue.processDecodes(UIXEditableValue.java:269)

oracle.adf.view.faces.component.UIXComponentBase.decodeChildrenImpl(UIXComponentBase.java:818)

oracle.adf.view.faces.component.UIXComponentBase.decodeChildren(UIXComponentBase.java:803)

oracle.adf.view.faces.component.UIXForm.processDecodes(UIXForm.java:53)

javax.faces.component.UIComponentBase.processDecodes(UIComponentBase.java:880)

javax.faces.component.UIViewRoot.processDecodes(UIViewRoot.java:306)

com.sun.faces.lifecycle.ApplyRequestValuesPhase.execute(ApplyRequestValuesPhase.java:79)

com.sun.faces.lifecycle.LifecycleImpl.phase(LifecycleImpl.java:200)

com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:90)

javax.faces.webapp.FacesServlet.service(FacesServlet.java:197)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

com.paetec.paonline.web.PAStatisticsFilter.doFilter(PAStatisticsFilter.java:68)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

com.paetec.paonline.web.PATransactionFilter.doFilter(PATransactionFilter.java:353)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

com.paetec.paonline.web.PALoggingFilter.doFilter(PALoggingFilter.java:102)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

oracle.adfinternal.view.faces.webapp.AdfFacesFilterImpl._invokeDoFilter(AdfFacesFilterImpl.java:367)

oracle.adfinternal.view.faces.webapp.AdfFacesFilterImpl._doFilterImpl(AdfFacesFilterImpl.java:336)

oracle.adfinternal.view.faces.webapp.AdfFacesFilterImpl.doFilter(AdfFacesFilterImpl.java:196)

oracle.adf.view.faces.webapp.AdfFacesFilter.doFilter(AdfFacesFilter.java:87)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:81)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)

org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)

org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:39)

org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:159)

org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:59)

org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)

org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)

org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommonAccessLogValve.java:481)

org.apache.catalina.valves.RequestDumperValve.invoke(RequestDumperValve.java:150)

org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)

org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)

org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:856)

org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:744)

org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)

org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112)

java.lang.Thread.run(Thread.java:595)

Thread: http-0.0.0.0-8080-2 : priority:5, demon:true, threadId:85, threadState:RUNNABLE, threadLockName:null

java.util.HashMap.get(HashMap.java:329)

com.sun.faces.el.impl.JsfParser.parse(JsfParser.java:15)

com.sun.faces.el.ValueBindingFactory.createValueBinding(ValueBindingFactory.java:44)

com.sun.faces.application.ApplicationImpl.createValueBinding(ApplicationImpl.java:263)

oracle.adf.view.faces.webapp.UIXComponentTag.createValueBinding(UIXComponentTag.java:357)

oracle.adf.view.faces.webapp.UIXComponentTag.setProperty(UIXComponentTag.java:139)

oracle.adfinternal.view.faces.taglib.UIXSelectItemTag.setProperties(UIXSelectItemTag.java:41)

oracle.adfinternal.view.faces.taglib.core.input.CoreSelectItemTag.setProperties(CoreSelectItemTag.java:68)

oracle.adf.view.faces.webapp.UIXComponentTag.setProperties(UIXComponentTag.java:126)

javax.faces.webapp.UIComponentTag.createComponent(UIComponentTag.java:1008)

javax.faces.webapp.UIComponentTag.createChild(UIComponentTag.java:1027)

javax.faces.webapp.UIComponentTag.findComponent(UIComponentTag.java:740)

javax.faces.webapp.UIComponentTag.doStartTag(UIComponentTag.java:429)

oracle.adf.view.faces.webapp.UIXComponentTag.doStartTag(UIXComponentTag.java:85)

org.apache.jsp.main.financial_jsp._jspx_meth_af_selectItem_1(org.apache.jsp.main.financial_jsp:2221)

org.apache.jsp.main.financial_jsp._jspx_meth_af_forEach_7(org.apache.jsp.main.financial_jsp:2197)

org.apache.jsp.main.financial_jsp._jspx_meth_af_selectOneChoice_1(org.apache.jsp.main.financial_jsp:2171)

org.apache.jsp.main.financial_jsp._jspService(org.apache.jsp.main.financial_jsp:859)

org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:97)

javax.servlet.http.HttpServlet.service(HttpServlet.java:810)

org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:322)

org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:314)

org.apache.jasper.servlet.JspServlet.service(JspServlet.java:264)

javax.servlet.http.HttpServlet.service(HttpServlet.java:810)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:672)

org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:463)

org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:398)

org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:301)

com.sun.faces.context.ExternalContextImpl.dispatch(ExternalContextImpl.java:322)

com.sun.faces.application.ViewHandlerImpl.renderView(ViewHandlerImpl.java:130)

oracle.adfinternal.view.faces.application.ViewHandlerImpl.renderView(ViewHandlerImpl.java:157)

com.paetec.paonline.web.app.PAOViewHandler.renderView(PAOViewHandler.java:114)

com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:87)

com.sun.faces.lifecycle.LifecycleImpl.phase(LifecycleImpl.java:200)

com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:117)

javax.faces.webapp.FacesServlet.service(FacesServlet.java:198)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

com.paetec.paonline.web.PAStatisticsFilter.doFilter(PAStatisticsFilter.java:68)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

com.paetec.paonline.web.PATransactionFilter.doFilter(PATransactionFilter.java:353)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

com.paetec.paonline.web.PALoggingFilter.doFilter(PALoggingFilter.java:102)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

oracle.adfinternal.view.faces.webapp.AdfFacesFilterImpl._invokeDoFilter(AdfFacesFilterImpl.java:367)

oracle.adfinternal.view.faces.webapp.AdfFacesFilterImpl._doFilterImpl(AdfFacesFilterImpl.java:336)

oracle.adfinternal.view.faces.webapp.AdfFacesFilterImpl.doFilter(AdfFacesFilterImpl.java:196)

oracle.adf.view.faces.webapp.AdfFacesFilter.doFilter(AdfFacesFilter.java:87)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:81)

org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)

org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)

org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:39)

org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:159)

org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:59)

org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)

org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)

org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommonAccessLogValve.java:481)

org.apache.catalina.valves.RequestDumperValve.invoke(RequestDumperValve.java:150)

org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)

org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)

org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:856)

org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:744)

org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)

org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112)

java.lang.Thread.run(Thread.java:595)

[13178 byte] By [hergioa] at [2007-10-3 0:31:32]
# 1

I wanted to mention, when it occurs while rendering the page (as can be seen from the stack traces) that its occurring when rendering a tag. Here is one of the tags in my JSP page, specifically one where I think it could be hanging. Does anyone see anything fishy? This tag is an Oracle ADF tag and the "param" variable is a local loop variable. I jus recently added the " || !financialBean.profitAssistant.paDataEditable" part but I don't know if thats the cause of the problem. This does not occur everytime, it just seems like when there is a good amount of load on the system.

<af:inputText simple="true"

id= "tlInputTextParam"

value="#{param.textValue}"

rendered="#{param.rendered}"

disabled="#{param.disabled || !financialBean.profitAssistant.paDataEditable}"

styleClass= "#{param.styleClass}"

inlineStyle="#{param.style}"

columns="#{param.componentSize}"

onchange="#{param.onChangeJS}"

onclick="#{param.onClickJS}"

onkeydown= "#{param.onKeyDownJS}"

onfocus="#{param.onFocusJS}"

onblur="#{param.onBlurJS}"

onmouseover="try{this.title='#{param.description}';#{param.onMouseOverValueJS}}catch(e){}"

/>

hergioa at 2007-7-14 17:24:46 > top of Java-index,Enterprise & Remote Computing,Web Tier APIs...
# 2
Lat post, then I hope someone responds. :0)I did some fishing around in the JsfParser class's execute method, and I see that its using a map for caching and its not synchronized. I've read in places that simultaneously accessing a map from different threads can corrupt it.
hergioa at 2007-7-14 17:24:46 > top of Java-index,Enterprise & Remote Computing,Web Tier APIs...
# 3

FYI, I have corrected the problem. It appears the hashmap was getting corrupt. The internal hashmap used in the JsfParser class accessed the map in a non-synchronized way. And this cause the map to get corrupt. I read a post once about hashmaps getting corrupt and their buckets linked in endless loops if you access (get and set) them at the same time from different threads.

The solution: Using reflection, we just swapped it out with a synchronized map.

hergioa at 2007-7-14 17:24:46 > top of Java-index,Enterprise & Remote Computing,Web Tier APIs...
# 4
This issue should have been fixed in JSF 1.1_01. What version were you using?
rlubkea at 2007-7-14 17:24:46 > top of Java-index,Enterprise & Remote Computing,Web Tier APIs...
# 5

I had it noted as being JSF 1.1_01 but apparently its not. I downloaded _01 from Sun just now and compared the two impl.jar files and they are different.I must not have copied over my old version of JSF.

The JsfParser class doesn't even exist anymore, looks like most if not all of the EL parsing stuff has been gutted.

I will be sure to update. Thanks.

hergioa at 2007-7-14 17:24:46 > top of Java-index,Enterprise & Remote Computing,Web Tier APIs...
# 6
I'd suggest going to 1.1_02 if you plan to upgrade.You can download it from https://javaserverfaces.dev.java.net.If you run into any issues, please be sure to use the issue trackeron that project.Thanks!
rlubkea at 2007-7-14 17:24:46 > top of Java-index,Enterprise & Remote Computing,Web Tier APIs...