通過 ftrace 來分析 Linux 內(nèi)核
通過
ftrace
來了解 Linux 內(nèi)核內(nèi)部工作方式是一個好方法。
操作系統(tǒng)的內(nèi)核是最難以理解的軟件之一。自從你的系統(tǒng)啟動后,它會一直在后臺運行。盡管每個用戶都不與內(nèi)核直接交互,但他們在內(nèi)核的幫助下完成自己的計算任務(wù)。與內(nèi)核的交互發(fā)生在調(diào)用系統(tǒng)調(diào)用或者用戶日常使用的各種庫或應(yīng)用間接調(diào)用了系統(tǒng)調(diào)用。
在之前的文章里我介紹了如何使用 strace 來追蹤系統(tǒng)調(diào)用。然而,使用 strace
時你的視野是有限的。它允許你查看特定參數(shù)的系統(tǒng)調(diào)用。并在工作完成后,看到其返回值或狀態(tài),以表明是成功還是失敗。但是你無法知道內(nèi)核在這段時間內(nèi)發(fā)生了什么。除了系統(tǒng)調(diào)用外,還有很多其他活動內(nèi)核中發(fā)生,而你卻視而不見。
ftrace 介紹
本文的旨在通過使用一個名為 ftrace
的機(jī)制來闡明追蹤內(nèi)核函數(shù)的一些情況。它使得任何 Linux 用戶可以輕松地追蹤內(nèi)核,并且了解更多關(guān)于 Linux 內(nèi)核內(nèi)部如何工作。
ftrace
默認(rèn)產(chǎn)生的輸出往往是巨大的,因為內(nèi)核總是忙碌的。為了節(jié)省空間,很多情況下我會通過截斷來給出盡量小的輸出。
我使用 Fedora 來演示下面的例子,但是它們應(yīng)該在其他最新的 Linux 發(fā)行版上同樣可以運行。
啟用 ftrace
ftrace
現(xiàn)在已經(jīng)是內(nèi)核中的一部分了,你不再需要事先安裝它了。也就是說,如果你在使用最近的 Linux 系統(tǒng),那么 ftrace
是已經(jīng)啟用了的。為了驗證 ftrace
是否可用,運行 mount
命令并查找 tracefs
。如果你看到類似下面的輸出,表示 ftrace
已經(jīng)啟用,你可以輕松地嘗試本文中下面的例子。下面有些命令需要在 root 用戶下使用(用 sudo
執(zhí)行是不夠的)。
# mount | grep tracefs
none on /sys/kernel/tracing type tracefs (rw,relatime,seclabel)
要想使用 ftrace
,你首先需要進(jìn)入上面 mount
命令中找到的特定目錄中,在那個目錄下運行文章中的其他命令。
# cd /sys/kernel/tracing
一般的工作流程
首先,你需要理解捕捉蹤跡和獲取輸出的一般流程。如果你直接運行 ftrace
,不會運行任何特定的 ftrace
命令。相反的,基本操作是通過標(biāo)準(zhǔn) Linux 命令來寫入或讀取一些文件。
一般的步驟如下:
- 通過寫入一些特定文件來啟用/結(jié)束追蹤
- 通過寫入一些特定文件來設(shè)置/取消追蹤時的過濾規(guī)則
- 從文件中讀取基于第 1 和 2 步的追蹤輸出
- 從文件中清除早期輸出或緩沖區(qū)
- 縮小到你的特定用例(你要追蹤的內(nèi)核函數(shù)),重復(fù) 1、2、3、4 步
可用的追蹤器類型
有多種不同的追蹤器可供使用。之前提到,在運行任何命令前,你需要進(jìn)入一個特定的目錄下,因為需要的文件在這些目錄下。我在我的例子中使用了相對路徑(而不是絕對路徑)。
你可以查看 available_tracers
文件內(nèi)容來查看所有可用的追蹤器類型。你可以看下面列出了幾個。不需要擔(dān)心這些:
$ pwd
/sys/kernel/tracing
$ sudo cat available_tracers
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
在所有輸出的追蹤器中,我會聚焦于下面三個特殊的:啟用追蹤的 function
和 function_graph
,以及停止追蹤的 nop
。
確認(rèn)當(dāng)前的追蹤器
通常情況默認(rèn)的追蹤器設(shè)定為 nop
。即在特殊文件中 current_tracer
中的 “無操作”,這意味著追蹤目前是關(guān)閉的:
$ pwd
/sys/kernel/tracing
$ sudo cat current_tracer
nop
查看追蹤輸出
在啟用任何追蹤功能之前,請你看一下保存追蹤輸出的文件。你可以用 cat 命令查看名為 trace
的文件的內(nèi)容:
# 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
(文件原本內(nèi)容為 nop
,意味著追蹤是關(guān)閉的)。把這個操作看成是啟用追蹤的一種方式:
$ pwd
/sys/kernel/tracing
$ sudo cat current_tracer
nop
$ echo function > current_tracer
$
$ cat current_tracer
function
查看 function 追蹤器的更新追蹤輸出
現(xiàn)在你已啟用追蹤,是時候查看輸出了。如果你查看 trace
文件內(nèi)容,你將會看到許多被連續(xù)寫入的內(nèi)容。我通過管道只展示了文件內(nèi)容的前 20 行。根據(jù)左邊輸出的標(biāo)題,你可以看到在某個 CPU 上運行的任務(wù)和進(jìn)程 ID。根據(jù)右邊輸出的內(nèi)容,你可以看到具體的內(nèi)核函數(shù)和其父函數(shù)。中間顯示了時間戳信息:
# 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
請記住當(dāng)追蹤打開后,這意味著追蹤結(jié)果會被一直連續(xù)寫入直至你關(guān)閉追蹤。
關(guān)閉追蹤
關(guān)閉追蹤是簡單的。你只需要在 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
文件的輸出格式已經(jīng)發(fā)生變化?,F(xiàn)在,你可以看到 CPU ID 和內(nèi)核函數(shù)的執(zhí)行時長。接下來,一個花括號表示一個函數(shù)的開始,以及它內(nèi)部調(diào)用了哪些其他函數(shù):
# 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 | }
啟用追蹤的設(shè)置來增加追蹤的深度
你可以使用下面的步驟來調(diào)整追蹤器以看到更深層次的函數(shù)調(diào)用。完成之后,你可以查看 trace
文件的內(nèi)容并發(fā)現(xiàn)輸出變得更加詳細(xì)了。為了文章的可讀性,這個例子的輸出被省略了:
# cat max_graph_depth
0
# echo 1 > max_graph_depth ## or:
# echo 2 > max_graph_depth
# sudo cat trace
查找要追蹤的函數(shù)
上面的步驟足以讓你開始追蹤。但是它產(chǎn)生的輸出內(nèi)容是巨大的,當(dāng)你想試圖找到自己感興趣的內(nèi)容時,往往會很困難。通常你更希望能夠只追蹤特定的函數(shù),而忽略其他函數(shù)。但如果你不知道它們確切的名稱,你怎么知道要追蹤哪些進(jìn)程?有一個文件可以幫助你解決這個問題 —— available_filter_functions
文件提供了一個可供追蹤的函數(shù)列表:
$ sudo wc -l available_filter_functions
63165 available_filter_functions
查找一般的內(nèi)核函數(shù)
現(xiàn)在試著搜索一個你所知道的簡單內(nèi)核函數(shù)。用戶空間由 malloc
函數(shù)用來分配內(nèi)存,而內(nèi)核由 kmalloc
函數(shù),它提供類似的功能。下面是所有與 kmalloc
相關(guān)的函數(shù):
$ 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
[...]
查找內(nèi)核模塊或者驅(qū)動相關(guān)函數(shù)
在 available_filter_functions
文件的輸出中,你可以看到一些以括號內(nèi)文字結(jié)尾的行,例如下面的例子中的 [kvm_intel]
。這些函數(shù)與當(dāng)前加載的內(nèi)核模塊 kvm_intel
有關(guān)。你可以運行 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
僅追蹤特定的函數(shù)
為了實現(xiàn)對特定函數(shù)或模式的追蹤,你可以利用 set_ftrace_filter
文件來指定你要追蹤上述輸出中的哪些函數(shù)。這個文件也接受 *
模式,它可以擴(kuò)展到包括具有給定模式的其他函數(shù)。作為一個例子,我在我的機(jī)器上使用 ext4 文件系統(tǒng)。我可以用下面的命令指定 ext4 的特定內(nèi)核函數(shù)來追蹤:
# 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)在當(dāng)你可以看到追蹤輸出時,你只能看到與內(nèi)核函數(shù)有關(guān)的 ext4
函數(shù),而你之前已經(jīng)為其設(shè)置了一個過濾器。所有其他的輸出都被忽略了:
# 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
排除要被追蹤的函數(shù)
你并不總是知道你想追蹤什么,但是,你肯定知道你不想追蹤什么。因此,有一個 set_ftrace_notrace
—— 請注意其中的 “no”。你可以在這個文件中寫下你想要的模式,并啟用追蹤。這樣除了所提到的模式外,任何其他東西都會被追蹤到。這通常有助于刪除那些使我們的輸出變得混亂的普通功能:
$ sudo cat set_ftrace_notrace
#### no functions disabled ####
具有目標(biāo)性的追蹤
到目前為止,你一直在追蹤內(nèi)核中發(fā)生的一切。但是,它無法幫助你追蹤與某個特定命令有關(guān)的事件。為了達(dá)到這個目的,你可以按需打開和關(guān)閉跟蹤,并且在它們之間,運行我們選擇的命令,這樣你就不會在跟蹤輸出中得到額外的輸出。你可以通過向 tracing_on
寫入 1
來啟用跟蹤,寫 0
來關(guān)閉跟蹤。
# 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
如果你想追蹤與正在運行的特定進(jìn)程有關(guān)的活動,你可以將該 PID 寫入一個名為 set_ftrace_pid
的文件,然后啟用追蹤。這樣一來,追蹤就只限于這個 PID,這在某些情況下是非常有幫助的。
$ sudo echo $PID > set_ftrace_pid
總結(jié)
ftrace
是一個了解 Linux 內(nèi)核內(nèi)部工作的很好方式。通過一些練習(xí),你可以學(xué)會對 ftrace
進(jìn)行調(diào)整以縮小搜索范圍。要想更詳細(xì)地了解 ftrace
和它的高級用法,請看 ftrace
的核心作者 Steven Rostedt 寫的這些優(yōu)秀文章。