Java 日志框架全解
===========
`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
为例进行分析。首先进行如下配置:
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>
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");
}
}
- 添加一个
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.总结
- 业务侧调用
slf4j
的getLogger
方法获取Logger
接口的实现类; slf4j
找到并调用logback
的绑定接口实现类;logback
通过joran
框架解析并处理logback.xml
配置文件,初始化到slf4j.Logger
的实现类logback.classic.Logger
对象中返回;- 业务侧获取的
Logger
接口,其实绑定的是logback
的Logger
对象。
3.Logback
源码解析
上面我们分析了slf4j
的源码入口,以及logback
如何与slf4j
进行绑定,但是关于logback
的处理细节还没看到。本节来分析logback
的源码细节。
3.1.初识joran
上面已经提到,logback
实现了slf4j
的绑定接口StaticLoggerBinder
,这是logback
日志框架初始化的入口:
autoConfig
完成了对logback.xml
的所有初始化配置,我们看下它都干了什么:
可以看到主要分为 2 步:
findURLOfDefaultConfigurationFile
获取配置文件路径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 个规律:
- 标签和事件的映射关系如下:
<pattern>
–>StartEvent
、context
–>BodyEvent
、</pattern>
–>EndEvent
; - 标签的嵌套关系与
List<SaxEvent>
顺序完全一致; - 如果标签中没有内容,就不会映射
BodyEvent
事件。
3.1.5.总结
logback
使用JDK
提供的XML
解析工具类SAXParser
将logback.xml
解析为自己定义的SaxEvent
子类,包括StartEvent
、BodyEvent
和EndEvent
;- 同时构造解析器,加载支持所有的模式匹配规则到
RuleStore
,默认匹配规则到implicitActions
; - 遍历事件列表,根据模式匹配规则找到对应的
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 种情况:
- 是否是JDK基本类型,包括
Boolean
、Character
、Byte
、Short
、Integer
、Long
、Float
、Double
和Void
; - 是否是
java.lang
包中的类**(为什么单独把java.lang
拿了出来?)**; - 是否是静态类;
- 是否是枚举;
- 是否是
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
处理流程:
- 查找标签对应的
Action
类型,先到RuleStore
中找,没找到去ImplicitActions
找,找到后将Action
推送到actionListStack
; - 如果是
ImplicitAction
类型,则先调用NestedComplexPropertyIA
的isApplicable
方法判断能否使用该类型处理标签; - 如果不行则继续调用
ImplicitActions
中的下一个类型的isApplicable
方法,即NestedBasicPropertyIA
; - 找到
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
的执行流程:
- 解析器直接读取
actionListStack
中的Action
类型为NestedBasicPropertyIA
,调用NestedBasicPropertyIA
的body()
方法; 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 件事:
- 将
PatternLayoutEncoder
记录到NestedComplexProperty
; - 将上下文
context
记录到NestedComplexProperty.context
; - 将
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()
方法主要逻辑:
- 构造
PatternLayout
对象; - 调用
PatternLayoutBase
对象的start()
方法; - 调用
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
中各个字段含义如下:
| 字段 | 说明 |
| — | — |
| name | logger
标签中name
属性值,表示名称,如果配置文件中没有指明,则和包的层级对应。 |
| level | logger
标签中level
属性值,表示日志级别,Level
类型,包括OFF/ERROR/WARN/INFO/DEBUG/TRAVE/ALL
七个级别,父子层级之间具有传递性,可以为null
。 |
| effectiveLevelInt | 日志级别,int
类型。 |
| parent | 父节点,所有节点至少都有一个共同的父节点root
。 |
| childList | 子节点列表。 |
| aai | 所有appender-ref
标签列表,如果配置文件中没有则为null
。 |
| additive | logger
标签中additivity
属性值,表示是否继承父节点的日志级别和Appender
等属性,默认为true
。 |
| loggerContext | logger
上下文,维护所有父子节点信息、过滤器、整个配置文件信息等内容。 |
这些字段我们现在可能还不清楚有什么作用,不着急,等我们后面分析logger.info()
方法是用到了给大家详细讲解。
我们先来分析一下iLoggerFactory.getLogger(name)
的流程,getLogger
的核心流程只有下面这部分:
主要分为两步:
- 逐级获取目录名称
- 根据目录名称获取对应的
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”: {LoggerContext@1121
}<} |
| com.combat
| { “name”: “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
}<} |
通过上面的列表我们可以得出如下结论:
Logger
对象通过parent
和childList
将目录层级串联起来,最上层com
的父节点是ROOT
;ROOT
根节点的日志级别与我们配置文件一致,为INFO
,其他层级均为null
,因为我们并没有在配置文件中配置logger
标签;ROOT
根节点有 2 个appender-ref
标签,其他层级没有定义,所以为null
;- 所有节点的
additive
属性均默认为true
; - 所有层级关联的
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
方法:
我们看到打印日志主要分为两步:
getTurboFilterChainDecision_0_3OrMore
:获取TurboFilter
链的计算结果,类型为FilterReply
;buildLoggingEventAndAppend
:构建日志事件,进行日志输出。
3.4.3.过滤器TurboFilter
TurboFilger
顾名思义,是一种过滤器,如果配置文件中设置了各种过滤器,这里通过对过滤器链进行计算,得出的结果决定是否打印日志。这个计算结果类型为FilterReply
:
接下来我们就去探索一下FilterReply
的获取过程:
通过分析这两段代码基本可以搞清楚TurboFilter
过滤器列表的计算逻辑了:
turboFilterList
中没有过滤器,则默认返回NEUTRUAL(中立)
;turboFilterList
中只有一个TurboFilter
,则返回该过滤器decide
方法的结果;turboFilterList
中有多个TurboFilter
,则从头开始遍历,只要有一个过滤器的decide
方法计算结果为DENY(拒绝)
或者ACCEPT(接受)
,则返回该结果,如果为NEUTRAL
则跳过判断下一个;turboFilterList
中所有过滤器的decide
方法计算结果都为NEUTRAL
,则返回NEUTRAL
。
深入细节:什么是TurboFilter
?它的decide
方法是如何算出FilterReply
结果的?
Logback
一共有 5 种TurboFilter
,我们大概都扫一眼这些过滤器,DynamicThresholdFilter
过滤器注释非常详细:
在配置文件中使用<turboFilter>
标签就可以定义一个turboFilter
过滤器,后面的class
参数指定的就是这 5 种过滤器中的一种。下面看看这个过滤器的作用:
- 如果日志中的关键字
userId=user1
,日志级别 >= DEBUG 才会打印; - 如果日志中的关键字
userId=user2
,日志级别 >= TRACE 才会打印; - 如果日志中的关键字
userId=其它值
,日志级别 >= ERROR 才会打印。
所有,TurboFilter
过滤器是为我们提供了一些策略,来决定是否打印日志。decide
计算过程我们先不去深入分析了,主要思想就如上述示例所示。
3.4.4.appender
执行完过滤器的判断逻辑后,如果通过了过滤规则,接下来就要打印日志了,打印日志调用的是buildLoggingEventAndAppend
:
一共就 3 行代码,首先构建了LoggingEvent
对象,然后设置了marker
字段的值,由于我们上层传过来的是null
,所以这里就跳过了,最后调用callAppenders
应该是用来打印日志的。如何封装LoggingEvent
对象我们就不看了,直接来看callAppenders(le)
:
callAppenders
的逻辑主要分为两部分:
Logger
对象依次向上层递归,调用父节点的appendLoopOnAppenders
;- 如果没有任何父节点需要处理,则执行
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 步预处理工作:
LoggingEvent.prepareForDeferredProcessing
-
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.日志脱敏
如果我们的业务中涉及一些账号、密码、验证码或者提取码等敏感信息的打印,为了方式日志泄漏后对用户造成不必要的损失,在业务中往往需要对日志进行脱敏处理。脱敏即去除敏感信息,例如:我们的邮箱源数据为13312348080@163.com
,则日志中仅打印1*********8@163.com
;而密码我们则固定打印为******
。
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.参考文献
Logback
官方文档:logback.qos.ch/manual/intr…Logback
中文文档:logbackcn.gitbook.io/logback/13-…Log4j2
官网:logging.apache.org/log4j/2.x/i…
原文链接: https://juejin.cn/post/7385784332445646859
文章收集整理于网络,请勿商用,仅供个人学习使用,如有侵权,请联系作者删除,如若转载,请注明出处:http://www.cxyroad.com/17767.html