作者:任坤

现居珠海,先后担任专职 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 后该问题得到解决。


avatar
100
  Subscribe  
提醒