apache / apache/logging-log4j2

Deadlock when use TimeoutBlockingWaitStrategy

Open
#4,009 2 comments 0 reactions 0 assignees View on GitHub
async bug waiting-for-maintainer
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

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.