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"