生产环境下JAVA进程高CPU占用故障排查

时间:2024-01-11 23:24:32

问题描述:
生产环境下的某台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已经安静下来了。

============================================

我们使用jdk自带的jstack来分析。当linux出现cpu被java程序消耗过高时,以下过程说不定可以帮上你的忙:

1.top查找出哪个进程消耗的cpu高 
21125 co_ad2    18   0 1817m 776m 9712 S  3.3  4.9  12:03.24 java                                                                                           
5284 co_ad     21   0 3028m 2.5g 9432 S  1.0 16.3   6629:44 java                                                                                           
21994 mysql     15   0  449m  88m 5072 S  1.0  0.6  67582:38 mysqld                                                                                         
8657 co_sparr  19   0 2678m 892m 9220 S  0.3  5.7 103:06.13 java

这里我们分析21125这个java进程。

2.top中shift+h查找出哪个线程消耗的cpu高 
先输入top -p 21125,然后再按shift+h。这里意思为只查看21125的进程,并且显示线程。 
21233 co_ad2    15   0 1807m 630m 9492 S  1.3  4.0   0:05.12 java                                                                                           
20503 co_ad2_s  15   0 1360m 560m 9176 S  0.3  3.6   0:46.72 java                                                                                           
21134 co_ad2    15   0 1807m 630m 9492 S  0.3  4.0   0:00.72 java                                                                                           
22673 co_ad2    15   0 1807m 630m 9492 S  0.3  4.0   0:03.12 java

这里我们分析21233这个线程,并且注意的是,这个线程是属于21125这个进程的。

3.jstack查找这个线程的信息 
jstack [进程]|grep -A 10 [线程的16进制] 
即:

  1. jstack 21125|grep -A 10 52f1

-A 10表示查找到所在行的后10行。21233用计算器转换为16进制52f1,注意字母是小写。 
结果:

  1. "http-8081-11" daemon prio=10 tid=0x00002aab049a1800 nid=0x52f1 in Object.wait() [0x0000000042c75000]
  2. java.lang.Thread.State: WAITING (on object monitor)
  3. at java.lang.Object.wait(Native Method)
  4. at java.lang.Object.wait(Object.java:485)
  5. at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:416)

说不定可以一下子定位到出问题的代码。