Log4j2的MDC详解

概述

MDC介绍

MDC（Mapped Diagnostic Context，映射调试上下文）是 log4j 和 logback 提供的一种方便在多线程条件下记录日志的功能。某些应用程序采用多线程的方式来处理多个用户的请求。在一个用户的使用过程中，可能有多个不同的线程来进行处理。典型的例子是 Web 应用服务器。当用户访问某个页面时，应用服务器可能会创建一个新的线程来处理该请求，也可能从线程池中复用已有的线程。在一个用户的会话存续期间，可能有多个线程处理过该用户的请求。这使得比较难以区分不同用户所对应的日志。当需要追踪某个用户在系统中的相关日志记录时，就会变得很麻烦。
一种解决的办法是采用自定义的日志格式，把用户的信息采用某种方式编码在日志记录中。这种方式的问题在于要求在每个使用日志记录器的类中，都可以访问到用户相关的信息。这样才可能在记录日志时使用。这样的条件通常是比较难以满足的。MDC 的作用是解决这个问题。
MDC 可以看成是一个与当前线程绑定的哈希表，可以往其中添加键值对。MDC 中包含的内容可以被同一线程中执行的代码所访问。当前线程的子线程会继承其父线程中的 MDC 的内容。当需要记录日志时，只需要从 MDC 中获取所需的信息即可。MDC 的内容则由程序在适当的时候保存进去。对于一个 Web 应用来说，通常是在请求被处理的最开始保存这些数据。

使用案例

相对比较大的项目来说，一般会有多个开发人员，如果每个开发人员凭自己的理解打印日志，那么当用户反馈问题时，很难通过日志去快速的定位到出错原因，也会消耗更多的时间。所以针对这种问题，一般会定义好整个项目的日志格式，如果是需要追踪的日志，开发人员调用统一的打印方法，在日志配置文件里面定义好相应的字段，通过MDC功能就能很好的解决问题。
比如我们可以事先把用户的sessionId，登录用户的用户名，访问的城市id，当前访问商户id等信息定义成字段，线程开始时把值放入MDC里面，后续在其他地方就能直接使用，无需再去设置了。
使用MDC来记录日志，一来可以规范多开发下日志格式的一致性，二来可以为后续使用ELK对日志进行分析。
所需依赖

 <dependency>
    <groupId>log4j</groupId>
    <artifactId>log4j</artifactId>
    <version>1.2.17</version>
  </dependency>
  <dependency>
      <groupId>org.slf4j</groupId>
      <artifactId>slf4j-log4j12</artifactId>
      <version>1.7.21</version>
  </dependency> 

log4j.xml配置样例，追踪日志自定义格式主要在name="trance"的layout里面进行设置，我们使用%X{userName}来定义此处会打印MDC里面key为userName的value，如果所定义的字段在MDC不存在对应的key，那么将不会打印，会留一个占位符。

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration>
    <appender name="console" class="org.apache.log4j.ConsoleAppender">
        <param name="target" value="System.out" />
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%-d{yyyy-MM-dd HH:mm:ss.SSS} %-6p%c:%L %x - %m%n" />
        </layout>
    </appender>
 
    <appender name="error" class="org.apache.log4j.DailyRollingFileAppender">
        <param name="File" value="D://logs//error.log" />
        <param name="DatePattern" value="'.'yyyy-MM-dd" />
        <param name="threshold" value="error"/>
        <param name="append" value="true"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="[%d{yyyy-MM-dd HH:mm:ss.SSS}] %-6p%c:%L - %m%n" />
        </layout>
    </appender>
 
    <appender name="logic" class="org.apache.log4j.DailyRollingFileAppender">
        <param name="File" value="D://logs//logic.log" />
        <param name="DatePattern" value="'.'yyyy-MM-dd" />
        <param name="threshold" value="info"/>
        <param name="append" value="true"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="[%d{yyyy-MM-dd HH:mm:ss.SSS}] %-6p%c:%L - %m%n" />
        </layout>
    </appender>
 
    <appender name="trace" class="org.apache.log4j.DailyRollingFileAppender">
        <param name="File" value="D://logs//trace.log" />
        <param name="DatePattern" value="'.'yyyy-MM-dd" />
        <param name="threshold" value="info"/>
        <param name="append" value="true"/>
        <layout class="org.apache.log4j.PatternLayout">
               <param name="ConversionPattern" value="[%d{yyyy-MM-dd HH:mm:ss.SSS}] - %X{mchId} - %X{mchName} - %X{siteName} - %X{sessionId} - %X{cityId} - %X{userName} - %X{mobile} - %m%n" />
         </layout>
    </appender>
 
    <logger name="traceLog" additivity="false">
        <level value="info" />
        <appender-ref ref="trace" />
    </logger>
 
    <root>
        <level value="info" />
        <appender-ref ref="console"/>
        <appender-ref ref="logic" />
        <appender-ref ref="error" />
    </root>
</log4j:configuration>

日志打印类

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
 
public class TraceLogger {
    //此处的"tranceLog"为log4j中定义的对应的 logger的name
    private static final Logger TRACE_LOGGER = LoggerFactory.getLogger("traceLog");
 
    private TraceLogger() {
    	
    }
  
    public static void info(String message){
        TRACE_LOGGER.info(message);
    }
 
    public static void info(String format,Object... arguments){
        TRACE_LOGGER.info(format, arguments);
    }
}

最后写个日志打印测试一下效果

@Test
public void Test(){
    MDC.clear();
    MDC.put("sessionId" , "f9e287fad9e84cff8b2c2f2ed92adbe6");
    MDC.put("cityId" , 1);
    MDC.put("siteName" , "北京");
    MDC.put("userName" , "userwyh");
    TraceLogger. info("测试MDC打印一");
		 
    MDC.put("mobile" , "110");
    TraceLogger. info("测试MDC打印二");
         
    MDC.put("mchId" , 12);
    MDC.put("mchName", "商户名称");
    TraceLogger. info("测试MDC打印三");
         
}

简单使用方式（无需log4j2.xml额外配置）

方法一

使用MDC.getCopyOfContextMap()和MDC.setContextMap(MAP<String,String>)，根据方法名我想当然以为在父线程中setContextMap，在子线程中getCopyOfContextMap，然而并不是这样！！！下面是正确的写法。

应该是先在父线程getCopyOfContextMap，再在子线程setContextMap。翻一下源码，其实也能理解，要先生成了map对象，然后里面存放了父线程的数据，在子线程中把它放到MDC中，那么子线程就可以读取其中的数据了。

方法二

我本地的项目是一个java项目，只有一个类，然后我按照网上的办法初始化了log4j2.isThreadContextMapInheritable为true。代码如下。

这个很简单就成功了，但是，换到开发环境上的web项目，就死活不行了。经过分析发现，必须在Logger对象第一次初始化之前，就要把环境变量设置进去。。。

然后就去tomcat的配置文件里面搞了，在catalina,.sh或catalina.bat里面，给JAVA_OPTS加上-Dlog4j2.isThreadContextMapInheritable=true。重启应用完活。

方法三：增加log4j2.component.properties文件

在resources目录下，增加log4j2.component.properties文件，在里面写上isThreadContextMapInheritable=true，这样log4j2会自己去读取配置文件，就不用再改其他地方了，这个在源码里面可以找到。

参考

log4j2的MDC或ThreadContext子线程获取不到父线程数据
log4j MDC用户操作日志追踪配置