Redis In Redis 4.0 partial synchronization not working when slave instance restarted.

I am experimenting with Redis 4.0 RC3 (redis-4.0.0-0.3.RC3.fc26.remi.x86_64) installed on both master and slave. In the release notes it is mentioned that with PSYNC2 the master-slave will be able to partially resynchronize when a slave instance is restarted. However when I tried this feature then the partial resynchronization is NOT happening after slave restarts. The slave still does FULL SYNC. I think this is a bug.

Slave logs say: Partial resynchronization not possible (no cached master) Full resync from master: 2d126ef1e016de2d03279436babd55152eecbba9:4536

Steps: 1) Slave starts and connects to Master. Expectedly Full SYNC happens for first time. 2) Slave restarts and connects to Master but again FULL SYNC happens and not the expected partial resync!

The RDB file on slave has correct ReplicationId and Offset from the first sync run of the slave but still after restart slave complains that 'no cached master'.

On Slave:

$ redis-check-rdb /var/lib/redis/dump.rdb [offset 85] AUX FIELD aof-preamble = '0' [offset 135] AUX FIELD repl-id = '2d126ef1e016de2d03279436babd55152eecbba9' [offset 151] AUX FIELD repl-offset = '4536'

$ redis-cli -h localhost -p 6379 localhost:6379> INFO replication role:slave master_host:10.168.10.104 master_port:6379 master_link_status:up master_last_io_seconds_ago:1 master_sync_in_progress:0 slave_repl_offset:4536 slave_priority:100 slave_read_only:0 connected_slaves:0 master_replid:2d126ef1e016de2d03279436babd55152eecbba9 master_replid2:0000000000000000000000000000000000000000 master_repl_offset:4536 second_repl_offset:-1 repl_backlog_active:1 repl_backlog_size:10485760 repl_backlog_first_byte_offset:3949 repl_backlog_histlen:14

On Master before slave connects:

localhost:6379> INFO replication role:master connected_slaves:0 master_replid:2d126ef1e016de2d03279436babd55152eecbba9 master_replid2:0000000000000000000000000000000000000000 master_repl_offset:4536 second_repl_offset:-1 repl_backlog_active:1 repl_backlog_size:104857600 repl_backlog_first_byte_offset:1 repl_backlog_histlen:4536 localhost:6379> INFO replication

Issue: In 4.0 slave does NOT partially resynchronize with master after slave restarts.

Comment From: badboy

Can you also include the logs of both instances?

Comment From: RamanGupta16

Scenario:

1) Master starts 2) Slave starts and connects to master first time. So FULL SYNC is expected 3) Slave restarts but still SYNC and no Partial sync (PSYNC2).

Master Log (removed ASCII Art):

12691:C 04 Jul 06:20:16.346 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
12691:C 04 Jul 06:20:16.347 # Redis version=3.9.103, bits=64, commit=00000000, modified=0, pid=12691, just started
12691:C 04 Jul 06:20:16.347 # Configuration loaded             
12691:M 04 Jul 06:20:16.352 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
12691:M 04 Jul 06:20:16.352 # Server initialized
12691:M 04 Jul 06:20:16.352 # 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.
12691:M 04 Jul 06:20:16.352 # 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.
12691:M 04 Jul 06:20:16.352 * Ready to accept connections
12691:M 04 Jul 06:22:37.356 * Slave 10.168.10.107:6379 asks for synchronization
12691:M 04 Jul 06:22:37.356 * Full resync requested by slave 10.168.10.107:6379
12691:M 04 Jul 06:22:37.356 * Starting BGSAVE for SYNC with target: disk
12691:M 04 Jul 06:22:37.358 * Background saving started by pid 14749
14749:C 04 Jul 06:22:37.359 * DB saved on disk
14749:C 04 Jul 06:22:37.360 * RDB: 4 MB of memory used by copy-on-write
12691:M 04 Jul 06:22:37.402 * Background saving terminated with success
12691:M 04 Jul 06:22:37.402 * Synchronization with slave 10.168.10.107:6379 succeeded
12691:M 04 Jul 06:23:07.469 # Connection with slave 10.168.10.107:6379 lost.
12691:M 04 Jul 06:23:34.251 * Slave 10.168.10.107:6379 asks for synchronization
12691:M 04 Jul 06:23:34.251 * Full resync requested by slave 10.168.10.107:6379
12691:M 04 Jul 06:23:34.251 * Starting BGSAVE for SYNC with target: disk
12691:M 04 Jul 06:23:34.253 * Background saving started by pid 15460
15460:C 04 Jul 06:23:34.254 * DB saved on disk
15460:C 04 Jul 06:23:34.255 * RDB: 4 MB of memory used by copy-on-write
12691:M 04 Jul 06:23:34.299 * Background saving terminated with success
12691:M 04 Jul 06:23:34.299 * Synchronization with slave 10.168.10.107:6379 succeeded

Slave Logs (removed ASCII Art): Slave Connects first time

7700:C 04 Jul 06:22:38.479 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
7700:C 04 Jul 06:22:38.479 # Redis version=3.9.103, bits=64, commit=00000000, modified=0, pid=7700, just started
7700:C 04 Jul 06:22:38.479 # Configuration loaded
7700:S 04 Jul 06:22:38.487 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
7700:S 04 Jul 06:22:38.487 # Server initialized
7700:S 04 Jul 06:22:38.487 # 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.
7700:S 04 Jul 06:22:38.487 # 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.
7700:S 04 Jul 06:22:38.487 * Ready to accept connections
7700:S 04 Jul 06:22:38.488 * Connecting to MASTER 10.168.10.104:6379
7700:S 04 Jul 06:22:38.488 * MASTER <-> SLAVE sync started
7700:S 04 Jul 06:22:38.488 * Non blocking connect for SYNC fired the event.
7700:S 04 Jul 06:22:38.488 * Master replied to PING, replication can continue...
7700:S 04 Jul 06:22:38.489 * Partial resynchronization not possible (no cached master)
7700:S 04 Jul 06:22:38.492 * Full resync from master: 336ff28da1ca11297adf041e28756fa194a3ff65:0
7700:S 04 Jul 06:22:38.536 * MASTER <-> SLAVE sync: receiving 177 bytes from master
7700:S 04 Jul 06:22:38.536 * MASTER <-> SLAVE sync: Flushing old data
7700:S 04 Jul 06:22:38.553 * MASTER <-> SLAVE sync: Loading DB in memory
7700:S 04 Jul 06:22:38.553 * MASTER <-> SLAVE sync: Finished with success
7700:S 04 Jul 06:22:38.555 * Background append only file rewriting started by pid 7704
7700:S 04 Jul 06:22:38.584 * AOF rewrite child asks to stop sending diffs.
7704:C 04 Jul 06:22:38.584 * Parent agreed to stop sending diffs. Finalizing AOF...
7704:C 04 Jul 06:22:38.584 * Concatenating 0.00 MB of AOF diff received from parent.
7704:C 04 Jul 06:22:38.584 * SYNC append only file rewrite performed
7704:C 04 Jul 06:22:38.585 * AOF rewrite: 4 MB of memory used by copy-on-write
7700:S 04 Jul 06:22:38.588 * Background AOF rewrite terminated with success
7700:S 04 Jul 06:22:38.588 * Residual parent diff successfully flushed to the rewritten AOF (0.00 MB)
7700:S 04 Jul 06:22:38.588 * Background AOF rewrite finished successfully
7700:S 04 Jul 06:23:08.583 # User requested shutdown...
7700:S 04 Jul 06:23:08.583 * Calling fsync() on the AOF file.
7700:S 04 Jul 06:23:08.583 * Saving the final RDB snapshot before exiting.
7700:S 04 Jul 06:23:08.601 * DB saved on disk
7700:S 04 Jul 06:23:08.601 * Removing the pid file.
7700:S 04 Jul 06:23:08.601 # Redis is now ready to exit, bye bye...

Slave Logs (removed ASCII Art): Slave restarts

7784:C 04 Jul 06:23:35.380 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
7784:C 04 Jul 06:23:35.380 # Redis version=3.9.103, bits=64, commit=00000000, modified=0, pid=7784, just started
7784:C 04 Jul 06:23:35.380 # Configuration loaded
7784:S 04 Jul 06:23:35.383 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
7784:S 04 Jul 06:23:35.383 # Server initialized
7784:S 04 Jul 06:23:35.383 # 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.
7784:S 04 Jul 06:23:35.383 # 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.
7784:S 04 Jul 06:23:35.383 * Ready to accept connections
7784:S 04 Jul 06:23:35.383 * Connecting to MASTER 10.168.10.104:6379
7784:S 04 Jul 06:23:35.383 * MASTER <-> SLAVE sync started
7784:S 04 Jul 06:23:35.383 * Non blocking connect for SYNC fired the event.
7784:S 04 Jul 06:23:35.384 * Master replied to PING, replication can continue...
7784:S 04 Jul 06:23:35.384 * Partial resynchronization not possible (no cached master)
7784:S 04 Jul 06:23:35.387 * Full resync from master: 336ff28da1ca11297adf041e28756fa194a3ff65:42
7784:S 04 Jul 06:23:35.433 * MASTER <-> SLAVE sync: receiving 177 bytes from master
7784:S 04 Jul 06:23:35.433 * MASTER <-> SLAVE sync: Flushing old data
7784:S 04 Jul 06:23:35.433 * MASTER <-> SLAVE sync: Loading DB in memory
7784:S 04 Jul 06:23:35.433 * MASTER <-> SLAVE sync: Finished with success
7784:S 04 Jul 06:23:35.436 * Background append only file rewriting started by pid 7788
7784:S 04 Jul 06:23:35.476 * AOF rewrite child asks to stop sending diffs.
7788:C 04 Jul 06:23:35.477 * Parent agreed to stop sending diffs. Finalizing AOF...
7788:C 04 Jul 06:23:35.477 * Concatenating 0.00 MB of AOF diff received from parent.
7788:C 04 Jul 06:23:35.477 * SYNC append only file rewrite performed
7788:C 04 Jul 06:23:35.478 * AOF rewrite: 4 MB of memory used by copy-on-write
7784:S 04 Jul 06:23:35.484 * Background AOF rewrite terminated with success
7784:S 04 Jul 06:23:35.484 * Residual parent diff successfully flushed to the rewritten AOF (0.00 MB)

When slave restarts then why not Partial SYNC (PSYNC2).

Comment From: badboy

(I reformatted your logs into code blocks for easier reading)

Does the slave has a dump file as well? Currently it looks like it has AOF enabled. Does it load only the AOF at start? (I need to read up on the current state of persistence in 4.0, so I can only guess here).

Comment From: antirez

Hello, not sure what loglevel are you using, but I would like to see in the slave "DB loaded from disk..." to verify that the RDB gets loaded. Later actually we see an AOF rewrite as @badboy noted, so it looks like you are not reading from the RDB. If you want a slave with AOF, but still you want to perform a restart, you should:

Terminate the slave with SHUTDOWN SAVE
Temporarily disable AOF from the slave configuration.
Restart the slave. Wait for partial resync and so forth.
Re-enable the AOF with CONFIG SET appendonly yes + CONFIG REWRITE.

Currently the PSYNC info cannot be persisted in AOF files (but will be later in next releases).

Comment From: antirez

@badboy solely to get you updated about the state of Redis 4.0 persistence RE this issue, it's quite trivial basically. What happens is that:

When the RDB file is loaded, we pass a structure that is filled with meta-data from the RDB.
After loading the RDB, if we found the replication-id / offset, and the instance is a slave, this information is just used in order to create a "cached master" in the slave replication state.
When the slave reconnects, from its POV, it is just like it was connected to a master before... so it will attempt a partial sync.

Comment From: RamanGupta16

@badboy (I reformatted your logs into code blocks for easier reading) Thanks.

@badboy Does the slave has a dump file as well? Yes.

@badboy Currently it looks like it has AOF enabled. Does it load only the AOF at start? Yes.

@antirez so it looks like you are not reading from the RDB. @antirez Currently the PSYNC info cannot be persisted in AOF files So does this mean that with 'appendonly yes' in redis.conf file the PSYNC will not happen upon slave restart in this release? From code reading of server.c::loadDataFromDisk() it seems so. The 'cached_master' replid and master_repl_offset fields are filled with real values from reading RDB dump only, but not filled when reading from AOF file.

Thus when I changed from 'appendonly yes' to 'appendonly no' in redis.conf then PSYNC is happening upon slave restart. Please document this in release notes so that anybody using this feature does not get a surprise.

I will investigate more of partial resync behaviour from more experimenting.

Comment From: RamanGupta16

New Issue:

In slave 'master_repl_offset' remains stuck at same value even after commands like BGSAVE, SHUTDOWN SAVE. The master's 'master_repl_offset' is however incrementing even though NO data is added to master database. So net result is when slave restarts the PSYNC happens from new updated master's 'master_repl_offset' to old stuck slave's 'master_repl_offset', leading to greater than 0 (> 0) number of bytes being resynched even though nothing is added in master database between slave restart.

Even if some data is added to master database in between slave restart, the bytes replicated is greater than actual data added, because slave is still at old 'master_repl_offset' and not updated.

Steps: 1) Master starts. Slave starts. Full SYNC happens. Now BGSAVE updates slave's 'master_repl_offset'. 2) After slave restarts and PSYNC happens now BGSAVE, SHUTDOWN SAVE do not update slave's 'master_repl_offset'. 3) Now every restart leads to master-->'master_repl_offset' minus slave-->'master_repl_offset' bytes replication even though no data added to master database.

AOF is disabled to allow PSYNC upon slave restart.

In below logs slave's 'master_repl_offset' seems stuck at 225 but master's 'master_repl_offset' is moving ahead. The ReplicationId is 9b447a48b3e0845020ebd398ea2043b3a9805bb9

Master logs:

8639:M 04 Jul 14:12:21.577 * Synchronization with slave 10.168.10.107:6379 succeeded
8639:M 04 Jul 14:14:58.155 # Connection with slave 10.168.10.107:6379 lost.
8639:M 04 Jul 14:15:27.145 * Slave 10.168.10.107:6379 asks for synchronization
8639:M 04 Jul 14:15:27.145 * Partial resynchronization request from 10.168.10.107:6379 accepted. Sending 0 bytes of backlog starting from offset 225.
8639:M 04 Jul 14:18:10.359 # Connection with slave 10.168.10.107:6379 lost.
8639:M 04 Jul 14:18:49.782 * Slave 10.168.10.107:6379 asks for synchronization
8639:M 04 Jul 14:18:49.782 * Partial resynchronization request from 10.168.10.107:6379 accepted. Sending 224 bytes of backlog starting from offset 225.
8639:M 04 Jul 14:19:56.356 # Connection with slave 10.168.10.107:6379 lost.
8639:M 04 Jul 14:20:11.765 * Slave 10.168.10.107:6379 asks for synchronization
8639:M 04 Jul 14:20:11.765 * Partial resynchronization request from 10.168.10.107:6379 accepted. Sending 308 bytes of backlog starting from offset 225.

role:master
connected_slaves:1
slave0:ip=10.168.10.107,port=6379,state=online,offset=462,lag=1
master_replid:9b447a48b3e0845020ebd398ea2043b3a9805bb9
master_replid2:0000000000000000000000000000000000000000
master_repl_offset:462
second_repl_offset:-1
repl_backlog_active:1
repl_backlog_size:104857600
repl_backlog_first_byte_offset:1
repl_backlog_histlen:462

Slave logs across restarts:

8517:S 04 Jul 14:12:22.066 * DB loaded from disk: 0.183 seconds
8517:S 04 Jul 14:12:22.066 * 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.
8517:S 04 Jul 14:12:22.066 * Ready to accept connections
8517:S 04 Jul 14:12:22.067 - DB 0: 100023 keys (0 volatile) in 131072 slots HT.
8517:S 04 Jul 14:12:22.067 - 0 clients connected (0 slaves), 30645576 bytes in use
8517:S 04 Jul 14:12:22.067 * Connecting to MASTER 10.168.10.104:6379
8517:S 04 Jul 14:12:22.067 * MASTER <-> SLAVE sync started
8517:S 04 Jul 14:12:22.067 * Non blocking connect for SYNC fired the event.
8517:S 04 Jul 14:12:22.067 * Master replied to PING, replication can continue...
8517:S 04 Jul 14:12:22.068 * Trying a partial resynchronization (request e9b924f2cc65d1f593542c734a55f1dd1e4a3d54:0).
8517:S 04 Jul 14:12:22.070 * Full resync from master: 9b447a48b3e0845020ebd398ea2043b3a9805bb9:0
8517:S 04 Jul 14:12:22.070 * Discarding previously cached master state.

8593:S 04 Jul 14:15:27.813 * DB loaded from disk: 0.181 seconds
8593:S 04 Jul 14:15:27.813 * 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.
8593:S 04 Jul 14:15:27.813 * Ready to accept connections
8593:S 04 Jul 14:15:27.814 - DB 0: 100023 keys (0 volatile) in 131072 slots HT.
8593:S 04 Jul 14:15:27.814 - 0 clients connected (0 slaves), 30645576 bytes in use
8593:S 04 Jul 14:15:27.814 * Connecting to MASTER 10.168.10.104:6379
8593:S 04 Jul 14:15:27.814 * MASTER <-> SLAVE sync started
8593:S 04 Jul 14:15:27.814 * Non blocking connect for SYNC fired the event.
8593:S 04 Jul 14:15:27.814 * Master replied to PING, replication can continue...
8593:S 04 Jul 14:15:27.815 * Trying a partial resynchronization (request 9b447a48b3e0845020ebd398ea2043b3a9805bb9:225).
8593:S 04 Jul 14:15:27.815 * Successful partial resynchronization with master.
8593:S 04 Jul 14:15:27.815 * MASTER <-> SLAVE sync: Master accepted a Partial Resynchronization.

8671:S 04 Jul 14:18:50.449 * Ready to accept connections
8671:S 04 Jul 14:18:50.449 - DB 0: 100023 keys (0 volatile) in 131072 slots HT.
8671:S 04 Jul 14:18:50.450 - 0 clients connected (0 slaves), 30645576 bytes in use
8671:S 04 Jul 14:18:50.450 * Connecting to MASTER 10.168.10.104:6379
8671:S 04 Jul 14:18:50.450 * MASTER <-> SLAVE sync started
8671:S 04 Jul 14:18:50.450 * Non blocking connect for SYNC fired the event.
8671:S 04 Jul 14:18:50.450 * Master replied to PING, replication can continue...
8671:S 04 Jul 14:18:50.451 * Trying a partial resynchronization (request 9b447a48b3e0845020ebd398ea2043b3a9805bb9:225).
8671:S 04 Jul 14:18:50.451 * Successful partial resynchronization with master.
8671:S 04 Jul 14:18:50.451 * MASTER <-> SLAVE sync: Master accepted a Partial Resynchronization.

8719:S 04 Jul 14:20:12.430 * DB loaded from disk: 0.183 seconds
8719:S 04 Jul 14:20:12.430 * 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.
8719:S 04 Jul 14:20:12.430 * Ready to accept connections
8719:S 04 Jul 14:20:12.431 - DB 0: 100023 keys (0 volatile) in 131072 slots HT.
8719:S 04 Jul 14:20:12.431 - 0 clients connected (0 slaves), 30645576 bytes in use
8719:S 04 Jul 14:20:12.431 * Connecting to MASTER 10.168.10.104:6379
8719:S 04 Jul 14:20:12.431 * MASTER <-> SLAVE sync started
8719:S 04 Jul 14:20:12.431 * Non blocking connect for SYNC fired the event.
8719:S 04 Jul 14:20:12.432 * Master replied to PING, replication can continue...
8719:S 04 Jul 14:20:12.432 * Trying a partial resynchronization (request 9b447a48b3e0845020ebd398ea2043b3a9805bb9:225).
8719:S 04 Jul 14:20:12.433 * Successful partial resynchronization with master.
8719:S 04 Jul 14:20:12.433 * MASTER <-> SLAVE sync: Master accepted a Partial Resynchronization.


$ redis-check-rdb /var/lib/redis/dump.rdb 
[offset 0] Checking RDB file /var/lib/redis/dump.rdb
[offset 28] AUX FIELD redis-ver = '3.9.103'
[offset 42] AUX FIELD redis-bits = '64'
[offset 54] AUX FIELD ctime = '1499192396'
[offset 69] AUX FIELD used-mem = '30708016'
[offset 85] AUX FIELD aof-preamble = '0'
[offset 135] AUX FIELD repl-id = '9b447a48b3e0845020ebd398ea2043b3a9805bb9'
[offset 151] AUX FIELD repl-offset = '224'
[offset 153] Selecting DB ID 0
[offset 3667759] Checksum OK
[offset 3667759] \o/ RDB looks OK! \o/
[info] 100023 keys read
[info] 0 expires
[info] 0 already expired

Comment From: RamanGupta16

Investigating more on new issue raised in previous comment above: In slave the 'slave_repl_offset' seems to have latest offset value, but for PSYNC upon restart it sends 'master_repl_offset:' to master.

# Replication
role:slave
master_host:10.168.10.104
master_port:6379
master_link_status:up
master_last_io_seconds_ago:2
master_sync_in_progress:0
slave_repl_offset:3374
slave_priority:100
slave_read_only:1
connected_slaves:0
master_replid:9b447a48b3e0845020ebd398ea2043b3a9805bb9
master_replid2:0000000000000000000000000000000000000000
master_repl_offset:224
second_repl_offset:-1
repl_backlog_active:0
repl_backlog_size:10485760
repl_backlog_first_byte_offset:0
repl_backlog_histlen:0

A quick hack in rdb.c:rdbSaveInfoAuxFields to save server.cached_master->reploff instead of original server.master_repl_offset for the RDB field repl-offset seems to have worked because upon slave restart the PSYNC now happens from latest offset instead of original server.master_repl_offset.

Can someone help on this issue, if my understanding is correct?

Comment From: RamanGupta16

Was this bug fixed in 4.0.0 GA release 4.0.0-1?

Comment From: allenling

not sure if same issue, but i am confused really.

scenario: 1. start master, start slave, full sync 2. restart master 3. slave reconnect to master, and perform full sync

still perform full sync in step 3, it is right? i think that master would store replication id and offset in own rdb, so when master restart, it would read replication id and offset from rdb, and perform a partial sync, and i am wrong about that?

and when check the log file, it seems that master got a new replication id after restart, and offset always less than offset in slave.

here is slave log

16009:S 18 Sep 16:56:52.312 # Connection with master lost.
16009:S 18 Sep 16:56:52.312 * Caching the disconnected master state.
16009:S 18 Sep 16:56:52.860 * Connecting to MASTER 10.21.2.245:6379
16009:S 18 Sep 16:56:52.861 * MASTER <-> SLAVE sync started
16009:S 18 Sep 16:56:52.861 * Non blocking connect for SYNC fired the event.
16009:S 18 Sep 16:56:52.861 * Master replied to PING, replication can continue...
16009:S 18 Sep 16:56:52.862 * Trying a partial resynchronization (request 807586d88a3f1cfe6b3b3bdb7712304202cbfd83:19471).
16009:S 18 Sep 16:56:52.864 * Full resync from master: 16455fa920d8f7b85631ba65cd7b1d38b79979d8:19470
16009:S 18 Sep 16:56:52.864 * Discarding previously cached master state.
16009:S 18 Sep 16:56:52.923 * MASTER <-> SLAVE sync: receiving 6057 bytes from master
16009:S 18 Sep 16:56:52.923 * MASTER <-> SLAVE sync: Flushing old data
16009:S 18 Sep 16:56:52.924 * MASTER <-> SLAVE sync: Loading DB in memory
16009:S 18 Sep 16:56:52.924 * MASTER <-> SLAVE sync: Finished with success

master log

19798:M 18 Sep 16:56:52.225 * Ready to accept connections
19798:M 18 Sep 16:56:52.765 * Slave 10.21.2.99:6379 asks for synchronization
19798:M 18 Sep 16:56:52.765 * Unable to partial resync with slave 10.21.2.99:6379 for lack of backlog (Slave request was: 19471).
19798:M 18 Sep 16:56:52.765 # Warning: slave 10.21.2.99:6379 tried to PSYNC with an offset that is greater than the master replication offset.
19798:M 18 Sep 16:56:52.766 * Starting BGSAVE for SYNC with target: disk
19798:M 18 Sep 16:56:52.766 * Background saving started by pid 19809
19809:C 18 Sep 16:56:52.772 * DB saved on disk
19809:C 18 Sep 16:56:52.772 * RDB: 6 MB of memory used by copy-on-write
19798:M 18 Sep 16:56:52.826 * Background saving terminated with success
19798:M 18 Sep 16:56:52.826 * Synchronization with slave 10.21.2.99:6379 succeeded

Comment From: RamanGupta16

Restart master will definitely cause full resync. My issue was about slave restart.

Comment From: allenling

so there is no way to avoid full sync when we restart master? i mean master already save replication id in rdb, why redis create a new replication id for master when master start(new replication means a full sync)? or, there is any post/article for me?

Comment From: RamanGupta16

so there is no way to avoid full sync when we restart master? I don't think there is any way to avoid full sync incase master restarts.

Comment From: mpataki

We're running some large redis instances in production with RDB + AOF on both the masters and the slaves, and we're using Sentinel to handle automatic failovers. We've noticed the same FULL SYNC behaviour when restarting slaves, evidently because the slaves are using an AOF.

Redis 5 just came out and appears not to address this issue. As a result, we're considering building something around the Sentinel provided Pub/Sub messaging to alter the master and slave configs ensuring only the masters have AOF on. This is riddled with downsides, unfortunately, so I'd just like to throw my support behind getting the required PSYNC data persisted in the AOF so we can keep using it. It would make for some solid/reliable host upgrades, and prevent us from needing to build a bunch of sketchy stuff to make this work.

Comment From: antirez

Hello, thanks for your hints, yes... that makes sense, it's non obvious how to do it properly, but we want to do it, also because supporting slave restarts with partial resync with RDB forced us to do a lot of work in the replication side, so not exploiting it also for AOF is a shame. I think that we should start at least to provide ASAP the restart with the slave is stopped with SHUTDOWN. This is trivial because we can just append the metadata to AOF. Then we can figure out how to do the rest... that is, to snapshot from time to time such metadata into the AOF and make Redis able to discard the last tail after the last snapshot, so that it is possible to restart the replication easily.

Comment From: TiagoTT

I have tried with aof-use-rdb-preamble yes to see if the RDB data prepended to the AOF would allow the slave to load the cached master state, but it did not work. So either the PSYNC data is not written to the RDB preamble or it is not loaded from the RDB preamble at start.

Comment From: mightydok

Any updates?

Comment From: antirez

This feature was added to Redis 5 (RDB, not AOF). Closing. Soon or later we'll fix this for AOF, not clear when, no room in Redis 6 release.

Comment From: deepak-auto

@antirez, has this been fixed as of Redis 6.0.9? Thanks!

Comment From: oranagra

@deepak-auto what do you mean? As Antirez stated, this feature was added to redis 5.0 when restarting from RDB (and not yet for AOF). nothing was changed in that respect, not even in 6.0.9.

Comment From: RayzorFlash

@oranagra Are there any plans to try and get this change in for AOF?

Comment From: oranagra

it's a bit more complicated to do for AOF, and i'm not sure how much sense it makes. Loading an AOF can take a lot of time, and during that time there's a good chance the master will already get a lot of progress in the replication offset and the backlog will no longer apply. So i don't think this is currently in our plans, but maybe in some future version.

Maybe if the master also has an AOF, then that AOF can be used instead of the replication backlog, so a long AOF loading process in the replica will not mean the backlog on the master is drained.

Bottom line, no plans for that anytime soon.