Support Article
Thread blocked on log4j Category.callAppenders()
SA-24725
Summary
The users' two production JVMs out of 12 JVMs were hung and had to be recycled.
Error Messages
Java core blocked thread
3XMTHREADINFO "WebContainer : 38" J9VMThread:0x000000003404CC00, j9thread_t:0x000001005B85CE70, java/lang/Thread:0x000000070A551208, state:B, prio=5
3XMJAVALTHREAD (java/lang/Thread getId:0x3B6DA, isDaemon:true)
3XMTHREADINFO1 (native thread ID:0x458035B, native priority:0x5, native policy:UNKNOWN)
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at com/pega/apache/log4j/Category.callAppenders(Category.java:204(Compiled Code))
4XESTACKTRACE at com/pega/apache/log4j/Category.forcedLog(Category.java:391)
4XESTACKTRACE at com/pega/apache/log4j/Category.alert(Category.java:728)
4XESTACKTRACE at com/pega/pegarules/priv/LogHelper.doAlert(LogHelper.java:1183(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/priv/LogHelper.alert(LogHelper.java:906(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/priv/LogHelper.alert(LogHelper.java:892)
4XESTACKTRACE at com/pega/pegarules/data/internal/access/ConnectionManagerImpl.getConnection(ConnectionManagerImpl.java:1351(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/data/internal/access/ConnectionManagerImpl.getConnection(ConnectionManagerImpl.java:947(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/data/internal/access/ThreadConnectionStoreImpl.getConnection(ThreadConnectionStoreImpl.java:392(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/data/internal/access/LockManagerImpl.unlockForRequestor(LockManagerImpl.java:2015(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/session/internal/engineinterface/etier/impl/LockManagerImpl._unlockForRequestor_privact(LockManagerImpl.java:166(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/session/internal/engineinterface/etier/impl/LockManagerImpl.unlockForRequestor(LockManagerImpl.java:145(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/session/internal/engineinterface/etier/ejb/LockManagerBean.unlockForRequestor(LockManagerBean.java:186(Compiled Code))
4XESTACKTRACE at sun/reflect/GeneratedMethodAccessor129.invoke(Bytecode PC:40(Compiled Code))
4XESTACKTRACE at sun/reflect/DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37(Compiled Code))
4XESTACKTRACE at java/lang/reflect/Method.invoke(Method.java:611(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/internal/bootstrap/PRBootstrap.invokeMethod(PRBootstrap.java:348(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/internal/bootstrap/PRBootstrap.invokeMethodPropagatingThrowable(PRBootstrap.java:389(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/internal/bootstrap/PRBootstrap.invokeMethod(PRBootstrap.java:438(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/internal/etier/ejb/LockManagerBeanBoot.unlockForRequestor(LockManagerBeanBoot.java:168(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/internal/etier/interfaces/EJSLocalStatelessLockManager_9a306bdc.unlockForRequestor(Bytecode PC:50(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/data/internal/access/LockManagerImpl.unlockForRequestor(LockManagerImpl.java:1978(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/session/internal/mgmt/base/RequestorPassivation.cleanupImpl(RequestorPassivation.java:555(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/session/internal/mgmt/PRRequestorBase.cleanup(PRRequestorBase.java:807(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/session/internal/mgmt/PRRequestorImpl.cleanup(PRRequestorImpl.java:305(Compiled Code))
4XESTACKTRACE at com/pega/pegarules/session/internal/mgmt/base/NodeRequestorMgt.cleanupInner(NodeRequestorMgt.java:912)
4XESTACKTRACE at sun/reflect/GeneratedMethodAccessor127.invoke(Bytecode PC:56(Compiled Code))
4XESTACKTRACE at sun/reflect/DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37(Compiled Code))
Steps to Reproduce
Not Applicable
Root Cause
A defect or configuration issue in the operating environment.
The JVMs were monitored nodes of an AES server. Since the AES server was under load with requests queued– monitored nodes’ SOAP messages have been held-back at the monitored nodes causing the log4j appender calls blocking / waiting for the response from the AES server.
Resolution
Make the following change to the operating environment:
The “Blocking” param for the AsyncAppenders have not been set to “false”. By default the value is “true” when not specified or the AsyncAppender will wait if there is no space available in the event buffer.
Modify the following APPENDERs under prlogging.xml for the monitored nodes –
<appender name="ASYNC" class="com.pega.apache.log4j.AsyncAppender">
<param name="BufferSize" value="1280"/>
<param name="Blocking" value="false"/>
[…]
</appender>
<appender name="ALERT-ASYNC" class="com.pega.apache.log4j.AsyncAppender">
<param name="BufferSize" value="1280"/>
<param name="Blocking" value="false"/>
[…]
</appender>
The above change should protect the monitored nodes should the AES server backup threads. The DEFAULT_BUFFER_SIZE of 128 events has been increased by a factor of 10.
Published August 1, 2016 - Updated October 8, 2020
Have a question? Get answers now.
Visit the Collaboration Center to ask questions, engage in discussions, share ideas, and help others.