【问题标题】:Log4j 2 performance: is single-threaded Console logging faster in Logback than Log4j 2?Log4j 2 性能:Logback 中的单线程控制台日志记录是否比 Log4j 2 更快?
【发布时间】:2016-07-01 10:05:07
【问题描述】:

最近,我尝试了 Log4j 2 日志记录,并尝试在我的本地 Mac 机器上将其性能与 Logback 进行比较。令人惊讶的是,我发现 Logback 在我的测试用例中表现更好。我希望 Log4j 2 比 Log4j 2 网站声称的 Logback 做得更好,所以我想检查一下我在使用 Log4j 2 时是否做错了。

为了测试,我使用了直接 Log4j 2 和使用 SLF4J 不使用的 Logback。另外,两个日志框架都使用了 ConsoleAppender,我测试的模式是:

<Pattern>%d{YYYY-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n</Pattern>

日志测试代码为:

logger.info("This is a bootstrap message");

long start = System.currentTimeMillis();
for (int i = 1; i <= 1000000; i++) {
    logger.info("Order={} successfully processed", "ABC123");
}
long end = System.currentTimeMillis();
logger.info("time taken to process={} ms", end - start);

我为每个日志分别运行了 10 次测试,并尝试计算平均处理时间。出乎意料的是,logback 在每次运行中都表现得更好。我尝试使用参数禁用 Log4j 2 附带的默认 GC 日志记录:

-Dlog4j2.enable.threadlocals=false -Dlog4j2.enable.direct.encoders=false

但我仍然没有看到比 logback 有任何改进。谁能确认我的做法是否正确?

log4j 2 配置:

<Configuration status="INFO" debug="false">
<Appenders>
    <Console name="Console" target="SYSTEM_OUT">
        <PatternLayout pattern="%d{YYYY-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n" />
    </Console>
</Appenders>

<Loggers>
    <Logger name="com.mycompany.app" level="INFO"/>
    <Root level="INFO">
        <AppenderRef ref="Console" />
    </Root>
</Loggers>
</Configuration>

Logback 配置:

<configuration debug="true" scan="true" scanPeriod="1 hour">

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
        <Pattern>
            %d{YYYY-MM-dd HH:mm:ss:S} [%thread] %-5level %logger{36} - %msg%n
        </Pattern>
    </layout>
</appender>

<logger name="com.mycompany.app" level="info"/>

<root level="info">
    <appender-ref ref="STDOUT"/>
</root>

</configuration>

【问题讨论】:

  • 在任何情况下,您都可以执行Task.Run(() =&gt; logger.info("Order={} successfully processed", "ABC123"));,它将在另一个线程中运行它,这样您就不会被阻塞。唯一可能发生的问题是“一劳永逸”的心态,即如果失败了,您将不会知道。
  • 嗨 Stan,谢谢,但这对它们的性能没有任何影响,两个框架都将从中受益,我想看看我在配置 log4j 2 时是否做错了跨度>
  • 请同时显示您的 Log4j2 配置和 Logback 配置,以便人们重现您的测试。
  • 嗨@RemkoPopma 配置添加

标签: java logging log4j logback log4j2


【解决方案1】:

我认为您尝试独立验证 Log4j2 的性能确实与宣传的一样好,这很棒。

我运行了你的测试,这些是我的结果。如您所见,在我的笔记本电脑上,您的测试给出的 Log4j 2 分数略高于 Logback。

Log4j 2.6.1    Logback 1.1.7
-----------    -------------
  7,337 ms       7,413 ms     
  6,956 ms       7,097 ms     
  6,748 ms       7,827 ms     
  6,828 ms       7,480 ms     
  6,745 ms       7,067 ms     
  7,146 ms       7,003 ms     
  6,852 ms       7,036 ms     

那么,这些结果意味着什么?您的测试表明,Console 附加程序的同步日志吞吐量在 Log4j 2 中比在 Logback 中略好于 单个线程。

为了更全面地了解日志库的性能,您还需要比较 异步 日志记录、不同的附加程序(尤其是 文件 附加程序)和来自 的日志记录>多个线程。

  • Asynchronous logging 比同步日志记录快很多,关心性能的应用程序通常会异步记录。在比较日志库性能时,我认为异步日志记录性能是最重要的基准。
  • 控制台日志记录至少50x slower (!) 比记录到文件。它会减慢您的应用程序,应该非常小心在生产配置中使用(最好避免)。因此测量控制台日志记录性能并不是很有用。大多数应用程序都记录到文件,因此文件附加程序可能是开始性能调查的更好地方。
  • 许多应用程序都是多线程的。如果日志库没有精心设计来处理这个问题,锁争用可能会减慢您的应用程序。如果您测量来自多个线程的日志记录,您会发现 Log4j 2 的细粒度锁定提供了much higher throughput than Logback。 (使用异步日志记录 difference is even more pronounced。)

测量多线程日志记录需要格外小心,因为您不想在所有线程都启动之前进行测量,因此您需要CountDownLatch 或类似的东西。

一般而言,我建议您查看JMH 以获得非常可靠且易于使用的基准测试工具。 Log4j 2 performance page 指向用于在页面上生成结果的 JMH 基准。 (例如,FileAppenderBenchmark。)这些可能是熟悉 JMH 和一般性能测试的良好起点。

祝你好运,保持好奇心!

【讨论】:

  • 嗨,@Remko,感谢您花时间运行我的代码示例。我将看看 JMH 并尝试比较结果。我很快就会在这里发布结果。
  • 如何将 Log4j2 存储库克隆到我的桌面并在本地运行测试?
  • 克隆和构建:logging.apache.org/log4j/2.x/build.html 大多数 JMH 基准测试都有关于如何运行它们的 javadoc。
  • @RemkoPopma 这种性能对控制台日志记录的影响是否也适用于在 Docker 容器中运行?我不知道是什么导致了这种负面影响,但我认为对于 docker 场景来说,情况大致相同,对吗?
  • 我认为控制台日志记录也比 Docker 中的文件日志记录慢,但我对 Docker 没有任何个人经验。
【解决方案2】:

在创建这样的测试时,您确实应该使用 JMH。我建议您查看 log4j-perf 模块中的测试,以获取有关如何执行此操作的示例。

另外,您只测试一个线程。 logback 的许多问题只出现在多线程的情况下。您可以在http://logging.apache.org/log4j/2.x/performance.html 的一些图表中看到这一点。请注意,这些图表中的所有数据都来自您可以自己运行的 log4j-perf 模块中的测试。

另外,除非您要实际登录到控制台,否则我不会在测试中使用它,因为它是最慢的登录位置,尽管 log4j 的下一个版本将对此进行一些改进。

最后,如果您对我们的测试有任何疑问,请随时在 log4j 邮件列表中提问。 Remko 一直在与一些性能测试专家合作,可以为您提供有关如何创建良好有意义的测试的良好指导。

【讨论】:

  • 嗨@rgoers,感谢您的回复
猜你喜欢
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2016-07-19
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
相关资源
最近更新 更多