乐趣区

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

作者:任坤

现居珠海,先后负责专职 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 172.18.2.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 后该问题失去解决。

退出移动版