原创

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

正文到此结束
广告是为了更好的提供数据服务
本文目录