作者：jasonzxpan，騰訊 IEG 運營開發工程師

本文排查一個Linux 機器 CPU 毛刺問題，排查過程中不變更進程狀態、也不會影響線上服務，最后還對 CPU 毛刺帶來的風險進行了分析和驗證。

本文中提到 CPU 統計和產生 core 文件的工具詳見 simple-perf-tools 倉庫。

問題描述

某服務所在機器統計顯示，其 CPU 使用率在高峰時段出現毛刺。

暫時未收服務調用方的不良反饋。

初步排查

查看 CPU 1 分鐘平均負載，發現 1 分鐘平均負載有高有低，波動明顯。說明機器上有些進程使用 CPU 波動很大。

登錄機器排查進程，使用top指令。因為 CPU 會明顯上升，重點懷疑使用 CPU 總時間高的進程，在打開 top 后，使用shift +t可以按照 CPU TIME 進行排序。

直觀的看，有幾個 spp_worker 相關的進程使用 CPU TIME 相對較高。

第一個進程因為啟動的時間比較長，所以 CPU TIME 也比較大。可以使用下面的腳本，計算各個進程從各自拉起后 CPU 使用率：

uptime=`awk?'{print?$1}'?/proc/uptime`?#?why?is?it?too?slow?indocker?hertz=`zcat?/proc/config.gz?|?grep?CONFIG_HZ=?|awk?-F"="?'{print?$2}'`awk?-v?uptime=$uptime?-v?hertz=$hertz?--?'{printf("%d%s%11.3f",?$1,?$2,?(100?*($14?+?$15)?/?(hertz?*?uptime?-?$22)));}'?/proc/*/stat?2>?/dev/null?|?sort??-gr?-k?+3?|?head?-n?20

看到的也是這些 spp_worker 使用 CPU 相對要高一些：

選其中的一個 PID 為 45558 的 Worker 進程監控器 CPU 使用率：

可以發現其 CPU 大部分情況很低，但是在某一個時間點會升高，持續 1 秒左右。而且大部分時間是耗費在用戶態，而非系統調用。

而《Linux Agent 采集項說明 - CPU 使用率》中描述的 CPU 使用率的采樣策略為：

Linux Agent 每分鐘會采集 4 次 15 秒內的 CPU 平均使用率。為了避免漏采集 CPU 峰值，網管 Agent 取這一分鐘內四次采集的最大值上報。

因為采樣可能采到高點或者低點，當 1 分鐘內出現 CPU 飆升，則會表現為尖峰；如果四次都沒有出現飆升，則表現為低谷。

至此，已經能確認是這批 Worker 進程引起了這種毛刺，但具體是哪部分代碼有問題還需要進一步排查。

進一步排查

前邊確認了沒有太多的系統調用，所以不必使用strace工具。

使用perf工具

使用perf工具進行查看。具體的命令是perf top -p 45558，在低 CPU 使用率的時候：

但是當 CPU 飚上去的時候，perf采樣的位置變成如下這樣：

看一下紅框的位置，可以發現可能是配置更新部分有問題，因為：

• 這個地方 Protobuf 特別多的地方，在做更新的操作(有MergeFrom，有Delete)
• 有大量的用到了std::map(有std::_Rb_tree，有字符串比較)

通過觀察perf結果的方法，雖然能夠猜測大計算量的位置，但是有兩個不便之處：

• 如果 CPU 高的情況發生概率很低，人為觀察比較耗時
• 不能明確的知道，具體在哪個文件的哪個函數

使用gcore

最初統計的時候，發現 CPU 高的情況會出現 1 秒多的時間，如果發現 CPU 高負載時，直接調用gcore {pid}的命令，可以保留堆棧信息，明確具體高負載的位置。

將使用 gcore 的指令，添加到統計工具中取，設置 CPU 上門先觸發。

通過gdb看了幾個 coredump 文件，發現堆棧和函數調用基本一致。可以明確的看到，大量的耗時發生在了AddActInfoV3這一函數中：

到此位置，我們明確了高計算量發生的具體位置。

風險點

CPU 突然飆升是否存在風險呢？是不是計算資源充足的時候，就不會有問題呢？

這個例子中，使用的是 SPP 微線程功能，每個 Worker 進程只啟用一個線程。

如果僅僅是因為高計算量卡住 CPU，正常處理請求的邏輯將很難被調度到。這樣勢必會造成處理請求的延遲增大，甚至有超時返回的風險。

使用 spp 的cost_stat_tool工具

利用 spp 自帶的統計工具印證這一風險點，查看 worker 處理前端請求時延統計信息，執行命令./cost_stat_tool -r 1：

上邊的例子中，統計發生配置更新前后的 5 秒鐘內，worker 處理的 231 個請求中，有 3 個請求的處理時間超過 500ms，遠高于普通請求。

使用tcpdump抓包確認

因該服務沒有打開詳細的日志，想要進一步驗證超過 500ms 的這些請求也是正常處理的請求，而非異常請求，可以通過抓包來分析。

tcpdump?-i?any?tcp?port?20391?-Xs0?-c?5000?-w?service_spp.pcap

通過 wireshark 打開，需要過濾出返回時間 - 請求時間 > 500ms的相關請求。翻譯成 wireshark 過濾器的表達式則是：

tcp.time_delta?>?0.5?&&?tcp.dstport?!=?20391

過濾出一條符合條件的請求：

在該條記錄上右鍵 -> Follow -> TCP Stream，可以查看該請求前后的 IP 包：

上邊 4 個包分別是：

+0ms 客戶端發送請求至服務端

+38ms 服務端回復 ACK，無數據

+661ms 服務端發送返回至客戶端

+662ms 客戶端回復 ACK

詳細看了包中的內容為一條普通請求，邏輯簡單，應該在 20ms 內返回。而此時的該進程使用 CPU 也確實為高負載的情況：

上述統計相互印證：

• CPU 高時，正常的網絡請求也會被阻塞住(回復 ACK 需要 38ms，低于 40ms，與TCP 延遲確認無關)
• 平時只需要 20ms 能返回的請求，耗時了 660ms

CPU 突然飚高有風險，需要認真對待。

總結

以上是生活随笔為你收集整理的查看cpu使用率_腾讯游戏开发工程师：Linux 机器 CPU 毛刺问题排查的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。