Slf4j之MDC机制

什么是MDC机制

MDC（Mapped Diagnostic Contexts）映射诊断上下文，主要用在做日志链路跟踪时，动态配置用户自定义的一些信息，比如requestId、sessionId等等。MDC使用的容器支持多线程操作，满足线程安全。

MDC的使用

pom.xml依赖

<!-- 日志log4j2 -->
<dependency><groupId>com.lmax</groupId><artifactId>disruptor</artifactId>
</dependency>
<dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

此处日志具体实现采用的是log4j2，依赖slf4j-api 版本1.7.25

log4j2配置日志输出

<!-- 控制台 -->
<Console name="Console" target="SYSTEM_OUT"><PatternLayoutpattern="%d{yyyy-MM-dd HH:mm:ss.SSS} - %X{requestId} %-5p %t [%c:%L]-%m%n"/>
</Console>

在patternLayout中 %X{requestId} 显示我们定义的变量
日志配置详解可以戳这里：【系统日志笔记一】——丰富Log4j2配置

MainLogAspect.java

package com.lucas.device.aop;import javax.servlet.http.HttpServletRequest;import com.phlico.common.framework.tool.unique.IdWorkerUtil;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.*;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;import lombok.extern.slf4j.Slf4j;/*** <Description> 系统日志切面<br>** @author xubin<br>* @version 1.0<br>* @taskId <br>* @CreateDate 2019/4/12 <br>*/@Aspect
@Slf4j
@Component
public class MainLogAspect {/*** Description: 自定义切点<br>* * @author xubin <br>* @taskId <br>*/@Pointcut("@annotation(com.lucas.device.aop.Logc)")public void pointCut() {}/*** Description: 前置通知-记录请求信息<br>* * @author xubin <br>* @taskId <br>* @param joinPoint <br>*/@Before("pointCut()")public void doBeforeAdvice(JoinPoint joinPoint) {Signature signature = joinPoint.getSignature();ServletRequestAttributes sra = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();HttpServletRequest request = sra.getRequest();// 获取目标方法的参数信息Object[] obj = joinPoint.getArgs();// MDC容器增加requestIdMDC.put("requestId", IdWorkerUtil.getFlowIdWorkerInstance().nextId());log.info("[MainLogAspect]-request url:{}, class: {}, method: {}, param: {}", request.getRequestURI(), signature.getDeclaringTypeName(), signature.getName(), obj[0].toString());}/*** Description: 后置通知-记录返回信息<br>* * @author xubin <br>* @taskId <br>* @param joinPoint <br>* @param result <br>*/@AfterReturning(returning = "result", pointcut = "pointCut()")public void doAfterReturningAdvice(JoinPoint joinPoint, Object result) {Signature signature = joinPoint.getSignature();ServletRequestAttributes sra = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();HttpServletRequest request = sra.getRequest();log.info("[MainLogAspect]-response url:{}, class: {}, method: {}, param: {}", request.getRequestURI(), signature.getDeclaringTypeName(), signature.getName(), result.toString());// MDC容器移除requestIdMDC.remove("requestId");}/*** Description: 后置异常通知-记录返回出现异常<br>* * @author xubin <br>* @taskId <br>* @param joinPoint <br>* @param exception <br>*/@AfterThrowing(value = "pointCut()", throwing = "exception")public void doAfterThrowingAdvice(JoinPoint joinPoint, Throwable exception) {Signature signature = joinPoint.getSignature();ServletRequestAttributes sra = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();HttpServletRequest request = sra.getRequest();log.info("[MainLogAspect]-response exception url:{}, class: {}, method: {}", request.getRequestURI(), signature.getDeclaringTypeName(), signature.getName());// MDC容器移除requestIdMDC.remove("requestId");}
}

MainLogAspect.java是自定义切面，拦截@Logc的请求，输出请求的入参出参，详细介绍可以戳：【系统日志笔记二】——撸起袖子写个自定义日志注解
在方法中合适的位置添加MDC.put和MDC.remove

运行结果

可以看到，日志中同一线程内的用户操作都会打印出一个requestId，如果线程中没有requestId则会输出一个空字符串。红框内第三行是在当前线程中启用了子线程，此时子线程并未集成父线程中MDC容器，其中原因可以在下面的源码跟踪里找到。

MDC源码与原理

MDC的源码在slf4j-api包的org.slf4j路径下，源码：

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;/*** An adapter to remove the key when done.*/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() {}/*** As of SLF4J version 1.7.14, StaticMDCBinder classes shipping in various bindings* come with a getSingleton() method. Previously only a public field called SINGLETON * was available.* * @return MDCAdapter* @throws NoClassDefFoundError in case no binding is available* @since 1.7.14*/private static MDCAdapter bwCompatibleGetMDCAdapterFromBinder() throws NoClassDefFoundError {try {return StaticMDCBinder.getSingleton().getMDCA();} catch (NoSuchMethodError nsme) {// binding is probably a version of SLF4J older than 1.7.14return StaticMDCBinder.SINGLETON.getMDCA();}}static {try {mdcAdapter = bwCompatibleGetMDCAdapterFromBinder();} catch (NoClassDefFoundError ncde) {mdcAdapter = new NOPMDCAdapter();String msg = ncde.getMessage();if (msg != null && msg.contains("StaticMDCBinder")) {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 hereUtil.report("MDC binding unsuccessful.", e);}}/*** Put a diagnostic context value (the <code>val</code> parameter) as identified with the* <code>key</code> parameter into the current thread's diagnostic context map. The* <code>key</code> parameter cannot be null. The <code>val</code> parameter* can be null only if the underlying implementation supports it.* * <p>* This method delegates all work to the MDC of the underlying logging system.** @param key non-null key * @param val value to put in the map* * @throws IllegalArgumentException*           in case the "key" parameter is null*/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);}/*** Put a diagnostic context value (the <code>val</code> parameter) as identified with the* <code>key</code> parameter into the current thread's diagnostic context map. The* <code>key</code> parameter cannot be null. The <code>val</code> parameter* can be null only if the underlying implementation supports it.** <p>* This method delegates all work to the MDC of the underlying logging system.* <p>* This method return a <code>Closeable</code> object who can remove <code>key</code> when* <code>close</code> is called.** <p>* Useful with Java 7 for example :* <code>*   try(MDC.MDCCloseable closeable = MDC.putCloseable(key, value)) {*     ....*   }* </code>** @param key non-null key* @param val value to put in the map* @return a <code>Closeable</code> who can remove <code>key</code> when <code>close</code>* is called.** @throws IllegalArgumentException*           in case the "key" parameter is null*/public static MDCCloseable putCloseable(String key, String val) throws IllegalArgumentException {put(key, val);return new MDCCloseable(key);}/*** Get the diagnostic context identified by the <code>key</code> parameter. The* <code>key</code> parameter cannot be null.* * <p>* This method delegates all work to the MDC of the underlying logging system.** @param key  * @return the string value identified by the <code>key</code> parameter.* @throws IllegalArgumentException*           in case the "key" parameter is null*/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);}/*** Remove the diagnostic context identified by the <code>key</code> parameter using* the underlying system's MDC implementation. The <code>key</code> parameter* cannot be null. This method does nothing if there is no previous value* associated with <code>key</code>.** @param key  * @throws IllegalArgumentException*           in case the "key" parameter is null*/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);}/*** Clear all entries in the MDC of the underlying implementation.*/public static void clear() {if (mdcAdapter == null) {throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL);}mdcAdapter.clear();}/*** Return a copy of the current thread's context map, with keys and values of* type String. Returned value may be null.* * @return A copy of the current thread's context map. May be null.* @since 1.5.1*/public static Map<String, String> getCopyOfContextMap() {if (mdcAdapter == null) {throw new IllegalStateException("MDCAdapter cannot be null. See also " + NULL_MDCA_URL);}return mdcAdapter.getCopyOfContextMap();}/*** Set the current thread's context map by first clearing any existing map and* then copying the map passed as parameter. The context map passed as* parameter must only contain keys and values of type String.* * @param contextMap*          must contain only keys and values of type String* @since 1.5.1*/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);}/*** Returns the MDCAdapter instance currently in use.* * @return the MDcAdapter instance currently in use.* @since 1.4.2*/public static MDCAdapter getMDCAdapter() {return mdcAdapter;}}

可以看到MDC具体操作都是通过MDCAdapter.java接口来操作，静态块中初始化得到MDCAdapter实现类的实例。

MDCAdapter.java

public class NOPMDCAdapter implements MDCAdapter {public void clear() {}public String get(String key) {return null;}public void put(String key, String val) {}public void remove(String key) {}public Map<String, String> getCopyOfContextMap() {return null;}public void setContextMap(Map<String, String> contextMap) {// NOP}}

slf4j-api包中对MDCAdapter接口提供了两个实现类BasicMDCAdapter和NOPMDCAdapter。在对slf4j提供具体实现的依赖包时也会提供其他MDCAdapter的实现，比如logback中提供了LogbackMDCAdapter，log4j2中提供了Log4jMDCAdapter。上述例子中集成了log4j2，下面看下Log4jMDCAdapter（log4j-slf4j-impl.jar）的具体实现：

public class Log4jMDCAdapter implements MDCAdapter {@Overridepublic void put(final String key, final String val) {ThreadContext.put(key, val);}@Overridepublic String get(final String key) {return ThreadContext.get(key);}@Overridepublic void remove(final String key) {ThreadContext.remove(key);}@Overridepublic void clear() {ThreadContext.clearMap();}@Overridepublic Map<String, String> getCopyOfContextMap() {return ThreadContext.getContext();}@Override@SuppressWarnings("unchecked") // nothing we can do about this, restricted by SLF4J APIpublic void setContextMap(@SuppressWarnings("rawtypes") final Map map) {ThreadContext.clearMap();for (final Map.Entry<String, String> entry : ((Map<String, String>) map).entrySet()) {ThreadContext.put(entry.getKey(), entry.getValue());}}

Log4jMDCAdapter内容很简洁，对容器的存取使用了一个封装类ThreadContext。
ThreadContext源码片段：

...//省略代码若干
private static ThreadContextMap contextMap;
private static ThreadContextStack contextStack;
...//省略代码若干
static void init() {contextMap = null;final PropertiesUtil managerProps = PropertiesUtil.getProperties();disableAll = managerProps.getBooleanProperty(DISABLE_ALL);useStack = !(managerProps.getBooleanProperty(DISABLE_STACK) || disableAll);useMap = !(managerProps.getBooleanProperty(DISABLE_MAP) || disableAll);contextStack = new DefaultThreadContextStack(useStack);if (!useMap) {contextMap = new NoOpThreadContextMap();} else {contextMap = ThreadContextMapFactory.createThreadContextMap();}
}
...//省略代码若干
public static void put(final String key, final String value) {contextMap.put(key, value);}
public static String get(final String key) {return contextMap.get(key);}
...//省略代码若干

ThreadContext类中存取数据使用了另一个封装ThreadContextMap，而默认ThreadContextMap由ThreadContextMapFactory.createThreadContextMap初始化：

public static ThreadContextMap createThreadContextMap() {final PropertiesUtil managerProps = PropertiesUtil.getProperties();final String threadContextMapName = managerProps.getStringProperty(THREAD_CONTEXT_KEY);final ClassLoader cl = ProviderUtil.findClassLoader();ThreadContextMap result = null;if (threadContextMapName != null) {try {final Class<?> clazz = cl.loadClass(threadContextMapName);if (ThreadContextMap.class.isAssignableFrom(clazz)) {result = (ThreadContextMap) clazz.newInstance();}} catch (final ClassNotFoundException cnfe) {LOGGER.error("Unable to locate configured ThreadContextMap {}", threadContextMapName);} catch (final Exception ex) {LOGGER.error("Unable to create configured ThreadContextMap {}", threadContextMapName, ex);}}if (result == null && ProviderUtil.hasProviders()) {final String factoryClassName = LogManager.getFactory().getClass().getName();for (final Provider provider : ProviderUtil.getProviders()) {if (factoryClassName.equals(provider.getClassName())) {final Class<? extends ThreadContextMap> clazz = provider.loadThreadContextMap();if (clazz != null) {try {result = clazz.newInstance();break;} catch (final Exception e) {LOGGER.error("Unable to locate or load configured ThreadContextMap {}",provider.getThreadContextMap(), e);result = createDefaultThreadContextMap();}}}}}if (result == null) {result = createDefaultThreadContextMap();}return result;}private static ThreadContextMap createDefaultThreadContextMap() {if (Constants.ENABLE_THREADLOCALS) {if (PropertiesUtil.getProperties().getBooleanProperty(GC_FREE_THREAD_CONTEXT_KEY)) {return new GarbageFreeSortedArrayThreadContextMap();}return new CopyOnWriteSortedArrayThreadContextMap();}return new DefaultThreadContextMap(true);}

最后默认使用DefaultThreadContextMap。DefaultThreadContextMap片段：

public DefaultThreadContextMap(final boolean useMap) {this.useMap = useMap;this.localMap = createThreadLocalMap(useMap);}// LOG4J2-479: by default, use a plain ThreadLocal, only use InheritableThreadLocal if configured.// (This method is package protected for JUnit tests.)static ThreadLocal<Map<String, String>> createThreadLocalMap(final boolean isMapEnabled) {final PropertiesUtil managerProps = PropertiesUtil.getProperties();final boolean inheritable = managerProps.getBooleanProperty(INHERITABLE_MAP);if (inheritable) {return new InheritableThreadLocal<Map<String, String>>() {@Overrideprotected Map<String, String> childValue(final Map<String, String> parentValue) {return parentValue != null && isMapEnabled //? Collections.unmodifiableMap(new HashMap<>(parentValue)) //: null;}};}// if not inheritable, return plain ThreadLocal with null as initial valuereturn new ThreadLocal<>();}

到这里已经很清楚的看到容器默认使用的是ThreadLocal<Map<String, String>>存储。所以在新建子线程时候需要通过MDC.getCopyOfContextMap()和MDC.setContextMap()将父线程MDC容器内容传递到子线程中。当然源码中注释提到，可以通过配置使用InheritableThreadLocal，这样子线程可以直接继承父线程中MDC容器内容，但是因为性能问题，默认是不启用InheritableThreadLocal的。
子线程示例：

可以看到子线程也打印出了父线程中设置的requestId值。
跟踪上面贴出来的源码，启用InheritableThreadLocal需要我们在工程里增加配置文件log4j2.component.properties，log4j-api.jar在加载时会通过PropertiesUtil读取该文件内配置的属性。
log4j2.component.properties

# 启用InheritableThreadLocal
isThreadContextMapInheritable = false

至此代码内无需在手动操作MDC.getCopyOfContextMap()和MDC.setContextMap()了，子线程会继承父线程内已经设置的MDC内容。

对于想要自定义ThreadContextMap的需要，也可以在配置文件log4j2.component.propertie中指定自己的实现类。
ThreadContextMapFactory.java

public static ThreadContextMap createThreadContextMap() {final PropertiesUtil managerProps = PropertiesUtil.getProperties();final String threadContextMapName = managerProps.getStringProperty(THREAD_CONTEXT_KEY);final ClassLoader cl = ProviderUtil.findClassLoader();ThreadContextMap result = null;// 在log4j2.component.propertie文件配置log4j2.threadContextMap = xx.xxx.xxx.yourThreadContextMap,会使用自定义ThreadContextMap实体if (threadContextMapName != null) {try {final Class<?> clazz = cl.loadClass(threadContextMapName);if (ThreadContextMap.class.isAssignableFrom(clazz)) {result = (ThreadContextMap) clazz.newInstance();}} catch (final ClassNotFoundException cnfe) {LOGGER.error("Unable to locate configured ThreadContextMap {}", threadContextMapName);} catch (final Exception ex) {LOGGER.error("Unable to create configured ThreadContextMap {}", threadContextMapName, ex);}}// 此处会检查log4j-core.jar内META-INF/log4j-provider.properties文件是否指定了ThreadContextMap实现类if (result == null && ProviderUtil.hasProviders()) {final String factoryClassName = LogManager.getFactory().getClass().getName();for (final Provider provider : ProviderUtil.getProviders()) {if (factoryClassName.equals(provider.getClassName())) {final Class<? extends ThreadContextMap> clazz = provider.loadThreadContextMap();if (clazz != null) {try {result = clazz.newInstance();break;} catch (final Exception e) {LOGGER.error("Unable to locate or load configured ThreadContextMap {}",provider.getThreadContextMap(), e);result = createDefaultThreadContextMap();}}}}}// 使用默认ThreadContextMap实体if (result == null) {result = createDefaultThreadContextMap();}return result;}