那晚杭州的悶熱,至今記憶猶新。
2021年,我剛來到杭州這座「卷城」,入職了一家夢想中的互聯網大廠。作為一名電商新人,我一頭扎進了促銷和會場的研發中。
那晚,我們正為一個S級的「會員閃促」活動做最後的護航,它將在零點準時生效。作戰室裡燈火通明,所有人都盯著大盤,期待著活動上線後,GMV曲線能像火箭一樣發射。
然而,我們等來的不是火箭,而是雪崩。
剛過0點,登登登登… 告警群裡的消息開始瘋狂刷屏,聲音急促得像是防空警報:
[嚴重] promotion-marketing集群 - 應用可用度 < 10%
[嚴重] promotion-marketing集群 - HSF執行緒池活躍執行緒數 > 95%
[緊急] promotion-marketing集群 - CPU Load > 8.0
我心裡咯噔一下,立馬打開內部代號「天眼」的監控系統——整個promotion-marketing
集群,上百台機器,像被病毒感染了一樣,CPU和Load曲線集體垂直拉升,整整齊齊。
這意味著,作為促銷中樞的服務已經事實性癱瘓。所有促銷頁面上,為大會員準備的活動入口,都因服務超時而被降級——活動,上線即「失踪」。
一場精心籌備的S級大促,在上線的第一秒,就「出師未捷身先死」了。
故障排查,有時候像是在黑暗的房間裡找一個黑色的開關,但這一次,我們連房間的門都找不到了。
jstack
分析,卻沒有發現任何死鎖跡象。再次排除。此時,距離故障爆發已經過去了18分鐘。作戰室裡的氣氛已經從緊張變成了壓抑。我能感覺到身後Leader的目光,像兩把手術刀,在我背上反復切割。
一個剛入職不久的小兄弟,看著滿屏的紅色曲線,悄聲自語道:「感覺都要被抬走了…」
他這句話,成了我當晚聽到的最實在的一句「B面」真話。
常規手段全部失效,唯一的辦法,就是深入到JVM的「肌體」內部,看看它的「細胞」到底出了什麼問題。
我保留了一台故障機作為「案發現場」,然後dump了它的堆內存和執行緒棧。
分析堆內存,我發現老年代(Old Gen)的使用率居高不下,CMS回收的效果非常差,導致了頻繁且耗時的Full GC,這完美解釋了為什麼CPU會飆升。
同時,我注意到,內存裡駐留了大量char[]
數組,內容都指向一個和「萬豪活動配置」相關的字符串常量。這說明,有一個巨大的活動配置對象,像一個幽靈,賴在內存裡不走。
接著,我開始分析執行緒棧快照。我用grep
簡單統計了一下:
# 查看等待的執行緒
$ sgrep 'TIMED_WAITING' HSF_JStack.log | wc -l
336
# 查看正在運行的執行緒
$ sgrep 'RUNNABLE' HSF_JStack.log | wc -l
246
三百多個執行緒在等待,兩百多個在運行。問題大概率就出在這兩百多個RUNNABLE
的執行緒上。我過濾出這些執行緒的堆棧信息,一個熟悉的身影,反复出現在我的螢幕上:
at com.alibaba.fastjson.toJSONString(...)
大量的執行緒,都卡在了FastJSON的序列化操作上!
結合堆內存裡那個巨大的「萬豪配置」字符串,一個大膽的猜測浮現在我腦海裡:有一個巨大的對象,正在被瘋狂地、反復地序列化,這個CPU密集型操作,耗盡了執行緒資源,拖垮了整個集群!
順著執行緒棧的指引,我很快定位到了代碼裡的「犯罪現場」: XxxxxCacheManager.java
在這段代碼上方,還留著一行幾個月前同事留下的、刺眼的註釋:
// TODO: 此處有性能風險,大促前需優化。
正是這個被所有人遺忘的TODO,在今晚,變成了捅向我們所有人的那把尖刀。
這是一個從快取(Tair)裡獲取活動玩法資料的工具類。而另一個寫入快取的方法,則讓我大開眼界:
// ... 省略部分代碼
// 從快取(Tair)裡獲取活動玩法資料的工具類
public void updateActivityXxxCache(Long sellerId, List<XxxDO> xxxDOList) {
try {
if (CollectionUtils.isEmpty(xxxDOList)) {
xxxDOList = new ArrayList<>();
}
// 為了防止單Key讀壓力過大,設計了20個散列Key
for (int index = 0; index < XXX_CACHE_PARTITION_NUMBER; index++) {
// 致命問題:將序列化操作放在了循環體內!
tairCache.put(String.format(ACTIVITY_PLAY_KEY, xxxId, index),
JSON.toJSONString(xxxDOList), // 就是這行代碼,序列化了20次!
EXPIRE_TIME);
}
} catch (Exception e) {
log.warn("update cache exception occur", e);
}
}
看著這段代碼,我愣了足足十秒鐘。
零點活動生效,快取裡沒有資料,發生了快取擊穿,這很正常。
為了防止單Key讀壓力過大,作者設計了20個散列Key來分散讀流量,這思路也沒問題。
但致命的是,在寫入快取時,將巨大對象(約1-2MB)序列化的操作,竟然被放在了for循環內部!
這意味著,每一次快取擊穿後的回寫,都會將一個1MB的巨大對象,連續不斷地、在同一執行緒裡,序列化整整20次!
這已經不是代碼了,這是一台CPU絞肉機。
而更要命的是,我們的快取中間件Tair LDB本身性能脆弱,被這放大了20倍的寫流量(20 x 1MB)瞬間打爆,觸發了限流。
Tair被限流後,寫入耗時急劇增加,從幾十毫秒飆升到幾秒。這導致「CPU絞肉機」的操作時間被進一步拉長。
最終,HSF執行緒池被這些「又慢又能吃」的執行緒全部佔滿,服務雪崩。
故障的根因已經水落出。我們緊急回滾了這段「循環序列化」的代碼,集群在凌晨0點30分左右,終於恢復了平靜。30分鐘,生死時速。
在事後的復盤會上,我分享了老A的「B面三法則」:
這次故障的始作俑者,就是一段為了解決「讀壓力」而設計的「好代碼」。但好的優化是錦上添花,壞的優化是「畫蛇添足」。敬畏之心,比奇技淫巧更重要。
我們有機器、接口、中間件等各種監控,但唯獨缺少對「代碼塊耗時」的精細化監控。如果APM工具能第一時間告訴我們90%的耗時都在XxxxxCacheManager
的update
方法裡,排查效率至少能提高一倍。
代碼裡使用的Tair LDB是一個早已無人維護的老舊中間件。技術債就像家裡的蟑螂,你平時可能看不到它,但它總會在最關鍵、最要命的時候,從角落裡爬出來,給你致命一擊。
那天凌晨一點,我走在杭州空無一人的大街上,吹著冷風,腦子裡卻異常地清醒。
因為在那場驚心動魄的「雪崩」裡,在那一串串冰冷的執行緒堆棧中,我再次確認了個樸素的道理:
所有宏大的系統,最終都是由一行行具體的代碼組成的。而魔鬼,恰恰就藏在其中。
老A說:
很多時候,一個P3故障的根因,可能並不是真正的高深的架構難題,而僅僅是一行被放錯了位置的for
循環。敬畏代碼,是每個工程師應有的基本素養。