SpringBoot 中的日志原来是这么工作的

Java
163
0
0
2024-08-12
标签   SpringBoot

在有些场景,能通过调整日志的打印策略来提升我们的系统吞吐量,你知道吗?

我们以Springboot集成Log4j2为例,详细说明Springboot框架下Log4j2是如何工作的,你可能会担心,如果是使用Logback日志框架该怎么办呢?

其实Log4j2和Logback极其相似,Springboot在启动时处理Log4j2和处理Logback也几乎是一样的套路,所以学会Springboot框架下Log4j2如何工作,切换成Logback也是轻轻松松的。

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

  • Springboot版本:2.7.2
  • Log4j2版本:2.17.2

一. Log4j2简单工作原理分析

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

实际打印日志的是Logger对象使用的Appender对象,至于Appender对象怎么打印日志,不在我们本文的关注范围内。

特别注意,在Log4j2中,Logger对象实际只是一个壳子,灵魂是其持有的LoggerConfig对象,LoggerConfig决定打印时使用哪些Appender对象,以及Logger的级别。

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

我们每在配置文件的<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的关系可以描述成下面这样子。

所以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() 方法来完成日志框架初始化前的一些准备,这里看一下Log4J2LoggingSystembeforeInitialize() 方法实现,如下所示。

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

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

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

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

2. 监听到ApplicationEnvironmentPreparedEvent

LoggingApplicationListeneronApplicationEnvironmentPreparedEvent() 方法如下所示。

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());
}

继续跟进LoggingApplicationListenerinitialize() 方法。

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中日志配置和系统属性名的对应关系:

2、调用LoggingSystem的initialize() 方法来完成日志框架初始化。这里就是实际完成Log4j2或Logback等框架的初始化;

3、在日志框架完成初始化后基于logging.level的配置来设置日志打印器组和日志打印器的级别。

上述第2点是Springboot如何完成具体的日志框架的初始化,这个在后面章节中会详细分析。

上述第3点是日志框架初始化完毕后,Springboot如何帮助我们完成日志打印器组或日志打印器的级别的设置,这里就扯出来一个概念:日志打印器组,也就是LoggerGroup。

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

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

  • name: 表示LoggerGroup的名字,要操作LoggerGroup时,就通过name来唯一确定一个LoggerGroup,假如有一个LoggerGroup名字为login,那么我们可以通过logging.level.loggin=debug,将这个LoggerGroup下所有的Logger的级别设置为debug;
  • members: 是当前LoggerGroup里所有Logger的名字的集合;
  • 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.weblogging.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主要完成三件事情。

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

3. 监听到ApplicationPreparedEvent

LoggingApplicationListeneronApplicationPreparedEvent() 方法如下所示。

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日志启动流程做一个总结。

四. 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事件后,最终会调用到LoggingApplicationListenerinitializeSystem() 方法来完成日志框架的初始化,所以我们先看一下这里的逻辑是什么,源码实现如下。

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) {
        // 省略异常处理
    }
}

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

1. 没配置logging.config

Log4J2LoggingSysteminitialize() 方法如下所示。

@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);
}

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

@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之后,就会调用到LoggerContextstart() 方法完成Log4j2框架的初始化,那么这里其实会做如下三件事情。

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

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

2. 有配置logging.config

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

@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);
}

继续跟进AbstractLoggingSysteminitialize() 方法,如下所示。

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

由于指定了配置文件,所以会调用到AbstractLoggingSysteminitializeWithSpecificConfig() 方法,该方法没有什么额外逻辑,最终会执行到和没配置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日志框架时,主要分为两种情况:

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

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

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

五. 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的名称,那么就基于LoggingSystemsetLogLevel() 方法来设置这个Logger的级别,如果是LoggerGroup的名称,那么就遍历这个组下所有的Logger,每个遍历到的Logger都基于LoggingSystem的setLogLevel() 方法来设置级别。

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

3. Log4J2LoggingSystem热更新原理

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

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

Log4J2LoggingSystemsetLogLevel() 方法如下所示。

@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.LogoutLevelSetLoggerConfig,那么名字是com.honey.auth.Logout的Logger理所应当的就会持有名字是com.honey.auth.LogoutLevelSetLoggerConfig,但是聪明的人就发现了,这个新创建出来的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.authcom.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.LogoutLevelSetLoggerConfig,并且这个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.LogoutLevelSetLoggerConfig,由于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完成了日志打印。

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

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,那么就从ConfigurationloggerConfigs中将其移除,如果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日志打印器的流程图,如下所示。

六. 自定义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修改日志打印器级别,是十分容易的。

最后说一句(求关注!别白嫖!)

如果这篇文章对您有所帮助,或者有所启发的话,求一键三连:点赞、转发、在看。