動態

詳情 返回 返回

凌晨零點,一個TODO,差點把我們整個部門抬走 - 動態 詳情

那晚杭州的悶熱,至今記憶猶新。

2021年,我剛來到杭州這座“卷城”,入職了一家夢想中的互聯網大廠。作為一名電商新人,我一頭扎進了促銷和會場的研發中。

那晚,我們正為一個S級的“會員閃促”活動做最後的護航,它將在零點準時生效。作戰室裏燈火通明,所有人都盯着大盤,期待着活動上線後,GMV曲線能像火箭一樣發射。

然而,我們等來的不是火箭,而是雪崩

剛過0點,登登登登… 告警羣裏的消息開始瘋狂刷屏,聲音急促得像是防空警報:

[嚴重] promotion-marketing集羣 - 應用可用度 < 10%
[嚴重] promotion-marketing集羣 - HSF線程池活躍線程數 > 95%
[緊急] promotion-marketing集羣 - CPU Load > 8.0

我心裏咯噔一下,立馬打開內部代號“天眼”的監控系統——整個promotion-marketing集羣,上百台機器,像被病毒感染了一樣,CPU和Load曲線集體垂直拉昇,整整齊齊。

這意味着,作為促銷中樞的服務已經事實性癱瘓。所有促銷頁面上,為大會員準備的活動入口,都因服務超時而被降級——活動,上線即“失蹤”

一場精心籌備的S級大促,在上線的第一秒,就“出師未捷身先死”了。

第一幕:無效的掙扎

故障排查,有時候像是在黑暗的房間裏找一個黑色的開關,但這一次,我們連房間的門都找不到了。

  1. 第一步,看日誌。 一個NPE(空指針異常)的數量有點多,但仔細一看,來自一個非常邊緣的富客户端jar包,跟核心鏈路無關。排除。
  2. 第二步,懷疑死鎖。 HSF線程池全部耗盡,是線程“罷工”的典型症狀。我立刻拉取線程快照,用jstack分析,卻沒有發現任何死鎖跡象。再次排除。
  3. 第三步,重啓大法。 我們挑了幾台負載最高的機器進行重啓。起初兩分鐘確實有效,但只要新流量一進來,CPU和Load就像脱繮的野馬,再次衝頂。
  4. 第四步,擴容。 既然單機扛不住,那就用“人海戰術”。我們緊急擴容了20台機器。但新機器就像衝入火場的士兵,沒堅持幾分鐘,就同樣陷入了高負載、瘋狂GC的泥潭。

此時,距離故障爆發已經過去了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面三法則”:

法則一:任何脱離了容量評估的“優化”,都是在“耍流氓”。

這次故障的始作俑者,就是一段為了解決“讀壓力”而設計的“好代碼”。但好的優化是錦上添花,壞的優化是“畫蛇添足”。敬畏之心,比奇技淫巧更重要。

法則二:監控的終點,是“代碼塊耗時”。

我們有機器、接口、中間件等各種監控,但唯獨缺少對“代碼塊耗 plataformas”的精細化監控。如果APM工具能第一時間告訴我們90%的耗時都在XxxxxCacheManagerupdate方法裏,排查效率至少能提高一倍。

法則三:技術債,總會在你最想不到的時候“爆炸”。

代碼裏使用的Tair LDB是一個早已無人維護的老舊中間件。技術債就像家裏的蟑螂,你平時可能看不到它,但它總會在最關鍵、最要命的時候,從角落裏爬出來,給你致命一擊。

那天凌晨一點,我走在杭州空無一人的大街上,吹着冷風,腦子裏卻異常地清醒。

因為在那場驚心動魄的“雪崩”裏,在那一串串冰冷的線程堆棧中,我再次確認了一個樸素的道理:

所有宏大的系統,最終都是由一行行具體的代碼組成的。而魔鬼,恰恰就藏在其中。


老A説:
很多時候,一個P3故障的根因,可能並不是什麼高深的架構難題,而僅僅是一行被放錯了位置的for循環。敬畏代碼,是每個工程師應有的基本素養。
user avatar aitaokedemugua 頭像 king_wenzhinan 頭像 u_17513518 頭像 smalike 頭像 journey_64224c9377fd5 頭像 segmentfault 頭像 teamcode 頭像 jingdongkeji 頭像 qingzhan 頭像 kobe_fans_zxc 頭像 aqiongbei 頭像 longlong688 頭像
點贊 195 用戶, 點贊了這篇動態!
點贊

Add a new 評論

Some HTML is okay.