以下是Redis sentinel的拓扑结构
[root@redis ~]# ps -ef|grep redis root 1259 1 0 3月18 ? 00:08:38 redis-server *:6379 root 1289 1 0 3月18 ? 00:08:18 redis-server *:6380 root 1343 1 0 3月18 ? 00:09:04 redis-server *:6381 root 2064 1 0 03:36 ? 00:09:29 redis-server *:26379 [sentinel] root 2076 1 0 03:38 ? 00:09:29 redis-server *:26380 [sentinel] root 2087 1 0 03:38 ? 00:10:19 redis-server *:26381 [sentinel]
说明：6379/6380/6381是三个Redis数据节点，而26379/26380/26381是三个sentinel
26379 run_id:6521bce7ca0d09d99d2d52976e71b73d96eafe52 26380 run_id:4261696cd87cd788f08dcbf7feffe33a960ae8a7 26381 run_id:cb0049d5314b388e6dbd4ed425029d752d9eaf42
开始模拟
模拟故障方法有很多，比较典型的方法有如下几种：
.方法一，强制杀掉对应节点的进程号，这样可以模拟出宕机的效果
.方法二, 使用Redis的debug sleep命令，让节点进入睡眠状态，这样可以模拟阻塞的效果
.方法三, 使用redis的shutdown命令，模拟正常的停掉redis。
这里使用方法一来进行测试，因为从实际经验来看，数百上千机器偶尔宕机一两台是会不定期出现的，这里记录一下用kill -9 使主节点(这里的主节点是6381)进程宕机的时间：
注意一下，这里发现kill掉主节点进程之后，主节点中没有打印什么日志信息(可能和shutdown效果不一样)，但是发现其余的另外的两个节点中有一些日志信息显示
看一下6379日志信息：
2845:S 24 Mar 2022 21:58:25.702 * RDB age 0 seconds 2845:S 24 Mar 2022 21:58:25.702 * RDB memory usage when created 1.97 Mb 2845:S 24 Mar 2022 21:58:25.702 # Done loading RDB, keys loaded: 4, keys expired: 0. 2845:S 24 Mar 2022 21:58:25.703 * MASTER <-> REPLICA sync: Finished with success 2845:S 24 Mar 2022 22:04:25.687 # Connection with master lost. ## 2845:S 24 Mar 2022 22:04:25.687 * Caching the disconnected master state. 2845:S 24 Mar 2022 22:04:25.688 * Reconnecting to MASTER 127.0.0.1:6381 2845:S 24 Mar 2022 22:04:25.688 * MASTER <-> REPLICA sync started 2845:S 24 Mar 2022 22:04:25.688 # Error condition on socket for SYNC: Connection refused 2845:S 24 Mar 2022 22:04:26.141 * Connecting to MASTER 127.0.0.1:6381 2845:S 24 Mar 2022 22:04:26.142 * MASTER <-> REPLICA sync started 2845:S 24 Mar 2022 22:04:26.142 # Error condition on socket for SYNC: Connection refused 2845:S 24 Mar 2022 22:04:27.155 * Connecting to MASTER 127.0.0.1:6381 2845:S 24 Mar 2022 22:04:27.155 * MASTER <-> REPLICA sync started
可以看到一个时间点间隔(从21:58跳到了22:04)这个过程就是执行了kill命令后所出现的反应，从 Connection with master lost这句话开始 说明6379这个从节点去6381(主节点)请求就开始失败了
然后22:04:56时它接到sentinel节点命令，清理原理缓冲的主节点状态信息，sentinel将6379节点晋升为主节点，并重写了配置(config rewrite executed with sucess).
2845:M 24 Mar 2022 22:04:56.005 * Discarding previously cached master state. 2845:M 24 Mar 2022 22:04:56.005 # Setting secondary replication ID to 4e096befcb0b46425e84c0935a44afd848cffe63, valid up to offset: 28505953. New replication ID is 42589dec1d800f42453389730f53bf92ea2fda26 2845:M 24 Mar 2022 22:04:56.005 * MASTER MODE enabled (user request from 'id=10 addr=127.0.0.1:43084 laddr=127.0.0.1:6379 fd=10 name=sentinel-ab0fbd6d-cmd age=391 idle=1 flags=x db=0 sub=0 psub=0 multi=4 qbuf=188 qbuf-free=40766 argv-mem=4 obl=45 oll=0 omem=0 tot-mem=61468 events=r cmd=exec user=default redir=-1') 2845:M 24 Mar 2022 22:04:56.009 # CONFIG REWRITE executed with success. 2845:M 24 Mar 2022 22:04:56.709 * Replica 127.0.0.1:6380 asks for synchronization 2845:M 24 Mar 2022 22:04:56.709 * Partial resynchronization request from 127.0.0.1:6380 accepted. Sending 289 bytes of backlog starting from offset 28505953.
然后从 Replica 127.0.0.1:6380 asks for synchronization 这句话可以看到6380这个节点发起了连接主节点的请求，
这时去看sentinel日志:
这里我们可以26379的日志：
2064:X 24 Mar 2022 22:04:55.814 # +try-failover master mymaster 127.0.0.1 6381 2064:X 24 Mar 2022 22:04:55.817 # +vote-for-leader ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a 4 2064:X 24 Mar 2022 22:04:55.824 # 18e34da0c4ee7c3c285d1d2735d8ab12a44cd72b voted for ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a 4 2064:X 24 Mar 2022 22:04:55.825 # eadd4c9ebfa6c1fbcbfdc5d7e1eec13c80774ec5 voted for ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a 4
这里可以看到sentinel集群在进行选举: 'ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a' 这个是run_id
再来看看26380的日志：
2076:X 24 Mar 2022 22:04:55.706 # +sdown master mymaster 127.0.0.1 6381 2076:X 24 Mar 2022 22:04:55.821 # +new-epoch 4 2076:X 24 Mar 2022 22:04:55.823 # +vote-for-leader ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a 4 2076:X 24 Mar 2022 22:04:56.700 # +config-update-from sentinel ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a 127.0.0.1 26379 @ mymaster 127.0.0.1 6381 2076:X 24 Mar 2022 22:04:56.700 # +switch-master mymaster 127.0.0.1 6381 127.0.0.1 6379 2076:X 24 Mar 2022 22:04:56.701 * +slave slave 127.0.0.1:6380 127.0.0.1 6380 @ mymaster 127.0.0.1 6379 2076:X 24 Mar 2022 22:04:56.701 * +slave slave 127.0.0.1:6381 127.0.0.1 6381 @ mymaster 127.0.0.1 6379 2076:X 24 Mar 2022 22:05:26.723 # +sdown slave 127.0.0.1:6381 127.0.0.1 6381 @ mymaster 127.0.0.1 6379
从26380日志可以看出，原master(127.0.0.1 6381)被主观下线了，然后sentinel进行选举了，选择了run_id是‘ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a’这个sentinel做了sentinel集群的主节点，从上面可以看到这个sentinel主节点也就是(23679)
而26381的日志也和26380内容差不多
2087:X 24 Mar 2022 22:04:55.795 # +sdown master mymaster 127.0.0.1 6381 2087:X 24 Mar 2022 22:04:55.822 # +new-epoch 4 2087:X 24 Mar 2022 22:04:55.825 # +vote-for-leader ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a 4 2087:X 24 Mar 2022 22:04:55.853 # +odown master mymaster 127.0.0.1 6381 #quorum 3/2 2087:X 24 Mar 2022 22:04:55.854 # Next failover delay: I will not start a failover before Thu Mar 24 22:10:55 2022 2087:X 24 Mar 2022 22:04:56.702 # +config-update-from sentinel ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a 127.0.0.1 26379 @ mymaster 127.0.0.1 6381 2087:X 24 Mar 2022 22:04:56.702 # +switch-master mymaster 127.0.0.1 6381 127.0.0.1 6379 2087:X 24 Mar 2022 22:04:56.702 * +slave slave 127.0.0.1:6380 127.0.0.1 6380 @ mymaster 127.0.0.1 6379 2087:X 24 Mar 2022 22:04:56.703 * +slave slave 127.0.0.1:6381 127.0.0.1 6381 @ mymaster 127.0.0.1 6379 2087:X 24 Mar 2022 22:05:26.765 # +sdown slave 127.0.0.1:6381 127.0.0.1 6381 @ mymaster 127.0.0.1 6379
这里来看一下各个节点客观下线的时间
26379 2064:X 24 Mar 2022 22:04:55.814 # +odown master mymaster 127.0.0.1 6381 #quorum 2/2 26380 这个在日志中竟然没有找到 26381 2087:X 24 Mar 2022 22:04:55.853 # +odown master mymaster 127.0.0.1 6381 #quorum 3/2
从这两个日志的+odown客观下线时间来看，26379是最先客观下线的，
3）故障转移日志：这里可以通过sentinel的主节点(26379)日志看出整个日志转移时的整个流程。
2064:X 24 Mar 2022 22:04:55.736 # +sdown master mymaster 127.0.0.1 6381 2064:X 24 Mar 2022 22:04:55.814 # +odown master mymaster 127.0.0.1 6381 #quorum 2/2 ##对主节点进行客观下线 2064:X 24 Mar 2022 22:04:55.814 # +new-epoch 4 2064:X 24 Mar 2022 22:04:55.814 # +try-failover master mymaster 127.0.0.1 6381 ##这里是尝试故障转移6381这个节点 2064:X 24 Mar 2022 22:04:55.817 # +vote-for-leader ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a 4 ##这里进行选举sentinel主节点 2064:X 24 Mar 2022 22:04:55.824 # 18e34da0c4ee7c3c285d1d2735d8ab12a44cd72b voted for ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a 4 ##run_id 2064:X 24 Mar 2022 22:04:55.825 # eadd4c9ebfa6c1fbcbfdc5d7e1eec13c80774ec5 voted for ab0fbd6da2b0a72051dbe3bee8ef3f02b3cc9a2a 4 2064:X 24 Mar 2022 22:04:55.878 # +elected-leader master mymaster 127.0.0.1 6381 ##这里没有没有搞懂意思。。。 2064:X 24 Mar 2022 22:04:55.879 # +failover-state-select-slave master mymaster 127.0.0.1 6381 ##这里故障转移原主节点(6381) 2064:X 24 Mar 2022 22:04:55.939 # +selected-slave slave 127.0.0.1:6379 127.0.0.1 6379 @ mymaster 127.0.0.1 6381 ##选举6379作为redis数据的主节点 2064:X 24 Mar 2022 22:04:55.939 * +failover-state-send-slaveof-noone slave 127.0.0.1:6379 127.0.0.1 6379 @ mymaster 127.0.0.1 6381 ##这里通过命令salveof no one使得6379成为主节点 2064:X 24 Mar 2022 22:04:56.003 * +failover-state-wait-promotion slave 127.0.0.1:6379 127.0.0.1 6379 @ mymaster 127.0.0.1 6381 ##这里是等待6379成为redis数据主节点 2064:X 24 Mar 2022 22:04:56.645 # +promoted-slave slave 127.0.0.1:6379 127.0.0.1 6379 @ mymaster 127.0.0.1 6381 ##这里是提升6379作为redis数据主节点 2064:X 24 Mar 2022 22:04:56.645 # +failover-state-reconf-slaves master mymaster 127.0.0.1 6381 ##这里重配置了原主节点6381的配置文件 2064:X 24 Mar 2022 22:04:56.695 * +slave-reconf-sent slave 127.0.0.1:6380 127.0.0.1 6380 @ mymaster 127.0.0.1 6381 ##这里是重配置了6380的配置文件 2064:X 24 Mar 2022 22:04:56.901 # -odown master mymaster 127.0.0.1 6381 ##撤销对原主节点进行客观下线 2064:X 24 Mar 2022 22:04:57.687 * +slave-reconf-inprog slave 127.0.0.1:6380 127.0.0.1 6380 @ mymaster 127.0.0.1 6381 2064:X 24 Mar 2022 22:04:57.687 * +slave-reconf-done slave 127.0.0.1:6380 127.0.0.1 6380 @ mymaster 127.0.0.1 6381 2064:X 24 Mar 2022 22:04:57.746 # +failover-end master mymaster 127.0.0.1 6381 ##原主节点故障转移结束 2064:X 24 Mar 2022 22:04:57.747 # +switch-master mymaster 127.0.0.1 6381 127.0.0.1 6379 ##这里最好说明了有原主127.0.0.1 6381 ---> 新主 127.0.0.1 6379 这样的一个过程 2064:X 24 Mar 2022 22:04:57.747 * +slave slave 127.0.0.1:6380 127.0.0.1 6380 @ mymaster 127.0.0.1 6379 ##原从节点6380开始连接新主节点 2064:X 24 Mar 2022 22:04:57.747 * +slave slave 127.0.0.1:6381 127.0.0.1 6381 @ mymaster 127.0.0.1 6379 ##原从节点6381也开始连接新主节点 2064:X 24 Mar 2022 22:05:27.798 # +sdown slave 127.0.0.1:6381 127.0.0.1 6381 @ mymaster 127.0.0.1 6379 ##这里又判断了6381为主观下线， 2064:X 25 Mar 2022 09:47:35.167 # +tilt #tilt mode entered
这里对日志中的一些订阅做解释：
原主节点如果重启后：
6381(原主节点)日志：
5294:S 25 Mar 2022 22:54:11.963 * Connecting to MASTER 127.0.0.1:6379 5294:S 25 Mar 2022 22:54:11.964 * MASTER <-> REPLICA sync started 5294:S 25 Mar 2022 22:54:11.964 * REPLICAOF 127.0.0.1:6379 enabled (user request from 'id=3 addr=127.0.0.1:49004 laddr=127.0.0.1:6381 fd=8 name=sentinel-18e34da0-cmd age=10 idle=0 flags=x db=0 sub=0 psub=0 multi=4 qbuf=196 qbuf-free=40758 argv-mem=4 obl=45 oll=0 omem=0 tot-mem=61468 events=r cmd=exec user=default redir=-1') 5294:S 25 Mar 2022 22:54:11.967 # CONFIG REWRITE executed with success
这里启动后接到sentinel节点的命令，让它去复制6379节点
再来看一下6379(现主节点)日志
2845:M 25 Mar 2022 22:54:11.972 * Replica 127.0.0.1:6381 asks for synchronization 2845:M 25 Mar 2022 22:54:11.972 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for 'f4503c1ab5bec8923b2fb0559e95a58f0cd9f039', my replication IDs are '42589dec1d800f42453389730f53bf92ea2fda26' and '4e096befcb0b46425e84c0935a44afd848cffe63') 2845:M 25 Mar 2022 22:54:11.972 * Starting BGSAVE for SYNC with target: disk 2845:M 25 Mar 2022 22:54:11.973 * Background saving started by pid 5309 5309:C 25 Mar 2022 22:54:11.977 * DB saved on disk 5309:C 25 Mar 2022 22:54:11.978 * RDB: 2 MB of memory used by copy-on-write 2845:M 25 Mar 2022 22:54:12.021 * Background saving terminated with success 2845:M 25 Mar 2022 22:54:12.022 * Synchronization with replica 127.0.0.1:6381 succeeded
这时可以新的主机点中看到，有来自失联多年的兄弟6381的请求复制，
然后再来看看sentinel日志：
26379日志： 撤销了对6381节点主观下线的决定
2064:X 26 Mar 2022 11:04:56.643 # -sdown slave 127.0.0.1:6381 127.0.0.1 6381 @ mymaster 127.0.0.1 6379
26380日志：也撤销了对6381节点主观下线的决定
2076:X 26 Mar 2022 11:04:56.921 # -sdown slave 127.0.0.1:6381 127.0.0.1 6381 @ mymaster 127.0.0.1 6379
26381日志：也是撤销了对6381的主观下线的决定
注意点：
部署各个节点的机器时间尽量要同步，否则日志的时序性会很混乱，例如可以给机器添加NTP服务来同步时间
这里补充一下如果其中一个节点宕掉了，会出现如下日志情况：
会在redis数据的主节点出现连接丢失的报错
2845:M 26 Mar 2022 11:02:43.602 # Connection with replica 127.0.0.1:6381 lost.