Details
Bug
Major
Description
There's a single instance of the D2DViewHandler in any ICEfacesApplication. This class uses an instance of com.icesoft.faces.webapp.parser.Parser to handle parsing JSP pages, which creates a UIComponentTree out of the tags using an instance of com.icesoft.faces.webapp.parser.JsfJspDigester
It appears that the Digester is stateful from the nature of the methods used
synchronized (this) {
digester.clear();
digester.push(rootTag);
digester.push(rootWire);
digester.parse(page);
}
The test I'm doing is to access the Timezone application, then using JMeter or the JavaClient create a new view with the Timezone application, interact, then dispose the View, repeat with up to 10 (or however many) views concurrently active.
Disposing the view is an important step since freshly creating the view causes the page to be re-parsed, however having several users attempting to render the very first response simultaneously causes exceptions similar to the following:
---> Starting reparse at: 98509527659283 This one finishes second at 98509551246548 (A)
---> Starting reparse at: 98509527659435 This one never finishes!
---> Starting reparse at: 98509535873067 This one ends first at 98509550752061 (B)
ERROR - Failed to execute JSP lifecycle. - com.icesoft.faces.webapp.parser.Parser
java.lang.ClassCastException: com.icesoft.faces.application.D2DViewHandler$1
at com.icesoft.faces.webapp.parser.XhtmlTag.setProperties(XhtmlTag.java:71)
at javax.faces.webapp.UIComponentClassicTagBase.findComponent(UIComponentClassicTagBase.java:614)
at javax.faces.webapp.UIComponentClassicTagBase.doStartTag(UIComponentClassicTagBase.java:1142)
at com.icesoft.faces.webapp.parser.Parser.executeJspLifecycle(Parser.java:200)
at com.icesoft.faces.webapp.parser.Parser.executeJspLifecycle(Parser.java:224)
at com.icesoft.faces.webapp.parser.Parser.executeJspLifecycle(Parser.java:224)
at com.icesoft.faces.webapp.parser.Parser.parse(Parser.java:161)
at com.icesoft.faces.application.D2DViewHandler.renderResponse(D2DViewHandler.java:516)
at com.icesoft.faces.application.D2DViewHandler.renderView(D2DViewHandler.java:164)
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:144)
at com.icesoft.faces.webapp.http.core.JsfLifecycleExecutor.apply(JsfLifecycleExecutor.java:18)
at com.icesoft.faces.webapp.http.core.PageServer$1.respond(PageServer.java:30)
at com.icesoft.faces.webapp.http.servlet.ServletRequestResponse.respondWith(ServletRequestResponse.java:161)
at com.icesoft.faces.webapp.http.servlet.ThreadBlockingAdaptingServlet$ThreadBlockingRequestResponse.respondWith(ThreadBlockingAdaptingServlet.java:36)
at com.icesoft.faces.webapp.http.core.PageServer.service(PageServer.java:40)
at com.icesoft.faces.webapp.http.core.MultiViewServer.service(MultiViewServer.java:56)
at com.icesoft.faces.webapp.http.common.standard.PathDispatcherServer$Matcher.serviceOnMatch(PathDispatcherServer.java:50)
at com.icesoft.faces.webapp.http.common.standard.PathDispatcherServer.service(PathDispatcherServer.java:19)
at com.icesoft.faces.webapp.http.servlet.ThreadBlockingAdaptingServlet.service(ThreadBlockingAdaptingServlet.java:19)
at com.icesoft.faces.webapp.http.servlet.EnvironmentAdaptingServlet.service(EnvironmentAdaptingServlet.java:29)
at com.icesoft.faces.webapp.http.servlet.MainSessionBoundServlet.service(MainSessionBoundServlet.java:106)
at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.service(SessionDispatcher.java:35)
at com.icesoft.faces.webapp.http.servlet.PathDispatcher$Matcher.serviceOnMatch(PathDispatcher.java:52)
at com.icesoft.faces.webapp.http.servlet.PathDispatcher.service(PathDispatcher.java:29)
at com.icesoft.faces.webapp.http.servlet.MainServlet.service(MainServlet.java:79)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:654)
at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:445)
at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:379)
at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:292)
at org.apache.jasper.runtime.PageContextImpl.doForward(PageContextImpl.java:694)
at org.apache.jasper.runtime.PageContextImpl.forward(PageContextImpl.java:665)
at org.apache.jsp.index_jsp._jspService(index_jsp.java:57)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:393)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:320)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:266)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:263)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:584)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
at java.lang.Thread.run(Thread.java:595)
---> Done parsing at: 98509550752061, took: 14878994 ns (B)
---> Done parsing at: 98509551246548, took: 23587265 ns (A)
---> Starting reparse at: 98509592642827 (C)
1-Apr-2008 11:51:54 AM com.sun.faces.lifecycle.Phase doPhase
SEVERE: JSF1054: (Phase ID: RENDER_RESPONSE 6, View ID: /timezone.jspx) Exception thrown during phase execution: javax.faces.event.PhaseEvent[source=com.sun.fac
es.lifecycle.LifecycleImpl@6af790]
---> Done parsing at: 98509657462362, took: 64819535 ns (C)
The exact exception varies from ClassCastExceptions to NullPointerExceptions and virtually anything in between.
This wont be seen as a problem in our common test situations since it's difficult for a single user to nearly simultaneously access an application, and even JMeter has facilities to spread out the user generated load at test startup enough to avoid having re-entrantcy being encountered. But with RIM and other clients expecting View disposal to release resources this type of test scenario will be encountered more often.
It appears that the Digester is stateful from the nature of the methods used
synchronized (this) {
digester.clear();
digester.push(rootTag);
digester.push(rootWire);
digester.parse(page);
}
The test I'm doing is to access the Timezone application, then using JMeter or the JavaClient create a new view with the Timezone application, interact, then dispose the View, repeat with up to 10 (or however many) views concurrently active.
Disposing the view is an important step since freshly creating the view causes the page to be re-parsed, however having several users attempting to render the very first response simultaneously causes exceptions similar to the following:
---> Starting reparse at: 98509527659283 This one finishes second at 98509551246548 (A)
---> Starting reparse at: 98509527659435 This one never finishes!
---> Starting reparse at: 98509535873067 This one ends first at 98509550752061 (B)
ERROR - Failed to execute JSP lifecycle. - com.icesoft.faces.webapp.parser.Parser
java.lang.ClassCastException: com.icesoft.faces.application.D2DViewHandler$1
at com.icesoft.faces.webapp.parser.XhtmlTag.setProperties(XhtmlTag.java:71)
at javax.faces.webapp.UIComponentClassicTagBase.findComponent(UIComponentClassicTagBase.java:614)
at javax.faces.webapp.UIComponentClassicTagBase.doStartTag(UIComponentClassicTagBase.java:1142)
at com.icesoft.faces.webapp.parser.Parser.executeJspLifecycle(Parser.java:200)
at com.icesoft.faces.webapp.parser.Parser.executeJspLifecycle(Parser.java:224)
at com.icesoft.faces.webapp.parser.Parser.executeJspLifecycle(Parser.java:224)
at com.icesoft.faces.webapp.parser.Parser.parse(Parser.java:161)
at com.icesoft.faces.application.D2DViewHandler.renderResponse(D2DViewHandler.java:516)
at com.icesoft.faces.application.D2DViewHandler.renderView(D2DViewHandler.java:164)
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:144)
at com.icesoft.faces.webapp.http.core.JsfLifecycleExecutor.apply(JsfLifecycleExecutor.java:18)
at com.icesoft.faces.webapp.http.core.PageServer$1.respond(PageServer.java:30)
at com.icesoft.faces.webapp.http.servlet.ServletRequestResponse.respondWith(ServletRequestResponse.java:161)
at com.icesoft.faces.webapp.http.servlet.ThreadBlockingAdaptingServlet$ThreadBlockingRequestResponse.respondWith(ThreadBlockingAdaptingServlet.java:36)
at com.icesoft.faces.webapp.http.core.PageServer.service(PageServer.java:40)
at com.icesoft.faces.webapp.http.core.MultiViewServer.service(MultiViewServer.java:56)
at com.icesoft.faces.webapp.http.common.standard.PathDispatcherServer$Matcher.serviceOnMatch(PathDispatcherServer.java:50)
at com.icesoft.faces.webapp.http.common.standard.PathDispatcherServer.service(PathDispatcherServer.java:19)
at com.icesoft.faces.webapp.http.servlet.ThreadBlockingAdaptingServlet.service(ThreadBlockingAdaptingServlet.java:19)
at com.icesoft.faces.webapp.http.servlet.EnvironmentAdaptingServlet.service(EnvironmentAdaptingServlet.java:29)
at com.icesoft.faces.webapp.http.servlet.MainSessionBoundServlet.service(MainSessionBoundServlet.java:106)
at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.service(SessionDispatcher.java:35)
at com.icesoft.faces.webapp.http.servlet.PathDispatcher$Matcher.serviceOnMatch(PathDispatcher.java:52)
at com.icesoft.faces.webapp.http.servlet.PathDispatcher.service(PathDispatcher.java:29)
at com.icesoft.faces.webapp.http.servlet.MainServlet.service(MainServlet.java:79)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:654)
at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:445)
at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:379)
at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:292)
at org.apache.jasper.runtime.PageContextImpl.doForward(PageContextImpl.java:694)
at org.apache.jasper.runtime.PageContextImpl.forward(PageContextImpl.java:665)
at org.apache.jsp.index_jsp._jspService(index_jsp.java:57)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:393)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:320)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:266)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:263)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:584)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
at java.lang.Thread.run(Thread.java:595)
---> Done parsing at: 98509550752061, took: 14878994 ns (B)
---> Done parsing at: 98509551246548, took: 23587265 ns (A)
---> Starting reparse at: 98509592642827 (C)
1-Apr-2008 11:51:54 AM com.sun.faces.lifecycle.Phase doPhase
SEVERE: JSF1054: (Phase ID: RENDER_RESPONSE 6, View ID: /timezone.jspx) Exception thrown during phase execution: javax.faces.event.PhaseEvent[source=com.sun.fac
es.lifecycle.LifecycleImpl@6af790]
---> Done parsing at: 98509657462362, took: 64819535 ns (C)
The exact exception varies from ClassCastExceptions to NullPointerExceptions and virtually anything in between.
This wont be seen as a problem in our common test situations since it's difficult for a single user to nearly simultaneously access an application, and even JMeter has facilities to spread out the user generated load at test startup enough to avoid having re-entrantcy being encountered. But with RIM and other clients expecting View disposal to release resources this type of test scenario will be encountered more often.
Activity
- All
- Comments
- History
- Activity
- Remote Attachments
- Subversion
There is a significant penalty in the initialization of the digester, so even though we can instantiate it quickly, we can't afford to keep doing so. So the solution must be to synchronze the parse method.
Checked in a change that separates digester operations from output. This should improve performance in the case reported on the forum:
Show
Ted Goddard
added a comment - Checked in a change that separates digester operations from output. This should improve performance in the case reported on the forum:
http://www.icefaces.org/JForum/posts/list/9276.page#38648
Two solutions. The easiest is to just add synchronization to the Parser.parse() method. The second is to move the Digester instance to be allocated during the parse method. Testing shows that it takes less than a millisecond to create and initialize the Digester on a 2.4 GHz P4, which doesn't seem to big a penalty. I cached the Map of tag to component rules that must be read from a serialized file. This seems a better approach, overall.