當一個 Go 程序把 CPU 核心佔到 100% 以上時,原因通常是某條熱程式碼路徑在瘋狂消耗 CPU。我們用 OpenResty XRay 剖析了一個正在執行、未經修改的 Go 聊天服務,將它的高 CPU 佔用定位到了正規表示式編譯——標準 regexp 庫中的函式(由業務函式 CheckMessageprev_processor.go 第 17 行呼叫)佔用了 36.8% 的 CPU 時間。編譯正規表示式開銷很大,應儘量避免在熱程式碼路徑中進行。擔心在生產機器上跑會有開銷?我們實測了 OpenResty XRay 對線上 Go 服務的開銷——取樣時的吞吐、延時與 CPU 都有資料。

本文完整展示整個剖析過程——無需修改程式碼、無需重啟——從觀察 Go 的高 CPU 佔用,到定位到具體的原始檔和行號。

觀察 Go 程序的高 CPU 佔用

執行 top 命令,可以看到名為 chat-service 的 Go 程序消耗了超過 100% 的 CPU 核心資源。(如果你的症狀恰好相反——請求不斷湧入而 CPU 使用率卻始終上不去——請參閱追蹤卡在 2% CPU 的 Go 程序。)

top 命令顯示 Go 程序 chat-service 消耗超過 100% 的 CPU 核心

使用 OpenResty XRay 剖析 Go 的 CPU 使用

我們用 OpenResty XRay 實時分析這個未經修改的程序——無需新增任何特殊模組、無需修改程式碼、無需重啟。在 Web 控制檯中,進入 Guided Analysis(引導式分析) 頁面,選擇 High CPU Usage(高 CPU 佔用) 作為問題型別。OpenResty XRay 會自動發現目標機器上正在執行的應用。在下拉選單中選擇這個 Go 應用。

OpenResty XRay 自動發現正在執行的應用,並選中 Go 應用

選擇 CPU 佔用 96% 的那個程序——也就是我們之前在 top 中看到的程序。

選擇 CPU 佔用 96% 的 Go chat-service 程序進行分析

將語言級別設為 Go,最大分析時間保持預設的 300 秒。啟動分析後,系統會執行多輪分析;對這個例子來說兩輪就足夠了。

語言級別設為 Go,最大分析時間為 300 秒

CPU 火焰圖分析

OpenResty XRay 自動生成了一個報告。

OpenResty XRay 為 Go 程序自動生成的 CPU 分析報告

報告顯示了消耗 CPU 時間最多的那些 Go 級別程式碼路徑。其中排名第一的是正規表示式編譯,它佔用了 36.8% 的 CPU 時間。

報告顯示正規表示式編譯是佔比最高的 CPU 消耗,達 36.8%

這是 Go 執行時中標準 regexp 庫裡的兩個函式,它們負責編譯正規表示式。

標準 regexp 庫中負責編譯正規表示式的兩個函式

這個 CheckMessage 函式是我們業務邏輯的一部分,它呼叫了我們剛才看到的正則編譯函式。

CheckMessage 業務邏輯函式呼叫了正則編譯函式

定位 Go 原始檔和行號

如果想進一步研究這條程式碼路徑,點選 More 連結。

點選 More 連結檢視最熱程式碼路徑的詳細分析

點選後會看到該程式碼路徑更詳細的檢視,它是從這個 Go 級別的 CPU 火焰圖中推匯出來的。

OpenResty XRay 生成的 Go 級別 CPU 火焰圖

這裡還有關於如何改善這條程式碼路徑效能的說明和建議。

針對 CPU 熱點的詳細說明與最佳化建議

比如,它指出正則編譯函式開銷很大,應儘量避免呼叫。

報告指出正規表示式編譯函式開銷很大

接著它解釋了業務級函式 CheckMessage,以及它使用和編譯正規表示式的情況。

報告解釋 CheckMessage 業務函式及其正則編譯

它也提到了編譯好的正規表示式。

報告描述編譯好的正規表示式

回到程式碼路徑,把滑鼠懸停在名為 CheckMessage 的 Go 函式的綠色框上。可以看到 CheckMessage 函式的 Go 原始檔,提示框中還顯示了 prev_processor.go 檔案的完整路徑。

提示框顯示 CheckMessage 函式的 prev_processor.go 原始檔路徑

Go 原始碼的行號是 17。

火焰圖提示框中顯示的 Go 原始碼行號 17

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

從火焰圖複製完整的 Go 原始檔路徑

在終端貼上剛剛複製的路徑,用 vim 編輯器檢視相應的 Go 業務程式碼。您可以自由使用喜歡的編輯器。

在 vim 編輯器中開啟 Go 原始檔

跳轉到第 17 行,也就是報告裡顯示的那個行號。

檢視 Go 原始檔的第 17 行

可以看到,這行程式碼確實在編譯正規表示式,呼叫的是 regexp.MustCompile 函式。

Go 原始碼第 17 行呼叫 regexp.MustCompile

它也確實位於報告中顯示的 CheckMessage 函式中。接下來最佳化這裡的 Go 程式碼就很容易了!

Go 原始檔中 CheckMessage 函式的定義

全自動監控與報告

對於生產環境的負載,OpenResty XRay 可以持續監控程序,並在 Insights 頁面自動生成以日和周為週期的報告——無需手動執行引導式分析。

Insights 頁面為 Go 應用自動生成的日報和週報 CPU 報告

除了高 CPU,OpenResty XRay 同樣能在執行中的程序上追蹤 Go Panic,無需重啟或改動程式碼。

常見問題

為甚麼我的 Go 程式 CPU 佔用這麼高?

Go 高 CPU 佔用的一個常見原因,是某條熱程式碼路徑中存在開銷很大的操作。在本例中,OpenResty XRay 將 CPU 瓶頸定位到了正規表示式編譯——標準 regexp 庫中的函式佔用了 36.8% 的 CPU 時間——它們由業務函式 CheckMessageprev_processor.go 第 17 行呼叫。CPU 火焰圖能揭示從業務邏輯一直到執行時庫函式的完整呼叫鏈。

在 Go 中編譯正規表示式開銷大嗎?

是的。編譯一個正規表示式需要構建匹配自動機,這比執行一個已經編譯好的正則要昂貴得多。OpenResty XRay 的報告明確將 regexp 編譯函式標記為開銷很大,並建議避免在熱程式碼路徑中呼叫。通行做法是每個正則只編譯一次並複用編譯結果,而不是反覆編譯。

如何找到導致 Go 高 CPU 的程式碼?

使用 OpenResty XRay 的引導式分析生成 Go 級別的 CPU 火焰圖。火焰圖以堆疊的函式呼叫呈現,框的寬度代表 CPU 時間。把滑鼠懸停在某個函式框上即可看到原始檔路徑和行號,然後用任意編輯器開啟該檔案,檢查具體負責的程式碼——全程無需插樁、無需修改程式碼。

關於 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. 公司的部落格網站 。也歡迎掃碼關注我們的微信公眾號:

我們的微信公眾號

翻譯

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