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-#" (Doc ID 2069369.1)

Last updated on DECEMBER 05, 2018

Applies to:

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'> <> <> <> <1444724524578> <BEA-000405> <Uncaught Throwable in processSockets
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:

1. Log into P6.
2. Navigate randomly anywhere in the application until the unresponsive behavior occurs.
3. Note the error defined above in the managed server log files.
4. Note the active thread blocked from the thread dump defined above.
   • To obtain a thread dump
     
     1. Login to WLS Admin Console
     2. Under Domain Structure, Expand Environment and select Servers
     3. Select the link for the server hosting P6
     4. Select Monitoring, Threads tab
     5. While hogging threads are displayed, select "Dump Thread Stacks"

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

Changes

Cause

My Oracle Support provides customers with access to over a million knowledge articles and a vibrant support community of peers and Oracle experts.