Describe the bug

Redis 6.2.6 in cluster mode. I have 6 nodes in cluster 3 masters and 3 replicas When i make manual failover in one replica via CLUSTER FAILOVER command and in time for it master have write command (ex. SET foo bar) this command paused is too long, about 10 seconds. And only after this time receive -MOVED answer and client do redirect to new master node. In same time all connections with any read command receive -MOVED answer instantly after failover process is done.

To reproduce

  1. Create cluster with 6 nodes: 3 master and 3 replicas. Nodes are all in localhost and listen ports 7000-7005
  2. Select one master-replica pair and some key which point to this nodes. For my setup i choose key foo which point to master-replica nodes :7005, :7002
  3. Connect to master node via redis-cli
root@f8c52b500613:/data# redis-cli -p 7005 -c
127.0.0.1:7005> set foo bar
OK
  1. In other console do manual failover
redis-cli -c -p 7000 cluster nodes | grep -E '(7005|7002)' | fgrep slave | head -n 1 | awk '{print $2}' | cut -d"@" -f1 | cut -d":" -f2 | xargs -n 1 -I{} redis-cli -p {} cluster failover
  1. Fast switch to previous console and make again set foo bar
172.17.0.3:7005> set foo bar
-> Redirected to slot [12182] located at 172.17.0.3:7002
OK
(9.36s)

This method is not stable and hard to reproduce but for reproducibility you need swap 4 and 5 steps and use redis-cli with -r and -i arguments:

  1. Run redis-cli with repeats and interval
time redis-cli -p 7005 -c -r 100 -i 0.01 set foo bar
  1. Fast switch console and do manual failover
redis-cli -c -p 7000 cluster nodes | grep -E '(7005|7002)' | fgrep slave | head -n 1 | awk '{print $2}' | cut -d"@" -f1 | cut -d":" -f2 | xargs -n 1 -I{} redis-cli -p {} cluster failover
  1. In console with set command you'll see something like that
root@f8c52b500613:/data# time redis-cli -p 7005 -c -r 100 -i 0.01 set foo bar
OK
...skipped...
OK

real    0m11.901s
user    0m0.005s
sys 0m0.038s

For read commands all works as expected and failover add about 1 second penalty

root@f8c52b500613:/data# time redis-cli -p 7005 -c -r 100 -i 0.01 get foo
"bar"
...skipped...
"bar"

real    0m2.021s
user    0m0.010s
sys 0m0.046s

In logs for master and replica nodes i am not see for any stranges. (logs for nodes is concated and sorted by time cat /var/log/supervisor/redis-[36].log | sort -k5,5)

43:M 15 Jul 2022 11:40:22.584 # Manual failover requested by replica a9728c13085a5f858409ab9f43e067ebe08abfa8.
45:S 15 Jul 2022 11:40:22.584 # Manual failover user request accepted.
45:S 15 Jul 2022 11:40:22.585 # All master replication stream processed, manual failover can start.
45:S 15 Jul 2022 11:40:22.585 # Received replication offset for paused master manual failover: 3896995
45:S 15 Jul 2022 11:40:22.585 # Start of election delayed for 0 milliseconds (rank #0, offset 3896995).
45:S 15 Jul 2022 11:40:22.585 # Starting a failover election for epoch 62.
45:M 15 Jul 2022 11:40:22.587 # Connection with master lost.
45:M 15 Jul 2022 11:40:22.587 * Caching the disconnected master state.
45:S 15 Jul 2022 11:40:22.587 # Failover election won: I'm the new master.
45:S 15 Jul 2022 11:40:22.587 # configEpoch set to 62 after successful failover
43:M 15 Jul 2022 11:40:22.588 # Connection with replica 172.17.0.3:7002 lost.
45:M 15 Jul 2022 11:40:22.588 # Setting secondary replication ID to 9f178db8b945b966053aa213275a1b9607eac92a, valid up to offset: 3896996. New replication ID is e07dd5b70453e84d1dece77d5e9c098fe008f0ec
45:M 15 Jul 2022 11:40:22.588 * Discarding previously cached master state.
43:M 15 Jul 2022 11:40:22.626 # Configuration change detected. Reconfiguring myself as a replica of a9728c13085a5f858409ab9f43e067ebe08abfa8
43:M 15 Jul 2022 11:40:22.626 # Failover auth granted to a9728c13085a5f858409ab9f43e067ebe08abfa8 for epoch 62
43:S 15 Jul 2022 11:40:22.626 * Before turning into a replica, using my own master parameters to synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer.
43:S 15 Jul 2022 11:40:22.626 * Connecting to MASTER 172.17.0.3:7002
43:S 15 Jul 2022 11:40:22.626 * MASTER <-> REPLICA sync started
43:S 15 Jul 2022 11:40:22.628 * Non blocking connect for SYNC fired the event.
43:S 15 Jul 2022 11:40:22.629 * Master replied to PING, replication can continue...
43:S 15 Jul 2022 11:40:22.630 * Trying a partial resynchronization (request 9f178db8b945b966053aa213275a1b9607eac92a:3896996).
45:M 15 Jul 2022 11:40:22.630 * Partial resynchronization request from 172.17.0.3:7005 accepted. Sending 0 bytes of backlog starting from offset 3896996.
45:M 15 Jul 2022 11:40:22.630 * Replica 172.17.0.3:7005 asks for synchronization
43:S 15 Jul 2022 11:40:22.631 * Successful partial resynchronization with master.
43:S 15 Jul 2022 11:40:22.632 # Master replication ID changed to e07dd5b70453e84d1dece77d5e9c098fe008f0ec
43:S 15 Jul 2022 11:40:22.632 * MASTER <-> REPLICA sync: Master accepted a Partial Resynchronization.

This behavior is probably regression from Redis 6.2 because Redis <6.2 works as expected and write command clients unpaused similarely as read command clients.

Expected behavior

Master node switching to replica role must respond with -MOVED to paused write clients after failover immediately and do not wait about 10 seconds before unblock its.

Comment From: madolson

So, this has been fixed in 7.0, I'm fairly confident the fix is just https://github.com/redis/redis/pull/9676. We originally decided not to backport because it didn't look like a regression, but reading through the code and testing confirms that it was actually a regression.

@DriverX If you can try on 7.0, that will likely resolve your issue.

Comment From: DriverX

@madolson thanks for quick answer. We use Redis 6.2.6 in production and do not plan to upgrade to new major version of Redis in the near feature for company political reason. And Redis 7.0 introduce many changes in response format what can break our integrations.

Comment From: madolson

@DriverX There are very few backwards incompatible changes in 7.0 compared to 6.2, so you should be generally safe doing an upgrade. Although, I fully understand the internal requirements some companies impose on versions.

I'll mark the instance as needing backport for 6.2.

Comment From: DriverX

@madolson This is great news. Thanks. We are looking forward to the release with backport.

How safe backport changes from #9676 via simple patching Redis 6.2.6 source code? We are thinking about adding this patch to rpm build stage for us.

Comment From: madolson

@DriverX It should be safe to take that patch is and apply on 6.2.6.

Btw, closing since I'm not sure anything else explicitly needs to be tracked here.