Java 程序 CPU 100% 排查

排查 Java 程序 CPU 100% 问题,三种方式:jvm工具、show-busy-java-threads脚本、Arthas

方式一:(不借助第三方工具排查方法)

1. 首先top查看cpu占用资源最高的java进程

1
2
# 查看top进程情况,拿到占用cpu最多的java进程pid
top

2. 通过上一步定位拿到的进程pid,继续查看进程下cpu占用率最高的线程编号

1
2
3
4

# 拿到进程下cpu占用率最高的线程编号(1094 为第一步拿到的进程pid)
top -Hp 1094

3. 将拿到的线程编号,转换为 16 进制

1
2
3
4
5
6

# 获取到的线程编号,转换为16进制(1103 为上一步获取到的线程编号)
printf "%x\n" 1103

# 拿到转换后的16进制值为:44f

4. 通过jstack定位信息

线程的几种状态说明:
NEW,未启动的。不会出现在Dump中。
RUNNABLE,在虚拟机内执行的。
BLOCKED,受阻塞并等待监视器锁。
WATING,无限期等待另一个线程执行特定操作。
TIMED_WATING,有时限的等待另一个线程的特定操作。
TERMINATED,已退出的。

1
2
3
4

# 拿到进程下cpu占用率最高的线程编号(1094 为第一步拿到的进程pid)
jstack 1094| grep 44f


方式二: 使用通过Agent方式连接java进程的第三方工具,如阿里的 Arthas,美团的java-debug-tool等,此处以Arthas为例

Arthas是通过Agent方式来连接运行的Java进程、主要通过交互式来完成功能,

Arthas重点帮助解决问题:
- 这个类从哪个 jar 包加载的?为什么会报各种类相关的 Exception?
- 我改的代码为什么没有执行到?难道是我没 commit?分支搞错了?
- 遇到问题无法在线上 debug,难道只能通过加日志再重新发布吗?
- 线上遇到某个用户的数据处理有问题,但线上同样无法 debug,线下无法重现!
- 是否有一个全局视角来查看系统的运行状况?
- 有什么办法可以监控到JVM的实时运行状态?
- 怎么快速定位应用的热点,生成火焰图?

[Arthas] (https://alibaba.github.io/arthas/quick-start.html “Arthas文档及下载地址”)

安装和启动Arthas

1
2
3
4
5
6
7
8
9

# 安装arthas
curl -O https://alibaba.github.io/arthas/arthas-boot.jar

# 启动
java -jar arthas-boot.jar
# [1]: 35542
# [2]: 71560 arthas-demo.jar

Demo进程是第2个,则输入2,再输入回车/enter。Arthas会attach到目标进程上,并输出日志:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

[INFO] Try to attach process 71560
[INFO] Attach process 71560 success.
[INFO] arthas-client connect 127.0.0.1 3658
,---. ,------. ,--------.,--. ,--. ,---. ,---.
/ O \ | .--. ''--. .--'| '--' | / O \ ' .-'
| .-. || '--'.' | | | .--. || .-. |`. `-.
| | | || |\ \ | | | | | || | | |.-' |
`--' `--'`--' '--' `--' `--' `--'`--' `--'`-----'

wiki: https://alibaba.github.io/arthas
version: 3.0.5.20181127201536
pid: 71560
time: 2018-11-28 19:16:24

查看dashboard

输入dashboard,按回车/enter,会展示当前进程的信息,按ctrl+c可以中断执行。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
ID     NAME                   GROUP          PRIORI STATE  %CPU    TIME   INTERRU DAEMON
17 pool-2-thread-1 system 5 WAITIN 67 0:0 false false
27 Timer-for-arthas-dashb system 10 RUNNAB 32 0:0 false true
11 AsyncAppender-Worker-a system 9 WAITIN 0 0:0 false true
9 Attach Listener system 9 RUNNAB 0 0:0 false true
3 Finalizer system 8 WAITIN 0 0:0 false true
2 Reference Handler system 10 WAITIN 0 0:0 false true
4 Signal Dispatcher system 9 RUNNAB 0 0:0 false true
26 as-command-execute-dae system 10 TIMED_ 0 0:0 false true
13 job-timeout system 9 TIMED_ 0 0:0 false true
1 main main 5 TIMED_ 0 0:0 false false
14 nioEventLoopGroup-2-1 system 10 RUNNAB 0 0:0 false false
18 nioEventLoopGroup-2-2 system 10 RUNNAB 0 0:0 false false
23 nioEventLoopGroup-2-3 system 10 RUNNAB 0 0:0 false false
15 nioEventLoopGroup-3-1 system 10 RUNNAB 0 0:0 false false
Memory used total max usage GC
heap 32M 155M 1820M 1.77% gc.ps_scavenge.count 4
ps_eden_space 14M 65M 672M 2.21% gc.ps_scavenge.time(m 166
ps_survivor_space 4M 5M 5M s)
ps_old_gen 12M 85M 1365M 0.91% gc.ps_marksweep.count 0
nonheap 20M 23M -1 gc.ps_marksweep.time( 0
code_cache 3M 5M 240M 1.32% ms)
Runtime
os.name Mac OS X
os.version 10.13.4
java.version 1.8.0_162
java.home /Library/Java/JavaVir
tualMachines/jdk1.8.0
_162.jdk/Contents/Hom
e/jre

通过thread命令来获取到arthas-demo进程的Main Class

thread 1会打印线程ID 1的栈,通常是main函数的线程。

1
2
3
4

$ thread 1 | grep 'main('
at demo.MathGame.main(MathGame.java:17)

通过jad来反编译Main Class

输入命令jad demo.MathGame,查看反编译class类

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78

ClassLoader:
+-sun.misc.Launcher$AppClassLoader@3d4eac69
+-sun.misc.Launcher$ExtClassLoader@66350f69

Location:
/tmp/arthas-demo.jar

/*
* Decompiled with CFR 0_132.
*/
package demo;

import java.io.PrintStream;
import java.util.ArrayList;
import java.util.Iterator;
import java.util.List;
import java.util.Random;
import java.util.concurrent.TimeUnit;

public class MathGame {
private static Random random = new Random();
private int illegalArgumentCount = 0;

public static void main(String[] args) throws InterruptedException {
MathGame game = new MathGame();
do {
game.run();
TimeUnit.SECONDS.sleep(1L);
} while (true);
}

public void run() throws InterruptedException {
try {
int number = random.nextInt();
List<Integer> primeFactors = this.primeFactors(number);
MathGame.print(number, primeFactors);
}
catch (Exception e) {
System.out.println(String.format("illegalArgumentCount:%3d, ", this.illegalArgumentCount) + e.getMessage());
}
}

public static void print(int number, List<Integer> primeFactors) {
StringBuffer sb = new StringBuffer("" + number + "=");
Iterator<Integer> iterator = primeFactors.iterator();
while (iterator.hasNext()) {
int factor = iterator.next();
sb.append(factor).append('*');
}
if (sb.charAt(sb.length() - 1) == '*') {
sb.deleteCharAt(sb.length() - 1);
}
System.out.println(sb);
}

public List<Integer> primeFactors(int number) {
if (number < 2) {
++this.illegalArgumentCount;
throw new IllegalArgumentException("number is: " + number + ", need >= 2");
}
ArrayList<Integer> result = new ArrayList<Integer>();
int i = 2;
while (i <= number) {
if (number % i == 0) {
result.add(i);
number /= i;
i = 2;
continue;
}
++i;
}
return result;
}
}

Affect(row-cnt:1) cost in 970 ms.

watch命令实时查看返回值

通过执行命令 watch demo.MathGame primeFactors returnObj

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30

Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 107 ms.
ts=2018-11-28 19:22:30; [cost=1.715367ms] result=null
ts=2018-11-28 19:22:31; [cost=0.185203ms] result=null
ts=2018-11-28 19:22:32; [cost=19.012416ms] result=@ArrayList[
@Integer[5],
@Integer[47],
@Integer[2675531],
]
ts=2018-11-28 19:22:33; [cost=0.311395ms] result=@ArrayList[
@Integer[2],
@Integer[5],
@Integer[317],
@Integer[503],
@Integer[887],
]
ts=2018-11-28 19:22:34; [cost=10.136007ms] result=@ArrayList[
@Integer[2],
@Integer[2],
@Integer[3],
@Integer[3],
@Integer[31],
@Integer[717593],
]
ts=2018-11-28 19:22:35; [cost=29.969732ms] result=@ArrayList[
@Integer[5],
@Integer[29],
@Integer[7651739],
]

方式三: 基于show-busy-java-threads脚本方式 (推荐)

由于方式一操作繁琐耗时,通过show-busy-java-threads脚本可快速消耗cpu高的线程,及打印出其线程栈。

脚本方式对应 Arthas 等工具优势,如:
可以在进程不能启动的情况下完成诊断(如依赖中的重复类分析、ClassPath上的资源或类查找)
开销少;简单少依赖(就纯文本的一个脚本文件)
方便与(已有的)工具(如awk、sed、cron)、流程或设施集成,进一步编程/自动化

[show-busy-java-threads] (https://github.com/oldratlee/useful-scripts/blob/master/docs/java.md “文档及脚本下载地址”)

1
2
3
4
5
6
7
8
9
10

# 从所有运行的Java进程中找出最消耗CPU的线程(缺省5个),打印出其线程栈
show-busy-java-threads

# 缺省会自动从所有的Java进程中找出最消耗CPU的线程,这样用更方便
# 当然你可以手动指定要分析的Java进程Id,以保证只会显示你关心的那个Java进程的信息
show-busy-java-threads -p <指定的Java进程Id>

show-busy-java-threads -c <要显示的线程栈数>