服务配置
内存:2GB
cpu:双核
问题描述:
程序运行一段时间,大概一上午的时间,就会出现卡死,无响应的情况
问题排查
top
: 使用top
命令查看资源占用,发现我们的程序cpu占用竟然达到200%top -H -p 进程号
:查看该进程内哪些进程的cpu占用率比较高,发现占用率高的都是GC线程jstat -gcutil 进程号 2000 10
: 每两秒打印一次gc情况,打印10次,发现Full GC每两秒就会执行一次
执行Full GC时,会 STW (stop the world,停止全部活动),回收这么频繁,相当于程序一直处于停止服务的状态,所以出现一种卡死的现象
问题分析
频繁Full GC,百分之九十是有大对象产生,这个时候可以dump下来文件使用mat分析一下
jmap -dump:format=b,file=文件名.bin 进程号
从这里能看出来,有很多线程都在等待,其中我还看到有很多线程已经死掉,几百个线程每一个线程是一个用户,每一个用户产生的数据在当前线程内都比较大,所以那些死掉的线程内有很多大对象,死掉的线程多,所以频繁的回收,我通过展开线程属性,发现大都是查询服务,再联系对应的代码部分,发现查询服务都会有请求埋点,最后打印,打印直接用的System.out.println
,我查看了System.out.println
源码,发现竟然是串行的,由此可以断定,是由它引起的,改成log打印就好了。
private void newLine() {
try {
synchronized (this) {
ensureOpen();
textOut.newLine();
textOut.flushBuffer();
charOut.flushBuffer();
if (autoFlush)
out.flush();
}
}
catch (InterruptedIOException x) {
Thread.currentThread().interrupt();
}
catch (IOException x) {
trouble = true;
}
}
修改前:
System.out.println("这里是日志输出");
修改后,使用类似SLF4J这种日志框架进行日志输出
log.info("日志内容")
多个用户都来访问系统,打印日志时还是串行去执行的,人一旦多,排队就多,时间长了,线程挂掉,累积一会儿,大对象得不到释放,频繁Full GC,一直处于 STW 的状态,程序卡死