KeyDB icon indicating copy to clipboard operation
KeyDB copied to clipboard

[BUG] Multi-Master Sync keeps restarting (one after the other).

Open digipigeon opened this issue 2 years ago • 5 comments

Describe the bug

Multi-master about a 100ms link with about 1gb of data restarts sync within 1 minute of completing a sync from the other side.

So for example, after both servers come online:

Server A replicates from server B Completes replication, stays stable for 20 seconds. Server B replicates from server A Completes replication, stays stable for 20 seconds. [REPEATS]

To reproduce

Please find attached config from both servers

Server A

bind 10.1.49.50
protected-mode no
port 6379
tcp-backlog 511
timeout 0
tcp-keepalive 300
daemonize yes
pidfile /var/run/keydb/keydb-server.pid
loglevel notice
logfile /var/log/keydb/keydb-server.log
databases 16
always-show-logo yes
set-proc-title yes
proc-title-template "{title} {listen-addr} {server-mode}"
save 900 1
save 300 10
save 60 10000
stop-writes-on-bgsave-error yes
rdbcompression yes
rdbchecksum yes
dbfilename dump.rdb
rdb-del-sync-files no
dir /var/lib/keydb
replica-serve-stale-data yes
replica-read-only yes
repl-diskless-sync no
repl-diskless-sync-delay 5
repl-diskless-load disabled
repl-disable-tcp-nodelay yes
repl-backlog-size 1024mb
replica-priority 100
acllog-max-len 128
lazyfree-lazy-eviction no
lazyfree-lazy-expire no
lazyfree-lazy-server-del no
replica-lazy-flush no
lazyfree-lazy-user-del no
lazyfree-lazy-user-flush no
oom-score-adj no
oom-score-adj-values 0 200 800
disable-thp yes
appendonly no
appendfilename "appendonly.aof"
appendfsync everysec
no-appendfsync-on-rewrite no
auto-aof-rewrite-percentage 100
auto-aof-rewrite-min-size 64mb
aof-load-truncated yes
aof-use-rdb-preamble yes
lua-time-limit 5000
slowlog-log-slower-than 10000
slowlog-max-len 128
latency-monitor-threshold 0
notify-keyspace-events ""
hash-max-ziplist-entries 512
hash-max-ziplist-value 64
list-max-ziplist-size -2
list-compress-depth 0
set-max-intset-entries 512
zset-max-ziplist-entries 128
zset-max-ziplist-value 64
hll-sparse-max-bytes 3000
stream-node-max-bytes 4096
stream-node-max-entries 100
activerehashing yes
client-output-buffer-limit normal 0 0 0
client-output-buffer-limit replica 256mb 64mb 60
client-output-buffer-limit pubsub 32mb 8mb 60
hz 10
dynamic-hz yes
aof-rewrite-incremental-fsync yes
rdb-save-incremental-fsync yes
jemalloc-bg-thread yes
server-threads 2
multi-master yes
active-replica yes
replicaof 10.1.143.50 6379

Server B

bind 10.1.143.50
protected-mode no
port 6379
tcp-backlog 511
timeout 0
tcp-keepalive 300
daemonize yes
pidfile /var/run/keydb/keydb-server.pid
loglevel notice
logfile /var/log/keydb/keydb-server.log
databases 16
always-show-logo yes
set-proc-title yes
proc-title-template "{title} {listen-addr} {server-mode}"
save 900 1
save 300 10
save 60 10000
stop-writes-on-bgsave-error yes
rdbcompression yes
rdbchecksum yes
dbfilename dump.rdb
rdb-del-sync-files no
dir /var/lib/keydb
replica-serve-stale-data yes
replica-read-only yes
repl-diskless-sync no
repl-diskless-sync-delay 5
repl-diskless-load disabled
repl-disable-tcp-nodelay yes
repl-backlog-size 1024mb
replica-priority 100
acllog-max-len 128
lazyfree-lazy-eviction no
lazyfree-lazy-expire no
lazyfree-lazy-server-del no
replica-lazy-flush no
lazyfree-lazy-user-del no
lazyfree-lazy-user-flush no
oom-score-adj no
oom-score-adj-values 0 200 800
disable-thp yes
appendonly no
appendfilename "appendonly.aof"
appendfsync everysec
no-appendfsync-on-rewrite no
auto-aof-rewrite-percentage 100
auto-aof-rewrite-min-size 64mb
aof-load-truncated yes
aof-use-rdb-preamble yes
lua-time-limit 5000
slowlog-log-slower-than 10000
slowlog-max-len 128
latency-monitor-threshold 0
notify-keyspace-events ""
hash-max-ziplist-entries 512
hash-max-ziplist-value 64
list-max-ziplist-size -2
list-compress-depth 0
set-max-intset-entries 512
zset-max-ziplist-entries 128
zset-max-ziplist-value 64
hll-sparse-max-bytes 3000
stream-node-max-bytes 4096
stream-node-max-entries 100
activerehashing yes
client-output-buffer-limit normal 0 0 0
client-output-buffer-limit replica 256mb 64mb 60
client-output-buffer-limit pubsub 32mb 8mb 60
hz 10
dynamic-hz yes
aof-rewrite-incremental-fsync yes
rdb-save-incremental-fsync yes
jemalloc-bg-thread yes
server-threads 2
multi-master yes
active-replica yes
replicaof 10.1.49.50 6379

Expected behavior

I would expect the servers (after completing their initial replication process) to remain in sync and not drop and resync.

Additional information

Version 6.2.2

Either side can remain stable if we run single-direction replication.

Both (Server A and Server B) also act as Masters for 6+ Slave servers within the same zone. This works perfectly.

Pertinent Logs

1587063:1587086:S 14 Feb 2023 14:54:03.459 * MASTER <-> REPLICA sync: Finished with success
1587063:1587087:S 14 Feb 2023 14:54:03.499 * Replica 10.1.143.63:6378 asks for synchronization
1587063:1587087:S 14 Feb 2023 14:54:03.499 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for '08b7646118c97dda89ec59c1dcf91e1de576c6e6', my replication IDs are '7097e29b26d52b108e78bcfc4e0b217ff42d6fdd' and '0000000000000000000000000000000000000000')
1587063:1587087:S 14 Feb 2023 14:54:03.499 * Starting BGSAVE for SYNC with target: disk
1587063:1587087:S 14 Feb 2023 14:54:03.545 * Background saving started by pid 1588467
1587063:1587087:S 14 Feb 2023 14:54:03.757 * Replica 10.1.143.64:6378 asks for synchronization
1587063:1587087:S 14 Feb 2023 14:54:03.757 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for '08b7646118c97dda89ec59c1dcf91e1de576c6e6', my replication IDs are '7097e29b26d52b108e78bcfc4e0b217ff42d6fdd' and '0000000000000000000000000000000000000000')
1587063:1587087:S 14 Feb 2023 14:54:03.757 * Waiting for end of BGSAVE for SYNC
1587063:1587087:S 14 Feb 2023 14:54:03.768 * Replica 10.1.143.62:6378 asks for synchronization
1587063:1587087:S 14 Feb 2023 14:54:03.768 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for '08b7646118c97dda89ec59c1dcf91e1de576c6e6', my replication IDs are '7097e29b26d52b108e78bcfc4e0b217ff42d6fdd' and '0000000000000000000000000000000000000000')
1587063:1587087:S 14 Feb 2023 14:54:03.768 * Waiting for end of BGSAVE for SYNC
1587063:1587087:S 14 Feb 2023 14:54:03.944 * Replica 10.1.143.61:6378 asks for synchronization
1587063:1587087:S 14 Feb 2023 14:54:03.944 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for 'f5a360014b192098695f64d176f54316bfcb1521', my replication IDs are '7097e29b26d52b108e78bcfc4e0b217ff42d6fdd' and '0000000000000000000000000000000000000000')
1587063:1587087:S 14 Feb 2023 14:54:03.944 * Waiting for end of BGSAVE for SYNC
1587063:1587087:S 14 Feb 2023 14:54:03.967 * Replica 10.1.143.67:6378 asks for synchronization
1587063:1587087:S 14 Feb 2023 14:54:03.967 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for 'f5a360014b192098695f64d176f54316bfcb1521', my replication IDs are '7097e29b26d52b108e78bcfc4e0b217ff42d6fdd' and '0000000000000000000000000000000000000000')
1587063:1587087:S 14 Feb 2023 14:54:03.967 * Waiting for end of BGSAVE for SYNC
1587063:1587087:S 14 Feb 2023 14:54:04.251 * Replica 10.1.143.66:6378 asks for synchronization
1587063:1587087:S 14 Feb 2023 14:54:04.251 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for '08b7646118c97dda89ec59c1dcf91e1de576c6e6', my replication IDs are '7097e29b26d52b108e78bcfc4e0b217ff42d6fdd' and '0000000000000000000000000000000000000000')
1587063:1587087:S 14 Feb 2023 14:54:04.251 * Waiting for end of BGSAVE for SYNC
1587063:1587087:S 14 Feb 2023 14:54:04.758 * Replica 10.1.49.50:6379 asks for synchronization
1587063:1587087:S 14 Feb 2023 14:54:04.758 * Full resync requested by replica 10.1.49.50:6379

digipigeon avatar Feb 14 '23 15:02 digipigeon

you shouldn't use replica-read-only yes with active-replica yes

artarik avatar May 12 '23 07:05 artarik

Hi @artarik Yes this was the problem, thank you. Sorry for the delay in updating.

digipigeon avatar Sep 27 '23 09:09 digipigeon

Hello @artarik Unfortunatly I spoke too soon,

This one of the masters kept disconnecting and getting the logs as follows:

1578754:1531733:C 26 Sep 2023 13:12:03.012 * DB saved on disk
1578754:1531733:C 26 Sep 2023 13:12:03.059 * RDB: 30 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:12:03.126 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:15:00.573 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:15:00.624 * Background saving started by pid 1578785
1578785:1531733:C 26 Sep 2023 13:15:03.156 * DB saved on disk
1578785:1531733:C 26 Sep 2023 13:15:03.195 * RDB: 37 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:15:03.308 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:18:00.654 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:18:00.702 * Background saving started by pid 1578837
1578837:1531733:C 26 Sep 2023 13:18:02.758 * DB saved on disk
1578837:1531733:C 26 Sep 2023 13:18:02.802 * RDB: 29 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:18:02.914 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:21:00.785 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:21:00.844 * Background saving started by pid 1578886
1578886:1531733:C 26 Sep 2023 13:21:03.184 * DB saved on disk
1578886:1531733:C 26 Sep 2023 13:21:03.223 * RDB: 36 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:21:03.312 * Background saving terminated with success
1531710:1531734:S 26 Sep 2023 13:23:44.685 # Connection with replica 10.1.143.61:6378 lost.
1531710:1531733:S 26 Sep 2023 13:24:00.504 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:24:00.558 * Background saving started by pid 1578941
1578941:1531733:C 26 Sep 2023 13:24:03.062 * DB saved on disk
1578941:1531733:C 26 Sep 2023 13:24:03.137 * RDB: 32 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:24:03.219 * Background saving terminated with success
1531710:1531734:S 26 Sep 2023 13:24:30.317 # Connection with replica 10.1.143.62:6378 lost.
1531710:1531734:S 26 Sep 2023 13:24:55.463 # Connection with replica 10.1.143.63:6378 lost.
1531710:1531734:S 26 Sep 2023 13:25:26.064 # Connection with replica 10.1.143.64:6378 lost.
1531710:1531733:S 26 Sep 2023 13:26:10.839 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:26:10.896 * Background saving started by pid 1578964
1578964:1531733:C 26 Sep 2023 13:26:12.895 * DB saved on disk
1578964:1531733:C 26 Sep 2023 13:26:12.934 * RDB: 27 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:26:13.054 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:26:58.396 # Connection with master lost.
1531710:1531733:S 26 Sep 2023 13:26:58.396 * Caching the disconnected master state.
1531710:1531733:S 26 Sep 2023 13:26:59.223 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:26:59.224 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:26:59.320 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:26:59.415 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:26:59.607 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:26:59.741 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11969360523708
1531710:1531733:S 26 Sep 2023 13:26:59.741 * Discarding previously cached master state.
1531710:1531733:S 26 Sep 2023 13:27:00.773 * MASTER <-> REPLICA sync: receiving 27717424 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:29:00.491 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:29:00.543 * Background saving started by pid 1579006
1579006:1531733:C 26 Sep 2023 13:29:02.542 * DB saved on disk
1579006:1531733:C 26 Sep 2023 13:29:02.585 * RDB: 23 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:29:02.684 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:29:39.186 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:29:39.335 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:29:39.335 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:29:39.431 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:29:39.527 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:29:39.720 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:29:39.852 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11969468914521
1531710:1531733:S 26 Sep 2023 13:29:40.884 * MASTER <-> REPLICA sync: receiving 27715340 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:32:00.503 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:32:00.559 * Background saving started by pid 1579055
1579055:1531733:C 26 Sep 2023 13:32:02.777 * DB saved on disk
1579055:1531733:C 26 Sep 2023 13:32:02.816 * RDB: 33 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:32:02.928 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:32:19.840 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:32:19.997 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:32:19.998 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:32:20.094 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:32:20.190 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:32:20.382 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:32:20.514 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11969576397721
1531710:1531733:S 26 Sep 2023 13:32:21.558 * MASTER <-> REPLICA sync: receiving 27724028 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:35:00.474 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:35:00.536 * Background saving started by pid 1579101
1531710:1531733:S 26 Sep 2023 13:35:01.829 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:35:02.513 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:35:02.513 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:35:02.609 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:35:02.714 * Master replied to PING, replication can continue...
1579101:1531733:C 26 Sep 2023 13:35:02.796 * DB saved on disk
1579101:1531733:C 26 Sep 2023 13:35:02.851 * RDB: 33 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:35:02.906 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:35:02.920 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:35:03.040 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11969685744744
1531710:1531733:S 26 Sep 2023 13:35:04.062 * MASTER <-> REPLICA sync: receiving 27725445 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:37:46.939 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:37:47.833 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:37:47.833 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:37:47.929 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:37:48.025 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:37:48.218 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:37:48.353 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11969795056169
1531710:1531733:S 26 Sep 2023 13:37:49.360 * MASTER <-> REPLICA sync: receiving 27728388 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:37:56.193 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:37:56.260 * Background saving started by pid 1579151
1579151:1531733:C 26 Sep 2023 13:37:58.595 * DB saved on disk
1579151:1531733:C 26 Sep 2023 13:37:58.635 * RDB: 19 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:37:58.755 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:40:00.559 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:40:00.614 * Background saving started by pid 1579194
1579194:1531733:C 26 Sep 2023 13:40:03.020 * DB saved on disk
1579194:1531733:C 26 Sep 2023 13:40:03.064 * RDB: 21 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:40:03.191 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:40:29.704 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:40:30.297 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:40:30.297 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:40:30.393 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:40:30.489 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:40:30.680 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:40:30.813 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11969903917019
1531710:1531733:S 26 Sep 2023 13:40:31.876 * MASTER <-> REPLICA sync: receiving 27724034 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:43:00.627 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:43:00.687 * Background saving started by pid 1579236
1579236:1531733:C 26 Sep 2023 13:43:02.845 * DB saved on disk
1579236:1531733:C 26 Sep 2023 13:43:02.887 * RDB: 29 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:43:02.934 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:43:09.678 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:43:10.339 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:43:10.340 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:43:10.435 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:43:10.531 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:43:10.723 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:43:10.855 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11970011217812
1531710:1531733:S 26 Sep 2023 13:43:11.904 * MASTER <-> REPLICA sync: receiving 27727365 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:45:54.358 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:45:54.512 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:45:54.513 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:45:54.608 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:45:54.704 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:45:54.896 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:45:55.029 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11970120904968
1531710:1531733:S 26 Sep 2023 13:45:56.017 * MASTER <-> REPLICA sync: receiving 27715082 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:46:00.607 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:46:00.672 * Background saving started by pid 1579270
1579270:1531733:C 26 Sep 2023 13:46:02.703 * DB saved on disk
1579270:1531733:C 26 Sep 2023 13:46:02.759 * RDB: 29 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:46:02.892 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:48:35.069 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:48:35.715 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:48:35.715 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:48:35.811 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:48:35.907 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:48:36.099 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:48:36.233 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11970228096776
1531710:1531733:S 26 Sep 2023 13:48:37.253 * MASTER <-> REPLICA sync: receiving 27717454 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:49:00.524 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:49:00.576 * Background saving started by pid 1579309
1579309:1531733:C 26 Sep 2023 13:49:02.688 * DB saved on disk
1579309:1531733:C 26 Sep 2023 13:49:02.737 * RDB: 29 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:49:02.788 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:51:15.473 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:51:15.953 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:51:15.954 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:51:16.049 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:51:16.145 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:51:16.336 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:51:16.498 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11970335339557
1531710:1531733:S 26 Sep 2023 13:51:17.505 * MASTER <-> REPLICA sync: receiving 27728990 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:52:00.597 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:52:00.657 * Background saving started by pid 1579349
1579349:1531733:C 26 Sep 2023 13:52:03.001 * DB saved on disk
1579349:1531733:C 26 Sep 2023 13:52:03.060 * RDB: 21 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:52:03.134 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:54:01.098 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:54:01.326 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:54:01.327 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:54:01.431 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:54:01.588 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:54:01.808 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:54:01.959 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11970446484939
1531710:1531733:S 26 Sep 2023 13:54:03.017 * MASTER <-> REPLICA sync: receiving 27723668 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:55:00.505 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:55:00.561 * Background saving started by pid 1579408
1579408:1531733:C 26 Sep 2023 13:55:02.840 * DB saved on disk
1579408:1531733:C 26 Sep 2023 13:55:02.912 * RDB: 29 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:55:03.057 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:56:45.772 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:56:46.622 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:56:46.623 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:56:46.729 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:56:46.834 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:56:47.037 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:56:47.169 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11970556262701
1531710:1531733:S 26 Sep 2023 13:56:48.224 * MASTER <-> REPLICA sync: receiving 27720784 bytes from master to disk
1531710:1531733:S 26 Sep 2023 13:58:00.535 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 13:58:00.585 * Background saving started by pid 1579451
1579451:1531733:C 26 Sep 2023 13:58:02.878 * DB saved on disk
1579451:1531733:C 26 Sep 2023 13:58:02.928 * RDB: 31 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 13:58:02.984 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 13:59:27.907 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 13:59:28.007 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 13:59:28.007 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 13:59:28.103 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 13:59:28.199 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 13:59:28.390 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 13:59:28.522 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11970665159256
1531710:1531733:S 26 Sep 2023 13:59:29.538 * MASTER <-> REPLICA sync: receiving 27725357 bytes from master to disk
1531710:1531733:S 26 Sep 2023 14:01:00.558 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 14:01:00.606 * Background saving started by pid 1579485
1579485:1531733:C 26 Sep 2023 14:01:02.712 * DB saved on disk
1579485:1531733:C 26 Sep 2023 14:01:02.753 * RDB: 32 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 14:01:02.810 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 14:02:09.944 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 14:02:10.284 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 14:02:10.285 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 14:02:10.381 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 14:02:10.477 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 14:02:10.668 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 14:02:10.801 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11970773577918
1531710:1531733:S 26 Sep 2023 14:02:11.847 * MASTER <-> REPLICA sync: receiving 27740942 bytes from master to disk
1531710:1531733:S 26 Sep 2023 14:04:00.626 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 14:04:00.691 * Background saving started by pid 1579512
1579512:1531733:C 26 Sep 2023 14:04:02.847 * DB saved on disk
1579512:1531733:C 26 Sep 2023 14:04:02.930 * RDB: 22 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 14:04:03.081 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 14:04:54.993 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 14:04:55.360 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 14:04:55.360 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 14:04:55.456 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 14:04:55.552 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 14:04:55.743 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 14:04:55.876 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11970883154112
1531710:1531733:S 26 Sep 2023 14:04:56.845 * MASTER <-> REPLICA sync: receiving 27748746 bytes from master to disk
1531710:1531733:S 26 Sep 2023 14:07:00.560 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 14:07:00.606 * Background saving started by pid 1579545
1579545:1531733:C 26 Sep 2023 14:07:02.632 * DB saved on disk
1579545:1531733:C 26 Sep 2023 14:07:02.672 * RDB: 29 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 14:07:02.715 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 14:07:37.692 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 14:07:38.138 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 14:07:38.138 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 14:07:38.261 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 14:07:38.384 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 14:07:38.625 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 14:07:38.784 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11970992183267
1531710:1531733:S 26 Sep 2023 14:07:39.791 * MASTER <-> REPLICA sync: receiving 27760472 bytes from master to disk
1531710:1531733:S 26 Sep 2023 14:09:06.698 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 14:09:06.774 * Background saving started by pid 1579568
1579568:1531733:C 26 Sep 2023 14:09:08.754 * DB saved on disk
1579568:1531733:C 26 Sep 2023 14:09:08.795 * RDB: 18 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 14:09:08.930 * Background saving terminated with success
1531710:1531733:S 26 Sep 2023 14:10:18.709 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 26 Sep 2023 14:10:18.886 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 26 Sep 2023 14:10:18.886 * MASTER <-> REPLICA sync started
1531710:1531733:S 26 Sep 2023 14:10:18.982 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 26 Sep 2023 14:10:19.078 * Master replied to PING, replication can continue...
1531710:1531733:S 26 Sep 2023 14:10:19.269 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 26 Sep 2023 14:10:19.402 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:11971098194546
1531710:1531733:S 26 Sep 2023 14:10:20.410 * MASTER <-> REPLICA sync: receiving 27760987 bytes from master to disk
1531710:1531733:S 26 Sep 2023 14:12:00.720 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 26 Sep 2023 14:12:00.781 * Background saving started by pid 1579595
1579595:1531733:C 26 Sep 2023 14:12:03.009 * DB saved on disk
1579595:1531733:C 26 Sep 2023 14:12:03.050 * RDB: 27 MB of memory used by copy-on-write
1531710:1531733:S 26 Sep 2023 14:12:03.112 * Background saving terminated with success

I then tried to set slaveof no one on the machine which kept failing to resync, it went to about 60% sync then started again. This loop continued. This is what we see in the logs when this happens:

1531710:1531733:S 28 Sep 2023 14:27:46.483 * Master replied to PING, replication can continue...
1531710:1531733:S 28 Sep 2023 14:27:46.696 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 28 Sep 2023 14:27:46.828 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:12087596259051
1531710:1531733:S 28 Sep 2023 14:27:47.835 * MASTER <-> REPLICA sync: receiving 28143794 bytes from master to disk
1531710:1531734:S 28 Sep 2023 14:29:28.489 # Setting secondary replication ID to bef39c29b7a29ef5c799315adb6164a9220ce157, valid up to offset: 226438441617. New replication ID is 6a1b5e05f1dedc996a32c87f40b4ef09403f172b
1531710:1531734:M 28 Sep 2023 14:29:28.489 * MASTER MODE enabled (user request from 'id=1405 addr=10.1.49.50:35732 laddr=10.1.49.50:6379 fd=1001 name= age=12 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=34 qbuf-free=40920 argv-mem=12 obl=0 oll=0 omem=0 tot-mem=61476 events=r cmd=slaveof user=default redir=-1')
1531710:1531734:S 28 Sep 2023 14:29:31.061 * 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.
1531710:1531734:S 28 Sep 2023 14:29:31.062 * REPLICAOF 10.1.143.50:6379 enabled (user request from 'id=1405 addr=10.1.49.50:35732 laddr=10.1.49.50:6379 fd=1001 name= age=15 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=45 qbuf-free=40909 argv-mem=22 obl=0 oll=0 omem=0 tot-mem=61486 events=r cmd=slaveof user=default redir=-1')
1531710:1531733:S 28 Sep 2023 14:29:31.594 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 28 Sep 2023 14:29:31.595 * MASTER <-> REPLICA sync started
1531710:1531733:S 28 Sep 2023 14:29:31.699 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 28 Sep 2023 14:29:31.795 * Master replied to PING, replication can continue...
1531710:1531733:S 28 Sep 2023 14:29:31.985 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 28 Sep 2023 14:29:32.120 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:12087667170575
1531710:1531733:S 28 Sep 2023 14:29:32.120 * Discarding previously cached master state.
1531710:1531733:S 28 Sep 2023 14:29:33.130 * MASTER <-> REPLICA sync: receiving 28143862 bytes from master to disk
1531710:1531733:S 28 Sep 2023 14:30:40.822 * 10000 changes in 60 seconds. Saving...
1531710:1531733:S 28 Sep 2023 14:30:40.923 * Background saving started by pid 1613242
1613242:1531733:C 28 Sep 2023 14:30:43.973 * DB saved on disk
1613242:1531733:C 28 Sep 2023 14:30:44.034 * RDB: 25 MB of memory used by copy-on-write
1531710:1531733:S 28 Sep 2023 14:30:44.168 * Background saving terminated with success
1531710:1531733:S 28 Sep 2023 14:32:14.322 # I/O error trying to sync with MASTER: connection lost
1531710:1531733:S 28 Sep 2023 14:32:14.856 * Connecting to MASTER 10.1.143.50:6379
1531710:1531733:S 28 Sep 2023 14:32:14.856 * MASTER <-> REPLICA sync started
1531710:1531733:S 28 Sep 2023 14:32:14.951 * Non blocking connect for SYNC fired the event.
1531710:1531733:S 28 Sep 2023 14:32:15.046 * Master replied to PING, replication can continue...
1531710:1531733:S 28 Sep 2023 14:32:15.236 * Partial resynchronization not possible (no cached master)
1531710:1531733:S 28 Sep 2023 14:32:15.367 * Full resync from master: af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a:12087775398340
1531710:1531733:S 28 Sep 2023 14:32:16.432 * MASTER <-> REPLICA sync: receiving 28148113 bytes from master to disk
1531710:1531734:S 28 Sep 2023 14:32:46.502 # Setting secondary replication ID to 1b68bfa06c1cd2d7556e20bd2de7d783a5895abe, valid up to offset: 226570946726. New replication ID is b7be17ac96af1fdda04bb4f61f0ba932cf409742
1531710:1531734:M 28 Sep 2023 14:32:46.502 * MASTER MODE enabled (user request from 'id=1411 addr=10.1.49.50:44898 laddr=10.1.49.50:6379 fd=1001 name= age=5 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=34 qbuf-free=40920 argv-mem=12 obl=0 oll=0 omem=0 tot-mem=61476 events=r cmd=slaveof user=default redir=-1')```

digipigeon avatar Sep 28 '23 14:09 digipigeon

And what's happening on the MASTER 10.1.143.50 logs?

artarik avatar Sep 28 '23 15:09 artarik

Please see below:

849378:807914:C 26 Sep 2023 13:10:01.599 * DB saved on disk
849378:807914:C 26 Sep 2023 13:10:01.630 * RDB: 4 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:10:01.709 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:13:01.745 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:13:01.778 * Background saving started by pid 849395
849395:807914:C 26 Sep 2023 13:13:02.674 * DB saved on disk
849395:807914:C 26 Sep 2023 13:13:02.705 * RDB: 3 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:13:02.786 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:15:40.345 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:15:40.378 * Background saving started by pid 849409
849409:807914:C 26 Sep 2023 13:15:41.263 * DB saved on disk
849409:807914:C 26 Sep 2023 13:15:41.295 * RDB: 1 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:15:41.384 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:18:01.437 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:18:01.473 * Background saving started by pid 849425
849425:807914:C 26 Sep 2023 13:18:02.375 * DB saved on disk
849425:807914:C 26 Sep 2023 13:18:02.407 * RDB: 4 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:18:02.480 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:21:01.765 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:21:01.797 * Background saving started by pid 849444
849444:807914:C 26 Sep 2023 13:21:02.698 * DB saved on disk
849444:807914:C 26 Sep 2023 13:21:02.730 * RDB: 3 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:21:02.803 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:23:45.084 * Replica 10.1.143.61:6378 asks for synchronization
807900:807914:S 26 Sep 2023 13:23:45.084 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for '5a08f8e8954f123f5a13cdc50437b7d0f8fc2cf9', my replication IDs are 'af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a' and '0000000000000000000000000000000000000000')
807900:807914:S 26 Sep 2023 13:23:45.084 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:23:45.119 * Background saving started by pid 849460
849460:807914:C 26 Sep 2023 13:23:46.017 * DB saved on disk
849460:807914:C 26 Sep 2023 13:23:46.050 * RDB: 2 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:23:46.127 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:23:50.979 * Synchronization with replica 10.1.143.61:6378 succeeded
807900:807914:S 26 Sep 2023 13:24:30.771 * Replica 10.1.143.62:6378 asks for synchronization
807900:807914:S 26 Sep 2023 13:24:30.771 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for '5a08f8e8954f123f5a13cdc50437b7d0f8fc2cf9', my replication IDs are 'af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a' and '0000000000000000000000000000000000000000')
807900:807914:S 26 Sep 2023 13:24:30.771 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:24:30.806 * Background saving started by pid 849511
849511:807914:C 26 Sep 2023 13:24:31.697 * DB saved on disk
849511:807914:C 26 Sep 2023 13:24:31.731 * RDB: 2 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:24:31.845 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:24:34.970 * Synchronization with replica 10.1.143.62:6378 succeeded
807900:807914:S 26 Sep 2023 13:24:56.007 * Replica 10.1.143.63:6378 asks for synchronization
807900:807914:S 26 Sep 2023 13:24:56.007 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for '5a08f8e8954f123f5a13cdc50437b7d0f8fc2cf9', my replication IDs are 'af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a' and '0000000000000000000000000000000000000000')
807900:807914:S 26 Sep 2023 13:24:56.007 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:24:56.041 * Background saving started by pid 849512
849512:807914:C 26 Sep 2023 13:24:56.942 * DB saved on disk
849512:807914:C 26 Sep 2023 13:24:56.975 * RDB: 4 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:24:57.054 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:25:00.474 * Synchronization with replica 10.1.143.63:6378 succeeded
807900:807914:S 26 Sep 2023 13:25:26.607 * Replica 10.1.143.64:6378 asks for synchronization
807900:807914:S 26 Sep 2023 13:25:26.607 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for '5a08f8e8954f123f5a13cdc50437b7d0f8fc2cf9', my replication IDs are 'af4297cb9f47db9cb5ef2f4ce172c09dfa948c8a' and '0000000000000000000000000000000000000000')
807900:807914:S 26 Sep 2023 13:25:26.607 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:25:26.642 * Background saving started by pid 849517
849517:807914:C 26 Sep 2023 13:25:27.551 * DB saved on disk
849517:807914:C 26 Sep 2023 13:25:27.584 * RDB: 5 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:25:27.669 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:25:32.535 * Synchronization with replica 10.1.143.64:6378 succeeded
807900:807914:S 26 Sep 2023 13:26:58.199 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:26:58.201 # Client id=10 addr=10.1.49.50:45545 laddr=10.1.143.50:6379 fd=19 name= age=167017 idle=1 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1560 omem=99967552 tot-mem=99988064 events=rw cmd=replconf user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:26:59.656 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:26:59.656 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:26:59.656 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:26:59.693 * Background saving started by pid 849524
849524:807914:C 26 Sep 2023 13:27:00.607 * DB saved on disk
849524:807914:C 26 Sep 2023 13:27:00.639 * RDB: 4 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:27:00.721 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:29:00.710 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:29:00.745 * Background saving started by pid 849539
849539:807914:C 26 Sep 2023 13:29:01.646 * DB saved on disk
849539:807914:C 26 Sep 2023 13:29:01.680 * RDB: 5 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:29:01.754 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:29:38.004 # Client id=15 addr=10.1.49.50:44531 laddr=10.1.143.50:6379 fd=19 name= age=159 idle=159 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1703 omem=106827688 tot-mem=106848200 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:29:38.004 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:29:39.769 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:29:39.769 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:29:39.769 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:29:39.805 * Background saving started by pid 849540
849540:807914:C 26 Sep 2023 13:29:40.698 * DB saved on disk
849540:807914:C 26 Sep 2023 13:29:40.732 * RDB: 3 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:29:40.837 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:32:00.669 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:32:00.705 * Background saving started by pid 849552
849552:807914:C 26 Sep 2023 13:32:01.606 * DB saved on disk
849552:807914:C 26 Sep 2023 13:32:01.641 * RDB: 5 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:32:01.712 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:32:19.045 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:32:19.053 # Client id=16 addr=10.1.49.50:40565 laddr=10.1.143.50:6379 fd=19 name= age=160 idle=160 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=13969 oll=1725 omem=107545016 tot-mem=107565528 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:32:20.431 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:32:20.431 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:32:20.431 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:32:20.467 * Background saving started by pid 849560
849560:807914:C 26 Sep 2023 13:32:21.351 * DB saved on disk
849560:807914:C 26 Sep 2023 13:32:21.385 * RDB: 6 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:32:21.510 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:35:00.755 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:35:00.790 * Background saving started by pid 849573
807900:807914:S 26 Sep 2023 13:35:01.092 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:35:01.093 # Client id=17 addr=10.1.49.50:43589 laddr=10.1.143.50:6379 fd=19 name= age=161 idle=161 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=12637 oll=1714 omem=107344048 tot-mem=107364560 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
849573:807914:C 26 Sep 2023 13:35:01.691 * DB saved on disk
849573:807914:C 26 Sep 2023 13:35:01.727 * RDB: 8 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:35:01.797 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:35:02.955 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:35:02.955 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:35:02.956 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:35:02.992 * Background saving started by pid 849574
849574:807914:C 26 Sep 2023 13:35:03.900 * DB saved on disk
849574:807914:C 26 Sep 2023 13:35:03.933 * RDB: 16 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:35:04.014 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:37:45.181 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:37:45.183 # Client id=18 addr=10.1.49.50:46499 laddr=10.1.143.50:6379 fd=19 name= age=163 idle=163 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1671 omem=106556584 tot-mem=106577096 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:37:48.267 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:37:48.267 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:37:48.267 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:37:48.306 * Background saving started by pid 849587
849587:807914:C 26 Sep 2023 13:37:49.214 * DB saved on disk
849587:807914:C 26 Sep 2023 13:37:49.249 * RDB: 15 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:37:49.313 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:40:00.861 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:40:00.897 * Background saving started by pid 849600
849600:807914:C 26 Sep 2023 13:40:01.798 * DB saved on disk
849600:807914:C 26 Sep 2023 13:40:01.833 * RDB: 5 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:40:01.905 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:40:28.093 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:40:28.100 # Client id=19 addr=10.1.49.50:34583 laddr=10.1.143.50:6379 fd=19 name= age=161 idle=160 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1705 omem=107724760 tot-mem=107745272 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:40:30.729 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:40:30.730 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:40:30.730 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:40:30.766 * Background saving started by pid 849605
849605:807914:C 26 Sep 2023 13:40:31.675 * DB saved on disk
849605:807914:C 26 Sep 2023 13:40:31.710 * RDB: 8 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:40:31.829 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:43:01.041 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:43:01.076 * Background saving started by pid 849619
849619:807914:C 26 Sep 2023 13:43:01.969 * DB saved on disk
849619:807914:C 26 Sep 2023 13:43:02.003 * RDB: 5 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:43:02.084 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:43:09.006 # Client id=20 addr=10.1.49.50:38589 laddr=10.1.143.50:6379 fd=19 name= age=159 idle=159 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=11441 oll=1696 omem=106827520 tot-mem=106848032 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:43:09.006 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:43:10.772 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:43:10.772 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:43:10.772 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:43:10.808 * Background saving started by pid 849620
849620:807914:C 26 Sep 2023 13:43:11.707 * DB saved on disk
849620:807914:C 26 Sep 2023 13:43:11.741 * RDB: 5 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:43:11.858 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:45:53.010 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:45:53.012 # Client id=21 addr=10.1.49.50:44283 laddr=10.1.143.50:6379 fd=19 name= age=163 idle=163 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=10295 oll=1687 omem=108027432 tot-mem=108047944 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:45:54.945 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:45:54.946 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:45:54.946 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:45:54.982 * Background saving started by pid 849635
849635:807914:C 26 Sep 2023 13:45:55.871 * DB saved on disk
849635:807914:C 26 Sep 2023 13:45:55.905 * RDB: 11 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:45:55.970 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:48:00.797 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:48:00.831 * Background saving started by pid 849651
849651:807914:C 26 Sep 2023 13:48:01.716 * DB saved on disk
849651:807914:C 26 Sep 2023 13:48:01.751 * RDB: 5 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:48:01.838 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:48:34.022 # Client id=22 addr=10.1.49.50:42399 laddr=10.1.143.50:6379 fd=19 name= age=160 idle=160 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=15873 oll=1697 omem=107036440 tot-mem=107056952 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:48:34.022 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:48:36.148 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:48:36.148 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:48:36.148 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:48:36.185 * Background saving started by pid 849652
849652:807914:C 26 Sep 2023 13:48:37.088 * DB saved on disk
849652:807914:C 26 Sep 2023 13:48:37.123 * RDB: 6 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:48:37.201 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:51:01.668 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:51:01.703 * Background saving started by pid 849670
849670:807914:C 26 Sep 2023 13:51:02.597 * DB saved on disk
849670:807914:C 26 Sep 2023 13:51:02.631 * RDB: 4 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:51:02.710 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:51:14.023 # Client id=23 addr=10.1.49.50:39521 laddr=10.1.143.50:6379 fd=19 name= age=159 idle=158 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=9222 oll=1691 omem=106008200 tot-mem=106028712 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:51:14.024 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:51:16.414 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:51:16.414 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:51:16.414 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:51:16.451 * Background saving started by pid 849675
849675:807914:C 26 Sep 2023 13:51:17.353 * DB saved on disk
849675:807914:C 26 Sep 2023 13:51:17.387 * RDB: 8 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:51:17.457 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:54:00.061 # Client id=24 addr=10.1.49.50:33119 laddr=10.1.143.50:6379 fd=19 name= age=164 idle=164 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1726 omem=109801936 tot-mem=109822448 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:54:00.061 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:54:00.716 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:54:00.754 * Background saving started by pid 849692
849692:807914:C 26 Sep 2023 13:54:01.670 * DB saved on disk
849692:807914:C 26 Sep 2023 13:54:01.706 * RDB: 6 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:54:01.759 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:54:01.874 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:54:01.874 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:54:01.875 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:54:01.912 * Background saving started by pid 849693
849693:807914:C 26 Sep 2023 13:54:02.816 * DB saved on disk
849693:807914:C 26 Sep 2023 13:54:02.851 * RDB: 3 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:54:02.969 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:56:44.050 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:56:44.052 # Client id=25 addr=10.1.49.50:38539 laddr=10.1.143.50:6379 fd=25 name= age=163 idle=163 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1700 omem=108203872 tot-mem=108224384 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:56:47.086 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:56:47.086 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:56:47.086 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:56:47.121 * Background saving started by pid 849703
849703:807914:C 26 Sep 2023 13:56:48.019 * DB saved on disk
849703:807914:C 26 Sep 2023 13:56:48.052 * RDB: 12 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:56:48.177 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:59:03.565 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 13:59:03.601 * Background saving started by pid 849712
849712:807914:C 26 Sep 2023 13:59:04.504 * DB saved on disk
849712:807914:C 26 Sep 2023 13:59:04.539 * RDB: 3 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:59:04.610 * Background saving terminated with success
807900:807914:S 26 Sep 2023 13:59:27.166 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 13:59:27.174 # Client id=26 addr=10.1.49.50:36821 laddr=10.1.143.50:6379 fd=19 name= age=161 idle=160 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1729 omem=107536920 tot-mem=107557432 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 13:59:28.439 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 13:59:28.439 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 13:59:28.439 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 13:59:28.474 * Background saving started by pid 849713
849713:807914:C 26 Sep 2023 13:59:29.394 * DB saved on disk
849713:807914:C 26 Sep 2023 13:59:29.427 * RDB: 10 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 13:59:29.490 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:02:00.787 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 14:02:00.820 * Background saving started by pid 849727
849727:807914:C 26 Sep 2023 14:02:01.730 * DB saved on disk
849727:807914:C 26 Sep 2023 14:02:01.767 * RDB: 5 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:02:01.828 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:02:09.045 # Client id=27 addr=10.1.49.50:34237 laddr=10.1.143.50:6379 fd=19 name= age=161 idle=161 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1716 omem=108343520 tot-mem=108364032 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:02:09.045 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:02:10.717 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:02:10.717 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:02:10.717 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:02:10.753 * Background saving started by pid 849728
849728:807914:C 26 Sep 2023 14:02:11.642 * DB saved on disk
849728:807914:C 26 Sep 2023 14:02:11.676 * RDB: 4 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:02:11.800 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:04:54.175 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:04:54.177 # Client id=28 addr=10.1.49.50:41607 laddr=10.1.143.50:6379 fd=19 name= age=164 idle=164 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=13174 oll=1717 omem=109641976 tot-mem=109662488 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:04:55.792 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:04:55.792 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:04:55.792 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:04:55.828 * Background saving started by pid 849739
849739:807914:C 26 Sep 2023 14:04:56.714 * DB saved on disk
849739:807914:C 26 Sep 2023 14:04:56.748 * RDB: 2 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:04:56.796 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:07:01.082 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 14:07:01.118 * Background saving started by pid 849749
849749:807914:C 26 Sep 2023 14:07:02.013 * DB saved on disk
849749:807914:C 26 Sep 2023 14:07:02.048 * RDB: 5 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:07:02.125 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:07:37.015 # Client id=29 addr=10.1.49.50:43649 laddr=10.1.143.50:6379 fd=19 name= age=162 idle=162 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=10977 oll=1704 omem=107708352 tot-mem=107728864 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:07:37.015 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:07:38.699 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:07:38.699 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:07:38.699 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:07:38.736 * Background saving started by pid 849751
849751:807914:C 26 Sep 2023 14:07:39.649 * DB saved on disk
849751:807914:C 26 Sep 2023 14:07:39.681 * RDB: 8 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:07:39.743 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:10:00.975 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 14:10:01.008 * Background saving started by pid 849760
849760:807914:C 26 Sep 2023 14:10:01.903 * DB saved on disk
849760:807914:C 26 Sep 2023 14:10:01.939 * RDB: 4 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:10:02.016 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:10:18.034 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:10:18.042 # Client id=30 addr=10.1.49.50:43169 laddr=10.1.143.50:6379 fd=19 name= age=160 idle=160 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1696 omem=106036992 tot-mem=106057504 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:10:19.318 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:10:19.318 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:10:19.318 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:10:19.355 * Background saving started by pid 849761
849761:807914:C 26 Sep 2023 14:10:20.269 * DB saved on disk
849761:807914:C 26 Sep 2023 14:10:20.304 * RDB: 10 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:10:20.362 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:12:58.001 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:12:58.003 # Client id=31 addr=10.1.49.50:33543 laddr=10.1.143.50:6379 fd=19 name= age=159 idle=159 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1660 omem=106417056 tot-mem=106437568 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:12:59.969 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:12:59.969 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:12:59.969 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:13:00.008 * Background saving started by pid 849773
849773:807914:C 26 Sep 2023 14:13:00.904 * DB saved on disk
849773:807914:C 26 Sep 2023 14:13:00.938 * RDB: 9 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:13:01.024 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:15:01.392 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 14:15:01.428 * Background saving started by pid 849780
849780:807914:C 26 Sep 2023 14:15:02.314 * DB saved on disk
849780:807914:C 26 Sep 2023 14:15:02.348 * RDB: 3 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:15:02.435 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:15:39.001 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:15:39.010 # Client id=32 addr=10.1.49.50:36661 laddr=10.1.143.50:6379 fd=19 name= age=160 idle=160 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1669 omem=104623224 tot-mem=104643736 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:15:41.717 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:15:41.717 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:15:41.717 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:15:41.753 * Background saving started by pid 849783
849783:807914:C 26 Sep 2023 14:15:42.669 * DB saved on disk
849783:807914:C 26 Sep 2023 14:15:42.703 * RDB: 17 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:15:42.762 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:18:00.876 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 14:18:00.911 * Background saving started by pid 849794
849794:807914:C 26 Sep 2023 14:18:01.808 * DB saved on disk
849794:807914:C 26 Sep 2023 14:18:01.844 * RDB: 4 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:18:01.917 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:18:22.028 # Client id=33 addr=10.1.49.50:33417 laddr=10.1.143.50:6379 fd=19 name= age=161 idle=161 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1732 omem=107672160 tot-mem=107692672 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:18:22.028 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:18:23.688 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:18:23.688 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:18:23.688 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:18:23.725 * Background saving started by pid 849795
849795:807914:C 26 Sep 2023 14:18:24.627 * DB saved on disk
849795:807914:C 26 Sep 2023 14:18:24.660 * RDB: 5 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:18:24.782 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:21:01.137 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 14:21:01.173 * Background saving started by pid 849804
849804:807914:C 26 Sep 2023 14:21:02.074 * DB saved on disk
849804:807914:C 26 Sep 2023 14:21:02.109 * RDB: 3 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:21:02.183 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:21:04.096 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:21:04.104 # Client id=34 addr=10.1.49.50:45929 laddr=10.1.143.50:6379 fd=19 name= age=161 idle=161 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1685 omem=105266680 tot-mem=105287192 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:21:06.157 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:21:06.157 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:21:06.157 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:21:06.193 * Background saving started by pid 849805
849805:807914:C 26 Sep 2023 14:21:07.101 * DB saved on disk
849805:807914:C 26 Sep 2023 14:21:07.135 * RDB: 6 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:21:07.228 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:23:47.015 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:23:47.017 # Client id=35 addr=10.1.49.50:37669 laddr=10.1.143.50:6379 fd=19 name= age=162 idle=161 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1691 omem=107568776 tot-mem=107589288 events=rw cmd=psync user=default redir=-1 closed for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:23:48.520 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:23:48.520 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:23:48.520 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:23:48.557 * Background saving started by pid 849815
849815:807914:C 26 Sep 2023 14:23:49.476 * DB saved on disk
849815:807914:C 26 Sep 2023 14:23:49.510 * RDB: 8 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:23:49.565 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:26:00.927 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 14:26:00.963 * Background saving started by pid 849821
849821:807914:C 26 Sep 2023 14:26:01.858 * DB saved on disk
849821:807914:C 26 Sep 2023 14:26:01.894 * RDB: 4 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:26:01.970 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:26:29.016 # Client id=36 addr=10.1.49.50:44821 laddr=10.1.143.50:6379 fd=19 name= age=161 idle=161 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1727 omem=108700136 tot-mem=108720648 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:26:29.016 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:26:31.063 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:26:31.063 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:26:31.063 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:26:31.099 * Background saving started by pid 849823
849823:807914:C 26 Sep 2023 14:26:31.997 * DB saved on disk
849823:807914:C 26 Sep 2023 14:26:32.030 * RDB: 12 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:26:32.119 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:29:00.895 * 10000 changes in 60 seconds. Saving...
807900:807914:S 26 Sep 2023 14:29:00.930 * Background saving started by pid 849832
849832:807914:C 26 Sep 2023 14:29:01.823 * DB saved on disk
849832:807914:C 26 Sep 2023 14:29:01.858 * RDB: 3 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:29:01.937 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:29:11.123 # Client id=37 addr=10.1.49.50:32841 laddr=10.1.143.50:6379 fd=19 name= age=161 idle=160 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=8104 oll=1704 omem=106786752 tot-mem=106807264 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:29:11.124 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:29:13.508 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:29:13.508 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:29:13.508 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:29:13.544 * Background saving started by pid 849833
849833:807914:C 26 Sep 2023 14:29:14.452 * DB saved on disk
849833:807914:C 26 Sep 2023 14:29:14.485 * RDB: 19 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:29:14.551 * Background saving terminated with success
807900:807914:S 26 Sep 2023 14:31:53.137 # Client id=38 addr=10.1.49.50:39311 laddr=10.1.143.50:6379 fd=19 name= age=160 idle=160 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=1702 omem=107794320 tot-mem=107814832 events=rw cmd=psync user=default redir=-1 scheduled to be closed ASAP for overcoming of output buffer limits.
807900:807914:S 26 Sep 2023 14:31:53.138 # Connection with replica 10.1.49.50:6379 lost.
807900:807914:S 26 Sep 2023 14:31:56.946 * Replica 10.1.49.50:6379 asks for synchronization
807900:807914:S 26 Sep 2023 14:31:56.946 * Full resync requested by replica 10.1.49.50:6379
807900:807914:S 26 Sep 2023 14:31:56.946 * Starting BGSAVE for SYNC with target: disk
807900:807914:S 26 Sep 2023 14:31:56.982 * Background saving started by pid 849843
849843:807914:C 26 Sep 2023 14:31:57.894 * DB saved on disk
849843:807914:C 26 Sep 2023 14:31:57.929 * RDB: 14 MB of memory used by copy-on-write
807900:807914:S 26 Sep 2023 14:31:58.037 * Background saving terminated with success

digipigeon avatar Sep 30 '23 16:09 digipigeon