MDC 简介

MDC ( Mapped Diagnostic Contexts )，它是一个线程安全的存放诊断日志的容器。

Logback设计的一个目标之一是对分布式应用系统的审计和调试。在现在的分布式系统中，需要同时处理很多的请求。如何来很好的区分日志到底是那个请求输出的呢？我们可以为每一个请求生一个logger，但是这样子最产生大量的资源浪费，并且随着请求的增多这种方式会将服务器资源消耗殆尽，所以这种方式并不推荐。

一种更加轻量级的实现是使用MDC机制，在处理请求前将请求的唯一标示放到MDC容器中如sessionId，这个唯一标示会随着日志一起输出，以此来区分该条日志是属于那个请求的。并在请求处理完成之后清除MDC容器。

下面是MDC对外提供的方法，也可以通过MDC javadocs查看所有方法。

package org.slf4j;public class MDC {// 将一个K-V的键值对放到容器，其实是放到当前线程的ThreadLocalMap中public static void put(String key, String val);// 根据key在当前线程的MDC容器中获取对应的值public static String get(String key);// 根据key移除容器中的值public static void remove(String key);// 清空当前线程的MDC容器public static void clear();
}

简单的例子

Example 7.1: Basic MDC usage ( logback-examples/src/main/java/chapters/mdc/SimpleMDC.java)

package com.xiaolyuh;import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;public class SimpleMDC {public static void main(String[] args) throws Exception {// You can put values in the MDC at any time. Before anything else// we put the first nameMDC.put("first", "Dorothy");Logger logger = LoggerFactory.getLogger(SimpleMDC.class);// We now put the last nameMDC.put("last", "Parker");// The most beautiful two words in the English language according// to Dorothy Parker:logger.info("Check enclosed.");logger.debug("The most beautiful two words in English.");MDC.put("first", "Richard");MDC.put("last", "Nixon");logger.info("I am not a crook.");logger.info("Attributed to the former US president. 17 Nov 1973.");}}

Logback配置：

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> <layout><Pattern>%X{first} %X{last} - %m%n</Pattern></layout>
</appender>

输出日志：

Dorothy Parker - Check enclosed.
Dorothy Parker - The most beautiful two words in English.
Richard Nixon - I am not a crook.
Richard Nixon - Attributed to the former US president. 17 Nov 1973.

在日志模板logback.xml 中，使用 %X{ }来占位，替换到对应的 MDC 中 key 的值。同样，logback.xml配置文件支持了多种格式的日志输出，比如%highlight、%d等等，这些标志，在PatternLayout.java中维护。

MDC的容器中的key可以多次赋值，最后一次的赋值会覆盖上一次的值。

PatternLayout :

public class PatternLayout extends PatternLayoutBase<ILoggingEvent> {public static final Map<String, String> defaultConverterMap = new HashMap<String, String>();public static final String HEADER_PREFIX = "#logback.classic pattern: ";static {defaultConverterMap.putAll(Parser.DEFAULT_COMPOSITE_CONVERTER_MAP);// 按照{}配置输出时间defaultConverterMap.put("d", DateConverter.class.getName());defaultConverterMap.put("date", DateConverter.class.getName());// 输出应用启动到日志时间触发时候的毫秒数defaultConverterMap.put("r", RelativeTimeConverter.class.getName());defaultConverterMap.put("relative", RelativeTimeConverter.class.getName());// 输出日志级别的信息defaultConverterMap.put("level", LevelConverter.class.getName());defaultConverterMap.put("le", LevelConverter.class.getName());defaultConverterMap.put("p", LevelConverter.class.getName());// 输出产生日志事件的线程名defaultConverterMap.put("t", ThreadConverter.class.getName());defaultConverterMap.put("thread", ThreadConverter.class.getName());// 输出产生log事件的原点的日志名=我们创建logger的时候设置的defaultConverterMap.put("lo", LoggerConverter.class.getName());defaultConverterMap.put("logger", LoggerConverter.class.getName());defaultConverterMap.put("c", LoggerConverter.class.getName());// 输出 提供日志事件的对应的应用信息defaultConverterMap.put("m", MessageConverter.class.getName());defaultConverterMap.put("msg", MessageConverter.class.getName());defaultConverterMap.put("message", MessageConverter.class.getName());// 输出调用方发布日志事件的完整类名defaultConverterMap.put("C", ClassOfCallerConverter.class.getName());defaultConverterMap.put("class", ClassOfCallerConverter.class.getName());// 输出发布日志请求的方法名defaultConverterMap.put("M", MethodOfCallerConverter.class.getName());defaultConverterMap.put("method", MethodOfCallerConverter.class.getName());// 输出log请求的行数defaultConverterMap.put("L", LineOfCallerConverter.class.getName());defaultConverterMap.put("line", LineOfCallerConverter.class.getName());// 输出发布日志请求的java源码的文件名defaultConverterMap.put("F", FileOfCallerConverter.class.getName());defaultConverterMap.put("file", FileOfCallerConverter.class.getName());// 输出和发布日志事件关联的线程的MDCdefaultConverterMap.put("X", MDCConverter.class.getName());defaultConverterMap.put("mdc", MDCConverter.class.getName());// 输出和日志事件关联的异常的堆栈信息defaultConverterMap.put("ex", ThrowableProxyConverter.class.getName());defaultConverterMap.put("exception", ThrowableProxyConverter.class.getName());defaultConverterMap.put("rEx", RootCauseFirstThrowableProxyConverter.class.getName());defaultConverterMap.put("rootException", RootCauseFirstThrowableProxyConverter.class.getName());defaultConverterMap.put("throwable", ThrowableProxyConverter.class.getName());// 和上面一样，此外增加类的包信息defaultConverterMap.put("xEx", ExtendedThrowableProxyConverter.class.getName());defaultConverterMap.put("xException", ExtendedThrowableProxyConverter.class.getName());defaultConverterMap.put("xThrowable", ExtendedThrowableProxyConverter.class.getName());// 当我们想不输出异常信息时，使用这个。其假装处理异常，其实无任何输出defaultConverterMap.put("nopex", NopThrowableInformationConverter.class.getName());defaultConverterMap.put("nopexception",NopThrowableInformationConverter.class.getName());// 输出在类附加到日志上的上下文名字. defaultConverterMap.put("cn", ContextNameConverter.class.getName());defaultConverterMap.put("contextName", ContextNameConverter.class.getName());// 输出产生日志事件的调用者的位置信息defaultConverterMap.put("caller", CallerDataConverter.class.getName());// 输出和日志请求关联的markerdefaultConverterMap.put("marker", MarkerConverter.class.getName());// 输出属性对应的值，一般为System.properties中的属性defaultConverterMap.put("property", PropertyConverter.class.getName());// 输出依赖系统的行分隔符defaultConverterMap.put("n", LineSeparatorConverter.class.getName());// 相关的颜色格式设置defaultConverterMap.put("black", BlackCompositeConverter.class.getName());defaultConverterMap.put("red", RedCompositeConverter.class.getName());defaultConverterMap.put("green", GreenCompositeConverter.class.getName());defaultConverterMap.put("yellow", YellowCompositeConverter.class.getName());defaultConverterMap.put("blue", BlueCompositeConverter.class.getName());defaultConverterMap.put("magenta", MagentaCompositeConverter.class.getName());defaultConverterMap.put("cyan", CyanCompositeConverter.class.getName());defaultConverterMap.put("white", WhiteCompositeConverter.class.getName());defaultConverterMap.put("gray", GrayCompositeConverter.class.getName());defaultConverterMap.put("boldRed", BoldRedCompositeConverter.class.getName());defaultConverterMap.put("boldGreen", BoldGreenCompositeConverter.class.getName());defaultConverterMap.put("boldYellow", BoldYellowCompositeConverter.class.getName());defaultConverterMap.put("boldBlue", BoldBlueCompositeConverter.class.getName());defaultConverterMap.put("boldMagenta", BoldMagentaCompositeConverter.class.getName());defaultConverterMap.put("boldCyan", BoldCyanCompositeConverter.class.getName());defaultConverterMap.put("boldWhite", BoldWhiteCompositeConverter.class.getName());defaultConverterMap.put("highlight", HighlightingCompositeConverter.class.getName());}
}

Notes：日志模板配置，使用 %为前缀让解析器识别特殊输出模式，然后以{}后缀结尾，内部指定相应的参数设置。

使用切面

在处理请求前将请求的唯一标示放到MDC容器中如sessionId，这个唯一标示会随着日志一起输出，以此来区分该条日志是属于那个请求的。这个我们可以使用Advanced来实现，可以使用filter，interceptor等。

Interceptor

可以参考篇文章Logback 快速定位用户在一次请求中的所有日志。

MDCInsertingServletFilter

这是Logback提供的一个filter，他会将一些请求信息放到MDC容器中，这个filter最好放到配置编码的filter之后。以下是详细的key：

MDC key	MDC value
req.remoteHost	as returned by the getRemoteHost() method
req.xForwardedFor	value of the “X-Forwarded-For” header
req.method	as returned by getMethod() method
req.requestURI	as returned by getRequestURI() method
req.requestURL	as returned by getRequestURL() method
req.queryString	as returned by getQueryString() method
req.userAgent	value of the “User-Agent” header

使用配置：需要保证filter在需要使用的到该MDC的其他filter之前。

<filter><filter-name>MDCInsertingServletFilter</filter-name><filter-class>ch.qos.logback.classic.helpers.MDCInsertingServletFilter</filter-class>
</filter>
<filter-mapping><filter-name>MDCInsertingServletFilter</filter-name><url-pattern>/*</url-pattern>
</filter-mapping>

应用key：

%X{req.remoteHost} %X{req.requestURI}%n%d - %m%n

管理每个线程的MDC容器

我们在主线程上，新起一个子线程，并由 java.util.concurrent.Executors来执行它时，在早期的版本中子线程可以直接自动继承父线程的MDC容器中的内容，因为MDC在早期版本中使用的是InheritableThreadLocal来作为底层实现。但是由于性能问题被取消了，最后还是使用的是ThreadLocal来作为底层实现。这样子线程就不能直接继承父线程的MDC容器。

所以，Logback官方建议我们在父线程新建子线程之前调用MDC.getCopyOfContextMap()方法将MDC内容取出来传给子线程，子线程在执行操作前先调用MDC.setContextMap()方法将父线程的MDC内容设置到子线程。

Slf4j MDC实现原理

Slf4j 的实现原则就是调用底层具体实现类，比如logback,logging等包；而不会去实现具体的输出打印等操作。这里使用了装饰者模式，看源码就能看出来，所有的方法都是在对mdcAdapter 这个属性进行操作。所以实现核心是MDCAdapter类。

MDCAdapter

MDCAdapter只是定义了一个接口，具体实现由子类完成，源码如下：

public interface MDCAdapter {public void put(String key, String val);public String get(String key);public void remove(String key);public void clear();public Map<String, String> getCopyOfContextMap();public void setContextMap(Map<String, String> contextMap);
}

它有三个实现类，BasicMDCAdapter、LogbackMDCAdapter，NOPMDCAdapter。Logback使用的是LogbackMDCAdapter。

LogbackMDCAdapter

package ch.qos.logback.classic.util;import java.util.Collections;
import java.util.HashMap;
import java.util.Map;
import java.util.Set;import org.slf4j.spi.MDCAdapter;public class LogbackMDCAdapter implements MDCAdapter {final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal<Map<String, String>>();private static final int WRITE_OPERATION = 1;private static final int MAP_COPY_OPERATION = 2;// keeps track of the last operation performedfinal ThreadLocal<Integer> lastOperation = new ThreadLocal<Integer>();private Integer getAndSetLastOperation(int op) {Integer lastOp = lastOperation.get();lastOperation.set(op);return lastOp;}private boolean wasLastOpReadOrNull(Integer lastOp) {return lastOp == null || lastOp.intValue() == MAP_COPY_OPERATION;}private Map<String, String> duplicateAndInsertNewMap(Map<String, String> oldMap) {Map<String, String> newMap = Collections.synchronizedMap(new HashMap<String, String>());if (oldMap != null) {// we don't want the parent thread modifying oldMap while we are// iterating over itsynchronized (oldMap) {newMap.putAll(oldMap);}}copyOnThreadLocal.set(newMap);return newMap;}/*** Put a context value (the <code>val</code> parameter) as identified with the* <code>key</code> parameter into the current thread's context map. Note that* contrary to log4j, the <code>val</code> parameter can be null.* <p/>* <p/>* If the current thread does not have a context map it is created as a side* effect of this call.** @throws IllegalArgumentException in case the "key" parameter is null*/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();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);}}/*** Remove the the context identified by the <code>key</code> parameter.* <p/>*/public void remove(String key) {if (key == null) {return;}Map<String, String> oldMap = copyOnThreadLocal.get();if (oldMap == null)return;Integer lastOp = getAndSetLastOperation(WRITE_OPERATION);if (wasLastOpReadOrNull(lastOp)) {Map<String, String> newMap = duplicateAndInsertNewMap(oldMap);newMap.remove(key);} else {oldMap.remove(key);}}/*** Clear all entries in the MDC.*/public void clear() {lastOperation.set(WRITE_OPERATION);copyOnThreadLocal.remove();}/*** Get the context identified by the <code>key</code> parameter.* <p/>*/public String get(String key) {final Map<String, String> map = copyOnThreadLocal.get();if ((map != null) && (key != null)) {return map.get(key);} else {return null;}}/*** Get the current thread's MDC as a map. This method is intended to be used* internally.*/public Map<String, String> getPropertyMap() {lastOperation.set(MAP_COPY_OPERATION);return copyOnThreadLocal.get();}/*** Returns the keys in the MDC as a {@link Set}. The returned value can be* null.*/public Set<String> getKeys() {Map<String, String> map = getPropertyMap();if (map != null) {return map.keySet();} else {return null;}}/*** Return a copy of the current thread's context map. Returned value may be* null.*/public Map<String, String> getCopyOfContextMap() {Map<String, String> hashMap = copyOnThreadLocal.get();if (hashMap == null) {return null;} else {return new HashMap<String, String>(hashMap);}}public void setContextMap(Map<String, String> contextMap) {lastOperation.set(WRITE_OPERATION);Map<String, String> newMap = Collections.synchronizedMap(new HashMap<String, String>());newMap.putAll(contextMap);// the newMap replaces the old one for serialisation's sakecopyOnThreadLocal.set(newMap);}
}

final ThreadLocal<Integer> lastOperation = new ThreadLocal<Integer>();

通过这段代码，我们可以看到底层最终是使用的是ThreadLocal来做实现。

参考

https://logback.qos.ch/manual/mdc.html
https://segmentfault.com/a/1190000008315137#articleHeader12
https://ketao1989.github.io/2015/04/29/LogBack-Implemention-And-Slf4j-Mdc/#%E8%BE%93%E5%87%BA%E6%97%A5%E5%BF%97%E6%A8%A1%E6%9D%BF%E8%A7%A3%E6%9E%90

Slf4j MDC机制相关推荐

基于SLF4J MDC机制实现日志的链路追踪
一.打印HTTP request body和response body实现日志跟踪 request 的inputStream和response 的outputStream默认情况下是只能读一次, 不可 ...
Slf4j之MDC机制
什么是MDC机制 MDC(Mapped Diagnostic Contexts)映射诊断上下文,主要用在做日志链路跟踪时,动态配置用户自定义的一些信息,比如requestId.sessionId等等. ...
MDC机制实现日志的链路追踪
一.问题描述排查问题用得最多的方式是查看日志,但是在现有系统中,各种无关日志穿行其中,导致没办法快速的找出用户在一次请求中所有的日志. 二.问题分析我们没办法快速定位用户在一次请求中对应的所有日志 ...
切面是异步还是同步操作‘_分布式中采用Logback的MDC机制与AOP切面结合串联日志...
导读:在实际开发中,打印日志是十分重要的.在生产环境中,如果日志打得好可以快速地排查问题,而在分布式的场景下,一个请求会跨越多个节点,既一个业务可能需要多个节点协调配合处理.那么日志将会分散,而为了更 ...
logback利用mdc机制为日志增加traceId
1 . 增加LogMdcFilter package cn.xbz.common.filter;import org.slf4j.MDC;import javax.servlet.*; import ...
简单记录使用org.slf4j.MDC进行日志追踪
日志追踪依赖配置文件代码 controller service 控制台打印源码追踪依赖这里使用的是log4j2 <parent><groupId>org.sprin ...
slf4j MDC是个好东西
slf4j MDC是个好东西简介 MDC 全拼 Mapped Diagnostic Contexts,是SLF4J类日志系统中实现分布式多线程日志数据传递的重要工具. 同时,用户也可利用MDC将一些 ...
slf4j MDC使用
slf4j MDC使用最近也是在项目代码里发现一个地方有个MDC.put(),忍不住好奇点了进去,于是知道了MDC这个东西,细研究一下,发现还真是个好东西. MDC解决了什么问题 MDC全名Mapp ...
slf4j的MDC机制
MDC(Mapped Diagnostic Context)诊断上下文映射,是slf4j提供的一个支持动态打印日志信息的工具,举例来说,对于一个web Server,如果服务端想在打印出的每行日志中都 ...

Slf4j MDC机制