APAR status
Closed as program error.
Error description
Running sip trace on WAS 8.5.5.14 server, resulted in Deadlock, This trace *=info:com.ibm.ws.sip.*=all:com.ibm.wsspi. sip*=all:com.ibm.ws.udp.*=all This deadlock 1LKDEADLOCK Deadlock detected !!! NULL --------------------- NULL 2LKDEADLOCKTHR Thread "SipContainerPool : 8" (0x000000000481C700) 3LKDEADLOCKWTR is waiting for: 4LKDEADLOCKMON sys_mon_t:0x00007F3CFCCE7878 infl_mon_t: 0x00007F3CFCCE78F8: 4LKDEADLOCKOBJ com/ibm/ws/loggin g/hpel/impl/LogRepositorySpaceAlert@0x00000006E0F765F0 3LKDEADLO CKOWN which is owned by: 2LKDEADLOCKTHR Thread "Timer-1" (0x00000000029EA700) 3LKDEADLOCKWTR which is waiting for: 4LKDEADLOCKMON sys_mon_t:0x00007F3D218944B8 infl_mon_t: 0x00007F3D21894538: 4LKDEADLOCKOBJ com/ibm/ws/logging/hpel/handl ers/LogRecordTextHandler@0x00000006E0F9FB90 3LKDEADLOCKOWN which is owned by: 2LKDEADLOCKTHR Thread "SipContainerPool : 8" (0x000000000481C700) NULL 3XMTHREADINFO "SipContainerPool : 8" J9VMThread:0x000000000481C700, omrthread_t:0x00007F3D1CFAAEE8, java/lang/Thread:0x00000006E4D9A260, state:B, prio=5 3XMJAVALTHREAD (java/lang/Thread getId:0xF5, isDaemon:true) 3XMTHREADINFO1 (native thread ID:0x2359, native priority:0x5, native policy:UNKNOWN, vmstate:B, vm thread flags:0x00000201) 3XMTHREADINFO2 (native stack address range from:0x00007F3D1769A000, to:0x00007F3D176DA000, size:0x40000) 3XMCPUTIME CPU usage total: 1652.771830022 secs, current category="Application" 3XMTHREADBLOCK Blocked on: com/ib m/ws/logging/hpel/impl/LogRepositorySpaceAlert@0x00000006E0F765F 0 Owned by: "Timer-1" (J9VMThread:0x00000000029EA700, java/lang/Thread:0x00000006E102AC08) 3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0) 3XMTHREADINFO3 Java callstack: 4XESTACKTRACE at com/ibm/ws/logging/hpel/impl/LogRepo sitorySpaceAlert.setRepositoryInfo(LogRepositorySpaceAlert.java: 150(Compiled Code)) 5XESTACKTRACE (entered lock: com/ibm/ws/logg ing/hpel/impl/LogRepositorySpaceAlert@0x00000006E0F765F0, entry count: 1) 4XESTACKTRACE at com/ibm/ws/logging/hpel/impl/LogRepos itoryManagerImpl.checkSpaceConstrain(LogRepositoryManagerImpl.ja va:377(Compiled Code)) 4XESTACKTRACE at com/ibm/ws/logging/hpel/ impl/LogRepositoryManagerImpl.checkForNewFile(LogRepositoryManag erImpl.java:640(Compiled Code)) 5XESTACKTRACE (entered lock: java/util/HashMap@0x00000007602928B0, entry count: 1) 5XESTACKTRACE (entered lock: com/ibm/ws/logging/hpel/impl/Log RepositoryManagerTextImpl@0x00000007602927E0, entry count: 1) 4XESTACKTRACE at com/ibm/ws/logging/hpel/impl/LogRepositoryWr iterImpl.logRecord(LogRepositoryWriterImpl.java:165(Compiled Code)) 5XESTACKTRACE (entered lock: com/ibm/ws/logging/hpel/hand lers/LogRepositoryComponent$3$1@0x000000076033C128, entry count: 1) 4XESTACKTRACE at com/ibm/ws/logging/hpel/handlers/LogR ecordTextHandler.processEvent(LogRecordTextHandler.java:83(Compi led Code)) 5XESTACKTRACE (entered lock: com/ibm/ws/logging/hpel/ handlers/LogRecordTextHandler@0x00000006E0F9FB90, entry count: 1) 4XESTACKTRACE at com/ibm/ws/logging/hpel/handlers/LogRecordTe xtHandler.publish(LogRecordTextHandler.java:186(Compiled Code)) 4XESTACKTRACE at java/util/logging/Logger.log(Logger.java:749(Compiled Code)) 4XESTACKTRACE at com/ibm/ws/logging/WsLogger.deliverOrBuf fer(WsLogger.java:422(Compiled Code)) ..... snip ..... 3XMTHREADINFO "Timer-1" J9VMThread:0x00000000029EA700, omrthread_t:0x00007F3D222F6118, java/lang/Thread:0x00000006E102AC08, state:B, prio=5 3XMJAVALTHREAD (java/lang/Thread getId:0x27, isDaemon:true) 3XMTHREADINFO1 (native thread ID:0x2081, native priority:0x5, native policy:UNKNOWN, vmstate:B, vm thread flags:0x00000201) 3XMTHREADINFO2 (native stack address range from:0x00007F3D20622000, to:0x00007F3D20662000, size:0x40000) 3XMCPUTIME CPU usage total: 2.275410006 secs, current category="Application" 3XMTHREADBLOCK Blocked on: com/ib m/ws/logging/hpel/handlers/LogRecordTextHandler@0x00000006E0F9FB 90 Owned by: "SipContainerPool : 8" (J9VMThread:0x000000000481C700, java/lang/Thread:0x00000006E4D9A260) 3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0) 3XMTHREADINFO3 Java callstack: 4XESTACKTRACE at com/ibm/ws/logging/hpel/handlers/Log RecordTextHandler.processEvent(LogRecordTextHandler.java:68(Comp iled Code)) 4XESTACKTRACE at com/ibm/ws/logging/hpel/handlers/Lo gRecordTextHandler.publish(LogRecordTextHandler.java:186(Compile d Code)) 4XESTACKTRACE at java/util/logging/Logger.log(Logger.java:749(Compiled Code)) 4XESTACKTRACE at com/ibm/ws/logging/WsLogger.deliverOrBuf fer(WsLogger.java:422(Compiled Code)) 4XESTACKTRACE at com/ibm/ws/logging/WsLogger.log(WsLogger.java:400(Compiled Code)) 4XESTACKTRACE at com/ibm/ws/logging/WsLogger.logp(WsLogger.java:638(Compiled Code)) 4XESTACKTRACE at com/ibm/ws/logging/hpel/impl/LogReposito rySpaceAlert.checkFileSystems(LogRepositorySpaceAlert.java:205(C ompiled Code)) 5XESTACKTRACE (entered lock: com/ibm/ws/logging/h pel/impl/LogRepositorySpaceAlert@0x00000006E0F765F0, entry count: 1) 4XESTACKTRACE at com/ibm/ws/logging/hpel/impl/LogRepos itorySpaceAlert.access$500(LogRepositorySpaceAlert.java:33(Compi led Code)) 4XESTACKTRACE at com/ibm/ws/logging/hpel/impl/LogRepo sitorySpaceAlert$FileSystemCheckTask.run(LogRepositorySpaceAlert .java:53(Compiled Code)) ..... snip .....
Local fix
To workaround the issue, the customer can either disable the SIP trace or lower its trace level, which will prevent the deadlock or since the WARNING was being printed, due to the File System running out of space to create a new file, they can clear out some space or modify their log and trace configurations to point to a different file system or consume less space during file rotation. For more information on the WARNING message, please refer to the following document and refer to the HPEL0161W message: https://www.ibm.com/support/kno wledgecenter/SSD28V_liberty/com.ibm.websphere.messages.liberty.d oc/com.ibm.ws.logging.hpel.resources.HpelMessages.html
Problem summary
**************************************************************** * USERS AFFECTED: All users of IBM WebSphere Application * * Server * **************************************************************** * PROBLEM DESCRIPTION: A deadlock occurs when HPEL tries to * * log a * * WARNING message when the file system is * * running out of space with SIP tracing * * enabled. * **************************************************************** * RECOMMENDATION: * **************************************************************** A deadlock was caused when HPEL was trying to log a WARNING message during the file system space check task, during log rotation, at the same time, SIP debug trace messages were being logged. The following two thread were contending for each others' locks, which resulted in a deadlock. 2LKDEADLOCKTHR Thread "SipContainerPool : 8" (0x000000000481C700) 3LKDEADLOCKWTR is waiting for: 4LKDEADLOCKMON sys_mon_t:0x00007F3CFCCE7878 infl_mon_t: 0x00007F3CFCCE78F8: 4LKDEADLOCKOBJ com/ibm/ws/logging/hpel/impl/LogRepositorySpaceAlert@0x00000006E 0F7 65F0 3LKDEADLO CKOWN which is owned by: 2LKDEADLOCKTHR Thread "Timer-1" (0x00000000029EA700) 3LKDEADLOCKWTR which is waiting for: 4LKDEADLOCKMON sys_mon_t:0x00007F3D218944B8 infl_mon_t: 0x00007F3D21894538: 4LKDEADLOCKOBJ com/ibm/ws/logging/hpel/handlers/LogRecordTextHandler@0x00000006 E0F 9FB90 3LKDEADLOCKOWN which is owned by: 2LKDEADLOCKTHR Thread "SipContainerPool : 8"(0x000000000481C700) NULL
Problem conclusion
The code was fixed to resolve lock contention when tracing and H is enabled, thus preventing he deadlock from occurring. The fix for this APAR is targeted for inclusion in fix pack 8.5.5.19 and 9.0.5.6. For more information, see 'Recommended Updates for WebSphere Application Server': https://www.ibm.com/support/pages/node/715553
Temporary fix
Comments
APAR Information
APAR number
PH27825
Reported component name
WEBS APP SERV N
Reported component ID
5724H8800
Reported release
850
Status
CLOSED PER
PE
NoPE
HIPER
NoHIPER
Special Attention
NoSpecatt / Xsystem
Submitted date
2020-07-24
Closed date
2020-09-01
Last modified date
2020-09-01
APAR is sysrouted FROM one or more of the following:
APAR is sysrouted TO one or more of the following:
Fix information
Fixed component name
WEBS APP SERV N
Fixed component ID
5724H8800
Applicable component levels
R850 PSY
UP
R900 PSY
UP
[{"Business Unit":{"code":"BU059","label":"IBM Software w\/o TPS"},"Product":{"code":"SSEQTP","label":"WebSphere Application Server"},"Platform":[{"code":"PF025","label":"Platform Independent"}],"Version":"8.5","Line of Business":{"code":"LOB45","label":"Automation"}}]
Document Information
Modified date:
02 November 2021