稀土掘金技术社区

十年经验竟不懂Springboot日志

前言

日志,是开发中熟悉又陌生的伙伴,熟悉是因为我们经常会在各种场合打印日志,陌生是因为大部分时候我们都不太关心日志是怎么打印出来的,因为打印一条日志,在我们看来是一件太平常不过的事情了,特别是在宇宙第一框架「Springboot」的加持下,日志打印是怎么工作的就更没人关注了。

但是了解日志框架怎么工作,以及学会「Springboot」怎么和「Log4j2」或「Logback」等日志框架集成,对我们扩展日志功能以及优雅打印日志大有好处,甚至在有些场景,还能通过调整日志的打印策略来提升我们的系统吞吐量。所以本文将以「Springboot」集成「Log4j2」为例,详细说明「Springboot」框架下「Log4j2」是如何工作的,你可能会担心,如果是使用「Logback」日志框架该怎么办呢,其实「Log4j2」和「Logback」极其相似,「Springboot」在启动时处理「Log4j2」和处理「Logback」也几乎是一样的套路,所以学会「Springboot」框架下「Log4j2」如何工作,切换成「Logback」也是轻轻松松的。

本文遵循一个该深则深,该浅则浅的整体指导方针,全方位的阐述「Springboot」中日志怎么工作,思维导图如下所示。

Image

「Springboot」版本:「2.7.2」
「Log4j2」版本:「2.17.2」

正文

一. Log4j2简单工作原理分析

使用「Log4j2」打印日志时,我们自己接触最多的就是「Logger」对象了,「Logger」对象叫做日志打印器,负责打印日志,一个「Logger」对象,结构简单示意如下。

Image

实际打印日志的是「Logger」对象使用的「Appender」对象,至于「Appender」对象怎么打印日志,不在我们本文的关注范围内。特别注意,在「Log4j2」中,「Logger」对象实际只是一个壳子,灵魂是其持有的「LoggerConfig」对象,「LoggerConfig」决定打印时使用哪些「Appender」对象,以及「Logger」的级别。

「LoggerConfig」和「Appender」通常是在「Log4j2」的配置文件中定义出来的,配置文件通常命名为「Log4j2.xml」,「Log4j2」框架在初始化时,会去加载这个配置文件并解析成一个配置对象「Configuration」,示意如下。

Image

我们每在配置文件的<「Appenders」>标签下增加一项,解析得到的「Configuration」的「appenders」中就多一个「Appender」,每在<「Loggers」>标签下增加一项,解析得到的「Configuration」的「loggerConfigs」中就多一个「LoggerConfig」,并且「LoggerConfig」解析出来时,其和「Appender」的关系也就确认了。

在「Log4j2」中,还有一个「LoggerContext」对象,这个对象持有上述的「Configuration」对象,我们使用的每一个「Logger」,一开始都会先去「LoggerContext」的「loggerRegistry」中获取,如果没有,则会创建一个「Logger」出来再缓存到「LoggerContext」的「loggerRegistry」中,同时我们在创建「Logger」时其实核心就是要为这个创建的「Logger」找到它对应的「LoggerConfig」,那么去哪里找「LoggerConfig」呢,当然就是去「Configuration」中找,所以「Logger」,「LoggerContext」和「Configuration」的关系可以描述成下面这样子。

Image

所以「Log4j2」在这种结构下,要修改日志打印器是十分方便的,我们通过「LoggerContext」就可以拿到「Configuration」,拿到「Configuration」之后,我们就可以方便的操作「LoggerConfig」了,例如最常用的日志打印器级别热更新就是这么完成的。

在继续阅读后文之前,有一个很重要的概念需要阐述清楚,那就是对于「Springboot」来说,「Springboot」在操作「Logger」时,操作的对象就是一个「Logger」,比如要给一个名字为「com.honey.Login」的「Logger」设置级别为「DEBUG」,那么在「Springboot」看来,它就是在设置名字为「com.honey.Login」的「Logger」的级别为「DEBUG」,但是具体到「Log4j2」框架,其实底层是在设置名字为「com.honey.Login」的「LoggerConfig」的级别为「DEBUG」,而具体到「Logback」框架,就是在设置名字为「com.honey.Login」的「Logger」的级别为「DEBUG」。

二. Springboot日志简单配置说明

我们在「Springboot」中使用「Log4j2」时,虽然大部分时候我们还是会提供一个「Log4j2.xml」文件来供「Log4j2」框架读取,但是「Springboot」也提供了一些配置来供我们使用,在分析「Springboot」日志启动机制前,先学习一下里面的若干配置项可以方便我们后续的机制理解。

1. logging.file.name

假如我们像下面这样配置。

logging:
  file:
    name: test.log

那么「Springboot」会把日志内容输出一份到当前项目根路径下的「test.log」文件中。

2. logging.file.path

假如我们像下面这样配置。

logging:
  file:
    path: /

那么「Springboot」会把日志内容输出一份到指定目录下的「spring.log」文件中。

3. logging.level

假如我们像下面这样配置。

logging:
  level:
    com.pww.App: warn

那么我们可以指定名称为「com.pww.App」的日志打印器的级别为「warn」级别。

三. Springboot日志启动机制分析

通常我们使用「Springboot」时,就算不提供「Log4j2.xml」配置文件,「Springboot」也能输出很漂亮的日志,那么「Springboot」肯定在背后有帮我们完成「Log4j2」或「Logback」等框架的初始化,那么本节就刨析一下「Springboot」中的日志启动机制。

「Springboot」中的日志启动主要依赖于「LoggingApplicationListener」,这个监听器在「Springboot」启动流程中主要会监听如下三个事件。

  • 「ApplicationStartingEvent」。在启动「SpringApplication」之后就发布该事件,先于「Environmen」和「ApplicationContext」可用之前发布;
  • 「ApplicationEnvironmentPreparedEvent」。在「Environmen」准备好之后立即发布;
  • 「ApplicationPreparedEvent」。在「ApplicationContext」完全准备好之后但刷新容器之前发布。

下面依次分析下监听到这些事件后,「LoggingApplicationListener」会完成一些什么事情来帮助初始化日志框架。

1. 监听到ApplicationStartingEvent

「LoggingApplicationListener」的「onApplicationStartingEvent()」 方法如下所示。

private void onApplicationStartingEvent(ApplicationStartingEvent event) {
    // 读取org.springframework.boot.logging.LoggingSystem系统属性来加载得到LoggingSystem
    this.loggingSystem = LoggingSystem.get(event.getSpringApplication().getClassLoader());
    // 调用LoggingSystem的beforeInitialize()方法提前做一些初始化准备工作
    this.loggingSystem.beforeInitialize();
}

「Springboot」中操作日志的最关键的一个对象就是「LoggingSystem」,这个对象会在「Springboot」的整个生命周期中掌控着日志,在「LoggingApplicationListener」监听到「ApplicationStartingEvent」事件后,第一件事情就是先读取「org.springframework.boot.logging.LoggingSystem」系统属性,得到要加载的「LoggingSystem」的全限定名,然后完成加载。如果是使用「Log4j2」框架,对应的「LoggingSystem」是「Log4J2LoggingSystem」,如果是使用「Logback」框架,对应的「LoggingSystem」是「LogbackLoggingSystem」,当然我们也可以在「LoggingApplicationListener」监听到「ApplicationStartingEvent」事件之前,提前把「org.springframework.boot.logging.LoggingSystem」设置为我们自己提供的「LoggingSystem」的全限定名,这样我们就可以对「Springboot」中的日志初始化做一些定制修改。

拿到「LoggingSystem」后,就会调用其「beforeInitialize()」 方法来完成日志框架初始化前的一些准备,这里看一下「Log4J2LoggingSystem」的「beforeInitialize()」 方法实现,如下所示。

@Override
public void beforeInitialize() {
    LoggerContext loggerContext = getLoggerContext();
    if (isAlreadyInitialized(loggerContext)) {
        return;
    }
    super.beforeInitialize();
    // 添加一个过滤器
    // 这个过滤器会阻止所有日志的打印
    loggerContext.getConfiguration().addFilter(FILTER);
}

上述方法最关键的就是添加了一个过滤器,虽然叫做过滤器,但是实则为阻断器,因为这个「FILTER」会阻止所有日志打印,「Springboot」这样设计是为了防止日志系统在完全完成初始化前打印出不可控的日志。

所以小结一下,「LoggingApplicationListener」监听到「ApplicationStartingEvent」之后,主要完成两件事情。

  1. 从系统属性中拿到「LoggingSystem」的全限定名并完成加载;
  2. 调用「LoggingSystem」的「beforeInitialize()」 方法来添加会拒绝打印任何日志的过滤器以阻止日志打印。

2. 监听到ApplicationEnvironmentPreparedEvent

「LoggingApplicationListener」的「onApplicationEnvironmentPreparedEvent()」 方法如下所示。

private void onApplicationEnvironmentPreparedEvent(ApplicationEnvironmentPreparedEvent event) {
    SpringApplication springApplication = event.getSpringApplication();
    if (this.loggingSystem == null) {
        this.loggingSystem = LoggingSystem.get(springApplication.getClassLoader());
    }
    // 因为此时Environment已经完成了加载
    // 获取到Environment并继续调用initialize()方法
    initialize(event.getEnvironment(), springApplication.getClassLoader());
}

继续跟进「LoggingApplicationListener」的「initialize()」 方法。

protected void initialize(ConfigurableEnvironment environment, ClassLoader classLoader) {
    // 把通过logging.xxx配置的值设置到系统属性中
    getLoggingSystemProperties(environment).apply();
    this.logFile = LogFile.get(environment);
    if (this.logFile != null) {
        // 把logging.file.name和logging.file.path的值设置到系统属性中
        this.logFile.applyToSystemProperties();
    }
    // 基于预置的web和sql日志打印器初始化LoggerGroups
    this.loggerGroups = new LoggerGroups(DEFAULT_GROUP_LOGGERS);
    // 读取配置中的debug和trace是否设置为true
    // 哪个为true就把springBootLogging级别设置为什么
    // 同时设置为true则trace优先级更高
    initializeEarlyLoggingLevel(environment);
    // 调用到具体的LoggingSystem实际初始化日志框架
    initializeSystem(environment, this.loggingSystem, this.logFile);
    // 完成日志打印器组和日志打印器的级别的设置
    initializeFinalLoggingLevels(environment, this.loggingSystem);
    registerShutdownHookIfNecessary(environment, this.loggingSystem);
}

上述方法概括下来就是做了三部分的事情。

  1. 把日志相关配置设置到系统属性中。例如我们可以通过「logging.pattern.console」来配置标准输出日志格式,但是在「XML」文件里面没办法读取到「logging.pattern.console」配置的值,此时就需要设置一个系统属性,属性名是「CONSOLE_LOG_PATTERN」,属性值是「logging.pattern.console」配置的值,后续在「XML」文件中就可以通过${「sys:CONSOLE_LOG_PATTERN」}读取到「logging.pattern.console」配置的值。下表是「Springboot」中日志配置和系统属性名的对应关系:

配置项系统属性名
「logging.exception-conversion-word」「EXCEPTION_CONVERSION_WORD」
「logging.pattern.console」「CONSOLE_LOG_PATTERN」
「logging.charset.console」「CONSOLE_LOG_CHARSET」
「logging.pattern.dateformat」「LOG_DATEFORMAT_PATTERN」
「logging.pattern.file」「FILE_LOG_PATTERN」
「logging.charset.file」「FILE_LOG_CHARSET」
「logging.pattern.level」「LOG_LEVEL_PATTERN」
「logging.file.name」「LOG_FILE」
「logging.file.path」「LOG_PATH」
  1. 调用「LoggingSystem」的「initialize()」 方法来完成日志框架初始化。这里就是实际完成「Log4j2」或「Logback」等框架的初始化;
  2. 在日志框架完成初始化后基于「logging.level」的配置来设置日志打印器组和日志打印器的级别。

上述第2点是「Springboot」如何完成具体的日志框架的初始化,这个在后面章节中会详细分析。上述第3点是日志框架初始化完毕后,「Springboot」如何帮助我们完成日志打印器组或日志打印器的级别的设置,这里就扯出来一个概念:日志打印器组,也就是「LoggerGroup」。

我们如果要操作一个「Logger」,那么实际就是要拿着这个「Logger」的名称,去找到「Logger」,然后再进行操作,这在「Logger」不多的时候是没问题的,但是假如我有几十上百个「Logger」呢,一个一个去找到「Logger」再操作无疑是很不现实的,一个实际的场景就是修改「Logger」的级别,如果是通过「Logger」的名字去找到「Logger」再修改级别,那么是很痛苦的一件事情,但是如果能够把所有「Logger」按照功能进行分组,我们一组一组的去修改,一下子就优雅起来了,「LoggerGroup」就是干这个事情的。

一个「LoggerGroup」,有三个字段,说明如下。

  1. 「name」。表示「LoggerGroup」的名字,要操作「LoggerGroup」时,就通过「name」来唯一确定一个「LoggerGroup」,假如有一个「LoggerGroup」名字为「login」,那么我们可以通过「logging.level.loggin=debug」,将这个「LoggerGroup」下所有的「Logger」的级别设置为「debug」;
  2. 「members」。是当前「LoggerGroup」里所有「Logger」的名字的集合;
  3. 「configuredLevel」。表示最近一次给「LoggerGroup」设置的级别。

在「Springboot」中,通过「logging.group」可以配置「LoggerGroup」,示例如下。

logging:
  group:
    login:
      - com.lee.controller.LoginController
      - com.lee.service.LoginService
      - com.lee.dao.LoginDao
    common:
      - com.lee.util
      - com.lee.config

结合「logging.level」可以直接给一组「Logger」设置级别,示例如下。

logging:
  level:
    login: info
    common: debug
  group:
    login:
      - com.lee.controller.LoginController
      - com.lee.service.LoginService
      - com.lee.dao.LoginDao
    common:
      - com.lee.util
      - com.lee.config

那么此时名称为「login」的「LoggerGroup」表示如下。

{
    "name": "login",
    "members": [
        "com.lee.controller.LoginController",
        "com.lee.service.LoginService",
        "com.lee.dao.LoginDao"
    ],
    "configuredLevel": "INFO"
}

名称为「common」的「LoggerGroup」表示如下。

{
    "name": "common",
    "members": [
        "com.lee.util",
        "com.lee.config"
    ],
    "configuredLevel": "DEBUG"
}

最后再看一下「Springboot」中预置的「LoggerGroup」,有两个,名字分别为「web」和「sql」,如下所示。

{
    "name": "web",
    "members": [
        "org.springframework.core.codec",
        "org.springframework.http",
        "org.springframework.web",
        "org.springframework.boot.actuate.endpoint.web",
        "org.springframework.boot.web.servlet.ServletContextInitializerBeans"
    ],
    "configuredLevel": ""
}
{
    "name": "sql",
    "members": [
        "org.springframework.jdbc.core",
        "org.hibernate.SQL",
        "org.jooq.tools.LoggerListener"
    ],
    "configuredLevel": ""
}

至于「web」和「sql」这两个「LoggerGroup」的级别是什么,有两种手段来指定,第一种是通过配置「debug=true」来将「web」和「sql」这两个「LoggerGroup」的级别指定为「DEBUG」,第二种是通过「logging.level.web」和「logging.level.sql」来指定「web」和「sql」这两个「LoggerGroup」的级别,其中第二种优先级高于第一种。

上面最后讲的这一点,其实就是告诉我们怎么来控制「Springboot」自己的相关的日志的打印级别,如果配置「debug=true」,那么如下的「Springboot」自己的「LoggerGroup」和「Logger」级别会设置为「debug」。

sql
web
org.springframework.boot

如果配置「trace=true」,那么如下的「Springboot」自己的「Logger」级别会设置为「trace」。

org.springframework
org.apache.tomcat
org.apache.catalina
org.eclipse.jetty
org.hibernate.tool.hbm2ddl

现在小结一下,监听到「ApplicationEnvironmentPreparedEvent」事件后,「Springboot」主要完成三件事情。

  1. 把通过配置文件配置的日志相关属性设置为系统属性;
  2. 实际完成日志框架的初始化;
  3. 设置「Springboot」和用户自定义的「LoggerGroup」与「Logger」级别。

3. 监听到ApplicationPreparedEvent

「LoggingApplicationListener」的「onApplicationPreparedEvent()」 方法如下所示。

private void onApplicationPreparedEvent(ApplicationPreparedEvent event) {
    ConfigurableListableBeanFactory beanFactory = event.getApplicationContext().getBeanFactory();
    if (!beanFactory.containsBean(LOGGING_SYSTEM_BEAN_NAME)) {
        // 把实际加载的LoggingSystem注册到容器中
        beanFactory.registerSingleton(LOGGING_SYSTEM_BEAN_NAME, this.loggingSystem);
    }
    if (this.logFile != null && !beanFactory.containsBean(LOG_FILE_BEAN_NAME)) {
        // 把实际使用的LogFile注册到容器中
        beanFactory.registerSingleton(LOG_FILE_BEAN_NAME, this.logFile);
    }
    if (this.loggerGroups != null && !beanFactory.containsBean(LOGGER_GROUPS_BEAN_NAME)) {
        // 把保存着所有LoggerGroup的LoggerGroups注册到容器中
        beanFactory.registerSingleton(LOGGER_GROUPS_BEAN_NAME, this.loggerGroups);
    }
}

主要就是把之前加载的「LoggingSystem」,「LogFile」和「LoggerGroups」添加到「Spring」容器中,进行到这里,其实整个日志框架已经完成初始化了,这里只是把一些和日志密切相关的一些对象注册为容器中的「bean」。

最后,本节以下图对「Springboot」日志启动流程做一个总结。

Image

四. Springboot集成Log4j2原理说明

在「Springboot」中使用「Log4j2」时,我们不提供「Log4j2」的配置文件也能打印日志,而我们提供了「Log4j2」的配置文件后日志打印行为又会以我们提供的配置文件为准,这里面其实「Springboot」为我们做了很多事情,当我们不提供「Log4j2」配置文件时,「Springboot」会加载其预置的配置文件,并且会根据我们是否配置了「logging.file.xxx」自动决定是加载预置的「log4j2.xml」还是「log4j2-file.xml」,而与此同时「Springboot」也会尽可能的去搜索我们提供的配置文件,无论我们在「classpath」下提供的配置文件名字是「Log4j2.xml」还是「Log4j2-spring.xml」,都是能够被「Springboot」搜索到并加载的。

上述的「Springboot」集成「Log4j2」的行为,全部发生在「Log4J2LoggingSystem」中,本节将对这里面的流程和原理进行说明。

在第三节中已经知道,「Springboot」启动时,当「LoggingApplicationListener」监听到「ApplicationEnvironmentPreparedEvent」事件后,最终会调用到「LoggingApplicationListener」的「initializeSystem()」 方法来完成日志框架的初始化,所以我们先看一下这里的逻辑是什么,源码实现如下。

private void initializeSystem(ConfigurableEnvironment environment, LoggingSystem system, LogFile logFile) {
    // 读取环境变量中的logging.config作为用户提供的配置文件路径
    String logConfig = StringUtils.trimWhitespace(environment.getProperty(CONFIG_PROPERTY));
    try {
        // 创建LoggingInitializationContext用于传递Environment对象
        LoggingInitializationContext initializationContext = new LoggingInitializationContext(environment);
        if (ignoreLogConfig(logConfig)) {
            // 1. 没有配置logging.config
            system.initialize(initializationContext, null, logFile);
        } else {
            // 2. 配置了logging.config
            system.initialize(initializationContext, logConfig, logFile);
        }
    } catch (Exception ex) {
        // 省略异常处理
    }
}

「LoggingApplicationListener」的「initializeSystem()」 方法会读取「logging.config」环境变量得到用户提供的配置文件路径,然后带着配置文件路径,调用到「Log4J2LoggingSystem」的「initialize()」 方法,所以后续分两种情况讨论,即没配置「logging.config」和有配置「logging.config」。

1. 没配置logging.config

「Log4J2LoggingSystem」的「initialize()」 方法如下所示。

@Override
public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) {
    LoggerContext loggerContext = getLoggerContext();
    // 判断LoggerContext的ExternalContext是不是当前LoggingSystem的全限定名
    // 如果是则表明当前LoggingSystem已经执行过初始化逻辑
    if (isAlreadyInitialized(loggerContext)) {
        return;
    }
    // 移除之前添加的防噪过滤器
    loggerContext.getConfiguration().removeFilter(FILTER);
    // 调用到父类AbstractLoggingSystem的initialize()方法
    // 注意因为没有配置logging.config所以这里configLocation为null
    super.initialize(initializationContext, configLocation, logFile);
    // 将当前LoggingSystem的全限定名设置给LoggerContext的ExternalContext
    // 表明当前LoggingSystem已经对LoggerContext执行过初始化逻辑
    markAsInitialized(loggerContext);
}

上述方法会继续调用到「AbstractLoggingSystem」的「initialize()」 方法,并且因为没有配置「logging.config」,所以传递过去的「configLocation」参数为「null」,下面看一下「AbstractLoggingSystem」的「initialize()」 方法的实现,如下所示。

@Override
public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) {
    if (StringUtils.hasLength(configLocation)) {
        initializeWithSpecificConfig(initializationContext, configLocation, logFile);
        return;
    }
    // 基于约定寻找配置文件并完成初始化
    initializeWithConventions(initializationContext, logFile);
}

因为「configLocation」为「null」,所以会继续调用到「initializeWithConventions()」 方法完成初始化,并且初始化使用到的配置文件,「Springboot」会按照约定的名字去「classpath」寻找,下面看一下「initializeWithConventions()」 方法的实现。

private void initializeWithConventions(LoggingInitializationContext initializationContext, LogFile logFile) {
    // 搜索标准日志配置文件路径
    String config = getSelfInitializationConfig();
    if (config != null && logFile == null) {
        reinitialize(initializationContext);
        return;
    }
    if (config == null) {
        // 搜索Spring日志配置文件路径
        config = getSpringInitializationConfig();
    }
    if (config != null) {
        // 如果搜索到约定的配置文件则进行配置文件加载
        loadConfiguration(initializationContext, config, logFile);
        return;
    }
    // 如果搜索不到则使用LoggingSystem同目录下的配置文件
    loadDefaults(initializationContext, logFile);
}

上述方法中,首先会去搜索标准日志配置文件路径,其实就是判断「classpath」下是否存在如下名字的配置文件。

log4j2-test.properties
log4j2-test.json
log4j2-test.jsn
log4j2-test.xml
log4j2.properties
log4j2.json
log4j2.jsn
log4j2.xml

如果不存在,则再去搜索「Spring」日志配置文件路径,也就是判断「classpath」下是否存在如下名字的配置文件。

log4j2-test-spring.properties
log4j2-test-spring.json
log4j2-test-spring.jsn
log4j2-test-spring.xml
log4j2-spring.properties
log4j2-spring.json
log4j2-spring.jsn
log4j2-spring.xml

如果都找不到,此时「Springboot」就会将「Log4J2LoggingSystem」同目录下的「log4j2.xml」(无「LogFile」)或「log4j2-file.xml」(有「LogFile」)作为日志配置文件,所以不用担心找不到配置文件,有「Springboot」为我们进行兜底。在获取到配置文件路径后,最终会调用到「Log4J2LoggingSystem」如下的加载配置的方法。

protected void loadConfiguration(String location, LogFile logFile, List<String> overrides) {
    Assert.notNull(location, "Location must not be null");
    try {
        List<Configuration> configurations = new ArrayList<>();
        LoggerContext context = getLoggerContext();
        // 根据配置文件路径加载得到Configuration并添加到集合中
        configurations.add(load(location, context));
        // 加载logging.log4j2.config.override配置的配置文件为Configuration
        // 所有加载的Configuration都要添加到configurations集合中
        for (String override : overrides) {
            configurations.add(load(override, context));
        }
        // 如果得到了大于1个的Configuration则基于所有Configuration创建CompositeConfiguration
        Configuration configuration = (configurations.size() > 1) ? createComposite(configurations)
                : configurations.iterator().next();
        // 将加载得到的Configuration启动并设置给LoggerContext
        // 这里会将加载得到的Configuration覆盖LoggerContext持有的老的Configuration
        context.start(configuration);
    } catch (Exception ex) {
        throw new IllegalStateException("Could not initialize Log4J2 logging from " + location, ex);
    }
}

上述方法中实际就会拿着配置文件的路径去加载得到「Configuration」,与此同时还会拿到所有通过「logging.log4j2.config.override」配置的路径,去加载得到「Configuration」,最终如果得到大于1个的「Configuration」,则将这些「Configuration」创建为「CompositeConfiguration」。这里可能会有疑问,「logging.log4j2.config.override」到底是一个什么东西,其实不难发现,无论是通过「logging.config」指定了配置文件路径,还是按照「Springboot」约定提供了配置文件,亦或者使用了「Springboot」预置的配置文件,其实最终都只能得到一个配置文件路径然后得到一个「Configuration」,那么怎么才能加载多份配置文件呢,那就要通过「logging.log4j2.config.override」来指定多个配置文件路径,使用示例如下。

logging:
  config: classpath:Log4j2.xml
  log4j2:
    config:
      override:
        - classpath:Log4j2-custom1.xml
        - classpath:Log4j2-custom2.xml

如果按照上面这样配置,那么最终就会加载得到三个「Configuration」,然后再基于这三个「Configuration」创建得到一个「CompositeConfiguration」。

在加载得到「Configuration」之后,就会调用到「LoggerContext」的「start()」 方法完成「Log4j2」框架的初始化,那么这里其实会做如下三件事情。

  1. 调用「Configuration」的「start()」 方法完成配置对象的初始化。这里其实就是将我们在配置文件中定义的各种「Appedner」和「LoggerConfig」等都创建出来并完成启动;
  2. 将启动完毕的「Configuration」设置给「LoggerContext」。这里会把「LoggerContext」持有的老的「Configuration」覆盖掉,所以如果「LoggerContext」之前持有其它的「Configuration」,那么其实在「Springboot」日志初始化完毕后老的「Configuration」会被丢弃掉;
  3. 更新「Logger」。如果之前有已经创建好的「Logger」,那么就基于新的「Configuration」替换掉这些「Logger」持有的「LoggerConfig」。

至此,没配置「logging.config」时的初始化逻辑就分析完毕。

2. 有配置logging.config

有配置「logging.config」时,情况就变得简单了。还是从「Log4J2LoggingSystem」的「initialize()」 方法出发,跟一下源码。

@Override
public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) {
    LoggerContext loggerContext = getLoggerContext();
    if (isAlreadyInitialized(loggerContext)) {
        return;
    }
    loggerContext.getConfiguration().removeFilter(FILTER);
    // 调用到父类AbstractLoggingSystem的initialize()方法
    // 注意因为配置了logging.config所以这里configLocation不为null
    super.initialize(initializationContext, configLocation, logFile);
    markAsInitialized(loggerContext);
}

继续跟进「AbstractLoggingSystem」的「initialize()」 方法,如下所示。

@Override
public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) {
    if (StringUtils.hasLength(configLocation)) {
        // 基于指定的配置文件完成初始化
        initializeWithSpecificConfig(initializationContext, configLocation, logFile);
        return;
    }
    initializeWithConventions(initializationContext, logFile);
}

由于指定了配置文件,所以会调用到「AbstractLoggingSystem」的「initializeWithSpecificConfig()」 方法,该方法没有什么额外逻辑,最终会执行到和没配置「logging.config」时一样的「Log4J2LoggingSystem」的加载配置的方法,如下所示。

protected void loadConfiguration(String location, LogFile logFile, List<String> overrides) {
    Assert.notNull(location, "Location must not be null");
    try {
        List<Configuration> configurations = new ArrayList<>();
        LoggerContext context = getLoggerContext();
        // 根据配置文件路径加载得到Configuration并添加到集合中
        configurations.add(load(location, context));
        // 加载logging.log4j2.config.override配置的配置文件为Configuration
        // 所有加载的Configuration都要添加到configurations集合中
        for (String override : overrides) {
            configurations.add(load(override, context));
        }
        // 如果得到了大于1个的Configuration则基于所有Configuration创建CompositeConfiguration
        Configuration configuration = (configurations.size() > 1) ? createComposite(configurations)
                : configurations.iterator().next();
        // 将加载得到的Configuration启动并设置给LoggerContext
        // 这里会将加载得到的Configuration覆盖LoggerContext持有的老的Configuration
        context.start(configuration);
    } catch (Exception ex) {
        throw new IllegalStateException("Could not initialize Log4J2 logging from " + location, ex);
    }
}

所以配置了「logging.config」时,就会以「logging.config」指定的配置文件作为最终使用的配置文件,而不会去基于约定搜索配置文件,同时也不会去使用「LoggingSystem」同目录下预置的配置文件。

小结一下,「Springboot」集成「Log4j2」日志框架时,主要分为两种情况:

  1. 没配置「logging.config」。这种情况下,「Springboot」会基于约定努力去寻找符合的配置文件,如果找不到则会使用预置的配置文件且预置的配置文件需要在「LoggingSystem」的同目录下,拿到配置文件后就会加载为「Configuration」然后替换掉「LoggerContext」里的旧的「Configuration」,此时就完成日志框架初始化;
  2. 有配置「logging.config」。这种情况下,会将「logging.config」指定的配置文件加载为「Configuration」,然后替换掉「LoggerContext」里的旧的「Configuration」,此时就完成日志框架初始化。

无论有没有配置「logging.config」,都只能加载一个配置文件为「Configuration」,如果想加载多个「Configuration」,那么需要通过「logging.log4j2.config.override」配置多个配置文件路径,此时就能加载多个「Configuration」来初始化「Log4j2」日志框架了。

「Springboot」集成「Log4j2」日志框架的流程图如下所示。

Image

五. Springboot日志打印器级别热更新

在日志打印中,一条日志在发起打印时,会根据我们的指定携带一个日志级别,同时打印日志的日志打印器,也有一个级别,日志打印器只能打印级别高于或等于自身的日志。

由于日志打印时,日志级别是由代码决定的,所以日志级别除非改代码,否则无法改变,但是日志打印器的级别是可以随时更改的,最简单的方式就是通过配置环境变量来更改「logging.level」,此时我们的应用进程所处的容器就会重启,就可以读取到我们更改后的「logging.level」,最终完成日志打印器级别的修改。但是这种方式会使应用重启,导致流量受损,我们更希望的是通过一种热更新的方式来修改日志打印器的级别,「spring-boot-actuator」包中提供了「LoggersEndpoint」来完成日志打印器级别热更新,所以本节将结合「LoggersEndpoint」的简单使用和实现原理,说明一下「Springboot」中,如何热更新日志打印器级别。

1. LoggersEndpoint简单使用

「LoggersEndpoint」由「spring-boot-actuator」提供,可以暴露一些端点用于获取「Springboot」应用中的所有日志打印器信息及其级别信息以及热更新日志打印器级别,由于默认情况下,「LoggersEndpoint」暴露的端点只能通过「JMX」的方式访问,所以想要通过「HTTP」请求的方式访问到「LoggersEndpoint」,需要做如下配置。

management:
  server:
    address: 127.0.0.1
    port: 10999
  endpoints:
    web:
      base-path: /actuator
      exposure:
        include: loggers    # 设置LoggersEndpoint可以通过HTTP方式访问
  endpoint:
    loggers:
      enabled: true     # 打开LoggersEndpoint

按照上述这么配置,我们可以通过「GET」调用如下接口拿到当前所有的日志打印器的相关数据。

http://localhost:10999/actuator/loggers

获取数据如下所示。

{
    "levels": [
        "OFF",
        "FATAL",
        "ERROR",
        "WARN",
        "INFO",
        "DEBUG",
        "TRACE"
    ],
    "loggers": {
        "ROOT": {
            "configuredLevel": null,
            "effectiveLevel": "INFO"
        },
        "org.springframework.boot.actuate.autoconfigure.web.server": {
            "configuredLevel": null,
            "effectiveLevel": "DEBUG"
        },
        "org.springframework.http.converter.ResourceRegionHttpMessageConverter": {
            "configuredLevel": null,
            "effectiveLevel": "ERROR"
        }
    },
    "groups": {
        "web": {
            "configuredLevel": null,
            "members": [
                "org.springframework.core.codec",
                "org.springframework.http",
                "org.springframework.web",
                "org.springframework.boot.actuate.endpoint.web",
                "org.springframework.boot.web.servlet.ServletContextInitializerBeans"
            ]
        },
        "login": {
            "configuredLevel": "INFO",
            "members": [
                "com.lee.controller.LoginController",
                "com.lee.service.LoginService",
                "com.lee.dao.LoginDao"
            ]
        },
        "common": {
            "configuredLevel": "DEBUG",
            "members": [
                "com.lee.util",
                "com.lee.config"
            ]
        },
        "sql": {
            "configuredLevel": null,
            "members": [
                "org.springframework.jdbc.core",
                "org.hibernate.SQL",
                "org.jooq.tools.LoggerListener"
            ]
        }
    }
}

上述内容中,返回的「levels」表示当前支持的日志级别,返回的「loggers」表示当前所有日志打印器的级别信息,返回的「groups」表示当前所有日志打印器组的级别信息,但是请注意,上述示例中的「loggers」其实做了大量的删减,实际调用接口时得到的「loggers」里面的内容会非常非常多,因为所有的日志打印器的信息都会被输出出来。此外,上述内容中出现的「configuredLevel」字段表示当前日志打印器或日志打印器组被设置过的级别,也就是只要通过「LoggersEndpoint」给某个日志打印器或日志打印器组设置过级别,那么对应的「configuredLevel」字段就有值,最后上述内容中出现的「effectiveLevel」字段表示当前日志打印器正在生效的级别。

如果只想看某个日志打印器或日志打印器组的级别信息,可以调用如下的「GET」接口。

http://localhost:10999/actuator/loggers/{日志打印器名或日志打印器组名}

如果「pathVariable」是日志打印器名,那么会得到如下结果。

{
    "configuredLevel": null,
    "effectiveLevel": "INFO"
}

如果「pathVariable」是日志打印器组名,那么会得到如下结果。

{
    "configuredLevel": null,
    "members": [
        "org.springframework.core.codec",
        "org.springframework.http",
        "org.springframework.web",
        "org.springframework.boot.actuate.endpoint.web",
        "org.springframework.boot.web.servlet.ServletContextInitializerBeans"
    ]
}

除了查询日志打印器或日志打印器组的级别信息,「LoggersEndpoint」更重要的功能是设置级别,比如可以通过如下「POST」接口来设置级别。

http://localhost:10999/actuator/loggers/{日志打印器名或日志打印器组名}
{
 "configuredLevel": "DEBUG"
}

此时对应的***日志打印器***或**日志打印器组「的级别就会更新为设置的级别,并且其」configuredLevel也会更新为设置的级别。

2. LoggersEndpoint原理分析

这里主要关注「LoggersEndpoint」如何实现日志打印器级别的热更新。「LoggersEndpoint」实现日志打印器级别的热更新对应的端点方法如下所示。

@WriteOperation
public void configureLogLevel(@Selector String name, @Nullable LogLevel configuredLevel) {
    Assert.notNull(name, "Name must not be empty");
    // 先尝试获取到LoggerGroup
    LoggerGroup group = this.loggerGroups.get(name);
    if (group != null && group.hasMembers()) {
        // 如果能获取到LoggerGroup则对组下每个Logger热更新级别
        group.configureLogLevel(configuredLevel, this.loggingSystem::setLogLevel);
        return;
    }
    // 获取不到LoggerGroup则按照Logger来处理
    this.loggingSystem.setLogLevel(name, configuredLevel);
}

上述方法的「name」即可以是「Logger」的名称,也可以是「LoggerGroup」的名称,如果是「Logger」的名称,那么就基于「LoggingSystem」的「setLogLevel()」 方法来设置这个「Logger」的级别,如果是「LoggerGroup」的名称,那么就遍历这个组下所有的「Logger」,每个遍历到的「Logger」都基于「LoggingSystem」的「setLogLevel()」 方法来设置级别。

所以实际上「LoggersEndpoint」热更新日志打印器级别,还是依赖的对应日志框架的「LoggingSystem」。

3. Log4J2LoggingSystem热更新原理

由于本文是基于「Log4j2」日志框架进行讨论,所以这里选择分析「Log4J2LoggingSystem」的「setLogLevel()」 方法,来探究「Logger」级别如何热更新。

在开始分析前,有一点需要重申,那就是对于「Log4j2」来说,「Logger」只是壳子,灵魂是「Logger」持有的「LoggerConfig」,所以更新「Log4j2」里面的「Logger」的级别,其实就是要去更新其持有的「LoggerConfig」的级别。

「Log4J2LoggingSystem」的「setLogLevel()」 方法如下所示。

@Override
public void setLogLevel(String loggerName, LogLevel logLevel) {
    // 将LogLevel转换为Level
    setLogLevel(loggerName, LEVELS.convertSystemToNative(logLevel));
}

「LogLevel」是「Springboot」中的日志级别对象,「Level」是「Log4j2」的日志级别对象,所以需要先将「LogLevel」转换为「Level」,然后继续调用如下方法。

private void setLogLevel(String loggerName, Level level) {
    // 从Configuration中根据loggerName获取到对应的LoggerConfig
    LoggerConfig logger = getLogger(loggerName);
    if (level == null) {
        // 2. 移除LoggerConfig或设置LoggerConfig级别为null
        clearLogLevel(loggerName, logger);
    } else {
        // 1. 添加LoggerConfig或设置LoggerConfig级别
        setLogLevel(loggerName, logger, level);
    }
    // 3. 更新Logger
    getLoggerContext().updateLoggers();
}

通过第一节知道,「Log4j2」的「Configuration」对象有一个字段叫做「loggerConfigs」,所以上面首先就是通过「loggerName」去「loggerConfigs」中匹配对应的「LoggerConfig」,那么这里就会存在一个问题,那就是配置文件里面每配一个「Logger」,「loggerConfigs」才会增加一个「LoggerConfig」,所以实际上「loggerConfigs」里面的「LoggerConfig」并不会很多,比如我们提供了如下一个「Log4j2.xml」文件。

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
    <Appenders>
        <Console name="MyConsole"/>
    </Appenders>

    <Loggers>
        <Root level="INFO">
            <Appender-ref ref="MyConsole"/>
        </Root>
        <Logger name="com.honey" level="WARN">
            <Appender-ref ref="MyConsole"/>
        </Logger>
        <Logger name="com.honey.auth.Login" level="DEBUG">
            <Appender-ref ref="MyConsole"/>
        </Logger>
    </Loggers>
</Configuration>

那么实际加载得到的「Configuration」的「loggerConfigs」只有下面这几个名字的「LoggerConfig」。

""
com.honey
com.honey.auth.Login

其中空字符串是根日志打印器(「rootLogger」)的名字。此时如果在调用「Log4J2LoggingSystem」的「setLogLevel()」 方法时传入的「loggerName」是「com.honey.auth.Login」,我们可以很顺利的从「Configuration」的「loggerConfigs」中拿到名字是「com.honey.auth.Login」的「LoggerConfig」,可要是传入的「loggerName」是「com.honey.auth.Logout」呢,那么获取出来的「LoggerConfig」肯定是「null」,此时该怎么处理呢,难道就不设置日志打印器的级别了吗,当然不是的,「Springboot」在这里做了一个巨巧妙的设计,就是如果热更新「Log4j2」时通过「loggerName」没有获取到「LoggerConfig」,那么「Springboot」就会创建一个「LevelSetLoggerConfig」(「LoggerConfig」的子类)然后添加到「Configuration」的「loggerConfigs」中。下面先看一下「LevelSetLoggerConfig」长什么样。

private static class LevelSetLoggerConfig extends LoggerConfig {

    LevelSetLoggerConfig(String name, Level level, boolean additive) {
        super(name, level, additive);
    }

}

既然我们往「Configuration」的「loggerConfigs」中添加了一个名字是「com.honey.auth.Logout」的「LevelSetLoggerConfig」,那么名字是「com.honey.auth.Logout」的「Logger」理所应当的就会持有名字是「com.honey.auth.Logout」的「LevelSetLoggerConfig」,但是聪明的人就发现了,这个新创建出来的「LevelSetLoggerConfig」也是没有灵魂的,为什么呢,因为「LevelSetLoggerConfig」不引用任何的「Appedner」,没有「Appedner」怎么打日志嘛,不过不用担心,只要在创建「LevelSetLoggerConfig」时,将「additive」指定为「true」,这个问题就解决了。

在「Log4j2」中,「LoggerConfig」之间是有父子关系的,假如「Configuration」的「loggerConfigs」有下面这几个名字的「LoggerConfig」。

""
com.honey
com.honey.auth.Login

那么名字是「com.honey.auth.Login」的「LoggerConfig」会依次按照「com.honey.auth」,「com.honey」,「com」和 「""」 去寻找自己的父「LoggerConfig」,所以每个「LoggerConfig」都有自己的父「LoggerConfig」,而「additive」参数的含义就是,当前日志是否还需要由父「LoggerConfig」打印,如果某个「LoggerConfig」的「additive」是「true」,那么一条日志除了让自己的所有「Appedner」打印,还会让父「LoggerConfig」的所有「Appender」来打印。

所以只要在创建「LevelSetLoggerConfig」时,将「additive」指定为「true」,就算「LevelSetLoggerConfig」自己没有「Appender」,父亲也是可以打印日志的。下面举个例子来加深理解,还是假如「Configuration」的「loggerConfigs」有下面这几个名字的「LoggerConfig」。

""
com.honey
com.honey.auth.Login

我们已经有一个名字为「com.honey.auth.Logout」的「Logger」,并且按照「Logger」寻找「LoggerConfig」的规则,我们知道名字为「com.honey.auth.Logout」的「Logger」会持有名字为「com.honey」的「LoggerConfig」,那么现在我们要热更新名字为「com.honey.auth.Logout」的「Logger」的级别,此时拿着「com.honey.auth.Logout」从「Configuration」的「loggerConfigs」中获取出来的「LoggerConfig」肯定为「null」,所以我们会创建一个名字为「com.honey.auth.Logout」的「LevelSetLoggerConfig」,并且这个「LevelSetLoggerConfig」的「additive」为「true」,此时「Configuration」的「loggerConfigs」有下面这几个名字的「LoggerConfig」。

""
com.honey
com.honey.auth.Login
com.honey.auth.Logout

此时我们重新让名字为「com.honey.auth.Logout」的「Logger」去寻找自己应该持有的「LoggerConfig」,那么肯定就会找到名字为「com.honey.auth.Logout」的「LevelSetLoggerConfig」,由于「Log4j2」中,「Logger」的级别跟着「LoggerConfig」走,所以名字为「com.honey.auth.Logout」的「Logger」的级别就更新了,现在使用名字为「com.honey.auth.Logout」的「Logger」打印日志,首先会让其持有的「LoggerConfig」引用的「Appedner」来打印,由于没有引用「Appedner」,所以不会打印日志,然后再让其父「LoggerConfig」引用的「Appedner」来打印日志,而名字为「com.honey.auth.Logout」的「LevelSetLoggerConfig」的父亲其实就是名字为「com.honey」的「LoggerConfig」,所以最终还是让名字为「com.honey」的「LoggerConfig」引用的「Appedner」完成了日志打印。

到这里仿佛好像逐渐偏离了本小节的主题,其实不是的,我们现在再回看「Log4J2LoggingSystem」的「setLogLevel()」 方法,如下所示。

private void setLogLevel(String loggerName, Level level) {
    // 从Configuration中根据loggerName获取到对应的LoggerConfig
    LoggerConfig logger = getLogger(loggerName);
    if (level == null) {
        // 2. 移除LoggerConfig或设置LoggerConfig级别为null
        clearLogLevel(loggerName, logger);
    } else {
        // 1. 添加LoggerConfig或设置LoggerConfig级别
        setLogLevel(loggerName, logger, level);
    }
    // 3. 更新Logger
    getLoggerContext().updateLoggers();
}

首先是第1点,在传入的「level」不为空时,我们就会去设置对应的「LoggerConfig」的级别,如果获取到的「LoggerConfig」为空,那么就会创建一个名字为「loggerName」,级别为「level」的「LevelSetLoggerConfig」并加到「Configuration」的「loggerConfigs」中,如果获取到的「LoggerConfig」不为空,则直接修改「LoggerConfig」的「level」字段。

其次是第2点,传入「level」为空时,此时要求能通过「loggerName」找到「LoggerConfig」,否则抛空指针异常。如果通过「loggerName」找到的「LoggerConfig」不为空,此时需要判断一下「LoggerConfig」的类型,如果「LoggerConfig」实际类型是「LevelSetLoggerConfig」,那么就从「Configuration」的「loggerConfigs」中将其移除,如果「LoggerConfig」实际类型就是「LoggerConfig」,那么就设置「LoggerConfig」的「level」字段为「null」。

最后是第3点,在前面第1和第2点,我们已经让目标「LoggerConfig」的级别完成了更新,此时就需要让「LoggerContext」里面所有的「Logger」重新去匹配一次自己的「LoggerConfig」,至此就完成了「Logger」的级别的更新。

相信到这里,「Log4J2LoggingSystem」热更新原理就阐释清楚了,小结一下就是通过「loggerName」找「LoggerConfig」,找到了就更新其「level」,找不到就创建一个名字为「loggerName」的「LevelSetLoggerConfig」,最后让所有「Logger」去重新匹配一下自己的「LoggerConfig」,此时我们的目标「Logger」就会持有更新过级别的「LoggerConfig」了。

最后给出基于「LoggersEndpoint」热更新「Log4j2」日志打印器的流程图,如下所示。

Image

六. 自定义Springboot下日志打印器级别热更新

有些时候,使用「spring-boot-actuator」包提供的「LoggersEndpoint」来热更新日志打印器级别,是有点不方便的,因为想要热更新日志级别而引入「spring-boot-actuator」包,大部分时候这个操作都有点重,而通过上面的分析,我们发现其实热更新日志打印器级别的原理特别简单,就是通过「LoggingSystem」来操作「Logger」,所以我们可以自己提供一个接口,通过这个接口来操作「Logger」的级别。

@RestController
public class HotModificationLevel {

    private final LoggingSystem loggingSystem;

    public HotModificationLevel(LoggingSystem loggingSystem) {
        this.loggingSystem = loggingSystem;
    }

    @PostMapping("/logger/level")
    public void setLoggerLevel(@RequestBody SetLoggerLevelParam levelParam) {
        loggingSystem.setLogLevel(levelParam.getLoggerName(), levelParam.getLoggerLevel());
    }

    public static class SetLoggerLevelParam {
        private String loggerName;
        private LogLevel loggerLevel;

        // 省略getter和setter
    }

}

通过调用上述接口使用「LoggingSystem」就能够完成指定日志打印器的级别热更新。

总结

对于「Log4j2」日志框架,我们需要知道「Logger」只是一个壳子,灵魂是「Logger」持有的「LoggerConfig」。

「Springboot」框架启动时,日志的初始化的发起点是「LoggingApplicationListener」,但是实际去寻找日志框架的配置文件并完成日志框架初始化是「LoggingSystem」。

在「Springboot」中提供日志框架的配置文件时,我们可以将配置文件命名为约定的名字然后放在「classpath」下,也可以通过「logging.config」显示的指定要使用的配置文件的路径,甚至可以完全不自己提供配置文件而使用「Springboot」预置的配置文件,因此使用「Springboot」框架,想打印日志是十分容易的。

「Springboot」框架中,为了统一的管理一组「Logger」,定义了一个日志打印器组「LoggerGroup」,通过操作「LoggerGroup」,可以方便的操作一组「Logger」,我们可以使用「logging.group.xxx」来定义「LoggerGroup」,而「xxx」就是组名,后续拿着组名就可以找到「LoggerGroup」并操作。

所谓日志打印器级别热更新,其实就是不重启应用的情况下修改日志打印器的级别,核心思路就是通过「LoggingSystem」去操作底层的日志框架,因为「LoggingSystem」可以为我们屏蔽底层的日志框架的细节,所以通过「LoggingSystem」修改日志打印器级别,是十分容易的。

点击关注公众号,“技术干货” 及时达!