Springboot MDC+logback實現(xiàn)日志追蹤的方法
Springboot-MDC+logback實現(xiàn)日志追蹤
一、MDC介紹
MDC(Mapped Diagnostic Contexts)映射診斷上下文,該特征是logback提供的一種方便在多線程條件下的記錄日志的功能。
某些應用程序采用多線程的方式來處理多個用戶的請求。在一個用戶的使用過程中,可能有多個不同的線程來進行處理。典型的例子是 Web 應用服務器。當用戶訪問某個頁面時,應用服務器可能會創(chuàng)建一個新的線程來處理該請求,也可能從線程池中復用已有的線程。在一個用戶的會話存續(xù)期間,可能有多個線程處理過該用戶的請求。這使得比較難以區(qū)分不同用戶所對應的日志。當需要追蹤某個用戶在系統(tǒng)中的相關日志記錄時,就會變得很麻煩。
MDC正是用于解決上述問題的,MDC 可以看成是一個與當前線程綁定的哈希表,可以往其中添加鍵值對。MDC 中包含的內(nèi)容可以被同一線程中執(zhí)行的代碼所訪問。當前線程的子線程會繼承其父線程中的 MDC 的內(nèi)容。當需要記錄日志時,只需要從 MDC 中獲取所需的信息即可。MDC 的內(nèi)容則由程序在適當?shù)臅r候保存進去。對于一個 Web 應用來說,通常是在請求被處理的最開始保存這些數(shù)據(jù)。
二、MDC實現(xiàn)日志跟蹤
一個系統(tǒng)提供服務,提供給其他系統(tǒng)來調(diào)用,當其他系統(tǒng)調(diào)用的時候,請求頭帶上唯一的請求標識(requestId),把這個requestId輸出到日志中,這樣兩個系統(tǒng)直接就會形成一個執(zhí)行鏈,用requestId串聯(lián)起來,當出現(xiàn)錯誤時,可以在調(diào)用方查詢對應的請求日志,也可以在服務方查詢請求日志,定位問題很方便,輸出日志的地方很多??梢允褂肕DC配合logback中的pattern。
三、HandlerInterceptor攔截器
import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.slf4j.MDC; import org.springframework.stereotype.Component; import org.springframework.web.servlet.HandlerInterceptor; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; @Component public class TokenInterceptor implements HandlerInterceptor { private static final Logger logger = LoggerFactory.getLogger(TokenInterceptor.class); @Override public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) { //添加MDC日志 String appkey = request.getHeader("appkey"); MDC.put("logTrackId", appkey); return true; } @Override public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) { //移除MDC日志 MDC.remove("logTrackId"); } }
四、logback文件
<?xml version="1.0" encoding="UTF-8"?> <configuration> <property name="logLevel" value="INFO"></property> <property name="logPath" value="./logs"></property> <property name="maxHistory" value="31"/> <property name="maxFileSize" value="100MB"/> <property name="totalSizeCap" value="200GB"/> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss} %-4relative [%thread] [%X{logTrackId}] %-5level %logger{35} - %msg %n</pattern> </encoder> </appender> <appender name="FILE_INFO" class="ch.qos.logback.classic.sift.SiftingAppender"> <!--discriminator鑒別器,根據(jù)logTrackId這個key對應的value鑒別日志事件,然后委托給具體appender寫日志--> <discriminator> <key>logTrackId</key> <defaultValue>default</defaultValue> </discriminator> <sift> <!--具體的寫日志appender,每一個logTrackId創(chuàng)建一個文件--> <appender name="FILE-${logTrackId}" class="ch.qos.logback.core.rolling.RollingFileAppender"> <!--直接指定文件路徑--> <append>true</append> <encoder charset="UTF-8"> <pattern>%d{yyyy-MM-dd HH:mm:ss} %-4relative [%thread] [%X{logTrackId}] %-5level %logger{35} - %msg%n</pattern> </encoder> <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy"> <!--定義文件滾動時的文件名的格式--> <fileNamePattern>${logPath}/%d{yyyy-MM-dd}/${logTrackId}-%i.log</fileNamePattern> <maxHistory>${maxHistory}</maxHistory> <maxFileSize>${maxFileSize}</maxFileSize> <totalSizeCap>${totalSizeCap}</totalSizeCap> </rollingPolicy> <filter class="ch.qos.logback.classic.filter.ThresholdFilter"> <level>INFO</level> </filter> </appender> </sift> </appender> <!-- 異步輸出 --> <appender name="ASYNC-INFO" class="ch.qos.logback.classic.AsyncAppender"> <!-- 不丟失日志.默認的,如果隊列的80%已滿,則會丟棄TRACT、DEBUG、INFO級別的日志 --> <discardingThreshold>0</discardingThreshold> <!-- 更改默認的隊列的深度,該值會影響性能.默認值為256 --> <queueSize>512</queueSize> <!-- 添加附加的appender,最多只能添加一個 --> <appender-ref ref="FILE_INFO"/> </appender> <root level="${logLevel}"> <appender-ref ref="STDOUT"/> <appender-ref ref="FILE_INFO"/> </root> </configuration>
擴展:
SpringBoot如何利用 MDC 機制過濾出單次請求相關的日志
1.前言
在服務出現(xiàn)故障時,我們經(jīng)常需要獲取一次請求流程里的所有日志進行定位 。如果請求只在一個線程里處理,則我們可以通過線程ID來過濾日志 ,但如果請求包含異步線程的處理,那么光靠線程ID就顯得捉襟見肘了。
比如華為IoT平臺,提供了接收設備上報數(shù)據(jù)的能力, 當數(shù)據(jù)到達平臺后,平臺會進行一些復雜的業(yè)務邏輯處理,如數(shù)據(jù)存儲,規(guī)則引擎,數(shù)據(jù)推送,命令下發(fā)等等。由于這個邏輯之間沒有強耦合的關系,所以通常是異步處理。
如何將一次數(shù)據(jù)上報請求中包含的所有業(yè)務日志快速過濾出來,就是本文要介紹的。
2.MDC 是什么
SLF4J MDC(Mapped Diagnostic Context)是一個用于日志記錄的實用工具,它提供了線程級別的日志上下文信息管理功能。SLF4J(Simple Logging Facade for Java)本身是一個抽象層,允許我們在使用不同的日志框架(如log4j, logback等),而MDC是SLF4J的一部分,主要在logback和log4j中使用。
MDC允許我們在一個線程的執(zhí)行上下文中設置和獲取鍵值對。這些鍵值對在日志輸出中可以以占位符的形式被引用,從而在日志信息中輸出這些上下文信息。這特別有用,例如,在Web應用中跟蹤用戶請求,或者在分布式系統(tǒng)中跟蹤跨服務的事務。
在設置和清除MDC數(shù)據(jù)時,通常使用put和remove方法,如:
MDC.put("requestId", "12345"); // ... logging statements ... MDC.remove("requestId");
這樣,日志框架在記錄日志時,就可以在日志格式中包含這個requestId的值。
3.代碼實戰(zhàn)
通過上門的介紹你可能還是有點難理解,我們可以先實戰(zhàn)一把。
public class Main { private static final String KEY = "requestId"; private static final Logger logger = LoggerFactory.getLogger(Main.class); public static void main(String[] args) { // 入口傳入請求ID MDC.put(KEY, UUID.randomUUID().toString()); // 打印日志 logger.debug("log in main thread 1"); logger.debug("log in main thread 2"); logger.debug("log in main thread 3"); // 出口移除請求ID MDC.remove(KEY); } }
我們在main函數(shù)的入口調(diào)用MDC.put()方法傳入請求ID,在出口調(diào)用MDC.remove()方法移除請求ID。配置好log4j2.xml 文件后,運行main函數(shù),可以在控制臺看到以下日志輸出:
2018-02-17 13:19:52.606 {requestId=f97ea0fb-2a43-40f4-a3e8-711f776857d0} [main] DEBUG cn.wudashan.Main - log in main thread 1
2018-02-17 13:19:52.609 {requestId=f97ea0fb-2a43-40f4-a3e8-711f776857d0} [main] DEBUG cn.wudashan.Main - log in main thread 2
2018-02-17 13:19:52.609 {requestId=f97ea0fb-2a43-40f4-a3e8-711f776857d0} [main] DEBUG cn.wudashan.Main - log in main thread 3
從日志中可以明顯地看到花括號中包含了 (映射的) 請求ID(requestId),這其實就是我們定位 (診斷) 問題的關鍵字 (上下文) 。
有了MDC工具,只要在接口或切面植入put()和remove()代碼,在為服務定位問題時,我們就可以通過grep requestId=xxx *.log快速的過濾出某次請求的所有日志。
然而,MDC工具真的有我們所想的這么方便嗎?
回到我們開頭,一次請求可能涉及多線程異步處理,那么在多線程異步的場景下,它是否還能正常運作呢?
public class Main { private static final String KEY = "requestId"; private static final Logger logger = LoggerFactory.getLogger(Main.class); public static void main(String[] args) { // 入口傳入請求ID MDC.put(KEY, UUID.randomUUID().toString()); // 主線程打印<font style="color: #1e6bb8;word-wrap: break-word;font-weight: bold;border-bottom: 1px solid">日志</font> logger.debug("log in main thread"); // 異步線程打印<font style="color: #1e6bb8;word-wrap: break-word;font-weight: bold;border-bottom: 1px solid">日志</font> new Thread(new Runnable() { @Override public void run() { logger.debug("log in other thread"); } }).start(); // 出口移除請求ID MDC.remove(KEY); } }
代碼里我們新起了一個異步線程,并在匿名對象Runnable的run()方法打印日志。運行main函數(shù),可以在控制臺看到以下日志輸出:
2018-02-17 14:05:43.487 {requestId=e6099c85-72be-4986-8a28-de6bb2e52b01} [main] DEBUG cn.wudashan.Main - log in main thread
2018-02-17 14:05:43.490 {} [Thread-1] DEBUG cn.wudashan.Main - log in other thread
不幸的是,請求ID在異步線程里不打印了。
這是怎么回事呢?要解決這個問題,我們就得知道MDC的實現(xiàn)原理。
由于篇幅有限,這里就暫不詳細介紹,MDC之所以在異步線程中不生效是因為底層采用ThreadLocal 作為數(shù)據(jù)結構,我們調(diào)用MDC.put()方法傳入的請求ID只在當前線程有效。
知道了原理那么解決這個問題就輕而易舉了,我們可以使用裝飾器模式 ,新寫一個MDCRunnable類對Runnable接口進行一層裝飾。
在創(chuàng)建MDCRunnable類時保存當前線程的MDC值,在執(zhí)行run()方法時再將保存的MDC值拷貝到異步線程中去。代碼實現(xiàn)如下:
public class MDCRunnable implements Runnable { private final Runnable runnable; private final Map<String, String> map; public MDCRunnable(Runnable runnable) { this.runnable = runnable; // 保存當前線程的MDC值 this.map = MDC.getCopyOfContextMap(); } @Override public void run() { // 傳入已保存的MDC值 for (Map.Entry<String, String> entry : map.entrySet()) { MDC.put(entry.getKey(), entry.getValue()); } // 裝飾器模式,執(zhí)行run方法 runnable.run(); // 移除已保存的MDC值 for (Map.Entry<String, String> entry : map.entrySet()) { MDC.remove(entry.getKey()); } } }
接著,我們需要對main函數(shù)里創(chuàng)建的Runnable實現(xiàn)類進行裝飾:
public class Main { private static final String KEY = "requestId"; private static final Logger logger = LoggerFactory.getLogger(Main.class); private static final ExecutorService EXECUTOR = Executors.newSingleThreadExecutor(); public static void main(String[] args) { // 入口傳入請求ID MDC.put(KEY, UUID.randomUUID().toString()); // 主線程打印<font style="color: #1e6bb8;word-wrap: break-word;font-weight: bold;border-bottom: 1px solid">日志</font> logger.debug("log in main thread"); // 異步線程打印<font style="color: #1e6bb8;word-wrap: break-word;font-weight: bold;border-bottom: 1px solid">日志</font>,用MDCRunnable裝飾Runnable new Thread(new MDCRunnable(new Runnable() { @Override public void run() { logger.debug("log in other thread"); } })).start(); // 異步線程池打印日志,用MDCRunnable裝飾Runnable EXECUTOR.execute(new MDCRunnable(new Runnable() { @Override public void run() { logger.debug("log in other thread pool"); } })); EXECUTOR.shutdown(); // 出口移除請求ID MDC.remove(KEY); } }
執(zhí)行main函數(shù),將會輸出以下日志 :
2018-03-04 23:44:05.343 {requestId=5ee2a117-e090-41d8-977b-cef5dea09d34} [main] DEBUG cn.wudashan.Main - log in main thread
2018-03-04 23:44:05.346 {requestId=5ee2a117-e090-41d8-977b-cef5dea09d34} [Thread-1] DEBUG cn.wudashan.Main - log in other thread
2018-03-04 23:44:05.347 {requestId=5ee2a117-e090-41d8-977b-cef5dea09d34} [pool-2-thread-1] DEBUG cn.wudashan.Main - log in other thread pool
Congratulations! 經(jīng)過我們的努力,最終在異步線程和線程池中都有requestId打印了!
4.總結
本文講述了如何使用MDC工具來快速過濾一次請求的所有日志 ,并通過裝飾器模式使得MDC工具在異步線程里也能生效。利用MDC,再配合AOP技術對所有的切面植入requestId,就可以將整個系統(tǒng)的任意流程的日志過濾出來。使用MDC工具,在開發(fā)自測階段,可以極大地節(jié)省定位問題的時間,提升開發(fā)效率;在運維維護階段,可以快速地收集相關日志信息,加快分析速度。
到此這篇關于SpringBoot利用 MDC 機制過濾出單次請求相關的日志的文章就介紹到這了,更多相關SpringBoo過濾出單次請求相關的日志內(nèi)容請搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關文章希望大家以后多多支持腳本之家!
相關文章
詳解APP微信支付(java后臺_統(tǒng)一下單和回調(diào))
這篇文章主要介紹了APP微信支付(java后臺_統(tǒng)一下單和回調(diào)),文中通過示例代碼介紹的非常詳細,對大家的學習或者工作具有一定的參考學習價值,需要的朋友們下面隨著小編來一起學習學習吧2019-05-05詳解Java編程規(guī)約(命名風格、常量定義、代碼格式)
這篇文章主要介紹了詳解Java編程規(guī)約(命名風格、常量定義、代碼格式),小編覺得挺不錯的,現(xiàn)在分享給大家,也給大家做個參考。一起跟隨小編過來看看吧2019-10-10