现象:一个平时运行2小时的任务,突然一天还没跑完,看系统cpu、load都不算高,接口监控发现rt从平时几ms到几十ms增加到了几千ms。
起初怀疑线程被阻塞了,然后top -p -H查看线程,返现有一个运行时间远远大于其他线程,jstack 查找发现是cmsgc 线程。 于是jstat -gcutil ,吓了一跳 eden、old全都是100%, fullgc 几千次了。。。。
于是考虑jmap -dump:file=dump pid , 打算查找未释放的对象,但是应用内存4g多,不是我的小本能分析的了得。。 上火。
于是考虑重启应用,在内存占用还不是太高时dump出来进行分析。 在内存占用大约1.5g的时候,dump了一次,拖到本机(压缩一下,压缩率达到80%,网速不好时可以节省很多时间),mat分析一通,发现一个应用对象量格外大,那基本上跑不掉了。。
上btrace 跟踪在哪里产生的对象:
package com.sun.btrace.samples;
import static com.sun.btrace.BTraceUtils.exit;
import static com.sun.btrace.BTraceUtils.jstack;
import static com.sun.btrace.BTraceUtils.println;
import com.sun.btrace.annotations.BTrace;
import com.sun.btrace.annotations.OnMethod;
@BTrace
public class MethodStackTrace {
private static int printCount = 0;
@OnMethod(clazz = "com.xxx.common.lang.diagnostic.Profiler", method = "/start/")
public static void func() {
if(printCount++ < 20){
println("=======stack======");
jstack();
println("########end#########");
}
else
exit(0);
}
}
一下就抓住了。。具体的就是业务代码的使用逻辑问题了。
另外, 当dump文件太大不好分析时,只是为了查看对象情况,可以直接使用 sudo -u admin jmap -histo:live `pgrep java` , 就能够按照内存占用量进行输出:
num #instances #bytes class name
----------------------------------------------
1: 263195 28174696 [C
2: 246862 25246080 [B
3: 144815 22059552 <constMethodKlass>
还有个加强版的工具TBMap,可以按内存分区输出对象占用量:
Object Histogram:
#num #all instances/bytes #eden instances/bytes #survivor instances/bytes #old instances/bytes #perm instances/bytes #Class description
-----------------------------------------------------------------------------------
1: 1459670/664283552 765458/85719080 75663/99027992 582912/476992632 35637/2543848 char[]
2: 325529/44662232 303670/27425504 13/136664 3773/14967256 18073/2132808 byte[]
3: 1301337/41642784 537975/17215200 75898/2428736 651827/20858464 35637/1140384 java.lang.String
4: 101777/39235776 80265/4929544 8/28572496 7283/4950376 14221/783360 int[]
5: 601661/24910032 204358/6248200 63154/3887328 334149/14774504 0/0 java.lang.Object[]
6: 141225/21381376 0/0 0/0 0/0 141225/21381376 * ConstMethodKlass