Log4j 2性能:单线程控制台在Logback中的记录速度比Log4j 2快吗？

Question

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

为了测试,我使用了直接Log4j 2和Logback 而不使用SLF4J.此外,它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.我尝试使用params禁用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>

Answer 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     

那么,这些结果意味着什么呢？您的测试显示,Log4j 2中单个线程的Console appender 的同步日志记录吞吐量略好于Logback.

为了更全面地了解日志库的性能,您还需要比较异步日志记录,不同的appender(尤其是File appender)和从多个线程进行日志记录.

• 异步日志记录是多少比同步记录速度更快,并且关心性能的应用程序通常将异步日志.我认为异步日志记录性能是比较日志库性能时最重要的基准.
• 控制台日志记录比记录到文件至少慢50倍(!).它会减慢您的应用程序,并且应该在生产配置中非常小心地使用(并且最好避免).因此,测量控制台日志记录性能不是很有用.大多数应用程序都会记录到文件,因此File appender可能是开始性能调查的更好地方.
• 许多应用程序都是多线程的.如果日志库未经过精心设计以解决此问题,则锁争用可能会降低应用程序的速度.如果您测量来自多个线程的日志记录,您会发现Log4j 2的细粒度锁定比Logback提供了更高的吞吐量.(使用异步日志记录,差异更加明显.)

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

总的来说,我建议在JMH上寻找一个非常可靠且易于使用的基准测试工具.该Log4j的2性能页面指向用来产生页面对结果的江铃控股的基准.(例如,FileAppenderBenchmark.)这些可能是熟悉JMH和性能测试的一个很好的起点.

祝你好运,保持好奇!