性能分析利器火焰图（2）- 火焰图绘制原理

IKNOW本尊
5,369 阅读4分钟

参考：

性能调优利器：火焰图-InfoQ

什么是火焰图？什么是火焰图？

火焰图（Flame Graph）是由 Linux 性能优化大师 Brendan Gregg 发明的，和所有其他的 profiling 方法不同的是，火焰图以一个全局的视野来看待时间分布，它从底部往顶部，列出所有可能导致性能瓶颈的调用栈。

2.png

如上图是我们服务的一个方法在一段时间内的火焰图示例，这边我抓取的是on-cpu的火焰图

火焰图有以下特征（这里以 on-cpu 火焰图为例）：

  • 每一列代表一个调用栈，每一个格子代表一个函数
  • 纵轴展示了栈的深度，按照调用关系从下到上排列。最顶上格子代表采样时，正在占用 cpu 的函数。
  • 横轴的意义是指：火焰图将采集的多个调用栈信息，通过按字母横向排序的方式将众多信息聚合在一起。需要注意的是它并不代表时间。
  • 横轴格子的宽度代表其在采样中出现频率，所以一个格子的宽度越大，说明它是瓶颈原因的可能性就越大。
  • 火焰图格子的颜色是随机的暖色调，方便区分各个调用信息。
  • 其他的采样方式也可以使用火焰图， on-cpu 火焰图横轴是指 cpu 占用时间，off-cpu 火焰图横轴则代表阻塞时间。

火焰图原理火焰图原理

火焰图可以分为很多的类型，有cpu的火焰图，有内存火焰图，io火焰图等等，本文只分析CPU的火焰图

分析CPU火焰图之前我们再来回顾下任务与CPU的两种状态关系：

on-cpu vs off-cpu

  • on-cpu: where threads are spending time running on-CPU.（线程花费在CPU上的时间）
  • off-cpu: where time is spent waiting while blocked on I/O, locks, timers, paging/swapping, etc. (线程花费在等待I/O, 锁, 页内存或者页交换的时间)

我们要针对我们程序或者服务的情况特殊分析，才可能对特定的情况针对性的进行分析，然后再用火焰图来分析程序性能问题是一种很有效的手段。

绘制火焰图

  火焰图是分析程序运行性能的利器，是帮助我们分析程序有可能出现的性能瓶颈，OK，我们先看如果没有火焰图我们如何去分析程序运行状况

  1. 绘制 on-cpu 火焰图的过程

    • 先trace系统，获取系统的profiling数据 ，现在比较方便的获取系统的profiling的工具有（perf、systemap，arthas）
    • 用脚本绘制

  2. 测试代码 CpuGraphTest.c：

    #include <stdio.h>
#include <pthread.h>
#include <unistd.h>

void fun_1() {
    int a = 0;
    for(a = 0; a < 10000 * 5; a = a + 1 );
}

void fun_2() {
    int a = 0;
    fun_1();
    for(a = 0; a < 10000 * 10; a = a + 1 );
}
void fun_3() {
    int a = 0;
    for(a = 0; a < 10000 * 20; a = a + 1 );
}
void fun_4() {
    int a = 0;
    for( a = 0; a < 10000 * 30; a = a + 1 );
}

void *fun_test(void *args) {
    while(1){
        int a = 0;
        for( a = 0; a < 10000 * 10; a = a + 1 );
        fun_2();
        fun_3();
        fun_4();
    }
}
int main() {
    pthread_t t1,t2;
    pthread_create(&t1, NULL, fun_test, NULL);
    pthread_create(&t2, NULL, fun_test, NULL);
    pthread_join(t1, NULL);
    pthread_join(t2, NULL);
    return 0;
}

  3. 代码分析：

    我们先不用火焰图进行分析，先自己分析下这段代码，对于线程启动后的程序运行过程我们可以估算出每个方法执行的时长

    fun_4                                                            10000 * 30
fun_3                                               10000 * 20  
fun_2                     10000 * 5 + 10000 * 10 
fun_1                     10000 * 5
fun_test: 10000 * 10  +  (10000 * 5  + 10000 * 10) + 10000 * 20 + 10000 * 30

假设我们fun_test 整个跑了 75 s
那么按照比例 
fun_2 = (10000 * 10) / (10000 * 10  + (10000 * 10  + 10000 * 5) + 10000 * 20 + 10000 * 30) * 75= 10s  16%  
fun_1 = (10000 * 5) / (10000 * 10  + (10000 * 10  + 10000 * 5) + 10000 * 20 + 10000 * 30) * 75 = 5s   6%
fun_3 = (10000 * 20) / (10000 * 10  + (10000 * 10  + 10000 * 5) + 10000 * 20 + 10000 * 30) * 75 = 20s 26%
fun_4 = (10000 * 30) / (10000 * 10  + (10000 * 10  + 10000 * 5) + 10000 * 20 + 10000 * 30) * 75 = 30s 40%

3.png

  1. perf 工具分析

    • yum install pref
    • gcc cpu_graph_test.c -lpthread -o cpu_graph_test
    • ./cpu_graph_test
    • sudo perf top

4.png 但是这样的数据只能看到每个函数内部的代码执行的花费，并不能看到全局的堆栈，因为按照堆栈来说，fun_2的执行时间是要包含fun_1的时间的，我们换种方式去查看稍微直观点的

  • sudo perf record -F 99 -a -g -p 17930 -- sleep 60

    • 上面的代码中，perf record表示记录，F 99表示每秒99次，p 'pidof a.out'是进程号，即对哪个进程进行分析，g表示记录调用栈，sleep 60`则是持续60秒。

  • sudo perf report -n --stdio

5.png

但是这样的结果在比较庞大且复杂的调用链中还是无法直观的观察，接下来我们用火焰完成这个分析
  1. FlameGraph 火焰图绘制工具

FlameGraph只是系统的 profiling 数据的加工和展示工具，在日常的使用中我们还需要通过 pref或者systemap等工具先抓取系统运行数据，才可以利用FlameGraph加工分析, 将上一步中 - sudo perf report -n --stdio 获取到的采样数据通过火焰图绘制出来

  • 下载火焰图的代码

    • git clone https://github.com/brendangregg/FlameGraph and cd FlameGraph

  • 加工折叠堆栈数据

    • 通过FlameGraph 的 perf script | ./stackcollapse-perf.pl > out.perf-folded 加工折叠堆栈数据

  • 通过 FlameGraph绘制火焰图数据

    • ./flamegraph.pl out.perf-folded > perf.svg 最后在利用 flamegraph.pl 将加工后的数据绘制成火焰图

  • 在当前目录启动一个文件服务器 python -m SimpleHTTPServer

  • 访问文件服务目录

6.png

  1. systemtap 分析

  • 安装 www.linuxidc.com/Linux/2019-… （仅限参考，比较难安装）

  • 安装 openresty-systemtap-toolki

  • cd openresty-systemtap-toolkit

  • 采集数据输出：./sample-bt -p ’pidof cpu_graph_test‘ -t 20 -u -a '-vv' -d

  • 采集数据：./sample-bt -p ’pidof cpu_graph_test‘ -t 20 -u > tmp.bt

    • -t代表监测10s，-u表示监测用户态

  • 利用flamegraph 对采集的数据进行加工（折叠堆栈数据）

    • ./stackcollapse-stap.pl tmp.bt > flame.cbt
    • flamegraph.pl flame.cbt > flame.svg

  • 在当前目录启动一个文件服务器 python -m SimpleHTTPServer

  • 访问文件服务目录

7.png

on-cpu 火焰图采样原理

不管perf还是systemap的采样都是在单位时间内，对系统中运行的代码堆栈做多次（可指定）的统计统计，在每次统计的时候，找到这个时刻还在执行的堆栈并进行计数，类似于有一个监视器，隔一段时间，就来看下还在系统中的堆栈，如果看到了对改堆栈计数加1，这样一直在CPU上运行的堆栈就会占比很大，通过这样的方式来计算的，并不是计算这个方法执行了多久。

8.png

可以看到systemap的计算规则就是启动了一个定时器，执行定时器，来对 bts<堆栈，计数> 指定堆栈的计数更新，达到在一定时间范围内对系统运行堆栈数据的抓取

off-cpu的火焰图

3.1 测试代码：

#include <stdio.h>
#include <pthread.h>
#include <unistd.h>

pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER;

void *fun_test(void *args) {
    while(1){
        pthread_mutex_lock(&mutex);
        usleep(3);
        pthread_mutex_unlock(&mutex);
        int a = 0;
        for(a = 0; a < 10000 ; a = a + 1 ){
            printf("hello world\n");
            }
        }
}
int main() {
    int num = 100;
    pthread_t threads[num];
    int i;
    for (i = 0; i < num; ++i) {
        pthread_create(&threads[i], NULL, fun_test, NULL);
    }
    for (i = 0; i < num; ++i) {
        pthread_join(threads[i], NULL);
    }
    return 0;
}

3.2 代码分析：

从上面代码中我们可以分析到，从mian函数中我们创建了100个线程去执行fun_test 方法
1. fun_test中会调用所有的线程都回去竞争全局锁 mutex 拿到的线程再去执行 usleep 3微妙，
2. 拿到锁的线程然后打印1000次的hello world

在上述的两个过程中是存在会出现off-cpu的地方
1. 一个发生在因为usleep 导致竞争锁的时候
2. 一个发生在打印的时候，打印的时候会进行sys_write系统调用后，sys_write中有一个tty_write的n_tty_write等待一个mutex的代码上面。

3.3 绘制火焰图

  • sudo ./sample-bt-off-cpu -p 'pidof a.out' -t 20 -u > off_tmp.bt

  • 折叠堆栈数据，绘制火焰图

    • ./stackcollapse-stap.pl off_tmp.bt > off_flame.cbt
    • ./flamegraph.pl off_flame.cbt > off_flame.svg

    https://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/03b5859e9e2c4620a8397b9c8effd951~tplv-k3u1fbpfcp-zoom-1.image

3.4 sample-bt-off-cpu 采集off-cpu数据的原理

可以看到sample-bt-off-cpu 是监听了获取到CPU和失去CPU的两个事件，通过这两个事件之前的时间差值计算出，进程在0ff-cpu上的时间，然后通过时间计算出进程在off-cpu的比例，与获取on-cpu不同的是，on-cpu是根据定时器很高频率的对还在运行中的堆栈做计数计算的，但是off-cpu是监听的是进程在cpu获取和失去的时间差值统计的。

https://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/3470b1b43398498a972d58c071eba8d3~tplv-k3u1fbpfcp-zoom-1.image

avatar
文章
阅读
粉丝