01、前言
在現(xiàn)網(wǎng)出現(xiàn)故障時(shí),我們經(jīng)常需要獲取一次請(qǐng)求流程里的所有日志進(jìn)行定位。如果請(qǐng)求只在一個(gè)線程里處理,則我們可以通過線程ID來過濾日志,但如果請(qǐng)求包含異步線程的處理,那么光靠線程ID就顯得捉襟見肘了。
華為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è)邏輯之間沒有強(qiáng)耦合的關(guān)系,所以通常是異步處理。如何將一次數(shù)據(jù)上報(bào)請(qǐng)求中包含的所有業(yè)務(wù)日志快速過濾出來,就是本文要介紹的。
02、正文
SLF4J日志框架提供了一個(gè)MDC(Mapped Diagnostic Contexts)工具類,谷歌翻譯為映射的診斷上下文,從字面上很難理解,我們可以先實(shí)戰(zhàn)一把。
publicclassMain{ privatestaticfinalStringKEY="requestId"; privatestaticfinalLoggerlogger=LoggerFactory.getLogger(Main.class); publicstaticvoidmain(String[]args){ //入口傳入請(qǐng)求ID MDC.put(KEY,UUID.randomUUID().toString()); //打印日志 logger.debug("loginmainthread1"); logger.debug("loginmainthread2"); logger.debug("loginmainthread3"); //出口移除請(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-1713:19:52.606{requestId=f97ea0fb-2a43-40f4-a3e8-711f776857d0}[main]DEBUGcn.wudashan.Main-loginmainthread1 2018-02-1713:19:52.609{requestId=f97ea0fb-2a43-40f4-a3e8-711f776857d0}[main]DEBUGcn.wudashan.Main-loginmainthread2 2018-02-1713:19:52.609{requestId=f97ea0fb-2a43-40f4-a3e8-711f776857d0}[main]DEBUGcn.wudashan.Main-loginmainthread3
從日志中可以明顯地看到花括號(hào)中包含了(映射的)*請(qǐng)求ID(requestId),這其實(shí)就是我們定位*(診斷)*問題的關(guān)鍵字*(上下文)。有了MDC工具,只要在接口或切面植入put()和remove()代碼,在現(xiàn)網(wǎng)定位問題時(shí),我們就可以通過grep requestId=xxx *.log快速的過濾出某次請(qǐng)求的所有日志。
03、進(jìn)階
然而,MDC工具真的有我們所想的這么方便嗎?回到我們開頭,一次請(qǐng)求可能涉及多線程異步處理,那么在多線程異步的場(chǎng)景下,它是否還能正常運(yùn)作呢?Talk is cheap, show me the code。
publicclassMain{ privatestaticfinalStringKEY="requestId"; privatestaticfinalLoggerlogger=LoggerFactory.getLogger(Main.class); publicstaticvoidmain(String[]args){ //入口傳入請(qǐng)求ID MDC.put(KEY,UUID.randomUUID().toString()); //主線程打印日志 logger.debug("loginmainthread"); //異步線程打印日志 newThread(newRunnable(){ @Override publicvoidrun(){ logger.debug("loginotherthread"); } }).start(); //出口移除請(qǐng)求ID MDC.remove(KEY); } }
代碼里我們新起了一個(gè)異步線程,并在匿名對(duì)象Runnable的run()方法打印日志。運(yùn)行main函數(shù),可以在控制臺(tái)看到以下日志輸出:
2018-02-1714:05:43.487{requestId=e6099c85-72be-4986-8a28-de6bb2e52b01}[main]DEBUGcn.wudashan.Main-loginmainthread 2018-02-1714:05:43.490{}[Thread-1]DEBUGcn.wudashan.Main-loginotherthread
不幸的是,請(qǐng)求ID在異步線程里不打印了。這是怎么回事呢?要解決這個(gè)問題,我們就得知道MDC的實(shí)現(xiàn)原理。由于篇幅有限,這里就暫不詳細(xì)介紹,MDC之所以在異步線程中不生效是因?yàn)榈讓硬捎?strong>ThreadLocal作為數(shù)據(jù)結(jié)構(gòu),我們調(diào)用MDC.put()方法傳入的請(qǐng)求ID只在當(dāng)前線程有效。感興趣的小伙伴可以自己深入一下代碼細(xì)節(jié)。
知道了原理那么解決這個(gè)問題就輕而易舉了,我們可以使用裝飾器模式,新寫一個(gè)MDCRunnable類對(duì)Runnable接口進(jìn)行一層裝飾。在創(chuàng)建MDCRunnable類時(shí)保存當(dāng)前線程的MDC值,在執(zhí)行run()方法時(shí)再將保存的MDC值拷貝到異步線程中去。代碼實(shí)現(xiàn)如下:
publicclassMDCRunnableimplementsRunnable{ privatefinalRunnablerunnable; privatefinalMapmap; publicMDCRunnable(Runnablerunnable){ this.runnable=runnable; //保存當(dāng)前線程的MDC值 this.map=MDC.getCopyOfContextMap(); } @Override publicvoidrun(){ //傳入已保存的MDC值 for(Map.Entry entry:map.entrySet()){ MDC.put(entry.getKey(),entry.getValue()); } //裝飾器模式,執(zhí)行run方法 runnable.run(); //移除已保存的MDC值 for(Map.Entry entry:map.entrySet()){ MDC.remove(entry.getKey()); } } }
接著,我們需要對(duì)main函數(shù)里創(chuàng)建的Runnable實(shí)現(xiàn)類進(jìn)行裝飾:
publicclassMain{ privatestaticfinalStringKEY="requestId"; privatestaticfinalLoggerlogger=LoggerFactory.getLogger(Main.class); privatestaticfinalExecutorServiceEXECUTOR=Executors.newSingleThreadExecutor(); publicstaticvoidmain(String[]args){ //入口傳入請(qǐng)求ID MDC.put(KEY,UUID.randomUUID().toString()); //主線程打印日志 logger.debug("loginmainthread"); //異步線程打印日志,用MDCRunnable裝飾Runnable newThread(newMDCRunnable(newRunnable(){ @Override publicvoidrun(){ logger.debug("loginotherthread"); } })).start(); //異步線程池打印日志,用MDCRunnable裝飾Runnable EXECUTOR.execute(newMDCRunnable(newRunnable(){ @Override publicvoidrun(){ logger.debug("loginotherthreadpool"); } })); EXECUTOR.shutdown(); //出口移除請(qǐng)求ID MDC.remove(KEY); } }
執(zhí)行main函數(shù),將會(huì)輸出以下日志:
2018-03-042305.343{requestId=5ee2a117-e090-41d8-977b-cef5dea09d34}[main]DEBUGcn.wudashan.Main-loginmainthread 2018-03-042305.346{requestId=5ee2a117-e090-41d8-977b-cef5dea09d34}[Thread-1]DEBUGcn.wudashan.Main-loginotherthread 2018-03-042305.347{requestId=5ee2a117-e090-41d8-977b-cef5dea09d34}[pool-2-thread-1]DEBUGcn.wudashan.Main-loginotherthreadpool
Congratulations!經(jīng)過我們的努力,最終在異步線程和線程池中都有requestId打印了!
04、總結(jié)
本文講述了如何使用MDC工具來快速過濾一次請(qǐng)求的所有日志,并通過裝飾器模式使得MDC工具在異步線程里也能生效。有了MDC,再通過AOP技術(shù)對(duì)所有的切面植入requestId,就可以將整個(gè)系統(tǒng)的任意流程的日志過濾出來。使用MDC工具,在開發(fā)自測(cè)階段,可以極大地節(jié)省定位問題的時(shí)間,提升開發(fā)效率;在運(yùn)維維護(hù)階段,可以快速地收集相關(guān)日志信息,加快分析速度。
審核編輯:劉清
-
AOP
+關(guān)注
關(guān)注
0文章
40瀏覽量
11238
原文標(biāo)題:Spring Boot 如何快速過濾出一次請(qǐng)求的所有日志?
文章出處:【微信號(hào):芋道源碼,微信公眾號(hào):芋道源碼】歡迎添加關(guān)注!文章轉(zhuǎn)載請(qǐng)注明出處。
發(fā)布評(píng)論請(qǐng)先 登錄
啟動(dòng)Spring Boot項(xiàng)目應(yīng)用的三種方法
java 日志框架Spring Boot分析
Spring Boot從零入門1 詳述
Spring Boot特有的實(shí)踐
強(qiáng)大的Spring Boot 3.0要來了
SpringBoot如何快速過濾出一次請(qǐng)求的所有日志?
怎樣使用Kiuwan保護(hù)Spring Boot應(yīng)用程序呢?
Spring Boot Web相關(guān)的基礎(chǔ)知識(shí)
Spring Boot如何實(shí)現(xiàn)日志鏈路追蹤

Spring Boot的日志框架使用

Spring Boot Actuator快速入門
Spring Boot啟動(dòng) Eureka流程

Spring Boot的啟動(dòng)原理

評(píng)論