BXW

博哥的blog

博哥的技术博客

0%

SpringBoot-log4j2将不同线程不同级别日志输出到不同的文件中

发表于 分类于 ，

SpringBoot-log4j2将不同线程不同级别日志输出到不同的文件中

在多线程编程中，如果不做特殊的设置，那么多个线程的日志会输出到同一个日志文件中，这样在查阅日志的时候，会带来诸多不便。很自然地，我们想到了让不同的线程输出日志到不同的文件中，这样不是更好吗？

本篇文章我们利用 Log4j2 来将不同线程的不同级别的日志打印到不同的文件中，并使用异步的方式来大大的提高日志输出的性能

Log4j2 的使用
相关依赖

使用 Log4j2 最少需要两个 JAR，分别是log4j-api-2.x和log4j-core-2.x，其它 JAR 包根据应用程序需要添加。

1
2
3
4
5
6
7
8
9
10
11
12
<dependencies>
  <dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>2.11.0</version>
  </dependency>
  <dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.11.0</version>
  </dependency>
</dependencies>
配置文件

默认的，Log4j2 会在 classpath 下寻找名为log4j2.xml的配置文件（具体顺序可以参加 Automatic Configuration）。
也可以使用系统属性指定配置文件的全路径-Dlog4j.configurationFile=path/to/log4j2.xml，在 Java 代码中指定路径如下所示

1
2
3
4
5
6
7
8
9
10
11
12
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.LoggerContext;

import java.io.File;

public class Demo {
    public static void main(String[] args) {
        LoggerContext loggerContext = (LoggerContext) LogManager.getContext(false);
        File file = new File("path/to/log4j2.xml");
        loggerContext.setConfigLocation(file.toURI());
    }
}

一般的，不需要手动关闭 Log4j2，如果想手动在代码中关闭 Log4j2 如下所示

1
2
3
4
5
6
7
8
9
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.core.config.Configurator;

public class Demo {
    public static void main(String[] args) {
        Configurator.shutdown((LoggerContext) LogManager.getContext());
    }
}
不同的线程输出日志到不同的文件中

不同的线程输出日志到不同的文件中有关 Log4j2 的内容很多，在此不一一列出，这里只介绍两种方法。如果在开发中遇到任何问题，推荐去官方文档中寻找解决方案。

方法一：使用 ThreadContext

在多线程编程中，如果不做特殊的设置，那么多个线程的日志会输出到同一个日志文件中，这样在查阅日志的时候，会带来诸多不便。很自然地，我们想到了让不同的线程输出日志到不同的文件中，这样不是更好吗？

在翻阅官方文档过程中，找到了 FAQ（Frequently Asked Questions），其中有个问题 How do I dynamically write to separate log files? 正是我们所需要的。根据提示步步推进即可顺利解决该问题。其中 log4j2.xml 配置如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="OFF">
    <Appenders>
        <Routing name="Routing">
            <Routes pattern="$${ctx:ROUTINGKEY}">
                <!-- This route is chosen if ThreadContext has value 'special' for key ROUTINGKEY. -->
                <Route key="special">
                    <RollingFile name="Rolling-${ctx:ROUTINGKEY}" fileName="logs/special-${ctx:ROUTINGKEY}.log"
                                 filePattern="./logs/${date:yyyy-MM}/${ctx:ROUTINGKEY}-special-%d{yyyy-MM-dd}-%i.log.gz">
                        <PatternLayout>
                            <Pattern>%d{ISO8601} [%t] %p %c{3} - %m%n</Pattern>
                        </PatternLayout>
                        <Policies>
                            <TimeBasedTriggeringPolicy interval="6" modulate="true"/>
                            <SizeBasedTriggeringPolicy size="10 MB"/>
                        </Policies>
                    </RollingFile>
                </Route>
                <!-- This route is chosen if ThreadContext has no value for key ROUTINGKEY. -->
                <Route key="$${ctx:ROUTINGKEY}">
                    <RollingFile name="Rolling-default" fileName="logs/default.log"
                                 filePattern="./logs/${date:yyyy-MM}/default-%d{yyyy-MM-dd}-%i.log.gz">
                        <PatternLayout>
                            <pattern>%d{ISO8601} [%t] %p %c{3} - %m%n</pattern>
                        </PatternLayout>
                        <Policies>
                            <TimeBasedTriggeringPolicy interval="6" modulate="true"/>
                            <SizeBasedTriggeringPolicy size="10 MB"/>
                        </Policies>
                    </RollingFile>
                </Route>
                <!-- This route is chosen if ThreadContext has a value for ROUTINGKEY
                     (other than the value 'special' which had its own route above).
                     The value dynamically determines the name of the log file. -->
                <Route>
                    <RollingFile name="Rolling-${ctx:ROUTINGKEY}" fileName="logs/other-${ctx:ROUTINGKEY}.log"
                                 filePattern="./logs/${date:yyyy-MM}/${ctx:ROUTINGKEY}-other-%d{yyyy-MM-dd}-%i.log.gz">
                        <PatternLayout>
                            <pattern>%d{ISO8601} [%t] %p %c{3} - %m%n</pattern>
                        </PatternLayout>
                        <Policies>
                            <TimeBasedTriggeringPolicy interval="6" modulate="true"/>
                            <SizeBasedTriggeringPolicy size="10 MB"/>
                        </Policies>
                    </RollingFile>
                </Route>
            </Routes>
        </Routing>
        <!-- 很直白，Console 指定了结果输出到控制台 -->
        <Console name="ConsolePrint" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss z} %t %-5level %class{36} %L %M - %msg%xEx%n"/>
        </Console>
    </Appenders>
    <Loggers>
        <!-- 级别顺序（低到高）：TRACE < DEBUG < INFO < WARN < ERROR < FATAL -->
        <Root level="DEBUG" includeLocation="true">
            <!-- AppenderRef 中的 ref 值必须是在前面定义的 appender -->
            <AppenderRef ref="Routing"/>
            <AppenderRef ref="ConsolePrint"/>
        </Root>
    </Loggers>
</Configuration>

测试类如下

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.ThreadContext;

public class TestLog {

    private static final Logger logger = LogManager.getLogger(TestLog.class);

    public static void main(String[] args) {
        new Thread(() -> {
            ThreadContext.put("ROUTINGKEY", Thread.currentThread().getName());
            logger.info("info");
            logger.debug("debug");
            logger.error("error");
            ThreadContext.remove("ROUTINGKEY");
        }).start();
        new Thread(() -> {
            ThreadContext.put("ROUTINGKEY", Thread.currentThread().getName());
            logger.info("info");
            logger.debug("debug");
            logger.error("error");
            ThreadContext.remove("ROUTINGKEY");
        }).start();
    }

}

运行测试类，会得到如下两个日志文件，other-Thread-1.log和other-Thread-2.log，每个日志文件对应着一个线程。

需要注意的一点是，每次在使用 logger 对象之前，需要先设置

1
ThreadContext.put("ROUTINGKEY", Thread.currentThread().getName());

设置的 key 和log4j2.xml配置文件中的 key 要一致，而 value 可以是任意值，参考配置文件即可理解。

有没有发现，每次使用 logger 对象，还需要添加额外的代码，这不是恶心他妈给恶心开门——恶心到家了吗？有没有更加优雅地解决办法呢？且看下节。

方法二：实现 StrLookup
修改log4j2.xml配置文件如下

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="OFF">
    <Appenders>
        <Routing name="Routing">
            <Routes pattern="$${thread:threadName}">
                <Route>
                    <RollingFile name="logFile-${thread:threadName}"
                                 fileName="logs/concurrent-${thread:threadName}.log"
                                 filePattern="logs/concurrent-${thread:threadName}-%d{MM-dd-yyyy}-%i.log">
                        <PatternLayout pattern="%d %-5p [%t] %C{2} - %m%n"/>
                        <Policies>
                            <SizeBasedTriggeringPolicy size="50 MB"/>
                        </Policies>
                        <DefaultRolloverStrategy max="100"/>
                    </RollingFile>
                </Route>
            </Routes>
        </Routing>
        <Async name="async" bufferSize="1000" includeLocation="true">
            <AppenderRef ref="Routing"/>
        </Async>
        <!-- 很直白，Console 指定了结果输出到控制台 -->
        <Console name="ConsolePrint" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss z} %t %-5level %class{36} %L %M - %msg%xEx%n"/>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="info" includeLocation="true">
            <AppenderRef ref="async"/>
            <AppenderRef ref="ConsolePrint"/>
        </Root>
    </Loggers>
</Configuration>

实现 StrLookup 中的 lookup 方法，代码如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.lookup.StrLookup;

@Plugin(name = "thread", category = StrLookup.CATEGORY)
public class ThreadLookup implements StrLookup {

    @Override
    public String lookup(String s) {
        return Thread.currentThread().getName();
    }

    @Override
    public String lookup(LogEvent logEvent, String s) {
        return logEvent.getThreadName() == null ? Thread.currentThread().getName()
                : logEvent.getThreadName();
    }
}

编写测试类，代码如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class TestLog2 {

    private static final Logger logger = LogManager.getLogger(TestLog2.class);

    public static void main(String[] args) {
        new Thread(() -> {
            logger.info("info");
            logger.debug("debug");
            logger.error("error");
        }).start();
        new Thread(() -> {
            logger.info("info");
            logger.debug("debug");
            logger.error("error");
        }).start();
    }

}

该测试类同样会得到两个日志文件，每个线程分别对应一个，是不是比方法一清爽多了。

不同级别的日志输出到不同的文件中

通常情况下，用到的日志级别主要是 info/debug/error 三个，而如果不做特殊配置，这三者信息是写到一个日志文件中的，当我们需要不同级别的日志输出到不同的文件中时，需要如何做呢？

log4j2.xml配置信息如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="OFF">
    <Properties>
        <Property name="logFilePath">logs</Property>
        <Property name="logFileName">testLog</Property>
    </Properties>
    <Appenders>
        <!-- 很直白，Console 指定了结果输出到控制台 -->
        <Console name="ConsolePrint" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss z} %t %-5level %class{36} %L %M - %msg%xEx%n"/>
        </Console>
        <!-- <File>输出结果到指定文件</File> -->
        <!-- <RollingFile>同样输出结果到指定文件，但是使用 buffer，速度会快点</RollingFile> -->
        <!-- filePattern：表示当日志到达指定的大小或者时间，产生新日志时，旧日志的命名路径 -->
        <!-- PatternLayout：和 log4j 一样，指定输出日志的格式，append 表示是否追加内容，值默认为 true -->
        <RollingFile name="RollingFileDebug" fileName="${logFilePath}/${logFileName}-debug.log"
                     filePattern="${logFilePath}/$${date:yyyy-MM}/${logFileName}-%d{yyyy-MM-dd}_%i.log.gz">
            <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>
            <!-- 注意，如果有多个 ThresholdFilter，那么 Filters 标签是必须的 -->
            <Filters>
                <!-- 首先需要过滤不符合的日志级别，把不需要的首先 DENY 掉，然后在 ACCEPT 需要的日志级别，次序不能颠倒 -->
                <!-- INFO 及以上级别拒绝输出 -->
                <ThresholdFilter level="INFO" onMatch="DENY" onMismatch="NEUTRAL"/>
                <!-- 只输出 DEBUG 级别信息 -->
                <ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="DENY"/>
            </Filters>
            <Policies>
                <!-- 时间策略，每隔 24h 产生新的日志文件 -->
                <TimeBasedTriggeringPolicy/>
                <!-- 大小策略，每到 30MB 时产生新的日志文件 -->
                <SizeBasedTriggeringPolicy size="30MB"/>
            </Policies>
        </RollingFile>

        <RollingFile name="RollingFileInfo" fileName="${logFilePath}/${logFileName}-info.log"
                     filePattern="${logFilePath}/$${date:yyyy-MM}/${logFileName}-%d{yyyy-MM-dd}_%i.log.gz">
            <Filters>
                <!-- onMatch:Action to take when the filter matches. The default value is NEUTRAL -->
                <!-- onMismatch:    Action to take when the filter does not match. The default value is DENY -->
                <!-- 级别在 ERROR 之上的都拒绝输出 -->
                <!-- 在组合过滤器中，接受使用 NEUTRAL（中立），被第一个过滤器接受的日志信息，会继续用后面的过滤器进行过滤，只有符合所有过滤器条件的日志信息，才会被最终写入日志文件 -->
                <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL"/>
                <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
            </Filters>
            <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="30MB"/>
            </Policies>
        </RollingFile>

        <RollingFile name="RollingFileError" fileName="${logFilePath}/${logFileName}-error.log"
                     filePattern="${logFilePath}/$${date:yyyy-MM}/${logFileName}-%d{yyyy-MM-dd}_%i.log.gz">
            <Filters>
                <ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY"/>
            </Filters>
            <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="30MB"/>
            </Policies>
        </RollingFile>
    </Appenders>
    <Loggers>
        <!-- logger 用于定义 log 的 level 以及所采用的 appender，如果无需自定义，可以使用 root 解决，root 标签是 log 的默认输出形式 -->
        <!-- 级别顺序（低到高）：TRACE < DEBUG < INFO < WARN < ERROR < FATAL -->
        <Root level="DEBUG" includeLocation="true">
            <!-- 只要是级别比 ERROR 高的，包括 ERROR 就输出到控制台 -->
            <!-- appender-ref 中的值必须是在前面定义的 appender -->
            <Appender-ref level="ERROR" ref="ConsolePrint"/>
            <Appender-ref ref="RollingFileDebug"/>
            <Appender-ref ref="RollingFileInfo"/>
            <Appender-ref ref="RollingFileError"/>
        </Root>
    </Loggers>
</Configuration>

测试代码如下

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class TestLog3 {

    private static final Logger logger = LogManager.getLogger(TestLog3.class);

    public static void main(String[] args) {
        new Thread(() -> {
            logger.info("info");
            logger.debug("debug");
            logger.error("error");
        }).start();
        new Thread(() -> {
            logger.info("info");
            logger.debug("debug");
            logger.error("error");
        }).start();
    }

}

该程序会生成三份日志文件 testLog-debug.log、testLog-error.log 和 testLog-info.log，如果你足够细心的话，就会发现线程 1 和线程 2 的 info|debug|error 信息都输出到一个 info|debug|error 日志文件中了。

如何解决这个问题呢？换句话说，我想得到

1
2
3
4
5
6
Thread 1 的 info 日志
Thread 1 的 debug 日志
Thread 1 的 error 日志
Thread 2 的 info 日志
Thread 2 的 debug 日志
Thread 2 的 error 日志
不同线程不同级别的日志输出到不同的文件中

要实现该功能，还要从 RoutingAppender 身上做文章。RoutingAppender 主要用来评估 LogEvents，然后将它们路由到下级 Appender。目标 Appender 可以是先前配置的并且可以由其名称引用的 Appender，或者可以根据需要动态地创建 Appender。RoutingAppender 应该在其引用的任何 Appenders 之后配置，以确保它可以正确关闭。

RoutingAppender 中的 name 属性用来指定该 Appender 的名字，它可以包含多个 Routes 子节点，用来标识选择 Appender 的条件，而 Routes 只有一个属性 “pattern”，该 pattern 用来评估所有注册的 Lookups，并且其结果用于选择路由。在 Routes 下可以有多个 Route，每个 Route 都必须配置一个 key，如果这个 key 匹配 “pattern” 的评估结果，那么这个 Route 就被选中。同时每个 Route 都必须引用一个 Appender，如果这个 Route 包含一个 ref 属性，那么这个 Route 将引用一个在配置中定义的 Appender，如果这个 Route 包含一个 Appender 的定义，那么这个 Appender 将会根据 RoutingAppender 的上下文创建并被重用。

废话说多了，直接上配置才简洁明了。log4j2.xml 配置如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
<?xml version="1.0" encoding="UTF-8"?>
<!-- status 的含义为是否记录 log4j2 本身的 event 信息，默认是 OFF -->
<Configuration status="OFF">
    <Properties>
        <!-- 自定义一些常量，之后使用${变量名}引用 -->
        <Property name="logFilePath">logs</Property>
        <Property name="logFileName">testLog</Property>
    </Properties>
    <Appenders>
        <!-- 很直白，Console 指定了结果输出到控制台 -->
        <Console name="ConsolePrint" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss z} %t %-5level %class{36} %L %M - %msg%xEx%n"/>
        </Console>
        <!-- <File>输出结果到指定文件</File> -->
        <!-- <RollingFile>同样输出结果到指定文件，但是使用 buffer，速度会快点</RollingFile> -->
        <!-- filePattern：表示当日志到达指定的大小或者时间，产生新日志时，旧日志的命名路径 -->
        <!-- PatternLayout：和 log4j 一样，指定输出日志的格式，append 表示是否追加内容，值默认为 true -->
        <Routing name="RollingFileDebug_${thread:threadName}">
            <Routes pattern="$${thread:threadName}">
                <Route>
                    <RollingFile name="RollingFileDebug_${thread:threadName}"
                                 fileName="${logFilePath}/${logFileName}_${thread:threadName}_debug.log"
                                 filePattern="${logFilePath}/$${date:yyyy-MM}/${logFileName}-%d{yyyy-MM-dd}-${thread:threadName}-debug_%i.log.gz">
                        <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>
                        <!-- 注意，如果有多个 ThresholdFilter，那么 Filters 标签是必须的 -->
                        <Filters>
                            <!-- 首先需要过滤不符合的日志级别，把不需要的首先 DENY 掉，然后在 ACCEPT 需要的日志级别，次序不能颠倒 -->
                            <!-- INFO 及以上级别拒绝输出 -->
                            <ThresholdFilter level="INFO" onMatch="DENY" onMismatch="NEUTRAL"/>
                            <!-- 只输出 DEBUG 级别信息 -->
                            <ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="DENY"/>
                        </Filters>
                        <Policies>
                            <!-- 时间策略，每隔 24h 产生新的日志文件 -->
                            <TimeBasedTriggeringPolicy/>
                            <!-- 大小策略，每到 30MB 时产生新的日志文件 -->
                            <SizeBasedTriggeringPolicy size="30MB"/>
                        </Policies>
                    </RollingFile>
                </Route>
            </Routes>
        </Routing>

        <Routing name="RollingFileInfo_${thread:threadName}">
            <Routes pattern="$${thread:threadName}">
                <Route>
                    <RollingFile name="RollingFileInfo_${thread:threadName}"
                                 fileName="${logFilePath}/${logFileName}_${thread:threadName}_info.log"
                                 filePattern="${logFilePath}/$${date:yyyy-MM}/${logFileName}-%d{yyyy-MM-dd}-${thread:threadName}-info_%i.log.gz">
                        <Filters>
                            <!-- onMatch:Action to take when the filter matches. The default value is NEUTRAL -->
                            <!-- onMismatch:    Action to take when the filter does not match. The default value is DENY -->
                            <!-- 级别在 ERROR 之上的都拒绝输出 -->
                            <!-- 在组合过滤器中，接受使用 NEUTRAL（中立），被第一个过滤器接受的日志信息，会继续用后面的过滤器进行过滤，只有符合所有过滤器条件的日志信息，才会被最终写入日志文件 -->
                            <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL"/>
                            <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
                        </Filters>
                        <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>
                        <Policies>
                            <TimeBasedTriggeringPolicy/>
                            <SizeBasedTriggeringPolicy size="30MB"/>
                        </Policies>
                    </RollingFile>
                </Route>
            </Routes>
        </Routing>

        <Routing name="RollingFileError_${thread:threadName}">
            <Routes pattern="$${thread:threadName}">
                <Route>
                    <RollingFile name="RollingFileError_${thread:threadName}"
                                 fileName="${logFilePath}/${logFileName}_${thread:threadName}_error.log"
                                 filePattern="${logFilePath}/$${date:yyyy-MM}/${logFileName}-%d{yyyy-MM-dd}-${thread:threadName}-error_%i.log.gz">
                        <Filters>
                            <ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY"/>
                        </Filters>
                        <PatternLayout pattern="%d{yyyy.MM.dd HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>
                        <Policies>
                            <TimeBasedTriggeringPolicy/>
                            <SizeBasedTriggeringPolicy size="30MB"/>
                        </Policies>
                    </RollingFile>
                </Route>
            </Routes>
        </Routing>
        <!-- bufferSize 整数，指定可以排队的 events 最大数量，如果使用 BlockingQueue，这个数字必须是 2 的幂次-->
        <!-- includeLocation 默认值是 FALSE，如果指定为 TRUE，会降低性能，但是推荐设置为 TRUE，否则不打印位置行信息-->
        <Async name="async" bufferSize="262144" includeLocation="true">
            <AppenderRef ref="RollingFileDebug_${thread:threadName}"/>
            <AppenderRef ref="RollingFileInfo_${thread:threadName}"/>
            <AppenderRef ref="RollingFileError_${thread:threadName}"/>
            <!-- 只要是级别比 ERROR 高的，包括 ERROR 就输出到控制台 -->
            <AppenderRef ref="ConsolePrint" level="ERROR"/>
        </Async>
    </Appenders>
    <Loggers>
        <!-- logger 用于定义 log 的 level 以及所采用的 appender，如果无需自定义，可以使用 root 解决，root 标签是 log 的默认输出形式 -->
        <!-- 级别顺序（低到高）：TRACE < DEBUG < INFO < WARN < ERROR < FATAL -->
        <Root level="DEBUG" includeLocation="true">
            <!-- appender-ref 中的值必须是在前面定义的 appender -->
            <AppenderRef ref="async"/>
        </Root>
    </Loggers>
</Configuration>

hreadLookup 类和依赖的 JAR 包均不变，测试类也和上节的一模一样，启动测试类，该程序会输出六个日志文件，分别是

1
2
3
4
5
6
testLog_Thread-0_debug.log
testLog_Thread-0_error.log
testLog_Thread-0_info.log
testLog_Thread-1_debug.log
testLog_Thread-1_error.log
testLog_Thread-1_info.log

至此，就实现了不同线程不同级别的日志输出到不同文件中的功能。

启用 All Loggers Asynchronous

根据官方的性能测试我们知道，Loggers all async的性能最高，但是我们在上边使用的是Sync模式（方法一，因为 Appender 默认是 synchronous 的）或Async Appender模式（方法二），那么如何更进一步让所有的 Loggers 都是 Asynchronous 的，让我们的配置更完美呢？想要使用Loggers all async只需要做两步操作。

因为Loggers all async是基于 LMAX Disruptor 实现的，所以我们首先需要添加这个依赖

1
2
3
4
5
<dependency> 
    <groupId>com.lmax</groupId>
    <artifactId>disruptor</artifactId>
    <version>3.4.2</version>
</dependency>

其次是设置系统属性

1
log4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

方式有以下几种

  • 如果是使用 IntelliJ IDEA，可以配置 Run/Debug Configurations 里边的 VM options
  • 可以在前面提到的 ThreadLookup 类中，添加静态代码块
    1
    2
    3
    static {
        System.setProperty("log4j2.contextSelector", "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector");
    }
    在src/main/resources目录下添加 log4j2.component.properties 配置文件，其内容为
    1
    log4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
    那配置好了，有没有方法可以证明我们确实使用了Loggers all async呢？

有。默认的 location 不会传递给Loggers all async的 I/O 线程，所以如果不设置includeLocation=true的话，打印出来的日志中 location 信息是 “?”。

我们可以先不设置includeLocation=true（注意是默认配置，不要人为设置为false），运行程序打印出

1
2
2018.05.05 22:08:46 CST Thread-0 ERROR com.yibo.TestLog3 17 lambda$main$0 - error
2018.05.05 22:08:46 CST Thread-1 ERROR com.yibo.TestLog3 22 lambda$main$1 - error

然后设置includeLocation=true，再次运行程序 location 变为 ? 就证明使用了Loggers all async

1
2
2018.05.05 22:09:51 CST Thread-1 ERROR ?   - error
2018.05.05 22:09:51 CST Thread-0 ERROR ?   - error

另外有一点需要注意的就是，要使用或标签，而不是<asyncRoot>和<asyncLogger>

1
2
When AsyncLoggerContextSelector is used to make all loggers asynchronous, make sure to use normal <root> and <logger> elements in the configuration. The AsyncLoggerContextSelector will ensure that all loggers are asynchronous, using a mechanism that is different from what happens when you configure <asyncRoot> or <asyncLogger>. The latter elements are intended for mixing async with sync loggers. If you use both mechanisms together you will end up with two background threads, where your application passes the log message to thread A, which passes the message to thread B, which then finally logs the message to disk. This works, but there will be an unnecessary step in the middle.
Making All Loggers Asynchronous
混合使用 Synchronous 和 Asynchronous Loggers

依旧需要依赖com.lmax:disruptor，但不需要设置系统属性log4j2.contextSelector，在配置中可以混合使用同步和异步的 loggers，使用或者去指定需要异步的 loggers，元素还可以包含和用于同步的 loggers。

一个混合了同步和异步的 Loggers 配置如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
<?xml version="1.0" encoding="UTF-8"?>
<!-- No need to set system property "Log4jContextSelector" to any value
     when using <asyncLogger> or <asyncRoot>. -->
<Configuration status="WARN">
  <Appenders>
    <!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
    <RandomAccessFile name="RandomAccessFile" fileName="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>