Spring Boot 应用系列 4 -- Spring Boot 2 整合log4j2

Posted 2021-01-05 光焱

一、背景

1. log4j2传承于log4j和logback，它是目前性能最好的日志处理工具，有关它们的性能对比请看：

2. 除了性能好之外，log4j2有这么几个重要的新features:

(1) 自动热重载配置文件，而且重新加载期间不会丢失日志请求。logback也可以热重载配置文件，但是它在重新加载期间会丢失请求；

(2) 用插件代替code style的自定义appender；

(3) 支持异步日志，至于异步日志的性能，请参考官方评测:

由此可见，log4j2的性能优势就体现在异步日志上，如果使用log4j2而不用其异步日志，那么它的性能跟logback相差不大。

3. 日志级别

我们使用log4j2或者logback时一般会用通用接口slf4j来进行桥接，但是slf4j仅支持trace->error区间的事件。

二、配置

1. pom.xml

由于Spring Boot默认的日志实现是logback、log4j和slf4j，所以需要在引入log4j2的同时排除掉默认的日志实现。

pom.xml的dependencies节点是这样的：

    <dependencies>
        <!-- Spring Boot -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>org.springframework.boot</groupId>
                    <artifactId>spring-boot-starter-logging</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
        <!-- Spring Boot end -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-log4j2</artifactId>
        </dependency>
    </dependencies>

2. 本文我们希望通过配置达到以下效果：

(1) 所有级别的日志均可以通过控制台打印；

(2) 日志的存储目录格式为“/yyyy-MM/dd/”(“年-月/日/”)，日志文件名称包含小时；

(2) error级别的日志存储在“/yyyy-MM/dd/app-error-{HH}.log”中，其中HH是日志发生的小时；

(3) warn级别的日志存储在“/yyyy-MM/dd/app-warn-{HH}.log”中；

(4) 其他级别的日志存储在“/yyyy-MM/dd/app-other-{HH}.log”中；

(5) 所有日志文件按照小时归档，一个小时一套文件(三个具体文件error, warn, other)；

(6) 设置日志文件的size上限，如果某一小时出现的日志特别多，超过size limit之后自动生成带数字后缀的文件。

3. log4j2.xml

log4j2的配置均在log4j2.xml中：

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
    <Properties>
        <Property name="baseDir">logs</Property>
        <Property name="message-pattern">[%d{HH:mm:ss:SSS}] [%t] %-5level %logger{36} - %msg%n</Property>
    </Properties>
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout>
                <Pattern>${message-pattern}</Pattern>
            </PatternLayout>
        </Console>
        <RollingRandomAccessFile name="RollingRandomAccessFile_Other" fileName="${baseDir}/app-other.log" filePattern="${baseDir}/$${date:yyyy-MM}/$${date:dd}/app-other-%d{HH-mm}-%i.log" immediateFlush="false">
            <PatternLayout>
                <Pattern>${message-pattern}</Pattern>
            </PatternLayout>
            <Filters>
                <ThresholdFilter level="FATAL" onMatch="ACCEPT" onMismatch="NEUTRAL" />
                <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL" />
                <ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL" />
                <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="NEUTRAL" />
                <ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="NEUTRAL" />
                <ThresholdFilter level="TRACE" onMatch="ACCEPT" onMismatch="NEUTRAL" />
                <ThresholdFilter level="ALL" onMatch="ACCEPT" onMismatch="NEUTRAL" />
            </Filters>
            <Policies>
                <TimeBasedTriggeringPolicy />
                <SizeBasedTriggeringPolicy size="10 MB" />
            </Policies>
        </RollingRandomAccessFile>
        <RollingRandomAccessFile name="RollingRandomAccessFile_Warn" fileName="${baseDir}/app-warn.log" filePattern="${baseDir}/$${date:yyyy-MM}/$${date:dd}/app-warn-%d{HH-mm}-%i.log" immediateFlush="false">
            <PatternLayout>
                <Pattern>${message-pattern}</Pattern>
            </PatternLayout>
            <Filters>
                <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL" />
                <ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="DENY" />
            </Filters>
            <Policies>
                <TimeBasedTriggeringPolicy />
                <SizeBasedTriggeringPolicy size="10 MB" />
            </Policies>
        </RollingRandomAccessFile>
        <RollingRandomAccessFile name="RollingRandomAccessFile_Error" fileName="${baseDir}/app-error.log" filePattern="${baseDir}/$${date:yyyy-MM}/$${date:dd}/app-error-%d{HH}-%i.log" immediateFlush="false">
            <PatternLayout>
                <Pattern>${message-pattern}</Pattern>
            </PatternLayout>
            <Filters>
                <ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY" />
            </Filters>
            <Policies>
                <TimeBasedTriggeringPolicy />
                <SizeBasedTriggeringPolicy size="10 MB" />
            </Policies>
        </RollingRandomAccessFile>
        <Async name="Async">
            <AppenderRef ref="RollingRandomAccessFile_Warn" />
            <AppenderRef ref="RollingRandomAccessFile_Error" />
            <AppenderRef ref="RollingRandomAccessFile_Other" />
        </Async>
    </Appenders>
    <Loggers>
        <Root level="INFO">
            <AppenderRef ref="Console" />
            <AppenderRef ref="Async" />
        </Root>
        <Logger name="devutility.test.log.log4j2.controller.TestController" level="TRACE" additivity="false">
            <AppenderRef ref="Console" />
        </Logger>
    </Loggers>
</Configuration>

(1) Properties节点的功能类似于pom.xml里的properties节点，相当于一个xml级别的全局变量，可用来统一配置，节省代码；

(2) baseDir这个Property是日志文件的根目录，如果以“/”开头，运行时会在磁盘根目录下创建指定的日志目录；如果开头没有“/”，则会在项目根目录下创建日志目录；将Spring Boot打成jar包后，如果baseDir以“/”开头，运行时会在磁盘根目录下创建指定的日志目录；如果开头没有“/”，则会在jar包相同的目录下创建日志目录；

(3) RollingRandomAccessFile是log4j2提供的一种appender，它用使用java.io.RandomAccessFile类来操作日志文件，详见log4j2官网。

(4) RollingRandomAccessFile的filePattern属性可以理解为“归档”，是日志的最终归属地，必填字段；

(5) RollingRandomAccessFile的fileName属性可选，如果fileName为空或没有该属性则日志直接写到filePattern指定的文件中，如果fileName不为空，则fileName指定的日志文件相当于工作台，日志首先被写到fileName中，等触发条件满足再写到filePattern中归档；

(6) Filters中的ThresholdFilter需要特别注意顺序，如果第一个ThresholdFilter中的onMatch="ACCEPT"，则不管后面的ThresholdFilter怎么配置该ThresholdFilter所配级别之上的级别全部ACCEPT；如果36和37两行对调，则WARN和WARN级别之上的日志全部写到warn日志中，这显然不是我们想要的；

(7) TimeBasedTriggeringPolicy指明写新日志文件的触发机制是根据时间，它取filePattern中配置的最后一个时间单位，本文中RollingRandomAccessFile_Other和RollingRandomAccessFile_Warn最后的时间单位是mm，也就是每分钟写一个日志文件，RollingRandomAccessFile_Error最后的时间单位是HH，也就是每小时写一个日志文件。

(8) immediateFlush这个属性代表是否立即将日志写入文件，默认值是true，常跟异步日志配合使用。但是在实际使用中发现，对于error日志来讲，即便你设置为true，log4j2也会立即将日志立即写入文件，因为error级别的日志等级较高，需要实时查看；

(9) <Loggers>节点下可以有<loger>节点，用来设置某一个包或者具体的某一个类的日志打印级别，它自动继承root节点的level。<loger>节点有三个属性，一个子节点：

a. name属性，必填，指定受此loger约束的包或者类；

b. level属性，选填，指定loger的日志级别，如果不指定则继承父级的level；

c. addtivity属性，默认为true，指定Logger 是否继承父Logger输出源（appender）。

d. 如果<logger>节点包含appender，则该logger使用其所包含的appender打印日志；如果不包含任何appender，且addtivity=true，则该logger使用父级appender输出，否则该logger没有任何输出。

本文中TestController下的trace级别以上的日志均通过控制台输出，其他类中INFO级别以上的日志通过控制台+文件的方式输出。

(10) Async节点中包含了所有需要异步写日志的appender，此外还可以使用asyncRoot来代替Root节点，让所有日志均已异步方式实现。

三、应用

package devutility.test.log.log4j2.controller;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
@RequestMapping("/test")
public class TestController {
    Logger logger = LoggerFactory.getLogger(TestController.class);

    @RequestMapping("/all")
    public String all(String message) {
        logger.trace(message);
        logger.debug(message);
        logger.info(message);
        logger.warn(message);
        logger.error(message);
        return message;
    }
}

LoggerFactory是slf4j提供的一个工厂类，slf4j定义了访问日志的一种规范，包括trace->error等五种日志级别，使用它你就可以无需关心日志的底层实现，无论你是使用logback还是log4j或者是log4j2，它都可以支持。

Demo代码