生(sheng)產事故-Caffeine緩存誤用之臨下班的救(jiu)贖(shu)
入職多年,面對生產(chan)環境,盡管都(dou)(dou)是(shi)(shi)小心翼翼,慎之又慎,還是(shi)(shi)難免捅出簍(lou)子。輕則滿(man)頭大(da)汗,面紅(hong)耳(er)(er)赤。重則系(xi)統停擺,損失(shi)資金。每(mei)一(yi)個生產(chan)事故(gu)的(de)(de)背后,都(dou)(dou)是(shi)(shi)寶貴的(de)(de)經驗和(he)教訓(xun),都(dou)(dou)是(shi)(shi)項目成員的(de)(de)血(xue)淚史。為了(le)更好(hao)地防范(fan)和(he)遏(e)制今后的(de)(de)各(ge)類事故(gu),特開此專題,長期更新和(he)記錄大(da)大(da)小小的(de)(de)各(ge)類事故(gu)。有(you)些是(shi)(shi)親身(shen)經歷,有(you)些是(shi)(shi)經人耳(er)(er)傳口授,但無一(yi)例(li)(li)外都(dou)(dou)是(shi)(shi)真(zhen)實案例(li)(li)。
注意:為了避免不必要的麻煩和商密問題,文中提到的特定名稱都將是化名、代稱。
0x00 大綱
0x01 事故背景
2025年(nian)7月9日17時有(you)余,筆者正準備結束(shu)疲憊(bei)的一(yi)(yi)(yi)天,關機走人之(zhi)時,桌面右(you)下(xia)角安靜了(le)一(yi)(yi)(yi)天的內部通訊軟件圖標突然亮起,內心頓感不妙(miao)……打開一(yi)(yi)(yi)看,原來是運維小哥找過來了(le),說是某接(jie)口服務連續多次調(diao)用超時或失敗,觸發告警(jing)閾值,具體原因不明(ming),請求支援。(臨下(xia)班出(chu)事(shi)似乎已成為(wei)一(yi)(yi)(yi)種規律)
0x02 事故分析
該服(fu)務是一個基于 SpringBoot + JDK 1.8 的(de) API 服(fu)務,提供了幾個信(xin)息查詢接口(kou),沒有復雜的(de)業務邏(luo)輯,也不涉(she)及第三方接口(kou)調用,僅依(yi)賴于數據庫進行簡單的(de) CURD 操作。
第一(yi)時間讓運維拷(kao)貝和固定了事故系統日志及生產版本(ben)應用包。發現該服務在一(yi)周前升(sheng)級(ji)部署過,不排除是版本(ben)升(sheng)級(ji)引起的問(wen)題。于是先留一(yi)手(shou),招呼(hu)運維小哥做(zuo)好隨時進(jin)行(xing)版本(ben)回退的準(zhun)備,以免不能及時修復問(wen)題。
運維(wei)小哥(ge)已經(jing)排除(chu)了是(shi)(shi)網絡和線路(lu)的問題(ti),也嘗試按照常(chang)見故障應對手冊重啟過(guo)應用,服務短暫恢復正(zheng)常(chang),但是(shi)(shi)隨著請求(qiu)壓力上來以后,又(you)會(hui)頻繁失敗觸發告警。為(wei)了避免(mian)事故進一步擴(kuo)大,運維(wei)小哥(ge)選擇迅(xun)速搖(yao)人。
秉著先易后難的順序,先快速掃描了一遍應用日志,常規日志未見明顯ERROR、WARN以及Exception等信息(xi),SQL日志未(wei)見慢查詢和連(lian)接池異(yi)常(chang)。隨(sui)后檢(jian)查數(shu)據庫(ku)壓力(li),發現數(shu)據庫(ku)活躍連(lian)接數(shu)不高,也未(wei)見死鎖和異(yi)常(chang)會(hui)話。
jps找到服務進程對應的PID,使用top命令查看進程的資源占用情況,發現服務的 CPU 和內存資源占用不高。ss -antp|grep :9999| wc -l查看對應端口(kou)的(de)連接情(qing)況,大約兩百多個(ge)活躍連接,屬于正常范(fan)圍內(nei)。磁(ci)盤監控(kong)未見明顯壓(ya)力(li),看來基本(ben)可以確定是(shi)應用本(ben)身的(de)問(wen)題。
于是使用jstack -l保存了第一次線程快照,然后讓運維小哥重啟接口服務,果然如小哥所說,接口調用短暫正常以后很快又出現異常。為了排除偶然因素干擾,這時做了第二次線程快照用于對照分析,同時使用jmap抓取了 dump 文件備(bei)用。完成以(yi)上步驟以(yi)后,果斷讓運維(wei)小哥(ge)將服務回退(tui)到(dao)歷史版(ban)本,應急解決(jue)故障。
仔細分析兩次抓取的線程快照,發現大量的線程處于BLOCKED狀(zhuang)態,且擁(yong)有高度(du)相似的調用(yong)棧:
"thread-3197" Id=4959 BLOCKED on java.util.concurrent.ConcurrentHashMap$ReservationNode@1b1f101f owned by "TaskExecutor-827" Id=936
at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1868)
- blocked on java.util.concurrent.ConcurrentHashMap$ReservationNode@1b1f101f
at com.github.benmanes.caffeine.cache.BoundedLocalCache.doComputeIfAbsent(BoundedLocalCache.java:2404)
at com.github.benmanes.caffeine.cache.BoundedLocalCache.computeIfAbsent(BoundedLocalCache.java:2387)
at com.github.benmanes.caffeine.cache.LocalCache.computeIfAbsent(LocalCache.java:108)
at com.github.benmanes.caffeine.cache.LocalLoadingCache.get(LocalLoadingCache.java:56)
(這里省略部分信息)
看(kan)起來是高并發的時候 Caffeine 緩存的處(chu)理出現(xian)了(le)競態爭搶,問題(ti)初(chu)步定位,需(xu)要進一(yi)步分析事(shi)故原(yuan)因。
0x03 事故原因
簡單 review 了一下變更的代碼,發現同事A為某個關鍵系統參數的查詢添加了秒級的短時緩存,減少高并發下的數據庫查詢調用,并且使用有界的LoadingCache來加載和刷新相關數據,關鍵的Bean定義如下:
@Bean
@ConditionalOnBean(ParameterRepository.class)
public LoadingCache<String, ParameterEntity> parameterCache(ParameterRepository parameterRepository,
Executor refreshExecutor) {
return Caffeine.newBuilder()
.maximumSize(256)
.refreshAfterWrite(Duration.ofSeconds(3))
.expireAfterAccess(Duration.ofSeconds(7))
.executor(refreshExecutor)
.build(bssSysparmRepository::getById);
}
乍看之下似乎很合理。但是為何會出問題呢?在高并發場景下,多個線程同時請求緩存中不存在的數據,導致多個線程都需要去加載數據,而LoadingCache的刷新策略是按需刷新,即只有當緩存中的數據過期時才會觸發刷新。如果多個線程同時觸發刷新,就會導致多個線程同時去加載數據,并使用相同的Key值調用ConcurrentHashMap.compute方法加載和刷新數據,從而導致競態爭搶。這種機理導致LoadingCache或者說ConcurrentHashMap(在JDK1.8里面)并(bing)不適合用(yong)在需(xu)要高并(bing)發頻繁刷新的緩存場景。
有意思的是,這個鍋其實跟JDK中ConcurrentHashMap的實現機制有關,存在同樣問題的還有computeIfPresent方法,。
解決的方法不難,就是使用AsyncLoadingCache來代替LoadingCache,異步加載數(shu)據,避(bi)免(mian)競態爭搶。修改下代(dai)碼:
@Bean
@ConditionalOnBean(ParameterRepository.class)
public AsyncLoadingCache<String, ParameterEntity> parameterCache(ParameterRepository parameterRepository,
Executor refreshExecutor) {
return Caffeine.newBuilder()
.maximumSize(256)
.refreshAfterWrite(Duration.ofSeconds(3))
.expireAfterAccess(Duration.ofSeconds(7))
.executor(refreshExecutor)
.buildAsync(parameterRepository::getById);
}
取用時,從LoadingCache.get()方法改為AsyncLoadingCache.synchronous().get()方法(fa)即可。優化版本上(shang)線后,各方人員(yuan)情緒穩定。
0x04 事故復盤
比起追究(jiu)責任,更重要的是帶給我們的啟(qi)發(fa):
- 沒有基準的性能優化都是耍流氓;
- 上線前需要先進行性能回歸,確認優化后的性能是否符合預期。
0x05 事故影響
生產系統緊急回滾一次,所幸的是沒有收到客訴(那就是沒有問題)。A公(gong)司相關負責(ze)人連夜編寫事(shi)故(gu)報告一份,并通知其他項目組未(wei)雨綢繆。
