闲敲棋子 / 遇到问题

日志-MDC

2019-04-15 posted in [遇到问题]

先从问题说起

线上发现一个问题,日志里的traceId数据是错误的。排查后发现是新同学近期引入线程池时,子线程没有更新MDC里数据引起的。

看下代码,就是常规的线程池使用:

image

这里就要引入MDC的特性了。

MDC介绍

MDC(Mapped Diagnostic Context,映射调试上下文)是 log4j 和 logback 提供的一种方便在多线程条件下记录日志的类。

MDC类,简单来说就是日志的增强功能,如果配置了MDC,并添加了相应的key-value对,就会在打印日志的时候把key对应的value打印出来。

MDC内部是用ThreadLocal实现的,可以携带当前线程的context信息。

实现

MDC类(slf4j包)中包装了一个MDCAdapter(接口),不同的log包有不同的实现。log4j 中实现类是 Log4jMDCAdapter,logback 的实现类是 LogbackMDCAdapter。

MDC类中put(),get() 等方法均是调用其成员的mdcAdapter实现。我们代码中是 log4j 实现的,这里的代码切图,都来自log4j。MDC的管理是基于一个线程,然后子线程自动的继承它的父线程的MDC的副本。

image

这里MDC.put()是放到了tlm这个threadLocalMap里。

image

image

ThreadLocalMap继承自InheritableThreadLocal,在创建线程时,子线程会复制父线程的inheritableThreadLocals变量,从而拿到父线程中的信息。

产生问题原因

子线程在创建的时候会把父线程中的inheritableThreadLocals变量设置到子线程的inheritableThreadLocals中,而MDC内部是用InheritableThreadLocal实现的,所以自然会把父线程中的上下文带到子线程中。

但对于线程池中的线程来说,这部分线程是可以重用的,但是线程本身只会初始化一次,所以之后重用线程的时候,就不会进行初始化操作了,也就不会有上一段中提到的父线程inheritableThreadLocals拷贝到子线程中的过程了。

线上的traceId是在入口层统一处理了MDC的put()和remove(),然而代码中创建的线程池则没有处理这些。代码中使用的是线程池内子线程第一次创建时,copy自当时父线程的数据。因为子线程内没有更新策略,子线程自己也不会主动更新。导致日志内记录的traceId不会更新。

image

解决方法:可以在将任务提交给执行程序之前,在原始(主)线程上调用MDC.getCopyOfContextMap()得到当前线程的context拷贝。当任务运行时,作为其第一个操作,调用MDC.setContextMapValues()将原始MDC值的存储副本与新的Executor管理线程关联起来。

ibatis中传参$与#区别以及对List的排序

2012-12-17 posted in [遇到问题]

JAVA POI 操作excel遇到问题

2012-09-11 posted in [遇到问题]

SQL UPDATE语句执行顺序问题

2012-09-04 posted in [遇到问题]

SQL分组取最大N条记录

2012-09-04 posted in [遇到问题]

开发定时任务要注意的问题

2012-08-27 posted in [遇到问题]

github + jekyll 安装遇到问题

2012-08-15 posted in [遇到问题]

Maven + tomcat 报错 ClassNotFoundException

2012-05-24 posted in [遇到问题]

搞坏了配置文件于是重新配环境

2012-05-04 posted in [遇到问题]

笔记(二)

2012-03-02 posted in [遇到问题]

记在各种乱七八糟的事儿之中

2012-02-17 posted in [遇到问题]

笔记

2012-01-10 posted in [遇到问题]