我們有一個基於 Sled(Rust 編寫的嵌入式 KV 資料庫)的內部快取服務,CPU 使用率超過了 100%。透過 OpenResty XRay 的 Rust CPU 剖析,我們把 CPU 消耗追蹤到了兩條熱程式碼路徑——sled::tree::Tree::insertget_inner(後者佔了近 40% 的 CPU 時間),並精確定位到具體原始碼行,全程無需修改程式碼、無需重新編譯。

本教程將逐步演示整個分析過程。下面展示的熱程式碼路徑,是 OpenResty XRay 自動分析和解讀 Rust 語言級別的 CPU 火焰圖得來的。

問題:基於 Sled 的快取服務 CPU 使用率超過 100%

Sled 是一個由 Rust 編寫的嵌入式 KV 資料庫,我們的內部快取服務就構建在它之上。在 top 中可以看到,該程序的 CPU 使用率持續超過 100%。

top 輸出顯示基於 Rust Sled 的快取服務程序 CPU 使用率超過 100%

用引導式分析剖析執行中的 Rust 程序

讓我們使用 OpenResty XRay 來檢查這個未經修改的程序。您可以對它進行實時分析並找出原因,無需改動程式碼、無需重新編譯。這類分析的執行時開銷非常低,我們在《OpenResty XRay 對 Rust 應用的效能影響實測》一文中做過量化測量。

開啟 OpenResty XRay 的 Web 控制檯,確認當前檢視的是正確的機器,然後進入 “Guided Analysis”(引導式分析)頁面。這裡可以看到系統能診斷的不同型別的問題。

OpenResty XRay 引導式分析頁面列出可診斷的問題型別,包括 High CPU Usage

選擇 “High CPU Usage”,然後選擇前面的 Sled 應用,以及消耗超過 100% CPU 資源的那個程序——也就是我們之前在 top 中看到的。

引導式分析的程序選擇步驟,顯示 CPU 使用率超過 100% 的 Sled 程序

應用型別預設就是 Rust,語言級別這裡也只有 “Rust”。最大分析時間保持預設的 300 秒不變,開始分析。系統會持續執行多輪分析;第一輪完成後,對這個例子來說已經足夠,停止分析後系統自動生成了一份分析報告。

針對 Rust Sled 程序高 CPU 問題自動生成的引導式分析報告

解讀 Rust CPU 火焰圖:第一熱程式碼路徑

報告展示了佔用 CPU 時間最多的第一條 Rust 程式碼路徑。

OpenResty XRay 報告的第一熱 Rust 程式碼路徑,頂層為 sled::tree::Tree::insert

第一個函式 sled::tree::Tree::insert 在 Sled 中用於資料插入。

報告標註 sled::tree::Tree::insert 為第一熱函式,用於向 Sled 樹中插入資料

點選 “More” 檢視詳情。

點選報告條目上的 More 按鈕展開該熱路徑的詳細分析

上面的熱程式碼路徑是從下面這張 Rust 級別的 CPU 火焰圖中自動推匯出來的。

OpenResty XRay 據以自動推匯出 insert 熱路徑的 Rust 級別 CPU 火焰圖

下面是報告針對當前問題給出的更詳細的解釋和建議:Explanation 部分逐一說明了 insert 及其呼叫鏈上各個函式,Suggestions 部分則給出了批次寫入(sled::Batch)、併發、引數調優等最佳化方向。

報告的 Explanation 與 Suggestions 部分:解釋 insert 呼叫鏈各函式並給出批次寫入、併發、調參等最佳化建議

點選這個圖示可以放大火焰圖。

點選圖示放大 Rust CPU 火焰圖以檢視呼叫細節

點選 insert 函式的框檢視更多詳情。

在放大的火焰圖中點選 insert 函式框檢視其內部呼叫

在左側,可以看到 view_for_key 函式佔比較大——這是 Sled 庫中為給定 key 獲取快照檢視的函式。

放大後的火焰圖顯示 view_for_key 函式在 insert 路徑中佔比較大

在右側,pagecache 是 Sled 的一個元件,用於按頁面管理資料。寫入的資料首先儲存在 pagecache 的記憶體頁面中,當批次寫滿時,再透過刷盤持久化。

火焰圖右側顯示 Sled 的 pagecache 元件按記憶體頁面管理寫入資料

繼續點選放大。

繼續放大火焰圖檢視 pagecache 之下的呼叫

可以看到 Glibc 中的 realloc 函式——libc 的記憶體分配函式在這個負載下比較熱。

火焰圖中 Glibc 的 realloc 記憶體分配函式在該負載下成為熱點

從火焰圖跳轉到 Sled 的原始碼

在終端上,用 find 命令在 cargo 快取中找到 Sled 庫的原始碼目錄。

在終端用 find 命令在 cargo 快取中定位 Sled 庫原始碼目錄

複製找到的目錄,進入 Sled 原始碼目錄。

複製 find 得到的路徑並進入 Sled 原始碼目錄

回到火焰圖,將滑鼠懸停在 insert 函式的綠框上:提示框中會顯示這個函式的原始檔名。

火焰圖提示框顯示 insert 函式的原始檔路徑

提示框中給出的原始碼行號是 164。

提示框顯示 insert 函式對應的原始碼行號為 164

點選這個圖示,複製該函式的原始檔路徑。

點選圖示複製 insert 函式的原始檔路徑

用您喜歡的編輯器開啟原始檔,貼上剛才複製的檔案路徑(這裡用的是 vim)。

在 vim 中開啟貼上的 Sled 原始檔路徑

OpenResty XRay 的提示跳轉到第 164 行。

按提示在編輯器中跳轉到 Sled 原始碼第 164 行

這行程式碼就在 insert 函式內部。

編輯器中開啟的 Sled 原始碼定位到第 164 行,位於 insert 函式體內

第二熱程式碼路徑:get_inner 與 view_for_key

接下來檢視第二條程式碼路徑。第二熱的程式碼路徑消耗了近 40% 的 CPU 時間。

消耗近 40% CPU 時間的第二熱 Rust 程式碼路徑,頂層為 get_inner

頂層的函式呼叫 get_inner 是 Sled 庫內部用於查詢資料的函式。

報告標註 get_inner 為第二熱路徑頂層函式,負責 Sled 的資料查詢

get 函式是庫對外暴露的取數介面,它在內部呼叫了 get_inner 函式。

get 是 Sled 對外暴露的取數介面,內部呼叫 get_inner

點選 “More” 檢視詳情。

點選 More 展開 get_inner 熱路徑的詳細分析

放大火焰圖,檢視 get_inner 函式呼叫的詳情。

放大火焰圖檢視 get_inner 的呼叫細節

繼續放大 get_inner

進一步放大 get_inner 函式在火焰圖中的子呼叫

可以看到,get_inner 函式內的大部分 CPU 時間同樣被前面提到的 view_for_key 函式佔用。

火焰圖顯示 get_inner 內大部分 CPU 時間被 view_for_key 函式佔用

sled::lru::Lru::accessed 函式在 Rust 的 Sled 庫中用於更新 LRU 快取中條目的訪問狀態,並返回需要剔除的頁面 ID 列表。

火焰圖細節顯示 get_inner 路徑內 sled::lru::Lru::accessed 更新 LRU 快取狀態

全自動 Rust CPU 分析報告

OpenResty XRay 也可以自動監控線上程序,並顯示分析報告。

OpenResty XRay 自動監控線上程序並生成分析報告

切換到 “Insights” 頁面。

切換到 OpenResty XRay 控制檯的 Insights 頁面

您可以在 “Insights” 頁面中找到以日和周為週期的報告,因此其實不是非得用 “Guided Analysis” 功能。

OpenResty XRay 的 Insights 頁面顯示自動生成的日報和週報 CPU 分析報告

當然,“Guided Analysis” 對於應用的開發和演示還是很有用的。在 Insights 的日報中,可以看到該程序的 CPU 使用率(min 102%、avg 107%、max 113%),以及按佔比排序的最熱 Rust 程式碼路徑。

Insights 日報顯示 sled-cache 程序 CPU min 102%/avg 107%/max 113% 及按佔比排序的最熱 Rust 程式碼路徑

除了 CPU 時間,OpenResty XRay 還能以同樣非侵入的方式追蹤 Rust 程式中的 panic,以及診斷 Rust 應用的高磁碟 I/O 問題

常見問題

如何在不修改程式碼的情況下剖析 Rust 程式的 CPU 使用?

使用基於動態追蹤的非侵入式剖析工具。OpenResty XRay 直接分析正在執行的、未經修改的 Rust 程序:在引導式分析中選中目標程序,它就會對程序取樣並生成 Rust 語言級別的 CPU 火焰圖——無需重新編譯,也無需在目標程序中插樁。

如何找出哪個 Rust 函式消耗的 CPU 最多?

對程序取樣得到 Rust 級別的 CPU 火焰圖,然後讓 OpenResty XRay 從火焰圖中自動推匯出最熱的程式碼路徑——不需要人工解讀火焰圖。在本文的 Sled 案例中,它報告 sled::tree::Tree::insert 是第一熱路徑,還直接指出了具體的原始碼行號(第 164 行)。

我們基於 Sled 的服務為甚麼會佔用超過 100% 的 CPU?

在這個案例中,CPU 時間集中在兩條路徑上:一是經由 sled::tree::Tree::insert 的資料插入——其中 view_for_key 和 pagecache 寫入佔大頭,Glibc 的 realloc 記憶體分配函式也比較熱;二是經由 get_inner 的資料查詢,消耗了近 40% 的 CPU 時間,同樣主要花在 view_for_key 上。

關於 OpenResty XRay

OpenResty XRay 是一個動態追蹤產品,它可以自動分析執行中的應用,以解決效能問題、行為問題和安全漏洞,並提供可行的建議。在底層實現上,OpenResty XRay 由我們的 Y 語言 驅動,可以在不同環境下支援多種不同的執行時,如 Stap+、eBPF+、GDB 和 ODB。

關於作者

章亦春是開源 OpenResty® 專案創始人兼 OpenResty Inc. 公司 CEO 和創始人。

章亦春(Github ID: agentzh),生於中國江蘇,現定居美國灣區。他是中國早期開源技術和文化的倡導者和領軍人物,曾供職於多家國際知名的高科技企業,如 Cloudflare、雅虎、阿里巴巴, 是 “邊緣計算”、“動態追蹤 “和 “機器程式設計 “的先驅,擁有超過 22 年的程式設計及 16 年的開源經驗。作為擁有超過 4000 萬全球域名使用者的開源專案的領導者。他基於其 OpenResty® 開源專案打造的高科技企業 OpenResty Inc. 位於美國矽谷中心。其主打的兩個產品 OpenResty XRay(利用動態追蹤技術的非侵入式的故障剖析和排除工具)和 OpenResty Edge(最適合微服務和分散式流量的全能型閘道器軟體),廣受全球眾多上市及大型企業青睞。在 OpenResty 以外,章亦春為多個開源專案貢獻了累計超過百萬行程式碼,其中包括,Linux 核心、Nginx、LuaJITGDBSystemTapLLVM、Perl 等,並編寫過 60 多個開源軟體庫。

關注我們

如果您喜歡本文,歡迎關注我們 OpenResty Inc. 公司的部落格網站 。也歡迎掃碼關注我們的微信公眾號:

我們的微信公眾號

翻譯

我們提供了英文版原文和中譯版(本文)。我們也歡迎讀者提供其他語言的翻譯版本,只要是全文翻譯不帶省略,我們都將會考慮採用,非常感謝!