日志追踪
日志追踪对于功能问题的排查和数据流转的路径分析时非常重要的，有了全链路日志追踪体系机制可以非常有效且快速的定位问题，但在多线程环境中，若没有相关成熟的框架的支持，想要实现日志追踪，就需要手动将主线程中的日志参数传递给子线程，接下来就在线程池场景下借助 MDC 实现了 traceId 参数的透传。
候选方案
方案 1：解决办法是采用自定义的日志格式，把用户的信息采用某种方式编码在日志记录中。这种方式的问题在于要求在每个使用日志记录器的类中，都可以访问到用户相关的信息。这样才可能在记录日志时使用。这样的条件通常是比较难以满足的，MDC 的作用是解决这个问题。
方案 2： MDC（Mapped Diagnostic Context，映射调试上下文） 是 slf4j 提供的一种轻量级的日志跟踪工具，Log4j、Logback 或者 Log4j2 等日志中最常见区分同一个请求的方式是通过线程名/线程 ID，但是而如果请求量大，线程名/线程 ID 会在相邻的时间内出现多次重复的打印，因此引出了 trace-id，即在接收到的时候生成唯一的请求 id，在整个执行链路中带上此唯一 id。
Sl4fj 的 MDC 模式的介绍
Sl4fj 的 MDC 的源码
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;
private MDC() { }
private static MDCAdapter bwCompatibleGetMDCAdapterFromBinder() throws NoClassDefFoundError { try { return StaticMDCBinder.getSingleton().getMDCA(); } catch (NoSuchMethodError var1) { return StaticMDCBinder.SINGLETON.getMDCA(); } }
public static void put(String key, String val) throws IllegalArgumentException { if (key == null) { throw new IllegalArgumentException("key parameter cannot be null"); } else if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA"); } else { mdcAdapter.put(key, val); } }
public static MDCCloseable putCloseable(String key, String val) throws IllegalArgumentException { put(key, val); return new MDCCloseable(key); }
public static String get(String key) throws IllegalArgumentException { if (key == null) { throw new IllegalArgumentException("key parameter cannot be null"); } else if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA"); } else { return mdcAdapter.get(key); } }
public static void remove(String key) throws IllegalArgumentException { if (key == null) { throw new IllegalArgumentException("key parameter cannot be null"); } else if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA"); } else { mdcAdapter.remove(key); } } public static void clear() { if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA"); } else { mdcAdapter.clear(); } } public static Map<String, String> getCopyOfContextMap() { if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA"); } else { return mdcAdapter.getCopyOfContextMap(); } } public static void setContextMap(Map<String, String> contextMap) { if (mdcAdapter == null) { throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA"); } else { mdcAdapter.setContextMap(contextMap); } } public static MDCAdapter getMDCAdapter() { return mdcAdapter; } static { try { mdcAdapter = bwCompatibleGetMDCAdapterFromBinder(); } catch (NoClassDefFoundError var2) { mdcAdapter = new NOPMDCAdapter(); String msg = var2.getMessage(); if (msg == null || !msg.contains("StaticMDCBinder")) { throw var2; } Util.report("Failed to load class \"org.slf4j.impl.StaticMDCBinder\"."); Util.report("Defaulting to no-operation MDCAdapter implementation."); Util.report("See http://www.slf4j.org/codes.html#no_static_mdc_binder for further details."); } catch (Exception var3) { Util.report("MDC binding unsuccessful.", var3); } } public static class MDCCloseable implements Closeable { private final String key; private MDCCloseable(String key) { this.key = key; } public void close() { MDC.remove(this.key); } }}
复制代码
Sl4fj 的 MDC 模式主要的门面类是 MDC.java，但是最核心的类是 MDCAdapter，可由下面的代码观测出。
对应而定实现加载所有相关的 MDCAdapter 的类就在这里，而代码里面的功能展示信息也是我们经常会遇见的，如果出现错误的时候，经常会打印再日志的最开始部分。
Sl4fj 的 MDCAdapter 的源码
大家可以观察到对应的 MDCAdapter 的实现类有一下这几种，基本上是会交由第三方去实现的。
而对于 Sl4j 本身不提供传递 traceId 的能力，真正提供能力的是 MDCAdapter 接口的实现。
Logback 使用的是 LogbackMDCAdapter。比如 Log4j 的是 Log4jMDCAdapter，Logback 的是 LogbackMDCAdapter。其内部自己的 MDCAdapter 属于空实现的 NOPMDCAdapter 类和 BasicMDCAdapter，第三方的 OPMDCAdapter，不太了解。
MDC 的实现原理
MDC 可以看成是每个线程内部都进行顶一个所属私有的容器（也可以理解为哈希表），我们可以通过程序往其中添加键值对。
MDC 内的数据可以被当前线程的代码所访问，当前线程所产生的子线程也会继承其父线程中的 MDC 的数据，当需要记录日志时，只需要从 MDC 中获取所需的信息即可。
MDC 的内容则由程序在适当的时候保存进去。对于一个 Web 应用来说，通常是在请求被处理的最开始保存这些数据。
Sl4j 的 MDCAdapter 的实现机制
public class BasicMDCAdapter implements MDCAdapter { private InheritableThreadLocal<Map<String, String>> inheritableThreadLocal = new InheritableThreadLocal<Map<String, String>>() { protected Map<String, String> childValue(Map<String, String> parentValue) { return parentValue == null ? null : new HashMap(parentValue); } };
public BasicMDCAdapter() { } public void put(String key, String val) { if (key == null) { throw new IllegalArgumentException("key cannot be null"); } else { Map<String, String> map = (Map)this.inheritableThreadLocal.get(); if (map == null) { map = new HashMap(); this.inheritableThreadLocal.set(map); } ((Map)map).put(key, val); } } public String get(String key) { Map<String, String> map = (Map)this.inheritableThreadLocal.get(); return map != null && key != null ? (String)map.get(key) : null; } public void remove(String key) { Map<String, String> map = (Map)this.inheritableThreadLocal.get(); if (map != null) { map.remove(key); } } public void clear() { Map<String, String> map = (Map)this.inheritableThreadLocal.get(); if (map != null) { map.clear(); this.inheritableThreadLocal.remove(); } } public Set<String> getKeys() { Map<String, String> map = (Map)this.inheritableThreadLocal.get(); return map != null ? map.keySet() : null; } public Map<String, String> getCopyOfContextMap() { Map<String, String> oldMap = (Map)this.inheritableThreadLocal.get(); return oldMap != null ? new HashMap(oldMap) : null; } public void setContextMap(Map<String, String> contextMap) { this.inheritableThreadLocal.set(new HashMap(contextMap)); }}
复制代码
Logback 的 MDC 模式
当在 logback.xml 中配置了 %X{key} 或 SiftingAppender 的<discriminator>的<key>，在需要输出日志的时候，从 MDC 中获取对应的 key 值，然后 append 到日志字符串中或生成文件路径，然后输出。
LogbackMDCAdapter 的源码分析
public class LogbackMDCAdapter implements MDCAdapter { final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal(); private static final int WRITE_OPERATION = 1; private static final int MAP_COPY_OPERATION = 2; final ThreadLocal<Integer> lastOperation = new ThreadLocal();
public LogbackMDCAdapter() { }
private Integer getAndSetLastOperation(int op) { Integer lastOp = (Integer)this.lastOperation.get(); this.lastOperation.set(op); return lastOp; }
private boolean wasLastOpReadOrNull(Integer lastOp) { return lastOp == null || lastOp == 2; }
private Map<String, String> duplicateAndInsertNewMap(Map<String, String> oldMap) { Map<String, String> newMap = Collections.synchronizedMap(new HashMap()); if (oldMap != null) { synchronized(oldMap) { newMap.putAll(oldMap); } }
this.copyOnThreadLocal.set(newMap); return newMap; }
public void put(String key, String val) throws IllegalArgumentException { if (key == null) { throw new IllegalArgumentException("key cannot be null"); } else { Map<String, String> oldMap = (Map)this.copyOnThreadLocal.get(); Integer lastOp = this.getAndSetLastOperation(1); if (!this.wasLastOpReadOrNull(lastOp) && oldMap != null) { oldMap.put(key, val); } else { Map<String, String> newMap = this.duplicateAndInsertNewMap(oldMap); newMap.put(key, val); } } }
public void remove(String key) { if (key != null) { Map<String, String> oldMap = (Map)this.copyOnThreadLocal.get(); if (oldMap != null) { Integer lastOp = this.getAndSetLastOperation(1); if (this.wasLastOpReadOrNull(lastOp)) { Map<String, String> newMap = this.duplicateAndInsertNewMap(oldMap); newMap.remove(key); } else { oldMap.remove(key); } } } } public void clear() { this.lastOperation.set(1); this.copyOnThreadLocal.remove(); } public String get(String key) { Map<String, String> map = (Map)this.copyOnThreadLocal.get(); return map != null && key != null ? (String)map.get(key) : null; } public Map<String, String> getPropertyMap() { this.lastOperation.set(2); return (Map)this.copyOnThreadLocal.get(); } public Set<String> getKeys() { Map<String, String> map = this.getPropertyMap(); return map != null ? map.keySet() : null; } public Map<String, String> getCopyOfContextMap() { Map<String, String> hashMap = (Map)this.copyOnThreadLocal.get(); return hashMap == null ? null : new HashMap(hashMap); } public void setContextMap(Map<String, String> contextMap) { this.lastOperation.set(1); Map<String, String> newMap = Collections.synchronizedMap(new HashMap()); newMap.putAll(contextMap); this.copyOnThreadLocal.set(newMap); }
复制代码
主要问题是针对于 Collections.synchronizedMap(new HashMap())，建立 HashMap 的安全模式进行构建容器对象，所以是线程安全的问题控制。
final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal();
复制代码
某些应用程序采用多线程的方式来处理多个用户的请求。在一个用户的使用过程中，可能有多个不同的线程来进行处理。典型的例子是 Web 应用服务器。当用户访问某个页面时，应用服务器可能会创建一个新的线程来处理该请求，也可能从线程池中复用已有的线程。
MDC 的简单使用方式
添加 traceId
MDC.put(“trace-id”, traceId);
复制代码
移除 traceId
在日志配置文件中<pattern>节点中以 %X{trace-id}取出，比如：<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level [uniqid-%X{trace-id}] %logger{50}-%line - %m%n</pattern>以上方式，只能在做 put 操作的当前线程中获取到值。那是因为 MDC 的实现原理主要就是 ThreadLocal，ThreadLocal 只对当前线程有效。例如我们举一个简单的 Logback 案例、log4j 和 log4j2 也是一样的模式。
<?xml version="1.0" encoding="UTF-8"?><configuration> <appender name="console" class="ch.qos.logback.core.ConsoleAppender"> <encoder charset="UTF-8"> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%trace-id] %-5level %logger{36} - %msg%n</pattern> </encoder> </appender> <logger name="com.XXX" level = "INFO"> <appender-ref ref="console"/> </logger></configuration>
复制代码
此外 logback 中也可以使用占位符 %X{ }来占位，替换到对应的 MDC 中 key 的值
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> <layout> <Pattern>%X{trace-id}- %m%n</Pattern> </layout> </appender>
复制代码
MDC 的难点功课实战
多线程情况下的 MDC 实现问题
当我们处于多个线程之间进行传递 traceId 的时候，可能就会存在 ThreadLocal 的问题了。那么如果要破除 ThreadLocal 只对当前线程有线的方法：
（针对于跨线程传递的问题）可以采用 JDK 自带的、ThreadLocal 的扩展类 InheritableThreadLocal，子线程会拷贝父线程中的变量值
（针对于线程池线程复用的问题）引入 alibaba 包的 TransmittableThreadLocal 实现
（针对于线程池线程复用的问题）自己封装一个线程池去处理线程池所存在的问题。
针对于跨线程传递的问题
针对于跨线程传递 traceId 的问题，主要通过 InheritableThreadLocal 的方式进行拷贝传递即可，需要注意的是，如果没有采用线程池的场景的化，基本上不会出现什么问题，但是如果村子啊线程池的场景下那么就只能我们自己手动实现和处理了，如果采用 TransmittableThreadLocal 的话大家可以自行百度了，在这里我们主要实现的是自己去通过几种方式实现功能传递。
针对于线程池线程复用的问题
如果使用的是 Spring 的线程池 ThreadPoolTaskExecutor
那么就可以采用 TaskDecorator 的线程任务装饰器方式为线程池的线程提供 traceId 的传递操作，例如以下代码。
定义线程装饰器
此处我采用的是 log back，如果是 log4j 或者 log4j2 还是有一些区别的，比如说 MDC.getCopyOfContextMap()。
public class MDCTaskDecorator implements TaskDecorator { @Override public Runnable decorate(Runnable runnable) { // 此时获取的是父线程的上下文数据 Map<String, String> contextMap = MDC.getCopyOfContextMap(); return () -> { try { if (contextMap != null) { // 内部为子线程的领域范围，所以将父线程的上下文保存到子线程上下文中，而且每次submit/execute调用都会更新为最新的上 // 下文对象 MDC.setContextMap(contextMap); } runnable.run(); } finally { // 清除子线程的，避免内存溢出，就和ThreadLocal.remove()一个原因 MDC.clear(); } }; }}
复制代码
定义线程池
@Bean("taskExecutor") public Executor taskExecutor() { ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor(); //配置核心线程数 executor.setCorePoolSize(5); //配置最大线程数 executor.setMaxPoolSize(10); //配置队列大小 executor.setQueueCapacity(100); //配置线程池中的线程的名称前缀 executor.setThreadNamePrefix("mdc-trace-"); // 异步MDC executor.setTaskDecorator(new MDCTaskDecorator()); //执行初始化 executor.initialize(); return executor; }
复制代码
这样就是先了 traceId 传递到线程池中了。
我们自定义线程装饰器
与上面的不同我们如果用的不是 spring 的线程池那么无法实现 TaskDecorator 接口，那么就无法实现他的功能了，此时我们就会定义我们自身的线程装配器。
public class MDCTaskDecorator {
public static <T> Callable<T> buildCallable(final Callable<T> callable, final Map<String, String> context) { return () -> { if (CollectionUtils.isEmpty(context)) { MDC.clear(); } else { //MDC.put("trace_id", IdUtil.objectId()); MDC.setContextMap(context); } try { return callable.call(); } finally { // 清除子线程的，避免内存溢出，就和ThreadLocal.remove()一个原因 MDC.clear(); } }; }
public static Runnable buildRunnable(final Runnable runnable, final Map<String, String> context) { return () -> { if (CollectionUtils.isEmpty(context)) { MDC.clear(); } else { //MDC.put("trace_id", IdUtil.objectId()); MDC.setContextMap(context); } try { runnable.run(); } finally { // 清除子线程的，避免内存溢出，就和ThreadLocal.remove()一个原因 MDC.clear(); } }; }}
复制代码
清除子线程的，避免内存溢出，就和 ThreadLocal.remove()一个原因
自定义线程池进行封装包装操作（普通线程池）
主线程中，如果使用了线程池，会导致线程池中丢失 MDC 信息；解决办法：需要我们自己重写线程池，在调用线程跳动 run 之前，获取到主线程的 MDC 信息，重新 put 到子线程中的。
public class ThreadPoolMDCExecutor extends ThreadPoolTaskExecutor { @Override public void execute(Runnable task) { super.execute(MDCTaskDecorator.buildRunnable(task, MDC.getCopyOfContextMap())); } @Override public Future<?> submit(Runnable task) { return super.submit(MDCTaskDecorator.buildRunnable(task, MDC.getCopyOfContextMap())); }
@Override public <T> Future<T> submit(Callable<T> task) { return super.submit(MDCTaskDecorator.buildCallable(task, MDC.getCopyOfContextMap())); }}
复制代码
自定义线程池进行封装包装操作（任务调度线程池）
public class ThreadPoolMDCScheduler extends ThreadPoolTaskScheduler { @Override public ScheduledFuture<?> scheduleWithFixedDelay(Runnable task, Date startTime, long delay) { return super.scheduleWithFixedDelay(MDCTaskDecorator.buildRunnable(task), startTime, delay); } @Override public ScheduledFuture<?> schedule(Runnable task, Date startTime) { return super.schedule(MDCTaskDecorator.buildRunnable(task), startTime); }}
复制代码
同理，即使你使用 ExecutorCompletionService 实现多线程调用，也是相同的方案和思路机制。
特殊场景-CompletableFuture 实现多线程调用
使用 CompletableFuture 实现多线程调用，其中收集 CompletableFuture 运行结果，也可以手动使用相似的思路进行填充上下文信息数据，但是别忘记了清理 clear 就好。
private CompletableFuture<Result> test() { Map<String, String> copyOfContextMap = MDC.getCopyOfContextMap(); return CompletableFuture.supplyAsync(() -> { MDC.setContextMap(copyOfContextMap); //执行业务操作 MDC.clear(); return new Result(); }, threadPoolExecutor).exceptionally(new Function<Throwable, Result>() { @Override public Result apply(Throwable throwable) { log.error("线程[{}]发生了异常[{}], 继续执行其他线程", Thread.currentThread().getName(), throwable.getMessage()); MDC.clear(); return null; } }); }
复制代码
最后总结说明
后续的它的姊妹篇【Logback+Spring-Aop】实现全面生态化的全链路日志追踪系统服务插件「SpringAOP 整合篇」，会进行分析通过 SpringAOP 模式将 Logback 的 MDC 模式与 SpringAOP 结合形成一个较为体系化的组件，从而减少了很多开发过程中的代码和问题。
评论