基於slf4j日志MDC輸出格式的問題
slf4j日志MDC輸出格式
配置使用
// 自動配置模板 ... <Property name="layout">%d %p %X{traceId} [%t] %c{10}:%M:%L %m%n</Property> ... <PatternLayout pattern="${layout}"/> ... // 具體項目覆蓋配置的格式 <Property name="layout">%d %p [%t] %c{1.}:%M:%L %X{myTraceId} %m%n</Property>
MDC.put("myTraceId", myTraceId); try { ... } catch (Exception e) { ... } finally { MDC.clear(); }
日志輸出效果發現是直接打印瞭myTraceId所對應的的值,而我們期望是這樣的格式{myTraceId=123}。
原因分析
查看格式化的實現類PatternLayout,內部通過PatternSelector匹配選擇器根據Pattern匹配選擇對應的轉換器進行格式化
默認使用MarkerPatternSelector實現,選擇器構造器中解析獲取各個匹配模式對應的格式化實現列表PatternFormatter
PatternFormatter實現的實例屬性LogEventPatternConverter抽象類對具體的日志內容進行格式化轉換,查看其實現類
直接查看MdcPatternConverter實現
構造器中按照逗號“,”切分MDC的key配置
// options, 對應配置中的key列表 private MdcPatternConverter(final String[] options) { super(options != null && options.length > 0 ? "MDC{" + options[0] + '}' : "MDC", "mdc"); if (options != null && options.length > 0) { full = false; if (options[0].indexOf(',') > 0) { // 按照逗號切分key keys = options[0].split(","); for (int i = 0; i < keys.length; i++) { keys[i] = keys[i].trim(); } key = null; } else { keys = null; key = options[0]; } } else { full = true; key = null; keys = null; } }
// 格式化 public void format(final LogEvent event, final StringBuilder toAppendTo) { final ReadOnlyStringMap contextData = event.getContextData(); // if there is no additional options, we output every single // Key/Value pair for the MDC in a similar format to Hashtable.toString() // 如果沒有附加的屬性,我們輸出每一個單獨的MDC配置的key/value對,類似與Hashtable.toString()的格式 if (full) { if (contextData == null || contextData.size() == 0) { toAppendTo.append("{}"); return; } appendFully(contextData, toAppendTo); } else { if (keys != null) { if (contextData == null || contextData.size() == 0) { toAppendTo.append("{}"); return; } // 存在附加屬性配置 appendSelectedKeys(keys, contextData, toAppendTo); } else if (contextData != null){ // otherwise they just want a single key output final Object value = contextData.getValue(key); if (value != null) { StringBuilders.appendValue(toAppendTo, value); } } } }
我們配置瞭%X擴展即存在附加屬性配置
// 按照配置的MDC keys輸出,輸出格式為{key=value,key2=value2} private static void appendSelectedKeys(final String[] keys, final ReadOnlyStringMap contextData, final StringBuilder sb) { // Print all the keys in the array that have a value. final int start = sb.length(); sb.append('{'); for (int i = 0; i < keys.length; i++) { final String theKey = keys[i]; final Object value = contextData.getValue(theKey); if (value != null) { // !contextData.containskey(theKey) if (sb.length() - start > 1) { sb.append(", "); } sb.append(theKey).append('='); StringBuilders.appendValue(sb, value); } } sb.append('}'); }
問題定位後修改配置即可,修改配置後驗證格式符合我們的期望
<Property name="layout">%d %p [%t] %c{1.}:%M:%L %X{myTraceId,} %m%n</Property>
小結一下:MDC配置的key,日志會按照逗號切分出keys列表,如果keys列表小於等於1則直接輸出一個單獨的value值。如果大於1則按照map的格式輸出,即:{key1=value1,key2=value2}
slf4j輸出日志的語法
slf4j輸出log的語法
1. 直接拼接字符串
用字符串拼接的構造方式輸出log,字符串消息還是會被求值,存在類型轉換和字符串連接的性能消耗。例:
int index = 1; logger.info("這是第"+index+"條數據"); logger.info("這是第"+String.valueOf(index)+"條數據");
輸出結果:
2. 使用SLF4J的格式化功能
這種用法不存在上面提到的缺點。SLF4J使用自己的格式化語法{},同時提供瞭適合不同參數個數的方法重載:
logger.debug(String format, Object param); //支持一個參數 logger.debug(String format, Object param1, Object param2); //支持兩個參數 logger.debug(String format, Object… param); //任意數量參數,構造參數數組具有一定的性能損耗
例:
int index1=1;int index2=2;i logger.info("這是第{}條數據",index1); logger.info("這是第{}、{}條數據",index1,index2);
輸出:
3. 格式化占位符的轉義
連續的{}才被認為是格式化占位符
例:
logger.info("{1,2} 這是第{}條數據",index2); logger.info("{1,2} 這是第{{}}條數據",index2);
輸出:
用”\”轉義{}占位符
例:
/**用”\”轉義{}占位符*/ logger.info("\\{} 這是第{}條數據 ",index2); /**用“\”本身轉義“{}”中的”\”*/ logger.info("\\\\{} 這是第{}條數據 ",index3);
輸出:
4. log前做條件判斷
isDebugEnabled()的方法在debug disabled的情況下不存在構造字符串參數的性能消耗,但是如果debug enabled,debug是否被enabled將會被求值兩次:
- 一次是isDebugEnabled(),
- 一次是debug()本身(該影響較小,因為求值logger狀態花費的時間比真正log一條語句花費的時間的1%都還要小)。
例:
if(logger.isDebugEnabled()){ logger.info("這是第{}條數據 ",index2); }
輸出:
5、打印異常堆棧
logger.error("Failed to format {}", s, e);
slf4j總結
slf4j是Java的一種Log Api,類似Apache Commons Logging 。
官網介紹:http://www.slf4j.org/.
在SLF4J中,不需要進行字符串拼接,不會導致使用臨時字符串帶來的消耗。
相反,我們使用帶占位符的模板消息來記錄日志信息,並提供實際值作為參數。可以使用帶參數版的日志方法,也可以通過Object數組傳入。在為日志信息產生最終的字符串之前,該方法會檢查是否開啟瞭特定的日志級別,這不僅降低瞭內存占用,而且預先減少瞭執行字符串拼接所消耗的CPU時間。
log.debug("Found {} records matching filter: '{}'", records, filter);//slf4j log.debug("Found " + records + " records matching filter: '" + filter + "'");//log4j
可以看出SLF4J的優點有:
更簡略易讀;
在日志級別不夠時,少瞭字符串拼接的開銷,不會調用對象(records/filter)的toString方法。通過使用日志記錄方法,直到你使用到的時候,才會去構造日志信息(字符串),這就同時提高瞭內存和CPU的使用率。
Slf4j在1.6.0之後,更是支持瞭異常堆棧的打印,作為最後一個參數傳入即可,基本滿足瞭日志的常見打印場景。
在你的開源庫或者私有庫中使用SLF4J,可以使它獨立於任何的日志實現,這就意味著不需要管理多個庫和多個日志文件。
SLF4J提供瞭占位日志記錄,通過移除對isDebugEnabled(), isInfoEnabled()等等的檢查提高瞭代碼的可讀性。
以上為個人經驗,希望能給大傢一個參考,也希望大傢多多支持WalkonNet。
推薦閱讀:
- org.slf4j.Logger中info()方法的使用詳解
- Python 中 logging 模塊使用詳情
- golang日志包logger的用法詳解
- 集成apollo動態日志取締logback-spring.xml配置
- SpringBoot@Aspect 打印訪問請求和返回數據方式