動態調整日誌級別思路&實現
引言
上篇文章 性能調優——小小的 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 倉庫: //github.com/jifuwei/dynamic-logger-util,可隨時查看/索取/使用,有問題隨時提問。
總結
通過 xml 修改日誌級別去追查 api 方法,找到可用的方法後再去設計如何觸發方法調用。按照這一思路,就解決了動態調整日誌級別的問題。在生產發生大量異常,可對日誌進行降級,不至於 I/O 升高導致 CPU 爆滿,從而導致用戶體驗卡頓問題。
如果你覺得本人分享的內容夠「干」,麻煩點贊、關注、轉發,這是對我最大鼓勵,感謝支持!
希望我分享的文章能夠給每一位讀者帶來幫助!
往期精彩
個人技術博客://jifuwei.github.io/
公眾號:是咕咕雞