记录一次频繁GC的排查

2022-02-08 本文已影响0人假鞋子

背景：
某天午后，线上环境突然出现GC预警，一分钟达到30+次。

young gc

随着时间，老年代占用空间逐步提升.

老年代占用%

且在达到full gc后并未清理多少。（期间）

image.png

第一反应：保留现场

1:dump内存---jmap -dump:[live,]format=b,file=
由于老年代无法通过full gc回收，需加入[:live]参数，只打印活跃对象，缩小dump文件大小，方便排查和下载。

2:下载gc日志，线程栈
docker容器可联系运维人员
手动下载gc日志需要在jvm配置路径和日志格式
手动下载线程栈-----jstack pid > log.txt

3:通过arthas生成cpu热力图，并下载---profiler start---profiler stop

4:重启应用或将容器节点的权重调整为0，避免影响用户体验。

步骤一:
查看内存中的活跃对象---jmap -histo:live pid，（也可以导出，避免dump文件太大下载太慢，其中不加live参数会打印所有堆内存中的对象）

线程+猜测：
发现一个类存在大量实例。即可定位是该类引起的内存溢出。

步骤二：
查看CPU，发现CPU迅速飙高，且维持在25%，一段时间后飙升至50%，且维持。

cpu曲线

猜测：
由于系统可视为4核节点，猜测是某个线程死循环引起的内存泄漏。随着请求增加不停的有线程进入死循环。

步骤三：
查看多次保留的线程栈，发现大部分线程不是等待就是运行中但最后的执行方法也是readBytes、epoll等，除了2个业务线程处于runable，切最后执行方法是一样的业务方法。因为cpu执行很快如果两次均在某一点上，说明这一点的耗时是很大的

猜测：
猜测就是该段代码引起的死循环。
也可以找到所有runable方法，查看是否有上述步骤一产生的对象。来寻找问题代码。

步骤4:
既然是cpu问题，查看之前保留的热力图。发现问题代码段。

cpu火焰图

猜测：
更加确定是死循环问题。因为大量的cpu消耗在同一段代码身上。

至此已找到问题代码。通过分析发现频繁gc是死循环造成，且由于线程未释放，大量对象进入老年带，即使full gc也无法释放。