slf4j 之MDC使用

公司目前使用的都 slf4j+logback 的日志框架，并且日志流水习惯直接在请求进来就生成并且用 slf4j 的 MDC 类设置进去，方便日志根据流水排查，但是没有系统的好好看过具体 MDC 做了什么事情，也刚好在某个模块使用 MDC 的时候踩了点坑，趁这个机会把 MDC 好好看一遍。

本文 slf4j 版本为 1.7.5，因为用的logback 版本是 1.0.13，里面自带了 slf4j api 的版本就是 1.7.5 的。

1、什么是MDC

    根据 https://logback.qos.ch/manual/mdc.html 说的一段话：

To uniquely stamp each request, the user puts contextual information into the MDC, the abbreviation of Mapped Diagnostic Context.

 The salient parts of the MDC class are shown below. Please refer to the MDC javadocs for a complete list of methods. 

MDC 为每个请求提供了保存当前上下文本的内容。也就是说 MDC 操作的值，无论是插入还是获取，主要在当前请求中（线程中）操作，都可以完成。通俗说就是线程变量。

看看 MDC 主要提供的几个方法：

package org.slf4j;

public class MDC {
  //Put a context value as identified by key
  //into the current thread's context map.
  public static void put(String key, String val);

  //Get the context identified by the key parameter.
  public static String get(String key);

  //Remove the context identified by the key parameter.
  public static void remove(String key);

  //Clear all entries in the MDC.
  public static void clear();
}

跟容易操作，跟正常的 Map 的put&set 操作差不多，而且还是静态方法，更简单了。

2、搭配 logback 配置使用

    假设定义个变量名为 TRACE_LOG_ID，我们希望在日志打印的时候每次都会打印这个 TRACE_LOG_ID 的值，那么我们在请求进来的时候就需要先调用 MDC 的 put 方法进行设值

MDC.put("TRACE_LOG_ID",System.currentTimeMillis());

接着在 logback 配置文件中加上这句配置：

<Pattern>[%date][%-4level][%line][%thread] logSeq:[%X{TRACE_LOG_ID}] call [%logger][%method] %msg%n</Pattern>

3、MDCAdapter

    先看看 MDC 的代码（下面删了很多代码，留下了部分比较重要的）：

public class MDC {

  static MDCAdapter mdcAdapter;

  private MDC() {
  }

  static {
    try {
      mdcAdapter = StaticMDCBinder.SINGLETON.getMDCA();
    } catch (NoClassDefFoundError ncde) {
      mdcAdapter = new NOPMDCAdapter();
      
    } 
  }
  
  public static void put(String key, String val)
      throws IllegalArgumentException {
    
    mdcAdapter.put(key, val);
  }
  
  public static String get(String key) throws IllegalArgumentException {
    
    return mdcAdapter.get(key);
  }

  public static void remove(String key) throws IllegalArgumentException {
    
    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 getCopyOfContextMap() {
    
    return mdcAdapter.getCopyOfContextMap();
  }
 
  public static void setContextMap(Map contextMap) {
    
    mdcAdapter.setContextMap(contextMap);
  }

  public static MDCAdapter getMDCAdapter() {
    return mdcAdapter;
  }

}

根据 MDC 的代码实际可以发现他的 put，get 等操作都是交给了 MDCAdapter 这个对象来处理的，而看了对于不同的日志框架实现都有自己的实现类，像我们使用的 logback 的实现类为 LogbackMDCAdapter。

看看下面这句话：

mdcAdapter = StaticMDCBinder.SINGLETON.getMDCA();

这里就是 slf4j 对不同框架的实现的调用，在 logback 中，有这么一个类 org.slf4j.impl.StaticMDCBinder 实际上他返回的就是一个新的 LogbackMDCAdapter 实例：

public class StaticMDCBinder {

  public static final StaticMDCBinder SINGLETON = new StaticMDCBinder();
  private StaticMDCBinder() {
  }
  public MDCAdapter getMDCA() {
     return new LogbackMDCAdapter();
  }

}

4、LogbackMDCAdapter

  通过上面我们知道，实际上当我们用 slf4j+logback 配合使用的时候，调用的 MDC 的具体实现是交给了 LogbackMDCAdapter，那么它是如何操作的？

    先看看 LogbackMDCAdapter 的文档说明：

 * A <em>Mapped Diagnostic Context</em>, or MDC in short, is an instrument for
 * distinguishing interleaved log output from different sources. Log output is
 * typically interleaved when a server handles multiple clients
 * near-simultaneously.
 * <p/>
 * <b><em>The MDC is managed on a per thread basis</em></b>. A child thread
 * automatically inherits a <em>copy</em> of the mapped diagnostic context of
 * its parent.

    主要说明了两点：   

1.     MDC 主要用于保存上下文，区分不同的请求来源。
2.     MDC 管理是按线程划分，并且子线程会自动继承母线程的上下文。

    再看看主要的 get&put 具体的实现代码：

public final class LogbackMDCAdapter implements MDCAdapter {

  final InheritableThreadLocal<Map<String, String>> copyOnInheritThreadLocal = new InheritableThreadLocal<Map<String, String>>();

  private static final int WRITE_OPERATION = 1;
  private static final int READ_OPERATION = 2;

  // keeps track of the last operation performed
  final ThreadLocal<Integer> lastOperation = new ThreadLocal<Integer>();
 
  public void put(String key, String val) throws IllegalArgumentException {
    
    Map<String, String> oldMap = copyOnInheritThreadLocal.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);
    }
  }

  public String get(String key) {
    Map<String, String> map = getPropertyMap();
    if ((map != null) && (key != null)) {
      return map.get(key);
    } else {
      return null;
    }
  }

}

可以看到 LogbackMDCAdapter 有两个主要的变量：InheritableThreadLocal 跟 ThreadLocal .其中 InheritableThreadLocal 是 ThreadLocal 的子类。

在 LogbackMDCAdapter 中，把真正的操作都交给了 InheritableThreadLocal ，ThreadLocal 主要用来记录最后一次对保存在 InheritableThreadLocal  中的map的操作，是read 还是write，在做操作的时候都会进行检查。

InheritableThreadLocal 是 ThreadLocal 的子类，实际上他只重写了3个方法：

public class InheritableThreadLocal<T> extends ThreadLocal<T> {

    protected T childValue(T parentValue) {
        return parentValue;
    }

    ThreadLocalMap getMap(Thread t) {
       return t.inheritableThreadLocals;
    }

    void createMap(Thread t, T firstValue) {
        t.inheritableThreadLocals = new ThreadLocalMap(this, firstValue);
    }
}

根据 InheritableThreadLocal  的文档说明如下：

 * This class extends <tt>ThreadLocal</tt> to provide inheritance of values
 * from parent thread to child thread: when a child thread is created, the
 * child receives initial values for all inheritable thread-local variables
 * for which the parent has values.  Normally the child's values will be
 * identical to the parent's; however, the child's value can be made an
 * arbitrary function of the parent's by overriding the <tt>childValue</tt>
 * method in this class.

    简单的理解就是创建子线程的时候，如果父线程的 InheritableThreadLocal 中保存有上下文内容的话，那么就会继承给子线程，这也就理解了 LogbackMDCAdapter 在父线程保存的值为什么子线程可以获取到。

    再看看 InheritableThreadLocal  的 set&get 操作，也就是 ThreadLocal 的 set() & get() 方法：

public void set(T value) {
        Thread t = Thread.currentThread();
        ThreadLocalMap map = getMap(t);
        if (map != null)
            map.set(this, value);
        else
            createMap(t, value);

}
public T get() {
	Thread t = Thread.currentThread();
	ThreadLocalMap map = getMap(t);
	if (map != null) {
		ThreadLocalMap.Entry e = map.getEntry(this);
		if (e != null) {
			@SuppressWarnings("unchecked")
			T result = (T)e.value;
			return result;
		}
	}
	return setInitialValue();
}

     这里步骤很简单，获取当前的具体线程，然后调用getMap()获取 ThreadLocalMap对象（我们都知道ThreadLocal实际上是保存到了 ThreadLocalMap 中的，key就是 ThreadLocal，value就是 ThreadLocal保存的value）.

    而 InheritableThreadLocal  的 getMap 方法是重写的，返回的实际上是 Thread类的 inheritableThreadLocals。（这里补充一下，Thread 有两个 ThreadLocalMap 变量，默认是使用 threadLocals，inheritableThreadLocals是配合 InheritableThreadLocal  这个类使用的。）

    /* ThreadLocal values pertaining to this thread. This map is maintained
     * by the ThreadLocal class. */
    ThreadLocal.ThreadLocalMap threadLocals = null;

    /*
     * InheritableThreadLocal values pertaining to this thread. This map is
     * maintained by the InheritableThreadLocal class.
     */
    ThreadLocal.ThreadLocalMap inheritableThreadLocals = null;

    那么具体父线程保存到的 InheritableThreadLocal  的值是如何传递给子线程的？根据 Thread 的代码可以发现，在 new Thread() 的时候会做一个  init() 的操作，而该 init() 的方法就会执行下面具体这几行代码：

private void init(ThreadGroup g, Runnable target, String name,
                      long stackSize, AccessControlContext acc) {
       
        Thread parent = currentThread();
       
	   if (parent.inheritableThreadLocals != null)
            this.inheritableThreadLocals =
                ThreadLocal.createInheritedMap(parent.inheritableThreadLocals);
       
}

具体操作：

1.     设置当前线程为新创建的线程的父线程。
2.    判断父线程的 inheritableThreadLocals 是否为空，若不为空，则将父线程的该值重新赋给新创建的线程的 inheritableThreadLocals。

至此也就基本清楚了为何 MDC 的在父线程的一个 put 才操作，在子线程可以直接get 到对应的值。

总结：

    MDC 实际上的实现就是交给了具体实现了 MDCAdapter 的 LogbackMDCAdapter 进行操作，而 LogbackMDCAdapter 底层也是用了jdk 自带的 InheritableThreadLocal 对象进行处理，该对象在进行操作的时候是操作当前线程的 inheritableThreadLocals（ThreadLocalMap） 变量，该变量当前线程创建新的子线程的时候，会从当前线程把该变量的值复制一份给子线程。

    特别需要注意的点：从父线程自动复制 inheritableThreadLocals 给子线程的 inheritableThreadLocals 变量的时候，只有在 new Thread() 子线程的时候才会触发，也就是说只会触发一遍，一旦父线程创建子线程之后，父线程修改了变量，子线程是不生效的。