OutputStreamManager.write 上的 Log4j2 线程阻塞

Question

背景 我将 log4j2(2.12.1) 与同步根和异步记录器一起使用。 Lmax 环形缓冲区大小默认为 256*1024。我在控制台中的附加程序。我正在使用 JSON 布局记录 MapMessage。我的日志消息的平均大小约为 100 字节。

通过以上详细信息，我注意到很少有线程被阻塞

"http-nio-8080-exec-172" #451
   Thread State: BLOCKED (on object monitor) owned by "http-nio-8080-exec-148" Id=429
  at org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:231)
  - blocked on <0x000000003eb936ae> (a org.apache.logging.log4j.core.appender.OutputStreamManager)
  at org.apache.logging.log4j.core.appender.OutputStreamManager.writeBytes(OutputStreamManager.java:206)
  at org.apache.logging.log4j.core.layout.AbstractLayout.encode(AbstractLayout.java:211)
  at org.apache.logging.log4j.core.layout.AbstractLayout.encode(AbstractLayout.java:37)
  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:197)
  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:190)
  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:181)
  at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
  at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
  at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
  at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
  at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:543)
  at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502)
  at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485)
  at org.apache.logging.log4j.core.config.LoggerConfig.logParent(LoggerConfig.java:534)
  at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:504)
  at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485)
  at org.apache.logging.log4j.core.async.AsyncLoggerConfig.log(AsyncLoggerConfig.java:121)
  at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:460)
  at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82)
  at org.apache.logging.log4j.core.Logger.log(Logger.java:162)
  at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2190)
  at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2144)
  at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2127)
  at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1828)
  at org.apache.logging.log4j.spi.AbstractLogger.info(AbstractLogger.java:1282)

我的问题是..

1. Ring Buffer 是否快满了，这会导致主线程背压（在我的情况下，servlet 容器线程是 http-nio-8080-exec-148）？堆转储显示 RingBuffer 总是占用 7MB（测试前后）。
2. 如果环形缓冲区快满了，我该如何增加它的大小？或者可能是丢弃事件？？
3. 查看 Log42 性能报告我知道不建议使用控制台附加程序，但我真的没有选择这里。这里有更好的写入 STDOUT 的附加程序吗？

感谢任何建议或想法。

Answer 1

该锁用于防止多个线程同时写入同一个 OutputStream，因为这可能导致数据混合在一起。尽管不能保证，但许多 OutputStream 实现无论如何都会锁定 write 调用 - 所以即使锁被移除，它也会阻塞在 OutputStream 实现中。

这显然是因为正在使用的 OutputStream 正在从其他线程写入数据。该线程并不表示环形缓冲区已满，但有可能其他线程因此而被阻塞。我不清楚为什么必须写信给控制台，但Logging in the Cloud 提供了更多数据，说明为什么不应该这样做，以及在云环境中运行时有哪些替代方案。

更新：查看完整的线程转储后，我有一些观察：

1. com.xxxx.apie.library.InternalRequest.execute(InternalRequest.java:273) 有许多线程在等待。这些似乎正在等待在另一个线程上执行工作，但从线程转储中不清楚这是什么。
2. 有几个线程记录到输出流被阻塞。这些调用来自几个类中的不同点，但都在信息级别记录。
3. 您正在使用 JsonLayout。
4. 您没有发布 Log4j 配置，但在上面的堆栈跟踪中，您可以看到 AsyncLoggerConfig 正在调用 LoggerConfig 的 log 方法。在查看 AsyncLogger 中的代码时，您似乎已经配置了一个没有 Appender 引用的 AsyncLogger，因此 Logger 正在委托给它的父级，它不是异步记录器，因此日志事件甚至没有排队到环​​形缓冲区，而是正在从应用程序线程直接记录。

最重要的是，您正在同步记录到 OutputStream（可能是控制台）并且线程正在阻塞，因为 I/O 很慢。