記一次 Redis 連接問題排查

作者：kiritomoe 2023-04-06 07:53:56

Redis 和業(yè)務(wù)應(yīng)用部署在同一個 K8s 集群中，Redis Server 暴露了一個 redis-service，指向到 master 節(jié)點(diǎn)，業(yè)務(wù)應(yīng)用通過 redis-service 連接 Redis。

問題發(fā)現(xiàn)

客戶端：業(yè)務(wù)應(yīng)用使用 lettuce 客戶端

服務(wù)端：Redis server 部署架構(gòu)采用 1 主 + 1 從 + 3 哨兵

某個時刻起，開始發(fā)現(xiàn)業(yè)務(wù)報(bào)錯，稍加定位，發(fā)現(xiàn)是 Redis 訪問出了問題，搜索業(yè)務(wù)應(yīng)用日志，發(fā)現(xiàn)關(guān)鍵信息：

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 訪問的報(bào)錯，看起來跟 Redis 的讀寫配置有關(guān)。

問題定位

首先排查下業(yè)務(wù)應(yīng)用和 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 是業(yè)務(wù) pod 的 ip，10.96.113.219 是 redis 的 K8s service ip，連接是 ESTABLISHED 狀態(tài)，說明連接沒有斷。

繼續(xù)排查 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

無論是讀寫節(jié)點(diǎn)還是哨兵節(jié)點(diǎn)，都沒有重啟過。

既然報(bào)了只讀節(jié)點(diǎn)的異常，索性看下 redis 節(jié)點(diǎn)的讀寫角色情況。

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 節(jié)點(diǎn)，redis-shareredis-1（172.24.1.96）是 master 節(jié)點(diǎn)。

排查到這里，猜測是業(yè)務(wù) pod 實(shí)際通過 K8s service 連到了 slave 節(jié)點(diǎn)。進(jìn)入 slave 確認(rèn)這一信息，發(fā)現(xiàn)果然如此，并且 master 節(jié)點(diǎn)并沒有檢查到有該業(yè)務(wù) 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 角色發(fā)生了互換，而主從切換過程中由于 pod 沒有重啟，長連接會一直保留著，此時即使 Redis service 的 endpoint 被修正，也不會影響到已有的連接。

為了驗(yàn)證上述猜想，著手排查 Redis server 節(jié)點(diǎn)和 sentinel 節(jié)點(diǎn)。

查看 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 (時區(qū)+8)時發(fā)生了主從切換。

嘗試排查主從切換的原因，進(jìn)到 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

從日志分析是主從同步時出現(xiàn)了網(wǎng)絡(luò)分區(qū)，導(dǎo)致哨兵進(jìn)行重新選主，但為什么出現(xiàn)網(wǎng)絡(luò)分區(qū)，就無從得知了，K8s 中兩個 pod 之間的通信都能出現(xiàn) Connection lost 的確挺詭異的。

到這里，問題的根源基本定位清楚了。

問題復(fù)盤

無論 Redis 的主從切換是故意的還是不小心，都應(yīng)當(dāng)被當(dāng)做是一個常態(tài)，程序需要兼容這類場景。反映出兩個問題：

問題一，Redis 使用了哨兵機(jī)制，程序應(yīng)當(dāng)首選通過哨兵連接 Redis
問題二，Lettuce 客戶端沒有自動斷開錯誤的連接

那么改進(jìn)思路自然是有兩種，一是改用哨兵連接 Redis，二是替換掉 Lettuce。對于本文遇到的問題，方案一可能可以，但不能確保沒有其他極端情況導(dǎo)致其他連接問題，所以我實(shí)際采用的是方案二，使用 Jedis 替換掉 Lettuce。

項(xiàng)目一開始采用 Lettuce，主要是因?yàn)?spring-boot-data-redis 默認(rèn)采用了 Lettuce 的實(shí)現(xiàn)，盡管我一開始已經(jīng)留意到搜索引擎中諸多關(guān)于 Lettuce 的問題，但實(shí)際測試發(fā)現(xiàn)，高版本 Lettuce 基本均已修復(fù)了這些問題，忽略了特殊場景下其可能存在的風(fēng)險。簡單對比下 Jedis 和 Lettuce:

Lettuce：

Lettuce 客戶端沒有連接保活探測，錯誤連接存在連接池中會造成請求超時報(bào)錯。
Lettuce 客戶端未實(shí)現(xiàn) testOnBorrow 等連接池檢測方法，無法在使用連接之前進(jìn)行連接校驗(yàn)。

Jedis：
Jedis 客戶端實(shí)現(xiàn)了 testOnBorrow、testWhileIdle、testOnReturn 等連接池校驗(yàn)配置。
開啟 testOnBorrow 在每次借用連接前都會進(jìn)行連接校驗(yàn)，可靠性最高，但是會影響性能（每次 Redis 請求前會進(jìn)行探測）。
testWhileIdle 可以在連接空閑時進(jìn)行連接檢測，合理配置閾值可以及時剔除連接池中的異常連接，防止使用異常連接造成業(yè)務(wù)報(bào)錯。
在空閑連接檢測之前，連接出現(xiàn)問題，可能會造成使用該連接的業(yè)務(wù)報(bào)錯，此處可以通過參數(shù)控制檢測間隔（timeBetweenEvictionRunsMillis）。

因此，Jedis 客戶端在面對連接異常，網(wǎng)絡(luò)抖動等場景下的異常處理和檢測能力明顯強(qiáng)于 Lettuce，可靠性更強(qiáng)。

參數(shù)	配置介紹	配置建議
maxTotal	最大連接，單位：個	根據(jù)Web容器的Http線程數(shù)來進(jìn)行配置，估算單個Http請求中可能會并行進(jìn)行的Redis調(diào)用次數(shù)，例如：Tomcat中的Connector內(nèi)的maxConnections配置為150，每個Http請求可能會并行執(zhí)行2個Redis請求，在此之上進(jìn)行部分預(yù)留，則建議配置至少為：150 x 2 + 100= 400限制條件：單個Redis實(shí)例的最大連接數(shù)。maxTotal和客戶端節(jié)點(diǎn)數(shù)（CCE容器或業(yè)務(wù)VM數(shù)量）數(shù)值的乘積要小于單個Redis實(shí)例的最大連接數(shù)。例如：Redis主備實(shí)例配置maxClients為10000，單個客戶端maxTotal配置為500，則最大客戶端節(jié)點(diǎn)數(shù)量為20個。
maxIdle	最大空閑連接，單位：個	建議配置為maxTotal一致。
minIdle	最小空閑連接，單位：個	一般來說建議配置為maxTotal的X分之一，例如此處常規(guī)配置建議為：100。對于性能敏感的場景，防止經(jīng)常連接數(shù)量抖動造成影響，也可以配置為與maxIdle一致，例如：400。
maxWaitMillis	最大獲取連接等待時間，單位：毫秒	獲取連接時最大的連接池等待時間，根據(jù)單次業(yè)務(wù)最長容忍的失敗時間減去執(zhí)行命令的超時時間得到建議值。例如：Http最大容忍超時時間為15s，Redis請求的timeout設(shè)置為10s，則此處可以配置為5s。
timeout	命令執(zhí)行超時時間，單位：毫秒	單次執(zhí)行Redis命令最大可容忍的超時時間，根據(jù)業(yè)務(wù)程序的邏輯進(jìn)行選擇，一般來說處于對網(wǎng)絡(luò)容錯等考慮至少建議配置為210ms以上。特殊的探測邏輯或者環(huán)境異常檢測等，可以適當(dāng)調(diào)整達(dá)到秒級。
minEvictableIdleTimeMillis	空閑連接逐出時間，大于該值的空閑連接一直未被使用則會被釋放，單位：毫秒	如果希望系統(tǒng)不會經(jīng)常對連接進(jìn)行斷鏈重建，此處可以配置一個較大值（xx分鐘），或者此處配置為-1并且搭配空閑連接檢測進(jìn)行定期檢測。
timeBetweenEvictionRunsMillis	空閑連接探測時間間隔，單位：毫秒	根據(jù)系統(tǒng)的空閑連接數(shù)量進(jìn)行估算，例如系統(tǒng)的空閑連接探測時間配置為30s，則代表每隔30s會對連接進(jìn)行探測，如果30s內(nèi)發(fā)生異常的連接，經(jīng)過探測后會進(jìn)行連接排除。根據(jù)連接數(shù)的多少進(jìn)行配置，如果連接數(shù)太大，配置時間太短，會造成請求資源浪費(fèi)。對于幾百級別的連接，常規(guī)來說建議配置為30s，可以根據(jù)系統(tǒng)需要進(jìn)行動態(tài)調(diào)整。
testOnBorrow	向資源池借用連接時是否做連接有效性檢測（ping），檢測到的無效連接將會被移除。	對于業(yè)務(wù)連接極端敏感的，并且性能可以接受的情況下，可以配置為True，一般來說建議配置為False，啟用連接空閑檢測。
testWhileIdle	是否在空閑資源監(jiān)測時通過ping命令監(jiān)測連接有效性，無效連接將被銷毀。	True
testOnReturn	向資源池歸還連接時是否做連接有效性檢測（ping），檢測到無效連接將會被移除。	False
maxAttempts	在JedisCluster模式下，您可以配置maxAttempts參數(shù)來定義失敗時的重試次數(shù)。	建議配置3-5之間，默認(rèn)配置為5。根據(jù)業(yè)務(wù)接口最大超時時間和單次請求的timeout綜合配置，最大配置不建議超過10，否則會造成單次請求處理時間過長，接口請求阻塞。

再次回到本次案例，如果使用了 Jedis，并且配置了合理的連接池策略，可能仍然會存在問題，因?yàn)?Jedis 底層檢測連接是否可用，使用的是 ping 命令，當(dāng)連接到只讀節(jié)點(diǎn)，ping 命令仍然可以工作，所以實(shí)際上連接檢查機(jī)制并不能解決本案例的問題。

但 Jedis 提供了一個 minEvictableIdleTimeMillis 參數(shù)，該參數(shù)表示一個連接至少停留在 idle 狀態(tài)的最短時間，然后才能被 idle object evitor 掃描并驅(qū)逐，該參數(shù)會受到 minIdle 的影響，驅(qū)逐到 minIdle 的數(shù)量。也就意味著：默認(rèn)配置 minEvictableIdleTimeMillis=60s，minIdle=0 下，連接在空閑時間達(dá)到 60s 時，將會被釋放。由于實(shí)際的業(yè)務(wù)場景 Redis 讀寫空閑達(dá)到 60s 的場景是很常見的，所以該方案勉強(qiáng)可以達(dá)到在主從切換之后，在較短時間內(nèi)恢復(fù)。但如果 minIdle > 0，這些連接依舊會有問題。而 Lettuce 默認(rèn)配置下，連接會一直存在。

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