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

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

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

关于 Log4j2

作为一个 Java 程序员，肯定离不开日志框架，现在最优秀的 Java 日志框架是 Log4j2，没有之一。根据官方的测试表明，在多线程环境下，Log4j2 的异步日志表现更加优秀。在异步日志中，Log4j2 使用独立的线程去执行 I/O 操作，可以极大地提升应用程序的性能。

在官方的测试中，下图比较了Sync、Async Appenders和Loggers all async三者的性能。其中Loggers all async表现最为出色，而且线程数越多，其性能越好。

Async loggers have much higher throughput than sync loggers.

除了对 Log4j2 自身的不同模式做对比以外，官方还做了 Log4j2/Log4j1/Logback  的对比，如下图所示

Async loggers have the highest throughput.

其中，Loggers all async是基于  LMAX Disruptor  实现的。

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();
    }

}

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

image-20180505203441996

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

通常情况下，用到的日志级别主要是 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>

ThreadLookup 类和依赖的 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

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

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，使用<AsyncRoot>或者<AsyncLogger>去指定需要异步的 loggers，<AsyncLogger>元素还可以包含<Root>和<Logger>用于同步的 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>

参考资料

Different log files for multiple threads using log4j2
log4j2: Location for setting Log4jContextSelector system property for asynchronous logging
Making All Loggers Asynchronous
AsyncAppender
Mixing Synchronous and Asynchronous Loggers
How to verify log4j2 is logging asynchronously via LMAX disruptor?
Log4j2 synchronous logging
Log4J2 sync loggers faster than mixed async/sync loggers
Difference between Asynclogger and AsyncAppender in Log4j2

Technology
#Java #Log4j2
Log4j2 将不同线程不同级别日志输出到不同的文件中
https://www.haoyizebo.com/posts/a29ac0/
作者
一博
发布于
2018年5月6日
许可协议