jstack应用-查找CPU飚高的原因
Posted
tags:
篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了jstack应用-查找CPU飚高的原因相关的知识，希望对你有一定的参考价值。
场景
在系统上线后，经常会遇到运维的同学跑过来说：“这次发版后，cpu线程使用率到一场，到100%了”。这时候不要慌，可以使用堆转储来分析到底是哪个线程引起的。
查找元凶
[[email protected]_mofei_01 test]# top
Mem: 16333644k total, 9472968k used, 6860676k free, 165616k buffers
Swap: 0k total, 0k used, 0k free, 6665292k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
17850 root 20 0 7588m 112m 11m S 100.7 0.7 47:53.80 java
1552 root 20 0 121m 13m 8524 S 0.7 0.1 14:37.75 AliYunDun
3581 root 20 0 9750m 2.0g 13m S 0.7 12.9 298:30.20 java
1 root 20 0 19360 1612 1308 S 0.0 0.0 0:00.81 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
3 root RT 0 0 0 0 S 0.0 0.0 0:00.14 migration/0 发现pid=17850的进程线程使用率100%，查询进程中哪个线程导致的问题
[[email protected]_mofei_01 test]# top -H -p 17850
top - 17:43:15 up 5 days, 7:31, 1 user, load average: 0.99, 0.97, 0.91
Tasks: 32 total, 1 running, 31 sleeping, 0 stopped, 0 zombie
Cpu(s): 3.7%us, 8.9%sy, 0.0%ni, 87.4%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 16333644k total, 9592504k used, 6741140k free, 165700k buffers
Swap: 0k total, 0k used, 0k free, 6781620k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
17880 root 20 0 7588m 112m 11m R 99.9 0.7 50:47.43 java
17856 root 20 0 7588m 112m 11m S 0.3 0.7 0:02.08 java
17850 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17851 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.23 java
17852 root 20 0 7588m 112m 11m S 0.0 0.7 0:02.09 java
17853 root 20 0 7588m 112m 11m S 0.0 0.7 0:02.12 java
17854 root 20 0 7588m 112m 11m S 0.0 0.7 0:02.07 java
17855 root 20 0 7588m 112m 11m S 0.0 0.7 0:02.06 java
17857 root 20 0 7588m 112m 11m S 0.0 0.7 0:02.07 java
17858 root 20 0 7588m 112m 11m S 0.0 0.7 0:02.08 java
17859 root 20 0 7588m 112m 11m S 0.0 0.7 0:02.04 java
17860 root 20 0 7588m 112m 11m S 0.0 0.7 0:02.05 java
17861 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17862 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17863 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17864 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.10 java
17865 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.12 java
17866 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.09 java
17867 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.12 java
17868 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17869 root 20 0 7588m 112m 11m S 0.0 0.7 0:01.04 java
17870 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17871 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17872 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17873 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17874 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17875 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17876 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17877 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17878 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17879 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
17946 root 20 0 7588m 112m 11m S 0.0 0.7 0:00.00 java
发现17880的线程导致cpu飚高。
通过jstack查看线程信息
[[email protected]_mofei_01 test]# printf "%x\n" 17880
45d8
[[email protected]_mofei_01 test]# jstack 17850|grep 45d8 -A 30
"pool-1-thread-11" #20 prio=5 os_prio=0 tid=0x00007fc860352800 nid=0x45d8 runnable [0x00007fc8417d2000]
java.lang.Thread.State: RUNNABLE
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:326)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
- locked <0x00000006c6c2e708> (a java.io.BufferedOutputStream)
at java.io.PrintStream.write(PrintStream.java:482)
- locked <0x00000006c6c10178> (a java.io.PrintStream)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
- locked <0x00000006c6c26620> (a java.io.OutputStreamWriter)
at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
at java.io.PrintStream.write(PrintStream.java:527)
- eliminated <0x00000006c6c10178> (a java.io.PrintStream)
at java.io.PrintStream.print(PrintStream.java:597)
at java.io.PrintStream.println(PrintStream.java:736)
- locked <0x00000006c6c10178> (a java.io.PrintStream)
at com.demo.guava.HardTask.call(HardTask.java:18)
at com.demo.guava.HardTask.call(HardTask.java:9)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-10" #19 prio=5 os_prio=0 tid=0x00007fc860345000 nid=0x45d7 waiting on condition [0x00007fc8418d3000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c6c14178> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)- 首先把pid 17880转成16进制
- 查询堆信息
- 发现HardTask（源码在末尾）第18行可能有问题
源码
public class HardTask implements Callable<String> {
@Override
public String call() throws Exception {
while(true){
int a=100;
int b=100;
int rs=a+b/100-b;
System.out.println(rs);
}
}
}
public class SimpleTask implements Callable<String> {
@Override
public String call() throws Exception {
Thread.sleep(300);
//什么都不做
return null;
}
}
public class CpuTest {
public static void main(String[] args){
ExecutorService executorService=Executors.newFixedThreadPool(11);
for (int i = 0; i < 10; i++) {
executorService.submit(new SimpleTask());
}
executorService.submit(new HardTask());
}
}源码很简单，就是创建了2种线程HardTask和SimpleTask。然后通过CpuTest进行启动。
以上是关于jstack应用-查找CPU飚高的原因的主要内容，如果未能解决你的问题，请参考以下文章