进程占用cpu过高分析总结

cpu排查过程记录

1. 使用top命令获取占用CPU最高的进程号

top
top - 10:21:31 up 783 days, 23:45,  1 user,  load average: 157.74, 144.77, 125.50
Tasks: 833 total,   5 running, 828 sleeping,   0 stopped,   0 zombie
Cpu(s): 48.5%us, 49.8%sy,  0.0%ni,  1.1%id,  0.0%wa,  0.0%hi,  0.6%si,  0.0%st
Mem:  132124464k total, 60951572k used, 71172892k free,    49348k buffers
Swap: 32767992k total,     1260k used, 32766732k free, 17250188k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                             
63080 sms_pt    20   0 56.8g  14g  11m S 3030.6 11.2   7335:30 java                                                                                                               
34482 sms_pt    20   0 56.4g 6.0g  11m S 743.1  4.8 509:42.39 java                                                                                                                
54999 sms_pt    20   0 57.1g  14g  11m S 724.1 11.9   5422:52 java     

可以看到进程号63080的进程占用CPU瞬时值达到3000多。

2. 根据进程号查看线程信息

ps -o THREAD,tid.time -mp $PID
#输出的内容比较多，不一一列出，可以根据自己的需要进行排序
#可以按照自己的需求进行排序
#命令如下：
# ps -o THREAD,tid.time -mp $PID|sort -nk $列数
#为了能获取完整结果，建议重定向

我把CPU的占用时间进行排序，截取一部分内容显示

sms_pt    1.3  19    - poll_s    -      - 36638 00:10:36
sms_pt    1.3  19    - poll_s    -      - 36720 00:10:31
sms_pt    1.3  19    - poll_s    -      - 36861 00:10:32
sms_pt    1.3  19    - poll_s    -      - 36907 00:10:38
sms_pt    1.3  19    - poll_s    -      - 36995 00:10:28
sms_pt    1.3  19    - poll_s    -      - 37020 00:10:38
sms_pt    1.3  19    - poll_s    -      - 37087 00:10:30
sms_pt    1.3  19    - poll_s    -      - 37136 00:10:32
sms_pt    1.3  19    - poll_s    -      - 37142 00:10:32
sms_pt    1.3  19    - poll_s    -      - 37368 00:10:29
sms_pt    1.4  19    - poll_s    -      - 55366 00:14:12
sms_pt    1.5  19    - poll_s    -      - 56871 00:14:36
sms_pt    1.6  19    - ep_pol    -      - 54976 00:16:00
sms_pt    2.6  19    - ep_pol    -      - 55221 00:25:22
sms_pt    2.6  19    - ep_pol    -      - 55222 00:25:23
sms_pt    3.0  19    - -         -      - 36818 00:24:39
sms_pt    3.0  19    - poll_s    -      - 37148 00:24:29
USER     %CPU PRI SCNT WCHAN  USER SYSTEM   TID     TIME
sms_pt   11.5  19    - -         -      - 55223 01:52:28
sms_pt    798   -    - -         -      -     - 5-09:38:31

3 查看堆栈信息

#堆栈信息重定向到文件
jstack $PID >> $file_name
#在堆栈信息里面tid（线程号）是用16进制显示，先将线程号转为16进制
$ printf "%x\n" 37148
911c
$ grep "911c" -A20 $filename
"http-nio-20002-exec-714" daemon prio=10 tid=0x00007f6250343800 nid=0x911c waiting on condition [0x00007f5e02221000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x0000000086a80be8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
        at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
        at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:86)
        at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:32)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:745)

给开发反馈之后，mq占用CPU资源比较多，已经在修改。

4. 根据自己的需要统计信息

统计线程的运行状态

# 这样会返回所有的状态
grep "java.lang.Thread.State:" $filename|awk '{print $2}'
#稍微改一下获取统计结果
$ grep "java.lang.Thread.State:" $filename|awk '{++s[$2]}END{for( a in s ) print s[a],a}'
7 WAITING
790 TIMED_WAITING
2 BLOCKED
299 RUNNABLE