阿里妹導(dǎo)讀
作者抽絲剝繭的記錄了一次訪問redis延時(shí)高問題的排查和總結(jié)。
背景
20230308 在某地域進(jìn)行了線上壓測, 發(fā)現(xiàn)接口RT頻繁超時(shí), 性能下降嚴(yán)重, P50 400ms+, P90 1200ms+, P99 2000ms+。
細(xì)致排查發(fā)現(xiàn)其中重要的原因是, 訪問緩存rt竟然飆到了1.2s左右。
作為高性能愛好者, 榨干CPU的每一分價(jià)值是我們的宗旨, 是可忍孰不可忍, 怎么能光空轉(zhuǎn), 不干活呢? 那就仔細(xì)分析下問題。
為啥Redis訪問延時(shí)如此高?
我們簡化下Redis訪問流程如下:
可能性1: 服務(wù)端問題?
我們Redis使用的是 redis_amber_master_4xlarge_multithread 16C32G+480G SSD 規(guī)格, 最大QPS參考值24w, 最大連接數(shù)3w, 配置還是非常豪華的。
如下, QPS以及Load在峰值請求階段, 都仍然處于低位。
可能性2: 物理網(wǎng)絡(luò)問題?
如下, 請求遠(yuǎn)遠(yuǎn)沒有達(dá)到機(jī)器帶寬, 不是瓶頸. 另外單獨(dú)看了網(wǎng)卡重傳率等指標(biāo), 也都正常。
可能性3: 客戶端問題?
那么很大概率就是客戶端自身問題了. 我們把客戶端詳細(xì)放大如下:
JVM FGC STW?
根據(jù)當(dāng)時(shí)ARMS監(jiān)控結(jié)果如下, 雖然YGC次數(shù)與耗時(shí)有所上升, 但沒有發(fā)生FGC:
JedisPool問題?
把內(nèi)存Dump出來, 分析JedisConnectionFactory幾個(gè)相關(guān)重要指標(biāo), 發(fā)現(xiàn)問題有如下2個(gè):
maxBorrowWAItTimeMills過大: 即最大等待時(shí)間過久。在等待從連接池中獲取連接, 最大等待了1200ms。很大概率是因?yàn)閎lock在連接池獲取, 導(dǎo)致請求處理緩慢。
Redis連接創(chuàng)建銷毀次數(shù)過多: createdCount 11555次; destroyedCount: 11553次。說明max-idle參數(shù)設(shè)置不合理(on return的時(shí)候檢查idle是否大于maxIdle, 如果大于則直接銷毀該連接)。每個(gè)對象的創(chuàng)建就是一次TCP連接的創(chuàng)建, 開銷較大。導(dǎo)致脈沖式請求過來時(shí)引發(fā)頻繁創(chuàng)建/銷毀, 也會(huì)影響整體性能。
順便說一句: maxBorrowWaitTimeMills, createdCount, destroyedCount 幾個(gè)metrics信息是JedisPool對象持久維護(hù)的全局變量信息, 只要JVM不重啟, 這個(gè)信息就會(huì)一直存在。這也就是為啥不需要在壓測峰值時(shí)獲取內(nèi)存dump, 而是事后dump也可以。
此外, 如果細(xì)致探索JedisPool參數(shù)工作機(jī)制, 就需要了解Apache的ObjectPool2的機(jī)制。剛好筆者在之前研究過ObjectPool, 后續(xù)會(huì)出單獨(dú)文章闡述&對比ObjectPool, ObjectPool2, JedisPool以及經(jīng)常踩坑的DruidPool的實(shí)現(xiàn)原理與差異。
本文就不再贅述, 敬請期待~
至此, 定位問題是JedisPool行為異常導(dǎo)致。
如何解決問題?
線上JedisPool實(shí)際參數(shù)
參數(shù)行為解析
脈沖式請求引發(fā)的問題
我們把問題簡化為如下序列, 即可發(fā)現(xiàn)問題所在. 在T2~T3內(nèi), 84個(gè)對象創(chuàng)建, 84個(gè)對象銷毀. 造成了極大的損耗。
期望的行為模式
由于線上環(huán)境, Redis服務(wù)器配置較高, 為了能充分壓榨性能, 同時(shí)應(yīng)對容器場景下典型的突發(fā)峰值, 因此如下行為:
連接池的最大數(shù)量=連接池的最小數(shù)量=連接池的穩(wěn)定數(shù)量. 即不要臨時(shí)去創(chuàng)建連接, 防止等待過久。
需要定時(shí)心跳保活與檢測, 及時(shí)刪除掉超時(shí)/無效的連接。
不要因?yàn)閕dle時(shí)間過久而重建連接(只因?yàn)檫B接失效而重建)。防止無意義的大規(guī)模連接重建。
效果驗(yàn)證
終于在20230413重新迎來了一波壓測, 流量模型與上次相同。結(jié)果如下:
maxBorrowWaitTimeMills 下降比例接近 80%
createdCount 也從之前的 11555次 下降到了 500次(即池子初始化的size)
業(yè)務(wù)側(cè)整體性能也大幅提升, P50與P90均下降了將近60%, P99更是夸張地下降了70%。簡直是amazing, 完結(jié)撒花!~
