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