使用MDC时,希望每个请求的日志都能绑定到对应的trackingid上,但是往往事与愿违,存在以下两种不可控情况:
(1)现象: 一些日志始终绑定某个trackingid
使用第三方或者其他人提供的包时,其他人采用的是异步线程去实现的,这个时候,第一个请求会触发第一个线程建立起来,而第一个线程的trackingid会和第一个请求一样(创建的线程的threadlocal会继承创建者):
Thread的构造器实现
if (parent.inheritableThreadLocals != null) this.inheritableThreadLocals = ThreadLocal.createInheritedMap(parent.inheritableThreadLocals);
这样导致,只要这个线程一直存在,就一直是和第一个请求一致。
因为callable或runnable的task内容不是自己可以控制的范畴,导致再无机会去修改。
private static final ExecutorService pool= Executors.newFixedThreadPool(3); public static final String checkAsync(String checkItem) { checkFuture= pool.submit(new Callable(checkItem) { public String call() throws Exception { ...... //第三方库,无法修改,如果是自己库,直接MDC.put("TrackingID", trackingID)既可修改,或者更标准的搞法(slf4j支持): “In such cases, it is recommended that MDC.getCopyOfContextMap() is invoked on the original (master) thread before submitting a task to the executor. When the task runs, as its first action, it should invoke MDC.setContextMapValues() to associate the stored copy of the original MDC values with the new Executor managed thread.” } });
代码示例的情况没有太大危险,因为线程一旦创建,就不会消亡,所以最多某个首次请求,查询到的日志特别多,后面的请求对不上号。但是如果某个线程池是有timeout回收的,则有可能导致很多次请求查询到的trackingid日志都特别多。
解决方案,不想固定死某个trackingid,则调用那个api前clean掉mdc里的trackingid,这样创建的线程就不会带有,即既然不属于我一个人,干脆放弃。调用完再找回。但是这样修改后,调用过程的log就都没有trackingid了。所以很难完美解决,要么有很多且对不上号的,要么一个都没有。
(2)现象:某个请求中,tracking中途丢失了或者变成别的了。
这是因为调用了第三方库,而第三库做了一些特殊处理,比如
public String call(String checkItem) { call(checkItem, null) } public String call(String checkItem, Map config) { String trackingID = config.get("TrackingID"); if(trackingID == null) trackingID = ""; MDC.put("TrackingID", trackingID); //因为没有显示trackingid来调用,导致后面的这段逻辑把之前设置的trackingid给清空了(="")。 ...... }
解决方案: 方案(1)显式传入trackingid。而不是直接调用call(String checkItem); 方案(2)既然使用mdc,为什么不去check下mdc里面实现是不是有值,如果有,也算传入了,而不是直接覆盖掉。
以上问题很容易出现在第三方库的调用上,且如果不看代码,很难预知会出现什么清空或一直绑定某个。不管哪种情况,都要意识到所以使用mdc不是完美的,因为很多第三库的调用对于你而言都是不透明且不可修改的。