動態調整紀錄檔級別思路&實現

2022-09-08 18:01:43

引言

上篇文章 效能調優——小小的 log 大大的坑 已將詳細的介紹了高並行下,不正確的使用紀錄檔姿勢,可能會導致服務效能急劇下降問題。文末也給各位留下了解決方案——紀錄檔級別動態調整。
本文將詳細介紹「動態紀錄檔」的實現原理及原始碼,希望各位能在今後的生產環境中應對紀錄檔問題能「得心應手」!

背景

紀錄檔的重要性不言而喻,是我們排查問題,解決 BUG 的重要手段之一,但是在高並行環境下,又會存在悖論:
大量列印紀錄檔,消耗 I/O,導致 CPU 佔用率高;減少紀錄檔,效能是下來了,但是排查問題的鏈路斷掉了。

痛點:一方面需要藉助紀錄檔可快速排查問題,另一方面要兼顧效能,二者能否得兼?
那麼本文的動態紀錄檔調整實現就是為了能解決這個痛點所構思開發的。

功能特性

  • 低侵入,快速接入:以二方包(jar)的形式介入,只需要設定啟用,對業務無感
  • 及時響應,隨調隨改:應對研發不小心在大流量入口鏈路列印了大量 INFO 紀錄檔,能及時調整紀錄檔級別
  • 階梯設定支援:預設全域性設定兜底,又可以支援區域性 Logger 放/限流
  • 人性化操作:與操作介面,方便修改

技術實現

如下,我將以 log4j2 為範例作講解,其它紀錄檔實現大同小異,參照實現即可。
如下是 log 介入的組態檔範例:

<?xml version="1.0" encoding="UTF-8"?>
<configuration status="info">
<Properties>
	// 全域性引數資訊
</Properties>

<appenders>
	// appender 詳細設定
</appenders>

<loggers>
	// 設定 appender 指向
</loggers>
</configuration>

以往我們調整專案的紀錄檔時,要麼是刪除程式碼中的廢紀錄檔,要麼是修改上面的 xml 設定,針對某個包下或者類作紀錄檔級別限制,再重新打包部署生效。此時的效率是非常低的,不符個我們的訴求。
那麼如何實現動態調整呢,首先想到的是 xml 調整紀錄檔級別後是如何生效的?xml 本身就是一些設定資訊, log 的實現類讀取 xml 資訊動態修改紀錄檔級別,有沒有可能我們在程式中直接去呼叫 log4j 內部的封裝方法,繞過 xml 不就好了?

動態調整紀錄檔級別

原始碼檢視:詳細原始碼我已放在 github dynamic-logger-util,可自行檢視。

順著思路,檢視 log4j 原始碼後,發現確實可行,如下即是調整紀錄檔方法的實現程式碼:

// 獲取紀錄檔上下文
LoggerContext logContext = LoggerContext.getContext(false);
Configuration configuration = logContext.getConfiguration();
LoggerConfig loggerConfig = configuration.getRootLogger();
loggerConfig.setLevel(level);

// 生效
logContext.updateLoggers();

獲取當前的 LoggerContext 後,再獲取 configuration,當前的設定即是 xml 內的設定轉換過來的,再獲取 root logger, 即對應 xml 中的設定如下:

 <Root level="info">
    <AppenderRef ref="..."/>
    <AppenderRef ref="..."/>
</Root>

其中 level 即是我們需要更改的紀錄檔級別,可供選擇的紀錄檔級別如下(參照 org.apache.logging.log4j.Level):

OFF, FATAL, ERROR, WARN, INFO, DEBUG, TRACE, ALL;

如上我們已經可以更改全域性紀錄檔級別,那麼比如我想只更改某個類內的紀錄檔級別如何實現呢?

LoggerContext logContext = LoggerContext.getContext(false);
if (logContext.hasLogger(name)) {
    // 精確匹配
    Logger logger = logContext.getLogger(name);
    logger.setLevel(newLevel);
    flag = true;
} else {
    // 正則匹配
    Collection<Logger> loggers = logContext.getLoggers();
    for (Logger logger : loggers) {
        if (Pattern.matches(name, logger.getName())) {
            logger.setLevel(newLevel);
            flag = true;
        }
    }
}

通過獲取的 logContext 獲取相應的 logger 即可設定當前的類對應的紀錄檔級別,對應的程式程式碼如下:

// name = com.jifuwei.dynamic.logger.DynamicLoggerConfiguration
private static final org.slf4j.Logger  = LoggerFactory.getLogger(DynamicLoggerConfiguration.class);

如上,已經知道了如何動態修改紀錄檔 api,那麼如何去動態觸發修改呢?

設定觸發

觸發更新的機制很多,我們梳理如下:

如上能滿足我們需求的,最最簡答方便的就是設定中心,現在都是微服務,大部分都是通過中心設定去通知各個系統資訊變更,設定中心都具備完善的介面和功能,可滿足我們實時變更下發通知,又能灰度部署,減少出錯,簡直是動態設定的最佳搭檔。

設定中心的選型非常多,我將以 Apollo 為例,演示如何觸發紀錄檔級別變更。我將設定 Key 設計如下:

// 全域性控制紀錄檔級別
key: log_level val=OFF/FATAL/ERROR/WARN/INFO/DEBUG/TRACE/ALL

// 區域性控制紀錄檔級別
key: log_level_detail

val:
{
	"com.jifuwei.demo.Test1": "ERROR", // 每個 logger 都可設定自己專屬的紀錄檔級別
	"com.jifuwei.demo.Test2": "OFF",
	"com.jifuwei.demo.Test3": "INFO",
}

關鍵實現如下:

public void init() {
    // 初始化風控監聽action設定
    String level = apolloConfig.getProperty(LOGGER_LEVEL, Level.ERROR.name());
    setRootLoggerLevel(Level.valueOf(level));

    // 註冊監聽
    apolloConfig.addChangeListener(this);
}

public void onChange(ConfigChangeEvent changeEvent) {
    if (changeEvent.changedKeys().contains(LOGGER_LEVEL)) {
        String newValue = changeEvent.getChange(LOGGER_LEVEL).getNewValue();
        try {
            setRootLoggerLevel(Level.valueOf(newValue));
        } catch (Exception e) {
            log.error("loggerLevel onChange error", e);
        }
    }
    if (changeEvent.changedKeys().contains(LOGGER_LEVEL_DETAIL)) {
        String newValue = changeEvent.getChange(LOGGER_LEVEL_DETAIL).getNewValue();
        try {
            parseLoggerConfig(newValue);
        } catch (Exception e) {
            log.error("loggerLevel detail onChange error", e);
        }
    }
}

初始化時即從 apollo config 獲取當前全域性紀錄檔級別及區域性紀錄檔級別,其次在註冊監聽器,此時只需要在 apollo 設定介面設定如上 key ,則程式會立即收到更新並重新設定相應的紀錄檔級別。

本文所有原始碼都放在了 github 倉庫: https://github.com/jifuwei/dynamic-logger-util,可隨時檢視/索取/使用,有問題隨時提問。

總結

通過 xml 修改紀錄檔級別去追查 api 方法,找到可用的方法後再去設計如何觸發方法呼叫。按照這一思路,就解決了動態調整紀錄檔級別的問題。在生產發生大量異常,可對紀錄檔進行降級,不至於 I/O 升高導致 CPU 爆滿,從而導致使用者體驗卡頓問題。

如果你覺得本人分享的內容夠「幹」,麻煩點贊、關注、轉發,這是對我最大鼓勵,感謝支援!
希望我分享的文章能夠給每一位讀者帶來幫助!

往期精彩

個人技術部落格:https://jifuwei.github.io/
公眾號:是咕咕雞