ftrace：跟蹤你的內核函數！ | Linux 中國

時間 2019-11-06

標籤 ftrace 跟蹤內核函數 linux 欄目 Linux 简体版

原文原文鏈接

ftrace 是一個 Linux 內核特性，它可以讓你去跟蹤 Linux 內核的函數調用。

爲何要這麼作呢？好吧，若是你調試一個奇怪的問題，而你已經獲得了你的內核版本號中這個問題在源碼中的開始的位置。而你想知道這裏究竟發生了什麼？-- Julia Evans
本文導航◈ 什麼是 ftrace？05%◈ 使用 ftrace 的第一步11%◈ 開始使用 trace-cmd：讓咱們僅跟蹤一個函數19%◈ 下一個 ftrace 技巧：咱們來跟蹤一個進程！35%◈ 「function graph」跟蹤47%◈ 怎樣知道哪些函數可以被跟蹤62%◈ 最後一件事：事件！63%◈ ftrace 是怎樣工做的？73%◈ 更easy地使用 ftrace：brendan gregg 的工具及 kernelshark79%◈ 一個新的超能力85%◈ ftrace 系列文章的一個索引87%編譯自　|　https://jvns.ca/blog/2017/03/19/getting-started-with-ftrace/
　做者　|　Julia Evans
　譯者　|　qhwdwcss

你們好！今天咱們將去討論一個調試工具：ftrace。以前個人博客上尚未討論過它。html

還有什麼能比一個新的調試工具更讓人激動呢？前端

這個很是棒的 ftrace 並不是個新的工具！它大約在 Linux 的 2.6 內核版本號中就有了，時間大約是在 2008 年。這一篇是我用谷歌能找到的最先的文檔[1]。所以，若是你是一個調試系統的「老手」。可能早就已經使用它了！linux

我知道，ftrace 已經存在了大約 2.5 年了（LCTT 譯註：距本文初次寫做時）。但是尚未真正的去學習它。若是我明天要召開一個專題研究會，那麼，關於 ftrace 應該討論些什麼？所以，今天是時間去討論一下它了。chrome

什麼是 ftrace？app

ftrace 是一個 Linux 內核特性，它可以讓你去跟蹤 Linux 內核的函數調用。爲何要這麼作呢？好吧。若是你調試一個奇怪的問題，而你已經獲得了你的內核版本號中這個問題在源碼中的開始的位置，而你想知道這裏究竟發生了什麼？函數

每次在調試的時候。我並不會經常去讀內核源碼，但是，極個別的狀況下會去讀它。好比，本週在工做中，我有一個程序在內核中卡死了。查看到底是調用了什麼函數。可以幫我更好的理解在內核中發生了什麼。哪些系統涉及當中！（在個人那個案例中，它是虛擬內存系統）。工具

我以爲 ftrace 是一個十分好用的工具（它確定沒有 strace 那樣使用普遍，也比它難以使用），但是它仍是值得你去學習。所以。讓咱們開始吧。post

使用 ftrace 的第一步性能

不像 strace 和 perf。ftrace 並不是真正的程序 – 你不能僅僅執行 ftrace my_cool_function。那樣太easy了！

若是你去讀使用 ftrace 調試內核[2]，它會告訴你從 cd /sys/kernel/debug/tracing 開始，而後作很是多文件系統的操做。

對於我來講，這種辦法太麻煩——一個使用 ftrace 的簡單樣例像是這樣：

cd /sys/kernel/debug/tracing
echo function > current_tracer
echo do_page_fault > set_ftrace_filter
cat trace

這個文件系統是跟蹤系統的接口（「給這些奇妙的文件賦值，而後該發生的事情就會發生」）理論上看起來彷佛可用，但是它不是個人首選方式。

幸運的是。ftrace 團隊也考慮到這個並不友好的用戶界面，所以，它有了一個更易於使用的界面。它就是 trace-cmd！！

！trace-cmd 是一個帶命令行參數的普通程序。咱們後面將使用它！

我在 LWN 上找到了一個 trace-cmd 的使用介紹：trace-cmd: Ftrace 的一個前端[3]。

開始使用 trace-cmd：讓咱們僅跟蹤一個函數

首先，我需要去使用 sudo apt-get install trace-cmd 安裝 trace-cmd。這一步很是easy。

對於第一個 ftrace 的演示，我決定去了解個人內核怎樣去處理一個頁面故障。當 Linux 分配內存時。它經常偷懶，（「你並不是真的計劃去使用內存，對嗎？」）。

這意味着。當一個應用程序嘗試去對分配給它的內存進行寫入時。就會發生一個頁面故障，而這個時候。內核纔會真正的爲應用程序去分配物理內存。

咱們開始使用 trace-cmd 並讓它跟蹤 do_page_fault 函數。

$ sudo trace-cmd record -p function -l do_page_fault
plugin 'function'
Hit Ctrl^C to stop recording

我將它執行了幾秒鐘，而後按下了 Ctrl+C。讓我大吃一驚的是，它竟然產生了一個 2.5MB 大小的名爲 trace.dat 的跟蹤文件。咱們來看一下這個文件的內容！

$ sudo trace-cmd report
chrome-15144 [000] 11446.466121: function: do_page_fault
chrome-15144 [000] 11446.467910: function: do_page_fault
chrome-15144 [000] 11446.469174: function: do_page_fault
chrome-15144 [000] 11446.474225: function: do_page_fault
chrome-15144 [000] 11446.474386: function: do_page_fault
chrome-15144 [000] 11446.478768: function: do_page_fault
CompositorTileW-15154 [001] 11446.480172: function: do_page_fault
chrome-1830 [003] 11446.486696: function: do_page_fault
CompositorTileW-15154 [001] 11446.488983: function: do_page_fault
CompositorTileW-15154 [001] 11446.489034: function: do_page_fault
CompositorTileW-15154 [001] 11446.489045: function: do_page_fault

看起來很是整潔 – 它展現了進程名（chrome）、進程 ID（15144）、CPU ID（000）。以及它跟蹤的函數。

經過察看整個文件。（sudo trace-cmd report | grep chrome）可以看到。咱們跟蹤了大約 1.5 秒。在這 1.5 秒的時間段內。Chrome 發生了大約 500 個頁面故障。真是太酷了！這就是咱們作的第一個 ftrace！

下一個 ftrace 技巧：咱們來跟蹤一個進程！

好吧，僅僅看一個函數是有點無聊！

假如我想知道一個程序中都發生了什麼事情。我使用一個名爲 Hugo 的靜態網站生成器。

看看內核爲 Hugo 都作了些什麼事情？

在個人電腦上 Hugo 的 PID 現在是 25314，所以，我使用例如如下的命令去記錄所有的內核函數：

sudo trace-cmd record --help # I read the help!
sudo trace-cmd record -p function -P 25314 # record for PID 25314

sudo trace-cmd report 輸出了 18,000 行。若是你對這些感興趣。你可以看這裏是所有的 18,000 行的輸出[4]。

18,000 行太多了，所以。在這裏僅摘錄當中幾行。

當系統調用 clock_gettime 執行的時候。都發生了什麼：

compat_SyS_clock_gettime
SyS_clock_gettime
clockid_to_kclock
posix_clock_realtime_get
getnstimeofday64
__getnstimeofday64
arch_counter_read
__compat_put_timespec

這是與進程調試相關的一些東西：

cpufreq_sched_irq_work
wake_up_process
try_to_wake_up
_raw_spin_lock_irqsave
do_raw_spin_lock
_raw_spin_lock
do_raw_spin_lock
walt_ktime_clock
ktime_get
arch_counter_read
walt_update_task_ravg
exiting_task

儘管你可能還不理解它們是作什麼的，但是，可以看到所有的這些函數調用也是件很是酷的事情。

「function graph」跟蹤

這裏有另一個模式，稱爲 function_graph。

除了它既可以進入也可以退出一個函數外，其餘的功能和函數跟蹤器是同樣的。

這裏是那個跟蹤器的輸出[5]

sudo trace-cmd record -p function_graph -P 25314

相同，這裏僅僅是一個片段（此次來自 futex 代碼）：

| futex_wake() {
| get_futex_key() {
| get_user_pages_fast() {
1.458 us | __get_user_pages_fast();
4.375 us | }
| __might_sleep() {
0.292 us | ___might_sleep();
2.333 us | }
0.584 us | get_futex_key_refs();
| unlock_page() {
0.291 us | page_waitqueue();
0.583 us | __wake_up_bit();
5.250 us | }
0.583 us | put_page();
+ 24.208 us | }

咱們看到在這個演示樣例中。在 futex_wake 後面調用了 get_futex_key。這是在源碼中真實發生的事情嗎？咱們可以檢查一下！！這裏是在 Linux 4.4 中 futex_wake 的定義[6] (個人內核版本號是 4.4）。

爲節省時間我直接貼出來，它的內容例如如下：

static int
futex_wake(u32 __user *uaddr, unsigned int flags, int nr_wake, u32 bitset)
{
struct futex_hash_bucket *hb;
struct futex_q *this, *next;
union futex_key key = FUTEX_KEY_INIT;
int ret;
WAKE_Q(wake_q);
if (!bitset)
return -EINVAL;
ret = get_futex_key(uaddr, flags & FLAGS_SHARED, &key, VERIFY_READ);

如你所見，在 futex_wake 中的第一個函數調用真的是 get_futex_key！

太棒了！

相比閱讀內核代碼，閱讀函數跟蹤確定是更easy的找到結果的辦法。並且讓人高興的是。還能看到所有的函數用了多長時間。

怎樣知道哪些函數可以被跟蹤

若是你去執行 sudo trace-cmd list -f，你將獲得一個你可以跟蹤的函數的列表。

它很是簡單但是也很是重要。

最後一件事：事件。

現在，咱們已經知道了怎麼去跟蹤內核中的函數。真是太酷了！

另外一類咱們可以跟蹤的東西！有些事件與咱們的函數調用並不相符。

好比，你可能想知道當一個程序被調度進入或者離開 CPU 時。都發生了什麼事件！你可能想經過「盯着」函數調用計算出來，但是，我告訴你，不可行。

因爲函數也爲你提供了幾種事件。所以，你可以看到當重要的事件發生時。都發生了什麼事情。你可以使用 sudo cat /sys/kernel/debug/tracing/available_events 來查看這些事件的一個列表。

我查看了所有的 schedswitch 事件。我並不全然知道 schedswitch 是什麼，但是，我推測它與調度有關。

sudo cat /sys/kernel/debug/tracing/available_events
sudo trace-cmd record -e sched:sched_switch
sudo trace-cmd report

輸出例如如下：

16169.624862: Chrome_ChildIOT:24817 [112] S ==> chrome:15144 [120]
16169.624992: chrome:15144 [120] S ==> swapper/3:0 [120]
16169.625202: swapper/3:0 [120] R ==> Chrome_ChildIOT:24817 [112]
16169.625251: Chrome_ChildIOT:24817 [112] R ==> chrome:1561 [112]
16169.625437: chrome:1561 [112] S ==> chrome:15144 [120]

現在，可以很是清楚地看到這些切換。從 PID 24817 -> 15144 -> kernel -> 24817 -> 1561 -> 15114。(所有的這些事件都發生在同一個 CPU 上）。

ftrace 是怎樣工做的？

ftrace 是一個動態跟蹤系統。當咱們開始 ftrace 內核函數時，函數的代碼會被改變。

讓咱們若是去跟蹤 do_page_fault 函數。

內核將在那個函數的彙編代碼中插入一些額外的指令。以便每次該函數被調用時去提示跟蹤系統。內核之因此可以加入額外的指令的緣由是，Linux 將額外的幾個 NOP 指令編譯進每個函數中。所以，當需要的時候，這裏有加入跟蹤代碼的地方。

這是一個十分複雜的問題，因爲，當不需要使用 ftrace 去跟蹤個人內核時，它根本就不影響性能。

而當我需要跟蹤時，跟蹤的函數越多。產生的開銷就越大。

（也許有些是不正確的，但是。我以爲的 ftrace 就是這樣工做的）

更easy地使用 ftrace：brendan gregg 的工具及 kernelshark

正如咱們在文件裏所討論的。你需要去考慮很是多的關於單個的內核函數/事件直接使用 ftrace 都作了些什麼。可以作到這一點很是酷！

但是也需要作大量的工做！

Brendan Gregg （咱們的 Linux 調試工具「大神」）有個工具倉庫。它使用 ftrace 去提供關於像 I/O 延遲這種各類事情的信息。這是它在 GitHub 上所有的 perf-tools[7] 倉庫。

這裏有一個權衡，那就是這些工具易於使用，但是你被限制僅能用於 Brendan Gregg 承認並作到工具裏面的方面。

它包含了很是多方面！:)

另外一個工具是將 ftrace 的輸出可視化，作的比較好的是 kernelshark[8]。我還沒實用過它，但是看起來彷佛很是實用。

你可以使用 sudo apt-get install kernelshark 來安裝它。

一個新的超能力

我很是高興可以花一些時間去學習 ftrace！對於不論什麼內核工具。不一樣的內核版本號有不一樣的功效，我但願有一天你能發現它很是實用！

ftrace 系列文章的一個索引

最後，這裏是我找到的一些 ftrace 方面的文章。

它們大部分在 LWN （Linux 新聞週刊）上，它是 Linux 的一個極好的資源（你可以購買一個訂閱[9]！

）

◈ 使用 Ftrace 調試內核 - part 1 [2] (Dec 2009, Steven Rostedt)◈ 使用 Ftrace 調試內核 - part 2 [10] (Dec 2009, Steven Rostedt)◈ Linux 函數跟蹤器的祕密 [11] (Jan 2010, Steven Rostedt)◈ trace-cmd：Ftrace 的一個前端 [3] (Oct 2010, Steven Rostedt)◈ 使用 KernelShark 去分析實時調試器 [8] (2011, Steven Rostedt)◈ Ftrace: 神奇的開關 [12] (2014, Brendan Gregg)◈ 內核文檔：（它十分實用） Documentation/ftrace.txt [13]◈ 你能跟蹤的事件的文檔 Documentation/events.txt [14]◈ linux 內核開發上的一些 ftrace 設計文檔（不是實用，而是有趣。) Documentation/ftrace-design.txt [15]

via: https://jvns.ca/blog/2017/03/19/getting-started-with-ftrace/

做者：Julia Evans[17] 譯者：qhwdw 校對：wxy

本文由 LCTT 原創編譯，Linux中國榮譽推出

LCTT 譯者

qhwdw ? ? ? ?共計翻譯： 53 篇貢獻時間：86 天