redis cluster 全部宕机后重启会自动恢复集群状态

蔚落 2022-05-21 07:37 793阅读 0赞

昨天 测试环境上3主3从的redis节点集群 虚拟机3台全部宕机

(3主3从交叉部署在3台虚机上)

重新启动各个节点发现  集群自动恢复了  本来以为要重新使用create  命令

猜测集群是根据node的主从信息文件自己恢复的 利用心跳检测

节点关系的文件node-7001.conf

197d2e50893487f54d3cbbf07f746abc1fa08318 10.166.15.36:7001@17001 master - 0 1530527218141 2 connected 5461-10922
    052b9df159281988af20d8b5d0690e5defa42c47 10.166.15.37:7002@17002 slave 197d2e50893487f54d3cbbf07f746abc1fa08318 0 1530527220145 4 connected
    ad20d73e76c72579be410a458c74bde554bf85bc 10.166.15.36:7002@17002 master - 0 1530527218000 7 connected 0-5460
    6d6f6fbeff41f5a85a7a7ebe15565a448fb0a69f 10.166.15.37:7001@17001 slave ad20d73e76c72579be410a458c74bde554bf85bc 0 1530527220431 7 connected
    b98f368b250360dbb4d74a1b831d7fa939ea4f8d 10.166.15.35:7001@17001 myself,slave 1e7a4a6b7376a89726211ce04acdaf97afbe2f13 0 1530527217000 1 connected
    1e7a4a6b7376a89726211ce04acdaf97afbe2f13 10.166.15.35:7002@17002 master - 0 1530527219143 8 connected 10923-16383
    vars currentEpoch 8 lastVoteEpoch 7

**对于日志的分析**

**1 查看了 一个slave节点10.166.15.35:7001的异常断电重新启动日志信息如下**

4446:M 02 Jul 18:07:55.091 \* Node configuration loaded, I'm b98f368b250360dbb4d74a1b831d7fa939ea4f8d  
                \_.\_                                                    
           \_.-\`\`\_\_ ''-.\_                                               
      \_.-\`\`    \`.  \`\_.  ''-.\_           Redis 4.0.6 (00000000/0) 64 bit  
  .-\`\` .-\`\`\`.  \`\`\`\\/    \_.,\_ ''-.\_                                     
 (    '      ,       .-\`  | \`,    )     Running in cluster mode  
 |\`-.\_\`-...-\` \_\_...-.\`\`-.\_|'\` \_.-'|     Port: 7001  
 |    \`-.\_   \`.\_    /     \_.-'    |     PID: 4446  
  \`-.\_    \`-.\_  \`-./  \_.-'    \_.-'                                     
 |\`-.\_\`-.\_    \`-.\_\_.-'    \_.-'\_.-'|                                    
 |    \`-.\_\`-.\_        \_.-'\_.-'    |           http://redis.io          
  \`-.\_    \`-.\_\`-.\_\_.-'\_.-'    \_.-'                                     
 |\`-.\_\`-.\_    \`-.\_\_.-'    \_.-'\_.-'|                                    
 |    \`-.\_\`-.\_        \_.-'\_.-'    |                                    
  \`-.\_    \`-.\_\`-.\_\_.-'\_.-'    \_.-'                                     
      \`-.\_    \`-.\_\_.-'    \_.-'                                         
          \`-.\_        \_.-'                                             
              \`-.\_\_.-'                                                 
  
  
4446:M 02 Jul 18:07:55.092 \# Server initialized  
4446:M 02 Jul 18:07:55.092 \# WARNING overcommit\_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit\_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit\_memory=1' for this to take effect.  
4446:M 02 Jul 18:07:55.092 \# WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent\_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.  
4446:M 02 Jul 18:07:55.716 \* DB loaded from append only file: 0.624 seconds  
4446:M 02 Jul 18:07:55.716 \* Ready to accept connections  
4446:S 02 Jul 18:07:55.717 \* Before turning into a slave, using my master parameters to synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer.  
4446:S 02 Jul 18:07:55.717 \# Cluster state changed: ok  
4446:S 02 Jul 18:07:56.720 \* Connecting to MASTER 10.166.15.35:7002  ---ps:说明本slave节点是10.166.15.35:7001 这里开始链接master  
4446:S 02 Jul 18:07:56.720 \* MASTER <-> SLAVE sync started  
4446:S 02 Jul 18:07:56.720 \* Non blocking connect for SYNC fired the event.  
4446:S 02 Jul 18:07:56.720 \* Master replied to PING, replication can continue...  
4446:S 02 Jul 18:07:56.721 \* Trying a partial resynchronization (request eda94ebd6d85f2f9dfb8337358ab14bdaee896bd:1).  
4446:S 02 Jul 18:07:56.723 \* Full resync from master: 79be914765bfde6e102bfae1b106847c8dcaea36:0  
4446:S 02 Jul 18:07:56.723 \* Discarding previously cached master state.  
4446:S 02 Jul 18:07:56.772 \* MASTER <-> SLAVE sync: receiving 318259 bytes from master  
4446:S 02 Jul 18:07:56.773 \* MASTER <-> SLAVE sync: Flushing old data  
4446:S 02 Jul 18:07:56.776 \* MASTER <-> SLAVE sync: Loading DB in memory  
4446:S 02 Jul 18:07:56.784 \* MASTER <-> SLAVE sync: Finished with success  
4446:S 02 Jul 18:07:56.785 \* Background append only file rewriting started by pid 4451  
4446:S 02 Jul 18:07:56.812 \* AOF rewrite child asks to stop sending diffs.  
4451:C 02 Jul 18:07:56.812 \* Parent agreed to stop sending diffs. Finalizing AOF...  
4451:C 02 Jul 18:07:56.812 \* Concatenating 0.00 MB of AOF diff received from parent.  
4451:C 02 Jul 18:07:56.812 \* SYNC append only file rewrite performed  
4451:C 02 Jul 18:07:56.812 \* AOF rewrite: 6 MB of memory used by copy-on-write  
4446:S 02 Jul 18:07:56.820 \* Background AOF rewrite terminated with success  
4446:S 02 Jul 18:07:56.820 \* Residual parent diff successfully flushed to the rewritten AOF (0.00 MB)  
4446:S 02 Jul 18:07:56.820 \* Background AOF rewrite finished successfully  
4446:S 02 Jul 18:08:10.776 \# Cluster state changed: fail  
4446:S 02 Jul 18:08:13.650 \# Cluster state changed: ok

4446:S 02 Jul 18:08:29.586 \* FAIL message received from 1e7a4a6b7376a89726211ce04acdaf97afbe2f13 about 052b9df159281988af20d8b5d0690e5defa42c47

说明:1e7a4a6b7376a89726211ce04acdaf97afbe2f13  就是10.166.15.35：7002

4446:S 02 Jul 18:08:29.586 \* FAIL message received from 1e7a4a6b7376a89726211ce04acdaf97afbe2f13 about 6d6f6fbeff41f5a85a7a7ebe15565a448fb0a69f  
4446:S 02 Jul 18:08:56.087 \* 10000 changes in 60 seconds. Saving...  
4446:S 02 Jul 18:08:56.088 \* Background saving started by pid 4472  
4472:C 02 Jul 18:08:56.106 \* DB saved on disk  
4472:C 02 Jul 18:08:56.107 \* RDB: 6 MB of memory used by copy-on-write  
4446:S 02 Jul 18:08:56.188 \* Background saving terminated with success  
4446:S 02 Jul 18:26:56.159 \* Clear FAIL state for node 052b9df159281988af20d8b5d0690e5defa42c47: slave is reachable again.  
4446:S 02 Jul 18:27:00.431 \* Clear FAIL state for node 6d6f6fbeff41f5a85a7a7ebe15565a448fb0a69f: slave is reachable again.  
4446:S 02 Jul 18:27:11.969 \* 1 changes in 900 seconds. Saving...  
4446:S 02 Jul 18:27:11.971 \* Background saving started by pid 5248  
5248:C 02 Jul 18:27:11.995 \* DB saved on disk  
5248:C 02 Jul 18:27:11.996 \* RDB: 6 MB of memory used by copy-on-write  
4446:S 02 Jul 18:27:12.071 \* Background saving terminated with success  
4446:S 02 Jul 18:42:13.029 \* 1 changes in 900 seconds. Saving...  
4446:S 02 Jul 18:42:13.031 \* Background saving started by pid 6014  
6014:C 02 Jul 18:42:13.051 \* DB saved on disk  
6014:C 02 Jul 18:42:13.051 \* RDB: 8 MB of memory used by copy-on-write  
4446:S 02 Jul 18:42:13.134 \* Background saving terminated with success  
4446:S 02 Jul 19:21:15.352 \* 1 changes in 900 seconds. Saving...  
4446:S 02 Jul 19:21:15.354 \* Background saving started by pid 7287  
7287:C 02 Jul 19:21:15.363 \* DB saved on disk  
7287:C 02 Jul 19:21:15.363 \* RDB: 8 MB of memory used by copy-on-write  
4446:S 02 Jul 19:21:15.455 \* Background saving terminated with success  
4446:S 02 Jul 19:26:16.093 \* 10 changes in 300 seconds. Saving...  
4446:S 02 Jul 19:26:16.094 \* Background saving started by pid 7615  
7615:C 02 Jul 19:26:16.113 \* DB saved on disk  
7615:C 02 Jul 19:26:16.114 \* RDB: 8 MB of memory used by copy-on-write  
4446:S 02 Jul 19:26:16.197 \* Background saving terminated with success  
4446:S 02 Jul 19:41:17.032 \* 1 changes in 900 seconds. Saving...  
4446:S 02 Jul 19:41:17.033 \* Background saving started by pid 8074  
8074:C 02 Jul 19:41:17.055 \* DB saved on disk  
8074:C 02 Jul 19:41:17.055 \* RDB: 8 MB of memory used by copy-on-write  
4446:S 02 Jul 19:41:17.134 \* Background saving terminated with success  
4446:S 02 Jul 22:03:58.651 \* 1 changes in 900 seconds. Saving...  
4446:S 02 Jul 22:03:58.653 \* Background saving started by pid 13916  
13916:C 02 Jul 22:03:58.667 \* DB saved on disk  
13916:C 02 Jul 22:03:58.667 \* RDB: 8 MB of memory used by copy-on-write  
4446:S 02 Jul 22:03:58.754 \* Background saving terminated with success  
4446:S 03 Jul 00:14:43.282 \* 1 changes in 900 seconds. Saving...  
4446:S 03 Jul 00:14:43.284 \* Background saving started by pid 19046  
19046:C 03 Jul 00:14:43.307 \* DB saved on disk

2 给出1中slave节点对应的主节点10.166.15.35:7002的异常断电后重新启动信息

4440:C 02 Jul 18:07:51.105 \# oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo  
4440:C 02 Jul 18:07:51.109 \# Redis version=4.0.6, bits=64, commit=00000000, modified=0, pid=4440, just started  
4440:C 02 Jul 18:07:51.109 \# Configuration loaded  
4441:M 02 Jul 18:07:51.122 \* Node configuration loaded, I'm 1e7a4a6b7376a89726211ce04acdaf97afbe2f13  
                \_.\_                                                    
           \_.-\`\`\_\_ ''-.\_                                               
      \_.-\`\`    \`.  \`\_.  ''-.\_           Redis 4.0.6 (00000000/0) 64 bit  
  .-\`\` .-\`\`\`.  \`\`\`\\/    \_.,\_ ''-.\_                                     
 (    '      ,       .-\`  | \`,    )     Running in cluster mode  
 |\`-.\_\`-...-\` \_\_...-.\`\`-.\_|'\` \_.-'|     Port: 7002  
** **|    \`-.\_   \`.\_    /     \_.-'    |     PID: 4441  
  \`-.\_    \`-.\_  \`-./  \_.-'    \_.-'                                     
 |\`-.\_\`-.\_    \`-.\_\_.-'    \_.-'\_.-'|                                    
 |    \`-.\_\`-.\_        \_.-'\_.-'    |           http://redis.io          
  \`-.\_    \`-.\_\`-.\_\_.-'\_.-'    \_.-'                                     
 |\`-.\_\`-.\_    \`-.\_\_.-'    \_.-'\_.-'|                                    
 |    \`-.\_\`-.\_        \_.-'\_.-'    |                                    
  \`-.\_    \`-.\_\`-.\_\_.-'\_.-'    \_.-'                                     
      \`-.\_    \`-.\_\_.-'    \_.-'                                         
          \`-.\_        \_.-'                                             
              \`-.\_\_.-'                                                 
  
  
  
4441:M 02 Jul 18:07:51.127 \# Server initialized  
4441:M 02 Jul 18:07:51.127 \# WARNING overcommit\_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit\_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit\_memory=1' for this to take effect.  
4441:M 02 Jul 18:07:51.127 \# WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent\_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.  
4441:M 02 Jul 18:07:51.752 \* DB loaded from append only file: 0.625 seconds  
4441:M 02 Jul 18:07:51.752 \* Ready to accept connections  
4441:M 02 Jul 18:07:53.759 \# Cluster state changed: ok  
4441:M 02 Jul 18:07:56.721 \* Slave 10.166.15.35:7001 asks for synchronization  
4441:M 02 Jul 18:07:56.721 \* Partial resynchronization not accepted: Replication ID mismatch (Slave asked for 'eda94ebd6d85f2f9dfb8337358ab14bdaee896bd', my replication IDs are 'd64784b6f440cfc58eb490428541b43c1cc7eecf' and '0000000000000000000000000000000000000000')  
4441:M 02 Jul 18:07:56.721 \* Starting BGSAVE for SYNC with target: disk  
4441:M 02 Jul 18:07:56.722 \* Background saving started by pid 4450  
4450:C 02 Jul 18:07:56.740 \* DB saved on disk  
4450:C 02 Jul 18:07:56.741 \* RDB: 6 MB of memory used by copy-on-write  
4441:M 02 Jul 18:07:56.771 \* Background saving terminated with success  
4441:M 02 Jul 18:07:56.772 \* Synchronization with slave 10.166.15.35:7001 succeeded  
4441:M 02 Jul 18:08:06.807 \# Cluster state changed: fail  
4441:M 02 Jul 18:08:18.647 \# Cluster state changed: ok  
4441:M 02 Jul 18:08:29.585 \* Marking node 052b9df159281988af20d8b5d0690e5defa42c47 as failing (quorum reached).

4441:M 02 Jul 18:08:29.586 \* Marking node 6d6f6fbeff41f5a85a7a7ebe15565a448fb0a69f as failing (quorum reached).

\--说明本节点为主节点 联合36虚拟启动的两个主节点 确认了37上两个slave节点宕机（超过半数的主投票确认,37上两个节点晚启动20分钟）

4441:M 02 Jul 18:26:56.159 \* Clear FAIL state for node 052b9df159281988af20d8b5d0690e5defa42c47: slave is reachable again.

4441:M 02 Jul 18:27:00.431 \* Clear FAIL state for node 6d6f6fbeff41f5a85a7a7ebe15565a448fb0a69f: slave is reachable again.

\--说明本节点为主节点 联合36虚拟启动的两个主节点 确认了37上两个slave节点恢复 重新加入集群（超过半数的主投票确认）

4441:M 02 Jul 18:27:11.969 \* 1 changes in 900 seconds. Saving...  
4441:M 02 Jul 18:27:11.970 \* Background saving started by pid 5249  
5249:C 02 Jul 18:27:11.979 \* DB saved on disk  
5249:C 02 Jul 18:27:11.979 \* RDB: 6 MB of memory used by copy-on-write  
4441:M 02 Jul 18:27:12.072 \* Background saving terminated with success  
4441:M 02 Jul 18:42:13.032 \* 1 changes in 900 seconds. Saving...  
4441:M 02 Jul 18:42:13.034 \* Background saving started by pid 6015  
6015:C 02 Jul 18:42:13.068 \* DB saved on disk  
6015:C 02 Jul 18:42:13.069 \* RDB: 8 MB of memory used by copy-on-write  
4441:M 02 Jul 18:42:13.135 \* Background saving terminated with success  
4441:M 02 Jul 19:21:15.353 \* 1 changes in 900 seconds. Saving...  
4441:M 02 Jul 19:21:15.354 \* Background saving started by pid 7288  
7288:C 02 Jul 19:21:15.363 \* DB saved on disk  
7288:C 02 Jul 19:21:15.363 \* RDB: 8 MB of memory used by copy-on-write  
4441:M 02 Jul 19:21:15.455 \* Background saving terminated with success

4441:M 02 Jul 19:26:16.093 \* 10 changes in 300 seconds. Saving...

参考: https://www.cnblogs.com/yjmyzz/p/redis-cluster-turotial.html

ps：2018.07.12add

以上这种是理想情况下的，可以自动恢复，极端情况（多发生在高并发场景）

可能出现主从数据不一致，

有一些公司遇到集群宕机某些节点后，重启无法恢复集群初始状态，甚至集群不可用的

情况

![70][]

[70]: /images/20220521/cc3e3e519dc8499da8d2506b7fd38f54.png