IBM Support

PH27825: DEADLOCK IN HPEL CODE WHEN RUNNING SIP TRACING.

Subscribe to this APAR

By subscribing, you receive periodic emails alerting you to the status of the APAR, along with a link to the fix after it becomes available. You can track this item individually or track all items by product.

Notify me when this APAR changes.

Notify me when an APAR for this component changes.

 

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

[{"Line of Business":{"code":"LOB36","label":"IBM Automation"},"Business Unit":{"code":"BU053","label":"Cloud & Data Platform"},"Product":{"code":"SSEQTP","label":"WebSphere Application Server"},"Platform":[{"code":"PF025","label":"Platform Independent"}],"Version":"850"}]

Document Information

Modified date:
14 September 2020