Java日志框架全解

我们在写代码过程中，天天都在打印日志，一会儿是Slf4j、Log4j，一会儿又是Log4j2、Logback等等，各种花里胡哨的日志依赖，你们有没有一脸懵逼？今天就带着大家从零开始了解这些日志，主要包括以下几项内容：

• 日志框架简介

• Slf4j源码解析

• Logback源码解析

• SpringBoot整合Logback源码解析

• Logback扩展

1.日志框架简介

要想了解这些日志，我们还是要先了解这些日志的历史，才能明白它们存在的意义。

1.1.日志框架历史

• Log4j

1996年早期，由Ceki带领的欧洲安全电子市场项目组决定编写一套自己的程序跟踪API（Tracing API），经过不断完善称为一个广受欢迎的Java日志软件包，即**Log4j**。后来Log4j成为Apache基金会项目的一员，近乎成为Java社区的日志标准；

• JUL

2002年管理Java标准库的Sun公司不甘寂寞，他们也想推出一套自己的日志库。在发布的Java1.4中推出日志库**JUL(Java Util Logging)**，其实就是抄了Log4j的实现；

• JCL

随后Apache推出JCL(Jakarta Commons Logging)，只是定义了一套日志接口，支持运行时动态加载日志组件的实现；

• Slf4j & Logback

2006年Ceki离开Apache，自己独创了**Slf4j**，这也是一套类似于JUL的日志门面，不止于此，他又独创了Logback，这是一个Slf4j的实现项目；

• Log4j2

2012年Apache眼看着势头要被Logback超越，然后重写Log4j 1.x，成立了新项目**Log4j2**，吸收了Logback的优秀设计，同时修复了Logback的一些设计上的缺陷。

1.2.日志框架分类

我们根据日志的功能以及源码的结构，可以把日志分为两类：记录型日志框架和门面型日志框架。

日志门面框架

• JCL：Apcache 基金会管理项目，是一套 Java 日志接口，之前叫 Jakarta Commons Logging，后更名为 Commons Logging；
• Slf4j(Simple Logging Facade for Java)：一套建议的 Java 日志门面，本身并无日志实现

日志实现框架

• Jul(Java Util Logging)：JDK 自带的官方日志记录工具，也常被称为 JDKLog、jdk-logging；

• Log4j：Apache 软件基金会管理的基于 Java 的日志记录工具；

• Log4j2：Log4j 的下一个版本，变化较大，不兼容 Log4j；

• **Logback：和 Slf4j 是同一个作者，性能更好（推荐使用）。**

1.3.Slf4j架构

Slf4j 设计思想简洁，使用了Facade设计模式，只提供了一个slf4j-api-version.jar包，这个 jar 主要是日志抽象接口，本身并没有对抽象出来的接口做实现；

对于不同的日志实现框架（如 Logback，Log4j 等），封装出不同的桥接组件（如logback-classic-version.jar，slf4j-log4j12-version.jar等），这样使用过程中可以灵活选取自己项目里的日志实现。 整体关系图如下：

可以看到，logback、slf4j-simple和slf4j-nop都直接实现了slf4j接口，所以我们在使用时直接引入对应的jar包即可；而log4j和jul没有实现slf4j接口，所以要想符合slf4j接口规范，则需要使用桥接器实现；还有图中没有展示的log4j2也没有实现slf4j接口，所以也需要桥接器log4j-slf4j-impl。

在做业务开发时如果你选择的日志框架是log4j2或log2j等没有实现slf4j接口的日志框架，最好选择使用桥接器，主要优点是便于迁移（后面会讲到）。

1.4.Logback日志框架使用

以下案例先以Slf4j + Logback为例进行分析。首先进行如下配置：

1. pom配置

< !-- slf4j-api 依赖 -->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.25</version>
    <scope>compile</scope>
</dependency>

< !-- logback 依赖 -->
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.2.10</version>
</dependency>
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-core</artifactId>
    <version>1.2.10</version>
</dependency>

1. main函数LogbackApplication.class：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class LogbackApplication {
    private static final Logger logger = LoggerFactory.getLogger(LogbackApplication.class);

    public static void main(String[] args)  {
        logger.info("hello world");
    }
}

1. 添加一个logback.xml的配置文件：

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <!-- 文件输出格式 -->
    <!-- 1格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg（或 %m / %message）：日志消息，%n是换行符-->
    <property name="FILE_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50}:  %m%n"/>
    <!-- 日志最大保存数量 -->
    <property name="MAX_HISTORY" value="10"/>
    <!-- 日志文件大小 -->
    <property name="FILE_SIZE" value="10MB"/>
    <!-- 所有日志文件总大小 -->
    <property name="TOTAL_SIZE_CAP" value="10G"/>
    <!-- 日志文件存放路径 -->
    <!--<property name="FILE_PATH" value="/Users/imangozhang/logs/log_file/"/> -->
    <!-- audit文件，记录info级别日志 -->
    <appender name="INFO-OUT" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 实时输出的日志文件 -->
        <file>/Users/imangozhang/logs/info.log</file>
        <append>true</append>
        <!-- 历史日志分块，配置滚动的策略  - 这个更适用于生产 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>./packer_log/error.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <maxFileSize>${FILE_SIZE}</maxFileSize>
            <totalSizeCap>${TOTAL_SIZE_CAP}</totalSizeCap>
            <maxHistory>${MAX_HISTORY}</maxHistory>
        </rollingPolicy>

        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>${FILE_PATTERN}</pattern>
        </encoder>
        <!-- 过滤掉非info的日志,即此日志文件中只会输出info日志 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>INFO</level>
            <onMatch>ACCEPT</onMatch>
            <onMissmatch>DENY</onMissmatch>
        </filter>
    </appender>

    <!-- 控制台输出 -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>${FILE_PATTERN}</pattern>
        </encoder>
    </appender>

    <!-- 相当于logger元素，只是name值已经确定为root了，level 默认为 DEBUG -->
    <root level="INFO">
        <appender-ref ref="STDOUT" />
        <appender-ref ref="INFO-OUT" />
    </root>

</configuration>

2.Slf4j源码解析

我们的应用代码中直接调用的是Slf4j的接口，这就是所谓的日志门面，在运行时才会去动态绑定日志实现框架Logback。我们本章就来分析日志门面框架Slf4j的源码。

2.1.slf4j入口

我们的程序入口是slf4j的LoggerFactory.getLogger(LogbackApplication.class)方法：

通过getILoggerFactory可以看到，返回的ILoggerFactory是一个单例类，如果没有初始化过，进行初始化：

IloggerFactory初始化的核心就是bind()方法：

初始化的核心是绑定，主要可以分为 4 步：

（1）获取实现了slf4j绑定接口的对象实例org.slf4j.imp.StaticLoggerBinder

（2）记录获找到的绑定对象实例

（3）调用logback绑定对象org.slf4j.imp.StaticLoggerBinder的init()方法，将slf4j与logback的Logger进行绑定

（4）记录实际绑定的对象和事件等

2.2.StaticLoggerBinder

slf4j具体是如何找到绑定接口实现类org.slf4j.imp.StaticLoggerBinder的呢？通过ClassLoader的getResources*()方法去挨个遍历所有的实现类，找到实现了STATIC_LOGGER_BINDER_PATH接口的类：

此时我们可以去logback-class-1.2.10.jar去确认一下是否有该实现：

如果获取到有实现了 slf4j 接口的日志框架，需要记录下来：

2.3.Logback绑定接口实现

接下来我们看一下logback是如何完成与slf4j的绑定的。StaticLoggerBinder.getSingleton()是logback绑定的核心工作，它负责解析logback.xml的配置信息，然后初始化到LoggerContext对象当中。

由于现在还没有进行初始化，所以先进行单例初始化：

初始化调用init() 方法：

init() 方法的核心逻辑就是解析logback.xml文件的解析到LoggerContext，然后与slf4j：

将logback.xml解析到LoggerContext用到了joran框架，后面分析logback源码时详细分析。

到此为止我们就获得了对接口ILoggerFactory实现后的对象LoggerContext：

LoggerContext中的Logger对象即为我们slf4j入口函数getLogger需要的返回参数：

logback的Logger对象也完全实现类slf4j的Logger接口，这是能够完成绑定的关键所在：

2.4.总结

1. 业务侧调用slf4j的getLogger方法获取Logger接口的实现类；
2. slf4j找到并调用logback的绑定接口实现类；
3. logback通过joran 框架解析并处理logback.xml配置文件，初始化到slf4j.Logger的实现类logback.classic.Logger对象中返回；
4. 业务侧获取的Logger接口，其实绑定的是logback的Logger对象。

3.Logback源码解析

上面我们分析了slf4j的源码入口，以及logback如何与slf4j进行绑定，但是关于logback的处理细节还没看到。本节来分析logback的源码细节。

3.1.初识joran

上面已经提到，logback实现了slf4j的绑定接口StaticLoggerBinder，这是logback日志框架初始化的入口：

autoConfig完成了对logback.xml的所有初始化配置，我们看下它都干了什么：

可以看到主要分为 2 步：

1. findURLOfDefaultConfigurationFile获取配置文件路径
2. configureByResource配置

获取文件路径的优先级分为：

logback.configurationFile --> logback-test.xml --> logback.xml

3.1.1.joran入口

配置的最终结果是生成一个JoranConfigurator对象，然后将loggerContext即日志上下文记录到该对象当中：

我们可以看到JoranConfigurator位于ch.qos.logback.classic.joran包中，joran是logback专门设计用来处理配置的框架，具体如何运作的？我们一路追踪到buildInterpreter()：

到这里为止，joran执行流程被分成了 3 步：

• SaxParser将logback.xml中的标签解析为SaxEvent事件列表；
• buildInterpreter构造事件解析器；
• play运行事件绑定的方法。

大胆猜想，第一步必然是给interperter这个字段进行赋值，然后第二步play就是依靠配置好的interperter来处理事件列表eventList。

3.1.2.joran之SaxEvent

joran框架运行的第一步就是利用SaxParser将logback.xml中的标签解析为SaxEvent事件列表。SaxParser是JDK提供的解析XML文件的工具类，是一种基于流的解析方式，边读取XML边解析，并以事件回调的方式让调用者获取数据：

这里的入参inputSource就是将logback.xml的内容转换成了字节流，parse方法我们简单理解，就是读取到不同的标签，回执行对应的事件回调，通过事件回调将标签转换为logback的SaxEvent。

3.1.3.joran之buildInterpreter

到了这里，别头大，代码真的很简单，你只要跟进去，就会发现这些内容很熟悉！

首先是addInstanceRules，这是一个抽象方法，我们刚刚不是看过JoranConfigurator嘛，它实现了这个方法:

怎么样，熟悉吗？这不就是我们在logback.xml里用到的一些标签嘛！看类名，**Rules、**Action、ElementSelector，所以addInstanceRules的作用就是将logback.xml的不同标签匹配路径和对应的动作进行绑定，然后保存到RuleStore中，这就是模式匹配！

我们顺便看一眼这些**Action的类，你会发现它们其实都继承了Action这个类：

**所有继承了Action的类都要实现begin和end方法，这很重要！**然后还在implicitActions中增加了处理其它标签的模式匹配规则NestedComplexPropertyIA和NestedBasicPropertyIA：

我们上面的addInstanceRules方法里，其实是没有添加类似<encode>和<file>等等这些标签的匹配规则，这是因为这些标签都属于嵌套标签，它们都与NestedComplexPropertyIA或NestedBasicPropertyIA进行绑定。

3.1.4.joran之play

我们现在代码追踪到了EventPlayer.play：

play的主要逻辑很直观：遍历事件列表List<SaxEvent>，处理每一个事件，事件包括 3 种类型：StartEvent、BodyEvent和EndEvent。我们先来看一下这个List<SaxEvent>都有什么内容（一共有 61 个元素，我只截取了一部分）：

就是我们配置文件中定义的各个标签，而且我们发现了 2 个规律：

1. 标签和事件的映射关系如下：<pattern>-->StartEvent、context-->BodyEvent、</pattern>-->EndEvent；
2. 标签的嵌套关系与List<SaxEvent>顺序完全一致；
3. 如果标签中没有内容，就不会映射BodyEvent事件。

3.1.5.总结

1. logback使用JDK提供的XML解析工具类SAXParser将logback.xml解析为自己定义的SaxEvent子类，包括StartEvent、BodyEvent和EndEvent；
2. 同时构造解析器，加载支持所有的模式匹配规则到RuleStore，默认匹配规则到implicitActions；
3. 遍历事件列表，根据模式匹配规则找到对应的Action，回调事件对应的方法，StartEvent回调Action.begin()，BodyEvent回调Action.body()，EndEvent回调Action.end()。

3.2.简单嵌套标签的事件执行流程

下面我们就以<file>标签为例，分别来分析简单嵌套标签的事件执行流程。然后在此基础上，去对比分析<encode>和<appender>等标签。

3.2.1.<file>之StartEvent

只有 2 行，调用startElement和fireInPlay：

startElement获取到标签绑定的Action对象（回顾上面的addInstanceRules），先将它们塞到actionListStack当中，供后面的BodyEvent使用，然后调用Action对象的begin()方法：

首先获取标签对应的Action对象：

先到ruleStore里边找，这里存放的都是我们一开始JoranConfigurator类的addInstanceRules方法写入的所有模式匹配规则：

在这里找不到，继续通过lookupImplicitAction到implicitActions找（一开始JoranConfigurator类的addImplicitRules写入的 2 个对象）：

会顺序遍历这两个对象**（NestedComplexPropertyIA在前NestedBasicPropertyIA在后）**，调用它们的isApplicable方法判断该标签是否适用当前的Action。首先是NestedComplexPropertyIA的isApplicable方法：

parentBean.computeAggregationType方法计算结果为AS_COMPLEX_*的标签，会使用NestedComplexPropertyIA。计算AggregationType前会先获取父类 Bean，我们以logback.xml中的<file>标签为例，它的父类就是<appender>标签指定的class参数ch.qos.logback.core.rolling.RollingFileAppender:

这里最关键的一步是将父类RollingFileAppender的get、set和add方法分别放入propertyNameToGetter、propertyNameToGetter和propertyNameToGetter Map 当中。在判别是使用哪个Action时会用到该信息：

先去RollingFileAppender类中找是否存在addFile方法，如果没有，再去找setFile，后者是有的，所以要通过computeRawAggregationType(setter)判别：

先获取入参类型，然后判断入参类型是简单类型还是复杂类型，如果没有入参类型或者是简单类型就用NestedBasicPropertyIA，如果是复杂类型就用NestedComplexPropertyIA。setFile的第一个入参类型为java.lang.String，不为空，所以继续判断入参类型：

类型判断共有 5 种情况：

1. 是否是JDK基本类型，包括Boolean、Character、Byte、Short、Integer、Long、Float、Double和Void；
2. 是否是java.lang包中的类**（为什么单独把java.lang拿了出来？）**；
3. 是否是静态类；
4. 是否是枚举；
5. 是否是Charset类型，或其子类。

这里命中了第 3 种情况，所以NestedComplexPropertyIA.isApplicable最终返回的是AS_BASIC_PROPERTY，这个类型自然不能使用复杂Action了，那接着会判断能否使用简单的Action，调用NestedBasicPropertyIA.isApplicable：

可以看到主体逻辑和复杂Action大差不差！唯一区别，就是如果是简单类型，那此刻要将父类Bean等信息构建成的IADataForBasicProperty添加到actionDataStash当中（你回上文看一下，会发现复杂类型也有类似操作）。

然后我们去看一下这个简单的Action，它的begin()方法干了什么：

空实现，好吧，还真是简单……

调用完begin()方法后，就这就是fireInPlay方法，主要用来执行注册的监听器：

只有配置文件中有<else>等条件标签以及<sift>等日志隔离的标签，才会在listenerList中注册监听器，例如<then>标签对应的ThenAction的父类ThenOrElseActionBase：

我们这里没有，直接跳过。

总结一下<file>标签的StartEvent处理流程：

1. 查找标签对应的Action类型，先到RuleStore中找，没找到去ImplicitActions找，找到后将Action推送到actionListStack；

2. 如果是ImplicitAction类型，则先调用NestedComplexPropertyIA的isApplicable方法判断能否使用该类型处理标签；

3. 如果不行则继续调用ImplicitActions中的下一个类型的isApplicable方法，即NestedBasicPropertyIA；

4. 找到ImplicitAction处理类后，将该类型推送到actionDataStack中，然后调用事件对应的play方法。

3.2.2.<file>之BodyEvent

<file>标签在执行完BeginEvent之后，就该执行BodyEvent了。前面入口的细节我们就不列了，直接分析一下重点。首先，不是每个标签的StartEvent后面都有BodyEvent，只有像<file>标签这种标签内有内容才会有BodyEvent：

BodyEvent的主要处理流程：

actionListStack是我们上面在执行StartEvent的时候塞好的，上面StartEvent已经分析过了，直接调用NestedBasicPropertyIA的body()方法即可：

可以看到，这里直接把body的内容作为setFile的入参，调用setFile：

setFile内部调用了父类FileAppender的setFile方法：

setFile方法只是把日志文件的完整路径保存到fileName字段当中。

总结一下BodyEvent的执行流程：

1. 解析器直接读取actionListStack中的Action类型为NestedBasicPropertyIA，调用NestedBasicPropertyIA的body()方法；
2. body()内部获取父类Bean（这里是RollingFileAppender）的setFile方法，将内容赋值给fileName。

3.2.3.<file>之EndEvent

调用完BodyEvent事件之后，就该接着执行<file>标签的EndEvent事件了，同样，还是调用NestedBasicPropertyIA的end()方法：

可以看到end()方法非常简单，只是单纯把actionDataStack中塞进去的和<file>标签相关的上下文清除。到此为止我们对<file>标签的全部解析过程就分析完了。

3.2.4.总结

<file>标签执行的所有事件流程整理如下：

3.3.复杂嵌套标签的事件执行流程

<file>标签对应的 3 个事件的执行逻辑比较简单，下面我们分析一个比较复杂的标签<encoder>，这也是logback最核心的功能交汇处，控制日志的输出格式和方式。我们先来回顾一下<encoder>相关的事件都有哪些：

可以看到事件顺序和配置文件当中的标签嵌套关系是一致的。我们如果回去看一下JoranConfigurator的addInstanceRules方法，会发现并没有往RuleStore当中添加和<encoder>或<pattern>相关的模式匹配规则，所以它们必然还是调用NestedBasicPropertyIA或NestedComplexPropertyIA的方法。

<encoder>标签指定的bean为PatternLayoutEncoder，这是logback目前唯一有用且默认的 encoder 。

3.3.1.<encoder>之StartEvent

首先是<encoder>标签的StartEvent事件，还是先后通过NestedComplexPropertyIA.isApplicable和NestedBasicPropertyIA.isApplicable判别使用哪个Action：

encoder和file对应的是同一个父类RollingFileAppender，所以这里要去判断该父类有没有实现addEncoder或setEncoder方法，实际上其父类OutputStreamAppender实现了，然后通过判断最终会调用到NestedComplexPropertyIA.begin()。

哇塞，这个复杂Action的begin我们还没看过哦：

begin主要完成了 3 件事：

1. 将PatternLayoutEncoder记录到NestedComplexProperty；
2. 将上下文context记录到NestedComplexProperty.context；
3. 将NestedComplexProperty（Object类型，真实类型为PatternLayoutEncoder）推送到objectStack。

3.3.2.<pattern>之StartEvent

执行完<encoder>的StartEvent之后，就要执行<pattern>标签的StartEvent了。<pattern>标签在NestedComplexPropertyIA.isApplicable进行判断时，通过ic.peekObject()获取到的栈顶bean是刚刚推送进去的PatternLayoutEncoder：

OK，获取到PartternLayoutEncoder之后就要判断它是否实现了setPattern、addPattern方法：

我们可以直接看一下PartternLayoutEncoder的内容：

它只有一个start()方法，然后我们还要去看它的父类PatternLayoutEncoderBase：

父类实现了setPattern，所以<pattern>标签的StartEvent事件必然会调用NestedBasicPropertyIA.begin()对吧！NestedBasicPropertyIA的begin()、body()和end()在5.1.3节分析<file>标签的事件流程时都分析过了，这里不再赘述。主要关注的一点是，body()方法会调用setPattern()将日志格式%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50}: %m%n赋值到PatternLayoutEncoderBase.pattern字段，后面会用到！

3.3.3.<encoder>之EndEvent

<pattern>标签的所有事件执行完之后，就要执行<encoder>标签的EndEvent了，调用的是NestedComplexPropertyIA.end()：

因为我们在begin()方法中将NestedComplexProperty已经推送到actionDataStack了，NestedComplexProperty的真实类型为PatternLayoutEncoder，它实现了LifeCycle接口，所以end()当中会调用PatternLayoutEncoder.start()：

这是LifeCycle第一次被唤醒，这次是用来启动encoder！后面还有一次哦～～～

start()方法主要逻辑：

1. 构造PatternLayout对象；
2. 调用PatternLayoutBase对象的start()方法；
3. 调用LayoutWrappingEncoder对象的start()方法。

PatternLayout是logback中非常重要的概念，它是encoder完成日志格式转换的关键对象。

• 构造PatternLayout

PatternLayout构造PatternLayout对象时会加载静态资源DEFAULT_CONVERTER_MAP：

是不是很眼熟？这些就是在<pattern>标签中的日志格式支持的所有可解析的标识符，以及标识符对应的格式转换器。

我们可以通过继承PatternLayout类，然后向DEFAULT_CONVERTER_MAP添加自定义的格式转换器，实现在日志中打印一些业务需要的内容，会在后面的扩展部分详细讲解。

• PatternLayoutBase.start()

PatternLayoutBase.start()会完成对日志模版的所有预置解析工作：

首先将pattern拆分成格式标识符和关键词后封装到Converter<E>链表当中，因为我们的日志pattern为%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50}: %m%n，所以解析后的链表以PatternLayoutBase.head为头节点，内容如下：

然后ConverterUtil.startConverters(this.head)会利用上面加载的静态资源DEFAULT_CONVERTER_MAP遍历每个Converter调用它们的start()方法。我们以DateConvert类为例：

它会解析optionList的第一个option，我们从上面的head内容可以得知此处为yyyy-MM-dd HH:mm:ss:SSS，start()方法会将该option赋值给cachingDateFormatter。

• LayoutWrappingEncoder.start()

LayoutWrappingEncoder.start()内容比较简单，如果是需要立即刷新，则需要设置immediateFlush标识，最后将started标识置为trun：

到此为止，<encoder>标签的所有事件就处理完了，logback所有配置工作也完成了，接下来就是打印日志了。

3.3.4.<appender>之EndEvent

对于<appender>标签，它在匹配模式中被绑定的Action类型为AppenderAction，StartEvent.begin()没有太多可说的，它也没有重写body()方法，因为<appender>标签内都是<encoder>、<filter>和<file>等嵌套标签，没有标签内容。

我们重点分析一下EndEvent调用的end()方法：

这是LifeCycle第二次被唤醒，这次用来启动appender！

这里启动了appender，会触发RollingFileAppender.start()：

然后像多米诺骨牌一样，层层向上调用父类的start()方法：

RollingFileAppender -> FileAppender -> OutputStreamAppender -> UnsynchronizedAppender

OK，最终调用到UnsynchronizedAppender.start()才停止：

将started字段赋值为true。

3.3.5.总结

将<encoder>和<appender>的完整执行流程整理如下：

3.4.打印日志

上面分析了主要涉及的标签通过joran框架的解析，完成初始化的流程。完成初始化后就可以进行日志打印了。

3.4.1.获取Logger对象

要想打印日志，首先要获取Logger对象，例如我们的示例程序：

我们先看看logback的Logger对象中都包含哪些内容：

首先，logback直接实现了slf4j的接口org.slf4j.Logger（logback直接实现了所有slf4j的接口，这也是logback不需要桥接器的原因！）。Logger中各个字段含义如下：

这些字段我们现在可能还不清楚有什么作用，不着急，等我们后面分析logger.info() 方法是用到了给大家详细讲解。

我们先来分析一下iLoggerFactory.getLogger(name)的流程，getLogger的核心流程只有下面这部分：

主要分为两步：

1. 逐级获取目录名称
2. 根据目录名称获取对应的Logger对象，如果没有获取到，则创建并缓存

我们传入的完整包名为com.combat.logback.LogbackApplication，看下最终完成遍历后的loggerCache结果：

通过上面的列表我们可以得出如下结论：

1. Logger对象通过parent和childList将目录层级串联起来，最上层com的父节点是ROOT；
2. ROOT根节点的日志级别与我们配置文件一致，为INFO，其他层级均为null，因为我们并没有在配置文件中配置logger标签；
3. ROOT根节点有 2 个appender-ref标签，其他层级没有定义，所以为null；
4. 所有节点的additive属性均默认为true;
5. 所有层级关联的loggerContext为同一个对象，即维护同一份上下文。

3.4.2.打印日志入口

获取到Logger对象后就可以调用slf4j规范提供的接口来打印日志了。本节我们分析当我们调用logback的logger.info()方法打印日志时，logback是如何运行的。

Logback在logback-classic.jar的Logger对象中实现了slf4j所有日志打印方法，以info()为例：

入参msg为我们需要打印的日志信息，info内部调用filterAndLog_0_Or3Plus方法，入参除了msg还有两个：

• FQCN: 日志实现类完整名称，即 ch.qos.logback.classic.Logger

• Level.INFO: 日志级别，Level对象各个日志级别对应的取值如下（包含 2 个字段，levelInt和levelStr）：

INFO的取值：

日志级别越高，levelInt值越大！

然后进入filterAndLog_0_Or3Plus方法：

我们看到打印日志主要分为两步：

1. getTurboFilterChainDecision_0_3OrMore：获取TurboFilter链的计算结果，类型为FilterReply；
2. buildLoggingEventAndAppend：构建日志事件，进行日志输出。

3.4.3.过滤器TurboFilter

TurboFilger顾名思义，是一种过滤器，如果配置文件中设置了各种过滤器，这里通过对过滤器链进行计算，得出的结果决定是否打印日志。这个计算结果类型为FilterReply：

接下来我们就去探索一下FilterReply的获取过程：

通过分析这两段代码基本可以搞清楚TurboFilter过滤器列表的计算逻辑了：

1. turboFilterList中没有过滤器，则默认返回NEUTRUAL(中立)；
2. turboFilterList中只有一个TurboFilter，则返回该过滤器decide方法的结果；
3. turboFilterList中有多个TurboFilter，则从头开始遍历，只要有一个过滤器的decide方法计算结果为DENY(拒绝)或者ACCEPT(接受)，则返回该结果，如果为NEUTRAL则跳过判断下一个；
4. turboFilterList中所有过滤器的decide方法计算结果都为NEUTRAL，则返回NEUTRAL。

深入细节：什么是TurboFilter？它的decide方法是如何算出FilterReply结果的？

Logback一共有 5 种TurboFilter，我们大概都扫一眼这些过滤器，DynamicThresholdFilter过滤器注释非常详细：

在配置文件中使用<turboFilter>标签就可以定义一个turboFilter过滤器，后面的class参数指定的就是这 5 种过滤器中的一种。下面看看这个过滤器的作用：

1. 如果日志中的关键字userId=user1，日志级别 >= DEBUG 才会打印；
2. 如果日志中的关键字userId=user2，日志级别 >= TRACE 才会打印；
3. 如果日志中的关键字userId=其它值，日志级别 >= ERROR 才会打印。

所有，TurboFilter过滤器是为我们提供了一些策略，来决定是否打印日志。decide计算过程我们先不去深入分析了，主要思想就如上述示例所示。

3.4.4.appender

执行完过滤器的判断逻辑后，如果通过了过滤规则，接下来就要打印日志了，打印日志调用的是buildLoggingEventAndAppend:

一共就 3 行代码，首先构建了LoggingEvent对象，然后设置了marker字段的值，由于我们上层传过来的是null，所以这里就跳过了，最后调用callAppenders应该是用来打印日志的。如何封装LoggingEvent对象我们就不看了，直接来看callAppenders(le)：

callAppenders的逻辑主要分为两部分：

1. Logger对象依次向上层递归，调用父节点的appendLoopOnAppenders；
2. 如果没有任何父节点需要处理，则执行noAppenderDefinedWarning方法。

我们先来看一下appendLoopOnAppenders：

由 5.1 的列表我们知道，只有ROOT根节点的aai字段不为空，为什么？我们先找到aai是在哪里赋值的，给aai赋值在Logger只类中有一个方法：

该方法是被AppenderRefAction.begin调用的，begin()会将该节点绑定的appender追加到appenderList当中：

这又回到了joran框架，必然是joran解析配置文件时，解析到与该Action绑定的标签时，执行StartEvent调用的begin()方法：

我们的配置文件中正是使用了<root/appender-ref>标签：

所以最终遍历到ROOT节点才会执行aai.appendLoopOnAppenders(event)方法：

其中appenderList包含 2 个对象：

• INFO-OUT指定的bean：ch.qos.logback.core.rolling.RollingFileAppender
  • STDOUT指定的bean：ch.qos.logback.core.ConsoleAppender

然后就是挨个执行这 2 个appender的日志打印逻辑doAppend(E var1)。

appenderList中的两个对象都继承自UnsynchronizedAppenderBase, 所以最终调用的是UnsynchronizedAppenderBase.doAppend(E)：

doAppend通过guard实现线程安全保证，然后通过started判断appender是否启动，我们上面 5.5 节已经分析过了，会在<appender>标签的EndEvent事件中，调用UnsynchronizedAppenderBase.start()将started赋值为true，所以此时appender已经启动了。

doAppend调用了抽象方法append，在我们指定的RollingFileAppender的父类OutputStreamAppender中实现了：

writeBytes完成最终日志的输出。 完成日志输出前，还有 2 步预处理工作：

1. LoggingEvent.prepareForDeferredProcessing
2. LayoutWrappingEncoder.encode

• LoggingEvent.prepareForDeferredProcessing

第一次预处理需要获取 3 个信息：格式化后的日志内容、线程名称和MDC属性。格式化后的内容这里就是我们在启动类中写的hello world字符串；线程名称为当前线程名称main；MDC属性由于我们还没有使用，所以这里获取的Map为空（后面会在实战当中为大家展示MDC的作用）。

• LayoutWrappingEncoder.encode

encode方法内部调用了最后一个关键步骤PatternLayout.doLayout：

PatternLayoutBase.head应该很眼熟了，在PatternLayoutBase.start()时将<pattern>标签的内容预处理为Convert<E>链表，head即为链表的头节点。这个while循环就是要跟据Convert<E>链表按照<pattern>标签的内容格式构建出最终的日志内容。

我们先看一下Convert<E>链表的内容，后面的逻辑就很好理解了：

c.write内部调用的就是封装好的每个Convert实现的write方法，然后将结果拼接到buf当中：

我们以最简单的DateConverter为例：

timestamp是调用logger.info()时的时间戳，cachingDateFormatter是在上面 5.4 节PatternLayoutBase.start()的最后调用DataConvert.start()，将时间格式yyyy-MM-dd HH:mm:ss.SSS赋值进去的，所以这里将时间戳转换成了我们日志配置文件中pattern规定的时间格式。

到此为止，貌似我们已经完成了对logback整个源码主要流程的解读！如果你可以像上文一样，自己耐心打断点调试一遍，会有更多收获。

3.4.5.总结

打印日志整体流程整理如下：

4.Log4j2与Logback对比

Log4j2是Log4j的升级，同时借鉴了Logback的优秀设计，并修复了Logback架构中的一些问题，号称是目前最优秀的Java日志框架。它本身就是日志门面，可以不依赖Slf4j独立使用，也可以使用Slf4j+Log4j2的架构。

4.1.使用Log4j2框架

如果是单纯使用Log4j2作为日志门面和实现框架，只需要引入 2 个包：

• log4j-api：Log4j2自带的日志门面
• log4j-core：Log4j2具体的日志实现

maven配置如下：

<dependencies>
    <!--Log4j2自带的日志门面-->
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
        <version>2.17.1</version>
    </dependency>
    <!--Log4j2具体的日志实现-->
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>2.17.1</version>
    </dependency>
</dependencies>

项目中需要通过LogManager获取日志对象：

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class Log4j2Application {
    public static final Logger logger = LogManager.getLogger(Log4j2Application.class);

        public static void main(String[] args) {
            logger.info("hello world");
        }
}

而如果是使用Slf4j作为日志门面，因为Log4j2本身没有实现Slf4j规范的接口，所以需要额外再引入一个包log4j-slf4j-impl作为桥接器：

<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-slf4j-impl</artifactId>
    <version>2.17.1</version>
</dependency>

使用Slf4j作为日志门面，那在项目中获取日志对象的方式自然也是使用Slf4j的接口：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Log4j2Application {
    public static final Logger logger = LoggerFactory.getLogger(Log4j2Application.class);

    public static void main(String[] args) {
            logger.info("hello world");
        }
}

如果我们的项目使用的日志框架为Slf4j2+Log4j2，可以看到这里的代码和Logback的main函数语法一致，那么迁移到Logback的日志框架就不需要修改代码，直接修改依赖和配置文件即可。

阿里的《Java 开发手册》明确提出：应用中不可直接使用日志系统（log4j、logback）中的 API ，而应依赖使用日志框架 SLF4J 中的 API 。使用门面模式的日志框架，有利于维护和各个类的日志处理方式的统一。

Slf4j的配置文件和Logback略有区别，我们需要在resources下新建一个log4j2.xml的文件：

<?xml version="1.0" encoding="UTF-8" ?>
<!--monitorInterval属性值（秒数）为一个非零值来让Log4j每隔指定的秒数来重新读取配置文件，可以用来动态应用Log4j配置-->
<Configuration status="debug" monitorInterval="30">
    <!--用来自定义一些变量-->
    <Properties>
        <!--变量定义-->
        <Property name="myPattern" value="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
        <Property name="dir_url">/Users/imangozhang/logs</Property>
    </Properties>
    <!--使用Appenders元素可以将日志事件数据写到各种目标位置-->
    <Appenders>
        <!-- 默认打印到控制台 -->
        <Console name="ConsoleAppend" target="SYSTEM_OUT">
            <!-- 默认打印格式 -->
            <PatternLayout pattern="${myPattern}"/>
        </Console>
        <!-- 打印到日志文件上 -->
        <File name="FileAppend" fileName="${dir_url}/fileLog.log" bufferedIO="true" immediateFlush="true">
            <PatternLayout>
                <pattern>${myPattern}</pattern>
            </PatternLayout>
        </File>
    </Appenders>
    <!--定义logger，只有定义了logger并引入的appender，appender才会生效-->
    <Loggers>
        <!-- 默认打印日志级别为 error -->
        <Root level="INFO">
            <AppenderRef ref="ConsoleAppend"/>
            <AppenderRef ref="FileAppend"/>
        </Root>
    </Loggers>
</Configuration>

当然也支持json和yml等格式的文件，最常用的还是xml。格式其实和Logback大差不差，主体框架都是一样的，只是部分标签略有区别而已（这里的标签首字母大小，如果改成首字母小写也是可以的）。

4.2.Log4j2迁移到Logback

Log4j2迁移到Logback主要考虑下面几个因素：

• 配置文件迁移
• 接口迁移: 如果使用的是纯Log4j2，则需要修改为使用Slf4j接口
• 自定义业务迁移: 如果业务有自定义的layout或appender，则需要迁移，它们的部分实现略有区别

4.2.1.配置文件迁移

如果我们的Log4j2的配置文件是log4j2.properties文件，则可以尝试使用官方提供的迁移工具，转换为logback.xml文件（很少用，如果你是这种，可以去尝试一下）。

但如果你是log4j2.xml，这个迁移工具是肯定用不了的，我试过了……只能手动去改了！

4.2.2.接口迁移

如果使用的是纯Log4j2，业务代码中引入的包是org.apache.commons.log4j.*，但如果要迁移到Logback框架的话，需要统一使用Slf4j接口，所以我们需要修改 2 个地方：

• 引入的包修改

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

修改为：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

• 接口修改

public static final Logger logger = LogManager.getLogger(Log4j2Application.class);

修改为：

public static final Logger logger = LoggerFactory.getLogger(Log4j2Application.class);

这里如果我们的项目比较庞大，无需一个个文件去手动修改，这里Logback官方提供了一个代码迁移工具，可以帮我吗干这个事情。

4.2.3.自定义业务迁移

• layout迁移

假设我们现在要迁移一个简单的，名叫 TrivialLog4jLayout 的 log4j layout，它将日志事件中的消息作为格式化消息返回。代码如下：

package chapters.migrationFromLog4j;

import org.apache.log4j.Layout;
import org.apache.log4j.spi.LoggingEvent;


public class TrivialLog4jLayout extends Layout {
    public void activateOptions() {
    }

    public String format(LoggingEvent loggingEvent) {
        return loggingEvent.getRenderedMessage();
    }
    
    public boolean ignoresThrowable() {
        return true;
    }
}

等价的 logback-classic TrivialLogbackLayout 如下：

package chapters.migrationFromLog4j;

import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.LayoutBase;

public class TrivialLogbackLayout extends LayoutBase<ILoggingEvent> {
  public String doLayout(ILoggingEvent loggingEvent) {
    return loggingEvent.getMessage();
  }
}

正如你所见，在logback-classic layout中，格式化的方法叫做doLayout，而在 log4j 中叫format()。因为在 logback-classic 中没有等价的方法，所以 ignoresThrowable() 方法则不需要。logback-classic layout 必须继承 LayoutBase<ILoggingEvent> 类。

activateOptions() 方法的优点值得进一步讨论。在 log4j 中，一个 layout 有它自己的 activateOptions() 方法，通过 log4j 的配置程序，也就是 PropertyConfigurator 与 DOMConfigurator，会在 layout 所有的选项都设置完之后调用。因此，layout 有机会去检查它的所有的选项是否一致，如果是，那么开始进行初始化。

在logback-classic中layout必须实现 LifeCycle 接口，该接口包含了一个 start() 方法。这个 start() 方法相当 log4j 中的 activateOptions() 方法。

• appender迁移

迁移appender与迁移layout类似。下面是有一个名为 TrivialLog4jAppender 的简单appender，它会在控制台输出由它的layout返回的字符串。

package chapters.migrationFromLog4j;

import org.apache.log4j.AppenderSkeleton;
import org.apache.log4j.spi.LoggingEvent;

public class TrivialLog4jAppender extends AppenderSkeleton {
  protected void append(LoggingEvent loggingevent) {
     String s = this.layout.format(loggingevent);
     System.out.println(s);
  }

  public void close() {
     // nothing to do
  }

  public boolean requiresLayout() {
     return true;
  }
}

在logback-classic中等价的写法为 TrivialLogbackAppender，如下：

package chapters.migrationFromLog4j;

import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.AppenderBase;

public class TrivialLogbackAppender extends AppenderBase<ILoggingEvent> {

  @Override
  public void start() {
    if (this.layout == null) {
      addError("No layout set for the appender named [" + name + "].");
      return;
    }
    super.start();
  }

  @Override
  protected void append(ILoggingEvent loggingevent) {
    // AppenderBase.doAppend 只会在这个 appender 成功启动之后调用这个方法
    String s = this.layout.doLayout(loggingevent);
    System.out.println(s);
  }
}

比较这两个类，你会发现 append() 方法的内容没有改变。requiresLayout 方法在 logback 中没有用到，所以它可以被移除。在 logback 中，stop() 方法与 log4j 中的 close() 方法等价。然而，logback-classic 中的 AppenderBase 包含一个没有实现的 stop 方法，但是在这个简单的 appender 已经足够了。

5.SpringBoot整合Logback

如果我们使用的是SpirngBoot 项目，如何打印日志呢？SpringBoot已经整合了所有主流的日志框架，当然包括我们上面介绍的Logback和Log4j2。

5.1.依赖和配置

SpringBoot项目默认使用的日志框架是Logback，也就是说只要你引入任意一个SpringBoot的starter依赖，它默认会引入Logback日志框架。例如：

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
    <version>2.7.12</version>
</dependency>

执行mvn dependency:tree获取的Maven依赖树如下：

[INFO] com.combat:spring-logback:jar:1.0-SNAPSHOT
[INFO] \- org.springframework.boot:spring-boot-starter-web:jar:2.7.12:compile
[INFO]    +- org.springframework.boot:spring-boot-starter:jar:2.7.12:compile
[INFO]    |  +- org.springframework.boot:spring-boot:jar:2.7.12:compile
[INFO]    |  +- org.springframework.boot:spring-boot-autoconfigure:jar:2.7.12:compile
[INFO]    |  +- org.springframework.boot:spring-boot-starter-logging:jar:2.7.12:compile
[INFO]    |  |  +- ch.qos.logback:logback-classic:jar:1.2.12:compile
[INFO]    |  |  |  +- ch.qos.logback:logback-core:jar:1.2.12:compile
[INFO]    |  |  |  \- org.slf4j:slf4j-api:jar:1.7.32:compile
[INFO]    |  |  +- org.apache.logging.log4j:log4j-to-slf4j:jar:2.17.2:compile
[INFO]    |  |  |  \- org.apache.logging.log4j:log4j-api:jar:2.17.2:compile
[INFO]    |  |  \- org.slf4j:jul-to-slf4j:jar:1.7.36:compile

可以看到spring-boot-starter-web已经添加了依赖logback-classic、log4j-to-slf4j和jul-to-slf4j。

由此看出，SpringBoot通过spring-boot-starter-logging不仅整合了logback，还整合了log4j。

如果你还不确定用哪些SpringBoot的start，那就直接使用spring-boot-starter-logging即可：

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-logging</artifactId>
    <version>2.7.12</version>
</dependency>

配置文件的读取略有区别，初了可以自动读取logback.xml，SpringBoot还支持下面的格式：

• logback-spring.xml
• logback.xml
• logback-spring.groovy
• logback.groovy

官方更建议使用logback-spring.xml。

配置文件的格式没有变化。

如果我们需要修改日志等级，可以修改logback-spring.xml配置文件，也可以在我们项目的配置文件application.properties中指定：

logger.level.root = INFO

application.properties中的优先级高于logback-spring.xml。

5.2.源码分析

SpringBoot通过事件的发布订阅模式（即观察者模式）完成Logback日志框架的初始化。我们首先简单回顾一下SpringBoot的事件发布和订阅（这部分详细分析属于SpringBoot源码范畴，这里不做太深入的介绍，大家自行网上搜资料学习），然后看SpringBoot如果完成对Logback的初始化。

5.2.1.SpringBoot事件机制

SpringBoot的事件机制是对JDK的事件机制的扩展。JDK中定义了事件和监听者：

• JDK事件

package java.util;

public class EventObject implements java.io.Serializable {
    private static final long serialVersionUID = 5516075349620653480L;
    protected transient Object  source;

    public EventObject(Object source) {
        if (source == null)
            throw new IllegalArgumentException("null source");
        this.source = source;
    }

    public Object getSource() {
        return source;
    }

    public String toString() {
        return getClass().getName() + "[source=" + source + "]";
    }
}

• JDK监听者

package java.util;

/**
 * A tagging interface that all event listener interfaces must extend.
 * @since JDK1.1
 */
public interface EventListener {
}

SpringBoot中定义了很多种事件，这些事件的基类是ApplicationEvent，而ApplicationEvent则继承自JDK的EventObject：

package org.springframework.context;

import java.time.Clock;
import java.util.EventObject;

public abstract class ApplicationEvent extends EventObject {

/** use serialVersionUID from Spring 1.2 for interoperability. */
private static final long serialVersionUID = 7099057708183571937L;
/** System time when the event happened. */
private final long timestamp;

    public ApplicationEvent(Object source) {
super(source);
this.timestamp = System.currentTimeMillis();
}

public ApplicationEvent(Object source, Clock clock) {
super(source);
this.timestamp = clock.millis();
}

public final long getTimestamp() {
return this.timestamp;
}
}

相比JDK的EventObject，ApplicationEvent多了timestamp字段。SpringBoot的事件包括下面这些：

SpringBoot会在不同的运行阶段发布对应的事件：

SpringBoot的监听者都实现了ApplicationListener，它又继承自JDK的EventListener：

SpringBoot的事件发布由ApplicationEventPublish接口的publishEvent方法完成，而AbstractApplicationContext唯一实现了该方法，所以有它完成事件的发布。

监听者有很多，如何让多个监听者顺序执行呢？—— 让监听者实现Ordered接口，然后实现getOrder方法，给这些监听者指定顺序。例如SmartApplicationListener：

5.2.2.SpringBoot完成Logback的初始化

SpringBoot通过LoggingApplicationListener来完成Logback的初始化：

主要看一下下面这几个事件的处理逻辑：

• onApplicationStartingEvent
• onApplicationEnvironmentPreparedEvent
• onApplicationPreparedEvent

onApplicationStartingEvent事件是容器刚启动时触发的，主要完成SpringBoor容器中的Bean实例化前的一些准备工作：

beforeInitialize()是一个抽象方法，SpringBoot分别实现了Log4j2、Logback和Slf4j等日志框架初始化的准备工作：

如果你认真研读了前面几章关于Logback源码的分析，到这里应该很熟悉了：这里直接调用了Logback的绑定方法StaticLoggerBinder.getSingleton()完成了Logback与Slf4j日志门面的绑定工作！

onApplicationEnvironmentPreparedEvent事件是SpringBoot创建好抽象环境类后发布的事件，这里监听到该事件后正式完成Logback日志对象的初始化：

初始化主要关注 2 个关键步骤，initializeSystem和initializeFinalLoggingLevels，前者用于设置日志文件路径，优先读取application.properties文件设的logging.config值，没有则去读取logback-spring.xml中的文件路径；后者用于设置日志级别，优先读取application.properties文件设的logging.level.root值，没有则去读取logback-spring.xml中的日志级别：

onApplicationPreparedEvent是SpringBoot已经构建好上下文以后发布的事件，这里主要完成日志Bean的注入工作：

到这里我们完整分析了SpringBoot是如何整合Logback日志框架的。当然，一些非主流链路的细节，我们这里就不分析了，大家感兴趣的话可以去调试和验证，我这里写再多也比不上你动手实践一遍的！

6.Logback常用扩展

我们如果只会配置Logback，然后让它打印规定格式的日志，很多时候还是无法满足业务要求的。就比如我想在所有业务日志中统一打印一些业务字段，但是这些字段Logback本身是不认识的，无法为我们解析和转换怎么办？如果我想对日志中的一些敏感信息进行脱敏处理怎么办？本节我们就列举一些常用的Logback扩展功能。

6.1.添加业务字段

业务中最常见的需求就是在日志中打印一次请求的RequestId以串联起一次请求的所有日志，或者打印用户的uid以方便确认某个用户的行为。我们给一个如何在SpringBoot项目的日志中添加RequestId的示例。

给日志添加业务字段的核心手段是AOP（AOP 的概念就不在这里普及了，大家自行了解），所以我们在第 5 章SpringBoot项目的基础上，添加依赖：

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-aop</artifactId>
    <version>2.7.12</version>
</dependency>

我们的项目结构如下：

主要是添加了一个切面类 LoggerAspect：

@Component帮助我们将切面类注入到SpringBoot容器中，@Aspect能够让SpringBoot识别到这是一个切面类。@Pointcut切点指向的是controller包下的所有方法（这是@Pointcut的语法规则）。

然后定义@Before注解方法：

如果请求Header中包含RequestId字段，则放到dataMap当中，如果是请求入参当中有RequestId，会覆盖Header的值，最终会在recoredRequestId方法中将RequestId字段放到MDC当中，这样就完成对RequestId字段的添加了（如果没有值，这里通过UUID做默认处理）：

然后是@AfterRunning注解打印请求完成时的日志：

打印的日志中还包含了接口耗时信息，注意这里还用到了ThreadLocal。打印完请求返回日志后要进行资源清理，防止内存泄漏或者请求直接串值。我们的示例请求接口很简单：

最后别忘记在我们的Logback配置文件logback-spring.xml的日志格式中添加requestId字段：

<property name="FILE_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %X{requestId} %-5level %logger{50}:  %m%n"/>

到此为止我们就完成业务字段requestId的添加了，来看一下执行效果：

6.2.日志脱敏

如果我们的业务中涉及一些账号、密码、验证码或者提取码等敏感信息的打印，为了方式日志泄漏后对用户造成不必要的损失，在业务中往往需要对日志进行脱敏处理。脱敏即去除敏感信息，例如：我们的邮箱源数据为[email protected]，则日志中仅打印1*********[email protected]；而密码我们则固定打印为******。

Java项目中的脱敏手段主要有 2 中方式：

• 在需要脱敏的字段上添加注解，通过Logback对带有注解的字段进行统一处理，这种方式直接引入houbb/sensitive即可；
• 直接在Logback配置文件中添加自定义规则，实现自定义Converter类。

第一种方式我们暂时不在这里展开讲，如果是在业务开发早期就对脱敏有规划，那我建议优先使用这种方式，因为这种方式性能好还不会有遗漏。但是如果对于一个我们不想有任何代码改动的项目，对性能以及脱敏的结果又没有那么苛刻，我更建议使用第二种，这种方式也可以应付大多是情况了，下面我们介绍一下第 2 中方式。

首先，我们要继承MessageConverter类，实现自定义的日志内容转换类，在这个类里完成日志的脱敏工作：

package com.combat.logback.converter;

import ch.qos.logback.classic.pattern.MessageConverter;
import ch.qos.logback.classic.spi.ILoggingEvent;

import java.util.HashMap;
import java.util.Map;

public class SensitiveMessageConverter extends MessageConverter {
    private static final Map<String, String> regexMap = new HashMap<>();

    static {
        // 手机号脱敏
        regexMap.put("(mobile|手机号)(=|=\[|\":\"|:|：|='|':')(1)([3-9]{2})(\d{4})(\d{4})(\]|\"|'|)", "$1$2$3$4****$6$7");
        // 密码脱敏
        regexMap.put("(password|pwd|PASSWORD)([=|\"|\\\\|:|：|\\[|'|\\s]+)([\\w\\d\\s$@$!%*?&/+=]{1,128})(\\w*)", "$1$2******$4");
    }

    @Override
    public String convert(ILoggingEvent event) {
        String oriLogMsg = event.getFormattedMessage();
        String afterLogMsg = oriLogMsg;
        if (afterLogMsg == null || afterLogMsg.length() <= 0) {
            return afterLogMsg;
        }

        for (Map.Entry<String, String> regexPair : regexMap.entrySet()) {
            afterLogMsg = afterLogMsg.replaceAll(regexPair.getKey(), regexPair.getValue());
        }
        return afterLogMsg;
    }
}

我们在上面分析Logback源码时知道Logback提供的Converter的继承类有很多，这里为什么实现类MessageConverter就可以呢？我们看一下该类的内容：

MessageConverter是日志格式化完成的最后一个Converter，它将格式化好的内容直接返回给appender，所以我们继承该类后重写convert方法，对日志内容进行最后的修改，即可完成脱敏。

然后，我们还需在logback.xml中添加一条自定义规则：

<conversionRule conversionWord="m" converterClass="com.combat.logback.converter.SensitiveMessageConverter"/>

conversionWord的值要和我们的日志格式中的关键字对应（%m，这里还支持%msg和%message）：

<property name="FILE_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50}:  %m%n"/>

converterClass指定我们自定义的脱敏类。

7.参考文献

1. Logback官方文档：https://logback.qos.ch/manual/introduction.html
2. Logback中文文档：https://logbackcn.gitbook.io/logback/13-di-shi-san-zhang-cong-log4j-qian-yi
3. Log4j2官网：https://logging.apache.org/log4j/2.x/index.html