Trace 對于軟體的維護和性能分析至關重要，ftrace 是目前 Linux 核心中一種新的 trace 工具。本文介紹 ftrace 的使用和實作原理，并将 ftrace 和 systemTap，LTTng 等軟體進行對比，希望讀者能夠對 ftrace 有一個全面的了解。
2
2009 年 10 月 15 日
在 IBM Bluemix 雲平台上開發并部署您的下一個應用。
<a href="https://developer.ibm.com/sso/bmregistration?lang=zh_CN&ca=dwchina-_-bluemix-_-l-cn-ftrace-_-sidebar">開始您的試用</a>
ftrace 的作用是幫助開發人員了解 Linux 核心的運作時行為，以便進行故障調試或性能分析。
最早 ftrace 是一個 function tracer，僅能夠記錄核心的函數調用流程。如今 ftrace 已經成為一個 framework，采用 plugin 的方式支援開發人員添加更多種類的 trace 功能。
Ftrace 由 RedHat 的 Steve Rostedt 負責維護。到 2.6.30 為止，已經支援的 tracer 包括：
Function tracer 和 Function graph tracer: 跟蹤函數調用。
Schedule switch tracer: 跟蹤程序排程情況。
Wakeup tracer：跟蹤程序的排程延遲，即高優先級程序從進入 ready 狀态到獲得 CPU 的延遲時間。該 tracer 隻針對實時程序。
Irqsoff tracer：當中斷被禁止時，系統無法相應外部事件，比如鍵盤和滑鼠，時鐘也無法産生 tick 中斷。這意味着系統響應延遲，irqsoff 這個 tracer 能夠跟蹤并記錄核心中哪些函數禁止了中斷，對于其中中斷禁止時間最長的，irqsoff 将在 log 檔案的第一行标示出來，進而使開發人員可以迅速定位造成響應延遲的罪魁禍首。
Preemptoff tracer：和前一個 tracer 類似，preemptoff tracer 跟蹤并記錄禁止核心搶占的函數，并清晰地顯示出禁止搶占時間最長的核心函數。
Preemptirqsoff tracer: 同上，跟蹤和記錄禁止中斷或者禁止搶占的核心函數，以及禁止時間最長的函數。
Branch tracer: 跟蹤核心程式中的 likely/unlikely 分支預測命中率情況。 Branch tracer 能夠記錄這些分支語句有多少次預測成功。進而為優化程式提供線索。
Hardware branch tracer：利用處理器的分支跟蹤能力，實作硬體級别的指令跳轉記錄。在 x86 上，主要利用了 BTS 這個特性。
Initcall tracer：記錄系統在 boot 階段所調用的 init call 。
Mmiotrace tracer：記錄 memory map IO 的相關資訊。
Power tracer：記錄系統電源管理相關的資訊。
Sysprof tracer：預設情況下，sysprof tracer 每隔 1 msec 對核心進行一次采樣，記錄函數調用和堆棧資訊。
Kernel memory tracer: 記憶體 tracer 主要用來跟蹤 slab allocator 的配置設定情況。包括 kfree，kmem_cache_alloc 等 API 的調用情況，使用者程式可以根據 tracer 收集到的資訊分析内部碎片情況，找出記憶體配置設定最頻繁的代碼片斷，等等。
Workqueue statistical tracer：這是一個 statistic tracer，統計系統中所有的 workqueue 的工作情況，比如有多少個 work 被插入 workqueue，多少個已經被執行等。開發人員可以以此來決定具體的 workqueue 實作，比如是使用 single threaded workqueue 還是 per cpu workqueue.
Event tracer: 跟蹤系統事件，比如 timer，系統調用，中斷等。
這裡還沒有列出所有的 tracer，ftrace 是目前非常活躍的開發領域，新的 tracer 将不斷被加入核心。
<a href="http://www.ibm.com/developerworks/cn/linux/l-cn-ftrace/index.html#ibm-pcon">回頁首</a>
Ftrace 最初是在 2.6.27 中出現的，那個時候，systemTap 已經開始嶄露頭角，其他的 trace 工具包括 LTTng 等也已經發展多年。那為什麼人們還要再開發一個 trace 工具呢？
SystemTap 項目是 Linux 社群對 SUN Dtrace 的反應，目标是達到甚至超越 Dtrace 。是以 SystemTap 設計比較複雜，Dtrace 作為 SUN 公司的一個項目開發了多年才最終穩定釋出，況且得到了 Solaris 核心中每個子系統開發人員的大力支援。 SystemTap 想要趕超 Dtrace，困難不僅是一樣，而且更大，是以她始終處在不斷完善自身的狀态下，在真正的産品環境，人們依然無法放心的使用她。不當的使用和 SystemTap 自身的不完善都有可能導緻系統崩潰。
Ftrace 的設計目标簡單，本質上是一種靜态代碼插裝技術，不需要支援某種程式設計接口讓使用者自定義 trace 行為。靜态代碼插裝技術更加可靠，不會因為使用者的不當使用而導緻核心崩潰。 ftrace 代碼量很小，穩定可靠。實際上，即使是 Dtrace，大多數使用者也隻使用其靜态 trace 功能。是以 ftrace 的設計非常務實。
從 2.6.30 開始，ftrace 支援 event tracer，其實作和功能與 LTTng 非常類似，或許将來 ftrace 會同 LTTng 進一步融合，各自取長補短。 ftrace 有定義良好的 ASCII 接口，可以直接閱讀，這對于核心開發人員非常具有吸引力，因為隻需核心代碼加上 cat 指令就可以工作了，相當友善； LTTng 則采用 binary 接口，更利于專門工具分析使用。此外他們内部 ring buffer 的實作不相同，ftrace 對所有 tracer 都采用同一個 ring buffer，而 LTTng 則使用各自不同的 ring buffer 。
目前，或許将來 LTTng 都隻能是核心主分支之外的工具。她主要受到嵌入式工程師的歡迎，而核心開發人員則更喜歡 ftrace 。
Ftrace 的實作依賴于其他很多核心特性，比如 tracepoint[3]，debugfs[2]，kprobe[4]，IRQ-Flags[5] 等。限于篇幅，關于這些技術的介紹請讀者自行查閱相關的參考資料。
ftrace 在核心态工作，使用者通過 debugfs 接口來控制和使用 ftrace 。從 2.6.30 開始，ftrace 支援兩大類 tracer：傳統 tracer 和 Non-Tracer Tracer 。下面将分别介紹他們的使用。
使用傳統的 ftrace 需要如下幾個步驟：
選擇一種 tracer
使能 ftrace
執行需要 trace 的應用程式，比如需要跟蹤 ls，就執行 ls
關閉 ftrace
檢視 trace 檔案
使用者通過讀寫 debugfs 檔案系統中的控制檔案完成上述步驟。使用 debugfs，首先要挂載她。指令如下：
此時您将在 /debug 目錄下看到 tracing 目錄。 Ftrace 的控制接口就是該目錄下的檔案。
選擇 tracer 的控制檔案叫作 current_tracer 。選擇 tracer 就是将 tracer 的名字寫入這個檔案，比如，使用者打算使用 function tracer，可輸入如下指令：
檔案 tracing_enabled 控制 ftrace 的開始和結束。
上面的指令使能 ftrace 。同樣，将 0 寫入 tracing_enable 檔案便可以停止 ftrace 。
ftrace 的輸出資訊主要儲存在 3 個檔案中。
Trace，該檔案儲存 ftrace 的輸出資訊，其内容可以直接閱讀。
latency_trace，儲存與 trace 相同的資訊，不過組織方式略有不同。主要為了使用者能友善地分析系統中有關延遲的資訊。
trace_pipe 是一個管道檔案，主要為了友善應用程式讀取 trace 内容。算是擴充接口吧。
下面詳細解析各種 tracer 的輸出資訊。
Function tracer 的輸出
Function tracer 跟蹤函數調用流程，其 trace 檔案格式如下：
可以看到，tracer 檔案類似一張報表，前 4 行是表頭。第一行顯示目前 tracer 的類型。第三行是 header 。
對于 function tracer，該表将顯示 4 列資訊。首先是程序資訊，包括程序名和 PID ；第二列是 CPU，在 SMP 體系下，該列顯示核心函數具體在哪一個 CPU 上執行；第三列是時間戳；第四列是函數資訊，預設情況下，這裡将顯示核心函數名以及它的上一層調用函數。
通過對這張報表的解讀，使用者便可以獲得完整的核心運作時流程。這對于了解核心代碼也有很大的幫助。有志于精讀核心代碼的讀者，或許可以考慮考慮 ftrace 。
如上例所示，path_walk() 調用了 path_put 。此後 path_put 又調用了 dput，進而 dput 再調用 _atomic_dec_and_lock 。
Schedule switch tracer 的輸出
Schedule switch tracer 記錄系統中的程序切換資訊。在其輸出檔案 trace 中 , 輸出行的格式有兩種：
第一種表示程序切換資訊：
第二種表示程序 wakeup 的資訊：
這裡舉一個執行個體：
第一行表示程序 fon 程序 wakeup 了 bash 程序。其中 fon 程序的 pid 為 6263，優先級為 120，程序狀态為 Ready 。她将程序 ID 為 2717 的 bash 程序喚醒。
第二行表示程序切換發生，從 fon 切換到 bash 。
irqsoff tracer 輸出
有四個 tracer 記錄核心在某種狀态下最長的時延，irqsoff 記錄系統在哪裡關中斷的時間最長； preemptoff/preemptirqsoff 以及 wakeup 分别記錄禁止搶占時間最長的函數，或者系統在哪裡排程延遲最長 (wakeup) 。這些 tracer 資訊對于實時應用具有很高的參考價值。
為了更好的表示延遲，ftrace 提供了和 trace 類似的 latency_trace 檔案。以 irqsoff 為例示範如何解讀該檔案的内容。
在檔案的頭部，irqsoff tracer 記錄了中斷禁止時間最長的函數。在本例中，函數 trace_hardirqs_on 将中斷禁止了 12us 。
檔案中的每一行代表一次函數調用。 Cmd 代表程序名，pid 是程序 ID 。中間有 5 個字元，分别代表了 CPU#，irqs-off 等資訊，具體含義如下：
CPU# 表示 CPU ID ；
irqs-off 這個字元的含義如下：’ d ’表示中斷被 disabled 。’ . ’表示中斷沒有關閉；
need-resched 字元的含義：’ N ’表示 need_resched 被設定，’ . ’表示 need-reched 沒有被設定，中斷傳回不會進行程序切換；
hardirq/softirq 字元的含義 : 'H' 在 softirq 中發生了硬體中斷， 'h' – 硬體中斷，’ s ’表示 softirq，’ . ’不在中斷上下文中，普通狀态。
preempt-depth: 當搶占中斷使能後，該域代表 preempt_disabled 的級别。
在每一行的中間，還有兩個域：time 和 delay 。 time: 表示從 trace 開始到目前的相對時間。 Delay 突出顯示那些有高延遲的地方以便引起使用者注意。當其顯示為 ! 時，表示需要引起注意。
function graph tracer 輸出
Function graph tracer 和 function tracer 類似，但輸出為函數調用圖，更加容易閱讀：
OVERHEAD 為 ! 時提醒使用者注意，該函數的性能比較差。上面的例子中可以看到 sys_open 調用了 do_sys_open，依次又調用了 getname()，依此類推。
Sysprof tracer 的輸出
Sysprof tracer 定時對核心進行采樣，她的輸出檔案中記錄了每次采樣時核心正在執行哪些核心函數，以及當時的核心堆棧情況。
每一行前半部分的格式和 3.1.1 中介紹的 function tracer 一樣，隻是，最後一部分 FUNCTION 有所不同。
Sysprof tracer 中，FUNCTION 列格式如下：
當 identifier 為 0 時，代表一次采樣的開始，此時第三個數字代表目前程序的 PID ；
Identifier 為 1 代表核心态的堆棧資訊；當 identifier 為 2 時，代表使用者态堆棧資訊；顯示堆棧資訊時，第三列顯示的是 frame_pointer，使用者可能需要打開 system map 檔案查找具體的符号，這是 ftrace 有待改進的一個地方吧。
當 identifier 為 3 時，代表一次采樣結束。
從 2.6.30 開始，ftrace 還支援幾種 Non-tracer tracer，所謂 Non-tracer tracer 主要包括以下幾種：
Max Stack Tracer
Profiling (branches / unlikely / likely / Functions)
Event tracing
和傳統的 tracer 不同，Non-Tracer Tracer 并不對每個核心函數進行跟蹤，而是一種類似邏輯分析儀的模式，即對系統進行采樣，但似乎也不完全如此。無論怎樣，這些 tracer 的使用方法和前面所介紹的 tracer 的使用稍有不同。下面我将試圖描述這些 tracer 的使用方法。
Max Stack Tracer 的使用
這個 tracer 記錄核心函數的堆棧使用情況，使用者可以使用如下指令打開該 tracer：
從此，ftrace 便留心記錄核心函數的堆棧使用。 Max Stack Tracer 的輸出在 stack_trace 檔案中：
從上例中可以看到核心堆棧最滿的情況如下，有 43 層函數調用，堆棧使用大小為 3088 位元組。此外還可以在 Location 這列中看到整個的 calling stack 情況。這在某些情況下，可以提供額外的 debug 資訊，幫助開發人員定位問題。
Branch tracer
Branch tracer 比較特殊，她有兩種模式，即是傳統 tracer，又實作了 profiling tracer 模式。
作為傳統 tracer 。其輸出檔案為 trace，格式如下：
在 FUNCTION 列中，顯示了 4 類資訊：
函數名，檔案和行号，用中括号引起來的部分，顯示了分支的資訊，假如該字元串為 ok，表明 likely/unlikely 傳回為真，否則字元串為 MISS 。舉例來說，在檔案 file.h 的第 29 行，函數 fput_light 中，有一個 likely 分支在運作時解析為真。我們看看 file.h 的第 29 行：
Trace 結果告訴我們，在 688 秒的時候，第 29 行代碼被執行，且預測結果為 ok，即 unlikely 成功。
Branch tracer 作為 profiling tracer 時，其輸出檔案為 profile_annotated_branch，其中記錄了 likely/unlikely 語句完整的統計結果。
下面是檔案 sched_rt.c 的第 1449 行的代碼：
記錄表明，unlikely 在這裡有 46 次為假，命中率為 100% 。假如為真的次數更多，則說明這裡應該改成 likely 。
Workqueue profiling
假如您在核心編譯時選中該 tracer，ftrace 便會統計 workqueue 使用情況。您隻需使用下面的指令檢視結果即可：
典型輸出如下：
可以看到 workqueue events 在 CPU 0 上有 38044 個 worker 被插入并執行。
Event tracer
Event tracer 不間斷地記錄核心中的重要事件。使用者可以用下面的指令檢視 ftrace 支援的事件。
下面以跟蹤程序切換為例講述 event tracer 的使用。首先打開 event tracer，并記錄程序切換：
上面三個指令的作用是一樣的，您可以任選一種。
此時可以檢視 ftrace 的輸出檔案 trace:
我想您會發現該檔案很容易解讀。如上例，表示一個程序切換 event，從 idle 程序切換到 sealer 程序。
研究 tracer 的實作是非常有樂趣的。了解 ftrace 的實作能夠啟發我們在自己的系統中設計更好的 trace 功能。
Ftrace 的整體構架：
Ftrace 有兩大組成部分，一是 framework，另外就是一系列的 tracer 。每個 tracer 完成不同的功能，它們統一由 framework 管理。 ftrace 的 trace 資訊儲存在 ring buffer 中，由 framework 負責管理。 Framework 利用 debugfs 系統在 /debugfs 下建立 tracing 目錄，并提供了一系列的控制檔案。
本文并不打算系統介紹 tracer 和 ftrace framework 之間的接口，隻是打算從純粹理論的角度，簡單剖析幾種具體 tracer 的實作原理。假如讀者需要開發新的 tracer，可以參考某個 tracer 的源代碼。
Ftrace 采用 GCC 的 profile 特性在所有核心函數的開始部分加入一段 stub 代碼，ftrace 重載這段代碼來實作 trace 功能。
gcc 的 -pg 選項将在每個函數入口處加入對 mcount 的調用代碼。比如下面的 C 代碼。
用 gcc 編譯：
反彙編如下：
再加入 -gp 選項編譯：
得到的彙編如下：
增加 pg 選項後，gcc 在函數 foo 的入口處加入了對 mcount 的調用：call _mcount 。原本 mcount 由 libc 實作，但您知道核心不會連接配接 libc 庫，是以 ftrace 編寫了自己的 mcount stub 函數，并借此實作 trace 功能。
在每個核心函數入口加入 trace 代碼，必然會影響核心的性能，為了減小對核心性能的影響，ftrace 支援動态 trace 功能。
當 CONFIG_DYNAMIC_FTRACE 被選中後，核心編譯時會調用一個 perl 腳本：recordmcount.pl 将每個函數的位址寫入一個特殊的段：__mcount_loc
在核心初始化的初期，ftrace 查詢 __mcount_loc 段，得到每個函數的入口位址，并将 mcount 替換為 nop 指令。這樣在預設情況下，ftrace 不會對核心性能産生影響。
當使用者打開 ftrace 功能時，ftrace 将這些 nop 指令動态替換為 ftrace_caller，該函數将調用使用者注冊的 trace 函數。其具體的實作在相應 arch 的彙編代碼中，以 x86 為例，在 entry_32.s 中：
Function tracer 将 line10 這行代碼替換為 function_trace_call() 。這樣每個核心函數都将調用 function_trace_call() 。
在 function_trace_call() 函數内，ftrace 記錄函數調用堆棧資訊，并将結果寫入 ring buffer，稍後，使用者可以通過 debugfs 的 trace 檔案讀取該 ring buffer 中的内容。
Irqsoff tracer 的實作依賴于 IRQ-Flags 。 IRQ-Flags 是 Ingo Molnar 維護的一個核心特性。使得使用者能夠在中斷關閉和打開時得到通知，ftrace 重載了其通知函數，進而能夠記錄中斷禁止時間。即，中斷被關閉時，記錄下當時的時間戳。此後，中斷被打開時，再計算時間差，由此便可得到中斷禁止時間。
IRQ-Flags 封裝開關中斷的宏定義：
ftrace 在檔案 ftrace_irqsoff.c 中重載了 trace_hardirqs_on 。具體代碼不再羅列，主要是使用了 sched_clock（）函數來獲得時間戳。
Hw-branch 隻在 IA 處理器上實作，依賴于 x86 的 BTS 功能。 BTS 将 CPU 實際執行到的分支指令的相關資訊儲存下來，即每個分支指令的源位址和目标位址。
軟體可以指定一塊 buffer，處理器将每個分支指令的執行情況寫入這塊 buffer，之後，軟體便可以分析這塊 buffer 中的功能。
Linux 核心的 DS 子產品封裝了 x86 的 BTS 功能。 Debug Support 子產品封裝了和底層硬體的接口，主要支援兩種功能：Branch trace store(BTS) 和 precise-event based sampling (PEBS) 。 ftrace 主要使用了 BTS 功能。
核心代碼中常使用 likely 和 unlikely 提高編譯器生成的代碼品質。 Gcc 可以通過合理安排彙編代碼最大限度的利用處理器的流水線。合理的預測是 likely 能夠提高性能的關鍵，ftrace 為此定義了 branch tracer，跟蹤程式中 likely 預測的正确率。
為了實作 branch tracer，重新定義了 likely 和 unlikely 。具體的代碼在 compiler.h 中。
其中 __branch_check 的實作如下：
ftrace_likely_update() 将記錄 likely 判斷的正确性，并将結果儲存在 ring buffer 中，之後使用者可以通過 ftrace 的 debugfs 接口讀取分支預測的相關資訊。進而調整程式代碼，優化性能。
本文講解了 ftrace 的基本使用。在實踐中，ftrace 是一個非常有效的性能調優和 debug 分析工具，每個人使用她的方法和角度都不相同，一定有很多 best practice，這非本文所能涉及。但希望通過本文的講解，能讓讀者對 ftrace 形成一個基本的了解，進而在具體工作中使用她。
【新浪微網誌】 張昺華--sky
【twitter】 @sky2030_
【facebook】 張昺華 zhangbinghua
本文版權歸作者和部落格園共有，歡迎轉載，但未經作者同意必須保留此段聲明，且在文章頁面明顯位置給出原文連接配接，否則保留追究法律責任的權利.