ali arthas 火焰图_性能优化之火焰图-2020-11-15

背景

相信大家都有过jvm程序运行导致cpu100% ,或者飙高的场景。这个排查的方式有很多，比如 linux 自带的top pidstat mpstat等，还有一些开源工具arthas 等；这里我介绍2种 top+jstack 、arthas火焰图

我先模拟一个cpu飙高的场景

public static void main(String[] args) {

while (true) {

double v = new Random().nextDouble();

System.out.println(v);

}

}

Top+jstack

通过jps查询到进程id

通过top -hp 查询对应进行的线程id

jstack 进程id > js.log

将线程id转换为16 进制 //printf %x 线程id；最后在js.log 中搜索该值

"main" #1 prio=5 os_prio=31 tid=0x00007fc5b2012000 nid=0x1103(你的线程id 16进制) runnable [0x00007000040ff000]

java.lang.Thread.State: RUNNABLE //cpu100%对应线程状态一般为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 <0x0000000740048fc8> (a java.io.BufferedOutputStream)

at java.io.PrintStream.write(PrintStream.java:482)

- locked <0x000000074001b290> (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 <0x0000000740048ed8> (a java.io.OutputStreamWriter)

at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)

at java.io.PrintStream.write(PrintStream.java:527)

- eliminated <0x000000074001b290> (a java.io.PrintStream)

at java.io.PrintStream.print(PrintStream.java:639)

at java.io.PrintStream.println(PrintStream.java:778)

- locked <0x000000074001b290> (a java.io.PrintStream)

at com.example.demo2.CpuTest.main(CpuTest.java:16) //这里就是我们的main方法

最后找到代码问题就可以进行优化了

Arthas 热力图

在解压目录运行 java -jar arthas-boot.jar (需要在程序cpu100%的机器上运行)

找到对应的程序，我这里是 CpuTest 类

[INFO] arthas-boot version: 3.4.4

[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.

* [1]: 1891

[2]: 1910 org.jetbrains.idea.maven.server.RemoteMavenServer36

[3]: 2439 org.jetbrains.jps.cmdline.Launcher

[4]: 2440 com.example.demo2.CpuTest

// 输入 4

输入 profiler start

几秒钟后输入profiler stop

会有如下提示，然后将图片路径再浏览器中打开

[arthas@2440]$ profiler stop

OK

profiler output file: /Users/yangjianbin/IdeaProjects/test/arthas-output/20201115-235908.svg

[arthas@2440]$

20201115-235908.svg

大家生成的图片也类似这样，火焰图是代表cpu执行的时间片，图片上大家只要关注最上面红色小矩形可以清楚的看到cpu被分配到做 写操作上既(System.out.println()) 和线程Sleep；细心的人会看到最右边我箭头指出的地方，对那是Random函数花费的时间；可以很清楚的分析到打印花了大量的cpu工作，大家可以将打印代码去了，在运行验证看看cpu是不是还是那么高，结论我就不说了

image.png

今天的分享就到这里，希望对大家有帮助，欢迎指正&提问