Logback日志跨線程追蹤實(shí)踐

1. 自定義日志模板參數(shù):Logback的Pattern模板

當(dāng)一個(gè)請(qǐng)求過(guò)來(lái),我們想要知道當(dāng)前請(qǐng)求具體跑了那些流程該怎么做呢? 噔噔噔噔..我們的男主Logback自定義Pattern模板即將登場(chǎng).

在我們打印日志的時(shí)候,通常我們都會(huì)把一些重要的參數(shù)信息寫到日志里面,方便我們后期從日志里面定位問(wèn)題,其他的內(nèi)部系統(tǒng)調(diào)用我們的程序的時(shí)候薇组,我們可以要求他們那邊在header頭里面增加trace-id這樣的唯一標(biāo)識(shí)濒析,如果沒(méi)有該參數(shù)的話拦止,我們自己手動(dòng)生成一個(gè)唯一的標(biāo)識(shí),方便我們將整條請(qǐng)求鏈路構(gòu)建起來(lái).

<property name="CONSOLE_LOG_PATTERN" value="[%yellow(%date{yyyy-MM-dd HH:mm:ss})] [%highlight(%-5level)] [%cyan(%traceId)] [%magenta(%thread)] [%blue(%file:%line)] [%green(%logger)] : %.4000m%n"/>

上面這里是Logback的定義變量,重點(diǎn)關(guān)注[%cyan(%traceId)]這個(gè)參數(shù)(ps:其他的日志系統(tǒng)如log4j2都有類似的實(shí)現(xiàn)


要實(shí)現(xiàn)讓Logback識(shí)別我們自定義的標(biāo)識(shí)符,我們需要繼承兩個(gè)方法ClassicConverter跟PatternLayout,具體實(shí)現(xiàn)如下:

public classPatternLogbackLayoutextendsPatternLayout{

? static {

? ? defaultConverterMap.put("traceId", TraceIdPatternConverter.class.getName());

? }

}public classTraceIdPatternConverterextendsClassicConverter{

@Override publicStringconvert(ILoggingEvent iLoggingEvent){

String traceId = LogHandlerInterceptor.getTrack();

return StringUtils.isEmpty(traceId) ? "traceId" : traceId;

}

}

通過(guò)spring的攔截器我們將請(qǐng)求的header頭里面的參數(shù)賦值給traceId,然后配置logback.xml和橙,讓logback去識(shí)別我們定義的traceId

<appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">

? <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">

? ? ? <layout class="com.blacksearch.logback.PatternLogbackLayout">

? ? ? <pattern>${CONSOLE_LOG_PATTERN}</pattern>

? ? ? </layout>

? </encoder>

</appender>

通過(guò)以上配置,我們已經(jīng)可以在日志里面看到traceId了

[2019-05-10 16:47:38] [INFO ] [538e2c0d-3800-4c86-b320-260bdd945c0c] [http-nio-8080-exec-6] [TestLogTrackController.java:15] [com.blacksearch.controller.TestLogTrackController] : 測(cè)試

[2019-05-10 16:47:38] [DEBUG] [538e2c0d-3800-4c86-b320-260bdd945c0c] [http-nio-8080-exec-6] [AbstractMessageConverterMethodProcessor.java:298] [org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor] : Nothing to write: null body

這樣子在服務(wù)器上面我們可以通過(guò)

grep '538e2c0d-3800-4c86-b320-260bdd945c0c'

查看到當(dāng)前請(qǐng)求的所有日志~或者上ELK之后 直接搜索538e2c0d-3800-4c86-b320-260bdd945c0c 方便開(kāi)心~

2. 當(dāng)我們使用多線程的時(shí)候,我們發(fā)現(xiàn),原先定義的標(biāo)識(shí)居然消失了T冶颉!顺囊!

@RequestMapping("/asynLogTrack")publicStringasynLogTrack(){

logger.info("ces--------");

new Thread(new Runnable() {

@Override publicvoidrun(){

logger.info("ces");

}

}).start();

return null;

}

[2019-05-10 16:55:18] [INFO ] [5b446567-97be-42f7-b6b0-205a6b431e87] [http-nio-8080-exec-2] [TestLogTrackController.java:21] [com.blacksearch.controller.TestLogTrackController] : ces--------

[2019-05-10 16:55:18] [INFO ] [traceId] [Thread-10] [TestLogTrackController.java:25] [com.blacksearch.controller.TestLogTrackController] : ces

[2019-05-10 16:55:18] [DEBUG] [5b446567-97be-42f7-b6b0-205a6b431e87] [http-nio-8080-exec-2] [AbstractMessageConverterMethodProcessor.java:298] [org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor] : Nothing to write: null body

我們看到打印 ces 的打印記錄,我們發(fā)現(xiàn),traceId居然丟失了!!! 原因在于,棧是線程私有,當(dāng)我們新建線程的時(shí)候,新建的線程跟原來(lái)的線程互相獨(dú)立,也就是說(shuō)logback無(wú)法在新建的線程上獲取到值蕉拢。既然如何,那么我們?cè)撊绾巫孡ogback在新線程上獲取到值呢特碳?正如標(biāo)題而言诚亚。

public abstract classTrackRunnableimplementsRunnable{

publicabstractvoidtrackRun();

private String track = LogHandlerInterceptor.getTrack();

@Override publicvoidrun(){

try {

LogHandlerInterceptor.setTrace(track);

trackRun();

}finally {

LogHandlerInterceptor.remove();

}

}

}

我們采用抽象類實(shí)現(xiàn)Runnable,然后在run()方法里面通過(guò)ThreadLocal去重新賦值。eg:

@RequestMapping("/asynLogTrackHasTrace")publicStringasynLogTrackHasTrace(){

logger.info("ces1------");

new Thread(new TrackRunnable() {

@Override publicvoidtrackRun(){

try {

Thread.sleep(4000);

} catch (InterruptedException e) {

e.printStackTrace();

}

logger.info("ces2-----------");

}

}).start();

return null;

}

[2019-05-10 17:07:20] [INFO ] [0a7f30d3-8e1d-49b4-9bca-4b72fd1c0ccd] [http-nio-8080-exec-5] [TestLogTrackController.java:33] [com.blacksearch.controller.TestLogTrackController] : ces1------

[2019-05-10 17:07:20] [DEBUG] [0a7f30d3-8e1d-49b4-9bca-4b72fd1c0ccd] [http-nio-8080-exec-5] [AbstractMessageConverterMethodProcessor.java:298] [org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor] : Nothing to write: null body

[2019-05-10 17:07:20] [DEBUG] [traceId] [http-nio-8080-exec-5] [FrameworkServlet.java:1130] [org.springframework.web.servlet.DispatcherServlet] : Completed 200 OK

[2019-05-10 17:07:24] [INFO ] [0a7f30d3-8e1d-49b4-9bca-4b72fd1c0ccd] [Thread-11] [TestLogTrackController.java:42] [com.blacksearch.controller.TestLogTrackController] : ces2-----------

覺(jué)得不錯(cuò)請(qǐng)點(diǎn)贊支持午乓,歡迎留言或進(jìn)我的個(gè)人群855801563領(lǐng)取【架構(gòu)資料專題目合集90期】站宗、【BATJTMD大廠JAVA面試真題1000+】,本群專用于學(xué)習(xí)交流技術(shù)益愈、分享面試機(jī)會(huì)梢灭,拒絕廣告,我也會(huì)在群內(nèi)不定期答題蒸其、探討敏释。

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 序言:七十年代末,一起剝皮案震驚了整個(gè)濱河市摸袁,隨后出現(xiàn)的幾起案子钥顽,更是在濱河造成了極大的恐慌,老刑警劉巖靠汁,帶你破解...
    沈念sama閱讀 216,372評(píng)論 6 498
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件蜂大,死亡現(xiàn)場(chǎng)離奇詭異,居然都是意外死亡蝶怔,警方通過(guò)查閱死者的電腦和手機(jī)奶浦,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 92,368評(píng)論 3 392
  • 文/潘曉璐 我一進(jìn)店門,熙熙樓的掌柜王于貴愁眉苦臉地迎上來(lái)踢星,“玉大人澳叉,你說(shuō)我怎么就攤上這事≌队” “怎么了耳高?”我有些...
    開(kāi)封第一講書人閱讀 162,415評(píng)論 0 353
  • 文/不壞的土叔 我叫張陵,是天一觀的道長(zhǎng)所踊。 經(jīng)常有香客問(wèn)我泌枪,道長(zhǎng),這世上最難降的妖魔是什么秕岛? 我笑而不...
    開(kāi)封第一講書人閱讀 58,157評(píng)論 1 292
  • 正文 為了忘掉前任碌燕,我火速辦了婚禮,結(jié)果婚禮上继薛,老公的妹妹穿的比我還像新娘修壕。我一直安慰自己,他們只是感情好遏考,可當(dāng)我...
    茶點(diǎn)故事閱讀 67,171評(píng)論 6 388
  • 文/花漫 我一把揭開(kāi)白布慈鸠。 她就那樣靜靜地躺著,像睡著了一般灌具。 火紅的嫁衣襯著肌膚如雪青团。 梳的紋絲不亂的頭發(fā)上譬巫,一...
    開(kāi)封第一講書人閱讀 51,125評(píng)論 1 297
  • 那天,我揣著相機(jī)與錄音督笆,去河邊找鬼芦昔。 笑死,一個(gè)胖子當(dāng)著我的面吹牛娃肿,可吹牛的內(nèi)容都是我干的咕缎。 我是一名探鬼主播,決...
    沈念sama閱讀 40,028評(píng)論 3 417
  • 文/蒼蘭香墨 我猛地睜開(kāi)眼料扰,長(zhǎng)吁一口氣:“原來(lái)是場(chǎng)噩夢(mèng)啊……” “哼凭豪!你這毒婦竟也來(lái)了?” 一聲冷哼從身側(cè)響起记罚,我...
    開(kāi)封第一講書人閱讀 38,887評(píng)論 0 274
  • 序言:老撾萬(wàn)榮一對(duì)情侶失蹤墅诡,失蹤者是張志新(化名)和其女友劉穎,沒(méi)想到半個(gè)月后桐智,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體末早,經(jīng)...
    沈念sama閱讀 45,310評(píng)論 1 310
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡,尸身上長(zhǎng)有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 37,533評(píng)論 2 332
  • 正文 我和宋清朗相戀三年说庭,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了然磷。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片。...
    茶點(diǎn)故事閱讀 39,690評(píng)論 1 348
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡刊驴,死狀恐怖姿搜,靈堂內(nèi)的尸體忽然破棺而出,到底是詐尸還是另有隱情捆憎,我是刑警寧澤舅柜,帶...
    沈念sama閱讀 35,411評(píng)論 5 343
  • 正文 年R本政府宣布,位于F島的核電站躲惰,受9級(jí)特大地震影響致份,放射性物質(zhì)發(fā)生泄漏。R本人自食惡果不足惜础拨,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,004評(píng)論 3 325
  • 文/蒙蒙 一氮块、第九天 我趴在偏房一處隱蔽的房頂上張望。 院中可真熱鬧诡宗,春花似錦滔蝉、人聲如沸。這莊子的主人今日做“春日...
    開(kāi)封第一講書人閱讀 31,659評(píng)論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽(yáng)。三九已至,卻和暖如春立肘,著一層夾襖步出監(jiān)牢的瞬間边坤,已是汗流浹背名扛。 一陣腳步聲響...
    開(kāi)封第一講書人閱讀 32,812評(píng)論 1 268
  • 我被黑心中介騙來(lái)泰國(guó)打工谅年, 沒(méi)想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留,地道東北人肮韧。 一個(gè)月前我還...
    沈念sama閱讀 47,693評(píng)論 2 368
  • 正文 我出身青樓融蹂,卻偏偏與公主長(zhǎng)得像,于是被迫代替她去往敵國(guó)和親弄企。 傳聞我的和親對(duì)象是個(gè)殘疾皇子超燃,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 44,577評(píng)論 2 353

推薦閱讀更多精彩內(nèi)容