动态追踪技术(三)：trace your kernel functions!-白红宇

动态追踪技术(三)：trace your kernel functions!

阅读量：6335 次

发布时间：2019-06-22

本文共 9326 字，大约阅读时间需要 31 分钟。

Ftrace是一个设计用来帮助开发者和设计者监视内核的追踪器，可用于调试或分析延迟以及性能问题。ftrace令人印象最深刻的是作为一个function tracer，内核函数调用、耗时等情况一览无余。另外，ftrace最常见的用途是事件追踪，通过内核是成百上千的静态事件点，看到系统内核的哪些部分在运行。实际上，ftrace更是一个追踪框架，它具备丰富工具集：延迟跟踪检查、何时发生中断、任务的启用、禁用及抢占等。在ftrace的基线版本之上，还有很多第三方提供的开源工具，用于简化操作或者提供数据可视化等扩展应用。

一、Introduction

Developer(s): Steven Rostedt(RedHat) and others Initial release: October 9, 2008; Operating system: Linux （merged into the Linux kernel mainline in kernel version 2.6.27） Type: Kernel extension License: GNU GPL Website:

二、ABC

在使用ftrace之前，需要确认调试目录是否已经挂载，默认目录：/sys/kernel/debug/ 。

debugfs是Linux内核中一种特殊的文件系统，非常易用、基于RAM，专门设计用于调试。（since version 2.6.10-rc3，)。

mount -t debugfs none /sys/kernel/debug或者指定到自己的目录mkdir /debugmount -t debugfs nodev /debug

挂载之后会自动创建如下文件：

/sys/kernel/debug# ls -lrtdrwxr-xr-x.  2 root root 0 12月 28 17:24 x86drwxr-xr-x.  3 root root 0 12月 28 17:24 boot_paramsdrwxr-xr-x. 34 root root 0 12月 28 17:24 bdi-r--r--r--.  1 root root 0 12月 28 17:24 gpiodrwxr-xr-x.  3 root root 0 12月 28 17:24 usbdrwxr-xr-x.  4 root root 0 12月 28 17:24 xendrwxr-xr-x.  6 root root 0 12月 28 17:24 tracingdrwxr-xr-x.  2 root root 0 12月 28 17:24 extfragdrwxr-xr-x.  2 root root 0 12月 28 17:24 dynamic_debugdrwxr-xr-x.  2 root root 0 12月 28 17:24 hid-rw-r--r--.  1 root root 0 12月 28 17:24 sched_featuresdrwxr-xr-x.  2 root root 0 12月 28 17:24 mcedrwxr-xr-x.  2 root root 0 12月 28 17:24 kprobes-r--r--r--.  1 root root 0 12月 28 17:24 vmmemctl/sys/kernel/debug/tracing# ls -lrt-rw-r--r--.  1 root root 0 12月 28 17:24 tracing_thresh-rw-r--r--.  1 root root 0 12月 28 17:24 tracing_on-rw-r--r--.  1 root root 0 12月 28 17:24 tracing_max_latency-rw-r--r--.  1 root root 0 12月 28 17:24 tracing_enabled-rw-r--r--.  1 root root 0 12月 28 17:24 tracing_cpumaskdrwxr-xr-x.  2 root root 0 12月 28 17:24 trace_stat-r--r--r--.  1 root root 0 12月 28 17:24 trace_pipe-rw-r--r--.  1 root root 0 12月 28 17:24 trace_options--w--w----.  1 root root 0 12月 28 17:24 trace_marker-rw-r--r--.  1 root root 0 12月 28 17:24 trace_clock-rw-r--r--.  1 root root 0 12月 28 17:24 trace-rw-r--r--.  1 root root 0 12月 28 17:24 sysprof_sample_period-r--r--r--.  1 root root 0 12月 28 17:24 set_graph_function-rw-r--r--.  1 root root 0 12月 28 17:24 set_ftrace_pid-rw-r--r--.  1 root root 0 12月 28 17:24 set_ftrace_notrace-r--r--r--.  1 root root 0 12月 28 17:24 saved_cmdlines-r--r--r--.  1 root root 0 12月 28 17:24 READMEdrwxr-xr-x.  2 root root 0 12月 28 17:24 options-rw-r--r--.  1 root root 0 12月 28 17:24 function_profile_enabled-r--r--r--.  1 root root 0 12月 28 17:24 dyn_ftrace_total_info-rw-r--r--.  1 root root 0 12月 28 17:24 buffer_size_kb-r--r--r--.  1 root root 0 12月 28 17:24 available_tracers-r--r--r--.  1 root root 0 12月 28 17:24 available_filter_functions-rw-r--r--.  1 root root 0 12月 28 17:24 set_event-r--r--r--.  1 root root 0 12月 28 17:24 printk_formatsdrwxr-xr-x. 34 root root 0 12月 28 17:24 per_cpudrwxr-xr-x. 24 root root 0 12月 28 17:24 events-r--r--r--.  1 root root 0 12月 28 17:24 available_events-r--r--r--.  1 root root 0 12月 28 17:24 kprobe_profile-rw-r--r--.  1 root root 0 12月 28 17:24 kprobe_events-r--r--r--.  1 root root 0 12月 28 17:24 stack_trace-rw-r--r--.  1 root root 0 12月 28 17:24 stack_max_size-rw-r--r--.  1 root root 0 5月  31 11:50 current_tracer-rwxr-xr-x.  1 root root 0 5月  31 11:57 set_ftrace_filter

三、BASIC

1. Function tracer

以Function tracer为例，结果存储在 trace，该文件类似一张报表，该表将显示 4 列信息。首先是进程信息，包括进程名和PID ；第二列是CPU；第三列是时间戳；第四列是函数信息，缺省情况下，这里将显示内核函数名以及它的上一层调用函数。

cd /sys/kernel/debug/tracingecho function > current_tracercat trace# tracer: function##  TASK-PID   CPU#  TIMESTAMP        FUNCTION#   |  |       |  gmond-6684  [004] 13285965.088308: _spin_lock <-hrtimer_interruptgmond-6684  [004] 13285965.088308: ktime_get_update_offsets <-hrtimer_interruptgmond-6684  [004] 13285965.088309: __run_hrtimer <-hrtimer_interruptgmond-6684  [004] 13285965.088309: __remove_hrtimer <-__run_hrtimergmond-6684  [004] 13285965.088309: tick_sched_timer <-__run_hrtimergmond-6684  [004] 13285965.088309: ktime_get <-tick_sched_timergmond-6684  [004] 13285965.088310: tick_do_update_jiffies64 <-tick_sched_timergmond-6684  [004] 13285965.088310: update_process_times <-tick_sched_timer

2. Function graph tracer

Function graph tracer 和 function tracer 类似，但输出为函数调用图，更加容易阅读：

# tracer: function_graph##     TIME        CPU  DURATION                  FUNCTION CALLS#      |          |     |   |                     |   |   |   | 21)   ==========> | 21)               |  smp_apic_timer_interrupt() { 31)   ==========> | 31)               |  smp_apic_timer_interrupt() { 8)               |  smp_apic_timer_interrupt() { 11)   2.598 us    |    native_apic_mem_write(); 18)   3.106 us    |    native_apic_mem_write(); 30)   ==========> | 30)               |  smp_apic_timer_interrupt() {  3)   3.590 us    |    native_apic_mem_write(); 22)   2.944 us    |    native_apic_mem_write();  7)   3.392 us    |    native_apic_mem_write(); 17)   ==========> | 17)               |  smp_apic_timer_interrupt() { 27)   ==========> | 27)               |  smp_apic_timer_interrupt() { 16)   ==========> | 16)               |  smp_apic_timer_interrupt() {

Linux ftrace tracers

四、体系结构

Ftrace有两大组成部分，framework和一系列的tracer 。每个tracer完成不同的功能，它们统一由framework管理。 ftrace 的trace信息保存在ring buffer中，由framework负责管理。Framework 利用debugfs建立tracing目录，并提供了一系列的控制文件。

Linux ftrace架构示意图

ftrace is a dynamic tracing system. 当你开始“ftracing”一个内核函数的时候，该函数的代码实际上就已经发生变化了。内核将在程序集中插入一些额外的指令，使得函数调用时可以随时通知追踪程序。

WARNNING:使用ftrace追踪内核将有可能对系统性能产生影响，追踪的函数越多，开销越大。使用者必须提前做好准备工作，生产环境必须谨慎使用。

#cat available_tracers //查看支持的tracersblk kmemtrace function_graph wakeup_rt wakeup function sysprof sched_switch initcall nop

五、Useful Tools

1. trace-cmd

trace-cmd是一个非常有用的Ftrace命令行工具。

sudo apt-get install trace-cmd或者git clone git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/trace-cmd.git

使用方法：

sudo trace-cmd record --help #helpsudo trace-cmd record -p function -P 123456 #record for PIDsudo trace-cmd record -p function -l do_page_fault #record for function  plugin 'function'Hit Ctrl^C to stop recording

trace.dat

$ sudo trace-cmd report          chrome-15144 [000] 11446.466121: function:             do_page_fault          chrome-15144 [000] 11446.467910: function:             do_page_fault          chrome-15144 [000] 11446.469174: function:             do_page_fault          chrome-15144 [000] 11446.474225: function:             do_page_fault          chrome-15144 [000] 11446.474386: function:             do_page_fault          chrome-15144 [000] 11446.478768: function:             do_page_fault CompositorTileW-15154 [001] 11446.480172: function:             do_page_fault          chrome-1830  [003] 11446.486696: function:             do_page_fault CompositorTileW-15154 [001] 11446.488983: function:             do_page_fault CompositorTileW-15154 [001] 11446.489034: function:             do_page_fault CompositorTileW-15154 [001] 11446.489045: function:             do_page_fault

在很有情况下不能使用函数追踪，需要依赖 事件追踪 的支持，例如：

# cat available_events  //查看支持的事件类型power:power_startpower:power_frequencypower:power_endsched:sched_kthread_stopsched:sched_kthread_stop_retsched:sched_wait_tasksched:sched_wakeupsched:sched_wakeup_newsched:sched_switchsched:sched_migrate_tasksched:sched_process_freesched:sched_process_exitsched:sched_process_waitsched:sched_process_forksched:sched_stat_waitsched:sched_stat_sleepsched:sched_stat_iowaitsched:sched_stat_runtimesudo trace-cmd record -e sched:sched_switchsudo trace-cmd report

输出如下：

16169.624862:   Chrome_ChildIOT:24817 [112] S ==> chrome:15144 [120] 16169.624992:   chrome:15144 [120] S ==> swapper/3:0 [120] 16169.625202:   swapper/3:0 [120] R ==> Chrome_ChildIOT:24817 [112] 16169.625251:   Chrome_ChildIOT:24817 [112] R ==> chrome:1561 [112] 16169.625437:   chrome:1561 [112] S ==> chrome:15144 [120]

切换路径：PID 24817 -> 15144 -> kernel -> 24817 -> 1561 -> 15114。

2. perf-tools

perf-tools 是性能调试大神Brendan Gregg开发的一个工具包，提供了很多强大的功能，例如： iosnoop: 磁盘I/O分析详细包括延迟 iolatency: 磁盘I/O分析概要(柱状图) execsnoop: 追踪进程exec() opensnoop: 追踪open()系统调用，包含文件名 killsnoop: 追踪kill()信号（进程和信号详细）

代码下载：

# ./execsnoop  //显示新进程和参数：Tracing exec()s. Ctrl-C to end.   PID   PPID ARGS 22898  22004 man ls 22905  22898 preconv -e UTF-8 22908  22898 pager -s 22907  22898 nroff -mandoc -rLL=164n -rLT=164n -Tutf8 22906  22898 tbl 22911  22910 locale charmap 22912  22907 groff -mtty-char -Tutf8 -mandoc -rLL=164n -rLT=164n 22913  22912 troff -mtty-char -mandoc -rLL=164n -rLT=164n -Tutf8 22914  22912 grotty# ./iolatency -Q  //测量设备I/O延迟Tracing block I/O. Output every 1 seconds. Ctrl-C to end.  >=(ms) .. <(ms)   : I/O      |Distribution                          |       0 -> 1       : 1913     |######################################|       1 -> 2       : 438      |#########                             |       2 -> 4       : 100      |##                                    |       4 -> 8       : 145      |###                                   |       8 -> 16      : 43       |#                                     |      16 -> 32      : 43       |#                                     |      32 -> 64      : 1        |#                                     |[...]