linux 系统性能问题分析工具及套路 - 极术社区

目录
综述
perf

2.1. 是什么

2.2. counting 模式：perf stat

2.3. sampling 模式：perf record

2.3.1. 两种采样模式

2.3.2. 结果分析：火焰图

ftrace

3.1. 基本使用范式

3.1.1. 函数筛选

3.1.2. 追踪栈回溯

3.2. 高阶用法：获取函数调用耗时

3.3. 套路总结

tracepoint

4.1. 是什么

4.2. 基本原理

4.3. 查看 tracepoint

4.3.1. perf list

4.3.2. tracefs

4.4. 使用方式

4.4.1. perf stat

4.4.2. tracefs

kprobe

5.1. 是什么

5.2. 基本原理

5.3. 使用方式

5.3.1. 内核态 register_kprobe

5.3.2. tracefs 使用方式

eBPF/BCC/bpfTrace

6.1. ebpf

6.2. BCC

6.3. bpftrace

strace

1. 综述

本文对 linux 系统性能问题分析的常见工具及套路做了一个逻辑梗概上的梳理，旨在建立一个手册型的速查文档。

笔者认为了解工具可以用来做什么，比了解工具具体怎么用更有价值，所以本文不会过多展开工具的具体用法。对具体用法感兴趣的读者，自行参阅工具的帮助文档，或者网上翻阅相关文章。

本文基于 4.9 内核。

2. perf

2.1. 是什么

perf 的基本工作原理，参考本号的 perf 系列文章。

如你所知，PMU 底层的性能指标，在 perf 接口层对应的是事件：

# 查看系统中所支持的事件列表
$ perf list

如你所知，对于未在 perf list 之列的硬件事件，可以通过查阅 spec 获取其 event id、umask，再通过 raw 事件读取，sth like：

# 统计 1s 内 eventid 为 0xf2，umask 为 0x01 的事件数
$ perf stat -e cycles -e cpu/event=0xf2,umask=0x01/ -a sleep 1

2.2. counting 模式：perf stat

# perf stat 用来做 counting 统计
# 下面这个命令统计 1s 内 page-faults 这个 software PMU 事件数
$ perf stat -e page-faults -- sleep 1

2.3. sampling 模式：perf record

# 以 sampling 模式，采样 10s 内，CPU4 上的 CPU 上下文（函数调用）情况
# 注意，如果不加 -e 指定事件，默认就是 cycles 这个 hardware PMU 事件。
$ perf record -C 4 -g -- sleep 10

2.3.1. 两种采样模式

# 模式 1：每 10000 cycles 采样一次，这是以事件的出现频率作为采样触发条件
$ perf record -e cycles -c 10000 -- sleep 1

# 模式 2：每秒采样 999 次，这是以固定时间频率作为采样触发条件
$ perf record -e cycles -F 999 -- sleep 1

2.3.2. 结果分析：火焰图

在 perf record 运行完毕后，会在当前目录下生成一个 perf.data 文件，该文件记录了采样信息，若要可视化分析此采样信息，有两种手法：1. 直接运行 perf report 查看函数或指令在采样里的分布比例，2. 使用火焰图做可视化分析。

火焰图的生成：

$ perf record -a -g -- sleep 60
$ perf script > out.perf

$ git clone --depth 1 https://github.com/brendangregg/FlameGraph.git

$ FlameGraph/stackcollapse-perf.pl out.perf > out.folded
$ FlameGraph/flamegraph.pl out.folded > out.sv

3. ftrace

ftrace 的实现原理，参考本号《浅度剖析 ftrace 实现原理》系列文章。

ftrace 的详细使用指南，参阅内核文档 Documentation/trace/ftrace.txt。建议充分阅读

3.1. 基本使用范式

ftrace 系统是以 tracefs 虚拟文件系统挂载在系统之上的，对 ftrace 的使用基于一系列 tracefs 下的基本文件路径操作。

# 查看 tracefs 挂载点
$ cat /proc/mounts | grep tracefs

# ftrace 的可配置文件项
$ cd /sys/kernel/debug/tracing
$ ls

# 查看可以使用的 tracer 类型
# cat available_tracer
shwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop

# 设置启用 function tracer
$ echo function > current_tracer

# 查看 trace 结果
$ cat trace | more

3.1.1. 函数筛选

以上是 ftrace 的基本使用套路，但如果直接按上述套路去用，会发现 cat trace 的输出中有太多我们所不关心的函数信息。

ftrace 系统提供了两种 filter，可以让我们筛选所关心的目标函数：1. set_ftrace_filter：按照函数名做筛选；2. set_ftrace_pid：按照进程做筛选：

# 清空 trace
$ echo nop > current_tracer

# 设置过滤只 trace do_mount 函数
$ echo do_mount > set_ftrace_filter
$ echo function > current_tracer

看一下筛选后的效果：

$ mount -t resctrl resctrl /sys/fs/resctrl

$ cat trace
# tracer: function
#
# entries-in-buffer/entries-written: 24/24   #P:96
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
           <...>-75837 [000] .... 30325301.811254: do_mount <-SyS_mount

至于为什么没有正确显示 TASK 的名字（mount 命令），不管了。

3.1.2. 追踪栈回溯

上面的 trace 没有打印出完整的栈回溯，有点不太过瘾，有办法可以解决：

# 使能栈回溯
$ echo 1 > options/func_stack_trace

$ umount /sys/fs/resctrl/ && mount -t resctrl resctrl /sys/fs/resctrl/

$ cat trace
# tracer: function
#
# entries-in-buffer/entries-written: 24/24   #P:96
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
           <...>-79500 [050] .... 30325554.627401: do_mount <-SyS_mount
           <...>-79500 [050] .... 30325554.627404: <stack trace>
 => do_syscall_64
 => entry_SYSCALL_64_after_swapgs

3.2. 高阶用法：获取函数调用耗时

function tracer 无法获取函数调用的准确耗时信息，咋整？使用 function_graph tracer：


# 采用 function_graph tracer
$ echo function_graph > current_tracer

$ umount /sys/fs/resctrl/ && mount -t resctrl resctrl /sys/fs/resctrl/

$ cat trace
# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |
  78) ! 849.120 us  |  do_mount();

通过 set_graph_function 还可以进一步展示相关函数及其子函数调用关系及时间明细：

# 取消此前设置的 do_mount filter
$ echo '!do_mount' >> set_ftrace_filter

# 设置 kfree_skb 的 set_graph_function
$ echo kfree_skb > set_graph_function

# 清空 trace
$ echo nop > current_tracer

# 使用 function_graph tracer
$ echo function_graph > current_tracer

$ cat trace
# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |
  77)               |  kfree_skb() {
  77)               |    skb_release_all() {
  77)               |      skb_release_head_state() {
  77)               |        sock_wfree() {
  77)   0.096 us    |          unix_write_space();
  77)   0.728 us    |        }
  77)   1.214 us    |      }
  77)               |      skb_release_data() {
  77)               |        skb_free_head() {
  77)   0.045 us    |          kfree();
  77)   0.524 us    |        }
  77)   0.975 us    |      }
  77)   2.930 us    |    }
  77)               |    kfree_skbmem() {
  77)   0.059 us    |      kmem_cache_free();
  77)   0.355 us    |    }
  77)   3.978 us    |  }

3.3. 套路总结

通过 perf 定位到内核中的高频调用函数，结合 function tracer 定位该函数是在啥情况下被调用到的，进一步使用 set_function_graph 调查相关函数调用的耗时细节。

4. tracepoint

tracepoint 的详细指南，参阅内核文档 Documentation/trace/tracepoint-analysis.txt，Documentation/trace/tracepoints.txt。建议充分阅读。

4.1. 是什么

tracepoint 的底层原理是在内核中通过 DEFINE_TRACE 和 DECLARE_TRACE 宏预留 hook 点，可以通过适当的前端工具（perf、ftrace）来激活这个 hook。

4.2. 基本原理

拿 kvm 的 kvm_entry 这个 tracepoint 来说，内核定义此 tracepoint 的地方：


./arch/x86/kvm/trace.h

/*
 * Tracepoint for guest mode entry.
 */
TRACE_EVENT(kvm_entry,
  ... ...
);

TRACE_EVENT 底层通过 __DECLARE_TRACE 宏定义了一个 trace_kvm_entry 函数，此函数内部又通过 __DO_TRACE 宏调用挂在这个 tracepoint 上的 probe 函数：

#define __DECLARE_TRACE(name, proto, args, cond, data_proto, data_args) \
  static inline void trace_##name(proto)  \
  {  \
    if (static_key_false(&__tracepoint_##name.key))    \
      __DO_TRACE(&__tracepoint_##name,    \
  }

#define __DO_TRACE(tp, proto, args, cond, prercu, postrcu)    \
  do {                \
    struct tracepoint_func *it_func_ptr;      \
    void *it_func;            \
    void *__data;            \
                  \
    rcu_read_lock_sched_notrace();        \
    it_func_ptr = rcu_dereference_sched((tp)->funcs);  \
    if (it_func_ptr) {          \
      do {            \
        it_func = (it_func_ptr)->func;    \
        __data = (it_func_ptr)->data;    \
        ((void(*)(proto))(it_func))(args);  \
      } while ((++it_func_ptr)->func);    \
    }              \
    rcu_read_unlock_sched_notrace();      \
    postrcu;            \
  } while (0)

hook 点（vcpu_enter_guest）会调用 trace_kvm_entry，换句话说，如果此 tracepoint 被激活了，每当 vcpu_enter_guest 执行到 trace_kvm_entry 时，会挨个调用挂在这个 tracepoint 上的 probe 函数：

arch/x86/kvm/x86.c

static int vcpu_enter_guest(struct kvm_vcpu *vcpu)
{
  ... ...
  trace_kvm_entry(vcpu->vcpu_id);
  ... ...
}

4.3. 查看 tracepoint

tracepoint 因为是通过宏来定义的，所以它们都是静态的，就是说内核编译好，有哪些 tracepoint 就定下来了。

查看系统定义的 tracepoint 有 perf 和 tracefs 两种方式。

4.3.1. perf list

$ perf list | grep Tracepoint | grep kvm_entry
  kvm:kvm_entry                                     [Tracepoint event]

4.3.2. tracefs

$ find /sys/kernel/debug/tracing/events -type d | sort | grep kvm_entry
/sys/kernel/debug/tracing/events/kvm/kvm_entry

4.4. 使用方式

tracepoint 的使用也有 perf 和 tracefs 两种方式。

4.4.1. perf stat

$ perf stat -a -e kvm:kvm_entry -- sleep 10

 Performance counter stats for 'system wide':

           9728237      kvm:kvm_entry                                              

      10.002049839 seconds time elapsed

4.4.2. tracefs


$ cd /sys/kernel/debug/tracing
$ echo 1 > events/kvm/kvm_entry/enable

$ cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 994520/28453682   #P:96
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
           <...>-77260 [017] d... 5805281.371878: kvm_entry: vcpu 7

5. kprobe

kprobe 的详细使用指南，参阅内核文档 Documentation/trace/kprobetrace.txt。建议充分阅读。

5.1. 是什么

tracepoint 在内核编写之时就定好了，这玩意是死的，如果内核没有对某个你想追踪的函数定义 tracepoint，那么就无法使用 tracepoint 机制来追踪。

kprobe 就是为了解决这个问题的，可以动态地对某个函数或者地址打开追踪能力。

5.2. 基本原理

原理比较简单，与 ftrace 类似，也是指令替换。

当使用 register_kprobe 注册时，内核会将指定位置（可以是函数名，也可以是一个地址）处的指令替换成 int3 指令，如此内核执行到指定位置时，会进入 int3 的异常处理函数 do_int3()，进而在 do_int3() 中依次执行注册的 pre_handler() 函数、原指令、post_handler() 函数。如果函数的开头预留了 ftrace 的 "callq mcount" 5 个字节，则使用 "callq ftrace_caller" 的指令替换方式（而不是替换成 int3），如此不需要走一遍异常触发以及异常处理函数。

5.3. 使用方式

5.3.1. 内核态 register_kprobe

kprobe 在内核态的编程，参考内核的 samples/kprobes/kprobe_example.c 以及 samples/kprobes/kretprobe_example.c。

本文这里不罗列详细的代码了，大概意思就是通过 register_kprobe 对一个 probe 点注册 pre、post、fault 函数：


static char symbol[MAX_SYMBOL_LEN] = "_do_fork";

/* For each probe you need to allocate a kprobe structure */
static struct kprobe kp = {
  .symbol_name    = symbol,
};

static int __init kprobe_init(void)
{
  int ret;
  kp.pre_handler = handler_pre;
  kp.post_handler = handler_post;
  kp.fault_handler = handler_fault;
  
  ret = register_kprobe(&kp);

  // 返回所注册点的地址
  pr_info("Planted kprobe at %p\n", kp.addr);
}

注册某个函数的 kprobe 时，会返回注册点的地址（kp.addr），这一点有些情况下可以被利用，比如新版本中内核不再支持 kallsyms_lookup_name 函数，此时就可以通过 kprobe 获取某内核函数的地址。

5.3.2. tracefs 使用方式

kprobe 的详细使用指南，参阅内核文档 Documentation/trace/kprobetrace.txt

下面只简单罗列一下关键命令：


# 在 do_sys_open 的入口处创建一个 kprobe，会定义一个新的 myprobe 事件
# 至于命令中各参数的含义，读者自行参考 Documentation/trace/kprobetrace.txt
$ echo 'p:myprobe do_sys_open dfd=%ax filename=%dx flags=%cx mode=+4($stack)' > /sys/kernel/debug/tracing/kprobe_events

# 在 do_sys_open 的返回点上创建一个 kretprobe，会定义一个新的 myretprobe 事件
$ echo 'r:myretprobe do_sys_open $retval' >> /sys/kernel/debug/tracing/kprobe_events

# 清除所有 probe 点
$ echo > /sys/kernel/debug/tracing/kprobe_events

# 使能新创建的事件
$ echo 1 > /sys/kernel/debug/tracing/events/kprobes/myprobe/enable
$ echo 1 > /sys/kernel/debug/tracing/events/kprobes/myretprobe/enable

# 读出 trace 信息
$ cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
#           TASK-PID    CPU#    TIMESTAMP  FUNCTION
#              | |       |          |         |
           <...>-1447  [001] 1038282.286875: myprobe: (do_sys_open+0x0/0xd6) dfd=3 filename=7fffd1ec4440 flags=8000 mode=0
           <...>-1447  [001] 1038282.286878: myretprobe: (sys_openat+0xc/0xe <- do_sys_open) $retval=fffffffffffffffe
           <...>-1447  [001] 1038282.286885: myprobe: (do_sys_open+0x0/0xd6) dfd=ffffff9c filename=40413c flags=8000 mode=1b6
           <...>-1447  [001] 1038282.286915: myretprobe: (sys_open+0x1b/0x1d <- do_sys_open) $retval=3
           <...>-1447  [001] 1038282.286969: myprobe: (do_sys_open+0x0/0xd6) dfd=ffffff9c filename=4041c6 flags=98800 mode=10
           <...>-1447  [001] 1038282.286976: myretprobe: (sys_open+0x1b/0x1d <- do_sys_open) $retval=3

6. eBPF/BCC/bpfTrace

6.1. ebpf

有关 ebPF 的详细知识，首推肯定是 Brendan Gregg 的《BPF Performance Tools》，中文版叫《BPF之巅洞悉Linux系统和应用性能》（个人推荐第 4、第 5 章必读）。

另外推荐 Daniel Thompson 的《Kernel analysis using eBPF》，sides：https://elinux.org/images/d/dc/Kernel-Analysis-Using-eBPF-Daniel-Thompson-Linaro.pdf，油管上有同名视频。

原教旨的 eBPF 用法，需要编写运行在内核态的 c 代码，使用 clang/LLVM 编译成 eBPF bytecode 后，再通过用户态程序调用 load_bpf_file 将 bytecode 加载到内核中运行，相关编程范式参考内核 sample/bpf 下的代码即可。

6.2. BCC

BCC 全称 BPF Compiler Collection，简单理解就是 eBPF 的前端工具，里面包含一坨用 python 写的 domain specific 诊断工具，比如诊断系统 open 操作的 opensnoop，等等。《BPF 之巅》第 3、4 章讲的比较充分。

BCC 是对 eBPF 的封装，前端可以使用 python 编写代码，python 通过 libbcc（集成了 clang/llvm 编译器）将 C 语言代码即时编译成 eBPF bytecode 再运行。

相对原教旨的 eBPF 用法来说：

BCC 库包含 clang/llvm，占用磁盘，且即时编译会浪费 CPU、内存，拖慢 BCC 工具的启动时间，且需要 BCC 部署机器上安装对应版本的内核头文件。优势是可以不用提前编译，代码可以即时修改。
原教旨的 eBPF 用法需要提前编译，而提前编译的 bytecode，会有不同内核版本间的兼容性问题（不同版本的内核数据结构偏移、大小不同）。

为了解决原教旨 eBPF 用法的问题，人们又发明了 CO-RE（Compile Once Run Everywhere）技术，通过 BTF（BPF Type Format）来协调不同版本内核间数据结构偏移、大小的问题。CO-RE 下运行在内核态的代码无需 include 内核的各种头文件，只需要 include vmlinux.h 即可，而 vmlinux.h 是由内核 vmlinux 中的 BTF 信息转化而来。

具体的不多说了，网上类似的信息很多。

6.3. bpftrace

《BPF之巅》第 5 章讲的比较充分。bpftrace 基于 eBPF 和 BCC，和 BCC 一样也包含了很多性能分析工具。

bpftrace 比较适合临时创造单行程序和短小脚本进行观测，而 BCC 则适合编写复杂的工具和守护进程。

7. strace

前面介绍的工具都偏内核态一点，有时候遇到用户态程序有性能不符合预期，可以结合 perf 和 strace 确定定位方向。

下面举个工作中遇到的具体问题（实际上是其他同事遇到的，我跟后面学了一下）：两台机器的 lscpu 命令执行快慢明显不同。

下面是问题定位过程：

确认程序版本是否一致

md5sum /usr/bin/lscpu

版本相同。

通过 perf 观察微观指标的差异

sudo perf stat lscpu

观察到慢的机器 instructions 数量明显更多。

观察系统调用层面的差异

strace -c lscpu > /dev/null

观察到慢的机器 read 系统调用次数明显更多。

观察系统调用的具体情况

strace -T -o lscpu.log lscpu

观察到慢的机器 read 某个文件的次数明显更多。

观察内核态函数的具体耗时情况

sudo perf record lscpu

观察到慢的机器某个内核函数调用栈耗时占比明显不同，根据调用栈分析具体逻辑即可。

作者：戴胜冬
来源：窗有老梅

推荐阅读

欢迎大家点赞留言，更多Arm技术文章动态请关注极术社区嵌入式客栈专栏欢迎添加极术小姐姐微信（id:aijishu20)加入技术交流群，请备注研究方向。