实战分析:原生工具

1、找到最耗CPU的进程

 命令:top –c,显示进程运行信息列表。实例:top -c。交互1:按1,数字1,显示多核CPU信息。交互2:键入P (大写p),进程按照CPU使用率排序。如下图所示结果,已经在交互过程中按了数字1及大写P。CPU百分百排查

可以看到红框标处,测试机器的双核CPU使用率都已经快达到100%。

而第一个进程PID是17376的就是我们要找的罪魁祸首了;可以看到进程最后一列,COMMAND注释的进程名:“java -jar spring-boot-hello-1.0.jar”。

2、找到最耗CPU的线程

 命令:top -H -p 【PID】,显示一个进程的线程运行信息列表。实例:top -Hp 17376 ,如下图所示,可以看到多个高耗CPU使用率的线程。CPU百分百排查

3、转换线程PID为16进制

 命令:printf “%x\n” 【线程pid】,转换多个线程数字为十六进制,第4步使用时前面加0x。实例:printf '%x\n' 17378 17379 17412 17426,得到结果43e2、43e3、4404、4412;如下图所示:CPU百分百排查

4、查看堆栈,定位线程

 命令:jstack 【进程PID】| grep 【线程转换后十六进制】-A10 , 使用jstack获取进程PID堆栈,利用grep定位线程id,打印后续10行信息。实例:jstack 17376 | grep '0x43e2' -A10 ,如下图所示:CPU百分百排查

看上图中的“GC task thread#0 (ParallelGC)”,代表垃圾回收线程,该线程会负责进行垃圾回收。为什么会有两个线程一直在进行垃圾回收,并且占用那么高的CPU使用率呢?

5、存储堆栈,批量查看

第4步也可以换个方法查看,可以先将jstack堆栈信息存储起来。 命令:jstack 【进程PID】> 【文件】 实例:jstack 17376 > yao.dump,存储17376进程的堆栈信息。再使用cat + grep查找看看后面几个高CPU线程的堆栈信息。实例:cat -n yao.dump | grep -A10 '0x4404',如下CPU百分百排查图所示:

可以看到线程0x4404【线程17426】产生堆栈信息,直指方法whileTrue。

6、GC查看

在第3步时我们看到CPU占用率最高的并不是0x4404,而是0x43e2、0x43e3。但是并没法看到其中是什么类与方法,只有一条GC信息。是不是死循环导致了GC太频繁,导致CPU使用率居高不下呢?我们使用jstat看下jvm的GC信息看看。 命令:jstat -gcutil 【进程PID】【毫秒】【打印次数】 实例:jstat -gcutil 17376 2000 5,查看17376进程的GC信息,每2秒打印一次,共打印5次,如下图所示:CPU百分百排查可以看到Full GC的次数高达506次,Full GC的持续时间很长,平均每次Full GC耗时达到9秒(4766/506,即GCT/FGC)。确实验证了我们之前的想法,再返回第4或第5步查看其他几个高CPU占用率线程,找到非GC信息的堆栈,查看具体的代码。

相关文章: