CPU 负载高一般是某个或某几个线程有问题,这里列出几种常用的排查定位方案。
核心思路是通过采样指定进程内线程的 CPU 使用率,筛选出 Top N 个可疑线程,再利用堆栈信息定位具体代码。
手动 top + jstack
朴实但有用的方式
top -b -d2 -n3 -H -p PID | grep 'top -' -A 16>cpu_slow.log && /jdk/bin/jstack -lPID >> cpu_slow.log
printf "%x\n" $TID
# 间隔2秒、获取3次进程的前10个最耗费CPU的线程信息,并与线程堆栈一起输出到文件cpu_slow.log中
# 然后通过线程 ID 转 16 进制找到最耗费 CPU 的线程。
# top -b:batch模式运行,适合打印到文件 -d2:间隔2s -n3:运行top三次后退出 -H:显示线程信息
# -p: 仅展示指定进程 top默认是按cpu使用率排序
# jstack -l:long listings,会打印出额外的锁信息,在发生死锁时可以用jstack -l pid来观察锁持有信息
# -m:mixed mode,不仅会输出Java堆栈信息,还会输出C/C++堆栈(比如Native方法)
# > : 输出重定向(会清空原文件中的内容) >> : 以追加的方式重定向
以上操作比较麻烦,可以通过以下整合的脚本来定位
Arthas
https://arthas.aliyun.com/doc/commands.html
安装启动:
curl -O https://arthas.aliyun.com/arthas-boot.jar
java -jar arthas-boot.jar
功能丰富,不仅可以采样线程 CPU 使用率、状态等等
thread -n 3 -i 1000
# 统计1000ms周期内,最忙的3个线程的线程栈
output:
[arthas@1427]$ thread -n 15 -i 10000
"C2 CompilerThread10" [Internal] cpuUsage=6.98% deltaTime=701ms time=18447ms
"ForkJoinPool.commonPool-worker-111" Id=1347 cpuUsage=5.71% deltaTime=574ms time=1761ms TIMED_WAITING
at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3310)
at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1775)
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
at io.lettuce.core.protocol.AsyncCommand.await(AsyncCommand.java:83)
at io.lettuce.core.internal.Futures.awaitOrCancel(Futures.java:244)
at io.lettuce.core.LettuceFutures.awaitOrCancel(LettuceFutures.java:74)
...
cpuUsage :为采样间隔时间内线程的 CPU 使用率,与dashboard命令的数据一致。
deltaTime: 为采样间隔时间内线程的增量 CPU 时间,小于 1ms 时被取整显示为 0ms。
time: 为线程运行总 CPU 时间。
注意:线程栈为采样结束时获取,不能表明采样间隔时间内该线程都是在处理相同的任务。建议间隔时间不要太长,可能间隔时间越大越不准确。 可以根据具体情况尝试指定不同的间隔时间,观察输出结果。
可利用 jad 反编译指定类
jad --source-only demo.MathGame
# 只展示源代码,不包含 ClassLoader
还提供 tt / watch 记录当前方法调用的出入参、时间、调用情况等,还可以重放入参进行复现、验证。
tt -t demo.MathGame primeFactors -n 100
# -t 记录指定方法每次执行情况 -n 指定记录的次数
tt -i 1004 -p
# 针对记录的 1004 号调用重放
总结
善用工具可以提升效率,但最重要的是思路正确。