日志級別動態調整——小工具解決大問題

NovellaFowl 7年前發布 | 45K 次閱讀日志處理 log4j logback

背景

隨著外賣業務的快速發展，業務復雜度不斷增加，線上系統環境有任何細小波動，對整個外賣業務都可能產生巨大的影響，甚至形成災難性的雪崩效應，造成巨大的經濟損失。每一次客訴、系統抖動等都是對技術人員的重大考驗，我們必須立即響應，快速解決問題。

如何提高排查問題的效率呢？最有效的方式是通過分析系統日志。如果系統日志全面，會為我們排查解決線上問題帶來絕大的幫助，但是要想保證系統日志全面，就必須打印出所有的系統或業務日志。這樣就會帶來另一個問題，那就是日志量的暴漲，過多的日志除了能夠幫助我們解決問題外，同時會直接造成系統性能下降，極端情況下，甚至導致系統宕機。在這種背景下，為了兼顧性能和快速響應線上問題，我們設計開發了日志級別動態調整組件。通過使用該組件，可以在需要解決線上問題時，實時調整線上日志輸出級別，獲取全面的Debug日志，幫助工程師提高定位問題的效率。

簡介

使用場景

場景一

業務依賴復雜。某一時刻，依賴的下游服務故障，導致請求大量超時，尤其是像外賣這種集中性特別明顯的業務，平均每秒QPS在8000以上，1分鐘的故障就會集中產生大量的錯誤日志，導致磁盤IO急劇提高，耗費大量CPU，進而導致整個服務癱瘓。如果該業務不能立即降級，怎么辦？

從代碼級別解決問題到發版上線，暫且不說流程長、操作麻煩，同時還存在引入其它故障的高風險。如果系統恰好使用Log4j版本，在極短時間內打印出了海量錯誤日志，會快速耗盡Buffer區內存，從而拖慢主線程，造成服務性能整體下降，甚至還沒有來得及修復問題，海量日志已經拖垮服務，造成服務宕機，損失慘重。

場景二

大量的訂單、結算等客訴問題反饋過來，一線工程師大量精力埋沒于排查問題中，而排查定位問題的最終手段仍然是依賴線上日志。由于鏈路較長，任一日志的缺失，都給問題的排查帶來極大的障礙，面對運營的催促，怎么辦？

工程師為了以后排查問題的方便，在任一可能出現異常的地方，都會打印出關鍵日志，然后發版上線。但好不容易解決了本次問題，還沒來得及收獲喜悅，就又面臨著一個新問題，那就是場景三。

場景三

由于線上業務系統默認日志打印級別是INFO級別，為了排查問題方便，調試型日志都以該級別打印出來。這樣的話給系統帶來了額外的負擔，在高峰期大量調試日志時會拖慢系統性能，增大出故障的風險，怎么辦？

一方面要快速響應業務，另一方面要兼顧系統性能，能不能兩方面兼顧？我們的動態調整日志級別工具正是為了解決這種痛點。

能解決哪些問題

日志降級。 兼容Log4j、Log4j2和Logback主流日志框架，如果遇到場景一，可以通過我們的日志工具，快速調整日志輸出級別，降低系統日志的輸出，從而達到日志降級的效果，同時能夠給RD爭取充裕的排查問題時間。
規范日志級別濫用，幫助工程師快速定位解決線上問題。 使用日志級別動態調整組件，可以實時動態調整線上服務的日志打印級別，調試型日志可以使用低級別打印出，減輕線上服務的負載壓力。遇到排查問題時，可以臨時將日志級別調低，快速得到精準化的日志信息，排查解決問題。

系統基礎架構

日志級別動態調整組件定位為中間件，在設計之初重點考慮了以下幾點：

低侵入性
- 接入服務僅需要引入JAR包和XML配置文件即可，不存在額外編碼工作，業務耦合低、接入成本小。
安全可靠
- 更改接入服務的日志輸出級別，只能通過我們提供的管理系統，所有的操作記錄有跡可查。
- 引入權限認證，確保工程師只能操作自己負責的服務或系統，同時會把操作內容實時周知給系統的所有相關責任人，避免誤傷。
可視化操作
- 操作者可以通過我們提供的管理頁面，定向修改一個或一批服務節點。
- 提供可視化的操控開關，可以隨時關閉或開啟服務。

具體實現

調用組件

本組件采用工廠模式實現，保障其高可擴展性。目前已實現日志級別動態調整和方法調用處理單元，下面主要介紹日志級別動態調整處理單元的實現。

目前美團外賣業務系統基本統一采用的SLF4J日志框架，在應用初始化時，SLF4J會綁定具體的日志框架，如Log4j、Logback或Log4j2等。具體源碼如下(slf4j-api-1.7.7)：

private final static void bind() {
  try {
    // 查找classpath下所有的StaticLoggerBinder類。
    Set<URL> staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet(); 
    reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);
    // 每一個slf4j橋接包中都有一個org.slf4j.impl.StaticLoggerBinder類，該類實現了LoggerFactoryBinder接口。
    // the next line does the binding
    StaticLoggerBinder.getSingleton();
    INITIALIZATION_STATE = SUCCESSFUL_INITIALIZATION;
    reportActualBinding(staticLoggerBinderPathSet);
    fixSubstitutedLoggers();
    ...
}

findPossibleStaticLoggerBinderPathSet方法用來查找當前classpath下所有的org.slf4j.impl.StaticLoggerBinder類。每一個slf4j橋接包中都有一個StaticLoggerBinder類，該類實現了LoggerFactoryBinder接口。具體綁定到哪一個日志框架則取決于類加載順序。

接下來，咱們分三部分，來說說ChangeLogLevelProcessUnit類：

初始化：確定所使用的日志框架，獲取配置文件中所有的Logger內存實例，并將它們的引用緩存到Map容器中。

String type = StaticLoggerBinder.getSingleton().getLoggerFactoryClassStr();
if (LogConstant.LOG4J_LOGGER_FACTORY.equals(type)) {
 logFrameworkType = LogFrameworkType.LOG4J;
 Enumeration enumeration = org.apache.log4j.LogManager.getCurrentLoggers();
 while (enumeration.hasMoreElements()) {
     org.apache.log4j.Logger logger = (org.apache.log4j.Logger) enumeration.nextElement();
     if (logger.getLevel() != null) {
         loggerMap.put(logger.getName(), logger);
     }
 }
 org.apache.log4j.Logger rootLogger = org.apache.log4j.LogManager.getRootLogger();
 loggerMap.put(rootLogger.getName(), rootLogger);
} else if (LogConstant.LOGBACK_LOGGER_FACTORY.equals(type)) {
 logFrameworkType = LogFrameworkType.LOGBACK;
 ch.qos.logback.classic.LoggerContext loggerContext = (ch.qos.logback.classic.LoggerContext) LoggerFactory.getILoggerFactory();
 for (ch.qos.logback.classic.Logger logger : loggerContext.getLoggerList()) {
     if (logger.getLevel() != null) {
         loggerMap.put(logger.getName(), logger);
     }
 }
 ch.qos.logback.classic.Logger rootLogger = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
 loggerMap.put(rootLogger.getName(), rootLogger);
} else if (LogConstant.LOG4J2_LOGGER_FACTORY.equals(type)) {
 logFrameworkType = LogFrameworkType.LOG4J2;
 org.apache.logging.log4j.core.LoggerContext loggerContext = (org.apache.logging.log4j.core.LoggerContext) org.apache.logging.log4j.LogManager.getContext(false);
 Map<String, org.apache.logging.log4j.core.config.LoggerConfig> map = loggerContext.getConfiguration().getLoggers();
 for (org.apache.logging.log4j.core.config.LoggerConfig loggerConfig : map.values()) {
     String key = loggerConfig.getName();
     if (StringUtils.isBlank(key)) {
         key = "root";
     }
     loggerMap.put(key, loggerConfig);
 }
} else {
 logFrameworkType = LogFrameworkType.UNKNOWN;
 LOG.error("Log框架無法識別: type={}", type);
}

獲取Logger列表：從本地Map容器取出。

private String getLoggerList() {
 JSONObject result = new JSONObject();
 result.put("logFramework", logFrameworkType);
 JSONArray loggerList = new JSONArray();
 for (ConcurrentMap.Entry<String, Object> entry : loggerMap.entrySet()) {
     JSONObject loggerJSON = new JSONObject();
     loggerJSON.put("loggerName", entry.getKey());
     if (logFrameworkType == LogFrameworkType.LOG4J) {
         org.apache.log4j.Logger targetLogger = (org.apache.log4j.Logger) entry.getValue();
         loggerJSON.put("logLevel", targetLogger.getLevel().toString());
     } else if (logFrameworkType == LogFrameworkType.LOGBACK) {
         ch.qos.logback.classic.Logger targetLogger = (ch.qos.logback.classic.Logger) entry.getValue();
         loggerJSON.put("logLevel", targetLogger.getLevel().toString());
     } else if (logFrameworkType == LogFrameworkType.LOG4J2) {
         org.apache.logging.log4j.core.config.LoggerConfig targetLogger = (org.apache.logging.log4j.core.config.LoggerConfig) entry.getValue();
         loggerJSON.put("logLevel", targetLogger.getLevel().toString());
     } else {
         loggerJSON.put("logLevel", "Logger的類型未知,無法處理!");
     }
     loggerList.add(loggerJSON);
 }
 result.put("loggerList", loggerList);
 LOG.info("getLoggerList: result={}", result.toString());
 return result.toString();
}

修改Logger的級別。

private String setLogLevel(JSONArray data) {
 LOG.info("setLogLevel: data={}", data);
 List<LoggerBean> loggerList = parseJsonData(data);
 if (CollectionUtils.isEmpty(loggerList)) {
     return "";
 }
 for (LoggerBean loggerbean : loggerList) {
     Object logger = loggerMap.get(loggerbean.getName());
     if (logger == null) {
         throw new RuntimeException("需要修改日志級別的Logger不存在");
     }
     if (logFrameworkType == LogFrameworkType.LOG4J) {
         org.apache.log4j.Logger targetLogger = (org.apache.log4j.Logger) logger;
         org.apache.log4j.Level targetLevel = org.apache.log4j.Level.toLevel(loggerbean.getLevel());
         targetLogger.setLevel(targetLevel);
     } else if (logFrameworkType == LogFrameworkType.LOGBACK) {
         ch.qos.logback.classic.Logger targetLogger = (ch.qos.logback.classic.Logger) logger;
         ch.qos.logback.classic.Level targetLevel = ch.qos.logback.classic.Level.toLevel(loggerbean.getLevel());
         targetLogger.setLevel(targetLevel);
     } else if (logFrameworkType == LogFrameworkType.LOG4J2) {
         org.apache.logging.log4j.core.config.LoggerConfig loggerConfig = (org.apache.logging.log4j.core.config.LoggerConfig) logger;
         org.apache.logging.log4j.Level targetLevel = org.apache.logging.log4j.Level.toLevel(loggerbean.getLevel());
         loggerConfig.setLevel(targetLevel);
         org.apache.logging.log4j.core.LoggerContext ctx = (org.apache.logging.log4j.core.LoggerContext) org.apache.logging.log4j.LogManager.getContext(false);
         ctx.updateLoggers(); // This causes all Loggers to refetch information from their LoggerConfig.
     } else {
         throw new RuntimeException("Logger的類型未知,無法處理!");
     }
 }
 return "success";
}

上面介紹了如何拿到日志配置文件中的Logger，以及修改Logger的級別。

通信方式

我們根據Web項目和純粹RPC項目，分別提供HTTP和Thrift兩種通信協議。

場景一、Thrift服務

所有的請求信息都包含在JSON String的數據結構里面，其中包含有簽名信息，請求時簽名驗證失敗將直接拋出異常。

引入組件提供的dynamic-invoker.xml配置，將會在系統中自動注入開啟一個專為日志級別調整的接口服務，該接口是一個單純的Thrift服務，能夠通過ZooKeeper實現服務注冊與發現，并且有可視化的開啟與關閉管理后臺，簡單明了，操作方便。

場景二、HTTP服務

對于一些Web項目，暴露一個RPC服務相當不安全。為此，我們提供了HTTP協議接口，接入流程完全一樣，在真正修改日志輸出級別時，會根據系統類型自主判斷使用哪種協議，有獨立實現的簽名認證，安全可靠。

結束語

從2016年9月V1.0版本上線以來，陸續接入外賣配送的20多個核心應用，覆蓋推送、接單、配送調度、斑馬配送、活動等核心交易服務。

舉例：

問題描述：發配送服務化項目由于間接依賴，引入了Logback日志框架。在項目啟動加載時，SLF4J動態綁定到Logback框架上，但是由于發配送項目使用的Log4j，并未配置Logback.xml文件，導致在打印日志時，SLF4J無法匹配到具體的日志配置，從而為項目自動創建了一個日志級別為Debug的ROOT節點，所有的日志以該級別打印輸出，導致發配送服務化項目在中午11：30左右高峰期，短時間內打印過多的系統日志，引起Load飆高，重新修改發版上線已經來不及，如果不能立即解決，勢必造成服務化宕機，損失非常嚴重。
處理結果：使用我們這個日志工具，批量將服務化項目所有的日志輸出級別調整為ERROR級別，大大減少了日志量的輸出，給工程師留出充裕的的時間完美的解決了該問題，避免造成更大的系統故障。
后記：更重要的是以該工具組件為切入點，幫助各業務系統逐漸規范系統日志使用，取得很好效果。

后續我們規劃將其推廣成為公司級別的工具，為越來越多的項目提供便利。

歡迎感興趣的同學與我們進一步交流。

參考文獻

來自：http://tech.meituan.com/change_log_level.html

本文由用戶 NovellaFowl 自行上傳分享，僅供網友學習交流。所有權歸原作者，若您的權利被侵害，請聯系管理員。

轉載本站原創文章，請注明出處，并保留原始鏈接、圖片水印。

本站是一個以用戶分享為主的開源技術平臺，歡迎各類分享！

本文地址：http://www.baiduhome.net/lib/view/open1487380959381.html

日志處理 log4j logback