asynchronous - 异步模式下的 Log4j2 在重负载下仍然阻塞在 java.util.concurrent.lock 上

Question

我正在尝试登录低延迟环境。
2 个高优先级线程在紧密循环中调用 log.error() (1Mmessages/s)

我想使用异步日志记录(使用干扰器)并丢弃任何多余的消息。所以调用线程不应该阻塞。

但是，jstack 清楚地显示它正在阻塞大约 100 次/秒。

是我的配置有问题吗？
或者，如果缓冲区填满，阻塞是否不可避免？

java -Log4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
-Dlog4j2.AsyncQueueFullPolicy=Discard
-Dlog4j2.DiscardThreshold=Trace
-DAsyncLogger.RingBufferSize=2000000 TestLog


"TT0" #14 prio=5 os_prio=0 tid=0x00007fe8cc690800 nid=0x2463 runnable [0x00007fe8ae70d000]
   java.lang.Thread.State: RUNNABLE
        at sun.misc.Unsafe.unpark(Native Method)
        at java.util.concurrent.locks.LockSupport.unpark(LockSupport.java:141)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.unparkSuccessor(AbstractQueuedSynchronizer.java:662)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1264)
        at java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:457)
        at com.lmax.disruptor.BlockingWaitStrategy.signalAllWhenBlocking(BlockingWaitStrategy.java:72)
        at com.lmax.disruptor.MultiProducerSequencer.publish(MultiProducerSequencer.java:218)
        at com.lmax.disruptor.RingBuffer.translateAndPublish(RingBuffer.java:934)
        at com.lmax.disruptor.RingBuffer.publishEvent(RingBuffer.java:444)
        at com.lmax.disruptor.dsl.Disruptor.publishEvent(Disruptor.java:245)
        at org.apache.logging.log4j.core.async.AsyncLogger.logMessage(AsyncLogger.java:285)
        at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:727)
        at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:716)
        at org.apache.logging.log4j.spi.AbstractLogger.debug(AbstractLogger.java:232)
        at TestLog$WriteToFile.run(TestLog.java:53)
        at java.lang.Thread.run(Thread.java:745)

"AsyncLogger-1" #12 daemon prio=5 os_prio=0 tid=0x00007fe8cc96f800 nid=0x2460 waiting on condition [0x00007fe8b4187000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007104a0f28> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at com.lmax.disruptor.BlockingWaitStrategy.waitFor(BlockingWaitStrategy.java:45)
        at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:55)
        at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:123)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

Answer 1

LMAX Disruptor 允许您选择后台线程在等待工作到达时应该做什么。

默认情况下，Log4j2 使用 BlockingWaitStrategy。这给出了您所看到的行为，这适用于大多数情况，但可能不适用于超低延迟用例。

如果您可以将核心专用于后台线程，则可以使用 BusySpin 等待策略。

见 https://github.com/apache/logging-log4j2/blob/master/log4j-core/src/main/java/org/apache/logging/log4j/core/async/DisruptorUtil.java