一个比较明显的OOM的排查过程

淘江湖由于之前遇到过因爬虫导致对用户中心的访问飚高而险些发生问题的情况，所以在其最近的一个项目中升级TDDL到2.4.4版本，以使用tddl的流控功能。但是在一次压测6个小时后产生了OOM异常。用晓锋的TProfiler分析结果是：

num #instances #bytes class name

1: 880137 104619672 char[]
914733 21953592 | +–java.lang.String
774175 37160400 | | +–com.**Profiler$Entry
790764 31074808 | | | +–java.lang.Object[]
781966 18767184 | | | | |–java.util.ArrayList
…
790764 31074808 | | +–java.lang.Object[]
781966 18767184 | | | +–java.util.ArrayList
774175 37160400 | | | | |–com.**Profiler$Entry
…

直接用jmap -histo查看结果是：

num #instances #bytes class name

1: 4542494 544227352 [C
2: 4429530 212617440 com.**Profiler$Entry
3: 4451761 165336648 [Ljava.lang.Object;
4: 4577468 109859232 java.lang.String
5: 4439023 106536552 java.util.ArrayList
6: 18058 24432336 [I
…

初步认为是com.**.Profiler没有release造成的问题，但是业务方的代码只有两行调用了Profiler，
包括其引用的jar包的代码中也没有发现忘记release的地方。
再用Mat分析过dump文件，一个线程引用了490多M的对象，Profiler$Entry本身占了92M的内存，但是占用了480M空间，
因此确定无疑是Profiler没有release造成的，所以写了一个BTrace脚本跟踪Profiler的enter和release调用，结果如下
com.taobao.matrix.center.interceptor.ProfilerInterceptor.invoke(ProfilerInterceptor.java:14) = 1541000 enter
com.alibaba.webx.filter.timer.TimerFilter.doFilter(TimerFilter.java:97) = 1 enter
com.taobao.matrix.center.interceptor.ProfilerInterceptor.invoke(ProfilerInterceptor.java:17) = 1541000 release

询问淘江湖的压测方法，是发了一个http请求后触发服务端开启线程池压测，直到压测完http请求才返回。因此在整个过程中
com..filter..XXFilter.doFilter(XXFilter.java:97) 调用Profiler.enter之后都没有立即释放。
com.**.Profiler使用ThreadLocal保存跟踪信息的，多线程情况下本来也不会有问题，
但碰巧线程池用的reject策略是Caller Run，而其并发量非常大，这样每次caller run时进入的entry都不会释放，直到最后OOM

修改压测代码，让http请求立即返回后服务端再开始压测，问题解决

本文来源于"阿里中间件团队播客",原文发表时间"  2011-03-08"