JAVA进程高CPU占用故障排查

时间:2022-07-30 20:31:52
问题描述:
生产环境下的某台tomcat7服务器,在刚发布时的时候一切都很正常,在运行一段时间后就出现CPU占用很高的问题,基本上是负载一天比一天高。

问题分析:
1,程序属于CPU密集型,和开发沟通过,排除此类情况。
2,程序代码有问题,出现死循环,可能性极大。

问题解决:
1,开发那边无法排查代码某个模块有问题,从日志上也无法分析得出。
2,记得原来通过strace跟踪的方法解决了一台PHP服务器CPU占用高的问题,但是通过这种方法无效,经过google搜索,发现可以通过下面的方法进行解决,那就尝试下吧。

解决过程:
1,根据top命令,发现PID为2633的Java进程占用CPU高达300%,出现故障。

2,找到该进程后,如何定位具体线程或代码呢,首先显示线程列表,并按照CPU占用高的线程排序:
[root@localhost logs]# ps -mp 2633 -o THREAD,tid,time | sort -rn

显示结果如下:
USER     %CPU PRI SCNT WCHAN  USER SYSTEM   TID     TIME
root     10.5  19    - -         -      -  3626 00:12:48
root     10.1  19    - -         -      -  3593 00:12:16

找到了耗时最高的线程3626,占用CPU时间有12分钟了!

将需要的线程ID转换为16进制格式:
[root@localhost logs]# printf "%x\n" 3626
e18

最后打印线程的堆栈信息:
[root@localhost logs]# jstack 2633 |grep e18 -A 30


将输出的信息发给开发部进行确认,这样就能找出有问题的代码。

通过最近几天的监控,CPU已经安静下来了。



使用 jstack [pid]  > xx.log 命令打印进程信息

#jstack 16511 > 1.log

#jstack 16511 > 2.log

#jstack 16511 > 3.log

 

3、打开日志文件,找到两个线程信息,如下

"Thread-77" prio=10 tid=0x00007f58d4041800 nid=0x4ceb runnable [0x00007f58d175f000]
   java.lang.Thread.State: RUNNABLE
 at com.huawei.iiss.upadapter.common.oprindex.thread.OprUserIndexThread.run(OprUserIndexThread.java:61)
 at java.lang.Thread.run(Thread.java:662)

"Thread-76" prio=10 tid=0x00007f58d4a43800 nid=0x4cea runnable [0x00007f58bd066000]
   java.lang.Thread.State: RUNNABLE
 at com.huawei.iiss.upadapter.common.oprlog.thread.SaveOprLogThread.run(SaveOprLogThread.java:80)
 at java.lang.Thread.run(Thread.java:662)

 

找到以上红色信息,已经定位到JAVA具体代码,产看代码,发现死循环。。。速度改之

 

附:TOP命令中需要关注的值:
(1)load average:此值反映了任务队列的平均长度;如果此值超过了CPU数量,则表示当前CPU数量不足以处理任务,负载过高
(2)%us:用户CPU时间百分比;如果此值过高,可能是代码中存在死循环、或是频繁GC等
(3)%sy:系统CPU时间百分比;如果此值过高,可能是系统线程竞争激烈,上下文切换过多,应当减少线程数
(4)%wa:等待输入、输出CPU时间百分比;如果此值过高,说明系统IO速度过慢,CPU大部分时间都在等待IO完成
(5)%hi:硬件中断CPU百分比;当硬件中断发生时,CPU会优先去处理硬件中断;比如,网卡接收数据会产生硬件中断
(6)swap used:被使用的swap;此值过高代表系统因为内存不足在进行频繁的换入、换出操作,这样会影响效率,应增大内存量
(7)%CPU:进程使用CPU的百分比;此值高表示CPU在进行无阻塞运算等