转载

日志配置热更新技术实践

一为什么需要服务日志热更新?

对于后端老鸟来说，一定遇到过这样的场景：

为了排查线上突发的问题，非常希望能够全面的看到请求在服务链路上的完整日志输出;

But，在生产环境中，为了避免日志打印过量造成磁盘空间浪费，通常会将日志级别设定在INFO，并关闭一般情况用不到的日志输出;

在不重启服务的情况下，开启本已经关闭的业务日志输出，能不能搞的定呢?答案是当然没问题。

二需求分析

熟悉logback的同学此时肯定已经想到通过扫描监听logback.xml文件配置变化来实现日志级别的调整，像如下这种方式：

<configuration debug="true" scan="true" scanPeriod="1 seconds">

但通常情况下，你的业务服务是分布式部署的，后端节点有多台，如果一台台的去改，且不说运维大哥未必就会同意给你生产机器文件的修改权限，即使可以，这么做未免有些过于“老实”了;有没有一种可以集中管理日志配置，修改文件后再逐个分发给各节点的解决方案呢?沿着这个思路，自然而然就会联想到配置中心，这里，我主要介绍携程开源的apollo，同类的配置中心产品还有百度Disconf、阿里ACM和Spring Cloud Config，感兴趣的自行研究。

三做实验

熟悉apollo文件管理的同学都知道，apollo通过推拉结合的方式将服务端存储的应用配置文件缓存到本地是以properties的格式存储的，如下面所示：

demo+dev+logback.xml.properties

content=<?xml version/="1.0" encoding/="UTF-8"?>/n<configuration debug/="true">/n/t<property name/="encoding" value/="UTF-8"/>/n/n/t<appender name/="STDOUT" class/="ch.qos.logback.core.ConsoleAppender">/n/t/t<encoder class/="ch.qos.logback.classic.encoder.PatternLayoutEncoder">/n/t/t/t<pattern>%d{yyyy-MM-dd HH/:mm/:ss.SSS}|%X{requestId}|[%t] %-5level %logger{50} %line - %m%n</pattern>/n/t/t</encoder>/n/t</appender>/n/n/t<appender name/="FILE" class/="ch.qos.logback.core.rolling.RollingFileAppender">/n/t/t<file>logs/brm.log</file>/n/t/t<encoder class/="ch.qos.logback.classic.encoder.PatternLayoutEncoder">/n/t/t/t<pattern>%d{yyyy-MM-dd HH/:mm/:ss.SSS}|%X{requestId}|%X{requestSeq}|[%t] %-5level %logger{50} %line - %m%n</pattern>/n/t/t</encoder>/n/t/t<rollingPolicy class/="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">/n/t/t/t<fileNamePattern>logs/brm-%d{yyyy-MM-dd-HH}-%i.log</fileNamePattern>>/n/t/t/t</!--单个文件切割阈值，超过生成新log文件-->/n/t/t/t<maxFileSize>200MB</maxFileSize>/n/t/t/t</!--最大保留天数-->/n/t/t/t<maxHistory>336</maxHistory>/n/t/t</rollingPolicy>/n/t</appender>/n/n    </!--log4jdbc -->/n    <logger name/="jdbc.sqltiming" level/="INFO"/>/n    <logger name/="jdbc.sqlonly" level/="OFF"/>/n    <logger name/="jdbc.audit" level/="OFF"/>/n    <logger name/="jdbc.resultset" level/="OFF"/>/n    <logger name/="jdbc.resultsettable" level/="OFF"/>/n    <logger name/="jdbc.connection" level/="OFF"/>/n        /n/t<root level/="INFO">/n/t/t<appender-ref ref/="STDOUT"/>/n/t/t<appender-ref ref/="FILE"/>/n/t</root>/n</configuration>

HH/:mm/:ss.SSS}|%X{requestId}|%X{requestSeq}|[%t] %-5level %logger{50} %line - %m%n /n/t/t /n/t/t /n/t/t/t logs/brm-%d{yyyy-MM-dd-HH}-%i.log >/n/t/t/t</!--单个文件切割阈值，超过生成新log文件-->/n/t/t/t 200MB /n/t/t/t</!--最大保留天数-->/n/t/t/t 336 /n/t/t /n/t /n/n </!--log4jdbc -->/n /n /n /n /n /n /n /n/t /n/t/t /n/t/t /n/t /n

而我们通常在配置logback的时候使用的是xml文件;

因此，我们要想办法让logback能够加载context的内存值信息。

阅读logback资料发现，JoranConfigurator支持我们以自定义的方式配置logback，

而springboot是通过LoggingSystem来加载管理日志系统的;如果我能在springboot启动的时候指定我自定义的日志加载类，问题便迎刃而解。

这里，我们在resources目录下新建META-INF文件夹，添加spring.factories，内容如下：

org.springframework.context.ApplicationContextInitializer = com.zhoupu.zplog.refresher.LoggerRefresher 
org.springframework.boot.env.EnvironmentPostProcessor = com.zhoupu.zplog.refresher.LoggerRefresher

这里我们定义一个LoggerRefresher，该类重写loadDefaults和loadConfiguration方法，通过JoranConfigurator加载logback配置，并在configureByApollo中添加一个apollo事件监听器，当发现logback.xml文件有变化时，重新执行configureByApollo方法刷新日志配置。

核心代码部分如下：

package com.zhoupu.zplog.refresher; 
 
import ch.qos.logback.classic.LoggerContext; 
import ch.qos.logback.classic.joran.JoranConfigurator; 
import ch.qos.logback.core.joran.spi.JoranException; 
import com.ctrip.framework.apollo.Config; 
import com.ctrip.framework.apollo.ConfigChangeListener; 
import com.ctrip.framework.apollo.ConfigService; 
import com.ctrip.framework.apollo.model.ConfigChangeEvent; 
import com.ctrip.framework.apollo.spring.config.PropertySourcesConstants; 
import org.slf4j.ILoggerFactory; 
import org.slf4j.Logger; 
import org.slf4j.LoggerFactory; 
import org.springframework.boot.SpringApplication; 
import org.springframework.boot.env.EnvironmentPostProcessor; 
import org.springframework.context.ApplicationContextInitializer; 
import org.springframework.context.ConfigurableApplicationContext; 
import org.springframework.core.Ordered; 
import org.springframework.core.env.ConfigurableEnvironment; 
import org.springframework.util.StringUtils; 
 
import javax.xml.parsers.DocumentBuilder; 
import javax.xml.parsers.DocumentBuilderFactory; 
import java.io.ByteArrayInputStream; 
import java.io.UnsupportedEncodingException; 
 
/** 
 * 
 * @author vigor 
 * @date 2019/6/14 上午11:27 
 */ 
 
public class LoggerRefresher implements ApplicationContextInitializer<ConfigurableApplicationContext>, EnvironmentPostProcessor, Ordered { 
    private static final Logger log = LoggerFactory.getLogger(LoggerRefresher.class); 
 
    private boolean loadFlag = false; 
 
    @Override 
    public void initialize(ConfigurableApplicationContext context) { 
        ConfigurableEnvironment environment = context.getEnvironment(); 
        load(environment); 
 
    } 
 
    @Override 
    public void postProcessEnvironment(ConfigurableEnvironment environment, SpringApplication application) { 
        load(environment); 
    } 
 
    @Override 
    public int getOrder() { 
        return 1; 
    } 
 
    private void load(ConfigurableEnvironment environment) { 
        if (!loadFlag) { 
            environment.getPropertySources().forEach(ps -> { 
                if (PropertySourcesConstants.APOLLO_BOOTSTRAP_PROPERTY_SOURCE_NAME.equals(ps.getName())) { 
                    configureByApollo(); 
                    loadFlag = true; 
                } 
            }); 
        } 
    } 
 
    private void configureByApollo() { 
        Config config = ConfigService.getConfig("logback.xml"); 
 
        String content = config.getProperty("content", ""); 
        if (StringUtils.isEmpty(content) || !validateXML(content)) { 
            return; 
        } 
 
        config.addChangeListener(new ConfigChangeListener() { 
            @Override 
            public void onChange(ConfigChangeEvent changeEvent) { 
                configureByApollo(); 
            } 
 
            @Override 
            public boolean equals(Object obj) { 
                if (this == obj) { 
                    return true; 
                } 
                if (this.getClass().equals(obj.getClass())) { 
                    return true; 
                } 
                return false; 
            } 
 
            @Override 
            public int hashCode() { 
                return 1; 
            } 
        }); 
 
        ILoggerFactory loggerFactory = LoggerFactory.getILoggerFactory(); 
        LoggerContext loggerContext = (LoggerContext) loggerFactory; 
        loggerContext.reset(); 
        JoranConfigurator configurator = new JoranConfigurator(); 
        configurator.setContext(loggerContext); 
        try { 
            configurator.doConfigure(new ByteArrayInputStream(content.getBytes("utf-8"))); 
            log.warn("*****************************logback configureByApollo success!********************************"); 
        } catch (JoranException e) { 
            e.printStackTrace(); 
        } catch (UnsupportedEncodingException e) { 
            e.printStackTrace(); 
        } 
    } 
 
    private boolean validateXML(String xml){ 
        boolean isValidated = true; 
        try { 
            DocumentBuilderFactory documentBuilderFactory = DocumentBuilderFactory.newInstance(); 
            DocumentBuilder builder = documentBuilderFactory.newDocumentBuilder(); 
            builder.parse(new ByteArrayInputStream(xml.getBytes("utf-8"))); 
        } catch (Exception e) { 
            log.error("apollo logback config error = {}", e); 
            isValidated = false; 
        } 
        return isValidated; 
    } 
 
}

至此已完成所有准备工作，运行demo程序，我的项目使用log4jdbc输出sql，这里我通过修改apollo配置管理后台jdbc日志配置，将sqltiming级别改为INFO：

<!--log4jdbc --> 
    <logger name="jdbc.sqltiming" level="INFO"/> 
    <logger name="jdbc.sqlonly" level="OFF"/> 
    <logger name="jdbc.audit" level="OFF"/> 
    <logger name="jdbc.resultset" level="OFF"/> 
    <logger name="jdbc.resultsettable" level="OFF"/> 
    <logger name="jdbc.connection" level="OFF"/>

发起一个后端请求，查看控制台日志输出，有了!

2019-11-08 10:11:27.794|1fe97e7dcfeb4fc2810d8a7a706fad2a||[http-nio-8062-exec-3] INFO  jdbc.sqltiming 357 - SELECT id, row_state, created_at, updated_at, created_by, updated_by, business_id, contact_name, 
role, mobile, contact_type FROM t_business_contact WHERE row_state = 0 AND business_id = 1000006

惊不惊喜_，意不意外!