SLF4J MDC在全链路跟踪中的应用

经常做线上问题排查的可能会有感受，由于日志打印一般是无序的，多线程下想要串行拿到一次请求中的相关日志简直是大海捞针。那么MDC是一种很好的解决办法。

SLF4J的MDC

SLF4J 提供了MDC ( Mapped Diagnostic Contexts )功能，它的实现也是利用了 ThreadLocal 机制。 在代码中，只需要将指定的值 put 到线程上下文的 Map 中，然后在对应的地方使用 get 方法获取对应的值，从而达到自定义和修改日志输出格式内容的目的。

例如以下受log4j2.xml模板：

<Pattern>%d %p [%c] [%X{key1},%X{key2}]- %m%n</Pattern>

在日志模板log4j2.xml中，使用 %X{} 来占位，内容会替换为对应MDC 中 key的值，以达到自定义日志格式的效果。

MDC在链路跟踪中的应用

在链路跟踪框架中，其实扩展MDC很简单，只需在log span的before方法中塞入traceId与spanId，在after方法中进行清理逻辑即可。

private void beforeStartSpan(Span span){
     MDC.put(TraceKeys.TRACE_ID, span.getTraceId());
     MDC.put(TraceKeys.SPAN_ID, span.getSpanId());
}

private void afterEndSpan(Span span){
      MDC.remove(TraceKeys.TRACE_ID);
      MDC.remove(TraceKeys.SPAN_ID);
      if (span != null) {
           MDC.put(TraceKeys.TRACE_ID, currentSpan.getTraceId());
           MDC.put(TraceKeys.SPAN_ID, currentSpan.getParentId()); //此处需要塞回parent span的spanId
      }
}

那么在log4j2.xml中配置:

<Pattern>%d %p [%c] [%X{TraceId},%X{SpanId}]- %m%n</Pattern>   //在合适的地方加入 [%X{TraceId},%X{SpanId}] 即可

这样输出日志即为:

2019-01-29 19:06:15,482 INFO [com.fredal.TestController] [e9b84d301f73f6e1a6386f216fa0120d,9296f83b058675d2]- this is a test in test
2019-01-29 19:06:15,489 INFO [com.fredal.TestController] [e9b84d301f73f6e1a6386f216fa0120d,f435c1cb819db821]- this is a test in test/provider

异步中的MDC

由于MDC是基于Threadlocal的，那么如果一个请求中有异步的逻辑，那么异步过程中的日志是取不到MDC中的值的。

这也是个老生常谈的问题了，由于我们的全链路跟踪框架已经使用Transmittable ThreadLocal改造过了，见 调用链跨线程传递THREADLOCAL对象 ，所以在异步线程中也是同样能获得的MDC的值的。