Springboot MDC+logback實(shí)現(xiàn)日志追蹤的方法
Springboot-MDC+logback實(shí)現(xiàn)日志追蹤
一、MDC介紹
MDC(Mapped Diagnostic Contexts)映射診斷上下文,該特征是logback提供的一種方便在多線程條件下的記錄日志的功能。
某些應(yīng)用程序采用多線程的方式來(lái)處理多個(gè)用戶的請(qǐng)求。在一個(gè)用戶的使用過(guò)程中,可能有多個(gè)不同的線程來(lái)進(jìn)行處理。典型的例子是 Web 應(yīng)用服務(wù)器。當(dāng)用戶訪問(wèn)某個(gè)頁(yè)面時(shí),應(yīng)用服務(wù)器可能會(huì)創(chuàng)建一個(gè)新的線程來(lái)處理該請(qǐng)求,也可能從線程池中復(fù)用已有的線程。在一個(gè)用戶的會(huì)話存續(xù)期間,可能有多個(gè)線程處理過(guò)該用戶的請(qǐng)求。這使得比較難以區(qū)分不同用戶所對(duì)應(yīng)的日志。當(dāng)需要追蹤某個(gè)用戶在系統(tǒng)中的相關(guān)日志記錄時(shí),就會(huì)變得很麻煩。
MDC正是用于解決上述問(wèn)題的,MDC 可以看成是一個(gè)與當(dāng)前線程綁定的哈希表,可以往其中添加鍵值對(duì)。MDC 中包含的內(nèi)容可以被同一線程中執(zhí)行的代碼所訪問(wèn)。當(dāng)前線程的子線程會(huì)繼承其父線程中的 MDC 的內(nèi)容。當(dāng)需要記錄日志時(shí),只需要從 MDC 中獲取所需的信息即可。MDC 的內(nèi)容則由程序在適當(dāng)?shù)臅r(shí)候保存進(jìn)去。對(duì)于一個(gè) Web 應(yīng)用來(lái)說(shuō),通常是在請(qǐng)求被處理的最開(kāi)始保存這些數(shù)據(jù)。
二、MDC實(shí)現(xiàn)日志跟蹤
一個(gè)系統(tǒng)提供服務(wù),提供給其他系統(tǒng)來(lái)調(diào)用,當(dāng)其他系統(tǒng)調(diào)用的時(shí)候,請(qǐng)求頭帶上唯一的請(qǐng)求標(biāo)識(shí)(requestId),把這個(gè)requestId輸出到日志中,這樣兩個(gè)系統(tǒng)直接就會(huì)形成一個(gè)執(zhí)行鏈,用requestId串聯(lián)起來(lái),當(dāng)出現(xiàn)錯(cuò)誤時(shí),可以在調(diào)用方查詢對(duì)應(yīng)的請(qǐng)求日志,也可以在服務(wù)方查詢請(qǐng)求日志,定位問(wèn)題很方便,輸出日志的地方很多??梢允褂肕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這個(gè)key對(duì)應(yīng)的value鑒別日志事件,然后委托給具體appender寫日志--> <discriminator> <key>logTrackId</key> <defaultValue>default</defaultValue> </discriminator> <sift> <!--具體的寫日志appender,每一個(gè)logTrackId創(chuàng)建一個(gè)文件--> <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"> <!--定義文件滾動(dòng)時(shí)的文件名的格式--> <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"> <!-- 不丟失日志.默認(rèn)的,如果隊(duì)列的80%已滿,則會(huì)丟棄TRACT、DEBUG、INFO級(jí)別的日志 --> <discardingThreshold>0</discardingThreshold> <!-- 更改默認(rèn)的隊(duì)列的深度,該值會(huì)影響性能.默認(rèn)值為256 --> <queueSize>512</queueSize> <!-- 添加附加的appender,最多只能添加一個(gè) --> <appender-ref ref="FILE_INFO"/> </appender> <root level="${logLevel}"> <appender-ref ref="STDOUT"/> <appender-ref ref="FILE_INFO"/> </root> </configuration>
擴(kuò)展:
SpringBoot如何利用 MDC 機(jī)制過(guò)濾出單次請(qǐng)求相關(guān)的日志
1.前言
在服務(wù)出現(xiàn)故障時(shí),我們經(jīng)常需要獲取一次請(qǐng)求流程里的所有日志進(jìn)行定位 。如果請(qǐng)求只在一個(gè)線程里處理,則我們可以通過(guò)線程ID來(lái)過(guò)濾日志 ,但如果請(qǐng)求包含異步線程的處理,那么光靠線程ID就顯得捉襟見(jiàn)肘了。
比如華為IoT平臺(tái),提供了接收設(shè)備上報(bào)數(shù)據(jù)的能力, 當(dāng)數(shù)據(jù)到達(dá)平臺(tái)后,平臺(tái)會(huì)進(jìn)行一些復(fù)雜的業(yè)務(wù)邏輯處理,如數(shù)據(jù)存儲(chǔ),規(guī)則引擎,數(shù)據(jù)推送,命令下發(fā)等等。由于這個(gè)邏輯之間沒(méi)有強(qiáng)耦合的關(guān)系,所以通常是異步處理。
如何將一次數(shù)據(jù)上報(bào)請(qǐng)求中包含的所有業(yè)務(wù)日志快速過(guò)濾出來(lái),就是本文要介紹的。
2.MDC 是什么
SLF4J MDC(Mapped Diagnostic Context)是一個(gè)用于日志記錄的實(shí)用工具,它提供了線程級(jí)別的日志上下文信息管理功能。SLF4J(Simple Logging Facade for Java)本身是一個(gè)抽象層,允許我們?cè)谑褂貌煌娜罩究蚣埽ㄈ鏻og4j, logback等),而MDC是SLF4J的一部分,主要在logback和log4j中使用。
MDC允許我們?cè)谝粋€(gè)線程的執(zhí)行上下文中設(shè)置和獲取鍵值對(duì)。這些鍵值對(duì)在日志輸出中可以以占位符的形式被引用,從而在日志信息中輸出這些上下文信息。這特別有用,例如,在Web應(yīng)用中跟蹤用戶請(qǐng)求,或者在分布式系統(tǒng)中跟蹤跨服務(wù)的事務(wù)。
在設(shè)置和清除MDC數(shù)據(jù)時(shí),通常使用put和remove方法,如:
MDC.put("requestId", "12345"); // ... logging statements ... MDC.remove("requestId");
這樣,日志框架在記錄日志時(shí),就可以在日志格式中包含這個(gè)requestId的值。
3.代碼實(shí)戰(zhàn)
通過(guò)上門的介紹你可能還是有點(diǎn)難理解,我們可以先實(shí)戰(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) { // 入口傳入請(qǐng)求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"); // 出口移除請(qǐng)求ID MDC.remove(KEY); } }
我們?cè)趍ain函數(shù)的入口調(diào)用MDC.put()方法傳入請(qǐng)求ID,在出口調(diào)用MDC.remove()方法移除請(qǐng)求ID。配置好log4j2.xml 文件后,運(yùn)行main函數(shù),可以在控制臺(tái)看到以下日志輸出:
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
從日志中可以明顯地看到花括號(hào)中包含了 (映射的) 請(qǐng)求ID(requestId),這其實(shí)就是我們定位 (診斷) 問(wèn)題的關(guān)鍵字 (上下文) 。
有了MDC工具,只要在接口或切面植入put()和remove()代碼,在為服務(wù)定位問(wèn)題時(shí),我們就可以通過(guò)grep requestId=xxx *.log快速的過(guò)濾出某次請(qǐng)求的所有日志。
然而,MDC工具真的有我們所想的這么方便嗎?
回到我們開(kāi)頭,一次請(qǐng)求可能涉及多線程異步處理,那么在多線程異步的場(chǎng)景下,它是否還能正常運(yù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) { // 入口傳入請(qǐng)求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(); // 出口移除請(qǐng)求ID MDC.remove(KEY); } }
代碼里我們新起了一個(gè)異步線程,并在匿名對(duì)象Runnable的run()方法打印日志。運(yùn)行main函數(shù),可以在控制臺(tái)看到以下日志輸出:
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
不幸的是,請(qǐng)求ID在異步線程里不打印了。
這是怎么回事呢?要解決這個(gè)問(wèn)題,我們就得知道MDC的實(shí)現(xiàn)原理。
由于篇幅有限,這里就暫不詳細(xì)介紹,MDC之所以在異步線程中不生效是因?yàn)榈讓硬捎肨hreadLocal 作為數(shù)據(jù)結(jié)構(gòu),我們調(diào)用MDC.put()方法傳入的請(qǐng)求ID只在當(dāng)前線程有效。
知道了原理那么解決這個(gè)問(wèn)題就輕而易舉了,我們可以使用裝飾器模式 ,新寫一個(gè)MDCRunnable類對(duì)Runnable接口進(jìn)行一層裝飾。
在創(chuàng)建MDCRunnable類時(shí)保存當(dāng)前線程的MDC值,在執(zhí)行run()方法時(shí)再將保存的MDC值拷貝到異步線程中去。代碼實(shí)現(xiàn)如下:
public class MDCRunnable implements Runnable { private final Runnable runnable; private final Map<String, String> map; public MDCRunnable(Runnable runnable) { this.runnable = runnable; // 保存當(dāng)前線程的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()); } } }
接著,我們需要對(duì)main函數(shù)里創(chuàng)建的Runnable實(shí)現(xiàn)類進(jì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) { // 入口傳入請(qǐng)求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(); // 出口移除請(qǐng)求ID MDC.remove(KEY); } }
執(zhí)行main函數(shù),將會(huì)輸出以下日志 :
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)過(guò)我們的努力,最終在異步線程和線程池中都有requestId打印了!
4.總結(jié)
本文講述了如何使用MDC工具來(lái)快速過(guò)濾一次請(qǐng)求的所有日志 ,并通過(guò)裝飾器模式使得MDC工具在異步線程里也能生效。利用MDC,再配合AOP技術(shù)對(duì)所有的切面植入requestId,就可以將整個(gè)系統(tǒng)的任意流程的日志過(guò)濾出來(lái)。使用MDC工具,在開(kāi)發(fā)自測(cè)階段,可以極大地節(jié)省定位問(wèn)題的時(shí)間,提升開(kāi)發(fā)效率;在運(yùn)維維護(hù)階段,可以快速地收集相關(guān)日志信息,加快分析速度。
到此這篇關(guān)于SpringBoot利用 MDC 機(jī)制過(guò)濾出單次請(qǐng)求相關(guān)的日志的文章就介紹到這了,更多相關(guān)SpringBoo過(guò)濾出單次請(qǐng)求相關(guān)的日志內(nèi)容請(qǐng)搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家!
- SpringBoot利用MDC機(jī)制過(guò)濾單次請(qǐng)求的所有日志
- SpringBoot項(xiàng)目使用slf4j的MDC日志打點(diǎn)功能(最新推薦)
- SpringBoot MDC全鏈路調(diào)用日志跟蹤實(shí)現(xiàn)詳解
- SpringBoot+MDC實(shí)現(xiàn)鏈路調(diào)用日志的方法
- Springboot+MDC+traceId日志中打印唯一traceId
- SpringBoot 項(xiàng)目添加 MDC 日志鏈路追蹤的執(zhí)行流程
- SpringBoot項(xiàng)目使用MDC給日志增加唯一標(biāo)識(shí)的實(shí)現(xiàn)步驟
相關(guān)文章
java初學(xué)者如何讓編程學(xué)習(xí)起來(lái)更簡(jiǎn)單
我們給大家?guī)?lái)一篇關(guān)于java初學(xué)者如何讓編程學(xué)習(xí)起來(lái)更簡(jiǎn)單的基礎(chǔ)性文章,有需要的朋友們可以學(xué)習(xí)下。2020-11-11Java中的Set集合不允許存儲(chǔ)重復(fù)元素的原理詳解
這篇文章主要介紹了Java中的Set集合不允許存儲(chǔ)重復(fù)元素的原理詳解,我們之前使用Set集合的時(shí)候發(fā)現(xiàn),Set集合的特點(diǎn)是不允許存儲(chǔ)重復(fù)元素,這是為什么呢,下面我們一起來(lái)研究一下,需要的朋友可以參考下2023-09-09詳解APP微信支付(java后臺(tái)_統(tǒng)一下單和回調(diào))
這篇文章主要介紹了APP微信支付(java后臺(tái)_統(tǒng)一下單和回調(diào)),文中通過(guò)示例代碼介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值,需要的朋友們下面隨著小編來(lái)一起學(xué)習(xí)學(xué)習(xí)吧2019-05-05java遞歸處理單位人員組織機(jī)構(gòu)樹(shù)方式
這篇文章主要介紹了java遞歸處理單位人員組織機(jī)構(gòu)樹(shù)方式,具有很好的參考價(jià)值,希望對(duì)大家有所幫助,如有錯(cuò)誤或未考慮完全的地方,望不吝賜教2023-08-08springboot整合httpClient代碼實(shí)例
這篇文章主要介紹了springboot整合httpClient代碼實(shí)例,文中通過(guò)示例代碼介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值,需要的朋友可以參考下2019-12-12詳解Java編程規(guī)約(命名風(fēng)格、常量定義、代碼格式)
這篇文章主要介紹了詳解Java編程規(guī)約(命名風(fēng)格、常量定義、代碼格式),小編覺(jué)得挺不錯(cuò)的,現(xiàn)在分享給大家,也給大家做個(gè)參考。一起跟隨小編過(guò)來(lái)看看吧2019-10-10Java數(shù)據(jù)結(jié)構(gòu)之散列表詳解
散列表(Hash table,也叫哈希表),是根據(jù)關(guān)鍵碼值(Key value)而直接進(jìn)行訪問(wèn)的數(shù)據(jù)結(jié)構(gòu)。本文將為大家具體介紹一下散列表的原理及其代碼實(shí)現(xiàn)2022-01-01在java List中進(jìn)行模糊查詢的實(shí)現(xiàn)方法
下面小編就為大家?guī)?lái)一篇在java List中進(jìn)行模糊查詢的實(shí)現(xiàn)方法。小編覺(jué)得挺不錯(cuò)的,現(xiàn)在就分享給大家,也給大家做個(gè)參考。一起跟隨小編過(guò)來(lái)看看吧2016-11-11Java分支結(jié)構(gòu)程序設(shè)計(jì)實(shí)例詳解
這篇文章主要介紹了Java分支結(jié)構(gòu)程序設(shè)計(jì)例題,本文通過(guò)實(shí)例代碼給大家介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或工作具有一定的參考借鑒價(jià)值,需要的朋友可以參考下2022-01-01Java利用反射自動(dòng)封裝成實(shí)體對(duì)象的方法
這篇文章主要介紹了Java利用反射自動(dòng)封裝成實(shí)體對(duì)象的方法,可實(shí)現(xiàn)自動(dòng)封裝成bean對(duì)象功能,具有一定參考借鑒價(jià)值,需要的朋友可以參考下2015-01-01