Redis slave keeps disconnecting during syn with master or master closes connection for slave

[satyendra singh]

Hi All,

We are finding some strange behaviour in our redis cluster.

where a slave tries to do full sync with master and after some loses disconnects and tries to reconnect again.

what we suspect is as redis slave is taking around two minutes to load received rdb file.

meanwhile other master thinks its unreachable and slaves master disconnects it.

master logs 

22:M 01 Sep 19:56:51.456 * Slave 10.66.110.61:6379 asks for synchronization

22:M 01 Sep 19:56:51.456 * Unable to partial resync with slave 10.66.110.61:6379 for lack of backlog (Slave request was: 35541788818).

22:M 01 Sep 19:56:51.456 * Delay next BGSAVE for diskless SYNC

22:M 01 Sep 19:56:57.962 * Starting BGSAVE for SYNC with target: slaves sockets

22:M 01 Sep 19:56:58.116 * Background RDB transfer started by pid 249

249:C 01 Sep 19:58:41.721 * RDB: 971 MB of memory used by copy-on-write

22:M 01 Sep 19:58:42.104 * Background RDB transfer terminated with success

22:M 01 Sep 19:58:42.104 # Slave 10.66.110.61:6379 correctly received the streamed RDB file.

22:M 01 Sep 19:58:42.104 * Streamed RDB transfer with slave 10.66.110.61:6379 succeeded (socket). Waiting for REPLCONF ACK from slave to enable streaming

22:M 01 Sep 19:59:00.314 * FAIL message received from cebafb35e58d950b27761e13ed8b8c20734841ef about 45266afe23fdb8fec18c0b2278be1a795e20243d

22:M 01 Sep 19:59:16.023 # Client id=1990468 addr=10.66.110.61:48599 fd=385 name= age=145 idle=1 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=16384 oll=7277 omem=116824142 events=r cmd=psync scheduled to be closed ASAP for overcoming of output buffer limits.

22:M 01 Sep 19:59:16.023 # Connection with slave 10.66.110.61:6379 lost.

slave logs 

22:S 01 Sep 19:56:51.453 * Connecting to MASTER 10.66.111.61:6379

22:S 01 Sep 19:56:51.453 * MASTER <-> SLAVE sync started

22:S 01 Sep 19:56:51.454 * Non blocking connect for SYNC fired the event.

22:S 01 Sep 19:56:51.454 * Master replied to PING, replication can continue...

22:S 01 Sep 19:56:51.456 * Trying a partial resynchronization (request 63e4efe185731152f9598d56c1d8dc8a0073ecb3:35541788818).

22:S 01 Sep 19:56:57.962 * Full resync from master: 63e4efe185731152f9598d56c1d8dc8a0073ecb3:35783099392

22:S 01 Sep 19:56:57.962 * Discarding previously cached master state.

22:S 01 Sep 19:56:58.118 * MASTER <-> SLAVE sync: receiving streamed RDB from master

22:S 01 Sep 19:58:41.639 * MASTER <-> SLAVE sync: Flushing old data

22:S 01 Sep 19:59:49.950 * MASTER <-> SLAVE sync: Loading DB in memory

22:S 01 Sep 20:01:39.351 * MASTER <-> SLAVE sync: Finished with success

22:S 01 Sep 20:01:39.352 # Connection with master lost.

Any help to understand this will help.

thanks and regards,

Satyendr

[Jose Moreira]

" scheduled to be closed ASAP for overcoming of output buffer limits." from the master logs.

Try to increase the buffer limits first: https://redislabs.com/blog/top-redis-headaches-for-devops-replication-buffer/

--
You received this message because you are subscribed to the Google Groups "Redis DB" group.
To unsubscribe from this group and stop receiving emails from it, send an email to redis-db+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/redis-db/527c9b79-96ab-4684-a2bb-79bbb0adf3d9%40googlegroups.com.

[satyendra singh]

Hi Jose,

Thanks for reply my question here.

As rdb sync was success why slave is disconnected with master saying buffer outflow limit exceeds.

Is this because post rbd success master tries to stream data to connected slave as data is large is size or slave was slow in processing incoming requests?

As this was in endless loop and slave neer really synced with master.

One more confusion why other masters reported that this slave which is syncing data is not available even though it was up and processing rbd file?

I can share full log if that helps as we really want to get to the root cause for this and solution to solve this.

Any help to understand this will be appreciated

thanks and regards,

Satyendra

--
You received this message because you are subscribed to the Google Groups "Redis DB" group.

To unsubscribe from this group and stop receiving emails from it, send an email to redi...@googlegroups.com.

[Greg Andrews]

It's because your master Redis server is busy and the RDB transfer/load on this slave is slow.  That is, there are a lot of writes happening during the period of time the slave is performing a sync.  Those writes are queued up in a memory buffer, ready to deliver to the slave when it has finished transferring the RDB file and loading its contents.  The buffer is a fixed size (but you can configure the master to use a larger size).

If the slave takes a long time to complete the sync, the busy master will find the buffer has overflowed.  The overflow means changes will be lost and the slave will not have the same data as the master (and other slaves).  Redis disconnects the slave to prevent this and make an engineer come and investigate the problem.

[satyendra singh]

Hi Greg,
Thanks for describing situation here.
It really helped us to understand what was happening.
In those nodes.

[kanagasabai karunanithy]

Hi,

Can you show the output of "config get client-output-buffer-limit" if the output is as shown below 

"Output looks like

   1) "client-output-buffer-limit"

   2) "normal 0 0 0 slave 268435456 67108864 60 pubsub 33554432 8388608 60" "  <--- under slave you see <hard-limit(256mb) soft-limit(64mb) 60sec> 

 

increase the buffer limit

# CONFIG SET client-output-buffer-limit "slave 10737418240 10737418240 60"   <--- Run 1st  ( this command increases hard and soft limit to 10gb

# config set repl-backlog-size 5gb <--- Ran on master & Backup Master


This will fix the replication issue.

--
You received this message because you are subscribed to the Google Groups "Redis DB" group.

To unsubscribe from this group and stop receiving emails from it, send an email to redis-db+u...@googlegroups.com.