Menu

  • Home
  • Work
    • Cloud
      • Virtualization
      • IaaS
      • PaaS
    • Java
    • Go
    • C
    • C++
    • JavaScript
    • PHP
    • Python
    • Architecture
    • Others
      • Assembly
      • Ruby
      • Perl
      • Lua
      • Rust
      • XML
      • Network
      • IoT
      • GIS
      • Algorithm
      • AI
      • Math
      • RE
      • Graphic
    • OS
      • Linux
      • Windows
      • Mac OS X
    • BigData
    • Database
      • MySQL
      • Oracle
    • Mobile
      • Android
      • IOS
    • Web
      • HTML
      • CSS
  • Life
    • Cooking
    • Travel
    • Gardening
  • Gallery
  • Video
  • Music
  • Essay
  • Home
  • Work
    • Cloud
      • Virtualization
      • IaaS
      • PaaS
    • Java
    • Go
    • C
    • C++
    • JavaScript
    • PHP
    • Python
    • Architecture
    • Others
      • Assembly
      • Ruby
      • Perl
      • Lua
      • Rust
      • XML
      • Network
      • IoT
      • GIS
      • Algorithm
      • AI
      • Math
      • RE
      • Graphic
    • OS
      • Linux
      • Windows
      • Mac OS X
    • BigData
    • Database
      • MySQL
      • Oracle
    • Mobile
      • Android
      • IOS
    • Web
      • HTML
      • CSS
  • Life
    • Cooking
    • Travel
    • Gardening
  • Gallery
  • Video
  • Music
  • Essay

利用perf剖析Linux应用程序

18
Jan
2019

利用perf剖析Linux应用程序

By Alex
/ in Linux
/ tags 性能剖析
0 Comments
简介

剖析(Profiling)是一种有效的、细粒度的软件性能检查手段,大部分编程语言的生态圈都有各种性能剖析工具。本文的讨论内容与具体编程语言无关,而关注在Linux系统上对应用程序的性能进行剖析。

Linux内核实现了非常有价值的性能分析基础设施(perf infrastructure),可以用于剖析各种CPU或软件事件。这一功能由perf_events接口暴露,并提供 perf这一用户空间工具,通过此工具,你可以发现以下问题的答案:

  1. 为什么内核使用太多的CPU,哪些代码使用了这些CPU时间
  2. 什么代码导致CPU二级缓存不命中
  3. CPU是否因内存IO而卡顿
  4. 什么代码在分配内存,分配了多少
  5. 什么触发了TCP重传
  6. 某个内核函数是否被频繁调用
  7. 线程离开CPU的原因 

perf_events是内核2.6+的一部分,用户空间工具perf在包linux-tools-common中,需要安装才能使用。要想从剖析中获得更多内核相关信息,你需要符号(Symbol)和栈追踪,这可能需要安装额外的包,甚至使用特定选项重新编译你的内核。剖析用户空间代码时,也要求目标应用程序的调试信息(符号表)被保留。

工作模式

perf_events有三种工作模式:

  1. counting,在内核上下文对各种指标进行计数
  2. sampling,对事件进行采样,并将性能数据存放到内核缓冲,然后异步的写入到perf.data
  3. bpf,4.4版本内核引入的新特性,允许在内核中执行一段用户自定义的代码,以执行高效的过滤、汇总
基于事件的采样

perf_events的采样是基于事件进行的。采样的周期以事件的数量来表示,而非基于时间。当目标事件计数溢出指定的数值,则产生一个采样。

样本中包含的信息取决于用户和工具指定的度量类型,但是最重要的信息是指令指针(instruction pointer),也就是程序被中断时所处的位置。

这种基于中断的采样,在现代处理器上存在刹车效应。也就是说,样本中记录的指针,和程序被中断以处理PMU事件时的指令指针,可能相隔数十个指令。

record子命令默认使用cycle事件,类似于定期采样。

事件类型

perf_events可以捕获的事件类型包括:

  1. 硬件事件,来自CPU自己或CPU的PMU(Performance Monitoring Unit,性能监控单元),包含一系列微架构事件例如时钟周期、L1缓存丢失等。具体支持的事件类型取决于CPU型号
  2. 软件事件,基于内核计数器的低级事件,例如CPU迁移、上下文切换、Minor Faults、Major Faults(页面错误)
  3. 追踪点事件,由内核中的ftrace实现,包括:
    1. 内核追踪点事件,静态的、内核级的追踪点,硬编码到内核
    2. 用户静态定义追踪(USDT),用户态应用程序硬编码的追踪点
    3. 动态追踪,软件可以被动态instrumented,在任何位置创建事件。对于内核软件,使用kprobes框架,对于用户软件,使用uprobes
    4. 定时追踪,以任意频率抓取快照,主要用于CPU剖析,工作机制是定期引发中断
动态追踪

要启用内核动态追踪,需要使用内核编译参数CONFIG_KPROBES=y、CONFIG_KPROBE_EVENTS=y。要追踪基于帧指针的内核栈,需要内核编译参数CONFIG_FRAME_POINTER=y。

要启用用户动态追踪,需要使用内核编译参数CONFIG_UPROBES=y、CONFIG_UPROBE_EVENTS=y

事件限定符

事件有多种表示方式,最简单的是它的字符串表示。引用事件时,可以指定限定符:

Shell
1
2
3
4
5
# 剖析用户级、内核级的cycle事件
-e cycles
-e cycles:uk
# 仅用户级
-e cycles:u

限定符包括:

限定符 说明 示例
u 监控特权级别3, 2, 1 ,也就是用户态 event:u
k 监控特权级别0,也就是内核态 event:k
h 在虚拟化环境下监控Hypervisor事件 event:h
H 在虚拟化环境下监控宿主机事件 event:H
G 在虚拟化环境下监控客户机事件 event:G
监控范围

perf可以在不同的范围收集性能数据:

  1. 单线程(per-thread):仅仅监控选择的线程。如果线程被调度失去CPU,对它的性能计数暂停,如果线程被调度到其它CPU,计数会存储并恢复,继续在新CPU上进行计数
  2. 单进程( per-process):进程的所有线程都被监控,计数被汇总
  3. 单CPU( per-cpu):仅仅监控单颗、或者选定的几颗CPU上的事件
  4. 全局(system-wide):监控所有CPU上的事件
调试信息
符号

和其它调试工具一样,perf需要符号信息,符号用于将内存地址转换为可读的函数、变量名称。没有符号信息,你会看到0x7ff3c1cddf29这样的HEX代码,无法阅读。

如果需要被剖析的软件通过包管理器安装,你需要找到并安装对应的调试包(可能以-dbgsym为后缀)。如果找不到调试包,可以考虑手工编译。

JIT符号

Java、Node.js等基于虚拟机的语言,在自己的虚拟CPU上执行代码,因而具有自己管理栈和执行函数的方法。

为了通过perf来剖析这类语言的程序,你需要:

  1. 对于Java,使用perf-map-agent
  2. 对于Node.js,使用命令行选项 --perf_basic_prof

你可能看不到完整的Java栈,这是因为X86上的Hotspot忽略了帧指针(Frame pointer)。在8u60+版本以后,可以使用-XX:+PreserveFramePointer修复这一问题。

栈追踪

为了方便剖析,编译时尽量保留帧指针,编译器的优化行为可能导致难以调试,但是很多情况下优化掉帧指针是默认行为。

缺少帧指针会导致无法看到完整的调用栈,解决此问题的方法有几种:

  1. 使用DWARF(ELF文件通常使用的调试信息格式)信息来Unwind栈
  2. 使用LBR(Last Branch Record),这是处理器特性,因此可能不可用
  3. 保留帧指针

下面是默认情况下编译(-O2,忽略帧指针)得到的OpenSSH的剖析结果:

1
2
3
4
5
6
7
8
9
10
11
    57.14%     sshd  libc-2.15.so        [.] connect          
               |
               --- connect
                  |          
                  |--25.00%-- 0x7ff3c1cddf29
                  |          
                  |--25.00%-- 0x7ff3bfe82761
                  |          0x7ff3bfe82b7c
                  |          
                  |--25.00%-- 0x7ff3bfe82dfc
                   --25.00%-- [...]

以 -fno-omit-frame-pointer重新编译后:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
   100.00%     sshd  libc-2.15.so   [.] __GI___connect_internal
               |
               --- __GI___connect_internal
                  |          
                  |--30.00%-- add_one_listen_addr.isra.0
                  |          add_listen_addr
                  |          fill_default_server_options
                  |          main
                  |          __libc_start_main
                  |          
                  |--20.00%-- __nscd_get_mapping
                  |          __nscd_get_map_ref
                  |          
                  |--20.00%-- __nscd_open_socket
                   --30.00%-- [...]

可以看到符号都显示出来了,另外add_one_listen_addr的祖先帧也显示出来了。 

关于内核

你需要使用 CONFIG_FRAME_POINTER=y来编译内核,以保留栈指针信息。

DWARF

从内核3.9版本开始,缺失栈指针的问题有个变通的解决方案(对于用户空间的栈)——使用libunwind。libunwind基于dwarf,调用perf时传入--call-graph dwarf即可。

安装
Ubuntu

在Ubuntu上可以这样安装:

Shell
1
apt install linux-tools-common

系统可能会提示你安装其它的包,安装即可。

子命令列表

perf支持一系列的子命令:

子命令 说明
annotate 读取perf.data并显示被注解的代码
bench 基准测试的框架
config 在配置文件中读写配置项
diff 读取perf.data并显示剖析差异
evlist 列出perf.data中的事件名称
inject 用于增强事件流的过滤器
kmem 跟踪/度量内核内存属性
kvm 跟踪/度量KVM客户机系统
list 显示符号化的事件列表
lock 分析锁事件
mem 分析内存访问
record 执行剖析
report 显示剖析结果
sched 分析调度器
stat 获取性能计数
top 显示成本最高的操作并动态刷新
trace 类似于strace的工具
probe 定义新的动态追踪点
stat
说明

运行一个命令,并收集性能计数器。

对于任何支持计数的事件,perf都能够在进程执行期间对发生的事件进行计数,计数结果会直接打印在控制台上。

stat子命令可以在线程、进程、CPU、全局级别进行计数。默认情况下进程的所有线程、子进程的计数都被统计在内,可以通过-i选项修改此行为。

选项

参考record子命令。

格式
Shell
1
2
3
# 如果不指定-e,则默认收集所有事件的计数器
perf stat [-e <EVENT> | --event=EVENT] [-a] <command>
perf stat [-e <EVENT> | --event=EVENT] [-a] -- <command> [<options>]
示例
Shell
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
# CPU性能计数器
perf stat command
 
# 详细的CPU性能计数器
perf stat -d command
 
# 收集指定进程的性能计数,直到Ctrl-C
perf stat -p PID
 
# 收集整个系统的性能计数,持续5秒
perf stat -a sleep 5
# Performance counter stats for 'system wide':
#      20010.623960      cpu-clock (msec)          #    4.000 CPUs utilized          
#            61,947      context-switches          #    0.003 M/sec                  
#             4,153      cpu-migrations            #    0.208 K/sec                  
#                99      page-faults               #    0.005 K/sec                  
#     5,003,068,069      cycles                    #    0.250 GHz                      (49.96%)
#     2,000,087,622      instructions              #    0.40  insn per cycle           (75.00%)
#       393,183,513      branches                  #   19.649 M/sec                    (75.05%)
#        24,391,051      branch-misses             #    6.20% of all branches          (74.99%)
 
#       5.003219775 seconds time elapsed
 
 
# 指定需要收集的几种计数器,持续10秒
perf stat -e cycles,instructions,cache-references,cache-misses,bus-cycles -a sleep 10
 
# CPU一级缓存计数器
perf stat -e L1-dcache-loads,L1-dcache-load-misses,L1-dcache-stores command
 
# TLB计数器
perf stat -e dTLB-loads,dTLB-load-misses,dTLB-prefetch-misses command
 
# CPU最后一级缓存计数器
perf stat -e LLC-loads,LLC-load-misses,LLC-stores,LLC-prefetches command
 
# 统计指定进程的系统调用
perf stat -e 'syscalls:sys_enter_*' -p PID
 
# 统计全局系统调用
perf stat -e 'syscalls:sys_enter_*' -a sleep 5
 
# 统计调度器相关事件
perf stat -e 'sched:*' -p PID
perf stat -e 'sched:*' -p PID sleep 10
 
# 统计Ext4相关事件
perf stat -e 'ext4:*' -a sleep 10
 
# 统计块IO事件
perf stat -e 'block:*' -a sleep 10
 
# 收集多种事件
perf stat -e cycles,instructions,cache-misses
top
说明

动态显示执行成本最高的项。

默认情况下以cycles事件采样,样本最高的输出在最顶部。

示例
Shell
1
2
3
4
# 动态显示成本最高的地址和符号,不保存到文件
perf top -F 49
# 动态显示成本最高的命令
perf top -F 49 -ns comm,dso
record
说明

此命令可以启动一个命令,并对其进行剖析,然后把剖析数据记录到文件(默认perf.data)。按Ctrl - C可以随时结束剖析。

此命令可以在线程、进程、CPU、全局级别进行剖析。

record, report, annotate是一组相关的命名,通常的使用流程是:

  1. 在被剖析机器上调用record录制数据
  2. 拷贝录制的perf.data,在任意机器上调用report、annotate进行分析

该命令不是记录所有事件,还是进行采样。默认情况下采样基于cycle事件,也就是进行定期采样。

perf_events接口允许通过两种方式描述采样周期:

  1. period:事件发生的次数
  2. frequency:每秒样本的平均个数

perf默认使用第二种,具体来说对应到-F选项。-F 1000表示1000Hz,也就是每秒平均采样1000个。内核会动态的调整采样周期,以尽量满足需求。

格式
Shell
1
2
perf record [-e <EVENT> | --event=EVENT] [-l] [-a]    <command>
perf record [-e <EVENT> | --event=EVENT] [-l] [-a] -- <command> [<options>]
选项
选项 说明
-e

剖析的事件类型,也就是性能监控单元(Performance Monitoring Unit,PMU)类型。可以指定:

  1. 事件名称,执行 perf list可以显示支持的事件列表
  2. 一组事件,以花括号包围 {event1,event2,...}
  3. 其它形式
--filter 事件过滤器,必须和指定了追踪点(tracepoint)事件的-e配合使用
--exclude-perf 不记录perf自己发起的事件
-a

使用Per-CPU模式,如果不指定-C,则相当于全局模式

如果指定-C,则可以选定若干CPU

-p 收集指定进程的事件,逗号分割的PID列表
-t 收集指定线程的事件,逗号分割的线程ID列表
-u 收集指定用户的进程的事件
-r 使用RT SCHED_FIFO优先级收集数据
-c 采样周期
-o 输出文件的名称
-i 不包括子任务的事件,不监控子进程、线程、子进程的线程
-F 以指定的频率剖析
-g 记录调用栈
--call-graph

收集调用栈使用的方法:

  1. fp,栈指针
  2. dwarf,DWARF的调用帧信息(CFI)
  3. lbr,Hardware Last Branch Record facility

某些系统上,如果应用通过GCC的--fomit-frame-pointer参数构建,fp模式下可能只能看到匿名调用帧,可以用dwarf代替

-s 记录每个线程的事件计数器,配合 perf report -T使用
-d 记录样本地址
-T 记录样本时间戳
-P 记录样本周期
-C 仅仅从指定的CPU上收集样本,示例: -C 0,2-3
-G 仅仅记录指定控制组的事件
示例
性能剖析
Shell
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
# 以99HZ的频率剖析指定的命令,默认情况下工作在Per-thread模式
perf record -F 99 command
 
# 以99HZ的频率剖析指定的PID
perf record -F 99 -p PID
# 以99HZ的频率剖析指定的PID,持续10秒
perf record -F 99 -p PID sleep 10
# 以99HZ的频率剖析整个系统
perf record -F 99 -ag -- sleep 10
 
# 基于事件发生次数,而非采样频率来指定采样周期
perf record -e retired_instructions:u -c 2000
 
# 进行栈追踪(通过Frame Pointer)
perf record -F 99 -p PID -g -- sleep 10
# 进行栈追踪(通过DWARF)
perf record -F 99 -p PID --call-graph dwarf sleep 10
# 全局性栈追踪
perf record -F 99 -ag -- sleep 10  # 4.11之前
perf record -F 99 -g -- sleep 10   # 4.11之后
# 追踪某个容器的栈
perf record -F 99 -e cpu-clock --cgroup=docker/1d567f4393190204...etc... -a -- sleep 10
 
# 每发生10000次L1缓存丢失,进行一次采样
perf record -e L1-dcache-load-misses -c 10000 -ag -- sleep 5
# 每发生以100次最后级别的CPU缓存丢失,进行一次采用
perf record -e LLC-load-misses -c 100 -ag -- sleep 5
 
# 采样内核指令
perf record -e cycles:k -a -- sleep 5
# 采用用户指令
perf record -e cycles:u -a -- sleep 5
# 精确采样用户指令,基于PEBS
perf record -e cycles:up -a -- sleep 5
静态追踪
Shell
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
# 追踪新进程的创建
perf record -e sched:sched_process_exec -a
 
# 追踪上下文切换
perf record -e context-switches -a
perf record -e context-switches -c 1 -a
perf record -e context-switches -ag
# 追踪通过sched跟踪点的上下文切换
perf record -e sched:sched_switch -a
 
# 追踪CPU迁移
perf record -e migrations -a -- sleep 10
 
# 追踪所有connect调用(出站连接)
perf record -e syscalls:sys_enter_connect -ag
# 追踪所有accepts调用(入站连接)
perf record -e syscalls:sys_enter_accept* -ag
 
# 追踪所有块设备请求
perf record -e block:block_rq_insert -ag
# 追踪所有块设备发起和完成
perf record -e block:block_rq_issue -e block:block_rq_complete -a
# 追踪100KB(200扇区)以上的块操作完成
perf record -e block:block_rq_complete --filter 'nr_sector > 200'
# 追踪所有同步写操作的完成
perf record -e block:block_rq_complete --filter 'rwbs == "WS"'
# 追踪所有写操作的完成
perf record -e block:block_rq_complete --filter 'rwbs ~ "*W*"'
 
# 采样Minor faults(RSS尺寸增加)
perf record -e minor-faults -ag
perf record -e minor-faults -c 1 -ag
# 采样页面错误
perf record -e page-faults -ag
 
# 追踪所有Ext4调用,并把结果写入到非Ext4分区
perf record -e 'ext4:*' -o /tmp/perf.data -a
 
# 追踪kswapd唤醒事件
perf record -e vmscan:mm_vmscan_wakeup_kswapd -ag
 
# 添加Node.js USDT 探针,要求Linux 4.10+
perf buildid-cache --add `which node`
# 跟踪Node.js http__server__request USDT事件
perf record -e sdt_node:http__server__request -a 
report
说明

此命令用于分析perf record生成的perf.data文件。

格式
Shell
1
perf report [-i <file> | --input=file]
选项
选项 说明
-i 指定输入文件
-n 显示每个符号的样本数量
-T 显示每个线程的事件计数器
--pid 仅仅显示指定PID的事件
--tid 仅仅显示指定TID的事件
-s

指定直方图的排序方式,逗号分隔多个排序方式,优先级降序

comm 任务的命令
pid 任务的PID
dso 采样时执行的库或者模块的名称
symbol 采样时执行的函数
srcline,srcfile 代码文件和行数,需要DWARF调试信息
overhead  采样的执行成本
overhead_sys 采样在内核态的执行成本
overhead_us 采样在用户态的执行成本
sample 采样数量

-F 指定输出字段,逗号分隔多个字段
输出
默认输出

默认情况下,样本根据函数(符号)分类,数量最多的样本位于最前面:

Shell
1
2
3
4
5
6
7
8
9
10
#  Overhead        Command  Shared Object                      Symbol
+  21.70%          swapper  [kernel.kallsyms]              [k] 0xffffffff8104f45a
+   8.89%  qemu-system-x86  [kernel.kallsyms]              [k] 0xffffffff810496f6
+   3.32%             Xorg  [kernel.kallsyms]              [k] 0xffffffff8172da33
+   2.96%       vmware-vmx  [kernel.kallsyms]              [k] 0xffffffff81121880
+   2.23%           chrome  chrome                         [.] 0x0000000004fdb6e6
+   2.17%             java  [kernel.kallsyms]              [k] 0xffffffff8109f02b
+   1.71%           chrome  [kernel.kallsyms]              [k] 0xffffffff8172d982
+   1.56%             Xorg  [nvidia]                       [k] _nv008054rm
+   1.55%             Xorg  [nvidia]                       [k] _nv014095rm

各列含义如下:

  1. Overhead,在对应函数中采样到的样本计数
  2.  Command,样本从什么应用程序中采集到
  3. Shared Object,样本来自的ELF镜像。如果:
    1. 应用程序是动态链接的,这里可能显示共享库的名称
    2. 如果样本来自内核空间,则一律显示伪ELF镜像名“kernel.kallsyms”
  4. 第4列是特权级别,点号表示用户级别,k、g、u、H分别表示内核级别、客户机内核级别、客户机用户级别、hypervisor
  5. 最后一列是符号名称,如果缺乏调试信息,则显示为0x开头的函数内存地址
指定分组规则

你可以指定多种分组规则,对样本数进行统计。

下面的例子根据共享对象分组:

Shell
1
2
3
4
5
6
7
8
perf report --sort=dso
 
+  48.05%  [kernel.kallsyms]                                                                                                                                                            
+   8.06%  libglib-2.0.so.0.4600.1                                                                                                                                                      
+   5.81%  libc-2.19.so                                                                                                                                                                  
+   4.93%  [nvidia]                                                                                                                                                                      
+   2.83%  libgobject-2.0.so.0.4600.1                                                                                                                                                    
+   2.39%  [kvm_intel]

下面的例子根据CPU序号分组:

Shell
1
2
3
4
5
6
7
8
9
10
perf report --sort=cpu
 
+  17.10%  0                                                                                                                                                                            
+  15.21%  2                                                                                                                                                                            
+  14.76%  4                                                                                                                                                                            
+  12.81%  6                                                                                                                                                                            
+  11.98%  3                                                                                                                                                                            
+  10.00%  5                                                                                                                                                                            
+   9.85%  1                                                                                                                                                                            
+   8.28%  7  
内核符号

perf不知道如何从压缩内核(vmlinuz)中抽取符号,如果你的内核保留了调试符号,则可以用-k来指出未压缩内核的位置:

Shell
1
perf report -k /tmp/vmlinux
Children/Self

如果在record时收集了调用链,则Overhead可以在Children、Self两个列中显示。Children显示子代函数的样本计数、Self显示函数自己的样本计数

示例
Shell
1
2
3
4
5
6
7
8
9
10
# 报告perf.data
perf report
 
# 显示样本数量
perf report -n
 
# 树状结构显示,展开,可以追踪到高成本的执行路径
perf report --stdio
# 每行显示一个帧,扁平化显示,按成本降序排列
perf report --stdio -n -g folded
annotate
说明

此命令用于源码级别的分析。

输出

所有被采样到的函数都会被反汇编,每个指令占据采样的比例会被输出。

源码信息

如果应用程序以-ggdb编译,annotate还能够生成源码级别信息:

Shell
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
------------------------------------------------
Percent |   Source code & Disassembly of noploop
------------------------------------------------
         :
         :
         :
         :   Disassembly of section .text:
         :
         :   08048484 <main>:
         :   #include <string.h>
         :   #include <unistd.h>
         :   #include <sys/time.h>
         :
         :   int main(int argc, char **argv)
         :   {
    0.00 :    8048484:       55                      push   %ebp
    0.00 :    8048485:       89 e5                   mov    %esp,%ebp
[...]
    0.00 :    8048530:       eb 0b                   jmp    804853d <main+0xb9>
         :                           count++;
   14.22 :    8048532:       8b 44 24 2c             mov    0x2c(%esp),%eax
    0.00 :    8048536:       83 c0 01                add    $0x1,%eax
   14.78 :    8048539:       89 44 24 2c             mov    %eax,0x2c(%esp)
         :           memcpy(&tv_end, &tv_now, sizeof(tv_now));
         :           tv_end.tv_sec += strtol(argv[1], NULL, 10);
         :           while (tv_now.tv_sec < tv_end.tv_sec ||
         :                  tv_now.tv_usec < tv_end.tv_usec) {
         :                   count = 0;
         :                   while (count < 100000000UL)
   14.78 :    804853d:       8b 44 24 2c             mov    0x2c(%esp),%eax
   56.23 :    8048541:       3d ff e0 f5 05          cmp    $0x5f5e0ff,%eax
    0.00 :    8048546:       76 ea                   jbe    8048532 <main+0xae>
[...]

再次强调一下刹车现象,百分比信息可能不准确。

内核符号

对于压缩内核,你可以指定非压缩版本内核的位置,以解析符号:

Shell
1
perf annotate -k /tmp/vmlinux -d symbol 
list
说明

显示支持的事件列表。

示例
Shell
1
2
3
4
5
# 显示所有事件
perf list
 
# 显示跟踪点sched下的事件
perf list 'sched:*'
probe
说明

用于定义新的追踪点,实现动态追踪。

格式
Shell
1
2
3
4
5
6
7
perf probe [options] --add=PROBE [...]
perf probe [options] PROBE
perf probe [options] --del=[GROUP:]EVENT [...]
perf probe --list[=[GROUP:]EVENT]
perf probe [options] --line=LINE
perf probe [options] --vars=PROBEPOINT
perf probe [options] --funcs
示例
动态追踪
Shell
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
# 为tcp_sendmsg函数添加进入追踪点,--add可以省略
perf probe --add tcp_sendmsg
 
# 移除tcp_sendmsg进入追踪点
perf probe -d tcp_sendmsg
 
# 为tcp_sendmsg函数添加退出追踪点
perf probe 'tcp_sendmsg%return'
 
# 显示tcp_sendmsg的可用变量,需要debuginfo
perf probe -V tcp_sendmsg
# 显示tcp_sendmsg的可用变量和外部变量
perf probe -V tcp_sendmsg --externs
 
# 显示tcp_sendmsg可用的行探针
perf probe -L tcp_sendmsg
 
# 显示tcp_sendmsg的81行可用的探针
perf probe -V tcp_sendmsg:81
 
# 为tcp_sendmsg添加进入进入追踪点,使用3个参数寄存器(依赖于平台)
perf probe 'tcp_sendmsg %ax %dx %cx'
 
# 为tcp_sendmsg添加进入进入追踪点,且将cx寄存器设置别名bytes(依赖于平台)
perf probe 'tcp_sendmsg bytes=%cx'
 
# 追踪tcp_sendmsg,要求%cx变量大于100
perf record -e probe:tcp_sendmsg --filter 'bytes > 100'
 
# 捕获返回值
perf probe 'tcp_sendmsg%return $retval'
 
# 为tcp_sendmsg和它的入口参数size添加追踪点,需要debuginfo,但是不依赖平台
perf probe 'tcp_sendmsg size'
 
# 为tcp_sendmsg和size、Socket状态添加追踪点
perf probe 'tcp_sendmsg size sk->__sk_common.skc_state'
 
# size大于0并且套接字状态不为TCP_ESTABLISHED时追踪tcp_sendmsg
perf record -e probe:tcp_sendmsg --filter 'size > 0 && skc_state != 1' -a
 
# 在tcp_sendmsg的81行添加追踪点,使用局部变量seglen
perf probe 'tcp_sendmsg:81 seglen'
 
# 为libc的用户态malloc函数添加探针
perf probe -x /lib64/libc.so.6 malloc
 
# 列出可用的动态探针
perf probe -l?
inject
说明

该命令使用额外的信息来增强事件流。

选项
选项 说明
-b 注入build-ids
-v 冗长输出
-i 指定输入文件
-o 指定输出文件
-s 合并sched_stat、sched_switch,以获得任务在何处睡眠、睡眠了多久
剖析示例
零散示例
全局剖析

进行10秒钟的剖析:

Shell
1
perf record -a -g sleep 10

根据应用程序的名称进行分组,整体上根据样本的执行成本进行排序:

Shell
1
perf report --sort comm,dso

可以展开执行成本高的项,追踪到CPU时间都消耗在哪里了:

perf
对于上面这个例子,可以看到,kubelet消耗的资源主要用于Prometheus相关的指标收集,以及grpc的客户端。

CPU性能计数
Shell
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
perf stat -- tar xzf ideaIU-2018.3.3.tar.gz
 
Performance counter stats for 'tar xzf ideaIU-2018.3.3.tar.gz':
    # 反映CPU利用率
       9725.627068 task-clock (msec)         #    0.941 CPUs utilized          
    # 上下文切换数量
            45,568 context-switches          #    0.005 M/sec                  
             1,370 cpu-migrations            #    0.141 K/sec        
    # 页面错误数量          
               623 page-faults               #    0.064 K/sec                  
    # 经过的时钟周期的数量
    36,249,427,884 cycles                    #    3.727 GHz                    
    # IPC,每时钟周期指令数(instructions per cycle),通常越高越好,表示工作处理过程是优化的
    # 但是,最好还是检查实际执行的指令,Spin loop就是高指令频率但是实际上什么事都不做的反例
    46,378,956,536 instructions              #    1.28  insns per cycle
     # 分支和分支预测失败
     8,274,686,762 branches                  #  850.813 M/sec                  
       214,332,307 branch-misses             #    2.59% of all branches        
 
      10.334029429 seconds time elapsed
定期采样

perf_events支持使用固定频率来采样指令指针或栈追踪,进而分析CPU使用。采样频率通过-F选项指定。

频率可以选用99,而非100HZ,以避免采样和某些周期性活动的步调完全一致而导致结果失真。如果需要更高分辨率的采样,可以使用997这样的频率,但是注意频率越高剖析本身的成本也越高。

示例:

Shell
1
2
# 以99HZ频率,全局的采样30秒
perf record -F 99 -a -g -- sleep 30
硬件计数器触发采样

除了定时触发(固定频率采样),采样也可以由特定的CPU硬件计数器触发。使用这些计数器可以分析缓存丢失、memory stall cycles(由于访问内存而导致的时钟周期浪费,内存访问速度相对CPU时钟周期要慢的多)等更低级别的处理器事件。

可用的事件列表:

Shell
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
perf list | grep Hardware
  cpu-cycles OR cycles                               [Hardware event]
  instructions                                       [Hardware event]
  cache-references                                   [Hardware event]
  cache-misses                                       [Hardware event]
  branch-instructions OR branches                    [Hardware event]
  branch-misses                                      [Hardware event]
  bus-cycles                                         [Hardware event]
  ref-cycles                                         [Hardware event]
  L1-dcache-loads                                    [Hardware cache event]
  L1-dcache-load-misses                              [Hardware cache event]
  L1-dcache-stores                                   [Hardware cache event]
  L1-dcache-store-misses                             [Hardware cache event]
  L1-dcache-prefetch-misses                          [Hardware cache event]
  L1-icache-load-misses                              [Hardware cache event]
  LLC-loads                                          [Hardware cache event]
  LLC-stores                                         [Hardware cache event]
  LLC-prefetches                                     [Hardware cache event]
  dTLB-loads                                         [Hardware cache event]
  dTLB-load-misses                                   [Hardware cache event]
  dTLB-stores                                        [Hardware cache event]
  dTLB-store-misses                                  [Hardware cache event]
  iTLB-loads                                         [Hardware cache event]
  iTLB-load-misses                                   [Hardware cache event]
  branch-loads                                       [Hardware cache event]
  branch-load-misses                                 [Hardware cache event]
  mem:<addr>[:access]                                [Hardware breakpoint]

如果每当发生这些事件,就记录栈追踪,对系统性能有严重的影响。因此,通常使用-c选项,当计数器增加一定数量后,记录一次栈追踪:

Shell
1
perf record -e L1-dcache-load-misses -c 10000 -ag -- sleep 5

上面这个例子,每当L1缓存丢失10000次,记录一次栈追踪。

统计系统调用

下面的命令统计所有调用次数大于0的系统调用的数量:

Shell
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
perf stat -e 'syscalls:sys_enter_*' tar xzf ideaIU-2018.3.3.tar.gz 2>&1 | awk '$1 != 0'
Performance counter stats for 'tar xzf ideaIU-2018.3.3.tar.gz':
 
                 2      syscalls:sys_enter_statfs                                  
            12,417      syscalls:sys_enter_utimensat                                  
  ...                                
            12,417      syscalls:sys_enter_unlinkat                                  
  ...                                
            12,432      syscalls:sys_enter_newfstat                                  
                 1      syscalls:sys_enter_lseek                                    
           184,818      syscalls:sys_enter_read                                    
           192,154      syscalls:sys_enter_write                                    
                12      syscalls:sys_enter_access                                  
            12,417      syscalls:sys_enter_fchmod                                  
            12,417      syscalls:sys_enter_fchown                                  
                26      syscalls:sys_enter_open                                    
            24,834      syscalls:sys_enter_openat                                  
            12,442      syscalls:sys_enter_close                                                                
  ...
      38.365080478 seconds time elapsed

可以看到,主要的系统调用都是read/write。

使用strace命令可以获得类似的结果,但是strace的成本要高的多。测试结果显示,perf可能让程序变慢2.5倍,而strace则会让程序变慢高达60倍。

统计新建进程 
Shell
1
2
3
4
5
6
7
8
9
10
11
12
perf record -e sched:sched_process_exec -a
# Ctrl-C
perf report -n --sort comm --stdio
 
# Overhead       Samples  Command
# ........  ............  .......
#
    32.14%             9  ionice
    32.14%             9  nice  
    21.43%             6  du    
    10.71%             3  find  
     3.57%             1  ipset  

追踪点sched:sched_process_exec在某个进程调用exec()产生另外一个进程时生效,这通常是新进程的产生方式。但是这个例子的结果不一定准确,原因是:

  1. 进程可能fork()出子进程,追踪点sched:sched_process_fork可以用于这种情况
  2. 应用程序可以reexec —— 针对自己再次调用exec() —— 这种用法可以清空地址空间,但是不会产生新进程
追踪出站连接

某些时候你希望了解服务器发起了哪些网络连接,是哪些进程发起的,为何发起。这些网络连接可能是延迟的根源。

追踪connect系统调用,即可了解出站连接:

Shell
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
perf record -e syscalls:sys_enter_connect -ag
perf report --stdio
 
# Children      Self  Trace output
# ........  ........  ............................................................
#
     5.88%     5.88%  fd: 0x00000005, uservaddr: 0xc4206fa390, addrlen: 0x0000001b
            |
            ---0x894812ebc0312874
               0xc42008e000
               runtime.main
               main.main
               github.com/projectcalico/node/pkg/readiness.Run
               github.com/projectcalico/node/pkg/readiness.checkBIRDReady
               github.com/projectcalico/node/pkg/readiness/bird.GRInProgress
               net.Dial
               net.(*Dialer).Dial
               net.(*Dialer).DialContext
               net.dialSerial
               net.dialSingle
               net.dialUnix
               net.unixSocket
               net.socket
               net.(*netFD).dial
               net.(*netFD).connect
               syscall.Connect
               syscall.Syscall

可以看到,占比最高的出站连接是由Calico Node容器发起的。

追踪套接字缓冲

通过剖析套接字缓冲的使用情况,也是定位到什么代码使用了最多的网络I/O的一种方法:

Shell
1
perf record -e 'skb:consume_skb' -ag
睡眠时间分析

使用perf可以了解应用程序为何休眠、在何处休眠、休眠多久。主要通过收集sched_stat、sched_switch事件实现。

剖析的目标代码如下:

sleep_test
C
1
2
3
4
5
6
7
8
9
10
11
for (i = 0; i <  10; i++) {
        ts1.tv_sec = 0;
        ts1.tv_nsec = 10000000;
        // 休眠
        nanosleep(&ts1, NULL);
 
        tv1.tv_sec = 0;
        tv1.tv_usec = 40000;
        // 休眠
        select(0, NULL, NULL, NULL,&tv1);
}

执行下面的命令开始剖析:

Shell
1
./perf record -e sched:sched_stat_sleep -e sched:sched_switch  -e sched:sched_process_exit -g -o perf.data.raw  sleep_test

合并sched_start、sched_switch事件:

Shell
1
perf inject -v -s -i perf.data.raw -o perf.data

报告:

Shell
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
perf report --stdio --show-total-period -i perf.data
 
  100.00%     502408738      foo  [kernel.kallsyms]  [k] __schedule
               |
               --- __schedule
                   schedule
                  |          
                  |--79.85%-- schedule_hrtimeout_range_clock
                  |          schedule_hrtimeout_range
                  |          poll_schedule_timeout
                  |          do_select
                  |          core_sys_select
                  |          sys_select
                  |          system_call_fastpath
                  |          __select
                  |          __libc_start_main
                  |          
                   --20.15%-- do_nanosleep
                             hrtimer_nanosleep
                             sys_nanosleep
                             system_call_fastpath
                             __GI___libc_nanosleep
                             __libc_start_main

 

← Bazel学习笔记
使用Sysdig进行系统性能分析 →

Leave a Reply Cancel reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code class="" title="" data-url=""> <del datetime=""> <em> <i> <q cite=""> <strike> <strong> <pre class="" title="" data-url=""> <span class="" title="" data-url="">

Related Posts

  • 使用Sysdig进行系统性能分析
  • Go应用性能剖析
  • 使用Chrome开发者工具分析内存泄漏
  • 使用Eclipse Memory Analyzer分析JVM堆Dump
  • 使用Oracle Java Mission Control监控JVM运行状态

Recent Posts

  • Investigating and Solving the Issue of Failed Certificate Request with ZeroSSL and Cert-Manager
  • A Comprehensive Study of Kotlin for Java Developers
  • 背诵营笔记
  • 利用LangChain和语言模型交互
  • 享学营笔记
ABOUT ME

汪震 | Alex Wong

江苏淮安人,现居北京。目前供职于腾讯云,专注容器方向。

GitHub:gmemcc

Git:git.gmem.cc

Email:gmemjunk@gmem.cc@me.com

ABOUT GMEM

绿色记忆是我的个人网站,域名gmem.cc中G是Green的简写,MEM是Memory的简写,CC则是我的小天使彩彩名字的简写。

我在这里记录自己的工作与生活,同时和大家分享一些编程方面的知识。

GMEM HISTORY
v2.00:微风
v1.03:单车旅行
v1.02:夏日版
v1.01:未完成
v0.10:彩虹天堂
v0.01:阳光海岸
MIRROR INFO
Meta
  • Log in
  • Entries RSS
  • Comments RSS
  • WordPress.org
Recent Posts
  • Investigating and Solving the Issue of Failed Certificate Request with ZeroSSL and Cert-Manager
    In this blog post, I will walk ...
  • A Comprehensive Study of Kotlin for Java Developers
    Introduction Purpose of the Study Understanding the Mo ...
  • 背诵营笔记
    Day 1 Find Your Greatness 原文 Greatness. It’s just ...
  • 利用LangChain和语言模型交互
    LangChain是什么 从名字上可以看出来,LangChain可以用来构建自然语言处理能力的链条。它是一个库 ...
  • 享学营笔记
    Unit 1 At home Lesson 1 In the ...
  • K8S集群跨云迁移
    要将K8S集群从一个云服务商迁移到另外一个,需要解决以下问题: 各种K8S资源的迁移 工作负载所挂载的数 ...
  • Terraform快速参考
    简介 Terraform用于实现基础设施即代码(infrastructure as code)—— 通过代码( ...
  • 草缸2021
    经过四个多月的努力,我的小小荷兰景到达极致了状态。

  • 编写Kubernetes风格的APIServer
    背景 前段时间接到一个需求做一个工具,工具将在K8S中运行。需求很适合用控制器模式实现,很自然的就基于kube ...
  • 记录一次KeyDB缓慢的定位过程
    环境说明 运行环境 这个问题出现在一套搭建在虚拟机上的Kubernetes 1.18集群上。集群有三个节点: ...
  • eBPF学习笔记
    简介 BPF,即Berkeley Packet Filter,是一个古老的网络封包过滤机制。它允许从用户空间注 ...
  • IPVS模式下ClusterIP泄露宿主机端口的问题
    问题 在一个启用了IPVS模式kube-proxy的K8S集群中,运行着一个Docker Registry服务 ...
  • 念爷爷
      今天是爷爷的头七,十二月七日、阴历十月廿三中午,老人家与世长辞。   九月初,回家看望刚动完手术的爸爸,发

  • 6 杨梅坑

  • liuhuashan
    深圳人才公园的网红景点 —— 流花山

  • 1 2020年10月拈花湾

  • 内核缺陷触发的NodePort服务63秒延迟问题
    现象 我们有一个新创建的TKE 1.3.0集群,使用基于Galaxy + Flannel(VXLAN模式)的容 ...
  • Galaxy学习笔记
    简介 Galaxy是TKEStack的一个网络组件,支持为TKE集群提供Overlay/Underlay容器网 ...
TOPLINKS
  • Zitahli's blue 91 people like this
  • 梦中的婚礼 64 people like this
  • 汪静好 61 people like this
  • 那年我一岁 36 people like this
  • 为了爱 28 people like this
  • 小绿彩 26 people like this
  • 彩虹姐姐的笑脸 24 people like this
  • 杨梅坑 6 people like this
  • 亚龙湾之旅 1 people like this
  • 汪昌博 people like this
  • 2013年11月香山 10 people like this
  • 2013年7月秦皇岛 6 people like this
  • 2013年6月蓟县盘山 5 people like this
  • 2013年2月梅花山 2 people like this
  • 2013年淮阴自贡迎春灯会 3 people like this
  • 2012年镇江金山游 1 people like this
  • 2012年徽杭古道 9 people like this
  • 2011年清明节后扬州行 1 people like this
  • 2008年十一云龙公园 5 people like this
  • 2008年之秋忆 7 people like this
  • 老照片 13 people like this
  • 火一样的六月 16 people like this
  • 发黄的相片 3 people like this
  • Cesium学习笔记 90 people like this
  • IntelliJ IDEA知识集锦 59 people like this
  • 基于Kurento搭建WebRTC服务器 38 people like this
  • Bazel学习笔记 37 people like this
  • PhoneGap学习笔记 32 people like this
  • NaCl学习笔记 32 people like this
  • 使用Oracle Java Mission Control监控JVM运行状态 29 people like this
  • Ceph学习笔记 27 people like this
  • 基于Calico的CNI 27 people like this
Tag Cloud
ActiveMQ AspectJ CDT Ceph Chrome CNI Command Cordova Coroutine CXF Cygwin DNS Docker eBPF Eclipse ExtJS F7 FAQ Groovy Hibernate HTTP IntelliJ IO编程 IPVS JacksonJSON JMS JSON JVM K8S kernel LB libvirt Linux知识 Linux编程 LOG Maven MinGW Mock Monitoring Multimedia MVC MySQL netfs Netty Nginx NIO Node.js NoSQL Oracle PDT PHP Redis RPC Scheduler ServiceMesh SNMP Spring SSL svn Tomcat TSDB Ubuntu WebGL WebRTC WebService WebSocket wxWidgets XDebug XML XPath XRM ZooKeeper 亚龙湾 单元测试 学习笔记 实时处理 并发编程 彩姐 性能剖析 性能调优 文本处理 新特性 架构模式 系统编程 网络编程 视频监控 设计模式 远程调试 配置文件 齐塔莉
Recent Comments
  • qg on Istio中的透明代理问题
  • heao on 基于本地gRPC的Go插件系统
  • 黄豆豆 on Ginkgo学习笔记
  • cloud on OpenStack学习笔记
  • 5dragoncon on Cilium学习笔记
  • Archeb on 重温iptables
  • C/C++编程:WebSocketpp(Linux + Clion + boostAsio) – 源码巴士 on 基于C/C++的WebSocket库
  • jerbin on eBPF学习笔记
  • point on Istio中的透明代理问题
  • G on Istio中的透明代理问题
  • 绿色记忆:Go语言单元测试和仿冒 on Ginkgo学习笔记
  • point on Istio中的透明代理问题
  • 【Maven】maven插件开发实战 – IT汇 on Maven插件开发
  • chenlx on eBPF学习笔记
  • Alex on eBPF学习笔记
  • CFC4N on eBPF学习笔记
  • 李运田 on 念爷爷
  • yongman on 记录一次KeyDB缓慢的定位过程
  • Alex on Istio中的透明代理问题
  • will on Istio中的透明代理问题
  • will on Istio中的透明代理问题
  • haolipeng on 基于本地gRPC的Go插件系统
  • 吴杰 on 基于C/C++的WebSocket库
©2005-2025 Gmem.cc | Powered by WordPress | 京ICP备18007345号-2