Hello - Our redis server does not start after the weekly reboot with below error: (We have not done any upgrades or changes to the cluster)
=== REDIS BUG REPORT START: Cut & paste starting from here ===
65002:S 13 Nov 2022 08:24:17.102 # Redis 6.2.6 crashed by signal: 11, si_code: 1
65002:S 13 Nov 2022 08:24:17.102 # Accessing address: (nil)
65002:S 13 Nov 2022 08:24:17.102 # Crashed running the instruction at: 0x530682
------ STACK TRACE ------
EIP:
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](je_large_dalloc+0x12)[0x530682]
Backtrace:
/lib64/libpthread.so.0(+0xf5d0)[0x7f6ff74145d0]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](je_large_dalloc+0x12)[0x530682]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](raxRecursiveFree+0xaf)[0x4c821f]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](raxRecursiveFree+0x92)[0x4c8202]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](raxRecursiveFree+0x92)[0x4c8202]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](raxRecursiveFree+0x92)[0x4c8202]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](raxRecursiveFree+0x92)[0x4c8202]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](raxRecursiveFree+0x92)[0x4c8202]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](raxRecursiveFree+0x92)[0x4c8202]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](raxRecursiveFree+0x92)[0x4c8202]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](raxFreeWithCallback+0xf)[0x4c827f]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](RM_FreeDict+0x24)[0x4b8114]
/export/data/redis-stable/modules/redistimeseries.so(RemoveAllIndexedMetrics_generic+0x82)[0x7f6ff7edfa82]
/export/data/redis-stable/modules/redistimeseries.so(FlushEventCallback+0x3d)[0x7f6ff7ee37fd]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](moduleFireServerEvent+0x15e)[0x4be56e]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](emptyDb+0x83)[0x45c7f3]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](readSyncBulkPayload+0x8a)[0x45edaa]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster][0x4dace3]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](aeProcessEvents+0x235)[0x433845]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](aeMain+0x1d)[0x433b4d]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster](main+0x416)[0x430546]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7f6ff705a3d5]
/export/data/redis-stable/src/redis-server 127.0.0.1:6380 [cluster][0x4308fa]
------ REGISTERS ------
65002:S 13 Nov 2022 08:24:17.104 #
RAX:00007f6e4d943d18 RBX:00007f6e0c31b438
RCX:0000000000000080 RDX:00000000000000eb
RDI:00007f6ff7f3e730 RSI:0000000000000000
RBP:0000000000000000 RSP:00007ffd070b8ae0
R8 :00007f6e00000000 R9 :00007f6ff6e00900
R10:00007ffd070b84f0 R11:00007f6ff71c5580
R12:00007f6ff7f3e730 R13:00007f6e0c31b438
R14:00007f6e0c31b430 R15:00007f6ff6c0e8e0
RIP:0000000000530682 EFL:0000000000010202
CSGSFS:0000000000000033
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8aef) -> 00000000004c8202
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8aee) -> 00007f6fdb938340
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8aed) -> 00007f6fdb938348
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8aec) -> 0000000000000000
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8aeb) -> 00007f6ff6c4d400
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8aea) -> 00007f6fdb938350
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8ae9) -> 00007f6eab140680
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8ae8) -> 00007f6f1bc2a160
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8ae7) -> 00000000004c821f
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8ae6) -> 00007f6e0c31b430
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8ae5) -> 00007f6e0c31b438
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8ae4) -> 0000000000000000
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8ae3) -> 00007f6ff6c4d400
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8ae2) -> 00007f6e0c31b438
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8ae1) -> 00007f6e0c31b438
65002:S 13 Nov 2022 08:24:17.104 # (00007ffd070b8ae0) -> 00007f6edb5bdab0
------ INFO OUTPUT ------
# Server
redis_version:6.2.6
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:1686df54907d814e
redis_mode:cluster
os:Linux 3.10.0-957.27.2.el7.x86_64 x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:4.8.5
process_id:65002
process_supervised:no
run_id:a88b898d87aee5ff560f83ad86ae6fec675fc352
tcp_port:6380
server_time_usec:1668345832859082
uptime_in_seconds:163
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:7401448
executable:/export/data/redis-stable/src/redis-server
config_file:/export/data/redis-stable/cluster/6380/./redis.conf
io_threads_active:0
# Clients
connected_clients:1
cluster_connections:16
maxclients:10000
client_recent_max_input_buffer:32
client_recent_max_output_buffer:0
blocked_clients:0
tracking_clients:0
clients_in_timeout_table:0
# Memory
used_memory:5255296
used_memory_human:5.01M
used_memory_rss:11521703936
used_memory_rss_human:10.73G
used_memory_peak:11191535680
used_memory_peak_human:10.42G
used_memory_peak_perc:0.05%
used_memory_overhead:1581432
used_memory_startup:1560920
used_memory_dataset:3673864
used_memory_dataset_perc:99.44%
allocator_allocated:11191322728
allocator_active:11196469248
allocator_resident:11543371776
total_system_memory:1081664782336
total_system_memory_human:1007.38G
used_memory_lua:37888
used_memory_lua_human:37.00K
used_memory_scripts:0
used_memory_scripts_human:0B
number_of_cached_scripts:0
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.00
allocator_frag_bytes:5146520
allocator_rss_ratio:1.03
allocator_rss_bytes:346902528
rss_overhead_ratio:1.00
rss_overhead_bytes:-21667840
mem_fragmentation_ratio:1.03
mem_fragmentation_bytes:330487008
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:20512
mem_aof_buffer:0
mem_allocator:jemalloc-5.1.0
active_defrag_running:0
lazyfree_pending_objects:0
lazyfreed_objects:0
# Persistence
loading: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:1668345831
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:46
rdb_current_bgsave_time_sec:-1
rdb_last_cow_size:4370432
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_last_write_status:ok
aof_last_cow_size:0
module_fork_in_progress:0
module_fork_last_cow_size:0
aof_current_size:3122108247
aof_base_size:3122108247
aof_pending_rewrite:0
aof_buffer_length:0
aof_rewrite_buffer_length:0
aof_pending_bio_fsync:0
aof_delayed_fsync:0
# Stats
total_connections_received:1
total_commands_processed:35
instantaneous_ops_per_sec:0
total_net_input_bytes:2707607361
total_net_output_bytes:52671
instantaneous_input_kbps:703021.19
instantaneous_output_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
keyspace_hits:5009421
keyspace_misses:0
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:191653
total_forks:1
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
tracking_total_keys:0
tracking_total_items:0
tracking_total_prefixes:0
unexpected_error_replies:0
total_error_replies:0
dump_payload_sanitizations:0
total_reads_processed:34
total_writes_processed:34
io_threaded_reads_processed:0
io_threaded_writes_processed:0
# Replication
role:slave
master_host:10.153.203.75
master_port:6379
master_link_status:down
master_last_io_seconds_ago:-1
master_sync_in_progress:1
slave_read_repl_offset:1
slave_repl_offset:1
master_sync_total_bytes:2707606252
master_sync_read_bytes:2707606252
master_sync_left_bytes:0
master_sync_perc:100.00
master_sync_last_io_seconds_ago:0
master_link_down_since_seconds:-1
slave_priority:100
slave_read_only:1
replica_announced:1
connected_slaves:0
master_failover_state:no-failover
master_replid:c75188c67eb7a186772f1e05bd28f45474a74746
master_replid2:0000000000000000000000000000000000000000
master_repl_offset:0
second_repl_offset:-1
repl_backlog_active:0
repl_backlog_size:1048576
repl_backlog_first_byte_offset:0
repl_backlog_histlen:0
# CPU
used_cpu_sys:18.722191
used_cpu_user:135.834437
used_cpu_sys_children:9.916971
used_cpu_user_children:33.267612
used_cpu_sys_main_thread:11.909212
used_cpu_user_main_thread:131.853558
# Modules
module:name=timeseries,ver=10609,api=1,filters=0,usedby=[],using=[],options=[handle-io-errors]
# Commandstats
cmdstat_config:calls=11,usec=750,usec_per_call=68.18,rejected_calls=0,failed_calls=0
cmdstat_auth:calls=1,usec=6,usec_per_call=6.00,rejected_calls=0,failed_calls=0
cmdstat_slowlog:calls=11,usec=61,usec_per_call=5.55,rejected_calls=0,failed_calls=0
cmdstat_info:calls=12,usec=1012,usec_per_call=84.33,rejected_calls=0,failed_calls=0
# Errorstats
# Cluster
cluster_enabled:1
# Keyspace
------ CLIENT LIST OUTPUT ------
id=6 addr=127.0.0.1:56776 laddr=127.0.0.1:6380 fd=17 name= age=154 idle=4 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=20512 events=r cmd=slowlog user=default redir=-1
------ MODULES INFO OUTPUT ------
------ FAST MEMORY TEST ------
65002:S 13 Nov 2022 08:24:17.125 # Bio thread for job type #0 terminated
65002:S 13 Nov 2022 08:24:17.125 # Bio thread for job type #1 terminated
65002:S 13 Nov 2022 08:24:17.125 # Bio thread for job type #2 terminated
*** Preparing to test memory region 7d9000 (2277376 bytes)
*** Preparing to test memory region 16c6000 (135168 bytes)
*** Preparing to test memory region 16e7000 (163840 bytes)
*** Preparing to test memory region 7f6d21400000 (11765022720 bytes)
*** Preparing to test memory region 7f6fde9ff000 (218103808 bytes)
*** Preparing to test memory region 7f6feba00000 (8388608 bytes)
*** Preparing to test memory region 7f6fec200000 (6291456 bytes)
*** Preparing to test memory region 7f6fec8b6000 (8388608 bytes)
*** Preparing to test memory region 7f6fed0b7000 (8388608 bytes)
*** Preparing to test memory region 7f6fed8b8000 (8388608 bytes)
*** Preparing to test memory region 7f6fee0b9000 (8388608 bytes)
*** Preparing to test memory region 7f6fee8ba000 (8388608 bytes)
*** Preparing to test memory region 7f6fef2d1000 (8192 bytes)
*** Preparing to test memory region 7f6fef59a000 (12288 bytes)
*** Preparing to test memory region 7f6fefd60000 (16384 bytes)
*** Preparing to test memory region 7f6feffd6000 (3145728 bytes)
*** Preparing to test memory region 7f6ff6800000 (8388608 bytes)
*** Preparing to test memory region 7f6ff7023000 (4096 bytes)
*** Preparing to test memory region 7f6ff7400000 (20480 bytes)
*** Preparing to test memory region 7f6ff761d000 (16384 bytes)
*** Preparing to test memory region 7f6ff7ec7000 (12288 bytes)
*** Preparing to test memory region 7f6ff7f3d000 (4096 bytes)
*** Preparing to test memory region 7f6ff7f3e000 (24576 bytes)
*** Preparing to test memory region 7f6ff7f4e000 (4096 bytes)
*** Preparing to test memory region 7f6ff7f4f000 (4096 bytes)
*** Preparing to test memory region 7f6ff7f52000 (4096 bytes)
.O.O.O.
Additional information
CentOS 7.6 Kernel 3.10.0-957.27.2.el7.x86_64 Running on hardware
We have 3 masters + 6 slaves (2 per master) on 3 nodes. We have 3 masters up but all slaves are crashing and it seems to happen during MASTER -> REPLICA sync when a FULL RESYNC is triggered.
Comment From: oranagra
@pgullipa this looks like an issue with RedisTimeSeries, please report there. https://github.com/RedisTimeSeries/RedisTimeSeries