glmapper

SpringBoot 源码系列-日志详解

字数统计: 7.2k阅读时长: 31 min
2019/12/14 Share

Spring Boot 使用 Commons Logging 进行所有内部日志记录,但保留底层日志实现。为 Java Util Logging、Log4J2 和 Logback 提供了默认配置。在每种情况下,loggers 都预先配置为使用 console 输出,并且也提供可选的文件输出。

默认情况下,如果使用 “starters”,则使用 Logback 进行日志记录。还包括适当的 Logback 路由,以确保使用 Java Util 日志记录、Commons 日志记录、Log4J 或 SLF4J 的依赖库都能正常工作。

下面先来看一个最简单的 SpringBoot demo 工程的日志输出,以此来展开日志格式、控制台输出、日志颜色、日志文件配置、日志体系解析等几个方面的介绍。

新建一个 SpringBoot 工程,默认在什么都不加的情况下直接启动,其启动日志大概如下:

1
2
3
4
5
6
7
8
2019-12-24 20:41:31.866  INFO 87851 --- [           main] com.glmapper.bridge.boot.BootStrap       : No active profile set, falling back to default profiles: default
2019-12-24 20:41:32.003 INFO 87851 --- [ main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@314c508a: startup date [Tue Dec 24 20:41:31 CST 2019]; root of context hierarchy
2019-12-24 20:41:32.556 INFO 87851 --- [ main] o.s.j.e.a.AnnotationMBeanExporter : Registering beans for JMX exposure on startup
2019-12-24 20:41:32.568 INFO 87851 --- [ main] com.glmapper.bridge.boot.BootStrap : Started BootStrap in 1.035 seconds (JVM running for 2.13)
2019-12-24 20:41:32.569 INFO 87851 --- [ Thread-4] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@314c508a: startup date [Tue Dec 24 20:41:31 CST 2019]; root of context hierarchy
2019-12-24 20:41:32.571 INFO 87851 --- [ Thread-4] o.s.j.e.a.AnnotationMBeanExporter : Unregistering JMX-exposed beans on shutdown

Process finished with exit code 0

日志格式

上面是 Spring Boot 的默认日志输出,从日志格式来看,主要包括以下几项:

  • 日期时间: 例如 2019-12-24 20:41:31.866 (毫秒精度)
  • 日志级别: 例如 INFO (ERROR, WARN, INFO, DEBUG, or TRACE.)
  • 当前进程: 例如 87851
  • — 分隔符,用于区分实际日志消息的开头。
  • 线程名称: 例如 Thread-4 (用方括号括起来(为了控制台输出可能被截断)).
  • 日志名称: 这通常是源类名(通常是缩写)。
  • 日志信息: 具体的日志消息

比如这条记录:

1
2019-12-24 20:41:31.866  INFO 87851 --- [           main] com.glmapper.bridge.boot.BootStrap       : No active profile set, falling back to default profiles: default

是在 org.springframework.boot.SpringApplication#logStartupProfileInfo 方法中打印的,日志级别为 INFO。

Console 输出

SpringBoot 默认会将日志输出到 Console,默认情况下,会记录 error 级别、warn 级别和 info 级别的消息。还可以通过使用 —-debug 参数启动应用程序来使用 “debug” 级别。

1
java -jar myapp.jar --debug

也可以在 application.properties 中指定 debug=true 来启用 debug 级别

当启用 debug 级别时,将配置一系列核心日志记录器(嵌入式容器、Hibernate 和 Spring Boot) 以输出更多信息。启用 debug 模式并不会将应用程序配置为记录所有具有 debug 级别的消息。同样的,也可以使用 —-trace 标记来启动 trace 级别模式来启动应用程序。

彩色编码输出

如果你的终端支持 ANSI,你可以通过设置 “spring.output.ansi.enable“ 配置项值来指定颜色(前提是官方已经支持的颜色)。颜色编码是通过使用 %clr 转换字来配置的,最简单的就是根据日志级别对输出的日志进行着色,如下面的示例所示:

1
%clr(%5p)

下表是官方提供的描述日志级别到颜色的映射关系表:

Level Color
FATAL Red
ERROR Red
WARN Yellow
INFO Green
DEBUG Green
TRACE Green

如果你想要使文本变成黄色,可以使用以下设置:

1
%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){yellow}

目前支持的颜色和样式包括 : blue、cyan、faint、green、magenta、red、yellow。

文件输出

默认情况下,Spring 引导日志只输出到 Console,不会写入到日志文件中。如果希望在 Console 输出之外还写入到日志文件,则需要设置 logging.file 和 logging.path 属性(在 application.properties 中)。下表显示了 logging.* 属性如何一起使用:

logging.file logging.path Example Description
none none 控制台日志
指定文件 none my.log 写入指定的日志文件,名称可以是精确位置或相对于当前目录。
none 指定文件 /var/log 将 spring.log 写入指定的目录,名称可以是精确位置或相对于当前目录。

日志文件在达到 10 MB 时会进行 Rolling,与 Console 输出一样,默认情况下会记录 ERROR 级别、WARN 级别和 INFO 级别的消息。可以使用 logging.file.max-size 属性更改大小限制。除非已设置 logging.file.max-history 属性,否则以前 Rolling 的文件将无限期归档。

日志系统在应用程序生命周期的早期初始化。因此,在通过 @PropertySource 注释加载的属性文件中是找不到日志属性的。另外,logging 属性独立于实际的logging 基础结构。所以,Spring Boot 不会管理特定的配置密钥(例如 Logback 的 logback.configurationFile)。

日志级别

SpringBoot 中所支持的日志系统都可以通过 logging.level.<logger-name>=<level> 在 Spring 环境中设置日志的级别(比如在application.properties 中)。日志级别主要包括 TRACE, DEBUG, INFO, WARN, ERROR, FATAL 和 OFF 几种。除此之外,还可以使用 logging.level.root 配置 root logger 的日志级别。下面的示例展示了如何在 application.properties 中配置日志级别:

1
2
3
logging.level.root=warn
logging.level.org.springframework.web=debug
logging.level.org.hibernate=error

除了 application.properties 之外,也可以使用环境变量设置日志级别。例如,LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB=DEBUG 将 org.springframework.web 包下的日志打印级别设置为 DEBUG。

上面的方法只适用于包级别的日志记录。由于 Relaxed Binding 总是将环境变量转换为小写形式,因此不可能以这种方式为单个类配置日志记录。如果需要为一个类配置日志记录,可以使用 SPRING_APPLICATION_JSON 变量。

日志 Groups

将相关的 loggers 分组在一起通常很有用,这样就可以同时对它们进行配置,Spring Boot 允许在 Spring 环境中定义日志组。例如将 “tomcat” 组添加到 application.properties。

1
logging.group.tomcat=org.apache.catalina, org.apache.coyote, org.apache.tomcat

这样,我们就可以通过一行配置来设置一组日志的日志级别:

1
logging.level.tomcat=TRACE

Spring Boot 包含以下可以开箱即用的预定义日志组:

Name Loggers
web org.springframework.core.codec, org.springframework.http, org.springframework.web, org.springframework.boot.actuate.endpoint.web, org.springframework.boot.web.servlet.ServletContextInitializerBeans
sql org.springframework.jdbc.core, org.hibernate.SQL

自定义日志配置

可以通过在类路径中包含适当的库来激活各种日志系统,还可以通过在类路径的根目录中提供适当的配置文件或在 Spring 环境的 logging.config 属性指定的位置提供适当的配置文件来进一步定制日志系统。

比如可以使用 org.springframework.boot.logging.LoggingSystem 配置属性强制 Spring 引导使用指定的日志系统。该值应该是 LoggingSystem 实现的完全限定类名;如果配置为 none 的话,则表示完全禁用 Spring Boot 的日志配置。下表描述了 SpringBoot 中日志系统所对应的日志配置文件:

Logging System Customization
Logback logback-spring.xml, logback-spring.groovy, logback.xml, or logback.groovy
Log4j2 org.springframework.jdbc.core, org.hibernate.SQL
JDK (Java Util Logging) logging.properties

SpringBoot 官方建议在日志配置中使用 -spring 的配置方式(例如,使用 logback-spring.xml 而不是 logback.xml)。如果使用标准配置位置,Spring 无法完全控制日志初始化。

另外官方文档中有明确提到,JUL(ava Util Logging) 在 FATJAR 场景下存在一些已知的类加载问题,所以要尽量避免在 FATJAR 场景下使用 JUL。

为了辅助对日志系统进行定制,Spring 会将环境变量属性设置成系统属性,如下表所示:

Spring Environment System Property Comments
logging.exception-conversion-word LOG_EXCEPTION_CONVERSION_WORD 记录异常时使用的 conversion word
logging.file LOG_FILE 如果已定义,则在默认日志配置中使用。
logging.file.max-size LOG_FILE_MAX_SIZE 最大日志文件大小(如果启用了LOG_FILE)。(只支持默认的Logback设置)
logging.file.max-history LOG_FILE_MAX_HISTORY 要保留的归档日志文件的最大数量(如果启用了LOG_FILE)。(只支持默认的Logback设置。)
logging.path LOG_PATH 如果已定义,则在默认日志配置中使用。
logging.pattern.console CONSOLE_LOG_PATTERN 要在控制台(stdout)上使用的日志模式。(只支持默认的Logback设置。)
logging.pattern.dateformat LOG_DATEFORMAT_PATTERN 日志日期格式的附加模式。(只支持默认的 Logback 设置。)
logging.pattern.file FILE_LOG_PATTERN 最大日志文件大小(如果启用了LOG_FILE)。(只支持默认的Logback设置)
logging.pattern.level LOG_LEVEL_PATTERN 呈现日志级别时使用的格式(默认%5p)。(只支持默认的Logback设置。)
PID PID 当前进程ID

所有支持的日志系统在解析配置文件时都可以参考系统属性进行配置解析。

如果希望在日志属性中使用占位符,应该使用 SpringBoot 的语法,而不是底层框架的语法。需要注意的是,如果使用 Logback,应该使用:作为属性名及其默认值之间的分隔符,而不是使用:-

springProfile 配置

允许用户根据激活的 Spring profiles 选择包含或排除配置部分。profile 文件部分在 元素的任何地方都受支持。可以使用 name 属性指定哪个配置文件接受配置。 可以包含简单的 profile 文件名称(例如 dev )或 profile 文件表达式。profile 文件表达式允许一些比较复杂的 profile 文件逻辑,例如: “production & (eu-central | eu-west)”。下面的显示了三个配置文件示例:

1
2
3
4
5
6
7
8
9
10
11
 <springProfile name="dev">
<!-- 激活 dev 环境的配置 -->
</springProfile>

<springProfile name="dev | pre">
<!-- 激活 dev 和 pre 的环境变量 -->
</springProfile>

<springProfile name="!prod">
<!-- 所有非 prod 环境的都激活 -->
</springProfile>

环境属性

标记允许用户传递 Spring Environment 中的属性,以便在 Logback 中使用。比如在 Logback 配置中访问 application.properties 文件中的值。 的作用机制与 Logback 的标准 标签类似。但是,不是指定直接 value,而是指定属性的 source(来自Environment)。如果需要将属性存储在 local 范围以外的其他位置,则可以使用 scope 属性来控制。如果需要默认值(如果未在 Environment 中设置该属性),则可以使用 defaultValue 属性配置。以下示例描述了如何传递在 Logback 中使用的属性:

1
2
3
4
5
6
<springProperty scope="context" name="fluentHost" source="myapp.fluentd.host"
defaultValue="localhost"/>
<appender name="FLUENT" class="ch.qos.logback.more.appenders.DataFluentAppender">
<remoteHost>${fluentHost}</remoteHost>
...
</appender>

前面基于 SpringBoot 官方文档对于 Logger 的支持描述做了简单的介绍,下面将通过分析源码来深入的掌握上述这些特性。本文以 log4j2 为例进行分析。

SpringBoot 系列-事件机制详解 文章中其实有提到过 logging 初始化的时机。这里简单回顾下:

1
2
3
4
5
# Application Listeners
org.springframework.context.ApplicationListener=\
// 省略其他
org.springframework.boot.context.logging.ClasspathLoggingApplicationListener,\
org.springframework.boot.context.logging.LoggingApplicationListener,\

这两个 logging 的监听器中,主要作用的是 LoggingApplicationListener ,这个监听器就是 SpringBoot 中日志初始化的入口。

日志初始化入口

LoggingApplicationListener 继承了 GenericApplicationListener 这个接口,其父接口是 ApplicationListener,GenericApplicationListener 中扩展了对于事件类型的支持判断。这里主要关心的是 onApplicationEvent 这个回调方法,关于这个方法中所提到的几个事件类型,可以参考 SpringBoot 系列-事件机制详解 这篇文章的介绍。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
@Override
public void onApplicationEvent(ApplicationEvent event) {
// ApplicationStartingEvent
if (event instanceof ApplicationStartingEvent) {
onApplicationStartingEvent((ApplicationStartingEvent) event);
}
// ApplicationEnvironmentPreparedEvent
else if (event instanceof ApplicationEnvironmentPreparedEvent) {
onApplicationEnvironmentPreparedEvent((ApplicationEnvironmentPreparedEvent) event);
}
// ApplicationPreparedEvent
else if (event instanceof ApplicationPreparedEvent) {
onApplicationPreparedEvent((ApplicationPreparedEvent) event);
}
// ContextClosedEvent
else if (event instanceof ContextClosedEvent
&& ((ContextClosedEvent) event).getApplicationContext().getParent() == null) {
onContextClosedEvent();
}
// ApplicationFailedEvent
else if (event instanceof ApplicationFailedEvent) {
onApplicationFailedEvent();
}
}

ApplicationStartingEvent 阶段的处理

在收到 ApplicationStartingEvent 事件时,SpringBoot 将通过当前应用的 classloader 来构建一个 loggingSystem 对象,然后执行初始化之前的一些准备工作。

1
2
3
4
5
6
private void onApplicationStartingEvent(ApplicationStartingEvent event) {
// 通过当前应用的 classloader 构建 loggingSystem 对象
this.loggingSystem = LoggingSystem.get(event.getSpringApplication().getClassLoader());
// loggingSystem 初始化之前准备
this.loggingSystem.beforeInitialize();
}

这里可以来看下 loggingSystem 是如何被构建出来的,这个过程可以使得我们非常清楚的了解到,为什么通过引入日志框架依赖或者使用 org.springframework.boot.logging.LoggingSystem 配置能够自动的完成日志框架的选择。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
public static LoggingSystem get(ClassLoader classLoader) {
// SYSTEM_PROPERTY=org.springframework.boot.logging.LoggingSystem
// 这里先从系统变量中获取下 org.springframework.boot.logging.LoggingSystem,看下是否用户自己指定了 LoggingSystem 的类型
String loggingSystem = System.getProperty(SYSTEM_PROPERTY);
// 如果 org.springframework.boot.logging.LoggingSystem=xx 有配置值
if (StringUtils.hasLength(loggingSystem)) {
// 是否配置的是 none
if (NONE.equals(loggingSystem)) {
// 如果配置的是 none ,则返回 NoOpLoggingSystem
return new NoOpLoggingSystem();
}
// 根据指定的日志类型通过反射创建 loggingSystem 对象
return get(classLoader, loggingSystem);
}
return SYSTEMS.entrySet().stream().filter((entry) -> ClassUtils.isPresent(entry.getKey(), classLoader))
.map((entry) -> get(classLoader, entry.getValue())).findFirst()
.orElseThrow(() -> new IllegalStateException("No suitable logging system located"));
}

上面代码的最后基于 SYSTEMS 一个 Map 结构的数据进行一系列的处理,主要就是通过判断 entry.getKey() 是否在当前 classpath 中存在,如果存在则通过反射构建类型为 entry.getValue() 的对象;SYSTEMS 是 LoggingSystem 抽象类中的一个静态的 MAP 结构变量,其初始化是在静态代码块中完成的:

1
2
3
4
5
6
7
8
9
10
11
static {
Map<String, String> systems = new LinkedHashMap<>();
// 添加 logback 的 LoggingSystem
systems.put("ch.qos.logback.core.Appender", "org.springframework.boot.logging.logback.LogbackLoggingSystem");、
// 添加 log4j2 的 LoggingSystem
systems.put("org.apache.logging.log4j.core.impl.Log4jContextFactory",
"org.springframework.boot.logging.log4j2.Log4J2LoggingSystem");
// 添加 JUL 的 LoggingSystem
systems.put("java.util.logging.LogManager", "org.springframework.boot.logging.java.JavaLoggingSystem");
SYSTEMS = Collections.unmodifiableMap(systems);
}

这样看来就比较清晰,如果当前 classpath 中存在 logback、log4j2 或者 JUL 的依赖,则就构建对应的 LoggingSystem 对象。LoggingSystem 对象构建之后还会调用 beforeInitialize 方法,假设引入的是 log4j2 的依赖,则最后构建的 LoggingSystem 就是 Log4J2LoggingSystem 。beforeInitialize 是 LoggingSystem 提供的抽象方法,其具体实现是由子类实现。下面在源码分析部分会展开分析。

ApplicationEnvironmentPreparedEvent 阶段的处理

接收到 ApplicationEnvironmentPreparedEvent 事件说明 Environment 对象已经构建完成,环境变量都已经初始化完成了。所以这里主要的工作就是初始化日志框架。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
private void onApplicationEnvironmentPreparedEvent(ApplicationEnvironmentPreparedEvent event) {
// 这里会再 check 一次loggingSystem 是否已经被创建
if (this.loggingSystem == null) {
this.loggingSystem = LoggingSystem.get(event.getSpringApplication().getClassLoader());
}
// 通过环境和类路径表达的首选项初始化日志系统。
initialize(event.getEnvironment(), event.getSpringApplication().getClassLoader());
}
// initialize
protected void initialize(ConfigurableEnvironment environment, ClassLoader classLoader) {
// Spring 环境转移到系统属性
new LoggingSystemProperties(environment).apply();
// 解析得到 logFile,依赖 logging.file 和 loggin.path 两个配置值
this.logFile = LogFile.get(environment);
if (this.logFile != null) {
//设置logging.file->LOG_FILE
// loggin.path -> LOG_PATH
this.logFile.applyToSystemProperties();
}
initializeEarlyLoggingLevel(environment);
// 根据 log 的配置文件初始化 日志
initializeSystem(environment, this.loggingSystem, this.logFile);
// 绑定 logging.group , 设置 logging.level
initializeFinalLoggingLevels(environment, this.loggingSystem);
// 注册 logging.register-shutdown-hook 配置的 钩子
registerShutdownHookIfNecessary(environment, this.loggingSystem);
}

这个阶段就是根据我们配置的日志相关的属性和配置文件对日志进行一系列的初始化工作,这里所涉及到的属性和配置在文章前面部分均有提及到。

ApplicationPreparedEvent 阶段的处理

接收到 ApplicationPreparedEvent 事件表示应用程序已经准备好,这里会注册两个 bean , 一个是 springBootLoggingSystem,一个是 pringBootLogFile 。

1
2
3
4
5
6
7
8
9
10
11
private void onApplicationPreparedEvent(ApplicationPreparedEvent event) {
ConfigurableListableBeanFactory beanFactory = event.getApplicationContext().getBeanFactory();
// 注册 springBootLoggingSystem bean
if (!beanFactory.containsBean(LOGGING_SYSTEM_BEAN_NAME)) {
beanFactory.registerSingleton(LOGGING_SYSTEM_BEAN_NAME, this.loggingSystem);
}
// 注册 pringBootLogFile bean
if (this.logFile != null && !beanFactory.containsBean(LOGFILE_BEAN_NAME)) {
beanFactory.registerSingleton(LOGFILE_BEAN_NAME, this.logFile);
}
}

ContextClosedEvent 和 ApplicationFailedEvent

ContextClosedEvent 事件是 Spring 容器关闭时发送的事件,这里主要就是在 Spring 容器关闭时对日志系统做的一些清理操作;ApplicationFailedEvent 是应用启动失败发送的事件,这里也会对日志系统做清理操作。清理方法由各个子 LoggingSystem 提供具体的实现,以 log4j2 为例,log4j2 的清理主要包括注销桥接处理器(前面初始化阶段有提到)、LogContext 置为null、移除 FILTER,基本上就是初始化阶段的逆过程。

LoggingSystem 分析

LoggingSystem 是 SpringBoot 对日志框架进行的一层抽象封装,LoggingSystem 使得我们可以很方便地使用一些日志框架,只需要定义对应日志框架的配置文件,比如 Logback、Log4j、Log4j2 等,代码内部便可以直接使用。

上图为 LoggingSystem 的类继承结构,可以看到 LoggingSystem 的实现子类有 Logback(LogbackLoggingSystem)、Log4j2(Log4J2LoggingSystem)以及 JDK 内置的 Log (JavaLoggingSystem)。LoggingSystem 是个抽象类,内部有这几个方法:

  • beforeInitialize:日志系统初始化之前需要处理的事情
  • initialize:初始化日志系统
  • cleanUp:日志系统的清除工作
  • getShutdownHandler:返回一个 Runnable 用于当 jvm 退出的时候处理日志系统关闭后需要进行的操作,默认返回 null
  • setLogLevel:设置 logger 的级别

这几个方法在上面分析启动入口和日志初始化时都有看到,上述几个方法在 LoggingSystem 要么是抽象方法,要么是空实现,均需要有具体的子类来完成的具体日志框架的处理。从类继承结构图看到有一个 AbstractLoggingSystem,日志实现子类都是继承自这个类,而这个类也是一个抽象类,它又是 LoggingSystem 的子类。所以下面就分别看下 AbstractLoggingSystem 和 Log4J2LoggingSystem 两个类是怎么重写上述几个方法的,这也是 SpringBoot 中日志框架处理的核心逻辑。

AbstractLoggingSystem 处理逻辑

beforeInitialize 在 AbstractLoggingSystem 中没有具体的处理逻辑,是个空方法,所以主要是看下 initialize 这个方法.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
@Override
public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) {
// 如果指定了日志配置文件,则通过此配置文件进行初始化
if (StringUtils.hasLength(configLocation)) {
initializeWithSpecificConfig(initializationContext, configLocation, logFile);
return;
}
// 没有指定配置文件,则使用默认的方式查找配置文件并加载
initializeWithConventions(initializationContext, logFile);
}
// 通过指定的配置文件初始化
private void initializeWithSpecificConfig(LoggingInitializationContext initializationContext, String configLocation,
LogFile logFile) {
// 这里会处理日志配置文件中的占位符
configLocation = SystemPropertyUtils.resolvePlaceholders(configLocation);
// 抽象方法,由具体子类实现(不同的日志框架处理配置文件的方式由其自身决定)
loadConfiguration(initializationContext, configLocation, logFile);
}
// 通过默认方式查找配置文件并初始化
private void initializeWithConventions(LoggingInitializationContext initializationContext, LogFile logFile) {
// 查找配置文件,以 log4j2 为例,默认会在 classpath 下查找文件名为
// log4j2.properties、log4j2.yaml, log4j2.yml、log4j2.json,log4j2.jsn,log4j2.xml 的文件
String config = getSelfInitializationConfig();
if (config != null && logFile == null) {
// 发生了自初始化,在属性发生变化时重新初始化
reinitialize(initializationContext);
return;
}
if (config == null) {
// 查找 Spring 规则方式的配置,
// log4j2-spring.properties、log4j2-spring.xml 等
config = getSpringInitializationConfig();
}
if (config != null) {
loadConfiguration(initializationContext, config, logFile);
return;
}
// 抽象方法,由具体的日志系统实现
loadDefaults(initializationContext, logFile);
}

initialize 里主要就是找配置文件,然后通过配置文件进行日志系统的初始化,如果找不到就使用日志系统提供的默认方式进行初始化。上面代码中关于如何 load 配置文件和 load 默认都是在子类中实现的。所以下面就看下在 log4j2 的情况下,是怎么玩的。

Log4J2LoggingSystem 处理逻辑

Log4J2LoggingSystem 并非是 AbstractLoggingSystem 的直接子类,而是 Slf4JLoggingSystem 的直接子类,Slf4JLoggingSystem 这个抽象类从代码来看其实就是为了做一些桥接处理,这里不展开分析。

beforeInitialize 在 Log4J2LoggingSystem 中的实现

1
2
3
4
5
6
7
8
9
10
11
12
13
@Override
public void beforeInitialize() {
// 创建、获取 LoggerContext 对象
LoggerContext loggerContext = getLoggerContext();
// 判断当前 LoggerContext 是否已经初始化过了,如果已经初始化过了则直接返回
if (isAlreadyInitialized(loggerContext)) {
return;
}
// 调用父类 Slf4JLoggingSystem 的 beforeInitialize 的方法,父类这个方法主要就是配置JDK Logging 的桥接处理器
super.beforeInitialize();
// 给 loggerContext 添加默认的 FILTER
loggerContext.getConfiguration().addFilter(FILTER);
}

getLoggerContext 是 log4j2 自己构建 LoggerContext 的过程,此处就先 pass。

initialize 在 Log4J2LoggingSystem 中的实现

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
@Override
public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) {
// 拿到当前 loggerContext
LoggerContext loggerContext = getLoggerContext();
// 判断下是否已经初始化过了
if (isAlreadyInitialized(loggerContext)) {
return;
}
// 移除默认的 FILTER
loggerContext.getConfiguration().removeFilter(FILTER);
// 调用父类 initialize,就是在找日志配置文件并且初始化
super.initialize(initializationContext, configLocation, logFile);
// 标记已经完成初始化
markAsInitialized(loggerContext);
}

这里核心 initialize方法 还是使用的父类的处理逻辑,前面也提到 initialize 在 AbstractLoggingSystem 中最核心的是 load 配置配置文件的过程(loadConfiguration/loadDefaults),而这个 load 的过程是子类实现的。所以下面就看下 log4j2 中 load 配置文件的过程。

  • loadConfiguration:有配置文件的情况
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
protected void loadConfiguration(String location, LogFile logFile) {
Assert.notNull(location, "Location must not be null");
try {
LoggerContext ctx = getLoggerContext();
// 拿到资源url
URL url = ResourceUtils.getURL(location);
// 构建 ConfigurationSource 对象
ConfigurationSource source = getConfigurationSource(url);
// 这里会根据配置的类型选择不同的解析器来解析配置文件,比如
// XmlConfigurationFactory、PropertiesConfigurationFactory...
// 以指定的 configuration 启动
ctx.start(ConfigurationFactory.getInstance().getConfiguration(ctx, source));
}
catch (Exception ex) {
throw new IllegalStateException("Could not initialize Log4J2 logging from " + location, ex);
}
}

简单概括:通过指定的配置文件地址构建 ConfigurationSource 配置资源对象,然后根据配置资源的文件类型选择不同的 ConfigurationFactory 来解析配置文件,最后日志框架根据此配置文件初始化日志系统。

  • loadDefaults:没有配置文件的情况
1
2
3
4
5
6
7
8
9
10
11
@Override
protected void loadDefaults(LoggingInitializationContext initializationContext, LogFile logFile) {
if (logFile != null) {
// 使用 classpath:org/springframework/boot/logging/log4j2/log4j2-file.xml
loadConfiguration(getPackagedConfigFile("log4j2-file.xml"), logFile);
}
else {
// 使用 classpath:org/springframework/boot/logging/log4j2/log4j2.xml
loadConfiguration(getPackagedConfigFile("log4j2.xml"), logFile);
}
}

简单概括:在没有指定日志配置文件或者没有在 classpath 下找到符合指定日志系统的配置文件时,则使用 SpringBoot 提供的默认的配置文件进行初始化。

日志系统的清理逻辑

cleanUp 方法也是由具体的 LoggingSystem 实现,主要作用就是清理 LoggingSystem 资源。

1
2
3
4
5
6
7
8
9
10
@Override
public void cleanUp() {
// 调用父类,移除桥接器
super.cleanUp();
LoggerContext loggerContext = getLoggerContext();
// 标记loggerContext为未初始化状态,并将内部的 externalContext 置为 null
markAsUninitialized(loggerContext);
// 移除默认的 FILTER
loggerContext.getConfiguration().removeFilter(FILTER);
}

一些场景分析

这里面包括日常开发工作中使用日志的一些常见场景,比如项目中没有任何日志配置的情况、在 resources 目录下配置日志配置文件的情况、已经使用 SpringBoot 无法识别的日志篇日志文件的情况。

没有任何配置文件

没有任何配置,通过前面的分析可知,initialize 方法执行时,是找不到任何资源的,所以会走默认的 loadDefaults 方法进行加载,LogbackLoggingSystem 的loadDefaults 方法,由于 logFile 为 null,所以会使用 classpath:org/springframework/boot/logging/log4j2/log4j2.xml 这份配置文件:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
<Properties>
<Property name="PID">????</Property>
<Property name="LOG_EXCEPTION_CONVERSION_WORD">%xwEx</Property>
<Property name="LOG_LEVEL_PATTERN">%5p</Property>
<Property name="LOG_DATEFORMAT_PATTERN">yyyy-MM-dd HH:mm:ss.SSS</Property>
<Property name="CONSOLE_LOG_PATTERN">%clr{%d{${LOG_DATEFORMAT_PATTERN}}}{faint} %clr{${LOG_LEVEL_PATTERN}} %clr{${sys:PID}}{magenta} %clr{---}{faint} %clr{[%15.15t]}{faint} %clr{%-40.40c{1.}}{cyan} %clr{:}{faint} %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD}</Property>
<Property name="FILE_LOG_PATTERN">%d{${LOG_DATEFORMAT_PATTERN}} ${LOG_LEVEL_PATTERN} ${sys:PID} --- [%t] %-40.40c{1.} : %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD}</Property>
</Properties>
<Appenders>
// 打在控制台
<Console name="Console" target="SYSTEM_OUT" follow="true">
<PatternLayout pattern="${sys:CONSOLE_LOG_PATTERN}" />
</Console>
</Appenders>
<Loggers>
<Logger name="org.apache.catalina.startup.DigesterFactory" level="error" />
<Logger name="org.apache.catalina.util.LifecycleBase" level="error" />
<Logger name="org.apache.coyote.http11.Http11NioProtocol" level="warn" />
<logger name="org.apache.sshd.common.util.SecurityUtils" level="warn"/>
<Logger name="org.apache.tomcat.util.net.NioSelectorPool" level="warn" />
<Logger name="org.eclipse.jetty.util.component.AbstractLifeCycle" level="error" />
<Logger name="org.hibernate.validator.internal.util.Version" level="warn" />
<logger name="org.springframework.boot.actuate.endpoint.jmx" level="warn"/>
<Root level="info">
<AppenderRef ref="Console" />
</Root>
</Loggers>
</Configuration>

这份配置文件中值有一个 Appender,就是默认的 Console,所以没有配置任何日志配置文件时,日志会被打在控制台。

在 resources 目录下配置 log4j2.xml

这份配置文件是能够被 SpringBoot 识别的,所以在初始化日志时会使用此份配置文件来进行日志系统的初始化。下面这份配置文件为每种日志级别都配置了一个 appender,所以在使用时,会根据日志级别将日志打在不同的日志目录下。(PS:关于能够识别的日志配置文件参考前面的分析)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
<?xml version="1.0" encoding="UTF-8"?>
<configuration status="OFF">

<Properties>
<Property name="logging.path">./logs</Property>
</Properties>

<appenders>
<Console name="Console" target="SYSTEM_OUT">
<!--只接受程序中 INFO 级别的日志进行处理 -->
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY" />
<PatternLayout pattern="[%d{HH:mm:ss.SSS}] %-5level %class{36} %L %M - %msg%xEx%n" />
</Console>
<!--处理DEBUG级别的日志,并把该日志放到logs/debug.log文件中-->
<!--打印出DEBUG级别日志,每次大小超过size,则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩,作为存档-->
<RollingFile name="RollingFileDebug" fileName="${logging.path}/debug.log"
filePattern="logs/$${date:yyyy-MM}/debug-%d{yyyy-MM-dd}-%i.log.gz">
<Filters>
<ThresholdFilter level="DEBUG"/>
<ThresholdFilter level="INFO" onMatch="DENY" onMismatch="NEUTRAL"/>
</Filters>
<PatternLayout
pattern="[%d{yyyy-MM-dd HH:mm:ss}] %-5level %class{36} %L %M - %msg%xEx%n"/>
<Policies>
<SizeBasedTriggeringPolicy size="500 MB"/>
<TimeBasedTriggeringPolicy/>
</Policies>
</RollingFile>

<!--处理INFO级别的日志,并把该日志放到logs/info.log文件中-->
<RollingFile name="RollingFileInfo" fileName="${logging.path}/info.log"
filePattern="logs/$${date:yyyy-MM}/info-%d{yyyy-MM-dd}-%i.log.gz">
<Filters>
<!--只接受INFO级别的日志,其余的全部拒绝处理-->
<ThresholdFilter level="INFO"/>
<ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL"/>
</Filters>
<PatternLayout
pattern="[%d{yyyy-MM-dd HH:mm:ss}] %-5level %class{36} %L %M - %msg%xEx%n"/>
<Policies>
<SizeBasedTriggeringPolicy size="500 MB"/>
<TimeBasedTriggeringPolicy/>
</Policies>
</RollingFile>

<!--处理WARN级别的日志,并把该日志放到logs/warn.log文件中-->
<RollingFile name="RollingFileWarn" fileName="${logging.path}/warn.log"
filePattern="logs/$${date:yyyy-MM}/warn-%d{yyyy-MM-dd}-%i.log.gz">
<Filters>
<ThresholdFilter level="WARN"/>
<ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL"/>
</Filters>
<PatternLayout
pattern="[%d{yyyy-MM-dd HH:mm:ss}] %-5level %class{36} %L %M - %msg%xEx%n"/>
<Policies>
<SizeBasedTriggeringPolicy size="500 MB"/>
<TimeBasedTriggeringPolicy/>
</Policies>
</RollingFile>

<!--处理error级别的日志,并把该日志放到logs/error.log文件中-->
<RollingFile name="RollingFileError" fileName="${logging.path}/error.log"
filePattern="logs/$${date:yyyy-MM}/error-%d{yyyy-MM-dd}-%i.log.gz">
<ThresholdFilter level="ERROR"/>
<PatternLayout
pattern="[%d{yyyy-MM-dd HH:mm:ss}] %-5level %class{36} %L %M - %msg%xEx%n"/>
<Policies>
<SizeBasedTriggeringPolicy size="500 MB"/>
<TimeBasedTriggeringPolicy/>
</Policies>
</RollingFile>
</appenders>

<loggers>
<root level="DEBUG">
<appender-ref ref="Console"/>
<appender-ref ref="RollingFileInfo"/>
<appender-ref ref="RollingFileWarn"/>
<appender-ref ref="RollingFileError"/>
<appender-ref ref="RollingFileDebug"/>
</root>

<!--log4j2 自带过滤日志-->
<Logger name="org.apache.catalina.startup.DigesterFactory" level="error" />
<Logger name="org.apache.catalina.util.LifecycleBase" level="error" />
<Logger name="org.apache.coyote.http11.Http11NioProtocol" level="warn" />
<logger name="org.apache.sshd.common.util.SecurityUtils" level="warn"/>
<Logger name="org.apache.tomcat.util.net.NioSelectorPool" level="warn" />
<Logger name="org.crsh.plugin" level="warn" />
<logger name="org.crsh.ssh" level="warn"/>
<Logger name="org.eclipse.jetty.util.component.AbstractLifeCycle" level="error" />
<Logger name="org.hibernate.validator.internal.util.Version" level="warn" />
<logger name="org.thymeleaf" level="warn"/>
<Logger name="org.springframework" level="warn"/>
</loggers>
</configuration>

在 resources 下配置一个 log4j2-glmapper.xml

将上面的配置文件重命名为 log4j2-glmapper.xml ,因为这个命名规则是 SpringBoot 无法默认识别的,所以在日志配置文件加载时和场景一是一样的。如果希望这份配置文件能够被识别,可以使用 logging.config 来指定。

1
logging.config=classpath:log4j2-glmapper.xml

小结

本篇对 SpringBoot 中的日志进行了系统的介绍和分析,文章主要是了解 SpringBoot 中对于日志系统的处理,所以不会太关注日志系统自身的一些处理逻辑,有兴趣的读者可以自行研究或者联系作者一起沟通。

原文作者:GuoLei Song

原文链接:http://www.glmapper.com/2019/12/14/springboot-series-log/

发表日期:December 14th 2019, 11:17:40 am

更新日期:April 5th 2020, 7:44:00 pm

版权声明:转载请注明出处

CATALOG
  1. 1. 日志格式
  2. 2. Console 输出
  3. 3. 彩色编码输出
  4. 4. 文件输出
  5. 5. 日志级别
  6. 6. 日志 Groups
  7. 7. 自定义日志配置
  8. 8. springProfile 配置
  9. 9. 环境属性
  10. 10. 日志初始化入口
    1. 10.1. ApplicationStartingEvent 阶段的处理
    2. 10.2. ApplicationEnvironmentPreparedEvent 阶段的处理
    3. 10.3. ApplicationPreparedEvent 阶段的处理
    4. 10.4. ContextClosedEvent 和 ApplicationFailedEvent
  11. 11. LoggingSystem 分析
    1. 11.1. AbstractLoggingSystem 处理逻辑
    2. 11.2. Log4J2LoggingSystem 处理逻辑
      1. 11.2.1. beforeInitialize 在 Log4J2LoggingSystem 中的实现
      2. 11.2.2. initialize 在 Log4J2LoggingSystem 中的实现
    3. 11.3. 日志系统的清理逻辑
  12. 12. 一些场景分析
    1. 12.1. 没有任何配置文件
    2. 12.2. 在 resources 目录下配置 log4j2.xml
    3. 12.3. 在 resources 下配置一个 log4j2-glmapper.xml
  13. 13. 小结