如何利用ftrace精確跟蹤特定進程調度信息

網上已經有很多闡述ftrace原理和使用方法的文章，本文不會面面俱到的介紹所有涉及的原理和方法，只會聚焦在闡述ftrace的event tracing機制，以及如何利用該機制（包括其他一些方法配合）去跟蹤某個進程的調度信息。本文的分析基於處理器為ARM64的多核手機平台，linux版本為msm-4.19，為了行文方便，我們還是先回顧下ftrace的基本概念。

一、 ftrace基本原理

圖1-1 ftrace框架

一句話總結：各類tracer往ftrace主框架注冊，不同的trace則在不同的probe點把信息通過probe函數給送到ring buffer中，再由暴露在用戶態debufs實現相關控制。

對不同tracer來說

1）需要實現probe點（需要跟蹤的代碼偵測點），有的probe點需要靜態代碼實現，有的probe點借助編譯器在運行時動態替換，event tracing屬於前者；

2）還要實現具體的probe函數，把需要記錄的信息送到ring buffer中；

3）增加debugfs 相關的文件，實現信息的解析和控制。

而ring buffer 和debugfs的通用部分的管理由框架負責。

二、ftrace event tracing原理介紹

圖2-1 ftrace event tracing原理

 

其它一些 trace 工具也具有相似的工作流程，需要一個 probe 點，一個 probe 函數，一種保存 log 信息的機制，還有用於戶進行交互的接口（分別對應圖中 A、B、C、D 點）。它們發現可以利用 function trace 的后兩部分，也就是環形緩存的管理和用戶交互接口部分的代碼，只需要實現自己的 probe 點和 probe 函數就可以了。於是在 function trace 進入內核 mainline 后，kprobe 也借用了該機制。

1.  tracepoint 的實現原理

tracepoint 是早就存在於內核當中的一種 trace 工具，具體原理不再詳細展開，示例代碼大家可參照內核源碼 sample/tracepoints/相關內容。需要使用小於3.9版本的內核來看。原因是linux不期望開發人員直接使用 tracepoint，而應該使用更高層的 event tracing，但是有兩個宏（DECLARE_TRACE和DEFINE_TRACE）會被trace event使用，需要看下。

（1） DECLARE_TRACE

該宏在<linux/tracepoint.h>被定義。

trace_##name最終調用__DO_TRACE宏將信息送到ring buffer中。

reg/unregister_trace_subsys_event 負責注冊或注銷 probe 函數，probe 函數的原型由 TP_PROTO 宏給出。例如：wakeup相關tracer則是調用了register_trace_sched_wakeup。

使用 tracepoint 需要自己實現 probe 函數，event tracing通過一套通用的機制省去了內核模塊/驅動自己實現probe函數的麻煩。

• __DO_TRACE

 

該(it_func_ptr)->func和(tp)->funcs在enable event的時候會被賦值，下文會有展開描述。

（2） DEFINE_TRACE

定義了__tpstrtab_##name字符串變量和struct tracepoint __tracepoint_##name。當然二者都放在了鏈接腳本專門的p里（詳見include/asm-generic/vmlinux.lds.h）。編譯后可查看system.map去查看具體的變量位置。

2. event tracing的實現原理

event tracing 可以理解為 tracepoint 加 function trace 的接口組合而成，提供了接口給內核開發者，讓其快速的定義信息保存的格式以及如何打印出來。具體原理可參照samples/trace_events/下的例子。

（1）TRACE_EVENT

該宏可以實現probe點、probe函數、event的格式，以及event打印出來的格式。

第1次通過包含include/linux/tracepoint.h，將其展開成DECLARE_TRACE。

第2次通過include/trace/trace_events.h，將其展開成DECLARE_EVENT_CLASS，而在該頭文件中DECLARE_EVENT_CLASS會被多次展開。

第3次通過包含include/trace/define_trace.h，將其展開成DEFINE_TRACE

其中，include/linux/和include/trace/define_trace.h必須顯示被使用者顯式包含。

總結下：

• trace_##name，是放置probe點的函數實現，如果該event enable則調用注冊進來的trace_event_raw_event_##call

• trace_raw_output_##call，是輸出信息的函數實現（cat trace時輸出）

• trace_event_raw_event_##call，是probe函數

（2）trace_##name

細節參見上文宏展開結果。

（3）trace_raw_output_##call

該函數在cat trace文件節點的時候會被調用。

（4）trace_event_raw_event_##call

綜上，通過上述宏展開，得到：

3. 關鍵流程梳理

（1）定義event

使用TRACE_EVENT宏定義event的原型、信息打印格式等。參見上文描述。

（2）記錄event

代碼中靜態埋點，調用trace_##name，放置probe點。參見上文描述。

（3）使能event

假設tracefs已經提前掛載好（可以通過cat /proc/mounts | grep tracefs命令查看）

tracefs /sys/kernel/debug/tracing tracefs rw,seclabel,relatime 0 0

對應命令：

echo 1 > /sys/kernel/debug/tracing/events/<one_trace_event>/enable

對應關鍵代碼流程：

將上文描述的展開后的宏里面的trace_event_raw_event_##call注冊到struct tracepoint_func中進去

（4）輸出event

對應命令：

對應關鍵代碼流程：

print_trace_fmt函數代碼截圖：

funcs->trace，參見上文被賦值成trace_raw_output_##call了。

三、使用ftrace event tracing跟蹤特定進程調度原理

本章我們主要介紹手機平台實現精准跟蹤特定進程調度使用的一些技巧。因為我們最終還是要借助systrace這個ftrace前端，所以簡單介紹ftrace相關tag，包括Java層和Native層如何使用ftrace接口。同時我們要簡單研究下調度相關的trace event以及filter功能，這是解決實際問題的關鍵。

1. Android systrace tag list

使用atrace –list即可查看所有支持的tag list。

2.  用戶態如何使用ftrace

有時候我們還要把用戶態信息和內核信息同步起來，可以通過 trace_marker 實現。

（1）使用trace_marker

Systrace利用ftrace提供了如下兩個接口供用戶程序調用：

• Java層：Trace.traceBegin(tag, name)/Trace.traceEnd(tag)

• Native層 ：ATRACE_BEGIN(name)/ATRACE_END()

當然，也可以根據特定需求，直接利用systrace現成的tag（即還可以使用systrace 設置tag和手動設置sched調度的event filfter搭配起來用）。如果想關閉用戶態的信息打印也是可以的。

（2）開關trace_marker

查看：

cat options/markers

打開：

echo 1 > options/markers

關閉：

echo 0 > options/markers

 

3. Android Linux狀態

 

（1）Android狀態轉移

圖3-1 Android進程狀態轉移

1）Runnable -> Running：就緒態的進程獲得了CPU的時間片，進入運行態；

2）Running -> Runnable: 運行態的進程在時間片用完后，必須出讓CPU，進入就緒態；

3）Running -> Blocked：當進程請求資源的使用權(如外設)或等待事件發生(如I/O完成)時，由運行態轉換為阻塞態；

4）Blocked -> Runnable：當進程已經獲取所需資源的使用權或者等待事件已完成時，中斷處理程序必須把相應進程的狀態由阻塞態轉為就緒態。

（2）Linux原生狀態信息

4. 調度相關events分析

可以通過cat available_events | grep sched:命令或者ls events/sched/去查看內核已經實現調度相關的events。結合上文的進程狀態分析，我們從中挑選events如下：

這些trace events足夠我們分析線程級別的調度信息。

5.  event的filter功能

為實現問題進程的跟蹤，我們需要使用event的filter功能。

（1）event filter語法簡單介紹

field-name relation-operatior value     

• 對於數字域，可以使用操作符==, !=, <, <=, >, >=, &

• 對於字符串域，可以使用==, !=, ~。目前字符串只支持完全匹配，且最多可以組合16個條件。”~”支持通配符(*,?)。

例子：

（2）event filter format

可以先通過該event目錄下的format查看event消息格式。

我們依次分析根據上文所有需要跟蹤的events，可以根據comm（包括pre_comm，next_comm）和PID等設置過濾條件。

剩下就是把相關events enable就可以了，細節本文就不展開了。

四、實際例子

1. 實際問題

我們在實際的項目中曾經遇到過低概率問題，那個問題是相機切換模式時預覽卡頓並出現閃退。我們第一反應肯定是直接打開systrace去抓取trace回來，但面臨個問題：

1）問題低概率出現，復現一次不容易，需要一次復現就抓到問題現場；

2）抓取log量還是過大（即使只用“sched”和“camera”），問題場景對負載敏感；

3）問題復現后，需要手動停止，這塊手動操作要到10幾秒到1分鍾不等，需要抓取log量盡可能短，以便抓到出問題時的現場，不然ring buffer被覆蓋會導致前功盡棄。

2. 問題分析

問題關鍵是要讓ftrace記錄時間盡可能長，很自然能想到的措施：

1）增大ftrace buffer；

2）減少ftrace記錄的內容，同時要保證足夠問題分析。

雖然該問題概率低，但好消息是只要壓測時間足夠久，還是能復現出來。通過分析規律，我們發現每次相機切換時，都有AlgoInterface::init出現，重點懷疑該對應的進程調度異常，經確認該方法會對應“APSRoutine”的進程異常。

所以解決問題的關鍵就變成：

1）利用ftrace event tracing的過濾功能，跟蹤“APSRoutine”進程，具體的events的filter設置參見上一章內容；

2）要知道對應的用戶態操作，所以必須要打開trace_marker開關（但trace_marker不支持過濾功能，這點比較遺憾，不然可以讓記錄的內容更少）；

3）在Java層crash的地方加hook，crash時抓取ftrace。

所以做了這樣滿足上述條件的小工具。后續我們還可以將其完善，做成支持抓取任意Java/Native層特定進程調度相關log的功能。

這樣我們就把ftrace event tracing的原理及一個基於ftrace的小工具解決實際問題的實踐介紹完了，由於時間和個人水平有限，難免有出錯的地方，如有還請大家幫忙指出。

參考材料

[1] 進程狀態的切換，袁輝輝

[2] ftrace 中 eventtracing 的實現原理，普侯

[3] 史上最長的宏定義，Kernel Exploring

[4] https://www.kernel.org/doc/html/latest/trace/events.html

掃碼關注
“內核工匠”微信公眾號
Linux 內核黑科技 | 技術文章 | 精選教程