通过 ftrace 来分析 Linux 内核
原创
通过使用一个名为 ftrace 的机制来阐明追踪内核函数的一些情况。它使得任何 Linux 用户可以轻松地追踪内核，并且了解更多关于 Linux 内核内部如何工作。
ftrace 默认产生的输出往往是巨大的，因为内核总是忙碌的。为了节省空间，很多情况下我会通过截断来给出尽量小的输出。
我使用 Fedora 来演示下面的例子，但是它们应该在其他最新的 Linux 发行版上同样可以运行。
启用 ftrace
ftrace 现在已经是内核中的一部分了，你不再需要事先安装它了。也就是说，如果你在使用最近的 Linux 系统，那么 ftrace 是已经启用了的。为了验证 ftrace 是否可用，运行 mount 命令并查找 tracefs。如果你看到类似下面的输出，表示 ftrace 已经启用，你可以轻松地尝试本文中下面的例子。下面有些命令需要在 root 用户下使用（用 sudo 执行是不够的）。
# mount | grep tracefsnone on /sys/kernel/tracing type tracefs (rw,relatime,seclabel)要想使用 ftrace，你首先需要进入上面 mount 命令中找到的特定目录中，在那个目录下运行文章中的其他命令。
# cd /sys/kernel/tracing一般的工作流程
首先，你需要理解捕捉踪迹和获取输出的一般流程。如果你直接运行 ftrace，不会运行任何特定的 ftrace 命令。相反的，基本操作是通过标准 Linux 命令来写入或读取一些文件。
一般的步骤如下：
- 通过写入一些特定文件来启用/结束追踪
- 通过写入一些特定文件来设置/取消追踪时的过滤规则
- 从文件中读取基于第 1 和 2 步的追踪输出
- 从文件中清除早期输出或缓冲区
- 缩小到你的特定用例（你要追踪的内核函数），重复 1、2、3、4 步
可用的追踪器类型
有多种不同的追踪器可供使用。之前提到，在运行任何命令前，你需要进入一个特定的目录下，因为需要的文件在这些目录下。我在我的例子中使用了相对路径（而不是绝对路径）。
你可以查看 available_tracers 文件内容来查看所有可用的追踪器类型。你可以看下面列出了几个。不需要担心这些：
$ pwd/sys/kernel/tracing$ sudo cat available_tracershwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop在所有输出的追踪器中，我会聚焦于下面三个特殊的：启用追踪的 function 和 function_graph，以及停止追踪的 nop。
确认当前的追踪器
通常情况默认的追踪器设定为 nop。即在特殊文件中 current_tracer 中的 “无操作”，这意味着追踪目前是关闭的：
$ pwd/sys/kernel/tracing$ sudo cat current_tracernop查看追踪输出
在启用任何追踪功能之前，请你看一下保存追踪输出的文件。你可以用 cat 命令查看名为 trace 的文件的内容：
# cat trace# tracer: nop## entries-in-buffer/entries-written: 0/0 #P:8## _-----=> irqs-off# / _----=> need-resched# | / _---=> hardirq/softirq# || / _--=> preempt-depth# ||| / delay# TASK-PID CPU# |||| TIMESTAMP FUNCTION# | | | |||| | |启用 function 追踪器
你可以通过向 current_tracer 文件写入 function 来启用第一个追踪器 function（文件原本内容为 nop，意味着追踪是关闭的）。把这个操作看成是启用追踪的一种方式：
$ pwd/sys/kernel/tracing$ sudo cat current_tracernop$ echo function > current_tracer$$ cat current_tracerfunction查看 function 追踪器的更新追踪输出
现在你已启用追踪，是时候查看输出了。如果你查看 trace 文件内容，你将会看到许多被连续写入的内容。我通过管道只展示了文件内容的前 20 行。根据左边输出的标题，你可以看到在某个 CPU 上运行的任务和进程 ID。根据右边输出的内容，你可以看到具体的内核函数和其父函数。中间显示了时间戳信息：
# sudo cat trace | head -20# tracer: function## entries-in-buffer/entries-written: 409936/4276216 #P:8## _-----=> irqs-off# / _----=> need-resched# | / _---=> hardirq/softirq# || / _--=> preempt-depth# ||| / delay# TASK-PID CPU# |||| TIMESTAMP FUNCTION# | | | |||| | | <idle>-0 [000] d... 2088.841739: tsc_verify_tsc_adjust <-arch_cpu_idle_enter <idle>-0 [000] d... 2088.841739: local_touch_nmi <-do_idle <idle>-0 [000] d... 2088.841740: rcu_nocb_flush_deferred_wakeup <-do_idle <idle>-0 [000] d... 2088.841740: tick_check_broadcast_expired <-do_idle <idle>-0 [000] d... 2088.841740: cpuidle_get_cpu_driver <-do_idle <idle>-0 [000] d... 2088.841740: cpuidle_not_available <-do_idle <idle>-0 [000] d... 2088.841741: cpuidle_select <-do_idle <idle>-0 [000] d... 2088.841741: menu_select <-do_idle <idle>-0 [000] d... 2088.841741: cpuidle_governor_latency_req <-menu_select请记住当追踪打开后，这意味着追踪结果会被一直连续写入直至你关闭追踪。
关闭追踪
关闭追踪是简单的。你只需要在 current_tracer 文件中用 nop 替换 function 追踪器即可：
$ sudo cat current_tracerfunction$ sudo echo nop > current_tracer$ sudo cat current_tracernop启用 function_graph 追踪器
现在尝试第二个名为 function_graph 的追踪器。你可以使用和上面相同的步骤：在 current_tracer 文件中写入 function_graph：
$ sudo echo function_graph > current_tracer$ sudo cat current_tracerfunction_graphfunction_tracer 追踪器的追踪输出
注意到目前 trace 文件的输出格式已经发生变化。现在，你可以看到 CPU ID 和内核函数的执行时长。接下来，一个花括号表示一个函数的开始，以及它内部调用了哪些其他函数：
# cat trace | head -20# tracer: function_graph## CPU DURATION FUNCTION CALLS# | | | | | | | 6) | n_tty_write() { 6) | down_read() { 6) | __cond_resched() { 6) 0.341 us | rcu_all_qs(); 6) 1.057 us | } 6) 1.807 us | } 6) 0.402 us | process_echoes(); 6) | add_wait_queue() { 6) 0.391 us | _raw_spin_lock_irqsave(); 6) 0.359 us | _raw_spin_unlock_irqrestore(); 6) 1.757 us | } 6) 0.350 us | tty_hung_up_p(); 6) | mutex_lock() { 6) | __cond_resched() { 6) 0.404 us | rcu_all_qs(); 6) 1.067 us | }启用追踪的设置来增加追踪的深度
你可以使用下面的步骤来调整追踪器以看到更深层次的函数调用。完成之后，你可以查看 trace 文件的内容并发现输出变得更加详细了。为了文章的可读性，这个例子的输出被省略了：
# cat max_graph_depth0# echo 1 > max_graph_depth ## or:# echo 2 > max_graph_depth# sudo cat trace查找要追踪的函数
上面的步骤足以让你开始追踪。但是它产生的输出内容是巨大的，当你想试图找到自己感兴趣的内容时，往往会很困难。通常你更希望能够只追踪特定的函数，而忽略其他函数。但如果你不知道它们确切的名称，你怎么知道要追踪哪些进程？有一个文件可以帮助你解决这个问题 —— available_filter_functions 文件提供了一个可供追踪的函数列表：
$ sudo wc -l available_filter_functions 63165 available_filter_functions查找一般的内核函数
现在试着搜索一个你所知道的简单内核函数。用户空间由 malloc 函数用来分配内存，而内核由 kmalloc 函数，它提供类似的功能。下面是所有与 kmalloc 相关的函数：
$ sudo grep kmalloc available_filter_functionsdebug_kmallocmempool_kmallockmalloc_slabkmalloc_orderkmalloc_order_tracekmalloc_fix_flagskmalloc_large_node__kmalloc__kmalloc_track_caller__kmalloc_node__kmalloc_node_track_caller[...]查找内核模块或者驱动相关函数
在 available_filter_functions 文件的输出中，你可以看到一些以括号内文字结尾的行，例如下面的例子中的 [kvm_intel]。这些函数与当前加载的内核模块 kvm_intel 有关。你可以运行 lsmod 命令来验证：
$ sudo grep kvm available_filter_functions | tail__pi_post_block [kvm_intel]vmx_vcpu_pi_load [kvm_intel]vmx_vcpu_pi_put [kvm_intel]pi_pre_block [kvm_intel]pi_post_block [kvm_intel]pi_wakeup_handler [kvm_intel]pi_has_pending_interrupt [kvm_intel]pi_update_irte [kvm_intel]vmx_dump_dtsel [kvm_intel]vmx_dump_sel [kvm_intel]$ lsmod | grep -i kvmkvm_intel 335872 0kvm 987136 1 kvm_intelirqbypass 16384 1 kvm仅追踪特定的函数
为了实现对特定函数或模式的追踪，你可以利用 set_ftrace_filter 文件来指定你要追踪上述输出中的哪些函数。这个文件也接受 * 模式，它可以扩展到包括具有给定模式的其他函数。作为一个例子，我在我的机器上使用 ext4 文件系统。我可以用下面的命令指定 ext4 的特定内核函数来追踪：
# mount | grep home/dev/mapper/fedora-home on /home type ext4 (rw,relatime,seclabel)# pwd/sys/kernel/tracing# cat set_ftrace_filter#### all functions enabled ####$$ echo ext4_* > set_ftrace_filter$$ cat set_ftrace_filterext4_has_free_clustersext4_validate_block_bitmapext4_get_group_numberext4_get_group_no_and_offsetext4_get_group_desc[...]现在当你可以看到追踪输出时，你只能看到与内核函数有关的 ext4 函数，而你之前已经为其设置了一个过滤器。所有其他的输出都被忽略了：
# cat trace |head -20## tracer: function## entries-in-buffer/entries-written: 3871/3871 #P:8## _-----=> irqs-off# / _----=> need-resched# | / _---=> hardirq/softirq# || / _--=> preempt-depth# ||| / delay# TASK-PID CPU# |||| TIMESTAMP FUNCTION# | | | |||| | | cupsd-1066 [004] .... 3308.989545: ext4_file_getattr <-vfs_fstat cupsd-1066 [004] .... 3308.989547: ext4_getattr <-ext4_file_getattr cupsd-1066 [004] .... 3308.989552: ext4_file_getattr <-vfs_fstat cupsd-1066 [004] .... 3308.989553: ext4_getattr <-ext4_file_getattr cupsd-1066 [004] .... 3308.990097: ext4_file_open <-do_dentry_open cupsd-1066 [004] .... 3308.990111: ext4_file_getattr <-vfs_fstat cupsd-1066 [004] .... 3308.990111: ext4_getattr <-ext4_file_getattr cupsd-1066 [004] .... 3308.990122: ext4_llseek <-ksys_lseek cupsd-1066 [004] .... 3308.990130: ext4_file_read_iter <-new_sync_read排除要被追踪的函数
你并不总是知道你想追踪什么，但是，你肯定知道你不想追踪什么。因此，有一个 set_ftrace_notrace —— 请注意其中的 “no”。你可以在这个文件中写下你想要的模式，并启用追踪。这样除了所提到的模式外，任何其他东西都会被追踪到。这通常有助于删除那些使我们的输出变得混乱的普通功能：
$ sudo cat set_ftrace_notrace#### no functions disabled ####具有目标性的追踪
到目前为止，你一直在追踪内核中发生的一切。但是，它无法帮助你追踪与某个特定命令有关的事件。为了达到这个目的，你可以按需打开和关闭跟踪，并且在它们之间，运行我们选择的命令，这样你就不会在跟踪输出中得到额外的输出。你可以通过向 tracing_on 写入 1 来启用跟踪，写 0 来关闭跟踪。
# cat tracing_on0# echo 1 > tracing_on# cat tracing_on1### Run some specific command that we wish to trace here #### echo 0 > tracing_on# cat tracing_on0追踪特定的 PID
如果你想追踪与正在运行的特定进程有关的活动，你可以将该 PID 写入一个名为 set_ftrace_pid 的文件，然后启用追踪。这样一来，追踪就只限于这个 PID，这在某些情况下是非常有帮助的。
$ sudo echo $PID > set_ftrace_pid原创声明：本文系作者授权腾讯云开发者社区发表，未经许可，不得转载。
如有侵权，请联系 cloudcommunity@tencent.com 删除。
原创声明：本文系作者授权腾讯云开发者社区发表，未经许可，不得转载。
如有侵权，请联系 cloudcommunity@tencent.com 删除。