在《大话高可用》里,之前的老大有过总结,高可用就是:别人死我们不死,自己不作死,不被别人搞死。

这段时间,网上都在传Log4j2的lookup远程执行代码漏洞。这个漏洞要想造成危害,基本都是被别人搞死的。因为只有url链接或者页面输入了可执行脚本才会触发。

最近在重构《简明日志规范》,就是重构我自己之前开源的一个统一日志的组件。对org.slf4j.MDC不放心,怕引发内存泄露等线上长时间运行才产生的问题。要是有这个问题,比Log4j2的漏洞更不可原谅。因为这纯属自己作死。所以做了一个小研究。


MDC(Mapped Diagnostic Context,映射调试上下文)是日志系统提供的一种方便在多线程条件下记录日志的功能。可以理解为一个存储容器,原理是将信息存储在了ThreadLocal里。ThreadLocal和线程绑定。程序里用的都是线程池,理论上应该不会出现无限膨胀的情况。总归还是不放心。


利用周末时间进行了源码研究和测试,终于放心了。


验证


首先读了源码,从MDC跟到ThreadLocal,反复的找,没有找到存储ThreadLocal相关信息的容器。因为要是有,且释放做的不好的话是会无限膨胀的。先进行了粗浅的理论研究之后。测试验证一下。


验证代码如下,实际上MDC.put的内容我放了1万字,便于确认效果。

public static void main(String[] args) {
ThreadPoolExecutor threadPoolExecutor = new ThreadPoolExecutor(2, 200, 1, TimeUnit.DAYS, new LinkedTransferQueue<>());
for (long i = 0; i < Long.MAX_VALUE; i++) {
threadPoolExecutor.submit(new Runnable() {
@Override
public void run() {
try {
MDC.put("k", Thread.currentThread().getName());
Thread.sleep(100);
} catch (Exception e) {
e.printStackTrace();
}

}
});
}
}


场景1

将最大线程数调到1W,内存增长根本停不下来,我的电脑明显心有余力不足,没有达到效果。《Java线程池总结》有对线程池参数的讲解,这里不赘述。


场景2

核心线程池数10,最大线程数20,在线程执行代码的结尾增加MDC.clear()。因为大多数的最佳实践是结束时都要加,避免线程复用造成的取出数据不准确。日志不准确是个问题,但是没有内存泄露这么可怕。这里加和不加做对比,验证如果忘记加会不会对内存造成压力。

结果运行的进程占2095.1M时达到稳定。

ThreadLocal&MDC内存泄漏问题_i++


场景3

上面场景中去掉MDC.clear()。

结果运行的进程占2045.8M时达到稳定。

ThreadLocal&MDC内存泄漏问题_内存泄露_02


场景4

核心线程池数1,最大线程数2,在线程执行代码的结尾增加MDC.clear()。

结果运行的进程占2116.7M时达到稳定。

ThreadLocal&MDC内存泄漏问题_i++_03


场景5

上面场景中去掉MDC.clear()。

结果运行的进程占2109.3M时达到稳定。

ThreadLocal&MDC内存泄漏问题_内存泄露_04


场景6

上面场景中修改核心线程池数2,最大线程数4。

结果运行的进程占2120.7M时达到稳定。

ThreadLocal&MDC内存泄漏问题_内存泄露_05


试验结论

无论是否执行MDC.clear()。最终内存占用都会趋于稳定,无内存泄露。


理论分析


虽然验证了,还是不放心。为什么呢?做了这么久的面试官,我深知ThreadLocal内存漏洞问题是一道经典面试题啊。

ThreadLocal&MDC内存泄漏问题_内存泄露_06

MDC是基于ThreadLocal做的,ThreadLocal泄露了,MDC可以幸免吗?测试没有泄露是不是测试姿势不对?


为了知其然而知其所以然,从ThreadLocal内存泄露的具体案例出发,更加仔细的研究了源码。


ThreadLocal内存泄露问题

下面这段测试代码在循环中会出现膨胀,循环过多会导致内存泄露。
public void test() throws Exception {
for (int i = 0; i < 100; i++) {
ThreadLocal threadLocal = new ThreadLocal();
threadLocal.set("t1"+i);
Thread t = Thread.currentThread();
log.info(t);
}
}


原因从debug现象来看,随着循环数i的增长,t也就是当前线程的threadLocals数随之增长。

ThreadLocal&MDC内存泄漏问题_i++_07


跟踪threadLocal.set("t1"+i)代码到set方法的源码:

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


解释一下:
1>threadLocal获取到当前线程,获取当前线程的ThreadLocalMap对象。

2>如果map存在,则将当前threadLocal对象作为key设置value="t1"+i

3>如果map不存在,则新建一个map,并将当前threadLocal对象作为key设置value="t1"+i。



就是说一个线程唯一对应一个ThreadLocalMap对象。threadLocal对象是ThreadLocalMap这个map中的一个key。将上面的test测试类用伪代码调整成正常的顺序大家应该就能理解了:
public void test() throws Exception {
Thread t = Thread.currentThread();
ThreadLocalMap map = getMap(t);
for (int i = 0; i < 100; i++) {
ThreadLocal threadLocal = new ThreadLocal();
map.set(threadLocal,"t1"+i);
log.info(t);
}
}

所以threadLocal 的引用一直在当前线程的ThreadLocalMap手里,并不是循环下一个这个引用就不可达了。所以会一直创建新的保存老的,直到内存溢出,如下面运行截图:

ThreadLocal&MDC内存泄漏问题_i++_08


简而言之: threadLocal使用不当,可能会内存泄露。


MDC为什么无内存泄露问题


跟MDC.put("k", Thread.currentThread().getName())到源码发现其实put的真正承载容器是static MDCAdapter mdcAdapter。这是一个静态类,在MDC类源码的底部有mdcAdapter的初始化过程static静态块,表明了整个JVM只有一份。


MDCAdapter 是一个接口,具体的实现因为这是slf4j门面中的。实现会有所不同,但logback等主流日志实现都是new一个ThreadLocal,将Map容器绑定到ThreadLocal中。代码片段感受一下:

public class LogbackMDCAdapter implements MDCAdapter {
final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal();
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);
}

}
}


简而言之:一个线程顶多会创建一个ThreadLocal,所以不会内存泄露。


总结

1、不要假定,要证明。证明之后要理解,逻辑自洽。

2、别人死我们不死,自己不作死,不被别人搞死。