[[421874]]

通過 ftrace 來了解 Linux 內核內部工作方式是一個好方法。

操作系統的內核是最難以理解的軟件之一。自從你的系統啟動后，它會一直在后臺運行。盡管每個用戶都不與內核直接交互，但他們在內核的幫助下完成自己的計算任務。與內核的交互發生在調用系統調用或者用戶日常使用的各種庫或應用間接調用了系統調用。

在之前的文章里我介紹了如何使用 strace 來追蹤系統調用。然而，使用 strace 時你的視野是有限的。它允許你查看特定參數的系統調用。并在工作完成后，看到其返回值或狀態，以表明是成功還是失敗。但是你無法知道內核在這段時間內發生了什么。除了系統調用外，還有很多其他活動內核中發生，而你卻視而不見。

ftrace 介紹

本文的旨在通過使用一個名為 ftrace 的機制來闡明追蹤內核函數的一些情況。它使得任何 Linux 用戶可以輕松地追蹤內核，并且了解更多關于 Linux 內核內部如何工作。

ftrace 默認產生的輸出往往是巨大的，因為內核總是忙碌的。為了節省空間，很多情況下我會通過截斷來給出盡量小的輸出。

我使用 Fedora 來演示下面的例子，但是它們應該在其他最新的 Linux 發行版上同樣可以運行。

啟用 ftrace

ftrace 現在已經是內核中的一部分了，你不再需要事先安裝它了。也就是說，如果你在使用最近的 Linux 系統，那么 ftrace 是已經啟用了的。為了驗證 ftrace 是否可用，運行 mount 命令并查找 tracefs。如果你看到類似下面的輸出，表示 ftrace 已經啟用，你可以輕松地嘗試本文中下面的例子。下面有些命令需要在 root 用戶下使用（用 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. 通過寫入一些特定文件來設置/取消追蹤時的過濾規則
3. 從文件中讀取基于第 1 和 2 步的追蹤輸出
4. 從文件中清除早期輸出或緩沖區
5. 縮小到你的特定用例（你要追蹤的內核函數），重復 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 中的 “無操作”，這意味著追蹤目前是關閉的：

$ pwd
/sys/kernel/tracing
 
$ sudo cat current_tracer
nop

查看追蹤輸出

在啟用任何追蹤功能之前，請你看一下保存追蹤輸出的文件。你可以用 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_tracer
nop
$ echo function > current_tracer
$
$ cat current_tracer
function

查看 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_tracer
function
 
$ sudo echo nop > current_tracer
 
$ sudo cat current_tracer
nop

啟用 function_graph 追蹤器

現在嘗試第二個名為 function_graph 的追蹤器。你可以使用和上面相同的步驟：在 current_tracer 文件中寫入 function_graph：

$ sudo echo function_graph > current_tracer
 
$ sudo cat current_tracer
function_graph

function_tracer 追蹤器的追蹤輸出

注意到目前 trace 文件的輸出格式已經發生變化?，F在，你可以看到 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_depth
0
 
# 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_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 的特定內核函數來追蹤：

# 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_filter
ext4_has_free_clusters
ext4_validate_block_bitmap
ext4_get_group_number
ext4_get_group_no_and_offset
ext4_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_on
0
 
# echo 1 > tracing_on
 
# cat tracing_on
1
 
### Run some specific command that we wish to trace here ###
 
# 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 寫的這些優秀文章。

• 調試 Linux 內核，第一部分
• 調試 Linux 內核，第二部分
• 調試 Linux 內核，第三部分