Python 程序 CPU 使用率只有 8%:off-CPU 分析定位阻塞的 subprocess.run 呼叫
當一個 Python 程序不斷收到請求、CPU 使用率卻始終上不去時——本例中的 gunicorn 工作程序卡在 8% 左右——說明有程式碼路徑在阻塞作業系統執行緒,而不是在 CPU 上幹活。本文演示如何用 OpenResty XRay 的 off-CPU 分析找到具體的阻塞 Python 程式碼路徑:它把 92.4% 的阻塞時間追蹤到業務檔案 processor.py 第 12 行的一個 subprocess.run 呼叫——全程不改程式碼、不重啟程序。
症狀:請求湧入但 Python 程序 CPU 使用率上不去
讓我們執行 top 命令來檢查每個程序的 CPU 使用情況。
可以看到這個 gunicorn python 程序的 CPU 使用率非常低,只有 8% 左右。即使有很多請求進來,它也不會上升。
透過 ps 命令可以看到,這個程序使用的是 Linux 發行版自帶的標準 Python 3 二進位制可執行檔案;而這個 Python Web 應用的訪問日誌還在隨著新的客戶端請求不斷增長,CPU 使用率卻始終很低。這意味著有一些東西阻塞了 Python 程式碼高效地執行。我們怎麼才能找出來阻塞的東西到底是甚麼呢?
用 OpenResty XRay 的引導式分析定位阻塞的 Python 程式碼路徑
我們可以使用 OpenResty XRay 來檢查這個未經修改的程序,對它進行實時分析,弄清楚到底發生了甚麼事。
在瀏覽器中開啟 OpenResty XRay 的 web 控制檯,確認當前分析的是正確的機器,然後進入 “Guided Analysis”(引導式分析)頁面。在可診斷的問題型別中,選擇 “Low CPU usage and cannot go up”(CPU 使用率低且上不去)。接下來跟隨嚮導操作:選擇 Python 應用,選中消耗 10% CPU 資源的 gunicorn 子程序(也就是我們之前在 top 中看到的那個),其餘步驟保持預設值即可——應用型別、同時選中 Python 和 C 兩個語言層級,以及 300 秒的最大分析時間。
開始分析。系統將持續進行多輪分析;對於這個案例來說,兩輪分析已經足夠,我們就此停止,系統會自動建立一個報告。
報告顯示了阻塞 CPU 高效執行的第一名 C 語言層程式碼路徑,它佔了 96% 的 off-CPU 時間。
第一個函式是 poll 系統呼叫。它意味著 Python 直譯器正在等待 I/O 事件。但是它在等待甚麼樣的 I/O 事件呢?要找出這個資訊,我們需要更多的上下文線索。
_PyEval_EvalFrameDefault 函式表示當前正在執行一些 Python 程式碼。
然後我們看看排名第一的 off-CPU Python 程式碼路徑,它佔了 92.4% 的阻塞時間。
看看這個 Python run 函式,它是在標準的 subprocess.py 模組檔案中定義的。這意味著 Python 程式碼正在執行一個子程序命令,並等待它的輸出。
函式 handle_by_script 是在我們的業務級 Python 程式碼庫中。
點選檢視更多細節。
最重要的阻塞性程式碼路徑是從這個 Python-land off-CPU 火焰圖中自動推匯出來的。火焰圖展示了一個整體的狀況。這樣的 off-CPU 分析也是診斷延遲問題的標準方法——參見我們如何在 50 萬 QPS 的 OpenResty 閘道器中定位 244ms 的延遲毛刺。
下面是關於當前問題的更詳細的解釋和建議。
它談到了我們之前看到的 handle_by_script 函式。
也提到了這個函式執行了一個子程序。
將滑鼠懸停在名為 handle_by_script 的 Python 函式的綠色框上。
可以看到這個函式的 Python 原始檔。並且,在提示框中可以看到 processor.py 檔案的完整路徑。
原始碼行號是 12。
點選圖示複製這個函式的完整 Python 原始檔路徑。
使用 vim 編輯器,貼上我們剛剛複製的程式碼路徑,檢視相應的業務 Python 程式碼。您可以使用任何您喜歡的編輯器。
正如 OpenResty XRay 建議的那樣跳轉到第 12 行。
可以看到,這個 Python 程式碼行確實是呼叫了 subprocess.run 函式,執行一個外部 bash 指令碼並等待其輸出。
它也在之前報告中顯示的函式 handle_by_script 中。同樣的 off-CPU 分析方法也適用於 Perl 和 Go 程序。
Insights 頁面中的全自動分析與報告
OpenResty XRay 也可以自動監控線上程序,並在 “Insights” 頁面中生成以日和周為週期的分析報告——所以您不一定非要手動使用引導式分析功能,儘管它對於應用的開發和演示很有用。
FAQ
為甚麼 Python 程序在大量請求下 CPU 使用率還是上不去?
因為有程式碼路徑在阻塞作業系統執行緒,而不是在 CPU 上幹活。在上面的案例中,gunicorn 工作程序在大量請求下 CPU 始終只有 8% 左右,因為 Python 程式碼正在執行一個子程序命令並等待它的輸出,阻塞在 poll 系統呼叫中。
如何在不修改程式碼的情況下找到阻塞的 Python 程式碼?
對未經修改的執行中程序執行 OpenResty XRay 的引導式分析,選擇 “Low CPU usage and cannot go up” 問題型別。自動生成的報告會推匯出最重要的阻塞程式碼路徑,將滑鼠懸停在 off-CPU 火焰圖中的函式上,即可看到它的原始檔和行號。
為甚麼 subprocess.run 會阻塞我的 Python Web 應用?
subprocess.run 會啟動一個外部命令並等待它執行完畢。在上面的案例中,業務函式 handle_by_script 在 processor.py 第 12 行呼叫 subprocess.run 執行一個 bash 指令碼,導致 gunicorn 工作程序把 92.4% 的阻塞時間花在等待子程序輸出上,而不是處理請求。
關於 OpenResty XRay
OpenResty XRay 是一個動態追蹤產品,它可以自動分析執行中的應用,以解決效能問題、行為問題和安全漏洞,並提供可行的建議。在底層實現上,OpenResty XRay 由我們的 Y 語言驅動,可以在不同環境下支援多種不同的執行時,如 Stap+、eBPF+、GDB 和 ODB。
關於本文和關聯影片
本文和相關聯的影片都是完全由我們的 OpenResty Showman 產品從一個簡單的劇本檔案自動生成的。
關於作者
章亦春是開源 OpenResty® 專案創始人兼 OpenResty Inc. 公司 CEO 和創始人。
章亦春(Github ID: agentzh),生於中國江蘇,現定居美國灣區。他是中國早期開源技術和文化的倡導者和領軍人物,曾供職於多家國際知名的高科技企業,如 Cloudflare、雅虎、阿里巴巴, 是 “邊緣計算“、”動態追蹤 “和 “機器程式設計 “的先驅,擁有超過 22 年的程式設計及 16 年的開源經驗。作為擁有超過 4000 萬全球域名使用者的開源專案的領導者。他基於其 OpenResty® 開源專案打造的高科技企業 OpenResty Inc. 位於美國矽谷中心。其主打的兩個產品 OpenResty XRay(利用動態追蹤技術的非侵入式的故障剖析和排除工具)和 OpenResty Edge(最適合微服務和分散式流量的全能型閘道器軟體),廣受全球眾多上市及大型企業青睞。在 OpenResty 以外,章亦春為多個開源專案貢獻了累計超過百萬行程式碼,其中包括,Linux 核心、Nginx、LuaJIT、GDB、SystemTap、LLVM、Perl 等,並編寫過 60 多個開源軟體庫。
關注我們
如果您喜歡本文,歡迎關注我們 OpenResty Inc. 公司的部落格網站 。也歡迎掃碼關注我們的微信公眾號:
翻譯
我們提供了英文版原文和中譯版(本文)。我們也歡迎讀者提供其他語言的翻譯版本,只要是全文翻譯不帶省略,我們都將會考慮採用,非常感謝!






































