定位线上最耗CPU的线程
准备工作
启动一个程序。
arthas-demo是一个简单的程序，每隔一秒生成一个随机数，再执行质因数分解，并打印出分解结果。
curl -O https://alibaba.github.io/arthas/arthas-demo.jar
java -jar arthas-demo.jar
[root@localhost ~]# curl -O https://alibaba.github.io/arthas/arthas-demo.jar% Total % Received % Xferd Average Speed Time Time Time CurrentDload Upload Total Spent Left Speed
100 3743 100 3743 0 0 3022 0 0:00:01 0:00:01 --:--:-- 3023
[root@localhost ~]# java -jar arthas-demo.jar
1813=7*7*37
illegalArgumentCount: 1, number is: -180005, need >= 2
illegalArgumentCount: 2, number is: -111175, need >= 2
18505=5*3701
166691=7*23813
105787=11*59*163
60148=2*2*11*1367
196983=3*3*43*509
illegalArgumentCount: 3, number is: -173479, need >= 2
illegalArgumentCount: 4, number is: -112840, need >= 2
39502=2*19751
....传统方式
通过top命令找到最耗时的进程
[root@localhost ~]# top
top - 11:11:05 up 20:02, 3 users, load average: 0.09, 0.07, 0.05
Tasks: 225 total, 1 running, 224 sleeping, 0 stopped, 0 zombie
%Cpu(s): 0.0 us, 0.7 sy, 0.0 ni, 99.3 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 1421760 total, 135868 free, 758508 used, 527384 buff/cache
KiB Swap: 2097148 total, 2070640 free, 26508 used. 475852 avail Mem
Change delay from 3.0 toPID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND98344 root 20 0 2422552 23508 12108 S 0.7 1.7 0:00.32 java1 root 20 0 194100 6244 3184 S 0.0 0.4 0:20.41 systemd2 root 20 0 0 0 0 S 0.0 0.0 0:00.12 kthreadd4 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0H6 root 20 0 0 0 0 S 0.0 0.0 0:20.25 ksoftirqd/0找到进程号是98344。
找到进程中最耗CUP的线程
使用ps -Lp #pid cu命令，查看某个进程中的线程CPU消耗排序：
[root@localhost ~]# ps -Lp 98344 cu
USER PID LWP %CPU NLWP %MEM VSZ RSS TTY STAT START TIME COMMAND
root 98344 98344 0.0 10 4.1 2422552 59060 pts/0 Sl+ 11:09 0:00 java
root 98344 98345 0.0 10 4.1 2422552 59060 pts/0 Sl+ 11:09 0:04 java
root 98344 98346 0.0 10 4.1 2422552 59060 pts/0 Sl+ 11:09 0:01 VM Thread
root 98344 98347 0.0 10 4.1 2422552 59060 pts/0 Sl+ 11:09 0:00 Reference Handl
root 98344 98348 0.0 10 4.1 2422552 59060 pts/0 Sl+ 11:09 0:00 Finalizer
root 98344 98349 0.0 10 4.1 2422552 59060 pts/0 Sl+ 11:09 0:00 Signal Dispatch
root 98344 98350 0.0 10 4.1 2422552 59060 pts/0 Sl+ 11:09 0:05 C2 CompilerThre
root 98344 98351 0.0 10 4.1 2422552 59060 pts/0 Sl+ 11:09 0:00 C1 CompilerThre
root 98344 98352 0.0 10 4.1 2422552 59060 pts/0 Sl+ 11:09 0:00 Service Thread
root 98344 98353 0.1 10 4.1 2422552 59060 pts/0 Sl+ 11:09 0:19 VM Periodic Tas
看TIME列可以看出那个线程耗费CUP多，根据LWP列可以看到线程的ID号，但是需要转换成16进制才可以查询线程堆栈信息。
获取线程id的十六进制码
使用printf '%x\n' 98345命令做进制转换：
[root@localhost ~]# printf '%x\n' 98345
18029
查看线程堆栈信息
使用jstack获取堆栈信息jstack 98344 | grep -A 10 18029：
[root@localhost ~]# jstack 98344 | grep -A 10 18029
"main" #1 prio=5 os_prio=0 tid=0x00007fb88404b800 nid=0x18029 waiting on condition [0x00007fb88caab000]java.lang.Thread.State: TIMED_WAITING (sleeping)at java.lang.Thread.sleep(Native Method)at java.lang.Thread.sleep(Thread.java:340)at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)at demo.MathGame.main(MathGame.java:17)"VM Thread" os_prio=0 tid=0x00007fb8840f2800 nid=0x1802a runnable"VM Periodic Task Thread" os_prio=0 tid=0x00007fb884154000 nid=0x18031 waiting on condition
通过命令我们可以看到这个线程的对应的耗时代码是在demo.MathGame.main(MathGame.java:17)
grep -C 5 foo file 显示file文件里匹配foo字串那行以及上下5行
grep -B 5 foo file 显示foo及前5行
grep -A 5 foo file 显示foo及后5行
使用Arthas
可以直接使用dashboard，thread命令进行定位。只是我们线上可能大部分情况下不允许装arthas。
启动Arthas
(base) admin@wangyuhao Desktop % java -jar arthas-demo.jar
Error: Unable to access jarfile arthas-demo.jar
(base) admin@wangyuhao Desktop % java -jar arthas-boot.jar
[INFO] JAVA_HOME: /Library/Java/JavaVirtualMachines/jdk1.8.0_281.jdk/Contents/Home/jre
[INFO] arthas-boot version: 3.7.2
[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.
* [1]: 16897 arthas-demo.jar[2]: 407
1
[INFO] local lastest version: 3.6.7, remote lastest version: 3.7.2, try to download from remote.
[INFO] Start download arthas from remote server: https://arthas.aliyun.com/download/3.7.2?mirror=aliyun
[INFO] File size: 17.84 MB, downloaded size: 6.05 MB, downloading ...
[INFO] File size: 17.84 MB, downloaded size: 10.81 MB, downloading ...
[INFO] File size: 17.84 MB, downloaded size: 14.74 MB, downloading ...
[INFO] Download arthas success.
[INFO] arthas home: /Users/admin/.arthas/lib/3.7.2/arthas
[INFO] Try to attach process 16897
Picked up JAVA_TOOL_OPTIONS:
[INFO] Attach process 16897 success.
[INFO] arthas-client connect 127.0.0.1 3658,---. ,------. ,--------.,--. ,--. ,---. ,---. / O \ | .--. ''--. .--'| '--' | / O \ ' .-'
| .-. || '--'.' | | | .--. || .-. |`. `-.
| | | || |\ \ | | | | | || | | |.-' |
`--' `--'`--' '--' `--' `--' `--'`--' `--'`-----' wiki https://arthas.aliyun.com/doc
tutorials https://arthas.aliyun.com/doc/arthas-tutorials.html
version 3.7.2
main_class demo.MathGame
pid 16897
time 2024-03-19 08:59:26
通过dashboard查看实时数据面板
[arthas@16897]$ dashboard
通过thread查看线程堆栈
[arthas@16897]$ thread -n 25
"C1 CompilerThread3" [Internal] cpuUsage=0.34% deltaTime=0ms time=588ms"arthas-command-execute" Id=22 cpuUsage=0.19% deltaTime=0ms time=15ms RUNNABLEat sun.management.ThreadImpl.dumpThreads0(Native Method)at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:448)at com.taobao.arthas.core.command.monitor200.ThreadCommand.processTopBusyThreads(ThreadCommand.java:206)at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:122)at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.process(AnnotatedCommandImpl.java:82)at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.access$100(AnnotatedCommandImpl.java:18)at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:111)at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:108)at com.taobao.arthas.core.shell.system.impl.ProcessImpl$CommandProcessTask.run(ProcessImpl.java:385)at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)at java.util.concurrent.FutureTask.run(FutureTask.java:266)at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)at java.lang.Thread.run(Thread.java:748)"VM Periodic Task Thread" [Internal] cpuUsage=0.07% deltaTime=0ms time=356ms"VM Thread" [Internal] cpuUsage=0.01% deltaTime=0ms time=46ms
..."main" Id=1 cpuUsage=0.0% deltaTime=0ms time=238ms TIMED_WAITINGat java.lang.Thread.sleep(Native Method)at java.lang.Thread.sleep(Thread.java:340)at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)at demo.MathGame.main(MathGame.java:17)"C2 CompilerThread2" [Internal] cpuUsage=0.0% deltaTime=0ms time=319ms"GC task thread#8 (ParallelGC)" [Internal] cpuUsage=0.0% deltaTime=0ms time=21ms"GC task thread#7 (ParallelGC)" [Internal] cpuUsage=0.0% deltaTime=0ms time=21ms"GC task thread#6 (ParallelGC)" [Internal] cpuUsage=0.0% deltaTime=0ms time=21ms
我们可以找到at demo.MathGame.main(MathGame.java:17)这个堆栈。
通过jad反编译看源码情况
[arthas@16897]$ jad demo.MathGameClassLoader:
+-sun.misc.Launcher$AppClassLoader@5c647e05 +-sun.misc.Launcher$ExtClassLoader@4554617c Location:
/Users/admin/arthas-demo.jar /** Decompiled with CFR.*/package demo;import java.util.ArrayList;import java.util.List;import java.util.Random;import java.util.concurrent.TimeUnit;public class MathGame {private static Random random = new Random();public int illegalArgumentCount = 0;public static void main(String[] args) throws InterruptedException {MathGame game = new MathGame();while (true) {
/*16*/ game.run();
/*17*/ TimeUnit.SECONDS.sleep(1L);}}public void run() throws InterruptedException {try {
/*23*/ int number = random.nextInt() / 10000;
/*24*/ List<Integer> primeFactors = this.primeFactors(number);
/*25*/ MathGame.print(number, primeFactors);}catch (Exception e) {
/*28*/ 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 + "=");
/*34*/ for (int factor : primeFactors) {
/*35*/ sb.append(factor).append('*');}
/*37*/ if (sb.charAt(sb.length() - 1) == '*') {
/*38*/ sb.deleteCharAt(sb.length() - 1);}
/*40*/ System.out.println(sb);}public List<Integer> primeFactors(int number) {
/*44*/ if (number < 2) {
/*45*/ ++this.illegalArgumentCount;throw new IllegalArgumentException("number is: " + number + ", need >= 2");}ArrayList<Integer> result = new ArrayList<Integer>();
/*50*/ int i = 2;
/*51*/ while (i <= number) {
/*52*/ if (number % i == 0) {
/*53*/ result.add(i);
/*54*/ number /= i;
/*55*/ i = 2;continue;}
/*57*/ ++i;}
/*61*/ return result;}}Affect(row-cnt:1) cost in 491 ms.
[arthas@16897]$
参考
https://arthas.aliyun.com/doc/commands.html#jvm-%E7%9B%B8%E5%85%B3
