瞭解 systrace

systrace 是分析 Android 裝置效能的主要工具。不過,這其實是其他工具的包裝函式。這是 atrace 的主機端包裝函式,也是裝置端的可執行檔,可控制使用者空間追蹤並設定 ftrace,以及 Linux 核心中的主要追蹤機制。systrace 會使用 atrace 啟用追蹤功能,然後讀取 ftrace 緩衝區,並將所有內容包裝在獨立的 HTML 檢視器中。(雖然較新的核心支援 Linux 強化 Berkeley 封包篩選器 (eBPF),但本頁內容與 3.18 核心 (無 eFPF) 相關,因為這是 Pixel 或 Pixel XL 使用的核心)。

systrace 由 Google Android 和 Google Chrome 團隊擁有,並以開放原始碼形式提供,是 Catapult 專案的一部分。除了 systrace 之外,Catapult 還包含其他實用公用程式。舉例來說,ftrace 的功能比 systrace 或 atrace 直接啟用的功能更多,且包含一些對偵錯效能問題至關重要的進階功能。(這些功能需要根存取權,且通常需要新的核心)。

執行 systrace

在 Pixel 或 Pixel XL 上偵錯抖動時,請先執行下列指令:

./systrace.py sched freq idle am wm gfx view sync binder_driver irq workq input -b 96000

結合 GPU 和螢幕管道活動所需的額外追蹤點,即可追蹤從使用者輸入內容到畫面上顯示影格的過程。將緩衝區大小設為較大的值,避免遺失事件 (因為如果緩衝區不夠大,部分 CPU 可能會在追蹤記錄中的某個時間點後不含任何事件)。

查看系統追蹤記錄時,請記住每個事件都是由 CPU 上的某個項目觸發

由於 systrace 是以 ftrace 為基礎建構,而 ftrace 會在 CPU 上執行,因此 CPU 上的某個項目必須寫入 ftrace 緩衝區,記錄硬體變更。也就是說,如果您想瞭解顯示器圍欄為何變更狀態,可以查看轉換的確切時間點 CPU 執行的作業 (CPU 執行的作業會觸發記錄中的變更)。這個概念是使用 systrace 分析效能的基礎。

範例:工作框架

這個範例說明一般 UI 管道的系統追蹤記錄。如要跟著範例操作,請下載追蹤記錄的 ZIP 檔案 (其中也包含本節提及的其他追蹤記錄),解壓縮檔案,然後在瀏覽器中開啟 systrace_tutorial.html 檔案。

對於 TouchLatency 等週期性工作負載,UI 管道會依序執行下列作業:

  1. SurfaceFlinger 中的 EventThread 會喚醒應用程式 UI 執行緒,表示該算繪新影格了。
  2. 應用程式會使用 CPU 和 GPU 資源,在 UI 執行緒、RenderThread 和 HWUI 工作中轉譯影格。這是 UI 所耗用的主要容量。
  3. 應用程式會使用繫結器將算繪的影格傳送至 SurfaceFlinger,然後 SurfaceFlinger 會進入休眠狀態。
  4. SurfaceFlinger 中的第二個 EventThread 會喚醒 SurfaceFlinger,以觸發組合和顯示輸出。如果 SurfaceFlinger 判斷沒有工作要執行,就會返回休眠狀態。
  5. SurfaceFlinger 會使用硬體合成器 (HWC)、硬體合成器 2 (HWC2) 或 GL 處理合成作業。HWC 和 HWC2 的組合速度較快且耗電量較低,但會受到晶片系統 (SoC) 的限制。這通常需要約 4 到 6 毫秒,但由於 Android 應用程式一律採用三緩衝區,因此可以與步驟 2 重疊。(雖然應用程式一律會使用三緩衝區,但 SurfaceFlinger 中可能只有一個待處理的影格,因此看起來與雙緩衝區相同)。
  6. SurfaceFlinger 會透過供應商驅動程式將最終輸出內容傳送至螢幕,然後返回休眠狀態,等待 EventThread 喚醒。

以下是從 15409 毫秒開始的影格序列範例:

執行 EventThread 的一般 UI 管道

圖 1. 一般 UI 管道,EventThread 正在執行。

圖 1 是由一般影格包圍的一般影格,因此是瞭解 UI 管道運作方式的絕佳起點。TouchLatency 的 UI 執行緒列在不同時間會顯示不同顏色。長條代表執行緒的不同狀態:

  • 灰色。睡覺。
  • 藍色。可執行 (可以執行,但排程器尚未選取執行)。
  • 綠色。正在執行 (排程器認為正在執行)。
  • 紅色。不中斷睡眠 (通常是在核心中鎖定睡眠)。這可能表示 I/O 負載。對效能問題進行偵錯時,這非常實用。
  • Orange。由於 I/O 負載,無法中斷睡眠。

如要查看不間斷睡眠的原因 (可從 sched_blocked_reason 追蹤點取得),請選取紅色的不間斷睡眠區塊。

EventThread 執行時,TouchLatency 的 UI 執行緒會變成可執行狀態。如要查看喚醒裝置的原因,請按一下藍色部分。

TouchLatency 的 UI 執行緒

圖 2. TouchLatency 的 UI 執行緒。

圖 2 顯示 TouchLatency UI 執行緒是由 tid 6843 喚醒,這對應於 EventThread。UI 執行緒會喚醒、算繪影格,並將其排入佇列,供 SurfaceFlinger 使用。

UI 執行緒喚醒、算繪影格,並將其排入佇列,供 SurfaceFlinger 使用

圖 3. UI 執行緒喚醒、算繪影格,並將其排入佇列,供 SurfaceFlinger 使用。

如果追蹤記錄中已啟用 binder_driver 標記,您可以選取繫結器交易,查看該交易涉及的所有程序資訊。

綁定交易

圖 4. 綁定交易。

圖 4 顯示,在 15,423.65 毫秒時,由於 tid 9579 (TouchLatency 的 RenderThread),Binder:6832_1 在 SurfaceFlinger 中變成可執行狀態。您也可以在繫結器交易的兩側查看 queueBuffer。

在 SurfaceFlinger 端的 queueBuffer 期間,TouchLatency 的待處理影格數會從 1 增加到 2。

待處理的影格從 1 到 2

圖 5. 待處理的影格會從 1 變成 2。

圖 5 顯示三重緩衝,其中有兩個已完成的影格,而應用程式即將開始算繪第三個影格。這是因為我們已捨棄部分影格,因此應用程式會保留兩個待處理影格,而非一個,以盡量避免進一步捨棄影格。

不久後,SurfaceFlinger 的主執行緒會由第二個 EventThread 喚醒,因此可將較舊的待處理影格輸出至螢幕:

第二個 EventThread 會喚醒 SurfaceFlinger 的主執行緒

圖 6. 第二個 EventThread 會喚醒 SurfaceFlinger 的主執行緒。

SurfaceFlinger 會先鎖定較舊的待處理緩衝區,導致待處理緩衝區數量從 2 減少為 1:

SurfaceFlinger 會先鎖定較舊的待處理緩衝區

圖 7. SurfaceFlinger 會先鎖定較舊的待處理緩衝區。

鎖定緩衝區後,SurfaceFlinger 會設定組合,並將最終影格提交至螢幕。(部分區段會啟用為mdss追蹤點的一部分,因此可能不會納入 SoC)。

SurfaceFlinger 會設定合成作業,並提交最終影格

圖 8. SurfaceFlinger 會設定合成作業,並提交最終影格。

接著,mdss_fb0會在 CPU 0 上喚醒。mdss_fb0 是顯示管道的輸出核心執行緒,用於將轉譯的影格輸出至螢幕。請注意,mdss_fb0 是追蹤記錄中的獨立資料列 (向下捲動即可查看):

mdss_fb0 wakes on CPU 0

圖 9. mdss_fb0 會在 CPU 0 上喚醒。

mdss_fb0 會喚醒、短暫執行,然後進入不中斷睡眠, 接著再次喚醒。

範例:非工作影格

這個範例說明如何使用系統追蹤功能,偵錯 Pixel 或 Pixel XL 的抖動問題。如要跟著範例操作,請下載追蹤記錄的 ZIP 檔案 (其中包含本節提及的其他追蹤記錄)、解壓縮檔案,然後在瀏覽器中開啟 systrace_tutorial.html 檔案。

開啟系統追蹤記錄時,您會看到類似下圖的內容:

在 Pixel XL 上執行 TouchLatency,並啟用大多數選項

圖 10. 在 Pixel XL 上執行 TouchLatency,並啟用大多數選項。

在圖 10 中,大部分選項都已啟用,包括 mdsskgsl 追蹤點。

如要尋找掉格,請查看 SurfaceFlinger 下方的 FrameMissed 列。 FrameMissed 是 HWC2 提供的一項生活品質改善功能。查看其他裝置的系統追蹤記錄時,如果裝置未使用 HWC2,可能不會顯示 FrameMissed 列。無論是哪種情況,FrameMissed 都與 SurfaceFlinger 缺少其中一個正常執行階段,以及應用程式在 VSync 的待處理緩衝區計數未變更 (com.prefabulated.touchlatency) 有關。

FrameMissed 與 SurfaceFlinger 的關聯性

圖 11. FrameMissed 與 SurfaceFlinger 的關聯性。

圖 11 顯示在 15598.29 毫秒時錯過一個影格。SurfaceFlinger 在 VSync 間隔短暫喚醒,但未執行任何工作就返回休眠狀態,這表示 SurfaceFlinger 判斷不值得再次嘗試將影格傳送至螢幕。

如要瞭解這個影格的管道為何中斷,請先查看上方的運作中影格範例,瞭解正常的 UI 管道在系統追蹤記錄中的顯示方式。準備就緒後,返回錯過的影格,然後往回作業。請注意,SurfaceFlinger 會喚醒並立即進入休眠狀態。從 TouchLatency 查看待處理影格數量時,會發現有兩個影格 (這是判斷發生什麼情況的好線索)。

SurfaceFlinger 會喚醒並立即進入休眠狀態

圖 12. SurfaceFlinger 會喚醒並立即進入休眠狀態。

由於 SurfaceFlinger 中有影格,因此這不是應用程式問題。此外,SurfaceFlinger 會在正確時間喚醒,因此這不是 SurfaceFlinger 的問題。如果 SurfaceFlinger 和應用程式看起來都正常,問題可能出在驅動程式。

由於已啟用 mdsssync 追蹤點,您可以取得有關柵欄的資訊 (在顯示器驅動程式和 SurfaceFlinger 之間共用),這些柵欄會控管影格提交至顯示器的時間。這些柵欄會列在 mdss_fb0_retire 下方,表示影格在螢幕上顯示的時間。這些柵欄會以 sync 追蹤記錄類別的一部分提供。SurfaceFlinger 中哪些柵欄對應特定事件,取決於您的 SOC 和驅動程式堆疊,因此請與 SOC 供應商合作,瞭解追蹤記錄中柵欄類別的意義。

mdss_fb0_retire fences

圖 13. mdss_fb0_retire 柵欄。

圖 13 顯示的影格為 33 毫秒,而非預期的 16.7 毫秒。在該切片的中途,該影格應該已替換為新的影格,但事實並非如此。查看前一格畫面,尋找任何內容。

發生問題的影格前一個影格

圖 14. 故障影格之前的影格。

圖 14 顯示 14.482 毫秒的影格。中斷的兩個影格片段為 33.6 毫秒,這大致是兩個影格的預期時間 (以 60 Hz 轉譯,每個影格 16.7 毫秒,兩者相近)。但 14.482 毫秒與 16.7 毫秒相差甚遠,表示顯示管道有問題。

調查圍籬的確切終點,判斷控制圍籬的項目:

調查圍欄終點

圖 15. 調查圍欄結尾。

工作佇列包含 __vsync_retire_work_handler,會在柵欄變更時執行。查看核心來源時,您會發現這是顯示器驅動程式的一部分。這項作業似乎位於顯示管道的關鍵路徑上,因此必須盡快執行。大約可執行 70 微秒 (排程延遲時間不長),但這是工作佇列,可能無法準確排程。

檢查前一個影格,判斷是否造成延遲;有時抖動會隨著時間累積,最終導致錯過期限:

前一個影格

圖 16. 上一個畫面。

由於檢視器會在選取可執行的 kworker 行時將其變為白色,因此您看不到該行,但統計資料會說明情況:顯示管道重要路徑的一部分有 2.3 毫秒的排程器延遲,這很糟糕。請先將顯示管道重要路徑的這部分從工作佇列 (以 SCHED_OTHER CFS 執行緒的形式執行) 移至專屬 SCHED_FIFO kthread,修正延遲問題,再繼續操作。這項函式需要工作佇列無法提供 (也不打算提供) 的時間保證。

無法確定這是否為卡頓的原因。除了容易診斷的案例 (例如核心鎖定爭用導致顯示器重要執行緒休眠) 之外,追蹤記錄通常不會指出問題。這個抖動可能是導致影格遺失的原因。柵欄時間應為 16.7 毫秒,但在影格掉落前,柵欄時間完全不接近這個值。由於顯示管道緊密耦合,圍欄時間的抖動可能導致影格掉格。

在這個範例中,解決方案涉及將 __vsync_retire_work_handler 從工作佇列轉換為專屬 kthread。這可顯著改善抖動問題,並減少彈跳球測試中的 Jank。後續追蹤記錄會顯示接近 16.7 毫秒的柵欄時間。