前几个月遇到过这样一个问题:一个业务进程的CPU占用率稳定在99.9x%到100%浮动(16核服务器,CPU满载为1600%),业务代码都是IO密集型的增删改查,没有太多占用CPU的操作,感觉不太正常。由于故障处理第一时间没有记录相关命令的执行结果,只能模拟一下执行相关命令的结果。问题调查过程如下:
1.执行top,按P按照cpu占用率排序,找到该进程,记录进程号pid
top - 21:40:45 up 71 days, 6:12, 4 users, load average: 0.27, 0.41, 0.48
Tasks: 295 total, 1 running, 294 sleeping, 0 stopped, 0 zombie
%Cpu(s): 2.7 us, 0.9 sy, 0.0 ni, 96.1 id, 0.0 wa, 0.0 hi, 0.3 si, 0.0 st
KiB Mem : 65713420 total, 31008160 free, 26820948 used, 7884312 buff/cache
KiB Swap: 0 total, 0 free, 0 used. 37552608 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
23140 www-data 20 0 5887912 1.682g 25108 S 99.9 2.7 9:47.99 java
28428 www-data 20 0 5813480 2.457g 24968 S 12.3 3.9 248:32.05 java
56649 www-data 20 0 5739432 2.153g 27568 S 5.0 3.4 80:09.12 java
30202 www-data 20 0 5824892 1.407g 24104 S 3.3 2.2 37:55.28 java
62716 www-data 20 0 5844888 1.574g 24292 S 3.0 2.5 9:22.16 java
63731 www-data 20 0 5820428 2.031g 24752 S 3.0 3.2 60:26.88 java
33209 www-data 20 0 5855216 1.556g 24580 S 2.0 2.5 11:42.94 java
54454 www-data 20 0 6100816 0.992g 18176 S 1.7 1.6 187:26.81 java
60647 www-data 20 0 5712880 1.924g 24884 S 1.7 3.1 27:21.18 java
假设执行结果如上,占用CPU的进程号为23140
2.执行 sudo -u www-data jstack 23140 > /home/yangyujian/tmp.jstack 打印该进程的jstack信息
3.执行 ps -mp 23140 -o THREAD,tid,time 打印进程23140的线程列表以及占用CPU的时间等信息,模拟执行结果如下
USER %CPU PRI SCNT WCHAN USER SYSTEM TID TIME
www-data 99.9 - - - - - - 01:10:17
www-data 0.0 19 - - - - 23140 00:00:00
www-data 99.9 19 - - - - 23142 01:10:17
www-data 0.0 19 - - - - 23143 00:00:01
www-data 0.0 19 - - - - 23144 00:00:01
www-data 0.0 19 - - - - 23145 00:00:01
www-data 0.0 19 - - - - 23146 00:00:01
www-data 0.0 19 - - - - 23147 00:00:01
www-data 0.0 19 - - - - 23148 00:00:01
可以看到占用CPU最高的线程id为23142
4.将线程id: 23142 转为16进制: 5a66,在jstack信息中寻找该线程id,即可找到堆栈信息。
最终发现是公司内部封装的RPC框架内一个失败重连的机制导致死循环,所以稳定占用一个核,联系框架维护者修复解决。