log4j的同步与异步日志 2022年4月18日
【Java】
2 条评论
views: 643

log4j2框架从配置文件来看，分为appenders与loggers。在配置Logger时官方提供了AsyncLogger异步标签，但是如果此时ref所指定的Appender是一个同步的，最终结果会是同步还是异步打印呢？

log4j2.xml某段配置如下：

<!--appenders:定义输出内容,输出格式,输出方式,日志保存策略等,常用其下三种标签[console,File,RollingFile]-->
<appenders>
    <!--console :控制台输出的配置-->
    <Console name="CONSOLE" target="system_out">
        <PatternLayout pattern="${PATTERN}" />
    </Console>
    <Async name="AsyncCONSOLE">
        <AppenderRef ref="CONSOLE" />
    </Async>
</appenders>

<!--定义logger，只有定义了logger并引入的appender，appender才会生效-->
<loggers>
    <!--Logger：节点用来单独指定日志的形式，name为包路径，比如要为com.hundsun.jrescloud.common.log.trace包下所有日志指定为INFO级别等。-->
    <!--AsyncLogger：异步日志，LOG4J有三种日志模式，全异步日志，混合模式，同步日志，性能从高到底，线程越多效率越高，也可以避免日志卡死线程情况发生。-->
    <!--additivity="false"：additivity设置事件是否在root logger输出，为了避免重复输出，可以在Logger标签下设置additivity为”false”-->
    <AsyncLogger name="cn.pcshao.util.pcsutil.creshelper.CresHelper"
                 level="info" additivity="false">
        <!--<AppenderRef ref="AsyncTraceLog" />-->
        <!--            <AppenderRef ref="AsyncCONSOLE" />-->
        <AppenderRef ref="CONSOLE" />
    </AsyncLogger>

    <Logger name="cn.pcshao.util.pcsutil.creshelper.CresHelper"
            level="info" additivity="false">
        <!--<AppenderRef ref="AsyncTraceLog" />-->
        <!--            <AppenderRef ref="AsyncCONSOLE" />-->
        <AppenderRef ref="CONSOLE" />
    </Logger>

    <!-- Root节点用来指定项目的根日志，如果没有单独指定Logger，那么就会默认使用该Root日志输出 -->
    <root level="info">
        <!--<AppenderRef ref="AsyncCONSOLE" />-->
        <AppenderRef ref="CONSOLE" />
    </root>
</loggers>

写一段多线程代码来运行

class MyRunnable implements Runnable {
    private int count;
    public MyRunnable(int count) {
        this.count = count;
    }

    @Override
    public void run() {
        System.out.println(String.format("start %d %s", count, Thread.currentThread().getName()));
        log.info("这是info count:{} 是否异步:{} ", count, AsyncLoggerContextSelector.isSelected());
        log.error("这是error count:{} 是否异步:{} ", count, AsyncLoggerContextSelector.isSelected());
        log.debug("这是debug count:{} 是否异步:{} ", count, AsyncLoggerContextSelector.isSelected());
        System.out.println(String.format("end %d %s", count, Thread.currentThread().getName()));
    }
}

/**
 * 主入口
 */
public void execute(){
    // test
    for (int i = 0; i < 5; i++) {
        taskExecutor.execute(new MyRunnable(i));
    }
}

输出如下，可以看出来是同步的，一个start n对应一个end n

start 0 CRESHelper Thread-1
start 1 CRESHelper Thread-2
start 4 CRESHelper Thread-5
start 3 CRESHelper Thread-4
start 2 CRESHelper Thread-3
2022-04-18 16:39:16.984 |-INFO
[CRESHelper Thread-3] cn.pcshao.util.pcsutil.creshelper.CresHelper [86] -| 这是info count:2 是否异步:false
2022-04-18 16:39:16.984 |-INFO
[CRESHelper Thread-5] cn.pcshao.util.pcsutil.creshelper.CresHelper [86] -| 这是info count:4 是否异步:false
2022-04-18 16:39:16.984 |-INFO
[CRESHelper Thread-4] cn.pcshao.util.pcsutil.creshelper.CresHelper [86] -| 这是info count:3 是否异步:false
2022-04-18 16:39:16.984 |-INFO
[CRESHelper Thread-2] cn.pcshao.util.pcsutil.creshelper.CresHelper [86] -| 这是info count:1 是否异步:false
2022-04-18 16:39:16.984 |-INFO
[CRESHelper Thread-1] cn.pcshao.util.pcsutil.creshelper.CresHelper [86] -| 这是info count:0 是否异步:false
2022-04-18 16:39:16.985 |-ERROR
[CRESHelper Thread-3] cn.pcshao.util.pcsutil.creshelper.CresHelper [87] -| 这是error count:2 是否异步:false
2022-04-18 16:39:16.985 |-ERROR
[CRESHelper Thread-4] cn.pcshao.util.pcsutil.creshelper.CresHelper [87] -| 这是error count:3 是否异步:false
2022-04-18 16:39:16.985 |-ERROR
[CRESHelper Thread-2] cn.pcshao.util.pcsutil.creshelper.CresHelper [87] -| 这是error count:1 是否异步:false
2022-04-18 16:39:16.985 |-ERROR
[CRESHelper Thread-5] cn.pcshao.util.pcsutil.creshelper.CresHelper [87] -| 这是error count:4 是否异步:false
2022-04-18 16:39:16.985 |-DEBUG
[CRESHelper Thread-3] cn.pcshao.util.pcsutil.creshelper.CresHelper [88] -| 这是debug count:2 是否异步:false
2022-04-18 16:39:16.985 |-ERROR
[CRESHelper Thread-1] cn.pcshao.util.pcsutil.creshelper.CresHelper [87] -| 这是error count:0 是否异步:false
2022-04-18 16:39:16.985 |-DEBUG
[CRESHelper Thread-5] cn.pcshao.util.pcsutil.creshelper.CresHelper [88] -| 这是debug count:4 是否异步:false
end 2 CRESHelper Thread-3
end 4 CRESHelper Thread-5
2022-04-18 16:39:16.985 |-DEBUG
[CRESHelper Thread-4] cn.pcshao.util.pcsutil.creshelper.CresHelper [88] -| 这是debug count:3 是否异步:false
2022-04-18 16:39:16.985 |-DEBUG
[CRESHelper Thread-2] cn.pcshao.util.pcsutil.creshelper.CresHelper [88] -| 这是debug count:1 是否异步:false
2022-04-18 16:39:16.985 |-DEBUG
[CRESHelper Thread-1] cn.pcshao.util.pcsutil.creshelper.CresHelper [88] -| 这是debug count:0 是否异步:false
end 3 CRESHelper Thread-4
end 0 CRESHelper Thread-1
end 1 CRESHelper Thread-2

结论确实如此吗？AsyncLogger因Appender而失效？注意这里两个logger同时配置了同一个class

只保留一条Logger尝试，结果如下

  • 异步AsyncLogger修饰，其ref的Appender为同步，结果为异步
  • 异步AsyncLogger修饰，其ref的Appender为异步，结果为异步
  • 同步Logger修饰，其ref的Appender为同步，结果为同步
  • 同步Logger修饰，其ref的Appender为异步，结果为同步

结论得出

  1. Logger与Appender其中一个有async的修饰即为异步
  2. 配置了两条，结果以最后配置的一条Logger为准

再引入 AsyncLoggerContextSelector.isSelected() 方法

说明如下：

Log4j-2.9及更高版本在类路径上需要disruptor-3.3.4.jar或更高版本。在Log4j-2.9之前，需要disruptor-3.0.0.jar或更高版本。
这是最简单的配置，并提供最佳性能。要使所有记录器异步，请将disruptor jar添加到类路径，并将系统属性log4j2.contextSelector设置 为org.apache.logging.log4j.core.async.AsyncLoggerContextSelector。
————————————————
版权声明：本文为CSDN博主「ThinkWon」的原创文章，遵循CC 4.0 BY-SA版权协议，转载请附上原文出处链接及本声明。
原文链接：https://blog.csdn.net/ThinkWon/article/details/101625124

然后在src/java/resources目录添加log4j2.component.properties配置文件，

##异步日志系统属性，全局生效，除了root的还可以单独配为同步，非root的都将为异步#log4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

可以发现，只要配置了该AsyncLoggerContextSelector，除了root日志，系统全局非root的log都会走异步模式，无论标签是否有配置async。

而root标签在此环境变量开启下，仍然可以自由配置root是同步还是异步打印。

<root level="info">
    <!--<AppenderRef ref="AsyncCONSOLE" />-->
    <AppenderRef ref="CONSOLE" />
</root>