P6 Becomes Unresponsive When Navigating Around the Application Or Loading Applets And the Managed Server Shows Stuck/Hogging Threads with "ExecuteThread BLOCKED on org.apache.log4j.Logger owned by "PrmThread-#"
Last updated on APRIL 02, 2018
Applies to:
Primavera P6 Enterprise Project Portfolio Management - Version 15.1.0.0 and laterInformation in this document applies to any platform.
Symptoms
While utilizing the P6 application (deployed under WebLogic), eventually the server will become unresponsive and when reviewing the Threads under the managed server hosting P6 (Monitoring, Threads tab of the Managed Server within the WebLogic Administration Console), the server displays "hogging threads".
In the managed server log file, the following errors are written:
####<TIMESTAMP> <Error> <Socket> <SERVERNAME> <P6> <ExecuteThread: '0' for queue: 'weblogic.socket.Muxer'> <
java.lang.NullPointerException
at weblogic.servlet.logging.CLFLogger.log(CLFLogger.java:86)
at weblogic.servlet.logging.LogManagerHttp.log(LogManagerHttp.java:110)
at weblogic.servlet.internal.HttpConnectionHandler.send400Response(HttpConnectionHandler.java:543)
at weblogic.servlet.internal.HttpConnectionHandler.dispatch(HttpConnectionHandler.java:618)
at weblogic.servlet.internal.MuxableSocketHTTP.dispatch(MuxableSocketHTTP.java:131)
at weblogic.socket.JSSEFilterImpl.dispatch(JSSEFilterImpl.java:216)
at weblogic.socket.MuxableSocketDiscriminator.dispatch(MuxableSocketDiscriminator.java:186)
at weblogic.socket.JSSEFilterImpl.dispatch(JSSEFilterImpl.java:216)
at weblogic.socket.SocketMuxer.readReadySocketOnce(SocketMuxer.java:970)
at weblogic.socket.SocketMuxer.readReadySocket(SocketMuxer.java:907)
at weblogic.socket.NIOSocketMuxer.process(NIOSocketMuxer.java:495)
at weblogic.socket.NIOSocketMuxer.processSockets(NIOSocketMuxer.java:461)
at weblogic.socket.SocketReaderRequest.run(SocketReaderRequest.java:30)
at weblogic.socket.SocketReaderRequest.execute(SocketReaderRequest.java:43)
at weblogic.kernel.ExecuteThread.execute(ExecuteThread.java:147)
at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:119)
When taking a thread dump from the WebLogic Administration Console while hogging sessions are active, the following blocking threads are noted:
"[ACTIVE] ExecuteThread: '6' for queue: 'weblogic.kernel.Default (self-tuning)'" Id=210333 BLOCKED on org.apache.log4j.Logger@7784817e owned by "PrmThread-6" Id=72
at org.apache.log4j.Category.callAppenders(Category.java:185)
- blocked on org.apache.log4j.Logger@7784817e
at org.apache.log4j.Category.forcedLog(Category.java:372)
at org.apache.log4j.Category.log(Category.java:864)
at org.apache.commons.logging.impl.Log4JLogger.info(Log4JLogger.java:133)
at com.primavera.infr.log.CommonsLoggingAdapter.info(Unknown Source)
at com.primavera.pvweb.listeners.PVSessionListener.sessionCreated(Unknown Source)
at weblogic.servlet.internal.EventsManager.notifySessionCreatedEvent(EventsManager.java:308)
at weblogic.servlet.internal.EventsManager.notifySessionLifetimeEvent(EventsManager.java:330)
at weblogic.servlet.internal.session.MemorySessionData.(MemorySessionData.java:10)
at weblogic.servlet.internal.session.MemorySessionContext.getNewSession(MemorySessionContext.java:21)
at weblogic.servlet.internal.ServletRequestImpl$SessionHelper.getNewSession(ServletRequestImpl.java:3274)
at weblogic.servlet.internal.ServletRequestImpl$SessionHelper._getSessionInternal(ServletRequestImpl.java:2746)
at weblogic.servlet.internal.ServletRequestImpl$SessionHelper.getSessionInternal(ServletRequestImpl.java:2702)
at weblogic.servlet.internal.ServletRequestImpl$SessionHelper.getSession(ServletRequestImpl.java:2692)
at weblogic.servlet.internal.ServletRequestImpl.getSession(ServletRequestImpl.java:1401)
at weblogic.servlet.internal.ServletRequestImpl.getSession(ServletRequestImpl.java:1397)
at javax.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:263)
at org.directwebremoting.impl.DefaultWebContext.getSession(DefaultWebContext.java:94)
at com.primavera.pvweb.common.DWRSessionTimeoutFilter.doFilter(Unknown Source)
at org.directwebremoting.impl.DefaultRemoter$1.doFilter(DefaultRemoter.java:428)
at org.directwebremoting.impl.DefaultRemoter.execute(DefaultRemoter.java:431)
at org.directwebremoting.impl.DefaultRemoter.execute(DefaultRemoter.java:283)
at org.directwebremoting.servlet.PlainCallHandler.handle(PlainCallHandler.java:52)
at org.directwebremoting.servlet.UrlProcessor.handle(UrlProcessor.java:101)
at org.directwebremoting.servlet.DwrServlet.doPost(DwrServlet.java:146)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:751)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:844)
at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:280)
at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:254)
at weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:136)
at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:346)
at weblogic.servlet.internal.TailFilter.doFilter(TailFilter.java:25)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.primavera.pvweb.DWRFilter.doFilter(Unknown Source)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.primavera.pvweb.GZIPFilter.doFilter(Unknown Source)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.primavera.pvweb.XSSFilter.doFilter(Unknown Source)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.primavera.pvweb.FrontFilter.doFilter(Unknown Source)
- locked com.primavera.pvweb.FrontFilter$1UniqueLockedObjectPerRequest@4a3c9b8
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.primavera.pvweb.filters.ApplicationContextInjector.doFilter(Unknown Source)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at weblogic.servlet.internal.RequestEventsFilter.doFilter(RequestEventsFilter.java:27)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3436)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3402)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:120)
at weblogic.servlet.provider.WlsSubjectHandle.run(WlsSubjectHandle.java:57)
at weblogic.servlet.internal.WebAppServletContext.doSecuredExecute(WebAppServletContext.java:2285)
at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2201)
at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:2179)
at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1572)
at weblogic.servlet.provider.ContainerSupportProviderImpl$WlsRequestExecutor.run(ContainerSupportProviderImpl.java:255)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:311)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:263)
STEPS
-----------------------
The issue can be reproduced at will with the following steps:
- Log into P6.
- Navigate randomly anywhere in the application until the unresponsive behavior occurs.
- Note the error defined above in the managed server log files.
- Note the active thread blocked from the thread dump defined above.
- To obtain a thread dump
- Login to WLS Admin Console
- Under Domain Structure, Expand Environment and select Servers
- Select the link for the server hosting P6
- Select Monitoring, Threads tab
- While hogging threads are displayed, select "Dump Thread Stacks"
- To obtain a thread dump
ADDITIONAL INFORMATION
---------------------------
While the hogging/hung threads occur, attempts to log into P6 will hang and may generate the following error when connecting through IE 11 (which are more a down-stream symptom of the errors occurring above and nothing of direct concern):
weblogic.servlet.internal.ServletNestedRuntimeException: Cannot parse POST parameters of request: '/p6/action/login'
at weblogic.servlet.internal.ServletRequestImpl$RequestParameters.mergePostParams(ServletRequestImpl.java:2426)
at weblogic.servlet.internal.ServletRequestImpl$RequestParameters.parseQueryParams(ServletRequestImpl.java:2243)
at weblogic.servlet.internal.ServletRequestImpl$RequestParameters.getQueryParams(ServletRequestImpl.java:2129)
at weblogic.servlet.internal.ServletRequestImpl$RequestParameters.getParameterNames(ServletRequestImpl.java:2164)
at weblogic.servlet.internal.ServletRequestImpl$RequestParameters.access$900(ServletRequestImpl.java:2014)
at weblogic.servlet.internal.ServletRequestImpl.getParameterNames(ServletRequestImpl.java:891)
at weblogic.servlet.internal.ServletRequestImpl.getParameterMap(ServletRequestImpl.java:946)
at javax.servlet.ServletRequestWrapper.getParameterMap(ServletRequestWrapper.java:189)
at com.primavera.pvweb.XSSFilter.a(Unknown Source)
at com.primavera.pvweb.XSSFilter.doFilter(Unknown Source)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.primavera.pvweb.FrontFilter.doFilter(Unknown Source)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.primavera.pvweb.filters.ApplicationContextInjector.doFilter(Unknown Source)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.primavera.pvweb.DisableURLEncodingFilter.doFilter(Unknown Source)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at weblogic.servlet.internal.RequestEventsFilter.doFilter(RequestEventsFilter.java:27)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3436)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3402)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:120)
at weblogic.servlet.provider.WlsSubjectHandle.run(WlsSubjectHandle.java:57)
at weblogic.servlet.internal.WebAppServletContext.doSecuredExecute(WebAppServletContext.java:2285)
at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2201)
at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:2179)
at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1572)
at weblogic.servlet.provider.ContainerSupportProviderImpl$WlsRequestExecutor.run(ContainerSupportProviderImpl.java:255)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:311)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:263)
Caused By: java.io.IOException: An existing connection was forcibly closed by the remote host
OR
Caused By: java.net.ProtocolException: EOF after reading only: '0' of: '151' promised bytes, out of which at least: '0' were already buffered
Exception in thread "Dispatcher-Thread-21" java.lang.NoSuchMethodError: org.apache.log4j.spi.LoggingEvent.getProperty(Ljava/lang/String;)Ljava/lang/String;
at com.primavera.infr.log.PrmConsoleLogLayout.format(Unknown Source)
at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:292)
at org.apache.log4j.WriterAppender.append(WriterAppender.java:150)
at com.primavera.infr.log.PrmConsoleAppender.append(Unknown Source)
at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221)
Changes
Cause
Sign In with your My Oracle Support account |
|
Don't have a My Oracle Support account? Click to get started |
My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms