java 日志追蹤MDC
MDC ( Mapped Diagnostic Contexts ) 有了日志之后，我們就可以追蹤各種線上問題。
但是，在分布式系統(tǒng)中，各種無關(guān)日志穿行其中，導(dǎo)致我們可能無法直接定位整個(gè)操作流程。
因此，我們可能需要對(duì)一個(gè)用戶的操作流程進(jìn)行歸類標(biāo)記，比如使用線程+時(shí)間戳，或者用戶身份標(biāo)識(shí)等；如此，我們可以從大量日志信息中g(shù)rep出某個(gè)用戶的操作流程，或者某個(gè)時(shí)間的流轉(zhuǎn)記錄。其目的是為了便于我們?cè)\斷線上問題而出現(xiàn)的方法工具類。
雖然，Slf4j 是用來適配其他的日志具體實(shí)現(xiàn)包的，但是針對(duì) MDC功能，目前只有l(wèi)ogback 以及 log4j 支持。 MDC
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
|
package org.slf4j; import java.io.Closeable;import java.util.Map; import org.slf4j.helpers.NOPMDCAdapter;import org.slf4j.helpers.BasicMDCAdapter;import org.slf4j.helpers.Util;import org.slf4j.impl.StaticMDCBinder;import org.slf4j.spi.MDCAdapter; public class MDC { static final String NULL_MDCA_URL = "http://www.slf4j.org/codes.html#null_MDCA"; static final String NO_STATIC_MDC_BINDER_URL = "http://www.slf4j.org/codes.html#no_static_mdc_binder"; static MDCAdapter mdcAdapter; public static class MDCCloseable implements Closeable { private final String key; private MDCCloseable(String key) { this.key = key; } public void close() { MDC.remove(this.key); } } private MDC() { } static { try { mdcAdapter = StaticMDCBinder.SINGLETON.getMDCA(); } catch (NoClassDefFoundError ncde) { mdcAdapter = new NOPMDCAdapter(); String msg = ncde.getMessage(); if (msg != null && msg.indexOf("StaticMDCBinder") != -1) { Util.report("Failed to load class \"org.slf4j.impl.StaticMDCBinder\"."); Util.report("Defaulting to no-operation MDCAdapter implementation."); Util.report("See " + NO_STATIC_MDC_BINDER_URL + " for further details."); } else { throw ncde; } } catch (Exception e) { // we should never get here Util.report("MDC binding unsuccessful.", e); } } public static void put(String key, String val) throws IllegalArgumentException { if (key == null) { throw new IllegalArgumentException("key parameter cannot be null"); } if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL); } mdcAdapter.put(key, val); } public static MDCCloseable putCloseable(String key, String val) throws IllegalArgumentException { put(key, val); return new MDCCloseable(key); } public static String get(String key) throws IllegalArgumentException { if (key == null) { throw new IllegalArgumentException("key parameter cannot be null"); } if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL); } return mdcAdapter.get(key); } public static void remove(String key) throws IllegalArgumentException { if (key == null) { throw new IllegalArgumentException("key parameter cannot be null"); } if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL); } mdcAdapter.remove(key); } public static void clear() { if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL); } mdcAdapter.clear(); } public static Map<String, String> getCopyOfContextMap() { if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL); } return mdcAdapter.getCopyOfContextMap(); } public static void setContextMap(Map<String, String> contextMap) { if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL); } mdcAdapter.setContextMap(contextMap); } public static MDCAdapter getMDCAdapter() { return mdcAdapter; } } |
簡(jiǎn)單的demo
|
1
2
3
4
5
6
7
8
9
10
11
|
package com.alibaba.otter.canal.common; import org.slf4j.Logger;import org.slf4j.LoggerFactory;import org.slf4j.MDC; public class LogTest { private static final Logger logger = LoggerFactory.getLogger(LogTest.class); public static void main(String[] args) { MDC.put("THREAD_ID", String.valueOf(Thread.currentThread().getId())); logger.info("純字符串信息的info級(jí)別日志"); }} |
logback.xml 配置
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
|
<configuration scan="true" scanPeriod=" 5 seconds"> <jmxConfigurator /> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{56} %X{THREAD_ID} - %msg%n </pattern> </encoder> </appender> <root level="INFO"> <appender-ref ref="STDOUT"/> </root></configuration |
對(duì)應(yīng)的輸出日志 可以看到輸出了THREAD_ID
2016-12-08 14:59:32.855 [main] INFO com.alibaba.otter.canal.common.LogTest THREAD_ID 1 - 純字符串信息的info級(jí)別日志
slf4j只是起到適配的作用 故查看實(shí)現(xiàn)類LogbackMDCAdapter屬性
final InheritableThreadLocal<Map<String, String>> copyOnInheritThreadLocal = new InheritableThreadLocal<Map<String, String>>();
InheritableThreadLocal 該類擴(kuò)展了 ThreadLocal，為子線程提供從父線程那里繼承的值：在創(chuàng)建子線程時(shí)，子線程會(huì)接收所有
可繼承的線程局部變量的初始值，以獲得父線程所具有的值。通常，子線程的值與父線程的值是一致的；但是，通過重寫這個(gè)類中的 childValue 方法，子線程的值可以作為父線程值的一個(gè)任意函數(shù)。
當(dāng)必須將變量（如用戶 ID 和 事務(wù) ID）中維護(hù)的每線程屬性（per-thread-attribute）自動(dòng)傳送給創(chuàng)建的所有子線程時(shí)，應(yīng)盡可能地采用可繼承的線程局部變量，而不是采用普通的線程局部變量
驗(yàn)證一下
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
|
package com.alibaba.otter.canal.parse.driver.mysql; import org.junit.Test; public class TestInheritableThreadLocal { @Test public void testThreadLocal() { final ThreadLocal<String> local = new ThreadLocal<String>(); work(local); } @Test public void testInheritableThreadLocal() { final ThreadLocal<String> local = new InheritableThreadLocal<String>(); work(local); } private void work(final ThreadLocal<String> local) { local.set("a"); System.out.println(Thread.currentThread() + "," + local.get()); Thread t = new Thread(new Runnable() { @Override public void run() { System.out.println(Thread.currentThread() + "," + local.get()); local.set("b"); System.out.println(Thread.currentThread() + "," + local.get()); } }); t.start(); try { t.join(); } catch (InterruptedException e) { e.printStackTrace(); } System.out.println(Thread.currentThread() + "," + local.get()); } } |
分別運(yùn)行得到的輸出結(jié)果
ThreadLocal 存貯輸出結(jié)果
Thread[main,5,main],a
Thread[Thread-0,5,main],null
Thread[Thread-0,5,main],b
Thread[main,5,main],a
InheritableThreadLocal存貯輸出結(jié)果
Thread[main,5,main],a
Thread[Thread-0,5,main],a
Thread[Thread-0,5,main],b
Thread[main,5,main],a
輸出結(jié)果說明一切 對(duì)于參數(shù)傳遞十分有用 我知道 canal的源碼中用到了MDC
在 CanalServerWithEmbedded 中的 start 和stop等方法中都有用到
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
|
public void start(final String destination) { final CanalInstance canalInstance = canalInstances.get(destination); if (!canalInstance.isStart()) { try { MDC.put("destination", destination); canalInstance.start(); logger.info("start CanalInstances[{}] successfully", destination); } finally { MDC.remove("destination"); } }}public void stop(String destination) { CanalInstance canalInstance = canalInstances.remove(destination); if (canalInstance != null) { if (canalInstance.isStart()) { try { MDC.put("destination", destination); canalInstance.stop(); logger.info("stop CanalInstances[{}] successfully", destination); } finally { MDC.remove("destination"); } } }} |
MDC的介紹及使用
1、MDC是什么？
MDC是（Mapped Diagnostic Context，映射調(diào)試上下文）是 log4j 和 logback 支持的一種方便在多線程條件下記錄追蹤日志的功能。通常打印出的日志會(huì)有線程號(hào)等信息來標(biāo)志當(dāng)前日志屬于哪個(gè)線程，然而由于線程是可以重復(fù)使用的，所以并不能很清晰的確認(rèn)一個(gè)請(qǐng)求的日志范圍。處理這種情況一般有兩種處理方式：
1）手動(dòng)生成一個(gè)唯一序列號(hào)打印在日志中；
2）使用日志控件提供的MDC功能，生成一個(gè)唯一序列標(biāo)記一個(gè)線程的日志；
兩種方法的區(qū)別在于：
方法一只能標(biāo)記一條日志，線程內(nèi)其他日志需要人肉去篩選；
方法二標(biāo)記整個(gè)線程的所有日志，方便grep命令查詢；
對(duì)比可見，使用MDC功能更好。
2、MDC的原理
MDC 可以看成是一個(gè)與當(dāng)前線程綁定的哈希表，可以往其中添加鍵值對(duì)。MDC 中包含的內(nèi)容可以被同一線程中執(zhí)行的代碼所訪問。當(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)用來說，通常是在請(qǐng)求被處理的最開始保存這些數(shù)據(jù)。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
|
@RunWith(SpringRunner.class)@SpringBootTest(classes=CreditAppApplication.class)publicclassMDCTest{ @TestpublicvoidmdcTest1(){MDC.put("first","thefirst1"); Loggerlogger=LoggerFactory.getLogger(MDCTest.class);MDC.put("last","thelast1"); logger.info("checkenclosed.");logger.debug("themostbeautifultwowordsinenglish."); MDC.put("first","thefirst2");MDC.put("last","thelast2"); logger.info("iamnotacrook.");logger.info("AttributedtotheformerUSpresident.17Nov1973.");}} |
logback的配置：
3、MDC的使用
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
|
@Component@Order(Ordered.HIGHEST_PRECEDENCE)publicclassGlobalLogTagConfigextendsOncePerRequestFilter{privatestaticfinalStringGLOBAL_LOG_TAG="GLOG_TAG"; privatestaticStringgenerateSeqNo(){returnUUID.randomUUID().toString().replace("-","").substring(0,12);} @OverrideprotectedvoiddoFilterInternal(HttpServletRequesthttpServletRequest,HttpServletResponsehttpServletResponse,FilterChainfilterChain)throwsServletException,IOException{try{StringseqNo;if(httpServletRequest!=null){seqNo=httpServletRequest.getHeader(GLOBAL_LOG_TAG); if(StringUtils.isEmpty(seqNo)){seqNo=generateSeqNo();}}else{seqNo=generateSeqNo();}MDC.put(GLOBAL_LOG_TAG,seqNo);filterChain.doFilter(httpServletRequest,httpServletResponse);}finally{MDC.remove(GLOBAL_LOG_TAG);}}} |
注意：
OncePerRequestFilter的作用是為了讓每個(gè)請(qǐng)求只經(jīng)過這個(gè)過濾器一次（因?yàn)閣eb container的不同，有些過濾器可能被多次執(zhí)行）
logback配置：
以上為個(gè)人經(jīng)驗(yàn)，希望能給大家一個(gè)參考，也希望大家多多支持服務(wù)器之家。
原文鏈接：https://www.jianshu.com/p/06b1d35526c2
