java - logback:AsyncAppender 比同步 FileAppender 花费更多时间

Question

我发现 logback 异步日志提供的性能比同步日志差。详情如下。

我可能遗漏了什么？

测试类:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Main extends Thread {

    public static final Logger defaultLogger = LoggerFactory.getLogger(Main.class);

    public static void main(String[] args) throws IOException {
        new Main().start();
        System.out.println("... Thread started\n");

        // This is to block till thread finishes writing
        System.in.read();
    }

    public void run() {
        long start = System.currentTimeMillis();

        for(int i = 0; i < 1000000; i++) {          
            defaultLogger.warn("Default logger:");
        }

        long end = System.currentTimeMillis();

        System.out.println("\n**** " + new Long(end - start));
    }
}

logback.xml:

<configuration>

    <appender name="DEFAULT-FILE" class="ch.qos.logback.core.FileAppender">
        <append>true</append>
        <file>logger.log</file>
        <encoder charset="UTF-8">
            <pattern>[%date] [%thread] %msg %n</pattern>
        </encoder>
    </appender>

    <appender name="DEFAULT-ASYNC" class="ch.qos.logback.classic.AsyncAppender">
        <!-- Have tried to play around with queue size - no major effect -->
        <!-- <queueSize>512</queueSize>  -->
        <discardingThreshold>0</discardingThreshold>
        <appender-ref ref="DEFAULT-FILE" />
    </appender>

    <root level="all">
        <!-- Switch between the two appenders -->
        <appender-ref ref="DEFAULT-FILE" />
        <!-- <appender-ref ref="DEFAULT-ASYNC" /> -->
    </root>

</configuration>

观察:

Sync FileAppender: ~5000ms AsyncAppender: ~7000ms

版本:

slf4j: 1.7.19 logback: 1.1.6

Answer 1

您的代码的一个问题是您在很短的时间内创建了 1000000 个日志记录条目，但是 AsyncAppender 有一个最大容量为 256(默认)的队列。

因此，作为第一步，您必须将队列大小增加到 1000000。否则您测量的时间无效。

此外，您应该在同一个 JVM 实例中进行多次测量并丢弃第一个，因为它可能因类和缓冲区初始化时间而受到污染。