HI,
Using log4j2 1.13.1 with disruptor 3.4.2. Linux CentOS. JRE 11.0.5
Using the following JRE args:
-DAsyncLogger.RingBufferSize=32768
-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
-Dlog4j.configurationFile=...
The disruptor queue has filled up. And we've observed deadlock with
the interesting threads stuck like the following. Disruptor processing
thread seems to be waiting to process events and all the other threads
locked up on trying to publish the events.
"Log4j2-TF-1-AsyncLogger[AsyncContext@5cb0d902]-1" #23 daemon prio=5
os_prio=0 cpu=40099128.73ms elapsed=44102.95s tid=0x00007f4c2ca34000
nid=0x611a runnable [0x00007f4bfdcfc000]
java.lang.Thread.State: RUNNABLE
at
com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at
com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:159)
at
com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.lang.Thread.run(java.base@11.0.5/Thread.java:834)
Locked ownable synchronizers:
- None
"xxx" #268 prio=5 os_prio=0 cpu=7051742.32ms elapsed=43967.04s
tid=0x00007f4c2e6ea800 nid=0x649d runnable [0x00007f49f77dd000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.5/Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.5
/LockSupport.java:357)
at
com.lmax.disruptor.MultiProducerSequencer.next(MultiProducerSequencer.java:136)
at
com.lmax.disruptor.MultiProducerSequencer.next(MultiProducerSequencer.java:105)
at com.lmax.disruptor.RingBuffer.publishEvent(RingBuffer.java:465)
at com.lmax.disruptor.dsl.Disruptor.publishEvent(Disruptor.java:331)
at
org.apache.logging.log4j.core.async.AsyncLoggerDisruptor.enqueueLogMessageWhenQueueFull(AsyncLoggerDisruptor.java:230)
- locked <0x0000000701017288> (a java.lang.Object)
at
org.apache.logging.log4j.core.async.AsyncLogger.handleRingBufferFull(AsyncLogger.java:246)
at
org.apache.logging.log4j.core.async.AsyncLogger.publish(AsyncLogger.java:230)
at
org.apache.logging.log4j.core.async.AsyncLogger.logWithThreadLocalTranslator(AsyncLogger.java:225)
at
org.apache.logging.log4j.core.async.AsyncLogger.access$000(AsyncLogger.java:67)
at
org.apache.logging.log4j.core.async.AsyncLogger$1.log(AsyncLogger.java:152)
at
org.apache.logging.log4j.core.async.AsyncLogger.log(AsyncLogger.java:136)
at
org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2198)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2152)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2135)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2016)
at
org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1875)
at org.apache.logging.slf4j.Log4jLogger.info(Log4jLogger.java:179)
...
at java.lang.Thread.run(java.base@11.0.5/Thread.java:834)
Locked ownable synchronizers:
- None
and all other threads are stuck like this:
"xx-nioW-16" #273 prio=5 os_prio=0 cpu=7439.15ms elapsed=43966.67s
tid=0x00007f4c2e4c7000 nid=0x64a9 waiting for monitor entry
[0x00007f49f6ad2000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.logging.log4j.core.async.AsyncLoggerDisruptor.enqueueLogMessageWhenQueueFull(AsyncLoggerDisruptor.java:230)
- waiting to lock <0x0000000701017288> (a java.lang.Object)
at
org.apache.logging.log4j.core.async.AsyncLogger.handleRingBufferFull(AsyncLogger.java:246)
at
org.apache.logging.log4j.core.async.AsyncLogger.publish(AsyncLogger.java:230)
at
org.apache.logging.log4j.core.async.AsyncLogger.logWithThreadLocalTranslator(AsyncLogger.java:225)
at
org.apache.logging.log4j.core.async.AsyncLogger.access$000(AsyncLogger.java:67)
at
org.apache.logging.log4j.core.async.AsyncLogger$1.log(AsyncLogger.java:152)
at
org.apache.logging.log4j.core.async.AsyncLogger.log(AsyncLogger.java:136)
at
org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2198)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2152)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2135)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2022)
at
org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1891)
at org.apache.logging.slf4j.Log4jLogger.info(Log4jLogger.java:194)
...
Does this ring any bells?
Thank you in advance!
