[[421874]]

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

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

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

ftrace 介紹

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

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

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

啟用 ftrace

ftrace 現(xiàn)在已經是內核中的一部分了，你不再需要事先安裝它了。也就是說，如果你在使用最近的 Linux 系統(tǒng)，那么 ftrace 是已經啟用了的。為了驗證 ftrace 是否可用，運行 mount 命令并查找 tracefs。如果你看到類似下面的輸出，表示 ftrace 已經啟用，你可以輕松地嘗試本文中下面的例子。下面有些命令需要在 root 用戶下使用（用 sudo 執(zhí)行是不夠的）。

# mount | grep tracefs
none on /sys/kernel/tracing type tracefs (rw,relatime,seclabel)

要想使用 ftrace，你首先需要進入上面 mount 命令中找到的特定目錄中，在那個目錄下運行文章中的其他命令。

# cd /sys/kernel/tracing

一般的工作流程

首先，你需要理解捕捉蹤跡和獲取輸出的一般流程。如果你直接運行 ftrace，不會運行任何特定的 ftrace 命令。相反的，基本操作是通過標準 Linux 命令來寫入或讀取一些文件。

一般的步驟如下：

1. 通過寫入一些特定文件來啟用/結束追蹤
2. 通過寫入一些特定文件來設置/取消追蹤時的過濾規(guī)則
3. 從文件中讀取基于第 1 和 2 步的追蹤輸出
4. 從文件中清除早期輸出或緩沖區(qū)
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 追蹤器的更新追蹤輸出

現(xiàn)在你已啟用追蹤，是時候查看輸出了。如果你查看 trace 文件內容，你將會看到許多被連續(xù)寫入的內容。我通過管道只展示了文件內容的前 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

請記住當追蹤打開后，這意味著追蹤結果會被一直連續(xù)寫入直至你關閉追蹤。

關閉追蹤

關閉追蹤是簡單的。你只需要在 current_tracer 文件中用 nop 替換 function 追蹤器即可：

$ sudo cat current_tracer
function
 
$ sudo echo nop > current_tracer
 
$ sudo cat current_tracer
nop

啟用 function_graph 追蹤器

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

$ sudo echo function_graph > current_tracer
 
$ sudo cat current_tracer
function_graph

function_tracer 追蹤器的追蹤輸出

注意到目前 trace 文件的輸出格式已經發(fā)生變化?，F(xiàn)在，你可以看到 CPU ID 和內核函數的執(zhí)行時長。接下來，一個花括號表示一個函數的開始，以及它內部調用了哪些其他函數：

# 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 文件的內容并發(fā)現(xiàn)輸出變得更加詳細了。為了文章的可讀性，這個例子的輸出被省略了：

# 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

查找一般的內核函數

現(xiàn)在試著搜索一個你所知道的簡單內核函數。用戶空間由 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

僅追蹤特定的函數

為了實現(xiàn)對特定函數或模式的追蹤，你可以利用 set_ftrace_filter 文件來指定你要追蹤上述輸出中的哪些函數。這個文件也接受 * 模式，它可以擴展到包括具有給定模式的其他函數。作為一個例子，我在我的機器上使用 ext4 文件系統(tǒng)。我可以用下面的命令指定 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
[...]

現(xiàn)在當你可以看到追蹤輸出時，你只能看到與內核函數有關的 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 ####

具有目標性的追蹤

到目前為止，你一直在追蹤內核中發(fā)生的一切。但是，它無法幫助你追蹤與某個特定命令有關的事件。為了達到這個目的，你可以按需打開和關閉跟蹤，并且在它們之間，運行我們選擇的命令，這樣你就不會在跟蹤輸出中得到額外的輸出。你可以通過向 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 寫的這些優(yōu)秀文章。

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