故障分析 | redis cluster 从库无法自动恢复同步案例一则

时间：2023-02-17 15:13:24

作者：任坤

现居珠海，先后担任专职 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#  #连接超时#

相关文章