天天看点

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

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查看结果是:

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"