Apollo配置中心动态刷新日志级别

背景

你是否碰到过如下场景：

• 在测试环境未发现的BUG，上了生产环境之后偶现，但同样由于缺少调试信息，无法定位问题。
• 调用内部服务、第三方服务，在某些case下系统未按预期运行，排查代码后怀疑是被依赖方返回了错误的数据导致，但苦于打印Response的日志为DEBUG，没有证据。

在以前的解决方案是，将日志级别改成DEBUG并上个线，排查完问题之后，再将日志级别改回INFO，再上一次线，整个生命周期很长；又或者为了省事，直接将调试日志级别定为INFO，避免上线。这两种方式，无论哪种都不够优雅，并且前者繁琐，后者导致日志爆炸。

我们期望实现的目标是：

能够动态修改日志级别并及时生效(主要目标)
问题排查完之后，能够还原日志级别

解决方案

针对需要实现的目标，逐条分析：

• 借助一些工具(如Arthas)，直接修改运行时内存中的值，但是在集群环境下需要逐台修改，实施成本较高；借助配置中心(如Apollo)，修改之后由配置中心把数据推给应用服务器，时延取决于配置中心推送的能力

• Spring Boot提供的设置日志级别的方式是，在application.properties/application.xml里配置logging.level.{loggerName} = DEBUG

• 为了排查问题，将某个类的日志级别设置为DEBUG，完事之后，通过将本Logger日志级别设置为父Logger的日志级别进行还原

Spring Boot提供了抽象日志系统(org.springframework.boot.logging.LoggingSystem)，通过借助LoggingSystem可以实现修改日志级别的目的，而Apollo则为动态修改提供了可能性。

最终采用的方案为Spring Boot(LoggingSystem) + Apollo，选用的日志组件为Logback为例：

引入apollo依赖包：

<dependency>
    <groupId>com.ctrip.framework.apollo</groupId>
    <artifactId>apollo-client</artifactId>
    <version>1.8.0</version>
</dependency>

类名： DynamicsLoggingLevelRefresher

package c.y.c.dynamics.logger;

import com.ctrip.framework.apollo.Config;
import com.ctrip.framework.apollo.model.ConfigChangeEvent;
import com.ctrip.framework.apollo.spring.annotation.ApolloConfig;
import com.ctrip.framework.apollo.spring.annotation.ApolloConfigChangeListener;
import org.apache.commons.lang3.StringUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.logging.LogLevel;
import org.springframework.boot.logging.LoggerConfiguration;
import org.springframework.boot.logging.LoggingSystem;

import javax.annotation.PostConstruct;
import java.lang.reflect.Method;
import java.util.Set;

/**
 * 风杨
 */
public class DynamicsLoggingLevelRefresher {
    private final static Logger log = LoggerFactory.getLogger(DynamicsLoggingLevelRefresher.class);

    /**
     * 监听关键字，当配置中心的依次开头的配置发生变化时，日志级别刷新
     */
    private static final String PREFIX = "logging.level.";

    private static final String ROOT = LoggingSystem.ROOT_LOGGER_NAME;
    private static final String SPLIT = ".";

    private final LoggingSystem loggingSystem;

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

    /**
     * 可以指定具体的namespace，未指定时使用的是 application这个namespace
     */
    @ApolloConfig(value = "application")
    private Config config;

    @PostConstruct
    private void init() {
        refreshLoggingLevels(config.getPropertyNames());
    }

    @ApolloConfigChangeListener(interestedKeyPrefixes = PREFIX)
    private void onChange(ConfigChangeEvent changeEvent) {
        refreshLoggingLevels(changeEvent.changedKeys());
    }

    private void refreshLoggingLevels(Set<String> changedKeys) {
        for (String key : changedKeys) {
            // key may be : logging.level.com.example.web
            if (StringUtils.startsWithIgnoreCase(key, PREFIX)) {
                String loggerName = PREFIX.equalsIgnoreCase(key) ? ROOT : key.substring(PREFIX.length());
                String strLevel = config.getProperty(key, parentStrLevel(loggerName));
                LogLevel level = LogLevel.valueOf(strLevel.toUpperCase());

                //重置日志级别，马上生效
                loggingSystem.setLogLevel(loggerName, level);

                // 当配置发生变更时，输出变更日志
                log(loggerName, strLevel);
            }
        }
    }


    private String parentStrLevel(String loggerName) {
        String parentLoggerName = loggerName.contains(SPLIT) ? loggerName.substring(0, loggerName.lastIndexOf(SPLIT)) : ROOT;

        return loggingSystem.getLoggerConfiguration(parentLoggerName).getEffectiveLevel().name();
    }

    /**
     * 获取当前类的Logger对象有效日志级别对应的方法，进行日志输出。举例：
     *
     * 如果当前类为 INFO，则获取的Method为 `org.slf4j.Logger#info(java.lang.String, java.lang.Object, java.lang.Object)`
     * 目的是为了输出`changed {} log level to:{}`这一行变更日志
     *
     * 如， 当配置发生变更时，输出：
     * <code>
     *     2021-09-16 18:25:44,122 INFO [][] [Apollo-Config-11] c.y.c.d.l.DynamicsLoggingLevelRefresher [NativeMethodAccessorImpl.java:-2] changed org.springframework.web log level to:debug
     * </code>
     */
    private void log(String loggerName, String strLevel) {
        try {
            LoggerConfiguration loggerConfiguration = loggingSystem.getLoggerConfiguration(log.getName());

            Method method = log.getClass().getMethod(
                    loggerConfiguration.getEffectiveLevel().name().toLowerCase(), String.class,
                    Object.class, Object.class);

            method.invoke(log, "changed {} log level to:{}", loggerName, strLevel);
        } catch (Exception e) {
            log.error("changed {} log level to:{} error", loggerName, strLevel, e);
        }
    }

}

配置生效的注入

package c.y..spring;

import c.y.c.dynamics.logger.DynamicsLoggingLevelRefresher;
import lombok.extern.slf4j.Slf4j;
import org.springframework.beans.factory.InitializingBean;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.logging.LoggingSystem;
import org.springframework.boot.web.servlet.ServletComponentScan;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
@Slf4j
public class SpringBeanConfiguration implements InitializingBean {

    @Bean
    public DynamicsLoggingLevelRefresher dynamicsLoggingLevelRefresher(@Autowired LoggingSystem loggingSystem){
        DynamicsLoggingLevelRefresher loggingLevelRefresher = new DynamicsLoggingLevelRefresher(loggingSystem);

        return loggingLevelRefresher;
    }

    @Override
    public void afterPropertiesSet() throws Exception {
        log.info("CommonConfiguration load");
    }

}

能够实现的效果如下：

• 在Apollo配置中心，配置 logging.level.com.example.web = DEBUG，能够将 loggerName 为 com.example.web 的日志级别改成DEBUG, 一般情况下，loggerName也等同于包名，也即是该包下的类日志级别都会被改成DEBUG(使用方式同等于在application.properties里的配置)

• 在Apollo里删掉logging.level.com.example.web的配置项或者更改日志级别，系统会将com.example.web的日志级别设置为等于同com.example的日志级别，默认情况下com.example等同于ROOT的日志级别，也就是INFO，就达到了恢复的目的。

配置中心配置的例子：

#  日志级别
logging.level.org.springframework.web = info
logging.level.com.m.f.p = debug
logging.level.com.y.cn = info

添加或修改配置后，当在apollo上面调整日志级别时不需要重启服务器，马上就能生效。

原理: Apollo配置中心动态刷新日志级别

~ end