性能优化之火焰图-2020-11-15
2020-11-16 本文已影响0人
five_year
背景
相信大家都有过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 热力图
- 先下载arthas [arthas 下载安装] (https://github.com/alibaba/arthas/releases) wget 网速慢的话用迅雷下
- 在解压目录运行 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
今天的分享就到这里，希望对大家有帮助，欢迎指正&提问
