Java日志框架的原理

大模型机器学习数据库

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

  • • 日志框架简介
  • • Slf4j源码解析
  • • Logback源码解析
  • • SpringBoot整合Logback源码解析
  • • Logback扩展

最近建了一些工作内推群,各大城市都有,欢迎各位HR和找工作的小伙伴进群交流,群里目前已经收集了不少的工作内推岗位。

扫码加苏三的微信:li_su223,备注:所在城市,即可进群。

picture.image

日志框架简介

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

日志框架历史

  • • Log4j

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

  • • JUL

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

  • • JCL

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

  • • Slf4j & Logback

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

  • • Log4j2

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

日志框架分类

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

日志门面框架

  • • 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 是同一个作者,性能更好(推荐使用)。

Slf4j架构

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

对于不同的日志实现框架(如 Logback,Log4j 等),封装出不同的桥接组件(如logback-classic-version.jar,slf4j-log4j12-version.jar等),这样使用过程中可以灵活选取自己项目里的日志实现。

整体关系图如下:

picture.image

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

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

Logback日志框架使用

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

    1. pom配置

 
 
 
 
   
< !-- slf4j-api 依赖 -->
    1. main函数LogbackApplication.class:

 
 
 
 
   
import org.slf4j.Logger;
    1. 添加一个logback.xml的配置文件:

 
 
 
 
   
<?xml version="1.0" encoding="UTF-8"?>

Slf4j源码解析

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

slf4j入口

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

picture.image

picture.image

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

picture.image

IloggerFactoryry初始化的核心就是bind()方法:

picture.image

picture.image

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

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

(2)记录获找到的绑定对象实例

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

(4)记录实际绑定的对象和事件等

StaticLoggerBinder

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

picture.image

picture.image

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

picture.image

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

picture.image

Logback绑定接口实现

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

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

picture.image

初始化调用init() 方法:

picture.image

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

picture.image

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

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

picture.image

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

picture.image

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

picture.image

总结

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

picture.image

Logback源码解析

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

初识joran

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

picture.image

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

picture.image

可以看到主要分为 2 步:

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

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

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

picture.image

picture.image

picture.image

joran入口

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

picture.image

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

picture.image

picture.image

picture.image

picture.image

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

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

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

joran之SaxEvent

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

picture.image

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

joran之buildInterpreter

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

picture.image

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

picture.image

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

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

picture.image

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

picture.image

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

joran之play

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

picture.image

picture.image

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

picture.image

picture.image

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

    1. 标签和事件的映射关系如下:-->EndEvent;
    1. 标签的嵌套关系与List顺序完全一致;
    1. 如果标签中没有内容,就不会映射BodyEvent事件。

总结

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

picture.image

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

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

file之StartEvent

只有 2 行,调用startElement和fireInPlay:

picture.image

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

picture.image

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

picture.image

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

picture.image

在这里找不到,继续通过lookupImplicitAction到implicitActions找(一开始JoranConfigurator类的addImplicitRules写入的 2 个对象):

picture.image

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

picture.image

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

picture.image

picture.image

picture.image

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

picture.image

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

picture.image

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

picture.image

类型判断共有 5 种情况:

    1. 是否是JDK基本类型,包括Boolean、Character、Byte、Short、Integer、Long、Float、Double和Void;
    1. 是否是java.lang包中的类(为什么单独把java.lang拿了出来?);
    1. 是否是静态类;
    1. 是否是枚举;
    1. 是否是Charset类型,或其子类。

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

picture.image

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

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

picture.image

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

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

picture.image

只有配置文件中有等条件标签以及等日志隔离的标签,才会在listenerList中注册监听器,例如标签对应的ThenAction的父类ThenOrElseActionBase:

picture.image

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

总结一下标签的StartEvent处理流程:

picture.image

    1. 查找标签对应的Action类型,先到RuleStore中找,没找到去ImplicitActions找,找到后将Action推送到actionListStack;
    1. 如果是ImplicitAction类型,则先调用NestedComplexPropertyIA的isApplicable方法判断能否使用该类型处理标签;
    1. 如果不行则继续调用ImplicitActions中的下一个类型的isApplicable方法,即NestedBasicPropertyIA;
    1. 找到ImplicitAction处理类后,将该类型推送到actionDataStack中,然后调用事件对应的play方法。

file之BodyEvent

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

picture.image

BodyEvent的主要处理流程:

picture.image

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

picture.image

picture.image

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

picture.image

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

picture.image

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

总结一下BodyEvent的执行流程:

picture.image

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

file之EndEvent

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

picture.image

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

总结

标签执行的所有事件流程整理如下:

picture.image

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

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

picture.image

picture.image

可以看到事件顺序和配置文件当中的标签嵌套关系是一致的。我们如果回去看一下JoranConfigurator的addInstanceRules方法,会发现并没有往RuleStore当中添加和或

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

encoder之StartEvent

首先是标签的StartEvent事件,还是先后通过NestedComplexPropertyIA.isApplicable和NestedBasicPropertyIA.isApplicable判别使用哪个Action:

picture.image

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

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

picture.image

begin主要完成了 3 件事:

    1. 将PatternLayoutEncoder记录到NestedComplexProperty;
    1. 将上下文context记录到NestedComplexProperty.context;
    1. 将NestedComplexProperty(Object类型,真实类型为PatternLayoutEncoder)推送到objectStack。

parttern之StartEvent

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

picture.image

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

picture.image

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

picture.image

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

picture.image

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

encoder之EndEvent

picture.image

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

picture.image

start()方法主要逻辑:

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

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

  • • 构造PatternLayout

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

picture.image

picture.image

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

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

  • • PatternLayoutBase.start()

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

picture.image

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

picture.image

picture.image

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

picture.image

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

  • • LayoutWrappingEncoder.start()

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

picture.image

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

appender之EndEvent

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

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

picture.image

这里启动了appender,会触发RollingFileAppender.start():

picture.image

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

RollingFileAppender -> FileAppender -> OutputStreamAppender -> UnsynchronizedAppender

OK,最终调用到UnsynchronizedAppender.start()才停止:

picture.image

将started字段赋值为true。

总结

将和的完整执行流程整理如下:

picture.image

打印日志

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

获取Logger对象

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

picture.image

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

picture.image

picture.image

首先,logback直接实现了slf4j的接口org.slf4j.Logger(logback直接实现了所有slf4j的接口,这也是logback不需要桥接器的原因!)。Logger中各个字段含义如下:

字段
说明
name
logger标签中nlogger标签中name属性值,表示名称,如果配置文件中没有指明,则和包的层级对应。
level
logger标签中level属性值,表示日志级别,Level类型,包括OFF/ERROR/WARN/INFO/DEBUG/Tlogger标签中level属性值,表示日志级别,Levelogger标签中level属性值,表示日志级别,Level类型,包括OFF/ERROR/WARN/INFO/DEBUG/TRAVE/ALL七个级别,父子层级之间具有传递性,可以为null。
effectiveLevelInt
日志级别,int类型。
parent
父节点,所有节点至少都有一个共同的父节点root。
childList
子节点列表。
aai
所有appender-ref标签列表,如果配置文件中没有则为null。
additive
logger标签中additivity属性值,表示是否继承父节点的日志logger标签中additivity属性值,表示是否继承父节点的日志级别和Appender等属性,默认为true。
loggerContext
logger上下文,维护所有父子节点信息、过滤器、整个配置文件信息等内容。

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

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

picture.image

主要分为两步:

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

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

|

|

| | logger标签名称 | Logger对象内容 | | ROOT | { "name": "ROOT", "level": "INFO", "effectiveLevelInt": 20000, "parent": null, "childList": [ {Logger@com} ], "aai": [ {ConsoleAppender}, {RollingFileAppender} ], "additive": true, "loggerContext": {LoggerContext@1121}< } | | com | { "name": "com", "level": "null", "effectiveLevelInt": 20000, "parent": {Logger@ROOT}, "childList": [ { Logger@com.combat } ], "aai": null, "additive": true, "loggerContext": {LoggerCon"com", "level": "null", "effectiveLevelInt": 20000, "parent": {Logger@ROOT}, "childList": [ { Logger@com.combat } ], "aai": null, "additive": true, "loggerContext": {LoggerContext@1121}< } | | com.combat | { "name": "com.combat", "level": "null", "effectiveLevelInt": 20000, "parent": {Logger@com}, "childList": [ { Logger@com.combat.logback } ], "aai": null, "additive": true, "loggerContext": {LoggerC "com.combat", "level": "null", "effectiveLevelInt": 20000, "parent": {Logger@com}, "childList": [ { Logger@com.combat.logback } ], "aai": null, "additive": true, "loggerContext": {LoggerContext@1121} } | | com.combat.logback | { "name": "com.combat.logback", "level": "null", "effectiveLevelInt": 20000, "parent": {Logger@com}, "childList": [ { Logger@com.combat.logback.LogbackApplication } }, "aai": null, "additive": true, "loggerContext": {LoggerContext@1121}< } | | com.combat.logback.LogbackApplication | { "name": "com.combat.logback.LogbackApplication", "level": "null", "effectiveLevelInt": 20000, "parent": { Logger@com.combat.logback }, "childList": null, "aai": null, "additive": true, "loggerContext": {LoggerContext@1121}< loggerContext": {LoggerContext@1121}{ "name": "com.combat.logback.LogbackApplication", "level": "null", "effectiveLevelInt": 20000, "parent": { Logger@com.combat.logback }, "childList": null, "aai": null, "additive": true, "loggerContext": {LoggerContext@1121}< } |

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

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

打印日志入口

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

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

picture.image

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

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

picture.image

  • • Level.INFO: 日志级别,Level对象各个日志级别对应的取值如下(包含 2Level.INFO: 日志级别,Level对象各个日志级别对应的取值如下(包含 2 个字段,levelInt和levelStr):

picture.image

INFO的取值:

picture.image

picture.image

然后进入filterAndLog_0_Or3Plus方法:

picture.image

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

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

过滤器TurboFilter

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

picture.image

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

picture.image

picture.image

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

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

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

picture.image

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

picture.image

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

picture.image

如果日志中的关键字userId=user1,日志级别 >= DEBUG 才会打印;

    1. 如果日志中的关键字userId=user2,日志级别 >= TRACE 才会打印;
    1. 如果日志中的关键字userId=其它值,日志级别 >= ERROR 才会打印。

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

appender

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

picture.image

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

picture.image

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

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

我们先来看一下appendLoopOnAppenders:

picture.image

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

picture.image

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

picture.image

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

picture.image

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

picture.image

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

picture.image

其中appenderList包含 2 个对象:

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

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

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

picture.image

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

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

picture.image

picture.image

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

    1. LoggingEvent.prepareForDeferredProcessing
    1. LayoutWrappingEncoder.encode
  • • LoggingEvent.prepareForDeferredProcessing

picture.image

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

  • • LayoutWrappingEncoder.encode

picture.image

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

picture.image

picture.image

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

我们先看一下Convert链表的内容,后面的逻辑就很好理解了:

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

picture.image

picture.image

我们以最简单的DateConverter为例:

picture.image

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

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

总结

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

picture.image

Log4j2与Logback对比

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

使用Log4j2框架

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

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

maven配置如下:


 
 
 
 
   
<dependencies>

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


 
 
 
 
   
import org.apache.logging.log4j.LogManager;

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


 
 
 
 
   
<dependency>

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


 
 
 
 
   
import org.slf4j.Logger;

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

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

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


 
 
 
 
   
<?xml version="1.0" encoding="UTF-8" ?>

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

Log4j2迁移到Logback

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

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

配置文件迁移

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

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

接口迁移

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

  • • 引入的包修改

 
 
 
 
   
import org.apache.logging.log4j.LogManager;

修改为:


 
 
 
 
   
import org.slf4j.Logger;
  • • 接口修改

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

修改为:


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

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

自定义业务迁移

  • • layout迁移

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


 
 
 
 
   
package chapters.migrationFromLog4j;

等价的 logback-classic TrivialLogbackLayout 如下:


 
 
 
 
   
package chapters.migrationFromLog4j;

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

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;

在logback-classic中等价的写法为 TrivialLogbackAppender,如下:


 
 
 
 
   
package chapters.migrationFromLog4j;

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

SpringBoot整合Logback

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

依赖和配置

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


 
 
 
 
   
<dependency>

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


 
 
 
 
   
[INFO] com.combat:spring-logback:jar:1.0-SNAPSHOT

可以看到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>

配置文件的读取略有区别,初了可以自动读取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。

源码分析

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

SpringBoot事件机制

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

  • • JDK事件

 
 
 
 
   
package java.util;
  • • JDK监听者

 
 
 
 
   
package java.util;

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


 
 
 
 
   
package org.springframework.context;

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

picture.image

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

picture.image

SpringBoot的监听者都实现了ApplicationListener,它又继承自JDK的EventLiBoot的监听者都实现了ApplicationListener,它又继承自JDK的EventListener:

picture.image

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

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

picture.image

SpringBoot完成Logback的初始化

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

picture.image

picture.image

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

  • • onApplicationStartingEvent
  • • onApplicationEnvironmentPreparedEvent
  • • onApplicationPreparedEvent

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

picture.image

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

picture.image

picture.image

picture.image

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

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

picture.image

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

picture.image

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

picture.image

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

Logback常用扩展

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

添加业务字段

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

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


 
 
 
 
   
<dependency>

我们的项目结构如下:

picture.image

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

picture.image

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

然后定义@Before注解方法:

picture.image

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

picture.image

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

picture.image

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

picture.image

最后别忘记在我们的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的添加了,来看一下执行效果:

picture.image

日志脱敏

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

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

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

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

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


 
 
 
 
   
package com.combat.logback.converter;

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

picture.image

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

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


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

conversionWord的值要和我们的日志格式中的关键字对应(conversionWord的值要和我们的日志格式中的关键字对应(%m,这里还支持%msg和%message):


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

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

参考文献

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

最后欢迎加入苏三的星球,你将获得:100万QPS短链系统、复杂的商城微服务系统、苏三AI项目、刷题吧小程序、秒杀系统、商城系统、秒杀系统、代码生成工具等8个项目的源代码、开发教程和技术答疑。

系统设计、性能优化、技术选型、底层原理、Spring源码解读、工作经验分享、痛点问题、面试八股文等多个优质专栏。

还有1V1免费修改简历、技术答疑、职业规划、送书活动、技术交流。

扫描下方二维码,可以优惠30元:

picture.image

只有20张优惠券,数量有限,先到先得。

目前星球已经更新了5800+篇优质内容,还在持续爆肝中.....

星球已经被官方推荐了3次,收到了小伙伴们的一致好评。戳我加入学习,已有1900+小伙伴加入学习。

0
0
0
0
关于作者
关于作者

文章

0

获赞

0

收藏

0

相关资源
云原生可观测性技术的落地实践
云原生技术和理念在近几年成为了备受关注的话题。应用通过云原生改造,变得更动态、弹性,可以更好地利用云的弹性能力。但是动态、弹性的环境也给应用以及基础设施的观测带来了更大的挑战。本次分享主要介绍了云原生社区中可观测性相关的技术和工具,以及如何使用这些工具来完成对云原生环境的观测。
相关产品
评论
未登录
看完啦,登录分享一下感受吧~
暂无评论