High cpu usage during JSF lifecycle phase execution

Question

In our performance test we encountered a high cpu usage (100%) and the thread dumps indicated that most of the times the threads are either executing restore view or render response phase of the JSF lifecycle or they are blocked while accessing the jar files which containing the xhtml pages.

One of the thread dump of a runnable thread is

java.lang.Thread.State: RUNNABLE
at java.util.HashMap.get(HashMap.java:317)
at javax.faces.component.ComponentStateHelper.get(ComponentStateHelper.java:174)
at javax.faces.component.ComponentStateHelper.add(ComponentStateHelper.java:216)
at javax.faces.component.UIComponent.setValueExpression(UIComponent.java:436)
at com.sun.faces.facelets.tag.jsf.CompositeComponentTagHandler$CompositeComponentRule$CompositeExpressionMetadata.applyMetadata(CompositeComponentTagHandler.java:631)
at com.sun.faces.facelets.tag.MetadataImpl.applyMetadata(MetadataImpl.java:81)
at javax.faces.view.facelets.MetaTagHandler.setAttributes(MetaTagHandler.java:129)
at javax.faces.view.facelets.DelegatingMetaTagHandler.setAttributes(DelegatingMetaTagHandler.java:102)
at com.sun.faces.facelets.tag.jsf.CompositeComponentTagHandler.setAttributes(CompositeComponentTagHandler.java:246)
at com.sun.faces.facelets.tag.jsf.CompositeComponentTagHandler.applyNextHandler(CompositeComponentTagHandler.java:184)
at com.sun.faces.facelets.tag.jsf.ComponentTagHandlerDelegateImpl.apply(ComponentTagHandlerDelegateImpl.java:184)
at javax.faces.view.facelets.DelegatingMetaTagHandler.apply(DelegatingMetaTagHandler.java:120)
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98)
at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93)
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98)
at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:86)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:308)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:367)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:346)
at com.sun.faces.facelets.impl.DefaultFaceletContext.includeFacelet(DefaultFaceletContext.java:199)
at com.sun.faces.facelets.tag.ui.IncludeHandler.apply(IncludeHandler.java:120)
at javax.faces.view.facelets.DelegatingMetaTagHandler.applyNextHandler(DelegatingMetaTagHandler.java:137)
at com.sun.faces.facelets.tag.jsf.ComponentTagHandlerDelegateImpl.apply(ComponentTagHandlerDelegateImpl.java:184)
at javax.faces.view.facelets.DelegatingMetaTagHandler.apply(DelegatingMetaTagHandler.java:120)
at com.sun.faces.facelets.tag.ui.DefineHandler.applyDefinition(DefineHandler.java:107)
at com.sun.faces.facelets.tag.ui.CompositionHandler.apply(CompositionHandler.java:178)
at com.sun.faces.facelets.impl.DefaultFaceletContext$TemplateManager.apply(DefaultFaceletContext.java:395)
at com.sun.faces.facelets.impl.DefaultFaceletContext.includeDefinition(DefaultFaceletContext.java:366)
at com.sun.faces.facelets.tag.ui.InsertHandler.apply(InsertHandler.java:112)
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98)
at javax.faces.view.facelets.DelegatingMetaTagHandler.applyNextHandler(DelegatingMetaTagHandler.java:137)
at com.sun.faces.facelets.tag.jsf.ComponentTagHandlerDelegateImpl.apply(ComponentTagHandlerDelegateImpl.java:184)
at javax.faces.view.facelets.DelegatingMetaTagHandler.apply(DelegatingMetaTagHandler.java:120)
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98)
at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93)
at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:86)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:308)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:367)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:346)
at com.sun.faces.facelets.impl.DefaultFaceletContext.includeFacelet(DefaultFaceletContext.java:199)
at com.sun.faces.facelets.tag.ui.CompositionHandler.apply(CompositionHandler.java:155)
at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93)
at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:86)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:308)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:367)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:346)
at com.sun.faces.facelets.impl.DefaultFaceletContext.includeFacelet(DefaultFaceletContext.java:199)
at com.sun.faces.facelets.tag.ui.IncludeHandler.apply(IncludeHandler.java:120)
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98)
at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93)
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98)
at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:86)
at com.sun.faces.facelets.impl.DefaultFacelet.apply(DefaultFacelet.java:152)
at com.sun.faces.application.view.FaceletViewHandlingStrategy.buildView(FaceletViewHandlingStrategy.java:774)
at com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:100)
at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101)
at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:139)
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:594)
at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1550)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:343)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:217)

while a thread trace for a blocked thread is

java.lang.Thread.State: BLOCKED (on object monitor)
at java.util.zip.ZipFile.getEntry(ZipFile.java:302)
- waiting to lock <0x00000000c0f678f8> (a java.util.jar.JarFile)
at java.util.jar.JarFile.getEntry(JarFile.java:225)
at java.util.jar.JarFile.getJarEntry(JarFile.java:208)
at sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:817)
at sun.misc.URLClassPath$JarLoader.findResource(URLClassPath.java:795)
at sun.misc.URLClassPath.findResource(URLClassPath.java:172)
at java.net.URLClassLoader$2.run(URLClassLoader.java:551)
at java.net.URLClassLoader$2.run(URLClassLoader.java:549)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findResource(URLClassLoader.java:548)
at java.lang.ClassLoader.getResource(ClassLoader.java:1138)
at java.lang.ClassLoader.getResource(ClassLoader.java:1133)
at org.glassfish.web.loader.WebappClassLoader.getResource(WebappClassLoader.java:1156)
at org.glassfish.web.loader.WebappClassLoader.getResourceFromJars(WebappClassLoader.java:1111)
at org.apache.catalina.core.StandardContext.getMetaInfResource(StandardContext.java:7586)
at org.apache.catalina.core.StandardContext.getResource(StandardContext.java:6979)
at org.apache.catalina.core.ApplicationContext.getResource(ApplicationContext.java:382)
at org.apache.catalina.core.ApplicationContextFacade.getResource(ApplicationContextFacade.java:260)
at com.sun.faces.context.ExternalContextImpl.getResource(ExternalContextImpl.java:502)
at com.sun.faces.application.resource.WebappResourceHelper.getURL(WebappResourceHelper.java:119)
at com.sun.faces.application.resource.ResourceImpl.getURL(ResourceImpl.java:190)
at com.sun.faces.facelets.tag.jsf.CompositeComponentTagHandler.applyCompositeComponent(CompositeComponentTagHandler.java:366)
at com.sun.faces.facelets.tag.jsf.CompositeComponentTagHandler.applyNextHandler(CompositeComponentTagHandler.java:191)
at com.sun.faces.facelets.tag.jsf.ComponentTagHandlerDelegateImpl.apply(ComponentTagHandlerDelegateImpl.java:184)
at javax.faces.view.facelets.DelegatingMetaTagHandler.apply(DelegatingMetaTagHandler.java:120)
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98)
at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93)
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98)
at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:86)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:308)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:367)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:346)
at com.sun.faces.facelets.impl.DefaultFaceletContext.includeFacelet(DefaultFaceletContext.java:199)
at com.sun.faces.facelets.tag.ui.IncludeHandler.apply(IncludeHandler.java:120)
at javax.faces.view.facelets.DelegatingMetaTagHandler.applyNextHandler(DelegatingMetaTagHandler.java:137)
at com.sun.faces.facelets.tag.jsf.ComponentTagHandlerDelegateImpl.apply(ComponentTagHandlerDelegateImpl.java:184)
at javax.faces.view.facelets.DelegatingMetaTagHandler.apply(DelegatingMetaTagHandler.java:120)
at com.sun.faces.facelets.tag.ui.DefineHandler.applyDefinition(DefineHandler.java:107)
at com.sun.faces.facelets.tag.ui.CompositionHandler.apply(CompositionHandler.java:178)
at com.sun.faces.facelets.impl.DefaultFaceletContext$TemplateManager.apply(DefaultFaceletContext.java:395)
at com.sun.faces.facelets.impl.DefaultFaceletContext.includeDefinition(DefaultFaceletContext.java:366)
at com.sun.faces.facelets.tag.ui.InsertHandler.apply(InsertHandler.java:112)
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98)
at javax.faces.view.facelets.DelegatingMetaTagHandler.applyNextHandler(DelegatingMetaTagHandler.java:137)
at com.sun.faces.facelets.tag.jsf.ComponentTagHandlerDelegateImpl.apply(ComponentTagHandlerDelegateImpl.java:184)
at javax.faces.view.facelets.DelegatingMetaTagHandler.apply(DelegatingMetaTagHandler.java:120)
at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:98)
at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93)
at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:86)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:308)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:367)
at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:346)
at com.sun.faces.facelets.impl.DefaultFaceletContext.includeFacelet(DefaultFaceletContext.java:199)
at com.sun.faces.facelets.tag.ui.CompositionHandler.apply(CompositionHandler.java:155)
at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93)
at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:86)
at com.sun.faces.facelets.impl.DefaultFacelet.apply(DefaultFacelet.java:152)
at com.sun.faces.application.view.FaceletViewHandlingStrategy.buildView(FaceletViewHandlingStrategy.java:774)
at com.sun.faces.application.view.StateManagementStrategyImpl.restoreView(StateManagementStrategyImpl.java:223)
at com.sun.faces.application.StateManagerImpl.restoreView(StateManagerImpl.java:188)
at com.sun.faces.application.view.ViewHandlingStrategy.restoreView(ViewHandlingStrategy.java:123)
at com.sun.faces.application.view.FaceletViewHandlingStrategy.restoreView(FaceletViewHandlingStrategy.java:453)
at com.sun.faces.application.view.MultiViewHandler.restoreView(MultiViewHandler.java:148)
at com.sun.faces.lifecycle.RestoreViewPhase.execute(RestoreViewPhase.java:192)
at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101)
at com.sun.faces.lifecycle.RestoreViewPhase.doPhase(RestoreViewPhase.java:116)
at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:118)
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:593)
at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1550)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:343)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:217)

We use glassfish 3.1.1 as our application. I would like to get suggestions on how should I investigate this further. Is this a normal behavior? Does glassfish provide an alternative for resolving blocked threads like some caching mechanism for resources etc?

Thanks in advance

Answer 1

The issue was because of a JSF defect. It got resolved by upgrading to the latest Mojarra JSF jars !