日誌級別動態調整--小工具解決大問題
背景
隨著外賣業務的快速發展,業務複雜度不斷增加,線上系統環境有任何細小波動,對整個外賣業務都可能產生巨大的影響,甚至形成災難性的雪崩效應,造成巨大的經濟損失,因而每一次客訴、系統抖動等都是對我們技術人員的重大考驗:我們必須立即響應,快速解決問題。但是,如何提高排查問題的效率呢?最有效的方式是通過分析系統日誌。如果系統日誌全面,會給我們排查解決線上問題帶來絕大幫助,但是要想保證系統日誌全面,就必須打印出所有的系統或業務日誌,這樣就會帶來另一個問題:日誌量的暴漲,過多的日誌除了能夠幫助我們解決問題外,同時會直接造成系統性能下降,極端情況下,甚至導致系統宕機。在這種背景下,為了兼顧效能和快速響應線上問題,我們設計開發了日誌級別動態調整元件。通過使用該元件,可以在需要解決線上問題時,實時調整線上日誌輸出級別,獲取全面的debug日誌,幫助工程師提高定位問題的效率。
場景介紹
場景一:
業務依賴複雜,某一時刻,依賴的下游服務故障,導致請求大量超時,尤其是對於外賣這種集中性特別明顯的業務,平均每秒QPS在8000以上,1分鐘的故障就會集中產生大量的錯誤日誌,導致磁碟IO急劇提高,耗費大量cpu,進而導致整個服務癱瘓。如果該業務不能立即降級,怎麼辦?
修改日誌級別,發版上線,流程長,操作麻煩暫且不談,同時存在引入其它故障的高風險。如果系統恰好使用的log4j版本,在面對極短時間內打印出的海量錯誤日誌,會快速耗盡buffer區記憶體,從而拖慢主執行緒,造成服務效能整體下降,甚至還未來得及修復問題,海量日誌已經拖垮服務,造成服務宕機了,損失慘重。
場景二:
大量的訂單、結算等客訴問題反饋過來,一線工程師大量精力埋沒於排查問題中,而排查定位問題的最終手段仍然是依賴線上日誌,由於鏈路較長,任一日誌的缺失,都給問題的排查帶來極大的障礙,面對運營的催促,怎麼辦?
工程師為了以後排查問題的方便,在任一可能出現異常的地方,打印出關鍵日誌。然後發版上線,好不容易解決了本次問題,還沒來得及收穫喜悅,就又面臨著一個新問題,請看場景三。
場景三:
由於線上業務系統預設日誌列印級別是INFO級別,為了排查問題方便,除錯型日誌都以該級別打印出,給系統帶來了額外的負擔,高峰期大量除錯日誌拖慢系統性能,增大出故障的風險,怎麼辦?
一方面要快速響應業務,另一方面要兼顧系統性能,是否可以兩方面都兼顧?我們的動態調整日誌級別工具正是為了解決這種痛點。
該元件能夠解決什麼問題?
1、日誌降級。相容log4j、log4j2和logback主流日誌框架,如果遇到場景一,可以通過我們的日誌工具,快速調整日誌輸出級別,降低系統日誌的輸出,從而達到日誌降級的效果,同時能夠給RD爭取充裕的排查問題時間。
2、規範日誌級別濫用,幫助工程師快速定位解決線上問題。使用日誌級別動態調整元件,可以實時動態調整線上服務的日誌列印級別,除錯型日誌可以使用低級別打印出,減輕線上服務的負載壓力,遇到排查問題時,可以臨時將日誌級別調低,快速得到精準化的日誌資訊,排查解決問題。
系統基礎架構
日誌級別動態調整元件定位為中介軟體,在設計之初重點考慮了以下幾點:
1、低侵入性
- 接入服務僅需要引入jar包和xml配置檔案即可,不存在額外編碼工作,業務耦合低,接入成本小。
2、安全可靠
- 更改接入服務的日誌輸出級別,只能通過我們授權的後臺系統操作,所有的操作記錄有跡可查。
- 引入許可權認證,確保工程師只能操作自己負責的服務或系統,同時會把操作內容實時周知給系統的所有相關責任人,避免誤傷。
3、視覺化操作
- 操作者可以通過我們提供的管理頁面,定向修改一個或一批服務節點。
- 提供視覺化的操控開關,可以隨時關閉或開啟服務。
具體實現
核心呼叫元件
本元件採用工廠模式實現,保障其高可擴充套件性。目前已實現日誌級別動態調整和方法呼叫處理單元,下面主要介紹日誌級別動態調整處理單元的實現。
目前咱們外賣業務系統基本統一採用的slf4j日誌框架,在應用初始化時,slf4j會繫結具體的日誌框架,如log4j、logback或log4j2等。具體原始碼如下(slf4j-api-1.7.7):
private final static void bind() { try { Set<URL> staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet(); reportMultipleBindingAmbiguity(staticLoggerBinderPathSet); // the next line does the binding StaticLoggerBinder.getSingleton(); INITIALIZATION_STATE = SUCCESSFUL_INITIALIZATION; reportActualBinding(staticLoggerBinderPathSet); fixSubstitutedLoggers(); } catch (NoClassDefFoundError ncde) { String msg = ncde.getMessage(); if (messageContainsOrgSlf4jImplStaticLoggerBinder(msg)) { INITIALIZATION_STATE = NOP_FALLBACK_INITIALIZATION; Util.report( "Failed to load class \"org.slf4j.impl.StaticLoggerBinder\"." ); Util.report( "Defaulting to no-operation (NOP) logger implementation" ); Util.report( "See " + NO_STATICLOGGERBINDER_URL + " for further details." ); } else { failedBinding(ncde); throw ncde; } } catch (java.lang.NoSuchMethodError nsme) { String msg = nsme.getMessage(); if (msg != null && msg.indexOf( "org.slf4j.impl.StaticLoggerBinder.getSingleton()" ) != - 1 ) { INITIALIZATION_STATE = FAILED_INITIALIZATION; Util.report( "slf4j-api 1.6.x (or later) is incompatible with this binding." ); Util.report( "Your binding is version 1.5.5 or earlier." ); Util.report( "Upgrade your binding to version 1.6.x." ); } throw nsme; } catch (Exception e) { failedBinding(e); throw new IllegalStateException( "Unexpected initialization failure" , e); } } |
findPossibleStaticLoggerBinderPathSet方法用來查詢當前classpath下所有的org.slf4j.impl.StaticLoggerBinder類。每一個slf4j橋接包中都有一個StaticLoggerBinder類,該類實現了LoggerFactoryBinder介面。具體繫結到哪一個日誌框架則取決於類載入順序。
接下來,咱們分三部分,來說說ChangeLogLevelProcessUnit類:
1.初始化:確定所使用的日誌框架,獲取配置檔案中所有的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
|