java - Log4J2 同步记录器比混合异步/同步记录器更快

Question

基于https://logging.apache.org/log4j/2.x/manual/async.html我想使用混契约(Contract)步和异步记录器方法，以便从所有同步记录器的性能改进中受益。

基准代码:

public static void main(String[] args) {
    org.apache.logging.log4j.Logger log4j2Logger = org.apache.logging.log4j.LogManager
            .getLogger("com.foo.Bar");

    long start = System.currentTimeMillis();
    int nbLogMessages = 1 * 1000 * 1000;

    for (int i = 0; i < nbLogMessages; i++) {
        log4j2Logger.info("Log Message");
    }

    org.apache.logging.log4j.core.Logger coreLogger = (org.apache.logging.log4j.core.Logger) log4j2Logger;
    org.apache.logging.log4j.core.LoggerContext context = (org.apache.logging.log4j.core.LoggerContext) coreLogger
            .getContext();
    Map<String, org.apache.logging.log4j.core.Appender> appenders = context
            .getConfiguration().getAppenders();
    for (org.apache.logging.log4j.core.Appender appender : appenders
            .values()) {
        appender.stop();
    }

    long elapsed = System.currentTimeMillis() - start;
    System.out.println("Elapsed " + elapsed + "ms "
            + (nbLogMessages * 1000 / elapsed) + "logs/sec.");
}

Log4j2 配置与文档 ( https://logging.apache.org/log4j/2.x/manual/async.html ) 中的配置完全相同:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
  <Appenders>
    <RandomAccessFile name="RandomAccessFile" fileName="/tmp/asyncWithLocation.log" immediateFlush="false" append="false">
      <PatternLayout>
        <Pattern>%d %p %class{1.} [%t] %location %m %ex%n</Pattern>
      </PatternLayout>
    </RandomAccessFile>
  </Appenders>
  <Loggers>
    <!-- pattern layout actually uses location, so we need to include it -->
    <AsyncLogger name="com.foo.Bar" level="trace" includeLocation="true">
      <AppenderRef ref="RandomAccessFile"/>
    </AsyncLogger>
    <Root level="info" includeLocation="true">
      <AppenderRef ref="RandomAccessFile"/>
    </Root>
  </Loggers>
</Configuration>

使用混契约(Contract)步/异步记录器配置，我可以达到大约 33,400 日志/秒。

现在，如果我用常规 Logger 替换 AsyncLogger“com.foo.Bar”，我会得到大约 35,300 日志/秒。

为什么同步记录器策略更快，根据图表，它应该具有更高的吞吐量不是？

在按照他们的建议进行基准测试之前，我尝试了各种其他方法，例如“预热”JVM，但没有帮助。

请注意，如果我将属性 Log4jContextSelector 设置为“org.apache.logging.log4j.core.async.AsyncLoggerContextSelector”以激活“所有异步”记录器，我会得到大约 86,400 个日志/秒。不幸的是，由于其他原因我无法使用该选项。

使用 log4j2-2.3、disruptor-3.3.2。
操作系统是Ubuntu，8核。

Answer 1

在开始测量之前，我建议您记录较少数量的消息，例如 100,000 条左右，然后在开始测量循环之前 hibernate 一秒钟。 (您不想在这里测量 log4j 的初始化或 JVM 优化。)

如果您在日志记录循环完成之后(在尝试停止附加程序之前)进行测量，您的性能结果是什么？

另请尝试在配置中设置 includeLocation="false"。这应该会产生很大的影响。

我认为您不应该手动停止附加程序(请参阅我对您的其他问题的回答)。