🔧 阿川の電商水電行
Shopify 顧問、維護與客製化
💡
小任務 / 單次支援方案
單次處理 Shopify 修正/微調
⭐️
維護方案
每月 Shopify 技術支援 + 小修改 + 諮詢
🚀
專案建置
Shopify 功能導入、培訓 + 分階段交付

P10老闆一句‘搞不定就P0’,15分鐘我用Arthas捞回1000萬資損

image

一次超驚險的故障排查經歷

  • 事件:雙十一大促高峰期,核心用戶服務集群出現大規模請求超時。
  • 影響:“下單成功率”斷崖式下跌,基於即時廣告流量轉化率估算,導致千萬級廣告費資損,故障被定級為P1。
  • 時長:從故障爆發到“止血”,耗時15分鐘;從故障爆發到“根因定位”,耗時約30分鐘。
  • 根因:歷史代碼在一個全球共享的單例中,誤用了非線程安全的HashBiMap,在高併發下被觸發競態,導致其內部鏈表打環,讀操作線程陷入無限循環,耗盡線程池。

大家好,我是老A。

上週我在沸點發起了一輪投票,諮詢大家寫作方向,大部分同學想看我是如何用arthas定位線上問題的,所以今天這篇文章我就好好講講,我是如何用arthas快速定位了線上問題,避免了千萬級別的廣告費資損的。

之前我說過,有兩年我一直在做電商業務,也經常搞大促,常在河邊走,哪有不濕鞋。記得有次雙十一就差點弄了個P0故障,欲知故障如何,且聽我細細道來。

雙十一前一週,會進行各種大促保障評審、預案評審以及核心鏈路壓測。前三天開始就要有人整夜的值班,那次雙十一我們是負責整點拉新(用增),在能進行用增的各大會場、各種整點的活動(紅包雨/秒殺)都放置轉化埋點,將拉新做到極致。沒成想,那次出的故障,差點把我們CTO送走了。。。

第一幕:風暴之眼——沉默的雪崩

時間拉回到2023年11月11號下午13點59分,我們用增小組的核心成員都在雙十一作戰室裡盯盤(盯盤就是看大促期間的各種核心指標,包括核心的應用水位、各種技術指標、業務上的核心交易成功率、用增轉化漏斗等等)。

再過下一分鐘,14點的紅包雨活動就會開始,我們的用增埋點將湧入大量流量,完成它的轉化使命。

14:00:我們看到用增埋點的流量曲線激增,所有的核心指標都很正常,我們都鬆了口氣,準備接杯咖啡,開啟一天的輕鬆盯盤工作。

14:01:突然,核心大盤開始閃爍,“下單成功率”斷崖式下跌,5分鐘內,從99.9%暴跌到70%以下。告警群瞬間爆炸,全是核心交易鏈路的“調用超時”。卧槽,作戰室瞬間炸開鍋了。技術Leader王哥(化名)馬上開始帶我們排查原因。

14:02:P9老闆衝進作戰室,他沒有說話,只是靜靜地看著大盤上那條觸目驚心的下跌曲線。會議室裡,空氣仿佛都凝固了,只能聽到我們團隊瘋狂敲擊鍵盤的聲音。

過了一分鐘,他用一種不帶任何情緒、但極其清晰的聲音,對我的Leader說:“老王,按照公司故障標準,分鐘級成功量下跌超30%,就直接觸發P1。” 他指了指屏幕上已經跌破70%的成功率曲線。“現在已經P1了,15分鐘內如果不能止血,就上升到P0故障。10分鐘內我要定位原因,15分鐘內我要止血,做不到你就直接去跟總裁解釋吧。你也知道,大促每分鐘的站外流量廣告費,100萬不止。”

詳細時間線與排查過程

14:02 - 第一輪排查:信息“矛盾”,陷入僵局

系統水位監控: 我們首先排查了集群整體的CPU、內存、網路、QPS大盤平均指標,發現無明顯異常。

我立刻意識到,集群平均指標可能會稀釋掉單點問題,隨即立刻下鑽到單機監控,果然發現有少數幾個節點的CPU使用率出現尖刺。(跟SRE溝通確認後,發現在部署該服務的50個Pod中,有3個CPU負載達到了100%,占比6%,尚未對集群整體CPU造成明顯衝擊,但已經足以拖垮上游鏈路)。

所以我緊接著立刻去看了線程池監控,果然--tomcat工作線程池中忙碌線程占比100%,線程池已耗尽!但是,Web入口的QPS曲線並未歸零,只是略有下降!

老A評點:為什麼線程池滿了,QPS沒歸零?
這是Tomcat架構的一個典型特徵。處理業務邏輯的worker線程池滿了,但處理健康檢查或部分簡單請求的acceptor線程池還正常,導致了QPS看似平穩的假象。

14:10 - 第二輪排查:jstack的“誤診”

發現單點CPU打滿,SRE的同學立刻對其中一台高CPU的“嫌疑機器”,執行了jstack,連續拉取了3份線程Dump。與此同時,GC日誌(通過jstat)和APM的鏈路監控也都沒有發現明顯異常,所有線索都指向了應用內部。

Dump結果顯示,大量業務線程處於RUNNABLE狀態,堆棧都指向HashBiMap.seekByKey,但沒有任何死鎖跡象。**

老A評點:jstack只能拍下一張靜態快照。它對於【死鎖】很敏感,但對於【死循環】或【活鎖】這種RUNNABLE狀態的軟故障,它只能告訴我們線程在幹什麼,卻無法告訴我們為什麼一直在這裡幹。根據這份Dump,我們初步判斷為“Guava某個方法有性能瓶頸”,但無法解釋為何會拖垮整個線程池(後來發現這裡的判斷是錯誤的)。

14:15 - 止血:業務降級

10分鐘的止血DDL馬上就要到了,根因依然不明。老王立刻做出決策:通過配置中心,將剛剛上線的【新用戶首次下單送紅包】功能,進行業務降級。因為這是最大、也是唯一的變數

“血”暫時止住了。下單成功率開始緩慢回升。

老A說:為什麼恢復是“緩慢”的?
即使關閉了新功能開關,那些已經陷入死循環的線程也不會立即釋放,需要等待Tomcat的worker線程超時或被健康檢查機制異常替換後才能被清理,因此恢復並非瞬時完成。

14:20 - Arthas登場

雖然止血了,但是問題根因還沒找到,我對老王說:“Guava只是猜測,但我們不能靠猜。剛剛的jstack看不出具體的問題是啥,我很懷疑那幾個線程死循環了。直接用arthas看看這幾個線程的即時CPU消耗吧。”

第二幕:絕境亮劍——Arthas的降魔三式

在獲得SRE和運維的緊急授權,並評估了Attach操作可能帶來的微小性能抖動風險、確認當前系統狀態尚能承受後,我直接在問題伺服器上掛載了Arthas。

第一式:thread命令,找到“案發現場”

14:25 - thread -n 3

我執行了 thread -n 3。螢幕上,那幾個RUNNABLE的線程(堆棧信息與jstack一致),CPU占用率赫然是100%!但這只是找到了“案發現場”,並沒有找到“作案手法”。

# 【脫敏後範例】
[arthas@12345]$ thread -n 3
"biz-thread-1" prio=5 tid=0x00007f8c9a0b8000 state=RUNNABLE cpu_usage=99.99%
   at com.google.common.collect.HashBiMap.seekByKey(HashBiMap.java:159)
   at com.google.common.collect.HashBiMap.put(HashBiMap.java:109)
   at com.example.service.UserCacheManager.syncUserCache(UserCacheManager.java:88)
   at com.example.controller.NewUserController.handleNewUser(NewUserController.java:45)
   ...
"biz-thread-2" prio=5 tid=0x00007f8c9a0b9800 state=RUNNABLE cpu_usage=99.98%
   at com.google.common.collect.HashBiMap.seekByKey(HashBiMap.java:159)
   at com.google.common.collect.HashBiMap.get(HashBiMap.java:99)
   at com.example.service.OrderServiceImpl.checkUserCache(OrderServiceImpl.java:112)
   at com.example.service.OrderServiceImpl.createOrder(OrderServiceImpl.java:76)
   ...
"main" prio=5 tid=0x00007f8d1c009000 state=TIMED_WAITING cpu_usage=0.01%
   ...

第二式:jadstack,還原“作案手法”

14:26 - jad & stack

拿到了threadstack的輸出後,我心裡反而咯噔一下,知道這事兒麻煩了。

為什麼?

jstack報告裡,所有線程都處於RUNNABLE狀態,而不是BLOCKED,這意味著沒有線程在等待鎖,它們都在“瘋狂地空轉”,這比死鎖更難排查。

看到堆棧頂部的HashBiMap.seekByKey時,我的“併發PTSD”犯了——​一個非線程安全的集合類 + 高CPU的RUNNABLE線程​,這兩個特徵組合在一起,幾乎可以確定問題出在了併發上。

我的初步推論是:這個HashBiMap的內部數據結構,在高併發寫入下,已經被破壞了。 極大概率,是它內部用於解決哈希衝突的鏈表,被打成了環,導致任何讀這個環的線程,都陷入了無限循環。

為了驗證這個推論,我立刻jad --classLoader [hash]指定類加載器,反編譯了調用HashBiMapxxxManager,確認了它是個沒有加鎖的、靜態的、非線程安全的緩存實例,也就是說它內部是使用鏈表法來解決哈希衝突。

接著stack com.xxx.service.xxxManager putUser,清晰地看到,所有觸發寫入操作的源頭,都來自於被我們剛剛降級的【新用戶首次下單送紅包】功能。

所有證據都指向了同一個結論,但我還缺少最後一點證據。我需要在P9面前,拿出無可辯駁的鐵證

第三式:tt & ognl,找到鐵證

第一步,tt時光隧道保留現場

14:28 - tt & ognl

先用tt命令,捕獲一次xxxManager.syncUserCache方法的調用現場。

# -t 表示記錄,-n 1 表示只記錄一次,防止內存爆炸
tt -t com.xxx.service.xxxManager syncUserCache -n 1

這個命令的作用是把整個JVM在那一瞬間的狀態給凍結並保存了下來。 記錄的INDEX1001

第二步,ognl深入內存,定位循環引用

然後,我寫下了這段ognl表達式。它的作用,就是進入到我們剛剛凍結的那個xxxManager實例的內存裡,直接拿到那個出問題的userCache(也就是HashBiMap),然後暴力遍歷它內部的鏈表結構。

# -i 1001 指定剛才tt記錄的index
# -x 4 表示結果最多展開4層,讓我們能看清內部結構
# -w 表示執行ognl表達式
tt -i 1001 -w '#[email protected]@getApplicationContext(), #xxxManager=#context.getBean("xxxManager"), #biMap=#xxxManager.xxCache, #table=#biMap.table, #entry=#table[15], {#entry.key, #entry.next.key, #entry.next.next.key, #entry.next.next.next.key}'

老A說:這段OGNL到底做了什麼
這段命令,實際上是一套組合拳:

  1. #context=@...():我們先通過一個能拿到Spring上下文的工具類,拿到了整個應用的ApplicationContext
  2. #xxxManager=#context.getBean("xxxManager"):然後,直接取出了我們想要的那個xxxManager的實例。
  3. #biMap=#xxxManager.xxCache, #table=#biMap.table:深入xxxManager內部,拿到了它的私有欄位xxCache(那個出問題的HashBiMap),甚至進一步拿到了HashBiMap內部存儲數據的私有數組table
  4. #entry=#table[15], ...:我們假設問題出在第15個哈希桶裡,直接拿出這個桶的第一個節點(entry),然後暴力打印出它後面三個節點的key

14:30 命令的返回結果,清晰地打印出了一個循環引用

# 偽示例
@ArrayList[
    @Long[12345],   // entry.key
    @Long[67890],   // entry.next.key
    @Long[12345],   // entry.next.next.key
    @Long[67890],   // entry.next.next.next.key
]

鐵證如山!邏輯鏈至此完全閉環。

第三幕:收刀入鞘——從“救火”到“防火”

1. 根因到底是什麼?

罪魁禍首,不是Google,而是我們自己。這是一個潛伏了三年的技術債:一位前輩為了圖方便,在一個靜態的、全局共享的緩存實例裡,誤用了非線程安全的HashBiMap,並且還沒有加任何鎖

# xxxManager.java - 導致問題的核心代碼(部分截取示意)
// 老A說:Guava官方文檔早已明確警告HashBiMap非線程安全, 建議使用Maps.synchronizedBiMap()包裝。
public class xxxManager {
    // 非線程安全
    private static final BiMap<Long, UserInfo> userCache = HashBiMap.create();
    // 未加鎖寫入,高併發下就是定時炸彈
    // 多個線程同時調用,在內部擴容時極易發生競態

    public void xxCache(UserInfo newUser) {
        userCache.forcePut(newUser.getUserId(), newUser);
    }
}

大促帶來的海量新用戶流量,觸發高併發寫入。在多線程下,HashBiMap內部在進行哈希衝突處理或擴容時,發生了競態條件,破壞了其內部用於解決哈希衝突的鏈表結構,最終形成循環引用,導致任何讀操作都陷入死循環。

2. 壓測為何會失效?

後來我去翻了當時的壓測文檔,發現壓測用的都是存量用戶,幾乎沒有觸發高併發的緩存寫入場景。而大促開始的瞬間,海量新用戶湧入,打開了這個埋了三年的雷。壓測,永遠無法100%模擬線上的“混沌效應”。

3. 長期改進措施

  • 代碼修復:使用ConcurrentHashMap替換HashBiMap,並重構相關邏輯。
  • 流程改進:在CR流程中,加入線程安全的專項自動化check list;在靜態代碼自動化掃描中,增加對非線程安全集合類在單例中使用的檢測規則。

老A說:
一個頂級專家的價值,不在於他會用多少工具,而在於他深刻理解每種工具的能力邊界。比如知道什麼時候jstack會誤診,什麼時候該用Arthas這類工具。


感謝大家的閱讀。我是老A,一個只想跟你說點B面真話的師兄。

如果這篇文章讓你有了一點點啟發,那就是對我最大的肯定。

為了感謝大家的支持,我把這兩年在一線大廠面試和帶團隊中,沉澱下來的所有私房筆記,整理成了一份《大廠碼農老A的B面真話手冊》。

裡面沒有市面上千篇一律的八股文,只有一些極其管用的潛規則和避坑指南,希望能幫你少走一些彎路。

關注我的同名公眾號【大廠碼農老A】,後台回覆“B面”,就能免費獲取。後台回覆“arthas”獲取史上最全的《大廠arthas實戰手冊》

最後,如果覺得內容還行,幫忙點個讚、點個在看,讓更多需要它的兄弟看到,感謝。


原文出處:https://juejin.cn/post/7555180687033810944


精選技術文章翻譯,幫助開發者持續吸收新知。

共有 0 則留言


精選技術文章翻譯,幫助開發者持續吸收新知。
🏆 本月排行榜
🥇
站長阿川
📝14   💬8   ❤️4
630
🥈
我愛JS
📝3   💬11   ❤️7
211
🥉
AppleLily
📝1   💬4   ❤️1
71
#4
御魂
💬1  
3
評分標準:發文×10 + 留言×3 + 獲讚×5 + 點讚×1 + 瀏覽數÷10
本數據每小時更新一次
🔧 阿川の電商水電行
Shopify 顧問、維護與客製化
💡
小任務 / 單次支援方案
單次處理 Shopify 修正/微調
⭐️
維護方案
每月 Shopify 技術支援 + 小修改 + 諮詢
🚀
專案建置
Shopify 功能導入、培訓 + 分階段交付