大家好久不見，我是walking。今天給大家帶來一個日志方面的知識——MDC，不知道大家認識不，反正我是最近剛知道的😂
初見MDC
前兩天看項目中的代碼，無意中看到一個自定義的線程池
MDCThreadExecutor extends ThreadPoolTaskExecutor
主要針對spring-context 中的 ThreadPoolTaskExecutor 線程池進行了擴展，但也沒做多少擴展，僅僅是引入了兩個屬性，如下：
private Map<String, String> threadContext; private Boolean useThreadContext; public Map<String, String> getThreadContext() { return useThreadContext ? (threadContext == null ? MDC.getCopyOfContextMap() : threadContext) : null; }
然后對 execute(Runnable task) 和 submit(Runnable task) 這兩個方法進行了重寫，如下：
@Override public void execute(Runnable task) { super.execute(getMDCTask(task, getThreadContext())); } @Override public Future<?> submit(Runnable task) { return super.submit(getMDCTask(task,getThreadContext())); }
我看到使用了 MDC.java 這個東西，第一反應就是，卧槽，MDC是什么？用這個干嘛？沒見過啊，所以我就想研究研究，瞻仰一下人家的代碼，於是就有了這篇文章。
自行探索
我很好奇這是什么東西，點進去看是 slf4j 包里的一個類，而自定義擴展線程池的這個類里僅僅使用了這個 MDC 做了一些簡單的操作，如下代碼：
private Runnable getMDCTask(Runnable task, Map<String, String> threadContext) { return () -> { if (useThreadContext) { MDC.setContextMap(threadContext); MDC.put("tranceID", UUID.randomUUID().toString().replaceAll("-","")); }else{ MDC.setContextMap(null); } try { task.run(); } finally { MDC.remove("tranceID"); MDC.clear(); } }; }
僅僅是對提交的任務做了一層包裝，往MDC里put了tranceId，value為一個UUID字符串，這樣寫的作用是什么呢？因為寫這個的人已經離職，也沒法問了，那就自己研究研究唄。
點進去put方法看看，代碼如下：
/** * 將由key參數標識的診斷上下文值（val參數）放入當前線程的診斷上下文映射中。 * 鍵參數不能為空。僅當基礎實現支持val參數時，它才能為null。 * 此方法將所有工作委托給底層日志系統的MDC。 * * @param key non-null key * @param val value to put in the map * * @throws IllegalArgumentException 參數key為空時拋出異常 */ 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); }
根據注釋我們可以大概知道這個意思，把一個key-value鍵值對put到map里，底層大概是對map進行操作的，我們可以看到上面代碼第18行 mdcAdapter.put(key, val); 最終執行的是 org.slf4j.spi.MDCAdapter.java 這個接口類定義的put的方法。這個接口又是什么呢？注釋是這樣解釋的：
這個接口抽象了各種MDC實現提供的服務。
接口中對put方法的注釋如下：
將由key參數標識的上下文值（val參數）放入當前線程的上下文映射中。鍵參數不能為空。僅當基礎實現支持val參數時，它才能為null。
如果當前線程沒有上下文映射，則創建它作為此調用的副作用。
而類名以Adadiaoer結尾表明它是一個適配器，我們都知道 slf4j 是一套日志接口門面（就像JDBC一樣），它的實現有logback，log4j等。所以我們需要進到他的實現中去一探究竟，因為我們用的是logback那當然看logback相關的了
LogbackMDCAdapter類上的注釋如下：
映射診斷上下文（Mapped Diagnostic Context，簡稱MDC）是一種工具，用於區分不同來源的交錯日志輸出。當服務器幾乎同時處理多個客戶機時，日志輸出通常是交錯的。
MDC是基於每個線程進行管理的。子線程自動繼承其父線程的映射診斷上下文的副本。
看到這我們就大概知道了MDC的基本作用了，我們之前用日志框架都知道，有5種日志級別，trace、debug、info、warn、error，而MDC是對日志的擴展應用，它應該能夠允許我們自定義想要展示在日志的信息，看上面的注釋，我們應該能夠了解到，MDC在多線程環境下有很大的用處，可以管理每個線程的日志。
好了，這些都是我們通過大致的瀏覽它的源碼上的注釋得知的，是不是這樣還有待驗證。我們繼續看一下put操作的實現，如下：
/** * 將由key參數標識的上下文值（val參數）放入當前線程的上下文映射中。 * 注意，與log4j相反，val參數可以為null。 * 如果當前線程沒有上下文映射，則創建它作為此調用的副作用。 * @throws IllegalArgumentException 參數key為空時拋出異常 */ public void put(String key, String val) throws IllegalArgumentException { if (key == null) { throw new IllegalArgumentException("key cannot be null"); } Map<String, String> oldMap = copyOnThreadLocal.get();//ThreadLocal調get方法 Integer lastOp = getAndSetLastOperation(WRITE_OPERATION); if (wasLastOpReadOrNull(lastOp) || oldMap == null) { Map<String, String> newMap = duplicateAndInsertNewMap(oldMap); newMap.put(key, val); } else { oldMap.put(key, val); } }
上面的代碼也很簡單，從ThreadLocal中獲取保存的map把我們的key-value放進去就完事了。我們知道了原來它是用ThreadLocal來保存我們自定義的線程上下文信息的。
MDC功能測驗
以上，我們大致知道了MDC做了什么了。這僅僅是我們自己看了別人在項目代碼里用MDC以及MDC的一點源碼得到的一些信息。我們還要到網上查一下資料，一是看我們以上的認知是不是對的，二是獲取關於MDC的更多信息，包括怎么使用。
首先我們用上面的代碼，就是自定義的擴展線程池來測試一下，我們put了一個tranceId，value是UUID，看有什么效果。
我寫了一個測試接口，如下，簡單的模擬一個任務提交到線程池，然后在這個任務內部穿插着調了很多方法，假設很多業務邏輯，並且各個邏輯分支、方法都有自己的日志輸出，就是這樣的一個測試接口。待會我們測試一下看用了MDC后日志會有什么效果。
@GetMapping("testMDCThreadPool")
public Map<String, Object> testMDCThreadPool() {
Map<String, Object> successResult = ResultUtil.getSuccessResult();
log.info("begin....");//在web容器創建的線程里打印日志
//提交任務
taskExecutor.execute(() -> {
log.info("task main......");//在自定義線程池創建的線程里打印日志
try {
TimeUnit.MILLISECONDS.sleep(1);
doSome1();
//other...
} catch (InterruptedException e) {
log.error("task error:{}", e);
}
});
log.info("end....");
return successResult;
}
public void doSome1() throws InterruptedException {
log.info("this is print......");
TimeUnit.MILLISECONDS.sleep(5);
doSome2();
//other...
}
public void doSome2() throws InterruptedException {
log.info("this is print......");
TimeUnit.MILLISECONDS.sleep(1);
//other...
}
然后就是把項目運行起來（一個簡單的springboot項目，配了一個我們擴展后的線程池MDCThreadExecutor，構造函數傳了一個map，map里放了一個key-value，即mdc-threadPool，然后下面是線程池的一些參數，然后還有我們的線程名是walking-mdc開頭的）
@Bean public MDCThreadExecutor taskExecutor(){ MDCThreadExecutor mdcThreadExecutor = new MDCThreadExecutor(new HashMap<String, String>() {{ put("appId", "mdc-threadPool"); }}); mdcThreadExecutor.setCorePoolSize(10); mdcThreadExecutor.setMaxPoolSize(20); mdcThreadExecutor.setKeepAliveSeconds(5); mdcThreadExecutor.setQueueCapacity(50); mdcThreadExecutor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy()); mdcThreadExecutor.setThreadFactory(new DefaultThreadFactory("walking-mdc")); return mdcThreadExecutor; }
然后我們訪問http://localhost:8899/testMDCThreadPool，觀察控制台輸出
109-05 21:48:20.478 [http-nio-8899-exec-2] INFO [c.w.r.controller.MDCTestController] useMDCThreadPool:25 [] []- begin.... 209-05 21:48:20.487 [http-nio-8899-exec-2] INFO [c.w.r.controller.MDCTestController] useMDCThreadPool:37 [] []- end.... 309-05 21:48:20.620 [walking-mdc-1-1] INFO [c.w.r.controller.MDCTestController] lambda$useMDCThreadPool$0:28 [mdc-threadPool] [cc8d01b41cfd4b3b83d8e0120f855187]- task main...... 409-05 21:48:20.622 [walking-mdc-1-1] INFO [c.w.r.controller.MDCTestController] doSome1:42 [mdc-threadPool] [cc8d01b41cfd4b3b83d8e0120f855187]- this is print...... 509-05 21:48:20.628 [walking-mdc-1-1] INFO [c.w.r.controller.MDCTestController] doSome2:49 [mdc-threadPool] [cc8d01b41cfd4b3b83d8e0120f855187]- this is print......
可以看到日志的前兩行是web容器線程池創建的線程所打印的日志，因為和我們自己的線程池創建的線程所打印出的線程名不一樣（http-nio-8899-exec-xx和walking-mdc-1-xx）。往后看可以看到還有區別，前兩行日志中有兩個空的中括號[]，[]，而后3行日志中括號里是這樣的[mdc-threadPool]、[6c60c8df5ff842adbd8aecef4aca3003]，這不就是我們的往map里放的appId和通過MDC.put放的UUID嗎？
噢~在這給區別顯示了，實現了打印我們自定義的日志參數。
難道放到線程上下文里就能打印了嗎？不會這么智能的吧。所以我全局搜一下appId和tranceId，果然不出所料，在logback-spring.xml里找到了這倆參數的身影。下面代碼第3行%X{appId}和%X{tranceId}，所以放進去的參數，在日志打印模板里配置上就能在日志里體現出來。
<appender name="console" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{MM-dd HH:mm:ss.SSS} [%thread] %-5level [%logger{38}] %method:%line [%X{appId}] [%X{tranceID}]- %msg%n </pattern> </encoder> </appender>
還記得剛才提到的LogbackMDCAdapter類上的注釋嗎？如下：
映射診斷上下文（Mapped Diagnostic Context，簡稱MDC）是一種工具，用於區分不同來源的交錯日志輸出。當服務器幾乎同時處理多個客戶機時，日志輸出通常是交錯的。
MDC是基於每個線程進行管理的。子線程自動繼承其父線程的映射診斷上下文的副本。
有一句說的很對，當程序在服務器上運行時，情況往往很復雜，多線程運行日志是錯綜復雜的，多線程的日志是交替的，所以這種情況下我們很難分辨出哪些日志是一個線程或者一個任務打印的。
看到這，恍然大悟了吧，MDC的作用就在這。如果還不明白，那么我們模擬多線程請求剛才們的測試接口看下效果吧。
我模擬了1秒內發10個線程請求，看下日志是什么樣的，幫助理解。
如上圖，日志交替執行的效果出來了，實際生產環境中並發量比這大，同一個線程的日志有時候會隔很遠，無法分辨哪些是同一個線程同一個任務打印的，也就不方便排查問題。而有了MDC，再配合linux的grep用關鍵字抽取日志，那就方便多了。MDC還挺棒的呢！
以上是通過項目里使用MDC，然后通過自己的小測驗和簡單的一點源碼來對MDC有了一個初步的了解。然后又搜集了一些信息對MDC有個更加全面的認識。
slf4j中MDC是什么鬼
MDC從使用方式上與我們常用的記錄日志的方式有些不同，我對它的理解是MDC可以將一個處理線程中你想體現在日志文件中的數據統一管理起來，根據你的日志文件配置決定是否輸出。
比如以下但不限於以下場景可以考慮使用MDC來達到目的
-
我們想在日志中體現請求用戶IP地址
-
用戶使用
http客戶端的user-agent -
記錄一次處理線程的日志跟蹤編號(這個編號目的是為了查詢日志方便，結合
grep命令能根據跟蹤編號將本次的處理日志全部輸出)
使用方式
使用方式可以用AOP或Filter或Interceptor或者在自定義的線程池中給每個線程一個唯一的編號（就行我上面那樣使用）這類工具配合使用，獲得你希望輸出到日志的變量並調用MDC.put(String key, String val)。再比如下面AOP中使用
@Around(value = "execution(* com.xx.xx.waling.impl.*.*(..))", argNames="bcdd") public Object validator(ProceedingJoinPoint pjp) throws Throwable { try { String traceId = TraceUtils.begin(); MDC.put("traceId", traceId); Object obj = pjp.proceed(args); return obj; } catch(Throwable e) { //TODO 處理錯誤 } finally { TraceUtils.endTrace(); } }
MDC帶來的好處
-
如果你的系統已經上線，突然有一天老板說我們增加一些用戶數據到日志里分析一下。如果沒有
MDC我猜此時此刻你應該處於雪崩狀態。MDC恰到好處的讓你能夠實現在日志上突如其來的一些需求 -
如果你是個代碼潔癖，封裝了公司LOG的操作，並且將處理線程跟蹤日志號也封裝了進去，但只有使用了你封裝日志工具的部分才能打印跟蹤日志號，其他部分(比如hibernate、mybatis、httpclient等等)日志都不會體現跟蹤號。當然我們可以通過linux命令來繞過這些困擾。
-
使代碼簡潔、日志風格統一
小結
到這里MDC就告一段落了，我們了解了MDC的基本使用和好處，小伙伴們你們學會了嗎？知道有這個東西，即便是現在用不到，以后如果有需求要實現類似的功能的話，你能第一時間想到可以用MDC就夠了，也能裝一把逼😄
本文涉及的代碼已托管到碼雲，https://gitee.com/it-wenbei/slf4j-MDC，需要的可以下載啦。
記得點贊、轉發，多謝支持啦
之前整理的 redis 和 MQ 的知識點思維導圖分享給大家，2K+的小伙伴都領取了你還不快來領~
往期熱文：
歡迎關注我哦，謝謝大家的支持
參考：
http://logback.qos.ch/manual/mdc.html
https://www.cnblogs.com/sealedbook/p/6227452.html