1.1 找到问题原因
问题起因是我们收到了jdos的容器CPU告警,CPU使用率已经达到104%
观察该机器日志发现,此时有很多线程在执行跑批任务。正常来说,跑批任务是低CPU高内存型,所以此时考虑是FullGC引起的大量CPU占用(之前有类似情况,告知用户后重启应用后解决问题)。
通过泰山查看该机器内存使用情况:
可以看到CPU确实使用率偏高,但是内存使用率并不高,只有62%,属于正常范围内。
到这里其实就有点迷惑了,按道理来说此时内存应该已经打满才对。
后面根据其他指标,例如流量的突然进入也怀疑过是jsf接口被突然大量调用导致的cpu占满,所以内存使用率不高,不过后面都慢慢排除了。其实在这里就有点一筹莫展了,现象与猜测不符,只有CPU增长而没有内存增长,那么什么原因会导致单方面CPU增长?然后又朝这个方向排查了半天也都被否定了。
后面突然意识到,会不会是监控有“问题”?
换句话说应该是我们看到的监控有问题,这里的监控是机器的监控,而不是JVM的监控!
JVM的使用的CPU是在机器上能体现出来的,而JVM的堆内存高额使用之后在机器上体现的并不是很明显。
遂去sgm查看对应节点的jvm相关情况:
可以看到我们的堆内存老年代确实有过被打满然后又清理后的情况,查看此时的CPU使用情况也可以与GC时间对应上。
那么此时可以确定,是Full GC引起的问题。
1.2 找到FULL GC的原因
我们首先dump出了gc前后的堆内存快照,
然后使用JPofiler进行内存分析。(JProfiler是一款堆内存分析工具,可以直接连接线上jvm实时查看相关信息,也可以分析dump出来的堆内存快照,对某一时刻的堆内存情况进行分析)
首先将我们dump出来的文件解压,修改后缀名.bin,然后打开即可。(我们使用行云上自带的dump小工具,也可以自己去机器上通过命令手工dump文件)
首先选择Biggest Objects,查看当时堆内存中最大的几个对象。
从图中可以看出,四个List对象就占据了近900MB的内存,而我们刚刚看到堆内存最大也只有1.3GB,因此再加上其他的对象,很容易就会把老年代占满引发full gc的问题。
选择其中一个最大的对象作为我们要查看的对象
这个时候我们已经可以定位到对应的大内存对象对应的位置:
其实至此我们已经能够大概定位出问题所在,如果还是不确定的话,可以查看具体的对象信息,方法如下:
可以看到我们的大List对象,其实内部是很多个Map对象,而每个Map对象中又有很多键值对。
在这里也可以看到Map中的相关属性信息。
也可以在以下界面直接看到相关信息:
然后一路点下去就可以看到对应的属性。
至此,我们理论上已经找到了大对象在代码中的位置。