调试Java程序持续占cpu问题

1、先用top查看占用cpu的进程id: 20232 114.4%
$ top
top - 09:51:59 up 656 days, 28 min, 3 users, load average: 1.47, 1.56, 1.56
Tasks: 137 total, 1 running, 136 sleeping, 0 stopped, 0 zombie
Cpu(s): 22.8%us, 30.8%sy, 0.0%ni, 45.7%id, 0.3%wa, 0.2%hi, 0.2%si, 0.0%st
Mem: 16331116k total, 12178884k used, 4152232k free, 322252k buffers
Swap: 0k total, 0k used, 0k free, 5134368k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
20232 admin 20 0 3576m 1.1g 14m S 114.4 6.9 883:55.78 java
27380 root 10 -10 129m 18m 5968 S 0.7 0.1 618:38.25 AliYunDun
875 root 20 0 2443m 62m 3416 S 0.3 0.4 15582:24 java
13589 admin 20 0 2825m 1.2g 6496 S 0.3 7.6 457:48.99 java
25834 admin 20 0 1039m 127m 5680 S 0.3 0.8 482:15.84 node /opt/web/d
1 root 20 0 19232 1344 1060 S 0.0 0.0 0:38.92 init

2、再用ps -ef | grep PID定位具体的进程主体；
$ ps -ef|grep activemq
admin 1123 20302 0 09:52 pts/1 00:00:00 grep activemq
admin 20232 1 90 Apr01 pts/0 14:44:25 /opt/jdk1.7.0_71/bin/java -Xms1G -Xmx2G -Djava.util.logging.config.file=logging.properties -Djava.security.auth.login.config=/opt/activemq-5.10.0/conf/login.config -Dcom.sun.management.jmxremote -Djava.awt.headless=true -Djava.io.tmpdir=/opt/activemq-5.10.0/tmp -Dactivemq.classpath=/opt/activemq-5.10.0/conf; -Dactivemq.home=/opt/activemq-5.10.0 -Dactivemq.base=/opt/activemq-5.10.0 -Dactivemq.conf=/opt/activemq-5.10.0/conf -Dactivemq.data=/opt/activemq-5.10.0/data -jar /opt/activemq-5.10.0/bin/activemq.jar start

3、用ps -mp pid -o THREAD,tid,time打印出该进程下的线程占用cpu情况: ps -mp 20232 -o THREAD,tid,time
找到了耗时最高的线程20326，占用CPU时间6个小时了！
$ ps -mp 20232 -o THREAD,tid,time
USER %CPU PRI SCNT WCHAN USER SYSTEM TID TIME
admin 90.5 - - - - - - 14:53:21
admin 40.4 19 - - - - 20326 06:38:38
admin 0.0 19 - futex_ - - 20328 00:00:03
admin 10.6 19 - futex_ - - 1204 00:00:22
admin 0.0 19 - futex_ - - 1208 00:00:00
admin 12.4 19 - futex_ - - 1209 00:00:25
admin 11.7 19 - futex_ - - 1242 00:00:11
admin 0.0 19 - futex_ - - 1252 00:00:00
admin 13.0 19 - futex_ - - 1258 00:00:04
admin 16.4 19 - futex_ - - 1259 00:00:05
admin 0.0 19 - futex_ - - 1287 00:00:00

4、其次将需要的线程ID转换为16进制格式：printf "%x\n" tid
$ printf "%x\n" 20326
4f66

5、最后打印线程的堆栈信息：jstack pid | grep tid -A 30
找到出现问题的代码，并分析具体函数中是否有可能出现死循环的代码段。
通常问题出现在while， for之类的循环代码片段。
$ whereis jstack
jstack: /opt/jdk1.7.0_71/bin/jstack
$ /opt/jdk1.7.0_71/bin/jstack 20232 | grep 4f66 -A 30
"Selector Worker: 0" daemon prio=10 tid=0x00007f84745c5800 nid=0x4f66 runnable [0x00007f845c57e000]
java.lang.Thread.State: RUNNABLE
at sun.misc.Unsafe.unpark(Native Method)
at java.util.concurrent.locks.LockSupport.unpark(LockSupport.java:152)
at java.util.concurrent.SynchronousQueue$TransferStack$SNode.tryMatch(SynchronousQueue.java:263)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:380)
at java.util.concurrent.SynchronousQueue.offer(SynchronousQueue.java:914)
at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1364)
at org.apache.activemq.transport.nio.SelectorWorker.run(SelectorWorker.java:116)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)

"qtp2033591567-3539 Acceptor0 SelectChannelConnector@0.0.0.0:8161" prio=10 tid=0x00007f8474beb000 nid=0x4f3b runnable [0x00007f845d089000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:241)
- locked <0x000000079175fbf8> (a java.lang.Object)
at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:109)
at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
at java.lang.Thread.run(Thread.java:745)

"qtp2033591567-3538 Selector0" prio=10 tid=0x00007f84746cb800 nid=0x4f3a runnable [0x00007f845d18a000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
- locked <0x000000079175ffb0> (a sun.nio.ch.Util$2)

 

 

$ /opt/jdk1.7.0_71/bin/jstack -F 32215 | grep 7dd7 -A 30
jstack command not found on centos
# sudo updatedb
# locate jstack
/usr/java/jdk1.7.0_79/bin/jstack
/usr/java/jdk1.7.0_79/man/ja_JP.UTF-8/man1/jstack.1
/usr/java/jdk1.7.0_79/man/man1/jstack.1