一个操作系统的内核是最难以捉摸的软件之一。从你的系统被打开的时候，它就一直在后台运行。每个用户都在内核的帮助下完成他们的计算工作，但他们从未与内核直接互动。与内核的交互是通过进行系统调用或由各种库或日常使用的应用程序代表用户进行这些调用来实现的。
我在之前的文章中已经介绍了如何跟踪系统调用，使用 [strace](https://opensource.com/article/19/10/strace).然而，使用strace ，你的可见性是有限的。它允许你查看用特定参数调用的系统调用，并且在工作完成后，看到返回值或状态，表明它们是通过还是失败。但是你不知道在这段时间内内核内部发生了什么。除了为系统调用服务外，还有很多其他的活动在内核内部发生，而你却视而不见。
Ftrace简介
这篇文章旨在通过使用一种叫做ftrace 的机制来阐明追踪内核函数的一些情况。它使任何Linux用户都可以轻松地追踪内核，在它的帮助下，你可以学到很多关于Linux内核内部的东西。
鉴于内核总是很忙，由ftrace 产生的默认输出往往是巨大的。为了节省空间，我把输出保持在最低限度，在许多情况下完全截断了输出。
我在这些例子中使用的是Fedora，但它们在任何最新的Linux发行版上都应该适用。
启用ftrace
Ftrace 现在是Linux内核的一部分，你不再需要安装任何东西来使用它。如果你使用的是最新的Linux操作系统，很可能已经启用了ftrace 。为了验证ftrace 设施是否可用，运行mount命令并搜索tracefs 。如果你看到与下面类似的输出，ftrace 已经启用，你可以很容易地按照本文的例子进行操作。
$ sudo mount | grep tracefs
none 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_tracers
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
在所有给定的追踪器中，我专注于三个具体的追踪器：function 和function_graph 来启用追踪器，nop 来禁用追踪器。
识别当前的追踪器
通常，默认情况下，追踪器被设置为nop 。也就是在特殊文件current_tracer 中的 "No operation"，这通常意味着追踪功能目前是关闭的。
$ pwd
/sys/kernel/tracing
$ sudo cat current_tracer
nop
查看跟踪输出
在你启用任何跟踪之前，看一看存储跟踪输出的文件。你可以使用cat命令查看名为trace 的文件的内容。
$ sudo 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 （其早期内容为nop ，表示追踪是关闭的）。把这个操作看成是启用跟踪的一种方式。
$ pwd
/sys/kernel/tracing
$ sudo cat current_tracer
nop
$ echo function > current_tracer
$
$ cat current_tracer
function
查看函数追踪器的最新追踪输出
现在你已经启用了追踪功能，现在是时候查看输出了。如果你查看trace 文件的内容，你会看到大量的数据被不断地写入其中。我对输出进行了管道处理，目前只查看了前20行，以保持事情的可控性。如果你在左边的输出中跟随标题，你可以看到哪个任务和进程ID在哪个CPU上运行。在输出的右边，你可以看到确切的内核函数在运行，然后是它的父函数。中间还有时间戳信息。
$ 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
# | | | |||| | |
-0 [000] d... 2088.841739: tsc_verify_tsc_adjust <-arch_cpu_idle_enter
-0 [000] d... 2088.841739: local_touch_nmi <-do_idle
-0 [000] d... 2088.841740: rcu_nocb_flush_deferred_wakeup <-do_idle
-0 [000] d... 2088.841740: tick_check_broadcast_expired <-do_idle
-0 [000] d... 2088.841740: cpuidle_get_cpu_driver <-do_idle
-0 [000] d... 2088.841740: cpuidle_not_available <-do_idle
-0 [000] d... 2088.841741: cpuidle_select <-do_idle
-0 [000] d... 2088.841741: menu_select <-do_idle
-0 [000] d... 2088.841741: cpuidle_governor_latency_req <-menu_select
记住，追踪是打开的，这意味着追踪的输出会继续被写入追踪文件，直到你关闭追踪。
关掉追踪
关掉追踪很简单。你所要做的就是在current_tracer 文件中用nop 替换function tracer，追踪就会被关闭。
$ sudo cat current_tracer
function
$ sudo echo nop > current_tracer
$ sudo cat current_tracer
nop
启用function_graph tracer
现在试试第二个追踪器，叫做function_graph 。你可以使用与之前相同的步骤启用它：将function_graph 写到current_tracer 文件中。
$ sudo echo function_graph > current_tracer
$ sudo cat current_tracer
function_graph
追踪 function_graph 追踪器的输出
注意，trace 文件的输出格式已经改变。现在，你可以看到CPU ID和内核函数执行的时间。接下来，你看到大括号表示函数的开始，以及从函数内部调用了哪些其他进程。
$ sudo 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 文件的内容，看到输出的内容稍微详细一些。为了便于阅读，这个例子的输出被省略了。
$ sudo cat max_graph_depth
0
$ sudo echo 1 > max_graph_depth
$ # or
$ sudo 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_functions
debug_kmalloc
mempool_kmalloc
kmalloc_slab
kmalloc_order
kmalloc_order_trace
kmalloc_fix_flags
kmalloc_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 kvm
kvm_intel 335872 0
kvm 987136 1 kvm_intel
irqbypass 16384 1 kvm
只追踪特定的函数
为了实现对特定函数或模式的跟踪，你可以利用set_ftrace_filter 文件来指定你要跟踪上述输出中的哪些函数。
这个文件也接受* 模式，它可以扩展到包括具有给定模式的其他函数。作为一个例子，我在我的机器上使用ext4 文件系统。我可以使用下面的命令指定ext4 特定的内核函数进行跟踪。
$ sudo mount | grep home
/dev/mapper/fedora-home on /home type ext4 (rw,relatime,seclabel)
$ pwd
/sys/kernel/tracing
$ sudo cat set_ftrace_filter
#### all functions enabled ####
$
$ echo ext4_* > set_ftrace_filter
$
$ cat set_ftrace_filter
ext4_has_free_clusters
ext4_validate_block_bitmap
ext4_get_group_number
ext4_get_group_no_and_offset
ext4_get_group_desc
[...]
现在，当你看到追踪输出时，你只能看到与你先前设置的过滤器有关的内核函数ext4 。所有其他的输出都被忽略了。
$ sudo 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 ####
有针对性的跟踪
到目前为止，你一直在追踪内核中发生的一切。但是如果你想追踪与某个特定命令有关的事件，这对我们没有帮助。为了达到这个目的，你可以按需打开和关闭跟踪，并且在它们之间，运行我们选择的命令，这样你就不会在跟踪输出中得到额外的输出。你可以通过写1 ，tracing_on ，0 ，来开启追踪功能，关闭追踪功能。
$ sudo cat tracing_on
0
$ sudo echo 1 > tracing_on
$ sudo cat tracing_on
1
$ # Run some specific command that we wish to trace here
$ sudo echo 0 > tracing_on
$ cat tracing_on
0
追踪特定的PID
如果你想跟踪与已经运行的特定进程有关的活动，你可以将该PID写入一个名为set_ftrace_pid 的文件，然后启用跟踪。这样一来，追踪就只限于这个PID，这在某些情况下是非常有帮助的。
$ sudo echo $PID > set_ftrace_pid
结论
Ftrace 是学习更多关于Linux内核内部工作原理的一个好方法。通过一些练习，你可以学会微调ftrace ，缩小你的搜索范围。要想更详细地了解ftrace ，以及它的高级用法，请看ftrace 的核心作者Steven Rostedt自己写的这些优秀文章。
