目录

​零、即看即用​

​一、perf 命令​

​二、火焰图的含义​

​三、互动性​

​四、火焰图示例​

​五、局限​

​六、Node 应用的火焰图​

​七、浏览器的火焰图​

​八、参考链接​

​九、其他类似工具​

​十、perf工具远比上面讲的更强大​

​perf top​

​perf stat​

​perf record​

​perf report​

​十一、perf命令详情 ​



零、即看即用

 前提:下载flamegraph工具包

git clone ​​GitHub - brendangregg/FlameGraph: Stack trace visualizer​

方法一、

第1步、监测进程

$ sudo perf record -F 99 -p 13204 -g -- sleep 30

-p ​​13204:​​监测进程号​​13204 (如果想监视线程则用 -t 6665 #6665为线程号)​

-F 99:频率是 99Hz(每秒99次)

​-g:​​表示记录调用栈

​--sleep 30:​​持续30秒。

Ctrl+c结束执行后,在当前目录下会生成采样数据perf.data.

第2步、 解析数据

用perf script工具对perf.data进行解析

perf script -i perf.data &> perf.unfold

第3步、符号进行折叠

将perf.unfold中的符号进行折叠:

#./stackcollapse-perf.pl perf.unfold &> perf.folded

第4步、生成svg图

./flamegraph.pl perf.folded > perf-$(date +%Y%m%d-%H:%M:%S).svg

【性能】perf + 火焰图分析软件性能瓶颈_调用栈

方法二、

1,perf record --call-graph dwarf -p 12345

2,perf script | FlameGraph/stackcollapse-perf.pl | FlameGraph/flamegraph.pl > process.svg

一、perf 命令

让我们从 perf 命令(performance 的缩写)讲起,它是 Linux 系统原生提供的性能分析工具,会返回 CPU 正在执行的函数名以及调用栈(stack)。

通常,它的执行频率是 99Hz(每秒99次),如果99次都返回同一个函数名,那就说明 CPU 这一秒钟都在执行同一个函数,可能存在性能问题。

​13204​​是进程号

$ sudo perf record -F 99 -p 13204 -g -- sleep 30

上面的代码中,​​perf record​​表示记录,​​-F 99​​表示每秒99次,​​-p 13204​​是进程号,即对哪个进程进行分析,​​-g​​表示记录调用栈,​​sleep 30​​则是持续30秒。

运行后会产生一个庞大的文本文件。如果一台服务器有16个 CPU,每秒抽样99次,持续30秒,就得到 47,520 个调用栈,长达几十万甚至上百万行。

举例:

sudo perf record -e cpu-clock -g -p 2548

-g 选项是告诉perf record额外记录函数的调用关系

-e cpu-clock 指perf record监控的指标为cpu周期

-p 指定需要record的进程pid

为了便于阅读,​​perf record​​命令可以统计每个调用栈出现的百分比,然后从高到低排列。


$ sudo perf report -n --stdio

【性能】perf + 火焰图分析软件性能瓶颈_执行时间_02

这个结果还是不易读,所以才有了火焰图。

生成火焰图

1、Flame Graph项目位于GitHub上:​​GitHub - brendangregg/FlameGraph: Stack trace visualizer​

2、可以用git将其clone下来:git clone ​​GitHub - brendangregg/FlameGraph: Stack trace visualizer​

我们以perf为例,看一下flamegraph的使用方法:

1、第一步

$sudo perf record -e cpu-clock -g -p 28591

Ctrl+c结束执行后,在当前目录下会生成采样数据perf.data.

2、第二步

用perf script工具对perf.data进行解析

perf script -i perf.data &> perf.unfold

3、第三步

将perf.unfold中的符号进行折叠:

#./stackcollapse-perf.pl perf.unfold &> perf.folded

4、最后生成svg图:

./flamegraph.pl perf.folded > perf.svg

【性能】perf + 火焰图分析软件性能瓶颈_调用栈

二、火焰图的含义

火焰图是基于 perf 结果产生的 ​​SVG 图片​​,用来展示 CPU 的调用栈。

【性能】perf + 火焰图分析软件性能瓶颈_linux_04

y 轴表示调用栈,每一层都是一个函数。调用栈越深,火焰就越高,顶部就是正在执行的函数,下方都是它的父函数。

x 轴表示抽样数,如果一个函数在 x 轴占据的宽度越宽,就表示它被抽到的次数多,即执行的时间长。注意,x 轴不代表时间,而是所有的调用栈合并后,按字母顺序排列的。

火焰图就是看顶层的哪个函数占据的宽度最大。只要有"平顶"(plateaus),就表示该函数可能存在性能问题。

颜色没有特殊含义,因为火焰图表示的是 CPU 的繁忙程度,所以一般选择暖色调。

三、互动性

火焰图是 ​​SVG 图片​​,可以与用户互动。

(1)鼠标悬浮

火焰的每一层都会标注函数名,鼠标悬浮时会显示完整的函数名、抽样抽中的次数、占据总抽样次数的百分比。下面是一个例子。


mysqld'JOIN::exec (272,959 samples, 78.34 percent)

(2)点击放大

在某一层点击,火焰图会水平放大,该层会占据所有宽度,显示详细信息。

【性能】perf + 火焰图分析软件性能瓶颈_执行时间_05

左上角会同时显示"Reset Zoom",点击该链接,图片就会恢复原样。

(3)搜索

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

四、火焰图示例

下面是一个简化的火焰图例子。

首先,CPU 抽样得到了三个调用栈。


func_c
func_b
func_a
start_thread

func_d
func_a
start_thread

func_d
func_a
start_thread

上面代码中,​​start_thread​​是启动线程,调用了​​func_a​​。后者又调用了​​func_b​​和​​func_d​​,而​​func_b​​又调用了​​func_c​​。

经过合并处理后,得到了下面的结果,即存在两个调用栈,第一个调用栈抽中1次,第二个抽中2次。


start_thread;func_a;func_b;func_c 1
start_thread;func_a;func_d 2

有了这个调用栈统计,​​火焰图工具​​就能生成 SVG 图片。

【性能】perf + 火焰图分析软件性能瓶颈_调用栈_06

上面图片中,最顶层的函数​​g()​​占用 CPU 时间最多。​​d()​​的宽度大,但是它直接耗用 CPU 的部分很少(主要是d()内调用的e()和f()消耗)。​​b()​​和​​c()​​没有直接消耗 CPU(因为一层一层调用,最终上c()内调用的函数消耗cpu)。因此,如果要调查性能问题,首先应该调查​​g()​​,其次是​​i()​​。

另外,从图中可知​​a()​​有两个分支​​b()​​和​​h()​​,这表明​​a()​​里面可能有一个条件语句,而​​b()​​分支消耗的 CPU 大大高于​​h()​​。

五、局限

两种情况下,无法画出火焰图,需要修正系统行为。

(1)调用栈不完整

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

(2)函数名缺失

有些函数没有名字,编译器只用内存地址来表示(比如匿名函数)。

六、Node 应用的火焰图

Node 应用的火焰图就是对 Node 进程进行性能抽样,与其他应用的操作是一样的。


$ perf record -F 99 -p `pgrep -n node` -g -- sleep 30

详细的操作可以看​​这篇文章​​。

七、浏览器的火焰图

Chrome 浏览器可以生成页面脚本的火焰图,用来进行 CPU 分析。

打开开发者工具,切换到 Performance 面板。然后,点击"录制"按钮,开始记录数据。这时,可以在页面进行各种操作,然后停止"录制"。

这时,开发者工具会显示一个时间轴。它的下方就是火焰图。

【性能】perf + 火焰图分析软件性能瓶颈_性能分析_07

浏览器的火焰图与标准火焰图有两点差异:它是倒置的(即调用栈最顶端的函数在最下方);x 轴是时间轴,而不是抽样次数。

【性能】perf + 火焰图分析软件性能瓶颈_执行时间_08

八、参考链接

摘自:​ ​​如何读懂火焰图? - 阮一峰的网络日志​

九、其他类似工具

vtune

十、perf工具远比上面讲的更强大

perf top

perf top类似top命令,主要用于实时分析各个函数在某个性能事件上的热度,能够快速的定位热点函数,包括应用程序函数、

模块函数与内核函数,甚至能够定位到热点指令。默认的性能事件为cpu cycles。

perf stat

用于输出指定程序的性能统计数据

perf record

perf record收集采样信息,并记录在文件中,可以离线分析。使用下面的 perf report解析收集的采样数据文件。

perf report

perf report 主要用来分析上面perf record生成的perf.data文件。

更多详情:

十一、perf命令详情 

perf是Linux下的一款性能分析工具,能够进行函数级与指令级的热点查找。

Perf List
利用perf剖析程序性能时,需要指定当前测试的性能时间。性能事件是指在处理器或操作系统中发生的,可能影响到程序性能的硬件事件或软件事件


Perf top
实时显示系统/进程的性能统计信息

常用参数

-e:指定性能事件

-a:显示在所有CPU上的性能统计信息

-C:显示在指定CPU上的性能统计信息

-p:指定进程PID

-t:指定线程TID

-K:隐藏内核统计信息

-U:隐藏用户空间的统计信息

-s:指定待解析的符号信息

‘‐G’ or‘‐‐call‐graph’ <output_type,min_percent,call_order>

graph: 使用调用树,将每条调用路径进一步折叠。这种显示方式更加直观。

每条调用路径的采样率为绝对值。也就是该条路径占整个采样域的比率。

fractal

默认选项。类似与 graph,但是每条路径前的采样率为相对值。

flat

不折叠各条调用

选项 call_order 用以设定调用图谱的显示顺序,该选项有 2个取值,分别是

callee 与caller。

将该选项设为callee 时,perf按照被调用的顺序显示调用图谱,上层函数被下层函数所调用。

该选项被设为caller 时,按照调用顺序显示调用图谱,即上层函数调用了下层函数路径,也不显示每条调用路径的采样率

注: Perf top需要root权限


Perf stat
分析系统/进程的整体性能概况

task‐clock事件表示目标任务真正占用处理器的时间,单位是毫秒。也称任务执行时间

context-switches是系统发生上下文切换的次数

CPU-migrations是任务从一个处理器迁往另外一个处理器的次数

page-faults是内核发生缺页的次数

cycles是程序消耗的处理器周期数

instructions是指命令执行期间产生的处理器指令数

branches是指程序在执行期间遇到的分支指令数。

branch‐misses是预测错误的分支指令数。

XXX seconds time elapsed系程序持续时间

任务执行时间/任务持续时间大于1,那可以肯定是多核引起的

参数设置:

-e:选择性能事件

-i:禁止子任务继承父任务的性能计数器。

-r:重复执行 n 次目标程序,并给出性能指标在n 次执行中的变化范围。

-n:仅输出目标程序的执行时间,而不开启任何性能计数器。

-a:指定全部cpu

-C:指定某个cpu

-A:将给出每个处理器上相应的信息。

-p:指定待分析的进程id

-t:指定待分析的线程id


Perf record
记录一段时间内系统/进程的性能时间

参数:

-e:选择性能事件

-p:待分析进程的id

-t:待分析线程的id

-a:分析整个系统的性能

-C:只采集指定CPU数据

-c:事件的采样周期

-o:指定输出文件,默认为perf.data

-A:以append的方式写输出文件

-f:以OverWrite的方式写输出文件

-g:记录函数间的调用关系


Perf Report
读取perf record生成的数据文件,并显示分析数据

参数

-i:输入的数据文件

-v:显示每个符号的地址

-d <dos>:只显示指定dos的符号

-C:只显示指定comm的信息(Comm. 触发事件的进程名)

-S:只考虑指定符号

-U:只显示已解析的符号

-g[type,min,order]:显示调用关系,具体等同于perf top命令中的-g

-c:只显示指定cpu采样信息

-M:以指定汇编指令风格显示

–source:以汇编和source的形式进行显示

-p<regex>:用指定正则表达式过滤调用函数

例1

# perf top -e cycles:k     #显示内核和模块中,消耗最多CPU周期的函数

# perf top -e kmem:kmem_cache_alloc #显示分配高速缓存最多的函数

# perf top

Samples: 1M of event 'cycles', Event count (approx.): 73891391490
5.44% perf [.] 0x0000000000023256
4.86% [kernel] [k] _spin_lock
2.43% [kernel] [k] _spin_lock_bh
2.29% [kernel] [k] _spin_lock_irqsave
1.77% [kernel] [k] __d_lookup
1.55% libc-2.12.so [.] __strcmp_sse42
1.43% nginx [.] ngx_vslprintf
1.37% [kernel] [k] tcp_poll
第一列:符号引发的性能事件的比例,默认指占用的cpu周期比例。
第二列:符号所在的DSO(Dynamic Shared Object),可以是应用程序、内核、动态链接库、模块。
第三列:DSO的类型。[.]表示此符号属于用户态的ELF文件,包括可执行文件与动态链接库)。[k]表述此符号属于内核或模块。
第四列:符号名。有些符号不能解析为函数名,只能用地址表示。

例2

# perf top -G         #得到调用关系图

# perf top -e cycles #指定性能事件

# perf top -p 23015,32476 #查看这两个进程的cpu cycles使用情况

# perf top -s comm,pid,symbol #显示调用symbol的进程名和进程号

# perf top --comms nginx,top #仅显示属于指定进程的符号

# perf top --symbols kfree #仅显示指定的符号

例3

#  perf stat ls 

Performance counter stats for 'ls':

0.653782 task-clock # 0.691 CPUs utilized
0 context-switches # 0.000 K/sec
0 CPU-migrations # 0.000 K/sec
247 page-faults # 0.378 M/sec
1,625,426 cycles # 2.486 GHz
1,050,293 stalled-cycles-frontend # 64.62% frontend cycles idle
838,781 stalled-cycles-backend # 51.60% backend cycles idle
1,055,735 instructions # 0.65 insns per cycle
# 0.99 stalled cycles per insn
210,587 branches # 322.106 M/sec
10,809 branch-misses # 5.13% of all branches

0.000945883 seconds time elapsed

输出包括ls的执行时间,以及10个性能事件的统计。

task-clock:任务真正占用的处理器时间,单位为ms。CPUs utilized = task-clock / time elapsed,CPU的占用率。

context-switches:上下文的切换次数。

CPU-migrations:处理器迁移次数。Linux为了维持多个处理器的负载均衡,在特定条件下会将某个任务从一个CPU

迁移到另一个CPU。

page-faults:缺页异常的次数。当应用程序请求的页面尚未建立、请求的页面不在内存中,或者请求的页面虽然在内

存中,但物理地址和虚拟地址的映射关系尚未建立时,都会触发一次缺页异常。另外TLB不命中,页面访问权限不匹配

等情况也会触发缺页异常。

cycles:消耗的处理器周期数。如果把被ls使用的cpu cycles看成是一个处理器的,那么它的主频为2.486GHz。

可以用cycles / task-clock算出。

stalled-cycles-frontend:略过。

stalled-cycles-backend:略过。

instructions:执行了多少条指令。IPC为平均每个cpu cycle执行了多少条指令。

branches:遇到的分支指令数。branch-misses是预测错误的分支指令数。


# perf stat -r 10 ls > /dev/null #执行10次程序,给出标准偏差与期望的比值

# perf stat -v ls > /dev/null #显示更详细的信息

# perf stat -n ls > /dev/null #只显示任务执行时间,不显示性能计数器

# perf stat -a -A ls > /dev/null #单独给出每个CPU上的信息

# perf stat -e syscalls:sys_enter ls #ls命令执行了多少次系统调用

例4

#  perf record -p `pgrep -d ',' nginx`      #记录nginx进程的性能数据

# perf record ls -g #记录执行ls时的性能数据

# perf record -e syscalls:sys_enter ls #记录执行ls时的系统调用,可以知道哪些系统调用最频繁

例5

#   perf lock record ls      #记录

# perf lock report #报告

Name acquired contended total wait (ns) max wait (ns) min wait (ns)

&mm->page_table_... 382 0 0 0 0
&mm->page_table_... 72 0 0 0 0
&fs->lock 64 0 0 0 0
dcache_lock 62 0 0 0 0
vfsmount_lock 43 0 0 0 0
&newf->file_lock... 41 0 0 0 0

Name:内核锁的名字。
aquired:该锁被直接获得的次数,因为没有其它内核路径占用该锁,此时不用等待。
contended:该锁等待后获得的次数,此时被其它内核路径占用,需要等待。
total wait:为了获得该锁,总共的等待时间。
max wait:为了获得该锁,最大的等待时间。
min wait:为了获得该锁,最小的等待时间。

例6

#  perf kmem record ls      #记录

# perf kmem stat --caller --alloc -l 20 #报告

------------------------------------------------------------------------------------------------------
Callsite | Total_alloc/Per | Total_req/Per | Hit | Ping-pong | Frag
------------------------------------------------------------------------------------------------------
perf_event_mmap+ec | 311296/8192 | 155952/4104 | 38 | 0 | 49.902%
proc_reg_open+41 | 64/64 | 40/40 | 1 | 0 | 37.500%
__kmalloc_node+4d | 1024/1024 | 664/664 | 1 | 0 | 35.156%
ext3_readdir+5bd | 64/64 | 48/48 | 1 | 0 | 25.000%
load_elf_binary+8ec | 512/512 | 392/392 | 1 | 0 | 23.438%

Callsite:内核代码中调用kmalloc和kfree的地方。
Total_alloc/Per:总共分配的内存大小,平均每次分配的内存大小。
Total_req/Per:总共请求的内存大小,平均每次请求的内存大小。
Hit:调用的次数。
Ping-pong:kmalloc和kfree不被同一个CPU执行时的次数,这会导致cache效率降低。
Frag:碎片所占的百分比,碎片 = 分配的内存 - 请求的内存,这部分是浪费的。
有使用--alloc选项,还会看到Alloc Ptr,即所分配内存的地址。

例7

#  perf sched record sleep 10    

# perf report latency --sort max

---------------------------------------------------------------------------------------------------------------
Task | Runtime ms | Switches | Average delay ms | Maximum delay ms | Maximum delay at |
---------------------------------------------------------------------------------------------------------------
events/10:61 | 0.655 ms | 10 | avg: 0.045 ms | max: 0.161 ms | max at: 9804.958730 s
sleep:11156 | 2.263 ms | 4 | avg: 0.052 ms | max: 0.118 ms | max at: 9804.865552 s
edac-poller:1125 | 0.598 ms | 10 | avg: 0.042 ms | max: 0.113 ms | max at: 9804.958698 s
events/2:53 | 0.676 ms | 10 | avg: 0.037 ms | max: 0.102 ms | max at: 9814.751605 s
perf:11155 | 2.109 ms | 1 | avg: 0.068 ms | max: 0.068 ms | max at: 9814.867918 s

TASK:进程名和pid。
Runtime:实际的运行时间。
Switches:进程切换的次数。
Average delay:平均的调度延迟。
Maximum delay:最大的调度延迟。
Maximum delay at:最大调度延迟发生的时刻。

例8

#  perf probe --line schedule    #前面有行号的可以探测,没有行号的就不行了

# perf report latency --sort max #在schedule函数的12处增加一个探测点