分散式訓練 job 在昂貴的 GPU 機器上跑了幾個小時,卻一再因為網卡突然斷線而整個 crash。把 perf 拉出來看,整機 CPU 用量很正常——直到有人改用 mpstat 一秒一秒地看每顆核心,才發現有一顆核(CPU 39)會連續好幾秒把 system CPU 吃到 100%,而網卡 reset 總是緊跟在後。
在系統裡抓殭屍——CPU 瓶頸追查記
Pinterest 的 ML 平台團隊回報了一個讓人摸不著頭緒的故障:他們用 Ray 跑的分散式訓練 job「會間歇性地失去網路連線,最終導致 job crash」。這些 job 動輒在昂貴的 GPU 硬體上跑好幾個小時,每一次中斷都是真金白銀的浪費。表面上看是網路問題,但網路團隊查不出網卡或交換器有什麼異常;找上 AWS support,得到的結論是「這個問題絕對不在 AWS 那一側」。一個會週期性復發、跨多台機器、又沒有任何一層直接背鍋的故障,正是 investigation 最典型的形狀:你看到的每一個現象都把你指向錯的方向。這篇 Pinterest Engineering 的 debug 故事值得拆開來讀的地方,不在於最後抓到的那隻「殭屍」是什麼,而在於他們用什麼順序排除假設、哪個指標騙了他們、哪個指標最後說了實話。
先把謎題的形狀講精確。故障的觸發點是 ENA(Elastic Network Adapter)driver reset——驅動程式自己重新啟動了網卡,連線因此中斷。reset 的日誌訊息是 TX q 5 is paused for too long (threshold 5000000):某個傳送佇列被卡住太久,超過門檻,驅動就把整張卡重置。問題是,網卡硬體本身沒壞,AWS 也排除了。那是什麼東西讓一個傳送佇列「卡太久」?這就是整個調查要回答的問題,而它的答案藏在一個跟網路八竿子打不著的地方。
這裡值得先想清楚 ENA 這個「卡太久就重置」的設計為什麼存在,因為它正是把一個 CPU 問題偽裝成網路問題的關鍵環節。網卡驅動需要定期處理傳送佇列——把要送出的封包描述符交給硬體、回收已完成的描述符。這些工作跑在 kernel 的某個執行緒上,而執行緒得排到某顆 CPU 才跑得動。當某顆核被別的東西連續佔滿好幾秒,排到那顆核上的 driver 工作就遲遲輪不到,傳送佇列因此「被暫停太久」,驅動於是判定網卡卡死、把它重置。換句話說,ENA reset 是一個下游的、無辜的受害者:它真正抱怨的不是網路,而是「我排不到 CPU」。任何把調查焦點放在網卡、交換器、封包路徑上的努力,從一開始就找錯了方向——這也是為什麼網路團隊查不出名堂、AWS 也兩手一攤。把這個機制想透,後面所有的線索才接得起來。
謎題:整機 CPU 正常,網卡卻一直自己重新啟動
調查的第一步是把 CPU 行為攤開看。團隊先用 perf 抓了一份 snapshot,看到的是「page faulting 和我們 ML job 的一些重運算」——換句話說,一份看起來很正常的 profile。整機的 CPU 用量沒有爆,重運算來自訓練本身,page fault 也在意料之內。如果調查停在這裡,結論會是「機器很忙,但沒什麼異常」,然後故障繼續復發。perf 的整機視角在這裡幫了倒忙:它把所有核心的時間加總在一起平均掉,於是「整體 CPU 沒問題」這個結論,恰恰掩蓋了「某一顆核心出了問題」這個事實。原文的說法很直接——整機的 perf 視角「對於每一顆核心各自發生了什麼,幾乎什麼都沒告訴我們」。
真正的突破來自換一個量測粒度。團隊改用 mpstat,以「每秒一次、連續一小時」的方式記錄每顆核心各自的使用率,然後在資料裡看到了刺眼的東西:有一顆核心(截圖裡是 CPU 39)「經常連續好幾秒把它的 system CPU 用到 100%」。更關鍵的是時間關聯——這個尖峰總是出現在 ENA reset 之前。aggregate 看不見,per-core 一眼就看見。下面這張圖把兩種視角擺在一起:同一段時間,整機平均的曲線平穩無波,逐核的曲線裡卻有一條獨自頂到天花板。investigation 的第一個方法論教訓就藏在這個切換裡——當「整體沒事」與「一直出事」兩個事實沒辦法同時成立時,先懷疑你的指標是不是把問題平均掉了。
「每秒一次」這個取樣頻率不是隨便挑的,它本身就是診斷的一部分。多數監控系統預設以 10 秒、30 秒甚至一分鐘為間隔取樣 CPU,而這個故障的尖峰只持續「好幾秒」。用 30 秒的取樣窗去看一個持續 4 秒的 100% 尖峰,落在窗裡會被平均成一個不痛不癢的數字,落在窗外則整個漏掉——無論哪種,常規監控都會回報「這顆核很閒」。mpstat 的逐秒粒度把這個瞬時尖峰從平均的稀釋裡撈了出來。這帶出第二層教訓:aggregate 不只發生在「跨核心平均」這個空間維度,也發生在「跨時間平均」這個時間維度上。一個夠短、夠劇烈的事件,會同時被空間平均和時間平均兩道濾鏡抹掉,而它造成的下游後果(網卡 reset)卻是實打實的。要抓這種事件,量測的空間粒度(逐核)和時間粒度(逐秒)都得夠細。
切換 aggregate / per-core 兩種視角 · 同一段約 60 秒的 system CPU
假設一:記憶體配置太沒效率,是 page fault 在燒 CPU
第一個合理的懷疑對象是記憶體。既然 perf 看到了 page faulting,而 page fault 本身就是 kernel 態的工作,那把 page fault 壓下去,system CPU 自然會降。團隊照這個思路試了兩招:打開 Transparent Huge Pages「來減少 page faulting」,並且「試了像 jemalloc 這種更有效率的記憶體配置器」。這兩招在方向上沒有錯,資料也給了正向的回饋——原文寫得很誠實:「我們確實從記憶體配置器和 huge pages 的設定上,看到整體 CPU 使用率和 page faulting 有一些下降。」
但故障沒有消失。同一句話的後半段是整段的關鍵:「然而網路 reset 還在繼續發生。」這是 investigation 裡最容易誤判的局面——一個假設帶來了可量測的改善,數字往好的方向動了,很容易就讓人以為「方向對了,再調一調就好」。實際上這個改善是真的,但它跟故障無關:huge pages 降的是訓練本身的 page fault 成本,而吃掉 CPU 39 的那股 system CPU 來自完全不同的來源。這一關教的方法論是:別把「指標改善了」當成「找到病因了」。一個能讓你看到 CPU 下降、卻不能讓 reset 停止的修改,證明的恰恰是病因在別處。
假設二:把核心讓給訓練、把網路中斷導到別處
第二條路是調度與中斷的隔離。如果是訓練 job 跟網路處理在搶同一顆核心,那把它們分開應該就好。團隊「試著用 taskset 給訓練 job 它們自己的 CPU 核心(CPU affinity)」,又「玩了 ENA driver 的中斷 pinning,把網路中斷導到其他核心去」。這套手法在處理「網路軟中斷被應用程式餓死」這類問題時是標準解法,邏輯上無懈可擊。結果原文只有兩個字:「Nothing worked.」
這一關其實藏了一條重要線索,只是當下沒人讀出來。把網路中斷導到別的核心、卻還是會 reset,意味著那顆把 CPU 吃光的核心並不是「剛好在跑網路中斷」——它是在做某件別的事,而那件事跟哪顆核心無關、跟把誰 pin 到哪裡也無關。換句話說,affinity 和 interrupt steering 之所以全部失效,是因為真正的元凶不是「資源被搶」,而是「有一段工作本身就很重」。事後回頭看,「Nothing worked」這四個字本身就是證據:它排除掉了一整類「資源競爭」假設,把調查逼向「到底是哪一段程式碼在那顆核上跑」這個更尖銳的問題。
這裡有個容易被忽略的細節值得停下來看。CPU affinity 和中斷 pinning 之所以是合理的第一反應,是因為它們在「應用程式把網路軟中斷餓死」這個經典場景裡確實有效——那種場景下,問題的本質就是兩種工作擠在同一顆核上互搶,把它們分開就好。但這個故障的形狀不一樣:吃 CPU 的是一段 kernel 態的會計工作,它跑在哪顆核、要不要避開網路中斷,都不影響它要做的工作量。你把網路中斷搬到核 A,那段會計工作下次照樣可能排到核 A,照樣把它餵滿。隔離只能解決「誰跟誰搶」,解決不了「有一件事本身就太重」。這條經驗對排查很實用:當你試遍了所有隔離手段都無效,多半代表問題不在資源分配,而在某段程式碼的絕對成本——該回頭去量「它到底在做什麼」,而不是繼續調「它跟誰一起跑」。
假設三:是硬體壞批、還是訓練容器 crash 在搞鬼
還有兩個方向同時被排除。其一是硬體:團隊注意到不同 availability zone 的表現有差異,這「暗示了可能是一批壞硬體」。但這條線最後證實是個幌子——那個差異其實是設定造成的假象(後面會交代是什麼設定)。AWS support 也介入並確認問題不在 AWS 那一側,硬體假設因此出局。其二是訓練本身:一開始也懷疑過是不是訓練容器在 crash-loop 拖垮機器,但查下去並沒有發現。
三個假設一一倒下之後,調查進入了最關鍵也最值得學的階段。前面的失敗已經把問題收斂得很乾淨:不是記憶體配置、不是資源競爭、不是硬體、不是訓練容器。剩下的問題只有一個——在 reset 發生之前的那幾秒,CPU 39 上到底在跑什麼?要回答這個,整機平均的 perf 不夠,連逐核的 mpstat 都不夠(它只告訴你「哪顆核」忙,不告訴你「在忙什麼」)。團隊需要的是能精準對到「reset 前那兩分鐘」這個時間窗、又能看到 call stack 的工具。下面這個假設掃描表,把前三關的測法與結果並排,看得出排除法是怎麼一步步縮小搜索空間的。
點任一假設看它怎麼測、結果如何 · 4 個被排除的方向
四個被測過、又被排除的假設
點一個假設看細節
H1 · 記憶體配置沒效率
方向沒錯但抓錯對象。huge pages 與 jemalloc 確實壓低了訓練自己的 page fault 成本,所以你會看到 CPU 數字下降——這是真的改善,卻不是 reset 的成因。教訓:指標改善 ≠ 找到病因;一個降得了 CPU 卻停不了 reset 的修改,正好證明病因在別處。
H2 · 資源競爭
「Nothing worked」本身就是線索。把網路中斷導到別核還是 reset,代表吃光 CPU 的那顆核不是在跑網路中斷,而是在做某件跟「哪顆核」無關的重活。這一步排除了整類資源競爭假設,把問題逼成「那顆核上到底在跑什麼程式碼」。
H3 · 硬體壞批
AZ 之間的差異看起來像壞硬體,實際是 bootstrap 設定造成的假象——某個 AZ 的開機腳本因為一個不同的 URL 讓最後一步 metric 上報失敗、整個 script 被標成失敗,反而擋掉了那顆殭屍的源頭。AWS 也確認問題不在它那側。
H4 · 訓練容器 crash
最直覺的對象反而最早出局:查下去並沒有發現訓練容器在 crash-loop。真正在 crash-loop 的是另一個沒人預期會出現在這些機器上的容器——這要等到時間旅行式的 profiling 才看得到。
逼出真相:把 perf 錄 360 次,用 Flamescope 倒帶到 reset 前那兩分鐘
排除法把問題收斂到「reset 前 CPU 39 在幹嘛」,剩下的就是量測工程。難點在於故障是間歇性的,你沒辦法一直盯著等它發作。團隊搭了一套可重現的實驗:先用 Kubernetes taints 把機器保留下來,用內部的超參數調校系統「編排了多個一模一樣的平行訓練 job」,然後讓 perf「以兩分鐘為單位」連續錄製,把 profile 和 CPU stack 存到磁碟,整套跑「360 次」,「涵蓋大約 12 小時的 profile」。這等於是給整段 12 小時裝了一台行車記錄器,事後可以倒帶到任何一刻。
有了這批資料,他們用 Flamescope(Netflix 的工具,原文形容它提供一種「time travel view」的 CPU stack 視角)放大到「reset 事件前後那兩分鐘的時間窗」。這一放大,元凶終於現形:在某次 ENA reset 發生前幾秒,「kubelet——我們那個輕量的 Kubernetes agent——佔了整機 CPU 約 6.5%」。再往下鑽,看到 kubelet「花了大量時間在一個 system call 上:mem_cgroup_nr_lru_pages」。一個負責管理容器的 agent,把時間全砸在「數某個 memory cgroup 裡有多少 LRU page」這件事上——這就是吃掉 CPU 39 的那股 system CPU 的真身。下面這個因果鏈把從「容器 crash」到「網卡 reset」的每一環串起來。
解決:機器裡有近七萬個殭屍 cgroup,源頭是一個沒人用的 ECS agent
線索指向 cgroup,下一步就是直接點數。團隊把 kernel 追蹤到的 cgroup 數量跟實際在用的數量擺在一起比,差距大到荒謬:
# kernel 追蹤的 cgroup(含殭屍)
cat /proc/cgroups | grep memory | awk '{print $3}'
68680
# 實際在用的 cgroup
find /sys/fs/cgroup/memory/ -type d | wc -l
240
kernel 裡追蹤著「將近七萬個 memory cgroup,但實際在用的只有 240 個」。這就是標題裡的「殭屍」——已經沒有對應的容器、卻還掛在 kernel 計數裡、沒被回收的 cgroup。kubelet 那個 mem_cgroup_nr_lru_pages 之所以那麼貴,正是因為它每次都得把這六萬八千多個殭屍 cgroup 全走一遍;數量到了這個量級,光是「數一遍」就足以把一顆核連續餵到 100% 好幾秒,剛好餓死排到同一顆核上的網路 driver thread。
為什麼一個本該已經消失的 cgroup 會「殭屍化」、留在 kernel 計數裡不走?這牽涉到 memory cgroup 回收的一個老問題。當一個容器結束、它的 cgroup 目錄被刪掉,kernel 並不會立刻把這個 cgroup 的記憶體會計結構釋放掉——只要還有任何一個 page 在 page cache 裡被算在這個 cgroup 名下(哪怕只是一個已經沒人用、但還沒被回收的 cache page),這個 cgroup 的 mem_cgroup 結構就得繼續存在,好讓那些 page 的會計有歸屬。於是目錄沒了、容器沒了,這個 cgroup 卻以「offline」狀態掛在 kernel 裡,繼續被 /proc/cgroups 計入。正常情況下這些殘留會慢慢被清掉,但累積速度一旦超過回收速度——這裡是一個每幾秒就 crash 重新啟動一次、每次都建立一批 cgroup 的 agent——數字就只增不減。合理的推測是,這也解釋了為什麼遍歷成本會線性惡化:mem_cgroup_nr_lru_pages 這類要走訪所有 cgroup 的路徑,工作量正比於 cgroup 總數,從 240 漲到 68,680,等於把同一個迴圈的長度放大了將近三百倍(原文只給了 68,680 與 240 兩個數字、以及 kubelet 卡在這個 system call 上的事實,遍歷成本與數量成正比是依此推斷)。
殭屍從哪來?源頭是一個完全沒人在用的東西。Pinterest「用 AWS Deep Learning AMI(Ubuntu 20.04)當基礎機器映像,而它預設把 ecs-agent 設成一個 systemd unit」。問題是這些機器跑的是 Kubernetes、不是 ECS,於是 ECS Agent 容器「在我們沒給機器加入 ECS cluster 的權限的情況下,理所當然地一直 crash」。每一次 crash 再重新啟動,就留下一批不會被清掉的 memory cgroup;「好幾天下來,累積出大量的 memory cgroup」。前面那個「不同 AZ 表現不同」的硬體假象也在這裡解開:某個 AZ 的開機腳本因為一個不同的 URL,讓最後一步上報 metric 失敗、整個 bootstrap script 被標成失敗,反而因為 systemd unit 的相依關係擋掉了 ECS agent 啟動——那個 AZ 因此「健康」,純屬意外。
修法簡單到近乎反高潮:「我們就只是在 base image 裡把 ECS agent 的 systemd unit 關掉,然後重開所有機器來清掉殭屍 memcg。」之後「memory cgroup 數量就穩定下來了」,Ray 訓練 job「又回到它們該有的高成功率」——在修好之前,某些 use case 曾經出現「成功率掉超過 25%」。原文的結語是「ENA reset 和機器裡那些殭屍的問題,徹底解決了」。下面這個互動把「為什麼重開機只能撐一週」這件事變成可以動手撥的東西:殭屍 cgroup 隨 uptime 線性累積,到了某個量級才會把單核餵滿、觸發 reset,所以 reboot 清零之後,時鐘又重新開始走。
拖滑桿改變開機天數,看殭屍 cgroup 累積到何時觸發 reset · uptime 0 到 10 天
開機 0.0 天 · 約 240 個 cgroup · 網路正常
橫軸是開機後天數,縱軸是 kernel 追蹤的 memory cgroup 數量
殭屍 cgroup 隨開機時間累積,近七萬個時餵滿單核、觸發 ENA reset;reboot 清零後約一週又復發,重開機只能暫時緩解。
把這個故事的方法論抽出來,對任何要 debug 間歇性、跨機器故障的人都用得上。第一,當「整體健康」與「持續出事」兩個事實打架時,先懷疑你的 aggregate 指標是不是把問題平均掉了——perf 的整機視角看不見的,mpstat 的逐核視角一眼看見。第二,一個假設帶來可量測的改善,不等於它就是病因;huge pages 真的降了 CPU,卻停不了 reset。第三,間歇性故障要靠「時間旅行」式的連續 profiling 來抓——把 perf 錄滿 12 小時,事後用 Flamescope 倒帶到故障前那兩分鐘,比守株待兔可靠得多。最後,殭屍 cgroup 這種「kernel 計數一直漲、實際在用的卻沒幾個」的洩漏,用 /proc/cgroups 的計數對上 /sys/fs/cgroup 的實際目錄數,一個減法就能驗出來。這四點裡沒有一點需要特殊工具,全是 Linux 上現成的 perf、mpstat 和兩個讀檔指令;真正稀缺的不是工具,而是「不相信 aggregate 指標、願意換粒度再看一次」的那份警覺。
Next time:下次看到一台機器「整體 CPU 沒問題」卻週期性出怪事,先用 mpstat 看每顆核的 system CPU,再拿 cat /proc/cgroups 的計數去對 find /sys/fs/cgroup/memory/ -type d | wc -l——兩個數字差到一個數量級,你就抓到殭屍了。