java - Log4j2 OutputStreamManager.write 上的线程阻塞

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. 环形缓冲区是否很快就满了，这对主线程造成了背压(在我的例子中，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 委托(delegate)给其父级，而该父级不是异步记录器，因此日志事件甚至没有排队到环​​形缓冲区，而是直接从应用程序线程记录。

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