Winse Blog

走走停停都是风景, 熙熙攘攘都向最好, 忙忙碌碌都为明朝, 何畏之.

Flamegraphs Java Cpu

在MacTalk的公众号上读到了agentzh关于火焰图介绍(2016年5月6日07:57 动态追踪技术(中) - Dtrace、SystemTap、火焰图),挺新奇的,并且应该对于查询热线程还是有作用的。

先了解perf和flamegraphs基础知识:

perf好像有点类似java的btrace,不过perf是操作系统层面的。把操作系统当做服务,客户端通过perf来获取/查询系统的信息。

监控系统

perf包括在linux 2.6.31代码里面,没装的话redhat可以通过yum来安装/更新:

  • 虚拟机
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
[root@hadoop-master2 ~]# yum install perf
...
Installed:
  perf.x86_64 0:2.6.32-573.26.1.el6  
  
[root@hadoop-master2 ~]# perf stat ls /dev/shm

 Performance counter stats for 'ls /dev/shm':

          0.697115 task-clock                #    0.613 CPUs utilized          
                 0 context-switches          #    0.000 K/sec                  
                 0 cpu-migrations            #    0.000 K/sec                  
               236 page-faults               #    0.339 M/sec                  
   <not supported> cycles                  
   <not supported> stalled-cycles-frontend 
   <not supported> stalled-cycles-backend  
   <not supported> instructions            
   <not supported> branches                
   <not supported> branch-misses           

       0.001137015 seconds time elapsed

虚拟机可能有一些event不能用,到真正的实体机上面应该是没问题的(网上有同学验证过)。可以通过 perf list 查看支持的event。

  • 实体机指标项:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
[root@dacs ~]# perf stat ls /dev/shm
...

 Performance counter stats for 'ls /dev/shm':

          1.793297      task-clock (msec)         #    0.677 CPUs utilized          
                 1      context-switches          #    0.558 K/sec                  
                 0      cpu-migrations            #    0.000 K/sec                  
               255      page-faults               #    0.142 M/sec                  
           2765454      cycles                    #    1.542 GHz                     [44.66%]
           1544155      stalled-cycles-frontend   #   55.84% frontend cycles idle    [64.12%]
           1013635      stalled-cycles-backend    #   36.65% backend  cycles idle   
           2692743      instructions              #    0.97  insns per cycle        
                                                  #    0.57  stalled cycles per insn
            603340      branches                  #  336.442 M/sec                  
             12499      branch-misses             #    2.07% of all branches         [98.00%]

       0.002650313 seconds time elapsed

windows的话直接下载 UIforETW ,运行 UIforETW.exe 就可以用来采样了。把采样产生的etl文件传给xperf_to_collapsedstacks.py,最后用flamegraph.pl画图。

  • perf的常用命令:
1
2
3
4
5
6
7
8
9
10
# http://www.brendangregg.com/perf.html
perf list

perf stat ./t1 
perf stat -a -A ls

perf top
 
perf record – e cpu-clock ./t1 
perf report

参考:

绘制系统火焰图

1
2
3
4
5
6
7
8
9
10
11
12
13
# http://www.brendangregg.com/FlameGraphs/cpuflamegraphs.html
# https://github.com/brendangregg/FlameGraph
# 真实的机器效果还是挺不错的
perf record -F 99 -a -g -- sleep 60
perf script | ~/FlameGraph/stackcollapse-perf.pl >out.perf-folded
~/FlameGraph/flamegraph.pl out.perf-folded >perf.svg
sz perf.svg

# --
# perf script | ./stackcollapse-perf.pl > out.perf-folded
# grep -v cpu_idle out.perf-folded | ./flamegraph.pl > nonidle.svg
# grep ext4 out.perf-folded | ./flamegraph.pl > ext4internals.svg
# egrep 'system_call.*sys_(read|write)' out.perf-folded | ./flamegraph.pl > rw.svg

安装的虚拟机中操作没采集到有用的。虚拟机和真实机器两个图

实体机:

虚拟机:

监控java

首先需要jdk8_u60+,直接下载最新的jdk就好了。应用启动带上参数 -XX:+PreserveFramePointer :

1
2
3
4
5
6
7
[root@hadoop-master2 ~]# java -version
java version "1.8.0_92"
Java(TM) SE Runtime Environment (build 1.8.0_92-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.92-b14, mixed mode)
[root@hadoop-master2 ~]# cd /home/hadoop/spark-1.6.0-bin-2.6.3/
[root@hadoop-master2 spark-1.6.0-bin-2.6.3]# export SPARK_SUBMIT_OPTS=-XX:+PreserveFramePointer     
[root@hadoop-master2 spark-1.6.0-bin-2.6.3]# bin/spark-shell --master local   

这里java进程使用root启动的,如果是普通用户如hadoop,为了采样需要把hadoop用户加入sudoer,在采样时使用 sudo -u hadoop CMD

http://techblog.netflix.com/2015/07/java-in-flames.html

操作方法一:使用perf-map-agent(推荐指数:AAAAA)

老版本OLD 实际操作

1
2
3
4
5
6
7
8
9
10
11
12
git clone https://github.com/jrudolph/perf-map-agent.git
cd perf-map-agent/
export JAVA_HOME=/opt/jdk1.8.0_92
cmake .
make

perf record -F 99 -g -p 7661 -- sleep 120
bin/create-java-perf-map.sh 7661

sudo perf script | ~/FlameGraph/stackcollapse-perf.pl >out.perf-folded
cat out.perf-folded | ~/FlameGraph/flamegraph.pl --color=java >perf.svg
sz perf.svg

新版本NEW 再实践

  • NOTE: 2017-10-21 项目改名了,挂到更牛逼的一个组织下了:jvm-profiling-tools
  • NOTE: 2018-03-09 再实践
  • NOTE: 2019-6-19 再更
  • NOTE: 2020-03-15 再更

参考:

实际操作:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
[root@dispatch-op-1 bigendian]# yum install git cmake make gcc gcc-c++ perf -y 
[root@dispatch-op-1 bigendian]# git clone https://github.com/jvm-profiling-tools/perf-map-agent.git
[root@dispatch-op-1 perf-map-agent]# cmake .
[root@dispatch-op-1 perf-map-agent]# make 

[root@dispatch-op-1 perf-map-agent]# mkdir -p /home/bigendian/jpt 
[root@dispatch-op-1 perf-map-agent]# bin/create-links-in /home/bigendian/jpt

[root@dispatch-op-1 bigendian]# git clone https://github.com/brendangregg/FlameGraph 

[bigendian@dispatch-op-1 jpt]$ ll
total 0
lrwxrwxrwx 1 root root 51 Mar 15 13:23 perf-java-flames -> /home/bigendian/perf-map-agent/bin/perf-java-flames
lrwxrwxrwx 1 root root 57 Mar 15 13:23 perf-java-record-stack -> /home/bigendian/perf-map-agent/bin/perf-java-record-stack
lrwxrwxrwx 1 root root 57 Mar 15 13:23 perf-java-report-stack -> /home/bigendian/perf-map-agent/bin/perf-java-report-stack
lrwxrwxrwx 1 root root 48 Mar 15 13:23 perf-java-top -> /home/bigendian/perf-map-agent/bin/perf-java-top

[bigendian@dispatch-op-1 ~]$ export FLAMEGRAPH_DIR=~/FlameGraph/
[bigendian@dispatch-op-1 ~]$ jpt/perf-java-flames 23652
Recording events for 15 seconds (adapt by setting PERF_RECORD_SECONDS)

JAVA_OPTS+=" -XX:+PreserveFramePointer  "
[bigendian@dispatch-op-1 ~]$ PERF_RECORD_SECONDS=360 jpt/perf-java-flames 25564 

然后把生成svg拷贝到本地看。

注意,x 轴表示抽样数, 如果一个函数在 x 轴占据的宽度越宽, 就表示它被抽到的次数多, 即执行的时间长. 注意, x 轴不代表时间, 而是所有的调用栈合并后, 按字母顺序排列的. 火焰图就是看顶层的哪个函数占据的宽度最大。只要有”平顶”(plateaus),就表示该函数可能存在性能问题,然后结合具体代码进行分析。

按下 Ctrl + F 会显示一个搜索框,用户可以输入关键词或正则表达式,所有符合条件的函数名会高亮显示.

调用栈不完整: 当调用栈过深时,某些系统只返回前面的一部分(比如前10层)。

操作方式二:使用perfj采样(不再推荐)

NOTE:2017-10-21 这个项目好久没更新了,用上面 perf-map-agent 吧。

参考:性能调优利器——PerfJ ,直接下载release-1.0的版本,解压后给 bin/perfj 加上执行权限。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
# 测试的时刻可以把-F 99设置大一点
# java和perfj的用户得一致!!
# https://github.com/coderplay/perfj/wiki/CPU-Flame-Graph

[root@dacs ~]# export JAVA_HOME=/usr/java/jdk1.8.0_92 
[root@dacs ~]# wget http://blog.minzhou.info/perfj/leveldb-benchmark.jar
[root@dacs ~]# $JAVA_HOME/bin/java -cp leveldb-benchmark.jar -XX:+PreserveFramePointer org.iq80.leveldb.benchmark.DbBenchmark --benchmarks=fillrandom --num=100000000

[root@dacs ~]# export JAVA_HOME=/usr/java/jdk1.8.0_92 
[root@dacs ~]# perfj-1.0/bin/perfj record -F 999 -g -p `pgrep -f DbBenchmark` 

perf script | ~/FlameGraph/stackcollapse-perf.pl >out.perf-folded
~/FlameGraph/flamegraph.pl out.perf-folded  --color=java >perf.svg
sz perf.svg

还是挺有意思的。运行效果:

虚拟机的少了好多信息!一模一样的命令,得出来的东西差好远!!

另一个 Context Switch 案例:

1
2
3
4
5
6
7
8
9
10
# https://github.com/coderplay/perfj/wiki/Context-Switch-Analysis
# 在vmware虚拟机里面运行啥都看不到!实体机也看不到作者的那些栈信息
[root@dacs ~]# wget http://blog.minzhou.info/perfj/leveldb-benchmark.jar
[root@dacs ~]# export JAVA_HOME=/usr/java/jdk1.8.0_92 
[root@dacs ~]# $JAVA_HOME/bin/javac ContextSwitchTest.java 
[root@dacs ~]# $JAVA_HOME/bin/java -XX:+PreserveFramePointer ContextSwitchTest

[root@dacs ~]# export JAVA_HOME=/usr/java/jdk1.8.0_92 
[root@dacs ~]# perfj-1.0/bin/perfj record  -e sched:sched_switch -F 999 -g -p `pgrep -f ContextSwitchTest` 
[root@dacs ~]# perfj-1.0/bin/perfj report --stdio

–END

Comments