日志配置熱更新技術實踐

作者：舟譜數據 2019-11-11 10:38:06

開發開發工具

一個簡單的日志配置熱更新嘗試，串聯起了logback的自定義配置加載原理，apollo的配置中心使用方法和事件監聽機制，以及springboot日志管理和自動裝配等知識點，希望大家能從中有所收獲!

[[281868]]

一為什么需要服務日志熱更新?

對于后端老鳥來說，一定遇到過這樣的場景：

為了排查線上突發的問題，非常希望能夠全面的看到請求在服務鏈路上的完整日志輸出;

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\tlogs/brm-%d{yyyy-MM-dd-HH}-%i.log>\n\t\t\t<\!--單個文件切割閾值，超過生成新log文件-->\n\t\t\t200MB\n\t\t\t<\!--最大保留天數-->\n\t\t\t336\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

驚不驚喜_，意不意外!

四總結

【本文是51CTO專欄機構“舟譜數據”的原創文章，微信公眾號“舟譜數據( id: zhoupudata)”】

戳這里，看該作者更多好文

責任編輯：武曉燕來源： 51CTO

日志配置技術