天天看點

記一次 Redis 連接配接問題排查

作者:Kirito的技術分享

問題發現

用戶端:業務應用使用 lettuce 用戶端

服務端:Redis server 部署架構采用 1 主 + 1 從 + 3 哨兵

Redis 和業務應用部署在同一個 K8s 叢集中,Redis Server 暴露了一個 redis-service,指向到 master 節點,業務應用通過 redis-service 連接配接 Redis。

某個時刻起,開始發現業務報錯,稍加定位,發現是 Redis 通路出了問題,搜尋業務應用日志,發現關鍵資訊:

org.springframework.data.redis.RedisSystemException: Error in execution; nested exception is io.lettuce.core.RedisCommandExecutionException: READONLY You can't write against a read only replica.
           

這是一個 Redis 通路的報錯,看起來跟 Redis 的讀寫配置有關。

問題定位

首先排查下業務應用和 Redis 的連接配接情況

# netstat -ano | grep 6379
tcp 0 0 172.24.7.34:44602 10.96.113.219:6379 ESTABLISHED off (0.00/0/0)
           

其中 172.24.7.34 是業務 pod 的 ip,10.96.113.219 是 redis 的 K8s service ip,連接配接是 ESTABLISHED 狀态,說明連接配接沒有斷。

繼續排查 Redis 的 pod 是否正常:

redis-shareredis-0 2/2 Running 0
redis-shareredis-1 2/2 Running 0
redis-shareredis-sentinel-5f7458cd89-7dwpz 2/2 Running 0
redis-shareredis-sentinel-5f7458cd89-rrfz7 2/2 Running 0
redis-shareredis-sentinel-5f7458cd89-xzpmb 2/2 Running 0
           

無論是讀寫節點還是哨兵節點,都沒有重新開機過。

既然報了隻讀節點的異常,索性看下 redis 節點的讀寫角色情況。

root@redis-shareredis-0:/data# redis-cli -h 172.24.1.95 -a xxxx role
1) "slave"
2) "172.24.1.96"
3) (integer) 6379
4) "connected"
5) (integer) 6942040980
root@redis-shareredis-0:/data# redis-cli -h 172.24.1.96 -a xxxx role
1) "master"
2) (integer) 6942173072
3) 1) 1) "172.24.1.95"
 2) "6379"
 3) "6942173072"
           

可以看到此時 redis-shareredis-0(172.24.1.95)是 slave 節點,redis-shareredis-1(172.24.1.96)是 master 節點。

排查到這裡,猜測是業務 pod 實際通過 K8s service 連到了 slave 節點。進入 slave 确認這一資訊,發現果然如此,并且 master 節點并沒有檢查到有該業務 pod 的連接配接

root@redis-shareredis-0:/data# netstat -ano | grep 172.24.7.34:44602
tcp 0 0 172.24.1.95:6379 172.24.7.34:44602 ESTABLISHED keepalive (24.09/0/0)
           

懷疑是某個時刻開始,master 和 slave 角色發生了互換,而主從切換過程中由于 pod 沒有重新開機,長連接配接會一直保留着,此時即使 Redis service 的 endpoint 被修正,也不會影響到已有的連接配接。

記一次 Redis 連接配接問題排查

為了驗證上述猜想,着手排查 Redis server 節點和 sentinel 節點。

檢視 Redis 哨兵日志:

1:X 03 Feb 2023 06:21:41.357 * +slave slave 172.24.1.96:6379 172.24.1.96 6379 @ mymaster 172.24.1.95 6379
1:X 14 Feb 2023 06:53:27.683 # +reset-master master mymaster 172.24.1.96 6379
1:X 14 Feb 2023 06:53:28.692 * +slave slave 172.24.1.95:6379 172.24.1.95 6379 @ mymaster 172.24.1.96 6379
1:X 14 Feb 2023 06:53:33.271 # +reset-master master mymaster 172.24.1.96 6379
           

可以看到在 2023/2/14 14:53 (時區+8)時發生了主從切換。

嘗試排查主從切換的原因,進到 redis-0 檢視日志:

1:M 14 Feb 2023 14:53:27.343 # Connection with replica 172.24.1.96:6379 lost.
1:S 14 Feb 2023 14:53:27.616 * Before turning into a replica, using my master parameters to synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer.
1:S 14 Feb 2023 14:53:27.616 * REPLICAOF 172.24.1.96:6379 enabled (user request from 'id=1238496 addr=172.24.1.91:49388 fd=7 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=45 qbuf-free=32723 obl=0 oll=0 omem=0 events=r cmd=slaveof')
1:S 14 Feb 2023 14:53:27.646 * REPLICAOF would result into synchronization with the master we are already connected with. No operation performed.
1:S 14 Feb 2023 14:53:27.670 * REPLICAOF would result into synchronization with the master we are already connected with. No operation performed.
1:S 14 Feb 2023 14:53:28.076 * Connecting to MASTER 172.24.1.96:6379
1:S 14 Feb 2023 14:53:28.076 * MASTER <-> REPLICA sync started
1:S 14 Feb 2023 14:53:28.076 * Non blocking connect for SYNC fired the event.
1:S 14 Feb 2023 14:53:28.076 * Master replied to PING, replication can continue...
1:S 14 Feb 2023 14:53:28.077 * Trying a partial resynchronization (request 816c44412b9008e6969b2fef6401a6cef85fff87:6901666283).
1:S 14 Feb 2023 14:53:28.081 * Full resync from master: 86aa2f4759f73114594586e2e7d2cfbdd1ed2b69:6901664978
1:S 14 Feb 2023 14:53:28.081 * Discarding previously cached master state.
1:S 14 Feb 2023 14:53:28.140 * MASTER <-> REPLICA sync: receiving 1117094 bytes from master
1:S 14 Feb 2023 14:53:28.144 * MASTER <-> REPLICA sync: Flushing old data
1:S 14 Feb 2023 14:53:28.157 * MASTER <-> REPLICA sync: Loading DB in memory
1:S 14 Feb 2023 14:53:28.234 * MASTER <-> REPLICA sync: Finished with success
           

從日志分析是主從同步時出現了網絡分區,導緻哨兵進行重新選主,但為什麼出現網絡分區,就無從得知了,K8s 中兩個 pod 之間的通信都能出現 Connection lost 的确挺詭異的。

到這裡,問題的根源基本定位清楚了。

問題複盤

無論 Redis 的主從切換是故意的還是不小心,都應當被當做是一個常态,程式需要相容這類場景。反映出兩個問題:

  • 問題一,Redis 使用了哨兵機制,程式應當首選通過哨兵連接配接 Redis
  • 問題二,Lettuce 用戶端沒有自動斷開錯誤的連接配接

那麼改進思路自然是有兩種,一是改用哨兵連接配接 Redis,二是替換掉 Lettuce。對于本文遇到的問題,方案一可能可以,但不能確定沒有其他極端情況導緻其他連接配接問題,是以我實際采用的是方案二,使用 Jedis 替換掉 Lettuce。

項目一開始采用 Lettuce,主要是因為 spring-boot-data-redis 預設采用了 Lettuce 的實作,盡管我一開始已經留意到搜尋引擎中諸多關于 Lettuce 的問題,但實際測試發現,高版本 Lettuce 基本均已修複了這些問題,忽略了特殊場景下其可能存在的風險。簡單對比下 Jedis 和 Lettuce:

  • Lettuce:
    • Lettuce 用戶端沒有連接配接保活探測,錯誤連接配接存在連接配接池中會造成請求逾時報錯。
    • Lettuce 用戶端未實作 testOnBorrow 等連接配接池檢測方法,無法在使用連接配接之前進行連接配接校驗。
  • Jedis:
    • Jedis 用戶端實作了 testOnBorrow、testWhileIdle、testOnReturn 等連接配接池校驗配置。

      開啟 testOnBorrow 在每次借用連接配接前都會進行連接配接校驗,可靠性最高,但是會影響性能(每次 Redis 請求前會進行探測)。

    • testWhileIdle 可以在連接配接空閑時進行連接配接檢測,合理配置門檻值可以及時剔除連接配接池中的異常連接配接,防止使用異常連接配接造成業務報錯。
    • 在空閑連接配接檢測之前,連接配接出現問題,可能會造成使用該連接配接的業務報錯,此處可以通過參數控制檢測間隔(timeBetweenEvictionRunsMillis)。

是以,Jedis 用戶端在面對連接配接異常,網絡抖動等場景下的異常處理和檢測能力明顯強于 Lettuce,可靠性更強。

參數 配置介紹 配置建議
maxTotal 最大連接配接,機關:個 根據Web容器的Http線程數來進行配置,估算單個Http請求中可能會并行進行的Redis調用次數,例如:Tomcat中的Connector内的maxConnections配置為150,每個Http請求可能會并行執行2個Redis請求,在此之上進行部分預留,則建議配置至少為:150 x 2 + 100= 400限制條件:單個Redis執行個體的最大連接配接數。maxTotal和用戶端節點數(CCE容器或業務VM數量)數值的乘積要小于單個Redis執行個體的最大連接配接數。例如:Redis主備執行個體配置maxClients為10000,單個用戶端maxTotal配置為500,則最大用戶端節點數量為20個。
maxIdle 最大空閑連接配接,機關:個 建議配置為maxTotal一緻。
minIdle 最小空閑連接配接,機關:個 一般來說建議配置為maxTotal的X分之一,例如此處正常配置建議為:100。對于性能敏感的場景,防止經常連接配接數量抖動造成影響,也可以配置為與maxIdle一緻,例如:400。
maxWaitMillis 最大擷取連接配接等待時間,機關:毫秒 擷取連接配接時最大的連接配接池等待時間,根據單次業務最長容忍的失敗時間減去執行指令的逾時時間得到建議值。例如:Http最大容忍逾時時間為15s,Redis請求的timeout設定為10s,則此處可以配置為5s。
timeout 指令執行逾時時間,機關:毫秒 單次執行Redis指令最大可容忍的逾時時間,根據業務程式的邏輯進行選擇,一般來說處于對網絡容錯等考慮至少建議配置為210ms以上。特殊的探測邏輯或者環境異常檢測等,可以适當調整達到秒級。
minEvictableIdleTimeMillis 空閑連接配接逐出時間,大于該值的空閑連接配接一直未被使用則會被釋放,機關:毫秒 如果希望系統不會經常對連接配接進行斷鍊重建,此處可以配置一個較大值(xx分鐘),或者此處配置為-1并且搭配空閑連接配接檢測進行定期檢測。
timeBetweenEvictionRunsMillis 空閑連接配接探測時間間隔,機關:毫秒 根據系統的空閑連接配接數量進行估算,例如系統的空閑連接配接探測時間配置為30s,則代表每隔30s會對連接配接進行探測,如果30s内發生異常的連接配接,經過探測後會進行連接配接排除。根據連接配接數的多少進行配置,如果連接配接數太大,配置時間太短,會造成請求資源浪費。對于幾百級别的連接配接,正常來說建議配置為30s,可以根據系統需要進行動态調整。
testOnBorrow 向資源池借用連接配接時是否做連接配接有效性檢測(ping),檢測到的無效連接配接将會被移除。 對于業務連接配接極端敏感的,并且性能可以接受的情況下,可以配置為True,一般來說建議配置為False,啟用連接配接空閑檢測。
testWhileIdle 是否在空閑資源監測時通過ping指令監測連接配接有效性,無效連接配接将被銷毀。 True
testOnReturn 向資源池歸還連接配接時是否做連接配接有效性檢測(ping),檢測到無效連接配接将會被移除。 False
maxAttempts 在JedisCluster模式下,您可以配置maxAttempts參數來定義失敗時的重試次數。 建議配置3-5之間,預設配置為5。根據業務接口最大逾時時間和單次請求的timeout綜合配置,最大配置不建議超過10,否則會造成單次請求處理時間過長,接口請求阻塞。

再次回到本次案例,如果使用了 Jedis,并且配置了合理的連接配接池政策,可能仍然會存在問題,因為 Jedis 底層檢測連接配接是否可用,使用的是 ping 指令,當連接配接到隻讀節點,ping 指令仍然可以工作,是以實際上連接配接檢查機制并不能解決本案例的問題。

但 Jedis 提供了一個 minEvictableIdleTimeMillis 參數,該參數表示一個連接配接至少停留在 idle 狀态的最短時間,然後才能被 idle object evitor 掃描并驅逐,該參數會受到 minIdle 的影響,驅逐到 minIdle 的數量。也就意味着:預設配置 minEvictableIdleTimeMillis=60s,minIdle=0 下,連接配接在空閑時間達到 60s 時,将會被釋放。由于實際的業務場景 Redis 讀寫空閑達到 60s 的場景是很常見的,是以該方案勉強可以達到在主從切換之後,在較短時間内恢複。但如果 minIdle > 0,這些連接配接依舊會有問題。而 Lettuce 預設配置下,連接配接會一直存在。

出于一些不可描述的原因,我無法将應用連接配接 Redis 的模式切換成哨兵模式,是以最終采取了切換到 Jedis 用戶端,并且配置 minIdle=0、minEvictableIdleTimeMillis=60s 的方案。

問題總結

當使用域名/K8s Service 連接配接 Redis 叢集時,需要考慮主從切換時可能存在的問題。Redis 通常使用長連接配接通信,主從切換時如果連接配接不斷開,會導緻無法進行寫入操作。可以在用戶端、服務端兩個層面規避這一問題,以下是一些行之有效的方案:

  • 用戶端連接配接哨兵叢集,哨兵會感覺到主從切換,并推送給用戶端這一變化
  • 用戶端配置 minIdle=0,及時斷開空閑的連接配接,可以一定程度規避連接配接已經不可用但健康檢測又檢查不出來的場景。(即本文的場景)
  • 服務端主從切換時斷開所有已有的連接配接,依靠用戶端的健康檢測以及重連等機制,確定連接配接到正确的節點。

Redis 用戶端推薦使用 Jedis 用戶端,其在面對連接配接異常,網絡抖動等場景下的異常處理和檢測能力明顯強于 Lettuce。

繼續閱讀