apache / apache/logging-log4j2
Deadlock when use TimeoutBlockingWaitStrategy
- Dominant language
- Java
- Stars
- 3.6k
- Forks
- 1.7k
- Avg merge
- 21h 30m
- Merged PRs (30d)
- 27
Description
## Description
Hello, we use a custom log implementation framework based on log4j2. But we meet a thread deadlock rencently. Although there is a very small probability, but the services will not work at that time. What could be the cause of this deadlock?
## Configuration
**Version:** log4j2 2.18.0、disruptor 3.4.1
**Operating system:** linux centos 7
**JDK:** jdk8u192
config:
Log4jContextSelector=org.apache.logging.log4j.core.async.BasicAsyncLoggerContextSelector
log4j2.AsyncQueueFullPolicy=Discard
log4j2.DiscardThreshold=ERROR
AsyncLogger.WaitStrategy=TIMEOUT
AsyncLogger.Timeout=100
## Logs
```
Java stack information for the threads listed above:
===================================================
"Thread-307":
at org.apache.logging.log4j.core.async.TimeoutBlockingWaitStrategy.signalAllWhenBlocking(TimeoutBlockingWaitStrategy.java:103)
- waiting to lock <0x00000006a372f698> (a java.lang.Object)
at com.lmax.disruptor.MultiProducerSequencer.publish(MultiProducerSequencer.java:218)
at com.lmax.disruptor.RingBuffer.translateAndPublish(RingBuffer.java:966)
at com.lmax.disruptor.RingBuffer.tryPublishEvent(RingBuffer.java:478)
at org.apache.logging.log4j.core.async.AsyncLoggerDisruptor.tryPublish(AsyncLoggerDisruptor.java:232)
at org.apache.logging.log4j.core.async.AsyncLogger.publish(AsyncLogger.java:229)
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:2205)
at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2159)
at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2142)
at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2028)
at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1891)
at org.apache.logging.slf4j.Log4jLoggerWrapper.lambda$logIfEnabled$0(Log4jLoggerWrapper.java:14)
at org.apache.logging.slf4j.Log4jLoggerWrapper$$Lambda$405/771220417.run(Unknown Source)
at com.jd.component.donglog.log.LogUtils.executeWithLogMDC(LogUtils.java:137)
at org.apache.logging.slf4j.Log4jLoggerWrapper.logIfEnabled(Log4jLoggerWrapper.java:14)
at org.apache.logging.slf4j.Log4jLogger.info(Log4jLogger.java:185)
at com.jd.kaware.fed.sdk.fedservice.threadpool.FedTaskThreadPool$1.run(FedTaskThreadPool.java:135)
at java.lang.Thread.run(Thread.java:748)
Found one Java-level deadlock:
=============================
"Thread-306":
waiting to lock monitor 0x00007f67e033e6c8 (object 0x00000006a372f698, a java.lang.Object),
which is held by UNKNOWN_owner_addr=0x00007f6808dbd000
。。。
"Log4j2-TF-1-AsyncLogger[AsyncDefault]-1" #45 daemon prio=5 os_prio=0 tid=0x00007f681d086800 nid=0x230 waiting for monitor entry [0x00007f6816cfe000]
java.lang.Thread.State: BLOCKED (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:460)
at org.apache.logging.log4j.core.async.TimeoutBlockingWaitStrategy.awaitNanos(TimeoutBlockingWaitStrategy.java:130)
at org.apache.logging.log4j.core.async.TimeoutBlockingWaitStrategy.waitFor(TimeoutBlockingWaitStrategy.java:86)
- locked <0x00000006a372f698> (a java.lang.Object)
at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56)
at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:141)
at java.lang.Thread.run(Thread.java:748)
Locked ownable synchronizers:
- None
```
## Reproduction
none
Contributor guide
No contributing guide indexed for this repository
Research direction
Start by reading TimeoutBlockingWaitStrategy.java at waitFor, awaitNanos, and signalAllWhenBlocking, then trace the reported calls through MultiProducerSequencer.publish and AsyncLoggerDisruptor.tryPublish. There is no reproduction, so done requires establishing the cause from a minimal reproducer or the supplied thread cycle and documenting or testing the resulting fix.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java, linux
- Domain
- observability-sre
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 20/100