[CRASH] Crash during upgrade from Redis 6.2.14 to Valkey 8.0.2

[esebole]

Crash report

=== VALKEY BUG REPORT START: Cut & paste starting from here ===
19:S valkey 8.0.2 crashed by signal: 11, si_code: 1
19:S Accessing address: 0x30
19:S Crashed running the instruction at: 0x7fc3fd6a41b8
------ STACK TRACE ------
EIP:
/usr/lib64/libssl.so.3(+0x3e1b8)[0x7fc3fd6a41b8]
21 bio_aof
/lib64/libc.so.6(+0xa3c4e)[0x7fc3fcf7bc4e]
/lib64/libc.so.6(pthread_cond_wait+0x202)[0x7fc3fcf7e890]
redis-server *:6380 [cluster](bioProcessBackgroundJobs+0x18e)[0x53aa0e]
/lib64/libc.so.6(+0xa758c)[0x7fc3fcf7f58c]
/lib64/libc.so.6(+0x12ea28)[0x7fc3fd006a28]
20 bio_close_file
/lib64/libc.so.6(+0xa3c4e)[0x7fc3fcf7bc4e]
/lib64/libc.so.6(pthread_cond_wait+0x202)[0x7fc3fcf7e890]
redis-server *:6380 [cluster](bioProcessBackgroundJobs+0x18e)[0x53aa0e]
/lib64/libc.so.6(+0xa758c)[0x7fc3fcf7f58c]
/lib64/libc.so.6(+0x12ea28)[0x7fc3fd006a28]
22 bio_lazy_free
/lib64/libc.so.6(+0xa3c4e)[0x7fc3fcf7bc4e]
/lib64/libc.so.6(pthread_cond_wait+0x202)[0x7fc3fcf7e890]
redis-server *:6380 [cluster](bioProcessBackgroundJobs+0x18e)[0x53aa0e]
/lib64/libc.so.6(+0xa758c)[0x7fc3fcf7f58c]
/lib64/libc.so.6(+0x12ea28)[0x7fc3fd006a28]
19 redis-server *
/lib64/libc.so.6(+0x57900)[0x7fc3fcf2f900]
/usr/lib64/libssl.so.3(+0x3e1b8)[0x7fc3fd6a41b8]
/usr/lib64/libssl.so.3(SSL_read+0x25)[0x7fc3fd6a4363]
redis-server *:6380 [cluster][0x5bd130]
redis-server *:6380 [cluster][0x53b308]
redis-server *:6380 [cluster](rdbLoadLzfStringObject+0xf9)[0x4c5729]
redis-server *:6380 [cluster](rdbLoadObject+0x88f)[0x4cb84f]
redis-server *:6380 [cluster](rdbLoadRioWithLoadingCtx+0x8b3)[0x4ce923]
redis-server *:6380 [cluster](readSyncBulkPayload+0x290)[0x4bfb20]
redis-server *:6380 [cluster][0x5af04e]
redis-server *:6380 [cluster][0x5b94af]
redis-server *:6380 [cluster][0x5ba22c]
redis-server *:6380 [cluster](beforeSleep+0x66)[0x4706d6]
redis-server *:6380 [cluster](aeMain+0x2f)[0x4686af]
redis-server *:6380 [cluster](main+0x4a7)[0x45e157]
/lib64/libc.so.6(+0x40e6c)[0x7fc3fcf18e6c]
/lib64/libc.so.6(__libc_start_main+0x87)[0x7fc3fcf18f35]
redis-server *:6380 [cluster](_start+0x21)[0x45e781]
4/4 expected stacktraces.
------ STACK TRACE DONE ------
------ REGISTERS ------
19:S 09 Apr 2025 13:33:46.710 # 
RAX:0000000000000000 RBX:0000000000002e3b
RCX:00007ffd88403df0 RDX:0000000000002e3b
RDI:0000000000000000 RSI:00007fc3fcbf21c4
RBP:00007ffd88403e40 RSP:00007ffd88403d90
R8 :00000000000021bf R9 :0000000000004000
R10:00007fc3fceaf968 R11:00007fc3fca067c0
R12:00007fc3f72aa260 R13:00007fc3fcbf21c4
R14:00000000000021bf R15:000000000000036b
RIP:00007fc3fd6a41b8 EFL:0000000000010246
CSGSFS:002b000000000033
19:S hide-user-data-from-log is on, skip logging stack content to avoid spilling user data.
------ INFO OUTPUT ------
# Server
redis_version:7.2.4
server_name:valkey
valkey_version:8.0.2
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:ce4c0d418411034b
server_mode:cluster
os:Linux 5.14.21-150500.55.68.1.28265.1.PTF.1199769-default x86_64
arch_bits:64
monotonic_clock:POSIX clock_gettime
multiplexing_api:epoll
gcc_version:13.3.0
process_id:19
process_supervised:no
run_id:68d6acb670b888463f627ce3e84da3badae56773
tcp_port:6380
server_time_usec:1744205626701774
uptime_in_seconds:9
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:16152378
executable:/redis-server
config_file:/redis-conf/redis.conf
io_threads_active:0
availability_zone:
listener2:name=tls,bind=*,bind=-::*,port=6380
# Clients
connected_clients:16
cluster_connections:14
maxclients:8192
client_recent_max_input_buffer:20480
client_recent_max_output_buffer:0
blocked_clients:0
tracking_clients:0
pubsub_clients:0
watching_clients:0
clients_in_timeout_table:0
total_watched_keys:0
total_blocking_keys:0
total_blocking_keys_on_nokey:0
# Memory
used_memory:38551408
used_memory_human:36.77M
used_memory_rss:72822784
used_memory_rss_human:69.45M
used_memory_peak:53466192
used_memory_peak_human:50.99M
used_memory_peak_perc:72.10%
used_memory_overhead:2736720
used_memory_startup:2690808
used_memory_dataset:35814688
used_memory_dataset_perc:99.87%
allocator_allocated:39040400
allocator_active:39329792
allocator_resident:62148608
allocator_muzzy:0
total_system_memory:103344246784
total_system_memory_human:96.25G
used_memory_lua:31744
used_memory_vm_eval:31744
used_memory_lua_human:31.00K
used_memory_scripts_eval:0
number_of_cached_scripts:0
number_of_functions:0
number_of_libraries:0
used_memory_vm_functions:33792
used_memory_vm_total:65536
used_memory_vm_total_human:64.00K
used_memory_functions:184
used_memory_scripts:184
used_memory_scripts_human:184B
maxmemory:4294967296
maxmemory_human:4.00G
maxmemory_policy:noeviction
allocator_frag_ratio:1.01
allocator_frag_bytes:289392
allocator_rss_ratio:1.58
allocator_rss_bytes:22818816
rss_overhead_ratio:1.17
rss_overhead_bytes:10674176
mem_fragmentation_ratio:1.89
mem_fragmentation_bytes:34277704
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_total_replication_buffers:0
mem_clients_slaves:0
mem_clients_normal:30720
mem_cluster_links:15008
mem_aof_buffer:0
mem_allocator:jemalloc-5.3.0
mem_overhead_db_hashtable_rehashing:0
active_defrag_running:0
lazyfree_pending_objects:0
lazyfreed_objects:78886
# Persistence
loading:1
async_loading:0
current_cow_peak:0
current_cow_size:0
current_cow_size_age:0
current_fork_perc:0.00
current_save_keys_processed:0
current_save_keys_total:0
rdb_changes_since_last_save:0
rdb_bgsave_in_progress:0
rdb_last_save_time:1744205617
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:-1
rdb_saves:0
rdb_last_cow_size:0
rdb_last_load_keys_expired:0
rdb_last_load_keys_loaded:69311
aof_enabled:0
aof_rewrite_in_progress:0
aof_rewrite_scheduled:0
aof_last_rewrite_time_sec:-1
aof_current_rewrite_time_sec:-1
aof_last_bgrewrite_status:ok
aof_rewrites:0
aof_rewrites_consecutive_failures:0
aof_last_write_status:ok
aof_last_cow_size:0
module_fork_in_progress:0
module_fork_last_cow_size:0
loading_start_time:1744205626
loading_total_bytes:0
loading_rdb_used_mem:643997904
loading_loaded_bytes:18874300
loading_loaded_perc:2.93
loading_eta_seconds:1
# Stats
total_connections_received:26
total_commands_processed:46
instantaneous_ops_per_sec:2
total_net_input_bytes:40422579
total_net_output_bytes:14479
total_net_repl_input_bytes:40420497
total_net_repl_output_bytes:0
instantaneous_input_kbps:1421.59
instantaneous_output_kbps:1.31
instantaneous_input_repl_kbps:1421.49
instantaneous_output_repl_kbps:0.00
rejected_connections:0
sync_full:0
sync_partial_ok:0
sync_partial_err:0
expired_keys:0
expired_stale_perc:0.00
expired_time_cap_reached_count:0
expire_cycle_cpu_milliseconds:0
evicted_keys:0
evicted_clients:0
evicted_scripts:0
total_eviction_exceeded_time:0
current_eviction_exceeded_time:0
keyspace_hits:0
keyspace_misses:0
pubsub_channels:0
pubsub_patterns:0
pubsubshard_channels:0
latest_fork_usec:0
total_forks:0
migrate_cached_sockets:0
slave_expires_tracked_keys:0
active_defrag_hits:0
active_defrag_misses:0
active_defrag_key_hits:0
active_defrag_key_misses:0
total_active_defrag_time:0
current_active_defrag_time:0
tracking_total_keys:0
tracking_total_items:0
tracking_total_prefixes:0
unexpected_error_replies:0
total_error_replies:1
dump_payload_sanitizations:0
total_reads_processed:54
total_writes_processed:43
io_threaded_reads_processed:0
io_threaded_writes_processed:0
io_threaded_freed_objects:0
io_threaded_poll_processed:0
io_threaded_total_prefetch_batches:0
io_threaded_total_prefetch_entries:0
client_query_buffer_limit_disconnections:0
client_output_buffer_limit_disconnections:0
reply_buffer_shrinks:22
reply_buffer_expands:1
eventloop_cycles:383
eventloop_duration_sum:1001347
eventloop_duration_cmd_sum:2090
instantaneous_eventloop_cycles_per_sec:43
instantaneous_eventloop_duration_usec:3728
acl_access_denied_auth:0
acl_access_denied_cmd:0
acl_access_denied_key:0
acl_access_denied_channel:0
# Replication
role:slave
master_host:192.168.91.78
master_port:6380
master_link_status:down
master_last_io_seconds_ago:-1
master_sync_in_progress:0
slave_read_repl_offset:1
slave_repl_offset:1
replicas_repl_buffer_size:0
replicas_repl_buffer_peak:0
master_link_down_since_seconds:-1
slave_priority:100
slave_read_only:1
replica_announced:1
connected_slaves:0
replicas_waiting_psync:0
master_failover_state:no-failover
master_replid:d5dd966e7cb3cb88b3cba02effb485df87765a12
master_replid2:0000000000000000000000000000000000000000
master_repl_offset:0
second_repl_offset:-1
repl_backlog_active:0
repl_backlog_size:134217728
repl_backlog_first_byte_offset:0
repl_backlog_histlen:0
# CPU
used_cpu_sys:0.218966
used_cpu_user:0.795228
used_cpu_sys_children:0.000000
used_cpu_user_children:0.000000
used_cpu_sys_main_thread:0.219824
used_cpu_user_main_thread:0.755913
# Modules
# Commandstats
cmdstat_config|set:calls=8,usec=58,usec_per_call=7.25,rejected_calls=0,failed_calls=0
cmdstat_ping:calls=4,usec=8,usec_per_call=2.00,rejected_calls=1,failed_calls=0
cmdstat_hello:calls=2,usec=22,usec_per_call=11.00,rejected_calls=0,failed_calls=0
cmdstat_client|tracking:calls=5,usec=30,usec_per_call=6.00,rejected_calls=0,failed_calls=0
cmdstat_client|setname:calls=1,usec=12,usec_per_call=12.00,rejected_calls=0,failed_calls=0
cmdstat_cluster|replicate:calls=1,usec=326,usec_per_call=326.00,rejected_calls=0,failed_calls=0
cmdstat_cluster|info:calls=6,usec=321,usec_per_call=53.50,rejected_calls=0,failed_calls=0
cmdstat_cluster|nodes:calls=9,usec=939,usec_per_call=104.33,rejected_calls=0,failed_calls=0
cmdstat_cluster|set-config-epoch:calls=1,usec=27,usec_per_call=27.00,rejected_calls=0,failed_calls=0
cmdstat_cluster|slots:calls=2,usec=154,usec_per_call=77.00,rejected_calls=0,failed_calls=0
cmdstat_info:calls=7,usec=193,usec_per_call=27.57,rejected_calls=0,failed_calls=0
# Errorstats
errorstat_LOADING:count=1
# Latencystats
# Cluster
cluster_enabled:1
# Keyspace
# Cluster info
cluster_state:ok
cluster_slots_assigned:16384
cluster_slots_ok:16384
cluster_slots_pfail:0
cluster_slots_fail:0
cluster_known_nodes:8
cluster_size:3
cluster_current_epoch:11
cluster_my_epoch:11
cluster_stats_messages_ping_sent:54
cluster_stats_messages_pong_sent:60
cluster_stats_messages_sent:114
cluster_stats_messages_ping_received:46
cluster_stats_messages_pong_received:57
cluster_stats_messages_meet_received:7
cluster_stats_messages_auth-req_received:1
cluster_stats_messages_received:111
total_cluster_links_buffer_limit_exceeded:0
------ CLUSTER NODES OUTPUT ------
6f6f53c1ddad269a65a76a121b8ff271f7a52d72 192.168.34.15:0@16380,,tls-port=6380,shard-id=ba3e243c49d8d7d8fd74e980a04abe0d0621425f slave 5c2a454afa2231c4cc7f3165e71d2864dc656541 0 1744205626239 11 connected
5aa4ee89389d3c7db4ac7175cd5badd7221300d7 192.168.91.126:0@16380,,tls-port=6380,shard-id=e09fe2428cacb4425adfc43b84783f7c726023a8 master - 0 1744205626239 1 connected 0-5460
c8aee20c5d8bd7a845c7db3c6d947d62dccd5af9 192.168.34.37:0@16380,,tls-port=6380,shard-id=e09fe2428cacb4425adfc43b84783f7c726023a8 slave 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 0 1744205626239 1 connected
5c2a454afa2231c4cc7f3165e71d2864dc656541 192.168.91.78:6380@16380,,tls-port=6380,shard-id=ba3e243c49d8d7d8fd74e980a04abe0d0621425f master - 0 1744205626239 11 connected 5461-10922
3a2a5e71000337e98135529471e277b5ee6bfcb6 192.168.62.22:0@16380,,tls-port=6380,shard-id=ba3e243c49d8d7d8fd74e980a04abe0d0621425f slave 5c2a454afa2231c4cc7f3165e71d2864dc656541 0 1744205626000 11 connected
59d4a94deef7f9af2abdfa270002b1017963c053 192.168.150.232:0@16380,,tls-port=6380,shard-id=0cc56990fa1d2fa5f7fe4018be1d554f2076cce0 master - 0 1744205626239 8 connected 10923-16383
b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b 192.168.150.214:6380@16380,,tls-port=6380,shard-id=ba3e243c49d8d7d8fd74e980a04abe0d0621425f myself,slave 5c2a454afa2231c4cc7f3165e71d2864dc656541 0 0 11 connected
d010c9fb3ab0b11bee57cb33ede1b7a1fee9fd1e 192.168.62.8:0@16380,,tls-port=6380,shard-id=0cc56990fa1d2fa5f7fe4018be1d554f2076cce0 slave 59d4a94deef7f9af2abdfa270002b1017963c053 0 1744205626239 8 connected
------ CLIENT LIST OUTPUT ------
id=14 addr=192.168.34.55:52874 laddr=192.168.150.214:6380 fd=34 name=*redacted* age=6 idle=6 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=15 addr=192.168.34.41:43906 laddr=192.168.150.214:6380 fd=35 name=*redacted* age=6 idle=6 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=23 addr=192.168.150.251:42288 laddr=192.168.150.214:6380 fd=41 name=*redacted* age=3 idle=3 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=13 addr=192.168.62.5:50052 laddr=192.168.150.214:6380 fd=33 name=*redacted* age=6 idle=6 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=24 addr=192.168.91.116:39084 laddr=192.168.150.214:6380 fd=42 name=*redacted* age=3 idle=3 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=28 addr=192.168.91.123:40802 laddr=192.168.150.214:6380 fd=45 name=*redacted* age=2 idle=2 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=26 addr=192.168.150.242:42184 laddr=192.168.150.214:6380 fd=43 name=*redacted* age=3 idle=3 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=4 addr=127.0.0.1:48594 laddr=127.0.0.1:6380 fd=13 name=*redacted* age=9 idle=0 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=552 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=ping user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=298 tot-net-out=2346 tot-cmds=9
id=7 addr=192.168.91.72:48414 laddr=192.168.150.214:6380 fd=22 name=*redacted* age=7 idle=7 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=19 addr=192.168.62.35:51308 laddr=192.168.150.214:6380 fd=37 name=*redacted* age=5 idle=5 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=20 addr=192.168.150.255:49500 laddr=192.168.150.214:6380 fd=38 name=*redacted* age=4 idle=4 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=27 addr=192.168.34.13:36694 laddr=192.168.150.214:6380 fd=44 name=*redacted* age=2 idle=2 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=12 addr=192.168.150.239:41160 laddr=192.168.150.214:6380 fd=14 name=*redacted* age=6 idle=6 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=18 addr=192.168.62.33:39178 laddr=192.168.150.214:6380 fd=36 name=*redacted* age=6 idle=6 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=21 addr=192.168.34.45:38414 laddr=192.168.150.214:6380 fd=39 name=*redacted* age=4 idle=4 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
id=22 addr=192.168.91.108:57944 laddr=192.168.150.214:6380 fd=40 name=*redacted* age=4 idle=4 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=0 multi-mem=0 rbs=1024 rbp=0 obl=0 oll=0 omem=0 tot-mem=1920 events=r cmd=NULL user=*redacted* redir=-1 resp=2 lib-name= lib-ver= tot-net-in=0 tot-net-out=0 tot-cmds=0
------ MODULES INFO OUTPUT ------
------ CONFIG DEBUG OUTPUT ------
proto-max-bulk-len 512mb
lazyfree-lazy-expire yes
client-query-buffer-limit 1gb
io-threads-do-reads no
repl-diskless-sync yes
list-compress-depth 0
debug-context ""
dual-channel-replication-enabled yes
lazyfree-lazy-eviction yes
sanitize-dump-payload no
activedefrag no
lazyfree-lazy-user-del yes
lazyfree-lazy-server-del yes
repl-diskless-load swapdb
lazyfree-lazy-user-flush yes
replica-read-only yes
slave-read-only yes
io-threads 1
------ FAST MEMORY TEST ------
19:S Bio worker thread #0 terminated
19:S Bio worker thread #1 terminated
19:S Bio worker thread #2 terminated
*** Preparing to test memory region 77b000 (2293760 bytes)
*** Preparing to test memory region b00000 (2748416 bytes)
*** Preparing to test memory region 7fc3f0000000 (135168 bytes)
*** Preparing to test memory region 7fc3f5600000 (8388608 bytes)
*** Preparing to test memory region 7fc3f5e00000 (2097152 bytes)
*** Preparing to test memory region 7fc3f617f000 (61341696 bytes)
*** Preparing to test memory region 7fc3f9c00000 (8388608 bytes)
*** Preparing to test memory region 7fc3fa400000 (6291456 bytes)
*** Preparing to test memory region 7fc3fab7e000 (8388608 bytes)
*** Preparing to test memory region 7fc3fb37f000 (8388608 bytes)
*** Preparing to test memory region 7fc3fbb80000 (8388608 bytes)
*** Preparing to test memory region 7fc3fc380000 (11010048 bytes)
*** Preparing to test memory region 7fc3fceaf000 (20480 bytes)
*** Preparing to test memory region 7fc3fd0df000 (65536 bytes)
*** Preparing to test memory region 7fc3fd663000 (12288 bytes)
*** Preparing to test memory region 7fc3fd808000 (8192 bytes)
Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible.
------ DUMPING CODE AROUND EIP ------
Symbol: (null) (base: (nil))
Module: /usr/lib64/libssl.so.3 (base 0x7fc3fd666000)
$ xxd -r -p /tmp/dump.hex /tmp/dump.bin
$ objdump --adjust-vma=(nil) -D -b binary -m i386:x86-64 /tmp/dump.bin
------
=== VALKEY BUG REPORT END. Make sure to include from START to END. ===
       Please report the crash by opening an issue on github:
           https://github.com/valkey-io/valkey/issues

Additional information

OS Version: (SUSE Linux) 13.3.0
OPEN SSL Version: OpenSSL 3.1.4 24 Oct 2023 (Library: OpenSSL 3.1.4 24 Oct 2023)

Scenario description:
We do have a Redis 6.2.14 node, 3a2a, which acts as a primary pod, with 3 replicas:
- Redis 6.2.14, 6f6f, which is already connected and synced
- Valkey 8.0.2, 5c2a, which will manage to connect, sync, and will become a new Primary
- Valkey 8.0.2, b7ee, which will crash during sync

# 5c2a, Valkey Replica which managed to replicate:
2025-04-09T13:33:37.888329290Z I0409 13:33:37.888120 *173] writing instance-info
2025-04-09T13:33:37.889032713Z I0409 13:33:37.888517 *310] listening on http://0.0.0.0:8080
2025-04-09T13:33:37.915468569Z W0409 13:33:37.915291 *176] 19:C WARNING: Changing databases number from 16 to 1 since we are in cluster mode
2025-04-09T13:33:37.915512739Z I0409 13:33:37.915362 *174] 19:C oO0OoO0OoO0Oo Valkey is starting oO0OoO0OoO0Oo
2025-04-09T13:33:37.915518737Z I0409 13:33:37.915370 *174] 19:C Valkey version=8.0.2, bits=64, commit=00000000, modified=0, pid=19, just started
2025-04-09T13:33:37.915523837Z I0409 13:33:37.915375 *174] 19:C Configuration loaded
2025-04-09T13:33:37.915859958Z I0409 13:33:37.915762 *174] 19:M monotonic clock: POSIX clock_gettime
2025-04-09T13:33:37.916514413Z I0409 13:33:37.916437 *174] 19:M Running mode=cluster, port=6380.
2025-04-09T13:33:37.916582915Z W0409 13:33:37.916500 *176] 19:M WARNING: The TCP backlog setting of 65536 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 4096.
2025-04-09T13:33:37.917102771Z I0409 13:33:37.917034 *174] 19:M No cluster configuration found, I'm 5c2a454afa2231c4cc7f3165e71d2864dc656541
2025-04-09T13:33:37.925509458Z I0409 13:33:37.924691 *174] 19:M Server initialized
2025-04-09T13:33:37.925533394Z I0409 13:33:37.924729 *174] 19:M Ready to accept connections tls
2025-04-09T13:33:37.945029025Z I0409 13:33:37.944872 *327] RedisNode: started successfully
2025-04-09T13:33:37.952036735Z I0409 13:33:37.951911 *143] awaiting stop signal
2025-04-09T13:33:38.669342966Z I0409 13:33:38.668857 *174] 19:M configEpoch set to 9 via CLUSTER SET-CONFIG-EPOCH
2025-04-09T13:33:38.669447465Z I0409 13:33:38.669299 *344] 5c2a454afa2231c4cc7f3165e71d2864dc656541 192.168.91.78:6380@16380 myself,master - 0 0 9 connected
2025-04-09T13:33:38.669460581Z I0409 13:33:38.669334 *344]
2025-04-09T13:33:38.704120661Z I0409 13:33:38.703905 *174] 19:M Node c8aee20c5d8bd7a845c7db3c6d947d62dccd5af9 () is now a replica of node 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 () in shard b53f7cb14ae1edf23b620f0480cbc3b1bc1f9b4c
2025-04-09T13:33:38.722687796Z I0409 13:33:38.722494 *174] 19:M Node 6f6f53c1ddad269a65a76a121b8ff271f7a52d72 () is now a replica of node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:33:38.744499602Z I0409 13:33:38.744354 *174] 19:M Node d010c9fb3ab0b11bee57cb33ede1b7a1fee9fd1e () is now a replica of node 59d4a94deef7f9af2abdfa270002b1017963c053 () in shard 8f9f09ac07ac33b9976fad4954d08e59381b91c6
2025-04-09T13:33:39.372832066Z I0409 13:33:39.372577 *174] 19:M Successfully completed handshake with b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b ()
2025-04-09T13:33:39.372873251Z I0409 13:33:39.372644 *174] 19:M Address updated for node b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b (), now 192.168.150.214:6380
2025-04-09T13:33:39.372878912Z I0409 13:33:39.372669 *229] log catcher is delaying logging cluster state
2025-04-09T13:33:39.919443408Z I0409 13:33:39.918575 *174] 19:S Connecting to PRIMARY 192.168.62.22:6380
2025-04-09T13:33:39.919482473Z I0409 13:33:39.918628 *174] 19:S PRIMARY <-> REPLICA sync started
2025-04-09T13:33:39.919489128Z I0409 13:33:39.918648 *174] 19:S Cluster state changed: ok
2025-04-09T13:33:39.919792382Z I0409 13:33:39.919607 *344] d010c9fb3ab0b11bee57cb33ede1b7a1fee9fd1e 192.168.62.8:6380@16380 slave 59d4a94deef7f9af2abdfa270002b1017963c053 0 1744205619000 8 connected
2025-04-09T13:33:39.919804536Z I0409 13:33:39.919621 *344] 6f6f53c1ddad269a65a76a121b8ff271f7a52d72 192.168.34.15:6380@16380 slave 3a2a5e71000337e98135529471e277b5ee6bfcb6 0 1744205619000 7 connected
2025-04-09T13:33:39.919809164Z I0409 13:33:39.919625 *344] 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 192.168.91.126:6380@16380 master - 0 1744205619000 1 connected 0-5460
2025-04-09T13:33:39.919811635Z I0409 13:33:39.919629 *344] b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b 192.168.150.214:6380@16380 master - 0 1744205619441 10 connected
2025-04-09T13:33:39.919814036Z I0409 13:33:39.919632 *344] 5c2a454afa2231c4cc7f3165e71d2864dc656541 192.168.91.78:6380@16380 myself,slave 3a2a5e71000337e98135529471e277b5ee6bfcb6 0 0 7 connected
2025-04-09T13:33:39.919816425Z I0409 13:33:39.919635 *344] c8aee20c5d8bd7a845c7db3c6d947d62dccd5af9 192.168.34.37:6380@16380 slave 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 0 1744205619840 1 connected
2025-04-09T13:33:39.919820006Z I0409 13:33:39.919638 *344] 3a2a5e71000337e98135529471e277b5ee6bfcb6 192.168.62.22:6380@16380 master - 0 1744205619000 7 connected 5461-10922
2025-04-09T13:33:39.919822377Z I0409 13:33:39.919641 *344] 59d4a94deef7f9af2abdfa270002b1017963c053 192.168.150.232:6380@16380 master - 0 1744205619000 8 connected 10923-16383
2025-04-09T13:33:39.919825042Z I0409 13:33:39.919644 *344]
2025-04-09T13:33:39.920921425Z I0409 13:33:39.920813 *174] 19:S Node b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b () is no longer primary of shard 2f9fb517b1869208f71dccebdafdfc25fe3f4bb9; removed all 0 slot(s) it used to own
2025-04-09T13:33:39.920930076Z I0409 13:33:39.920848 *174] 19:S Node b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b () is now part of shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:33:39.920932619Z I0409 13:33:39.920858 *174] 19:S Node b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b () is now a replica of node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:33:39.922309876Z I0409 13:33:39.922221 *174] 19:S Non blocking connect for SYNC fired the event.
2025-04-09T13:33:39.925976022Z I0409 13:33:39.925856 *174] 19:S Primary replied to PING, replication can continue...
2025-04-09T13:33:39.927216173Z I0409 13:33:39.927115 *174] 19:S (Non critical) Primary does not understand REPLCONF VERSION: -ERR Unrecognized REPLCONF option: version
2025-04-09T13:33:39.927231215Z I0409 13:33:39.927140 *174] 19:S Partial resynchronization not possible (no cached primary)
2025-04-09T13:33:39.927419945Z I0409 13:33:39.927351 *174] 19:S Full resync from primary: d770c4ba72ff0bc96aa3db7b947dee35bf2636de:4545688946
2025-04-09T13:33:39.960801777Z I0409 13:33:39.960598 *174] 19:S PRIMARY <-> REPLICA sync: receiving streamed RDB from primary with EOF to parser
2025-04-09T13:33:39.960832161Z I0409 13:33:39.960715 *174] 19:S PRIMARY <-> REPLICA sync: Loading DB in memory
2025-04-09T13:33:39.960835918Z I0409 13:33:39.960734 *174] 19:S Loading RDB produced by Redis version 6.2.14
2025-04-09T13:33:39.960851658Z I0409 13:33:39.960740 *174] 19:S RDB age 0 seconds
2025-04-09T13:33:39.960856769Z I0409 13:33:39.960747 *174] 19:S RDB memory usage when created 614.07 Mb
2025-04-09T13:33:43.667512139Z I0409 13:33:43.667133 *293] Redis is loading the dataset in memory, passing liveness
2025-04-09T13:33:45.301535778Z I0409 13:33:45.301300 *174] 19:S Done loading RDB, keys loaded: 864066, keys expired: 0.
2025-04-09T13:33:45.301573383Z I0409 13:33:45.301335 *174] 19:S PRIMARY <-> REPLICA sync: Swapping active DB with loaded DB
2025-04-09T13:33:45.301578509Z I0409 13:33:45.301431 *174] 19:S PRIMARY <-> REPLICA sync: Discarding old DB in background
2025-04-09T13:33:45.301591659Z I0409 13:33:45.301519 *174] 19:S PRIMARY <-> REPLICA sync: Finished with success
2025-04-09T13:33:45.408562097Z I0409 13:33:45.408346 *174] 19:S Manual failover user request accepted (user request from 'id=38 addr=192.168.62.62:43726 laddr=192.168.91.78:6380 fd=28 name=*redacted* age=0 idle=0 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 watch=0 qbuf=0 qbuf-free=0 argv-mem=15 multi-mem=0 rbs=16384 rbp=16384 obl=0 oll=0 omem=0 tot-mem=17311 events=r cmd=cluster|failover user=*redacted*
redir=-1 resp=2 lib-name= lib-ver= tot-net-in=162 tot-net-out=1767 tot-cmds=3').
2025-04-09T13:33:45.408946191Z I0409 13:33:45.408806 *174] 19:S Received replication offset for paused primary manual failover: 4550895545
2025-04-09T13:33:45.896310622Z I0409 13:33:45.896111 *174] 19:S All primary replication stream processed, manual failover can start.
2025-04-09T13:33:45.896324324Z I0409 13:33:45.896146 *174] 19:S Start of election delayed for 0 milliseconds (rank #0, offset 4550895545).
2025-04-09T13:33:45.896328164Z I0409 13:33:45.896223 *174] 19:S Starting a failover election for epoch 11.
2025-04-09T13:33:45.902110775Z I0409 13:33:45.899883 *174] 19:S Failover election won: I'm the new primary.
2025-04-09T13:33:45.902144411Z I0409 13:33:45.899913 *174] 19:S configEpoch set to 11 after successful failover
2025-04-09T13:33:45.902149988Z I0409 13:33:45.899921 *174] 19:M Connection with primary lost.
2025-04-09T13:33:45.902154308Z I0409 13:33:45.899929 *174] 19:M Caching the disconnected primary state.
2025-04-09T13:33:45.903598677Z I0409 13:33:45.903463 *344] d010c9fb3ab0b11bee57cb33ede1b7a1fee9fd1e 192.168.62.8:6380@16380 slave 59d4a94deef7f9af2abdfa270002b1017963c053 0 1744205625000 8 connected
2025-04-09T13:33:45.903610025Z I0409 13:33:45.903493 *344] 6f6f53c1ddad269a65a76a121b8ff271f7a52d72 192.168.34.15:6380@16380 slave 3a2a5e71000337e98135529471e277b5ee6bfcb6 0 1744205625304 7 connected
2025-04-09T13:33:45.903613781Z I0409 13:33:45.903498 *344] 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 192.168.91.126:6380@16380 master - 0 1744205625000 1 connected 0-5460
2025-04-09T13:33:45.903616159Z I0409 13:33:45.903511 *344] b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b 192.168.150.214:6380@16380 slave 3a2a5e71000337e98135529471e277b5ee6bfcb6 0 1744205625303 7 connected
2025-04-09T13:33:45.903618562Z I0409 13:33:45.903516 *344] 5c2a454afa2231c4cc7f3165e71d2864dc656541 192.168.91.78:6380@16380 myself,master - 0 0 11 connected 5461-10922
2025-04-09T13:33:45.903623847Z I0409 13:33:45.903522 *344] c8aee20c5d8bd7a845c7db3c6d947d62dccd5af9 192.168.34.37:6380@16380 slave 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 0 1744205625303 1 connected
2025-04-09T13:33:45.903700805Z I0409 13:33:45.903527 *344] 3a2a5e71000337e98135529471e277b5ee6bfcb6 192.168.62.22:6380@16380 master - 0 1744205625000 7 connected
2025-04-09T13:33:45.903705612Z I0409 13:33:45.903537 *344] 59d4a94deef7f9af2abdfa270002b1017963c053 192.168.150.232:6380@16380 master - 0 1744205625303 8 connected 10923-16383
2025-04-09T13:33:45.903708882Z I0409 13:33:45.903542 *344]
2025-04-09T13:33:45.903718225Z I0409 13:33:45.903574 *174] 19:M Discarding previously cached primary state.
2025-04-09T13:33:45.903741535Z I0409 13:33:45.903593 *174] 19:M Setting secondary replication ID to d770c4ba72ff0bc96aa3db7b947dee35bf2636de, valid up to offset: 4550895546. New replication ID is f67b7fdf24085b1af24da4bc088df94b37246d66
2025-04-09T13:33:45.944248254Z I0409 13:33:45.944072 *174] 19:M Replica 192.168.62.22:6380 asks for synchronization
2025-04-09T13:33:45.944291146Z I0409 13:33:45.944109 *174] 19:M Partial resynchronization request from 192.168.62.22:6380 accepted. Sending 158080 bytes of backlog starting from offset 4550895546.
2025-04-09T13:33:45.944296981Z I0409 13:33:45.944176 *174] 19:M Replica 192.168.34.15:6380 asks for synchronization
2025-04-09T13:33:45.944342478Z I0409 13:33:45.944182 *174] 19:M Partial resynchronization request from 192.168.34.15:6380 accepted. Sending 164768 bytes of backlog starting from offset 4550895546.
2025-04-09T13:33:46.029087737Z I0409 13:33:46.028917 *174] 19:M A failover occurred in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f; node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () failed over to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () with a config epoch of 11
2025-04-09T13:33:46.029120301Z I0409 13:33:46.028948 *174] 19:M Node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () is now a replica of node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:33:46.335653424Z I0409 13:33:46.335468 *174] 19:M Node 6f6f53c1ddad269a65a76a121b8ff271f7a52d72 () is now a replica of node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:33:48.235164315Z W0409 13:33:48.234885 *176] 19:M Error accepting a client connection: error:0A000126:SSL routines::unexpected eof while reading (addr=192.168.150.214:44342 laddr=192.168.91.78:6380)
2025-04-09T13:33:49.287676236Z I0409 13:33:49.287429 *174] 19:M NODE b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b () possibly failing.
2025-04-09T13:33:58.930229836Z I0409 13:33:58.930065 *174] 19:M PONG contains mismatching sender ID. About node b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af added 19602 ms ago, having flags 3078
2025-04-09T13:34:00.124373428Z I0409 13:34:00.124257 *174] 19:M Successfully completed handshake with 917fce766ef05824abac18fdab64a1e9574e9ba7 ()
2025-04-09T13:34:00.124512469Z I0409 13:34:00.124436 *174] 19:M Address updated for node 917fce766ef05824abac18fdab64a1e9574e9ba7 (), now 192.168.150.214:6380
2025-04-09T13:34:00.127258785Z I0409 13:34:00.127145 *344] 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 192.168.91.126:6380@16380 master - 0 1744205640037 1 connected 0-5460
2025-04-09T13:34:00.127275275Z I0409 13:34:00.127168 *344] 6f6f53c1ddad269a65a76a121b8ff271f7a52d72 192.168.34.15:6380@16380 slave 5c2a454afa2231c4cc7f3165e71d2864dc656541 0 1744205639329 11 connected
2025-04-09T13:34:00.127278023Z I0409 13:34:00.127174 *344] c8aee20c5d8bd7a845c7db3c6d947d62dccd5af9 192.168.34.37:6380@16380 slave 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 0 1744205640000 1 connected
2025-04-09T13:34:00.127290004Z I0409 13:34:00.127178 *344] 5c2a454afa2231c4cc7f3165e71d2864dc656541 192.168.91.78:6380@16380 myself,master - 0 0 11 connected 5461-10922
2025-04-09T13:34:00.127293075Z I0409 13:34:00.127182 *344] 59d4a94deef7f9af2abdfa270002b1017963c053 192.168.150.232:6380@16380 master - 0 1744205639127 8 connected 10923-16383
2025-04-09T13:34:00.127295499Z I0409 13:34:00.127186 *344] 3a2a5e71000337e98135529471e277b5ee6bfcb6 192.168.62.22:6380@16380 slave 5c2a454afa2231c4cc7f3165e71d2864dc656541 0 1744205639127 11 connected
2025-04-09T13:34:00.127297686Z I0409 13:34:00.127189 *344] 917fce766ef05824abac18fdab64a1e9574e9ba7 192.168.150.214:6380@16380 master - 0 1744205640047 12 disconnected
2025-04-09T13:34:00.127300042Z I0409 13:34:00.127192 *344] d010c9fb3ab0b11bee57cb33ede1b7a1fee9fd1e 192.168.62.8:6380@16380 slave 59d4a94deef7f9af2abdfa270002b1017963c053 0 1744205640000 8 connected
2025-04-09T13:34:00.127302966Z I0409 13:34:00.127195 *344] b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b :0@0 slave,fail?,noaddr 3a2a5e71000337e98135529471e277b5ee6bfcb6 1744205627250 1744205626237 7 disconnected
2025-04-09T13:34:00.127305662Z I0409 13:34:00.127198 *344]
2025-04-09T13:34:00.287791964Z I0409 13:34:00.279492 *174] 19:M Node 917fce766ef05824abac18fdab64a1e9574e9ba7 () is no longer primary of shard 0cb8f6a8deae6cd168eb6f058a17ef8032300ddc; removed all 0 slot(s) it used to own
2025-04-09T13:34:00.287827087Z I0409 13:34:00.279558 *174] 19:M Node 917fce766ef05824abac18fdab64a1e9574e9ba7 () is now part of shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:34:00.287832141Z I0409 13:34:00.279566 *174] 19:M Node 917fce766ef05824abac18fdab64a1e9574e9ba7 () is now a replica of node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:34:00.288339464Z I0409 13:34:00.288147 *174] 19:M Replica 192.168.150.214:6380 asks for synchronization
2025-04-09T13:34:00.288351781Z I0409 13:34:00.288177 *174] 19:M Full resync requested by replica 192.168.150.214:6380
2025-04-09T13:34:00.288356625Z I0409 13:34:00.288183 *174] 19:M Replica 192.168.150.214:6380 is capable of dual channel synchronization, and partial sync isn't possible. Full sync will continue with dedicated RDB channel.
2025-04-09T13:34:00.296322396Z I0409 13:34:00.293041 *174] 19:M Replica 192.168.150.214:6380 asks for synchronization
2025-04-09T13:34:00.296374781Z I0409 13:34:00.293068 *174] 19:M Starting BGSAVE for SYNC with target: replicas sockets using: dual-channel
2025-04-09T13:34:00.296380376Z I0409 13:34:00.293073 *174] 19:M Sending to replica 192.168.150.214:6380 RDB end offset 4563551269 and client-id 92
2025-04-09T13:34:00.305964438Z I0409 13:34:00.305819 *174] 19:M Background RDB transfer started by pid 25 to direct socket to replica
2025-04-09T13:34:00.308534399Z I0409 13:34:00.308323 *174] 19:M Replica 192.168.150.214:6380 asks for synchronization
2025-04-09T13:34:00.308551779Z I0409 13:34:00.308378 *174] 19:M Partial resynchronization request from 192.168.150.214:6380 accepted. Sending 4439 bytes of backlog starting from offset 4563551270.
2025-04-09T13:34:05.116544840Z I0409 13:34:05.116380 *174] 25:C Fork CoW for RDB: current 56 MB, peak 56 MB, average 36 MB
2025-04-09T13:34:05.131457541Z I0409 13:34:05.131339 *174] 19:M Replica 192.168.150.214:6380 rdb channel disconnected.
2025-04-09T13:34:05.131777303Z I0409 13:34:05.131725 *174] 19:M Synchronization with replica 192.168.150.214:6380 succeeded
2025-04-09T13:34:05.132046745Z I0409 13:34:05.131992 *344] 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 192.168.91.126:6380@16380 master - 0 1744205644407 1 connected 0-5460
2025-04-09T13:34:05.132061120Z I0409 13:34:05.132003 *344] 6f6f53c1ddad269a65a76a121b8ff271f7a52d72 192.168.34.15:6380@16380 slave 5c2a454afa2231c4cc7f3165e71d2864dc656541 0 1744205645114 11 connected
2025-04-09T13:34:05.132065353Z I0409 13:34:05.132008 *344] c8aee20c5d8bd7a845c7db3c6d947d62dccd5af9 192.168.34.37:6380@16380 slave 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 0 1744205645012 1 connected
2025-04-09T13:34:05.132069428Z I0409 13:34:05.132011 *344] 5c2a454afa2231c4cc7f3165e71d2864dc656541 192.168.91.78:6380@16380 myself,master - 0 0 11 connected 5461-10922
2025-04-09T13:34:05.132073991Z I0409 13:34:05.132015 *344] 59d4a94deef7f9af2abdfa270002b1017963c053 192.168.150.232:6380@16380 master - 0 1744205645113 8 connected 10923-16383
2025-04-09T13:34:05.132078432Z I0409 13:34:05.132018 *344] 917fce766ef05824abac18fdab64a1e9574e9ba7 192.168.150.214:6380@16380 slave 5c2a454afa2231c4cc7f3165e71d2864dc656541 0 1744205644429 11 connected
2025-04-09T13:34:05.132082794Z I0409 13:34:05.132021 *344] d010c9fb3ab0b11bee57cb33ede1b7a1fee9fd1e 192.168.62.8:6380@16380 slave 59d4a94deef7f9af2abdfa270002b1017963c053 0 1744205645113 8 connected
2025-04-09T13:34:05.132086860Z I0409 13:34:05.132024 *344] b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b :0@0 slave,fail?,noaddr - 1744205627250 1744205626237 10 disconnected


# b7ee, Valkey Replica which managed to replicate:
2025-04-09T13:33:37.946905349Z W0409 13:33:37.946356 *176] 19:C WARNING: Changing databases number from 16 to 1 since we are in cluster mode
2025-04-09T13:33:37.946938010Z I0409 13:33:37.946442 *174] 19:C oO0OoO0OoO0Oo Valkey is starting oO0OoO0OoO0Oo
2025-04-09T13:33:37.946941674Z I0409 13:33:37.946451 *174] 19:C Valkey version=8.0.2, bits=64, commit=00000000, modified=0, pid=19, just started
2025-04-09T13:33:37.946944769Z I0409 13:33:37.946457 *174] 19:C Configuration loaded
2025-04-09T13:33:37.946947821Z I0409 13:33:37.946793 *174] 19:M monotonic clock: POSIX clock_gettime
2025-04-09T13:33:37.947571795Z I0409 13:33:37.947368 *174] 19:M Running mode=cluster, port=6380.
2025-04-09T13:33:37.947586335Z W0409 13:33:37.947397 *176] 19:M WARNING: The TCP backlog setting of 65536 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 4096.
2025-04-09T13:33:37.947900769Z I0409 13:33:37.947818 *174] 19:M No cluster configuration found, I'm b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b
2025-04-09T13:33:37.954367651Z I0409 13:33:37.954262 *174] 19:M Server initialized
2025-04-09T13:33:37.954386111Z I0409 13:33:37.954307 *174] 19:M Ready to accept connections tls
2025-04-09T13:33:37.989296200Z I0409 13:33:37.989154 *327] RedisNode: started successfully
2025-04-09T13:33:37.993354417Z I0409 13:33:37.993245 *143] awaiting stop signal
2025-04-09T13:33:39.326464069Z I0409 13:33:39.326316 *174] 19:M configEpoch set to 10 via CLUSTER SET-CONFIG-EPOCH
2025-04-09T13:33:39.326673839Z I0409 13:33:39.326611 *344] b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b 192.168.150.214:6380@16380 myself,master - 0 0 10 connected
2025-04-09T13:33:39.326683595Z I0409 13:33:39.326629 *344]
2025-04-09T13:33:39.382606500Z I0409 13:33:39.382448 *174] 19:M Node d010c9fb3ab0b11bee57cb33ede1b7a1fee9fd1e () is now a replica of node 59d4a94deef7f9af2abdfa270002b1017963c053 () in shard 0cc56990fa1d2fa5f7fe4018be1d554f2076cce0
2025-04-09T13:33:39.382653954Z I0409 13:33:39.382576 *174] 19:M Address updated for node 5c2a454afa2231c4cc7f3165e71d2864dc656541 (), now 192.168.91.78:6380
2025-04-09T13:33:39.382672814Z I0409 13:33:39.382617 *229] log catcher is delaying logging cluster state
2025-04-09T13:33:39.388251512Z I0409 13:33:39.388094 *174] 19:M Node c8aee20c5d8bd7a845c7db3c6d947d62dccd5af9 () is now a replica of node 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 () in shard e09fe2428cacb4425adfc43b84783f7c726023a8
2025-04-09T13:33:39.388274420Z I0409 13:33:39.388153 *174] 19:M Node 6f6f53c1ddad269a65a76a121b8ff271f7a52d72 () is now a replica of node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af
2025-04-09T13:33:39.919833889Z I0409 13:33:39.919390 *174] 19:M Node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () is no longer primary of shard 6a89964965d5f242767b5bb6e7e4296a36501daa; removed all 0 slot(s) it used to own
2025-04-09T13:33:39.919877008Z I0409 13:33:39.919433 *174] 19:M Node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () is now part of shard e05be6b31f763e6a9e556060a0245d57d8ecd2af
2025-04-09T13:33:39.919882924Z I0409 13:33:39.919443 *174] 19:M Node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () is now a replica of node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af
2025-04-09T13:33:39.919888038Z I0409 13:33:39.919633 *174] 19:S Connecting to PRIMARY 192.168.62.22:6380
2025-04-09T13:33:39.919892278Z I0409 13:33:39.919644 *174] 19:S PRIMARY <-> REPLICA sync started
2025-04-09T13:33:39.919897537Z I0409 13:33:39.919703 *174] 19:S Cluster state changed: ok
2025-04-09T13:33:39.919902631Z I0409 13:33:39.919731 *234] log catcher skipped scheduling since already scheduled
2025-04-09T13:33:39.922971256Z I0409 13:33:39.922856 *174] 19:S Non blocking connect for SYNC fired the event.
2025-04-09T13:33:39.926421506Z I0409 13:33:39.926325 *174] 19:S Primary replied to PING, replication can continue...
2025-04-09T13:33:39.927260438Z I0409 13:33:39.927187 *174] 19:S (Non critical) Primary does not understand REPLCONF VERSION: -ERR Unrecognized REPLCONF option: version
2025-04-09T13:33:39.927270688Z I0409 13:33:39.927201 *174] 19:S Partial resynchronization not possible (no cached primary)
2025-04-09T13:33:40.383307516Z I0409 13:33:40.383141 *344] 6f6f53c1ddad269a65a76a121b8ff271f7a52d72 192.168.34.15:6380@16380 slave 3a2a5e71000337e98135529471e277b5ee6bfcb6 0 1744205619388 7 connected
2025-04-09T13:33:40.383344959Z I0409 13:33:40.383171 *344] 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 192.168.91.126:6380@16380 master - 0 1744205619469 1 connected 0-5460
2025-04-09T13:33:40.383351117Z I0409 13:33:40.383176 *344] c8aee20c5d8bd7a845c7db3c6d947d62dccd5af9 192.168.34.37:6380@16380 slave 5aa4ee89389d3c7db4ac7175cd5badd7221300d7 0 1744205619387 1 connected
2025-04-09T13:33:40.383355378Z I0409 13:33:40.383180 *344] 5c2a454afa2231c4cc7f3165e71d2864dc656541 192.168.91.78:6380@16380 slave 3a2a5e71000337e98135529471e277b5ee6bfcb6 0 1744205619470 7 connected
2025-04-09T13:33:40.383362349Z I0409 13:33:40.383184 *344] 3a2a5e71000337e98135529471e277b5ee6bfcb6 192.168.62.22:6380@16380 master - 0 1744205619473 7 connected 5461-10922
2025-04-09T13:33:40.383366892Z I0409 13:33:40.383187 *344] 59d4a94deef7f9af2abdfa270002b1017963c053 192.168.150.232:6380@16380 master - 0 1744205619871 8 connected 10923-16383
2025-04-09T13:33:40.383371225Z I0409 13:33:40.383190 *344] b7ee65cd1b5dfc81f5b64d7d839c756c7b87b69b 192.168.150.214:6380@16380 myself,slave 3a2a5e71000337e98135529471e277b5ee6bfcb6 0 0 7 connected
2025-04-09T13:33:40.383375419Z I0409 13:33:40.383193 *344] d010c9fb3ab0b11bee57cb33ede1b7a1fee9fd1e 192.168.62.8:6380@16380 slave 59d4a94deef7f9af2abdfa270002b1017963c053 0 1744205619382 8 connected
2025-04-09T13:33:40.383379901Z I0409 13:33:40.383195 *344]
2025-04-09T13:33:45.373674359Z I0409 13:33:45.373513 *174] 19:S Full resync from primary: d770c4ba72ff0bc96aa3db7b947dee35bf2636de:4550859702
2025-04-09T13:33:45.406422860Z I0409 13:33:45.406307 *174] 19:S PRIMARY <-> REPLICA sync: receiving streamed RDB from primary with EOF to parser
2025-04-09T13:33:45.406453793Z I0409 13:33:45.406372 *174] 19:S PRIMARY <-> REPLICA sync: Loading DB in memory
2025-04-09T13:33:45.406457754Z I0409 13:33:45.406378 *174] 19:S Loading RDB produced by Redis version 6.2.14
2025-04-09T13:33:45.406479532Z I0409 13:33:45.406382 *174] 19:S RDB age 0 seconds
2025-04-09T13:33:45.406497969Z I0409 13:33:45.406420 *174] 19:S RDB memory usage when created 618.72 Mb
2025-04-09T13:33:45.905840933Z W0409 13:33:45.905011 *176] 19:S Short read or OOM loading DB. Unrecoverable error, aborting now.
2025-04-09T13:33:45.905865715Z W0409 13:33:45.905054 *176] 19:S Internal error in RDB reading offset 20971362, function at rdb.c:3390 -> Unexpected EOF reading RDB file. Failure loading rdb format from socket, assuming connection error, resuming operation.
2025-04-09T13:33:45.905909805Z W0409 13:33:45.905066 *176] 19:S Failed trying to load the PRIMARY synchronization DB from socket, check server logs.
2025-04-09T13:33:45.905914723Z I0409 13:33:45.905231 *174] 19:S Reconnecting to PRIMARY 192.168.62.22:6380 after failure
2025-04-09T13:33:45.905919642Z I0409 13:33:45.905243 *174] 19:S PRIMARY <-> REPLICA sync started
2025-04-09T13:33:45.905923757Z I0409 13:33:45.905352 *174] 19:S PRIMARY <-> REPLICA sync: Discarding temporary DB in background
2025-04-09T13:33:45.905928530Z I0409 13:33:45.905495 *174] 19:S Slot 5461 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.919359312Z I0409 13:33:45.918695 *142] 245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.919385230Z I0409 13:33:45.918788 *142] 19:S 09 Apr 2025 13:33:45
2025-04-09T13:33:45.926836851Z I0409 13:33:45.926723 *142] .906 * Slot 5716 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.938064570Z I0409 13:33:45.935583 *142] 2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.938088752Z I0409 13:33:45.935655 *174] 19:S Slot 5967 is migra
2025-04-09T13:33:45.944478214Z I0409 13:33:45.943266 *142] ted from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.951593870Z I0409 13:33:45.951462 *142] d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.963318038Z I0409 13:33:45.959668 *142] 337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.971271600Z I0409 13:33:45.971081 *142]  ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.971292386Z I0409 13:33:45.971158 *174] 19:S Slot 6463 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.983580969Z I0409 13:33:45.981964 *142] fcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.991542014Z I0409 13:33:45.990977 *142] a04abe0d0621425f.
2025-04-09T13:33:46.001510437Z I0409 13:33:46.001377 *142] 1f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.001544016Z I0409 13:33:46.001425 *142] 19:S 09
2025-04-09T13:33:46.008996129Z I0409 13:33:46.008856 *142]  Apr 2025 13:33:45.989 * Slot 6846 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.016503045Z I0409 13:33:46.016355 *142] 8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.016540099Z I0409 13:33:46.016408 *142] 19:S 09 Apr 2025 13:33:46.008 *
2025-04-09T13:33:46.024413396Z I0409 13:33:46.024132 *142] Slot 7097 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.033540170Z I0409 13:33:46.033379 *142] a2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.033564987Z I0409 13:33:46.033442 *174] 19:S Slot 7348 is migrated fro
2025-04-09T13:33:46.041130956Z I0409 13:33:46.041002 *142] m node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.041203062Z I0409 13:33:46.041061 *174] 19:S Slot 7466 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.048978944Z I0409 13:33:46.048849 *142] 656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.070687776Z I0409 13:33:46.056305 *142] 35529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.070718756Z I0409 13:33:46.063950 *142] 3c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.074248338Z I0409 13:33:46.071043 *142]  in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.086349024Z I0409 13:33:46.078420 *142] d0621425f.
2025-04-09T13:33:46.087821677Z I0409 13:33:46.086540 *142] a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.087845276Z I0409 13:33:46.086621 *142] 19:S 09 Apr 20
2025-04-09T13:33:46.094740093Z I0409 13:33:46.094604 *142] 25 13:33:46.079 * Slot 8227 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.102494272Z I0409 13:33:46.101773 *142]  to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.102541426Z I0409 13:33:46.101825 *174] 19:S Slot 8467 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.102548970Z I0409 13:33:46.101833 *174] 19:S Slot 84
2025-04-09T13:33:46.109703087Z I0409 13:33:46.109574 *142] 78 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.116783325Z I0409 13:33:46.116696 *142] cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.123972838Z I0409 13:33:46.123855 *142] 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.131400224Z I0409 13:33:46.130913 *142] () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.138151056Z I0409 13:33:46.138035 *142] 1e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.147055328Z I0409 13:33:46.145222 *142] 7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.153638770Z I0409 13:33:46.152269 *142] rd e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.159635796Z I0409 13:33:46.159365 *142] 5f.
2025-04-09T13:33:46.159658102Z I0409 13:33:46.159408 *174] 19:S Slot 9468 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.171068002Z I0409 13:33:46.167116 *142] 60a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.171102890Z I0409 13:33:46.167183 *142] 19:S 09 Apr 2025 13:3
2025-04-09T13:33:46.175153264Z I0409 13:33:46.174254 *142] 3:46.158 * Slot 9608 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.181436607Z I0409 13:33:46.181323 *142] e 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.181460486Z I0409 13:33:46.181361 *174] 19:S Slot 9859 is m
2025-04-09T13:33:46.188697118Z I0409 13:33:46.188570 *142] igrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.195837097Z I0409 13:33:46.195719 *142] 5e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.206020159Z I0409 13:33:46.202969 *142] e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.210172663Z I0409 13:33:46.210025 *142] 980a04abe0d0621425f.
2025-04-09T13:33:46.217320072Z I0409 13:33:46.217208 *174] 19:S Slot 10470 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.217480057Z I0409 13:33:46.217229 *142] 19:S 09 Apr 202
2025-04-09T13:33:46.224763583Z I0409 13:33:46.224432 *142] 5 13:33:46.209 * Slot 10485 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.224782963Z I0409 13:33:46.224468 *174] 19:S S
2025-04-09T13:33:46.231657942Z I0409 13:33:46.231545 *142] lot 10610 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.231705388Z I0409 13:33:46.231586 *174] 19:S Slot 10735 is migra
2025-04-09T13:33:46.238795774Z I0409 13:33:46.238702 *142] ted from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.251801775Z I0409 13:33:46.245456 *142] 5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:46.251835778Z I0409 13:33:46.245482 *174] 19:S Non blocking connect for SYNC fired the event.
2025-04-09T13:33:46.251841893Z I0409 13:33:46.245504 *174] 19:S Node 6f6f53c1ddad269a65a76a121b8ff271f7a52d72 () is now a replica of node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:33:46.251846371Z I0409 13:33:46.245510 *174] 19:S Primary replied to PING, replication can continue...
2025-04-09T13:33:46.251850955Z I0409 13:33:46.245514 *174] 19:S (Non critical) Primary does not understand REPLCONF VERSION: -ERR Unrecognized REPLCONF option: version
2025-04-09T13:33:46.251855504Z I0409 13:33:46.245518 *174] 19:S Partial resynchronization not possible (no cached primary)
2025-04-09T13:33:46.251859869Z I0409 13:33:46.245522 *174] 19:S Full resync from primary: f67b7fdf24085b1af24da4bc088df94b37246d66:4551664006
2025-04-09T13:33:46.276326478Z I0409 13:33:46.276060 *174] 19:S PRIMARY <-> REPLICA sync: receiving streamed RDB from primary with EOF to parser
2025-04-09T13:33:46.276352730Z I0409 13:33:46.276157 *174] 19:S PRIMARY <-> REPLICA sync: Loading DB in memory
2025-04-09T13:33:46.276357982Z I0409 13:33:46.276172 *174] 19:S Loading RDB produced by Redis version 6.2.14
2025-04-09T13:33:46.276362793Z I0409 13:33:46.276180 *174] 19:S RDB age 0 seconds
2025-04-09T13:33:46.276367094Z I0409 13:33:46.276243 *174] 19:S RDB memory usage when created 614.16 Mb
2025-04-09T13:33:46.703243967Z I0409 13:33:46.703084 *174] 19:S Node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () is no longer primary of shard e05be6b31f763e6a9e556060a0245d57d8ecd2af; removed all 0 slot(s) it used to own
2025-04-09T13:33:46.703542762Z I0409 13:33:46.703425 *174] 19:S Node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () is now part of shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:33:46.703552251Z I0409 13:33:46.703471 *174] 19:S Node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () is now a replica of node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:33:46.703707686Z I0409 13:33:46.703483 *174] 19:S I'm a sub-replica! Reconfiguring myself as a replica of 5c2a454afa2231c4cc7f3165e71d2864dc656541 from 3a2a5e71000337e98135529471e277b5ee6bfcb6
2025-04-09T13:33:46.703737378Z I0409 13:33:46.703533 *293] Redis is loading the dataset in memory, passing liveness
2025-04-09T13:33:46.703832180Z I0409 13:33:46.703719 *174] 19:S Connecting to PRIMARY 192.168.91.78:6380
2025-04-09T13:33:46.703838367Z I0409 13:33:46.703731 *174] 19:S PRIMARY <-> REPLICA sync started
2025-04-09T13:33:46.703844400Z I0409 13:33:46.703735 *142] === VALKEY BUG REPORT START: Cut & paste starting from here ===
2025-04-09T13:33:46.703848741Z W0409 13:33:46.703739 *176] 19:S valkey 8.0.2 crashed by signal: 11, si_code: 1
...

[esebole]

I don't have a core dump captured, except the one Valkey did, but I suspect that the issue is related with OpenSSL library in version 3.1. I saw similar SSL_read crashes in the past in this point of ssl/ssl_lib.c:1837

1835 int ssl_read_internal(SSL *s, void *buf, size_t num, size_t *readbytes)
1836 {
1837 if (s->handshake_func == NULL) {
1838 ERR_raise(ERR_LIB_SSL, SSL_R_UNINITIALIZED);
1839 return -1;
1840 }

More recent versions of OpenSSL have this code refactored and 's' pointer is checked before members are accessed. Could it be the same case here?

[zuiderkwast]

This log message is interesting: "I'm a sub-replica! Reconfiguring myself as a replica of ..."

The crash happens after the node has discovered that it is a sub-replica and it wants to connect to the new primary instead.

Why does it become a sub-replica? During the upgrade, two new Valkey nodes have been added as replicas to the Redis primary. Before the failover, it looks like this:

             +---------+
             | Redis   |
             | 6.2.14  |
             | (3a2a)  |
             | primary |
             +---------+
             ^    ^    ^
            /     |     \
           /      |      \
+---------+  +---------+  +---------+
| Redis   |  | Valkey  |  | Valkey  |
| 6.2.14  |  | 8.0.2   |  | 8.0.2   |
| (6f6f)  |  | (5c2a)  |  | (b7ee)  |
| replica |  | replica |  | replica |
+---------+  +---------+  +---------+

Then, CLUSTER FAILOVER is sent to the Valkey node (5c2a) which becomes the new primary of the old Redis primary (3a2a) which now becomes a replica.

             +---------+
             | Valkey  |
             | 8.0.2   |
             | (5c2a)  |
             | primary |
             +---------+
             ^    ^    ^
            /     |     `.
           /      |       `.
          /  +---------+    `.
         /   | Redis   |      `.
        /    | 6.2.14  |       :
       /     | (3a2a)  |       :
      /      | replica |       :
     /       +---------+       :
     |                 ^       :
     |                  \      :
     |                   \     :       "I'm a sub-replica!
+---------+               +---------+   Reconfiguring myself
| Redis   |               | Valkey  |   as a replica of 5c2a."
| 6.2.14  |               | 8.0.2   |
| (6f6f)  |               | (b7ee)  |
| replica |               | replica |
+---------+               +---------+

The Redis node (6f6f) detects the new primary and becomes a replica of it.

The Valkey node (b7ee) detects that it is now a sub-replica and it wants to connect to the new primary instead.

It looks like the Valkey node tries to do another full sync with the new primary, which is surprising. The previous full sync succeeded so I would expect that it could do a partial sync after changing its primary. @PingXie Have you seen this behavior before?

Then, according to the stack trace, it crashes in SSL_read during the full sync.

[esebole]

I think in above drawing there is a mistake. 6f6f, also was a replica of 5c2a after failover. Only b7ee had this sub-replica episode.

[zuiderkwast]

@esebole OK, I updated the drawing.

Reading the log of b7ee more carefully, I can see there are more things happening.

When it first connects to the old Redis primary 3a2a, the sync fails:

2025-04-09T13:33:45.373674359Z I0409 13:33:45.373513 *174] 19:S Full resync from primary: d770c4ba72ff0bc96aa3db7b947dee35bf2636de:4550859702
2025-04-09T13:33:45.406422860Z I0409 13:33:45.406307 *174] 19:S PRIMARY <-> REPLICA sync: receiving streamed RDB from primary with EOF to parser
2025-04-09T13:33:45.406453793Z I0409 13:33:45.406372 *174] 19:S PRIMARY <-> REPLICA sync: Loading DB in memory
2025-04-09T13:33:45.406457754Z I0409 13:33:45.406378 *174] 19:S Loading RDB produced by Redis version 6.2.14
2025-04-09T13:33:45.406479532Z I0409 13:33:45.406382 *174] 19:S RDB age 0 seconds
2025-04-09T13:33:45.406497969Z I0409 13:33:45.406420 *174] 19:S RDB memory usage when created 618.72 Mb
2025-04-09T13:33:45.905840933Z W0409 13:33:45.905011 *176] 19:S Short read or OOM loading DB. Unrecoverable error, aborting now.
2025-04-09T13:33:45.905865715Z W0409 13:33:45.905054 *176] 19:S Internal error in RDB reading offset 20971362, function at rdb.c:3390 -> Unexpected EOF reading RDB file. Failure loading rdb format from socket, assuming connection error, resuming operation.
2025-04-09T13:33:45.905909805Z W0409 13:33:45.905066 *176] 19:S Failed trying to load the PRIMARY synchronization DB from socket, check server logs.
2025-04-09T13:33:45.905914723Z I0409 13:33:45.905231 *174] 19:S Reconnecting to PRIMARY 192.168.62.22:6380 after failure
2025-04-09T13:33:45.905919642Z I0409 13:33:45.905243 *174] 19:S PRIMARY <-> REPLICA sync started
2025-04-09T13:33:45.905923757Z I0409 13:33:45.905352 *174] 19:S PRIMARY <-> REPLICA sync: Discarding temporary DB in background

After this, I see a lot of slot migrations from 3a2a to 5c2a. That's from the old primary to the new primary. This shouldn't be possible. They are supposed to be in the same shard (but Redis 6 didn't have the concept of shard-id, so I guess that's why they appear as different shard-ids). What is the operator doing here?

Additionally, there is something funky with the line breaks in the log. It's mangled in some way by log processing?

2025-04-09T13:33:45.905928530Z I0409 13:33:45.905495 *174] 19:S Slot 5461 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.919359312Z I0409 13:33:45.918695 *142] 245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.
2025-04-09T13:33:45.919385230Z I0409 13:33:45.918788 *142] 19:S 09 Apr 2025 13:33:45
2025-04-09T13:33:45.926836851Z I0409 13:33:45.926723 *142] .906 * Slot 5716 is migrated from node 3a2a5e71000337e98135529471e277b5ee6bfcb6 () in shard e05be6b31f763e6a9e556060a0245d57d8ecd2af to node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f.

After some time, the sync with the old Redis primary succeeds, but at this point, the manual failover has already happened and the Valkey node 5c2a is now the primary. After this, the node discovers that it's a sub-replica.

2025-04-09T13:33:46.251835778Z I0409 13:33:46.245482 *174] 19:S Non blocking connect for SYNC fired the event.
2025-04-09T13:33:46.251841893Z I0409 13:33:46.245504 *174] 19:S Node 6f6f53c1ddad269a65a76a121b8ff271f7a52d72 () is now a replica of node 5c2a454afa2231c4cc7f3165e71d2864dc656541 () in shard ba3e243c49d8d7d8fd74e980a04abe0d0621425f
2025-04-09T13:33:46.251846371Z I0409 13:33:46.245510 *174] 19:S Primary replied to PING, replication can continue...
2025-04-09T13:33:46.251850955Z I0409 13:33:46.245514 *174] 19:S (Non critical) Primary does not understand REPLCONF VERSION: -ERR Unrecognized REPLCONF option: version
2025-04-09T13:33:46.251855504Z I0409 13:33:46.245518 *174] 19:S Partial resynchronization not possible (no cached primary)
2025-04-09T13:33:46.251859869Z I0409 13:33:46.245522 *174] 19:S Full resync from primary: f67b7fdf24085b1af24da4bc088df94b37246d66:4551664006
2025-04-09T13:33:46.276326478Z I0409 13:33:46.276060 *174] 19:S PRIMARY <-> REPLICA sync: receiving streamed RDB from primary with EOF to parser
2025-04-09T13:33:46.276352730Z I0409 13:33:46.276157 *174] 19:S PRIMARY <-> REPLICA sync: Loading DB in memory
2025-04-09T13:33:46.276357982Z I0409 13:33:46.276172 *174] 19:S Loading RDB produced by Redis version 6.2.14
2025-04-09T13:33:46.276362793Z I0409 13:33:46.276180 *174] 19:S RDB age 0 seconds
2025-04-09T13:33:46.276367094Z I0409 13:33:46.276243 *174] 19:S RDB memory usage when created 614.16 Mb

So... Some questions:

1. Why isn't the operator waiting for all the new nodes to sync with the old primary before the manual failover is started? I think it should.
2. Why are the slot migrations happening?

[zuiderkwast]

@esebole Since it crashed in SSL_read(), can it be related to this one?

• [BUG] 0A00010F:SSL routines::bad length causing high latency and reconnects #1135
• Fix error "SSL routines::bad length" when connTLSWrite is called second time with smaller buffer #1737

[esebole]

Hi @zuiderkwast, I doubt that. Above 2 mentions that issue is causing reconnects, but we have a crash. I saw similar cases in Redis 6.2 where coredump was collected, not the Valkey one, but the container one, and it was pointing to null pointer dereference in OpenSSL. I think this is a case here.

[esebole]

@zuiderkwast I found another instance of this issue with Valkey 8.0.3. This time with a proper coredump:

(gdb) bt

#0  0x00007f74dc2deb47 in __GI_kill () at ../sysdeps/unix/syscall-template.S:120

#1  0x000000000050b78f in bugReportEnd (killViaSignal=1, sig=11) at debug.c:2261

#2  <signal handler called>

#3  SSL_want (s=s@entry=0x0) at ssl/ssl_lib.c:4583

#4  0x00007f74dca568f8 in SSL_get_error (s=0x0, i=<optimized out>) at ssl/ssl_lib.c:3862

#5  0x00000000005cb077 in handleSSLReturnCode.constprop.0 (conn=conn@entry=0x7f74dbe35a30, 
ret_value=ret_value@entry=-1, want=want@entry=0x7ffd57490b8c) at tls.c:527

#6  0x00000000005bdbcd in updateStateAfterSSLIO (update_event=1, ret_value=-1, conn=0x7f74dbe35a30) at tls.c:568

#7  connTLSRead (conn_=0x7f74dbe35a30, buf=<optimized out>, buf_len=<optimized out>) at tls.c:966

#8  0x000000000053bf28 in connRead (buf_len=<optimized out>, buf=<optimized out>, conn=<optimized out>) at connection.h:232

#9  rioConnRead (r=0x7ffd57491220, buf=0x7f74d0953f03, len=54) at rio.c:248

#10 0x00000000004b672b in rioRead (r=0x7ffd57491220, buf=0x7f74d0953f03, len=54) at rio.h:140

#11 0x00000000004c6041 in rdbGenericLoadStringObject (rdb=0x7ffd57491220, flags=<optimized out>, lenptr=0x0) at rdb.c:566

#12 0x00000000004cefcc in rdbLoadRioWithLoadingCtx (rdb=0x7ffd57491220, rdbflags=2, rsi=0x7ffd574911e0, rdb_loading_ctx=0x7ffd574911c0) at rdb.c:3270

#13 0x00000000004c04e0 in rdbLoadRioWithLoadingCtxScopedRdb (rdb_loading_ctx=0x7ffd574911c0, rsi=0x7ffd574911e0, rdbflags=2, rdb=0x7ffd57491220) at rdb.c:2999

#14 readSyncBulkPayload (conn=0x7f74dbe35a30, conn@entry=<error reading variable: value has been optimized out>) at replication.c:2237

#15 0x00000000005afc3e in callHandler (conn=0x7f74dbe35a30, handler=<optimized out>) at connhelpers.h:79

#16 0x00000000005b9f0f in tlsHandleEvent (conn=0x7f74dbe35a30, mask=<optimized out>) at tls.c:736

#17 0x00000000005bac8c in tlsProcessPendingData () at tls.c:1107

#18 0x00000000004707a6 in connTypeProcessPendingData () at connection.c:174

#19 beforeSleep (eventLoop=<optimized out>) at server.c:1631

#20 0x000000000046872f in aeProcessEvents (flags=27, eventLoop=0x7f74dbe3f080) at ae.c:426

#21 aeProcessEvents (flags=27, eventLoop=0x7f74dbe3f080) at ae.c:411

#22 aeMain (eventLoop=0x7f74dbe3f080) at ae.c:543

#23 0x000000000045e1d7 in main (argc=2, argv=0x7ffd574955a8) at server.c:7064

This is another time I see this issue with on different databases Redis 6.2 some time ago, now with Valkey 8.0.2, and Valkey 8.0.3. All were using OpenSSL 3.1.4. I think one thing is that OpenSSL doesn't validate the pointers before accessing it members, but on the other hand Valkey/Redis also doesn't when dealing with 3PPs. So looking at tls.c code whenever Valkey is accessing conn->ssl there is a NULLPTR guard before it. However when same is passing to OpenSSL there is simple:
int ssl_err = SSL_get_error(conn->ssl, ret_value);
which leads to a crash later on. This is in many places. Do you think it would be wise to add some checks to conn->ssl?

BR,
Seb.

[zuiderkwast]

Thanks Seb, this is useful information!

Now, I'm trying to read backwards to see how conn->ssl can be null when we read from the connection in connTLSRead().

This is for reading RDB, so it must be a replica reading a full sync from the primary. It means it's an outgoing connection. I can see that when we create an outgoing TLS connections, we don't check if SSL_new() returned NULL.

It's called from connCreate() via connCreateTLS() here: https://github.com/valkey-io/valkey/blob/8.0.3/src/tls.c#L459-L472

In replication.c, connCreate() is followed by connConnect(). It just initiates a TCP connection and registers an event handler to the event loop. When the writable event comes, tlsHandleEvent is called and the connection state is CONN_STATE_CONNECTING. We reach some code like SSL_connect(conn->ssl). If conn->ssl is NULL here, I would assume it can crash, but if it doesn't, then the code can continue...

In contrast, for incoming connections, we check conn->ssl to see if SSL_new() returned NULL very early after creating it: https://github.com/valkey-io/valkey/blob/8.0.3/src/tls.c#L497-L501

I don't know if this is the source of this crash or not, but regardless, we should check that SSL_new() returned NULL as early as possible, for example just after calling SSL_new(), to abort this code path early. We should set conn->c.state = CONN_STATE_ERROR and then, when connConnect() is called, it returns an error that aborts the replication and logs an error like "Unable to connect to PRIMARY".

The only other place I can see conn->ssl is assigned is in connTLSShutdown() and connTLSClose(). Here it's set to NULL. But I think the SSL_new().