故障分析 | redis cluster 從庫無法自動恢復同步案例一則

碼農談IT發表於2023-02-17
Redis

作者：任坤

現居珠海，先後擔任專職 Oracle 和 MySQL DBA，現在主要負責 MySQL、mongoDB 和 Redis 維護工作。

本文來源：原創投稿

* 愛可生開源社群出品，原創內容未經授權不得隨意使用，轉載請聯絡小編並註明來源。

背景

線上有一套6節點 redis cluster ，6分片 * 2副本，每個節點上2個例項，埠號分別為7000和7001。

臘月29凌晨，有個節點硬體故障導致自動重啟，重啟後該節點上的例項變成從庫，卻遲遲無法完成和新主庫的同步進而觸發報警。
redis 版本為5.0。

診斷

登入該節點，檢視 redis 的日誌

22996:S 20 Jan 2023 07:27:15.091 * Connecting to MASTER x.x.x.46:7001
22996:S 20 Jan 2023 07:27:15.091 * MASTER <‐> REPLICA sync started
22996:S 20 Jan 2023 07:27:15.106 * Non blocking connect for SYNC fired the event.
22996:S 20 Jan 2023 07:27:15.106 * Master replied to PING, replication can continue...
22996:S 20 Jan 2023 07:27:15.106 * Trying a partial resynchronization (request 174e5c92c731090d3c9a05f6364ffff5a70e61d9:7180528579709).
22996:S 20 Jan 2023 07:35:29.263 * Full resync from master: 174e5c92c731090d3c9a05f6364ffff5a70e61d9:7180734380451
22996:S 20 Jan 2023 07:35:29.263 * Discarding previously cached master state.
22996:S 20 Jan 2023 07:44:47.717 * MASTER <‐> REPLICA sync: receiving 22930214160 bytes from master

例項啟動後和主庫進行連線，先嚐試 partial resync 失敗，後進行 full resync

22996:S 20 Jan 2023 07:48:07.305 * MASTER <‐> REPLICA sync: Flushing old data
22996:S 20 Jan 2023 07:53:24.576 * MASTER <‐> REPLICA sync: Loading DB in memory
22996:S 20 Jan 2023 07:59:59.491 * MASTER <‐> REPLICA sync: Finished with success

耗時11分鐘完成舊資料清理和新 rdb 載入，此時卻發現和主庫的連線中斷

22996:S 20 Jan 2023 07:59:59.521 # Connection with master lost.
22996:S 20 Jan 2023 07:59:59.521 * Caching the disconnected master state.

於是乎又發起和主庫的連線

22996:S 20 Jan 2023 08:00:00.404 * Connecting to MASTER x.x.x.46:7001
22996:S 20 Jan 2023 08:00:00.404 * MASTER <‐> REPLICA sync started
22996:S 20 Jan 2023 08:00:00.405 * Non blocking connect for SYNC fired the event.
22996:S 20 Jan 2023 08:00:00.406 * Master replied to PING, replication can continue...
22996:S 20 Jan 2023 08:00:00.408 * Trying a partial resynchronization (request 174e5c92c731090d3c9a05f6364ffff5a70e61d9:7180736029100).
22996:S 20 Jan 2023 08:08:21.849 * Full resync from master: 174e5c92c731090d3c9a05f6364ffff5a70e61d9:7180922115631
此時從庫陷入了1個死迴圈：全量同步 -- 清除舊資料 & 載入 RDB -- 和主庫連線中斷，此次同步作廢，從頭開始。

有2個疑問：

Q1：從庫的 partial resync 為何失敗?
Q2：從庫的 full resync 最後為何會遭遇 Connection with master lost ?

檢視主庫日誌，每9分鐘發起1次 bgsave ，每次 bgsave 期間新產生的記憶體有2600M之多，repl-backlog-size 預設只有100M，而從庫節點從當機到完成啟動耗時大約15分鐘，此時緩衝區中的複製位點早被覆蓋，難怪 partial resync 會失敗。

38241:C 20 Jan 2023 07:35:25.836 * DB saved on disk
38241:C 20 Jan 2023 07:35:26.552 * RDB: 2663 MB of memory used by copy‐on‐write
40362:M 20 Jan 2023 07:35:27.950 * Background saving terminated with success
40362:M 20 Jan 2023 07:35:27.950 * Starting BGSAVE for SYNC with target:disk
40362:M 20 Jan 2023 07:35:29.263 * Background saving started by pid 11680
11680:C 20 Jan 2023 07:44:44.585 * DB saved on disk
11680:C 20 Jan 2023 07:44:45.811 * RDB: 2681 MB of memory used by copy‐on‐write

繼續看日誌，

40362:M 20 Jan 2023 07:48:03.104 * Synchronization with replica x.x.x.45:7000 succeeded
40362:M 20 Jan 2023 07:48:17.100 * FAIL message received from 8e2a54fbaac768a5cc0e717f4aa93c6be8683ffe about ccb7589e3240bc95557ffb282435afd5dc13e4c9
40362:M 20 Jan 2023 07:50:17.109 # Disconnecting timedout replica:x.x.x.45:7000
40362:M 20 Jan 2023 07:50:17.109 # Connection with replica x.x.x.45:7000 lost.
40362:M 20 Jan 2023 07:53:26.114 * Clear FAIL state for node ccb7589e3240bc95557ffb282435afd5dc13e4c9: replica is reachable again.
40362:M 20 Jan 2023 08:00:00.408 * Replica x.x.x.45:7000 asks for sync hronization
梳理一下時間線：
07:48:03 主庫將全量 RDB 成功傳送到從庫；
07:48:07 從庫清理舊資料，期間 redis 全程阻塞無法響應，10多秒後 cluser 檢測到並在主庫日誌記錄 FAIL message ，這是 cluster-node-timeout 超時導致的，該引數為10000即10s；
07:50:17 主庫檢測到從庫連線超時並主動斷開連線；
07:53:24 從庫完成舊資料清理，開始載入新 RDB ，此時 redis 可以登入並執行命令，cluster 重新認定了這一對主從關係，但此時從庫的 master_link_status 仍然是 down ；
07:59:59 從庫完成了新 RDB 載入，此時才想起和主庫打招呼，然而主庫在9分鐘前就斷開了連線，於是一切從頭開始。
這套 redis 叢集寫操作非常活躍，且例項記憶體佔用很大(1個例項超過40G)，前者導致用於增量同步的 repl-backlog-size 有效期很短，後者導致全量同步耗時過長進而觸發主從連線超時。

解決方案

1、增大 repl-backlog-size ，大多數場景預設100M已經夠用，這套環境是個特例，該引數設定過大會導致 OS 可用記憶體變少，有可能會觸發 OOM ，因此暫不考慮；
2、增大 repl-timeout 引數，從60調大到1200，確保大於1次全量同步的時長；
3、對 redis 進行瘦身，儘量確保每個例項不超過10G，這個需要開發人員配合。
暫時選擇了方案2，調大 repl-timeout 後該問題得到解決。

本文關鍵字：#repl-timeout#  #連線超時#

來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/70024924/viewspace-2935742/，如需轉載，請註明出處，否則將追究法律責任。

相關文章