Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[bitnami/redis] Module crashes when master failover when a write is done #56378

Closed
wgnathanael opened this issue Feb 5, 2024 · 15 comments
Closed
Assignees
Labels
redis solved stale 15 days without activity tech-issues The user has a technical issue about an application

Comments

@wgnathanael
Copy link

wgnathanael commented Feb 5, 2024

Name and Version

bitnami/redis

What architecture are you using?

amd64

What steps will reproduce the bug?

  1. In K8s and docker/podman
  2. With this extremely simple module.c (as a reproducer)
  3. Bring up a 3 containers or nodes in k8s cluster with 3 sentienels
  4. Pause/Shutdown the master node

What is the expected behavior?

A replica/slave node/container becomes master, no crashes

What do you see instead?

redis 17:41:37.72 INFO  ==> 
redis 17:41:37.72 INFO  ==> Welcome to the Bitnami redis container
redis 17:41:37.72 INFO  ==> Subscribe to project updates by watching https://github.com/bitnami/containers
redis 17:41:37.72 INFO  ==> Submit issues and feature requests at https://github.com/bitnami/containers/issues
redis 17:41:37.72 INFO  ==> 
redis 17:41:37.72 INFO  ==> ** Starting Redis setup **
redis 17:41:37.73 WARN  ==> You set the environment variable ALLOW_EMPTY_PASSWORD=yes. For safety reasons, do not use this flag in a production environment.
redis 17:41:37.76 INFO  ==> Initializing Redis
redis 17:41:37.77 INFO  ==> Setting Redis config file
redis 17:41:37.80 INFO  ==> Configuring replication mode

redis 17:41:37.83 INFO  ==> ** Redis setup finished! **
redis 17:41:37.84 INFO  ==> ** Starting Redis **
1:C 05 Feb 2024 17:41:37.849 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
1:C 05 Feb 2024 17:41:37.849 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
1:C 05 Feb 2024 17:41:37.849 * Redis version=7.2.4, bits=64, commit=00000000, modified=0, pid=1, just started
1:C 05 Feb 2024 17:41:37.849 * Configuration loaded
1:S 05 Feb 2024 17:41:37.850 * monotonic clock: POSIX clock_gettime
1:S 05 Feb 2024 17:41:37.850 * Running mode=standalone, port=6379.
1:S 05 Feb 2024 17:41:37.850 * Module 'example' loaded from /usr/lib64/redis-test-module.so
1:S 05 Feb 2024 17:41:37.850 * Server initialized
1:S 05 Feb 2024 17:41:37.851 * Creating AOF base file appendonly.aof.1.base.rdb on server start
1:S 05 Feb 2024 17:41:37.852 * Creating AOF incr file appendonly.aof.1.incr.aof on server start
1:S 05 Feb 2024 17:41:37.852 * Ready to accept connections tcp
1:S 05 Feb 2024 17:41:37.852 * Connecting to MASTER redis-master:6379
1:S 05 Feb 2024 17:41:37.853 * MASTER <-> REPLICA sync started
1:S 05 Feb 2024 17:41:37.853 * Non blocking connect for SYNC fired the event.
1:S 05 Feb 2024 17:41:37.853 * Master replied to PING, replication can continue...
1:S 05 Feb 2024 17:41:37.854 * Partial resynchronization not possible (no cached master)
1:S 05 Feb 2024 17:41:40.926 * Full resync from master: 309a9bf2db7c592bad49a400e4075e421db21aa0:158
1:S 05 Feb 2024 17:41:40.927 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk
1:S 05 Feb 2024 17:41:40.927 * MASTER <-> REPLICA sync: Flushing old data
1:S 05 Feb 2024 17:41:40.927 * MASTER <-> REPLICA sync: Loading DB in memory
1:S 05 Feb 2024 17:41:40.929 * Loading RDB produced by version 7.2.4
1:S 05 Feb 2024 17:41:40.929 * RDB age 0 seconds
1:S 05 Feb 2024 17:41:40.929 * RDB memory usage when created 1.20 Mb
1:S 05 Feb 2024 17:41:40.929 * Done loading RDB, keys loaded: 0, keys expired: 0.
1:S 05 Feb 2024 17:41:40.929 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 0
1:S 05 Feb 2024 17:41:40.929 * <example> [EventHandler] Master Replication Link Up
1:S 05 Feb 2024 17:41:40.929 * MASTER <-> REPLICA sync: Finished with success
1:S 05 Feb 2024 17:41:40.929 * Creating AOF incr file temp-appendonly.aof.incr on background rewrite
1:S 05 Feb 2024 17:41:40.929 * Background append only file rewriting started by pid 92
92:C 05 Feb 2024 17:41:40.931 * Successfully created the temporary AOF base file temp-rewriteaof-bg-92.aof
92:C 05 Feb 2024 17:41:40.931 * Fork CoW for AOF rewrite: current 0 MB, peak 0 MB, average 0 MB
1:S 05 Feb 2024 17:41:40.978 * Background AOF rewrite terminated with success
1:S 05 Feb 2024 17:41:40.978 * Successfully renamed the temporary AOF base file temp-rewriteaof-bg-92.aof into appendonly.aof.2.base.rdb
1:S 05 Feb 2024 17:41:40.978 * Successfully renamed the temporary AOF incr file temp-appendonly.aof.incr into appendonly.aof.2.incr.aof
1:S 05 Feb 2024 17:41:40.979 * Removing the history file appendonly.aof.1.incr.aof in the background
1:S 05 Feb 2024 17:41:40.979 * Removing the history file appendonly.aof.1.base.rdb in the background
1:S 05 Feb 2024 17:41:40.980 * Background AOF rewrite finished successfully
1:M 05 Feb 2024 17:41:51.911 * Connection with master lost.
1:M 05 Feb 2024 17:41:51.911 * Caching the disconnected master state.
1:M 05 Feb 2024 17:41:51.911 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
1:M 05 Feb 2024 17:41:51.911 * <example> [EventHandler] Master Replication Link Down
1:S 05 Feb 2024 17:41:51.911 * <example> [EventHandler] Event Handler EVENT 0 SUBEVENT 1
1:S 05 Feb 2024 17:41:51.911 * <example> [EventHandler] Became Replica
1:S 05 Feb 2024 17:41:51.911 * <example> [KAU] AAAAA replica set
1:S 05 Feb 2024 17:41:51.911 * Connecting to MASTER 10.89.5.36:6379
1:S 05 Feb 2024 17:41:51.911 * MASTER <-> REPLICA sync started
1:S 05 Feb 2024 17:41:51.911 * REPLICAOF 10.89.5.36:6379 enabled (user request from 'id=6 addr=10.89.5.41:54528 laddr=10.89.5.39:6379 fd=12 name=sentinel-7a9cbc11-cmd age=12 idle=0 flags=x db=0 sub=0 psub=0 ssub=0 multi=3 qbuf=150 qbuf-free=20324 argv-mem=4 multi-mem=126 rbs=1024 rbp=1024 obl=36 oll=0 omem=0 tot-mem=22650 events=r cmd=exec user=default redir=-1 resp=2 lib-name= lib-ver=')
1:S 05 Feb 2024 17:41:51.912 # Could not create tmp config file (Permission denied)
1:S 05 Feb 2024 17:41:51.912 # CONFIG REWRITE failed: Permission denied
1:S 05 Feb 2024 17:41:51.912 * Non blocking connect for SYNC fired the event.
1:S 05 Feb 2024 17:41:51.913 * Master replied to PING, replication can continue...
1:S 05 Feb 2024 17:41:51.913 * Trying a partial resynchronization (request 309a9bf2db7c592bad49a400e4075e421db21aa0:2221).
1:S 05 Feb 2024 17:41:51.913 * Successful partial resynchronization with master.
1:S 05 Feb 2024 17:41:51.913 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 0
1:S 05 Feb 2024 17:41:51.913 * <example> [EventHandler] Master Replication Link Up
1:S 05 Feb 2024 17:41:51.913 * MASTER <-> REPLICA sync: Master accepted a Partial Resynchronization.
1:M 05 Feb 2024 17:42:53.332 * Connection with master lost.
1:M 05 Feb 2024 17:42:53.332 * Caching the disconnected master state.
1:M 05 Feb 2024 17:42:53.332 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
1:M 05 Feb 2024 17:42:53.332 * <example> [EventHandler] Master Replication Link Down
1:S 05 Feb 2024 17:42:53.332 * <example> [EventHandler] Event Handler EVENT 0 SUBEVENT 1
1:S 05 Feb 2024 17:42:53.332 * <example> [EventHandler] Became Replica
1:S 05 Feb 2024 17:42:53.332 * <example> [KAU] AAAAA replica set
1:S 05 Feb 2024 17:42:53.332 * Connecting to MASTER 10.89.5.38:6379
1:S 05 Feb 2024 17:42:53.332 * MASTER <-> REPLICA sync started
1:S 05 Feb 2024 17:42:53.332 * REPLICAOF 10.89.5.38:6379 enabled (user request from 'id=6 addr=10.89.5.41:54528 laddr=10.89.5.39:6379 fd=12 name=sentinel-7a9cbc11-cmd age=74 idle=0 flags=x db=0 sub=0 psub=0 ssub=0 multi=3 qbuf=285 qbuf-free=20189 argv-mem=4 multi-mem=126 rbs=2048 rbp=2048 obl=36 oll=0 omem=0 tot-mem=23674 events=r cmd=exec user=default redir=-1 resp=2 lib-name= lib-ver=')
1:S 05 Feb 2024 17:42:53.333 # Could not create tmp config file (Permission denied)
1:S 05 Feb 2024 17:42:53.333 # CONFIG REWRITE failed: Permission denied
1:S 05 Feb 2024 17:42:53.334 * Non blocking connect for SYNC fired the event.
1:S 05 Feb 2024 17:42:53.334 * Master replied to PING, replication can continue...
1:S 05 Feb 2024 17:42:53.335 * Trying a partial resynchronization (request 309a9bf2db7c592bad49a400e4075e421db21aa0:12970).
1:S 05 Feb 2024 17:42:53.335 * Successful partial resynchronization with master.
1:S 05 Feb 2024 17:42:53.335 * Master replication ID changed to 19101531687e8bb50bfa92760d7096452b0b4eae
1:S 05 Feb 2024 17:42:53.335 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 0
1:S 05 Feb 2024 17:42:53.335 * <example> [EventHandler] Master Replication Link Up
1:S 05 Feb 2024 17:42:53.335 * MASTER <-> REPLICA sync: Master accepted a Partial Resynchronization.
1:S 05 Feb 2024 17:42:53.335 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
1:S 05 Feb 2024 17:42:53.335 * <example> [EventHandler] Master Replication Link Down
1:M 05 Feb 2024 17:42:53.335 * Connection with master lost.
1:M 05 Feb 2024 17:42:53.335 * Caching the disconnected master state.
1:M 05 Feb 2024 17:42:53.335 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
1:M 05 Feb 2024 17:42:53.335 * <example> [EventHandler] Master Replication Link Down
1:M 05 Feb 2024 17:42:53.335 * Discarding previously cached master state.
1:M 05 Feb 2024 17:42:53.335 * Setting secondary replication ID to 19101531687e8bb50bfa92760d7096452b0b4eae, valid up to offset: 12993. New replication ID is feadb1522c823132fcb73ee80e662517e0709240
1:M 05 Feb 2024 17:42:53.335 * <example> [EventHandler] Event Handler EVENT 0 SUBEVENT 0
1:M 05 Feb 2024 17:42:53.335 * <example> [EventHandler] Became Master
1:M 05 Feb 2024 17:42:53.335 * <example> [KAU] AAAAA master set


=== REDIS BUG REPORT START: Cut & paste starting from here ===
1:M 05 Feb 2024 17:42:53.335 # Redis 7.2.4 crashed by signal: 11, si_code: 1
1:M 05 Feb 2024 17:42:53.335 # Accessing address: 0xffffffffffffffff
1:M 05 Feb 2024 17:42:53.335 # Crashed running the instruction at: 0x55cb065ca41b

------ STACK TRACE ------
EIP:
redis-server 0.0.0.0:6379(getClientMemoryUsage+0x4b)[0x55cb065ca41b]

Backtrace:
/lib/x86_64-linux-gnu/libpthread.so.0(+0x13140)[0x7fbe2a809140]
redis-server 0.0.0.0:6379(getClientMemoryUsage+0x4b)[0x55cb065ca41b]
redis-server 0.0.0.0:6379(catClientInfoString+0x16e)[0x55cb065ce68e]
redis-server 0.0.0.0:6379(replicaofCommand+0x17c)[0x55cb065e806c]
redis-server 0.0.0.0:6379(call+0x170)[0x55cb065aa740]
redis-server 0.0.0.0:6379(processCommand+0xb69)[0x55cb065ab9e9]
redis-server 0.0.0.0:6379(processInputBuffer+0xf7)[0x55cb065cfb37]
redis-server 0.0.0.0:6379(readQueryFromClient+0x350)[0x55cb065d00a0]
redis-server 0.0.0.0:6379(+0x1affd8)[0x55cb066c2fd8]
redis-server 0.0.0.0:6379(aeMain+0xf9)[0x55cb065a0d09]
redis-server 0.0.0.0:6379(main+0x3cd)[0x55cb06595ecd]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xea)[0x7fbe2a645d0a]
redis-server 0.0.0.0:6379(_start+0x2a)[0x55cb0659664a]

------ REGISTERS ------
1:M 05 Feb 2024 17:42:53.341 # 
RAX:0000000000000000 RBX:00007fbe2a3a6f80
RCX:00000000000000ff RDX:0000000000000000
RDI:0000000000000000 RSI:00007ffecc260e48
RBP:00007fbe2a3a6f80 RSP:00007ffecc260d60
R8 :00007fbe2a31b303 R9 :0000000000000000
R10:00000000034275e8 R11:00007fbe2a61e1c0
R12:0000000000000000 R13:00007ffecc260e50
R14:000055cb066cd3e0 R15:00007ffecc260f40
RIP:000055cb065ca41b EFL:0000000000010206
CSGSFS:002b000000000033
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d6f) -> 00000002002a6e56
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d6e) -> 0000000000000000
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d6d) -> 0000000000000000
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d6c) -> 0000000000000000
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d6b) -> 0000000000000000
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d6a) -> 0000000000000000
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d69) -> 0000000000000000
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d68) -> 0000000000000040
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d67) -> 0000000000000000
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d66) -> 0000000000000000
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d65) -> 000055cb065ce68e
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d64) -> 000055cb066cd3e0
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d63) -> 00007ffecc260e50
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d62) -> 00007fbe2a2637f8
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d61) -> 00007fbe2a3a6f80
1:M 05 Feb 2024 17:42:53.341 # (00007ffecc260d60) -> 00007fbe2a3a6f80

------ INFO OUTPUT ------
# Server
redis_version:7.2.4
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:5480667114e70c31
redis_mode:standalone
os:Linux 5.14.0-284.18.1.el9_2.x86_64 x86_64
arch_bits:64
monotonic_clock:POSIX clock_gettime
multiplexing_api:epoll
atomicvar_api:c11-builtin
gcc_version:10.2.1
process_id:1
process_supervised:no
run_id:4dd51bf4dd6064409c7024df8aef811545ec7824
tcp_port:6379
server_time_usec:1707154973335742
uptime_in_seconds:76
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:12656157
executable:/redis-server
config_file:/opt/bitnami/redis/etc/redis.conf
io_threads_active:0
listener0:name=tcp,bind=0.0.0.0,bind=::,port=6379

# Clients
connected_clients:2
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:20480
client_recent_max_output_buffer:0
blocked_clients:0
tracking_clients:0
clients_in_timeout_table:0
total_blocking_keys:0
total_blocking_keys_on_nokey:0

# Memory
used_memory:1268288
used_memory_human:1.21M
used_memory_rss:14315520
used_memory_rss_human:13.65M
used_memory_peak:1421696
used_memory_peak_human:1.36M
used_memory_peak_perc:89.21%
used_memory_overhead:949804
used_memory_startup:882960
used_memory_dataset:318484
used_memory_dataset_perc:82.65%
allocator_allocated:1539280
allocator_active:1900544
allocator_resident:5070848
total_system_memory:8060624896
total_system_memory_human:7.51G
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:32768
used_memory_vm_total:64512
used_memory_vm_total_human:63.00K
used_memory_functions:184
used_memory_scripts:184
used_memory_scripts_human:184B
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.23
allocator_frag_bytes:361264
allocator_rss_ratio:2.67
allocator_rss_bytes:3170304
rss_overhead_ratio:2.82
rss_overhead_bytes:9244672
mem_fragmentation_ratio:10.51
mem_fragmentation_bytes:12953112
mem_not_counted_for_evict:160
mem_replication_backlog:20508
mem_total_replication_buffers:20504
mem_clients_slaves:0
mem_clients_normal:45880
mem_cluster_links:0
mem_aof_buffer:160
mem_allocator:jemalloc-5.3.0
active_defrag_running:0
lazyfree_pending_objects:0
lazyfreed_objects:0

# Persistence
loading:0
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:3
rdb_bgsave_in_progress:0
rdb_last_save_time:1707154897
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:0
aof_enabled:1
aof_rewrite_in_progress:0
aof_rewrite_scheduled:0
aof_last_rewrite_time_sec:0
aof_current_rewrite_time_sec:-1
aof_last_bgrewrite_status:ok
aof_rewrites:1
aof_rewrites_consecutive_failures:0
aof_last_write_status:ok
aof_last_cow_size:270336
module_fork_in_progress:0
module_fork_last_cow_size:0
aof_current_size:199
aof_base_size:88
aof_pending_rewrite:0
aof_buffer_length:0
aof_pending_bio_fsync:0
aof_delayed_fsync:0

# Stats
total_connections_received:8
total_commands_processed:480
instantaneous_ops_per_sec:6
total_net_input_bytes:32062
total_net_output_bytes:273719
total_net_repl_input_bytes:13397
total_net_repl_output_bytes:0
instantaneous_input_kbps:0.17
instantaneous_output_kbps:17.92
instantaneous_input_repl_kbps:0.00
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
total_eviction_exceeded_time:0
current_eviction_exceeded_time:0
keyspace_hits:0
keyspace_misses:0
pubsub_channels:1
pubsub_patterns:0
pubsubshard_channels:0
latest_fork_usec:180
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
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:2
dump_payload_sanitizations:0
total_reads_processed:457
total_writes_processed:1024
io_threaded_reads_processed:0
io_threaded_writes_processed:0
reply_buffer_shrinks:29
reply_buffer_expands:26
eventloop_cycles:1225
eventloop_duration_sum:333668
eventloop_duration_cmd_sum:10768
instantaneous_eventloop_cycles_per_sec:15
instantaneous_eventloop_duration_usec:223
acl_access_denied_auth:0
acl_access_denied_cmd:0
acl_access_denied_key:0
acl_access_denied_channel:0

# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:feadb1522c823132fcb73ee80e662517e0709240
master_replid2:19101531687e8bb50bfa92760d7096452b0b4eae
master_repl_offset:12992
second_repl_offset:12993
repl_backlog_active:1
repl_backlog_size:1048576
repl_backlog_first_byte_offset:159
repl_backlog_histlen:12834

# CPU
used_cpu_sys:0.203994
used_cpu_user:0.138127
used_cpu_sys_children:0.057010
used_cpu_user_children:0.043846
used_cpu_sys_main_thread:0.202166
used_cpu_user_main_thread:0.138179

# Modules
module:name=example,ver=1,api=1,filters=0,usedby=[],using=[],options=[]

# Commandstats
cmdstat_config|rewrite:calls=2,usec=2503,usec_per_call=1251.50,rejected_calls=0,failed_calls=2
cmdstat_exec:calls=2,usec=3147,usec_per_call=1573.50,rejected_calls=0,failed_calls=0
cmdstat_select:calls=2,usec=2,usec_per_call=1.00,rejected_calls=0,failed_calls=0
cmdstat_set:calls=3,usec=89,usec_per_call=29.67,rejected_calls=0,failed_calls=0
cmdstat_info:calls=32,usec=4867,usec_per_call=152.09,rejected_calls=0,failed_calls=0
cmdstat_ping:calls=222,usec=470,usec_per_call=2.12,rejected_calls=0,failed_calls=0
cmdstat_publish:calls=200,usec=2244,usec_per_call=11.22,rejected_calls=0,failed_calls=0
cmdstat_subscribe:calls=3,usec=6,usec_per_call=2.00,rejected_calls=0,failed_calls=0
cmdstat_multi:calls=2,usec=2,usec_per_call=1.00,rejected_calls=0,failed_calls=0
cmdstat_slaveof:calls=2,usec=497,usec_per_call=248.50,rejected_calls=0,failed_calls=0
cmdstat_client|setname:calls=8,usec=30,usec_per_call=3.75,rejected_calls=0,failed_calls=0
cmdstat_client|kill:calls=2,usec=110,usec_per_call=55.00,rejected_calls=0,failed_calls=0

# Errorstats
errorstat_ERR:count=2

# Latencystats
latency_percentiles_usec_config|rewrite:p50=1212.415,p99=1294.335,p99.9=1294.335
latency_percentiles_usec_exec:p50=1540.095,p99=1613.823,p99.9=1613.823
latency_percentiles_usec_select:p50=1.003,p99=1.003,p99.9=1.003
latency_percentiles_usec_set:p50=4.015,p99=82.431,p99.9=82.431
latency_percentiles_usec_info:p50=181.247,p99=368.639,p99.9=368.639
latency_percentiles_usec_ping:p50=2.007,p99=12.031,p99.9=47.103
latency_percentiles_usec_publish:p50=11.007,p99=64.255,p99.9=118.271
latency_percentiles_usec_subscribe:p50=2.007,p99=2.007,p99.9=2.007
latency_percentiles_usec_multi:p50=1.003,p99=1.003,p99.9=1.003
latency_percentiles_usec_slaveof:p50=188.415,p99=309.247,p99.9=309.247
latency_percentiles_usec_client|setname:p50=0.001,p99=23.039,p99.9=23.039
latency_percentiles_usec_client|kill:p50=48.127,p99=62.207,p99.9=62.207

# Cluster
cluster_enabled:0

# Keyspace
db0:keys=2,expires=0,avg_ttl=0

------ CLIENT LIST OUTPUT ------
id=6 addr=10.89.5.41:54528 laddr=10.89.5.39:6379 fd=12 name=sentinel-7a9cbc11-cmd age=74 idle=0 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 qbuf=0 qbuf-free=20474 argv-mem=0 multi-mem=0 rbs=2048 rbp=2048 obl=0 oll=0 omem=0 tot-mem=23424 events=r cmd=publish user=default redir=-1 resp=2 lib-name= lib-ver=
id=7 addr=10.89.5.41:54536 laddr=10.89.5.39:6379 fd=13 name=sentinel-7a9cbc11-pubsub age=74 idle=0 flags=P db=0 sub=1 psub=0 ssub=0 multi=-1 qbuf=0 qbuf-free=20474 argv-mem=0 multi-mem=0 rbs=1024 rbp=135 obl=0 oll=0 omem=0 tot-mem=22456 events=r cmd=subscribe user=default redir=-1 resp=2 lib-name= lib-ver=

------ EXECUTING CLIENT INFO ------

Additional information

We originally saw this behaviour in our actual custom redis module. We wondered if it was because when a node became master we were causing a few SET calls to be made on the master in the handler function. So we created an extremely simple module to test the theory and sure enough it was crashing. We were deploying using the helm chart and tried the bitnami redis containers with 6.2 and 7.2.4. Both crashed. We filed a bug with redis here. However they were unable to reproduce it. So we used podman to run a cluster locally, this time using redis:latest instead of bitnami. The master failover worked perfectly. So we used podman with the docker.io/bitnami/redis:7.2.4-debian-11-r2 container. It crashed identically as it did in k8s. Here's everything needed to reproduce:

The module was taken from here.
Compiled with

gcc -I/usr/include -Wall -g -fPIC -lc -lm -std=gnu99     -c -o module.o module.c
ld -o module.so module.o -shared -Bsymbolic  -lc 

The module.c below has been very much simplified by essentially doing nothing. We tested the failover with just log messages and it worked perfectly. Once we added the SET calls it crashes every time.

#include <redismodule.h>
#include <inttypes.h>

int ParseCommand(RedisModuleCtx *ctx, RedisModuleString **argv, int argc) {
  return REDISMODULE_OK;
}

void EventHandler(RedisModuleCtx *ctx, RedisModuleEvent eid, uint64_t subevent, void *data)
{
    RedisModule_Log(ctx, REDISMODULE_LOGLEVEL_NOTICE, "[EventHandler] Event Handler EVENT %"PRIu64" SUBEVENT %"PRIu64, eid.id, subevent);
    switch (eid.id)
    {
        case REDISMODULE_EVENT_MASTER_LINK_CHANGE:
            if (subevent == REDISMODULE_SUBEVENT_MASTER_LINK_DOWN){
                RedisModule_Log(ctx, REDISMODULE_LOGLEVEL_NOTICE, "[EventHandler] Master Replication Link Down");
            }
            if (subevent == REDISMODULE_SUBEVENT_MASTER_LINK_UP){
                RedisModule_Log(ctx, REDISMODULE_LOGLEVEL_NOTICE, "[EventHandler] Master Replication Link Up");
            }
            break;
        case REDISMODULE_EVENT_REPLICATION_ROLE_CHANGED:
            switch (subevent)
            {
                case REDISMODULE_EVENT_REPLROLECHANGED_NOW_MASTER:
                {
                    RedisModule_Log(ctx, REDISMODULE_LOGLEVEL_NOTICE, "[EventHandler] Became Master");
                    RedisModule_Log(ctx, REDISMODULE_LOGLEVEL_NOTICE, "[KAU] AAAAA master set");
	            RedisModule_Call(ctx, "SET", "cc", "kau-master", "1");
                    break;
                }
                case REDISMODULE_EVENT_REPLROLECHANGED_NOW_REPLICA:
                    RedisModule_Log(ctx, REDISMODULE_LOGLEVEL_NOTICE, "[EventHandler] Became Replica");
                    RedisModule_Log(ctx, REDISMODULE_LOGLEVEL_NOTICE, "[KAU] AAAAA replica set");
	            RedisModule_Call(ctx, "SET", "cc", "kau-replica", "1");
                    break;
                default:
                    break;
            }
            break;
        default:
            break;
    }
}

int RedisModule_OnLoad(RedisModuleCtx *ctx) {

  // Register the module itself
  if (RedisModule_Init(ctx, "example", 1, REDISMODULE_APIVER_1) == REDISMODULE_ERR) {
    return REDISMODULE_ERR;
  }

  // register example.parse - the default registration syntax
  if (RedisModule_CreateCommand(ctx, "example.parse", ParseCommand, "readonly", 1, 1, 1) == REDISMODULE_ERR) {
    return REDISMODULE_ERR;
  }

  RedisModule_SubscribeToServerEvent(ctx, RedisModuleEvent_ReplicationRoleChanged, EventHandler);
  /* Example on how to check if a server sub event is supported */
  if (RedisModule_IsSubEventSupported(RedisModuleEvent_MasterLinkChange, REDISMODULE_SUBEVENT_MASTER_LINK_UP)) {
      RedisModule_SubscribeToServerEvent(ctx, RedisModuleEvent_MasterLinkChange, EventHandler);
  }

  return REDISMODULE_OK;
}

The Dockerfile

FROM docker.io/bitnami/redis:7.2.4-debian-11-r2

USER root

# Install redis module
RUN mkdir -p /usr/lib64/
COPY ./module.so /usr/lib64/redis-test-module.so

# Create overrides for redis
COPY overrides.conf /opt/bitnami/redis/mounted-etc/overrides.conf

overrides.conf:

loadmodule  /usr/lib64/redis-test-module.so

We were using https://github.com/AliyunContainerService/redis-cluster as a basis to setup the redis+sentinel in podman. So had built a sentinel image using their sentinel/Dockerfile to be used in the following docker-compose.yaml

---
version: '3.9'

services:
  master:
    image: localhost/bitnami:test
    container_name: redis-master
    environment:
      - ALLOW_EMPTY_PASSWORD=yes
      - REDIS_REPLICATION_MODE=master
      - REDIS_REPLICA_IP=redis-master

  slave1:
    image: localhost/bitnami:test
    container_name: redis-slave1
    environment:
      - ALLOW_EMPTY_PASSWORD=yes
      - REDIS_REPLICATION_MODE=slave
      - REDIS_MASTER_HOST=redis-master
    depends_on:
      - master

  slave2:
    image: localhost/bitnami:test
    container_name: redis-slave2
    environment:
      - ALLOW_EMPTY_PASSWORD=yes
      - REDIS_REPLICATION_MODE=slave
      - REDIS_MASTER_HOST=redis-master
    depends_on:
      - master

  slave3:
    image: localhost/bitnami:test
    container_name: redis-slave3
    environment:
      - ALLOW_EMPTY_PASSWORD=yes
      - REDIS_REPLICATION_MODE=slave
      - REDIS_MASTER_HOST=redis-master
    depends_on:
      - master

  sentinel1:
    image: localhost/sentinel:test
    container_name: redis-sentinel1
    environment:
      - SENTINEL_DOWN_AFTER=5000
      - SENTINEL_FAILOVER=5000
    depends_on:
      - master
      - slave1
      - slave2
      - slave3

  sentinel2:
    image: localhost/sentinel:test
    container_name: redis-sentinel2
    environment:
      - SENTINEL_DOWN_AFTER=5000
      - SENTINEL_FAILOVER=5000
    depends_on:
      - master
      - slave1
      - slave2
      - slave3

  sentinel3:
    image: localhost/sentinel:test
    container_name: redis-sentinel3
    environment:
      - SENTINEL_DOWN_AFTER=5000
      - SENTINEL_FAILOVER=5000
    depends_on:
      - master
      - slave1
      - slave2
      - slave3

This brought up redis, we could see all redis instances sync with the master. Checking replication info on the master showed 3 slaves. running podman pause redis-master the sentinels noticed it went down, a slave was chosen to become master but you'll see in the test set message it crashes. If we remove the call to the SET function, there's no crash.

What is super odd is that this does not occur if we use redis:7.2.4 instead of bitnami for our redis master/slave containers or nodes.

@wgnathanael wgnathanael added the tech-issues The user has a technical issue about an application label Feb 5, 2024
@wgnathanael wgnathanael changed the title Module crashes when master failover when a write is done [bitnami/redis] Module crashes when master failover when a write is done Feb 5, 2024
@github-actions github-actions bot added the triage Triage is needed label Feb 5, 2024
@wgnathanael
Copy link
Author

As an attempt to isolate the issue a bit further, I've checked out the bitnami/containers repo, and tried using debian:bullseye instead of minideb:bullseye. Same crash occurs. How can we find out how redis is being compiled? The Dockerfile is just downloading pre-compiled binaries as far as I can tell.

@wgnathanael
Copy link
Author

Also, where/how is redis being compiled? I can't find any repo that details how this is being compiled. Redis being opensource, doesn't that need to be provided somewhere so people can see the provenance and any patches applied etc? (Not meant in an accusatory tone, just generally curious)

@github-actions github-actions bot removed the triage Triage is needed label Feb 7, 2024
@github-actions github-actions bot assigned Mauraza and unassigned carrodher Feb 7, 2024
@Mauraza
Copy link
Contributor

Mauraza commented Feb 13, 2024

Hi @wgnathanael,

I'm trying to reproduce this, could you tell us if the sentinel:test is bitnami:redis-sentinel or if you made any changes?

Copy link

This Issue has been automatically marked as "stale" because it has not had recent activity (for 15 days). It will be closed if no further activity occurs. Thanks for the feedback.

@github-actions github-actions bot added the stale 15 days without activity label Feb 29, 2024
@wgnathanael
Copy link
Author

Hello @Mauraza, Not sure why I didn't get a notification when you wrote. The sentinel:test container is built using https://github.com/AliyunContainerService/redis-cluster where we used their sentinel/Dockerfile. Which is fairly straight forward:

FROM redis:3

MAINTAINER Li Yi <denverdino@gmail.com>

EXPOSE 26379
ADD sentinel.conf /etc/redis/sentinel.conf
RUN chown redis:redis /etc/redis/sentinel.conf
ENV SENTINEL_QUORUM 2
ENV SENTINEL_DOWN_AFTER 5000
ENV SENTINEL_FAILOVER 1000
COPY sentinel-entrypoint.sh /usr/local/bin/
RUN chmod +x /usr/local/bin/sentinel-entrypoint.sh
ENTRYPOINT ["sentinel-entrypoint.sh"]

It's using the base redis image.

We weren't using the bitnami image because failover there is plagued by issues with sentinel going into tilt mode and the sentinel servers taking forever to be able to come to agreement about the master node being down. bitnami/charts#9689 is the issue we found describing the tilt issue in the bitnami container. The work arounds essentially mean if you disable tls and hostnames there's no tilt issue but then there are connectivity and encryption issues.. We're still evaluating that aspect.

@github-actions github-actions bot removed the stale 15 days without activity label Mar 1, 2024
@Mauraza
Copy link
Contributor

Mauraza commented Mar 6, 2024

@wgnathanael
Copy link
Author

wgnathanael commented Mar 6, 2024

For weird implementation reasons we don't always use the cluster mode where it does its own sharding etc. Our module handles a node affinity type situation differently depending on if its cluster mode or not. W do have a version using redis-cluster, but we also support the non redis-cluster mode and so need failover in that situation to work as well. (We haven't gotten to testing redis-cluster as of yet).

@Mauraza
Copy link
Contributor

Mauraza commented Mar 11, 2024

Could you add to the environment variable in the bitnami images BITNAMI_DEBUG=true? to check if the logs appear something?

@wgnathanael
Copy link
Author

Doesn't seem to provide any additional information that I can see

redis 14:07:15.01 INFO  ==> 
redis 14:07:15.01 INFO  ==> Welcome to the Bitnami redis container
redis 14:07:15.01 INFO  ==> Subscribe to project updates by watching https://github.com/bitnami/containers
redis 14:07:15.01 INFO  ==> Submit issues and feature requests at https://github.com/bitnami/containers/issues
redis 14:07:15.01 INFO  ==> 
redis 14:07:15.01 INFO  ==> ** Starting Redis setup **
redis 14:07:15.02 DEBUG ==> Validating settings in REDIS_* env vars..
redis 14:07:15.03 WARN  ==> You set the environment variable ALLOW_EMPTY_PASSWORD=yes. For safety reasons, do not use this flag in a production environment.
redis 14:07:15.05 INFO  ==> Initializing Redis
redis 14:07:15.06 DEBUG ==> Ensuring expected directories/files exist
podman start -a redis-slave1
redis 14:07:15.07 INFO  ==> Setting Redis config file
redis 14:07:15.12 INFO  ==> Configuring replication mode
redis 14:07:15.13 INFO  ==> ** Redis setup finished! **
[master]    | 
redis 14:07:15.15 INFO  ==> ** Starting Redis **
[master]    | 1:C 11 Mar 2024 14:07:15.164 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
[master]    | 1:C 11 Mar 2024 14:07:15.165 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
[master]    | 1:C 11 Mar 2024 14:07:15.165 * Redis version=7.2.4, bits=64, commit=00000000, modified=0, pid=1, just started
[master]    | 1:C 11 Mar 2024 14:07:15.165 * Configuration loaded
[master]    | 1:M 11 Mar 2024 14:07:15.165 * monotonic clock: POSIX clock_gettime
[master]    | 1:M 11 Mar 2024 14:07:15.166 * Running mode=standalone, port=6379.
[master]    | 1:M 11 Mar 2024 14:07:15.166 * Module 'example' loaded from /usr/lib64/redis-test-module.so
[master]    | 1:M 11 Mar 2024 14:07:15.166 * Server initialized
[master]    | 1:M 11 Mar 2024 14:07:15.169 * Creating AOF base file appendonly.aof.1.base.rdb on server start
[master]    | 1:M 11 Mar 2024 14:07:15.170 * Creating AOF incr file appendonly.aof.1.incr.aof on server start
[master]    | 1:M 11 Mar 2024 14:07:15.170 * Ready to accept connections tcp
redis 14:07:15.25 INFO  ==> 
redis 14:07:15.25 INFO  ==> Welcome to the Bitnami redis container
redis 14:07:15.25 INFO  ==> Subscribe to project updates by watching https://github.com/bitnami/containers
redis 14:07:15.25 INFO  ==> Submit issues and feature requests at https://github.com/bitnami/containers/issues
redis 14:07:15.25 INFO  ==> 
redis 14:07:15.25 INFO  ==> ** Starting Redis setup **
redis 14:07:15.27 DEBUG ==> Validating settings in REDIS_* env vars..
redis 14:07:15.27 WARN  ==> You set the environment variable ALLOW_EMPTY_PASSWORD=yes. For safety reasons, do not use this flag in a production environment.
redis 14:07:15.33 INFO  ==> Initializing Redis
redis 14:07:15.34 DEBUG ==> Ensuring expected directories/files exist
redis 14:07:15.36 INFO  ==> Setting Redis config file
redis 14:07:15.41 INFO  ==> Configuring replication mode
redis 14:07:15.46 INFO  ==> ** Redis setup finished! **
[slave1]    | 
redis 14:07:15.47 INFO  ==> ** Starting Redis **
[slave1]    | 1:C 11 Mar 2024 14:07:15.493 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
[slave1]    | 1:C 11 Mar 2024 14:07:15.494 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
[slave1]    | 1:C 11 Mar 2024 14:07:15.494 * Redis version=7.2.4, bits=64, commit=00000000, modified=0, pid=1, just started
[slave1]    | 1:C 11 Mar 2024 14:07:15.494 * Configuration loaded
[slave1]    | 1:S 11 Mar 2024 14:07:15.494 * monotonic clock: POSIX clock_gettime
[slave1]    | 1:S 11 Mar 2024 14:07:15.495 * Running mode=standalone, port=6379.
[slave1]    | 1:S 11 Mar 2024 14:07:15.495 * Module 'example' loaded from /usr/lib64/redis-test-module.so
[slave1]    | 1:S 11 Mar 2024 14:07:15.495 * Server initialized
[slave1]    | 1:S 11 Mar 2024 14:07:15.496 * Creating AOF base file appendonly.aof.1.base.rdb on server start
[slave1]    | 1:S 11 Mar 2024 14:07:15.497 * Creating AOF incr file appendonly.aof.1.incr.aof on server start
[slave1]    | 1:S 11 Mar 2024 14:07:15.497 * Ready to accept connections tcp
[slave1]    | 1:S 11 Mar 2024 14:07:15.497 * Connecting to MASTER redis-master:6379
[slave1]    | 1:S 11 Mar 2024 14:07:15.498 * MASTER <-> REPLICA sync started
[slave1]    | 1:S 11 Mar 2024 14:07:15.498 * Non blocking connect for SYNC fired the event.
[slave1]    | 1:S 11 Mar 2024 14:07:15.498 * Master replied to PING, replication can continue...
[slave1]    | 1:S 11 Mar 2024 14:07:15.498 * Partial resynchronization not possible (no cached master)
[master]    | 1:M 11 Mar 2024 14:07:15.498 * Replica 10.89.5.3:6379 asks for synchronization
[master]    | 1:M 11 Mar 2024 14:07:15.499 * Full resync requested by replica 10.89.5.3:6379
[master]    | 1:M 11 Mar 2024 14:07:15.499 * Replication backlog created, my new replication IDs are 'c08f0bded9a7d84ce9b8484b182a402a54e5cd57' and '0000000000000000000000000000000000000000'
[master]    | 1:M 11 Mar 2024 14:07:15.499 * Delay next BGSAVE for diskless SYNC
podman start -a redis-slave2
redis 14:07:16.21 INFO  ==> 
redis 14:07:16.21 INFO  ==> Welcome to the Bitnami redis container
redis 14:07:16.21 INFO  ==> Subscribe to project updates by watching https://github.com/bitnami/containers
redis 14:07:16.21 INFO  ==> Submit issues and feature requests at https://github.com/bitnami/containers/issues
redis 14:07:16.21 INFO  ==> 
redis 14:07:16.21 INFO  ==> ** Starting Redis setup **
redis 14:07:16.22 DEBUG ==> Validating settings in REDIS_* env vars..
redis 14:07:16.23 WARN  ==> You set the environment variable ALLOW_EMPTY_PASSWORD=yes. For safety reasons, do not use this flag in a production environment.
redis 14:07:16.29 INFO  ==> Initializing Redis
redis 14:07:16.29 DEBUG ==> Ensuring expected directories/files exist
redis 14:07:16.32 INFO  ==> Setting Redis config file
redis 14:07:16.38 INFO  ==> Configuring replication mode
redis 14:07:16.46 INFO  ==> ** Redis setup finished! **
[slave2]    | 
redis 14:07:16.48 INFO  ==> ** Starting Redis **
[slave2]    | 1:C 11 Mar 2024 14:07:16.494 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
[slave2]    | 1:C 11 Mar 2024 14:07:16.494 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
[slave2]    | 1:C 11 Mar 2024 14:07:16.494 * Redis version=7.2.4, bits=64, commit=00000000, modified=0, pid=1, just started
[slave2]    | 1:C 11 Mar 2024 14:07:16.494 * Configuration loaded
[slave2]    | 1:S 11 Mar 2024 14:07:16.494 * monotonic clock: POSIX clock_gettime
[slave2]    | 1:S 11 Mar 2024 14:07:16.494 * Running mode=standalone, port=6379.
[slave2]    | 1:S 11 Mar 2024 14:07:16.495 * Module 'example' loaded from /usr/lib64/redis-test-module.so
[slave2]    | 1:S 11 Mar 2024 14:07:16.498 * Server initialized
[slave2]    | 1:S 11 Mar 2024 14:07:16.500 * Creating AOF base file appendonly.aof.1.base.rdb on server start
[slave2]    | 1:S 11 Mar 2024 14:07:16.502 * Creating AOF incr file appendonly.aof.1.incr.aof on server start
[slave2]    | 1:S 11 Mar 2024 14:07:16.502 * Ready to accept connections tcp
[slave2]    | 1:S 11 Mar 2024 14:07:16.502 * Connecting to MASTER redis-master:6379
[slave2]    | 1:S 11 Mar 2024 14:07:16.504 * MASTER <-> REPLICA sync started
[slave2]    | 1:S 11 Mar 2024 14:07:16.504 * Non blocking connect for SYNC fired the event.
[slave2]    | 1:S 11 Mar 2024 14:07:16.505 * Master replied to PING, replication can continue...
[slave2]    | 1:S 11 Mar 2024 14:07:16.505 * Partial resynchronization not possible (no cached master)
[master]    | 1:M 11 Mar 2024 14:07:16.505 * Replica 10.89.5.4:6379 asks for synchronization
[master]    | 1:M 11 Mar 2024 14:07:16.505 * Full resync requested by replica 10.89.5.4:6379
[master]    | 1:M 11 Mar 2024 14:07:16.505 * Delay next BGSAVE for diskless SYNC
podman start -a redis-sentinel1
[sentinel1] |                 _._                                                  
[sentinel1] |            _.-``__ ''-._                                             
[sentinel1] |       _.-``    `.  `_.  ''-._           Redis 3.2.12 (00000000/0) 64 bit
[sentinel1] |   .-`` .-```.  ```\/    _.,_ ''-._                                   
[sentinel1] |  (    '      ,       .-`  | `,    )     Running in sentinel mode
[sentinel1] |  |`-._`-...-` __...-.``-._|'` _.-'|     Port: 26379
[sentinel1] |  |    `-._   `._    /     _.-'    |     PID: 1
[sentinel1] |   `-._    `-._  `-./  _.-'    _.-'                                   
[sentinel1] |  |`-._`-._    `-.__.-'    _.-'_.-'|                                  
[sentinel1] |  |    `-._`-._        _.-'_.-'    |           http://redis.io        
[sentinel1] |   `-._    `-._`-.__.-'_.-'    _.-'                                   
[sentinel1] |  |`-._`-._    `-.__.-'    _.-'_.-'|                                  
[sentinel1] |  |    `-._`-._        _.-'_.-'    |                                  
[sentinel1] |   `-._    `-._`-.__.-'_.-'    _.-'                                   
[sentinel1] |       `-._    `-.__.-'    _.-'                                       
[sentinel1] |           `-._        _.-'                                           
[sentinel1] |               `-.__.-'                                               
[sentinel1] | 
[sentinel1] | 1:X 11 Mar 14:07:17.242 # Sentinel ID is ea7537e2ae8dce2499f3ca5bfffa84d3c54f13b6
[sentinel1] | 1:X 11 Mar 14:07:17.242 # +monitor master mymaster 10.89.5.2 6379 quorum 2
[sentinel1] | 1:X 11 Mar 14:07:17.243 * +slave slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:17.245 * +slave slave 10.89.5.4:6379 10.89.5.4 6379 @ mymaster 10.89.5.2 6379
podman start -a redis-sentinel2
[sentinel2] |                 _._                                                  
[sentinel2] |            _.-``__ ''-._                                             
[sentinel2] |       _.-``    `.  `_.  ''-._           Redis 3.2.12 (00000000/0) 64 bit
[sentinel2] |   .-`` .-```.  ```\/    _.,_ ''-._                                   
[sentinel2] |  (    '      ,       .-`  | `,    )     Running in sentinel mode
[sentinel2] |  |`-._`-...-` __...-.``-._|'` _.-'|     Port: 26379
[sentinel2] |  |    `-._   `._    /     _.-'    |     PID: 1
[sentinel2] |   `-._    `-._  `-./  _.-'    _.-'                                   
[sentinel2] |  |`-._`-._    `-.__.-'    _.-'_.-'|                                  
[sentinel2] |  |    `-._`-._        _.-'_.-'    |           http://redis.io        
[sentinel2] |   `-._    `-._`-.__.-'_.-'    _.-'                                   
[sentinel2] |  |`-._`-._    `-.__.-'    _.-'_.-'|                                  
[sentinel2] |  |    `-._`-._        _.-'_.-'    |                                  
[sentinel2] |   `-._    `-._`-.__.-'_.-'    _.-'                                   
[sentinel2] |       `-._    `-.__.-'    _.-'                                       
[sentinel2] |           `-._        _.-'                                           
[sentinel2] |               `-.__.-'                                               
[sentinel2] | 
[sentinel2] | 1:X 11 Mar 14:07:18.270 # Sentinel ID is 68bdcf22b4195c8f41007c295d1513e9859476a0
[sentinel2] | 1:X 11 Mar 14:07:18.270 # +monitor master mymaster 10.89.5.2 6379 quorum 2
[sentinel2] | 1:X 11 Mar 14:07:18.271 * +slave slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.2 6379
[sentinel2] | 1:X 11 Mar 14:07:18.271 * +slave slave 10.89.5.4:6379 10.89.5.4 6379 @ mymaster 10.89.5.2 6379
podman start -a redis-sentinel3
[sentinel3] |                 _._                                                  
[sentinel3] |            _.-``__ ''-._                                             
[sentinel3] |       _.-``    `.  `_.  ''-._           Redis 3.2.12 (00000000/0) 64 bit
[sentinel3] |   .-`` .-```.  ```\/    _.,_ ''-._                                   
[sentinel3] |  (    '      ,       .-`  | `,    )     Running in sentinel mode
[sentinel3] |  |`-._`-...-` __...-.``-._|'` _.-'|     Port: 26379
[sentinel3] |  |    `-._   `._    /     _.-'    |     PID: 1
[sentinel3] |   `-._    `-._  `-./  _.-'    _.-'                                   
[sentinel3] |  |`-._`-._    `-.__.-'    _.-'_.-'|                                  
[sentinel3] |  |    `-._`-._        _.-'_.-'    |           http://redis.io        
[sentinel3] |   `-._    `-._`-.__.-'_.-'    _.-'                                   
[sentinel3] |  |`-._`-._    `-.__.-'    _.-'_.-'|                                  
[sentinel3] |  |    `-._`-._        _.-'_.-'    |                                  
[sentinel3] |   `-._    `-._`-.__.-'_.-'    _.-'                                   
[sentinel3] |       `-._    `-.__.-'    _.-'                                       
[sentinel3] |           `-._        _.-'                                           
[sentinel3] |               `-.__.-'                                               
[sentinel3] | 
[sentinel3] | 1:X 11 Mar 14:07:19.258 # Sentinel ID is ce11e66f8b9a401cfaee85959e6f8cff710df519
[sentinel3] | 1:X 11 Mar 14:07:19.258 # +monitor master mymaster 10.89.5.2 6379 quorum 2
[sentinel3] | 1:X 11 Mar 14:07:19.259 * +slave slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.2 6379
[sentinel3] | 1:X 11 Mar 14:07:19.259 * +slave slave 10.89.5.4:6379 10.89.5.4 6379 @ mymaster 10.89.5.2 6379
[sentinel2] | 1:X 11 Mar 14:07:19.264 * +sentinel sentinel ea7537e2ae8dce2499f3ca5bfffa84d3c54f13b6 10.89.5.5 26379 @ mymaster 10.89.5.2 6379
[sentinel3] | 1:X 11 Mar 14:07:19.331 * +sentinel sentinel ea7537e2ae8dce2499f3ca5bfffa84d3c54f13b6 10.89.5.5 26379 @ mymaster 10.89.5.2 6379
[slave2]    | 1:S 11 Mar 2024 14:07:20.198 * Full resync from master: c08f0bded9a7d84ce9b8484b182a402a54e5cd57:156
[slave1]    | 1:S 11 Mar 2024 14:07:20.198 * Full resync from master: c08f0bded9a7d84ce9b8484b182a402a54e5cd57:156
[slave2]    | 1:S 11 Mar 2024 14:07:20.199 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk
[slave1]    | 1:S 11 Mar 2024 14:07:20.199 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk
[slave2]    | 1:S 11 Mar 2024 14:07:20.199 * MASTER <-> REPLICA sync: Flushing old data
[slave2]    | 1:S 11 Mar 2024 14:07:20.199 * MASTER <-> REPLICA sync: Loading DB in memory
[slave1]    | 1:S 11 Mar 2024 14:07:20.199 * MASTER <-> REPLICA sync: Flushing old data
[slave1]    | 1:S 11 Mar 2024 14:07:20.199 * MASTER <-> REPLICA sync: Loading DB in memory
[master]    | 1:M 11 Mar 2024 14:07:20.198 * Starting BGSAVE for SYNC with target: replicas sockets
[master]    | 1:M 11 Mar 2024 14:07:20.198 * Background RDB transfer started by pid 76
[master]    | 76:C 11 Mar 2024 14:07:20.199 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
[master]    | 1:M 11 Mar 2024 14:07:20.199 * Diskless rdb transfer, done reading from pipe, 2 replicas still up.
[slave2]    | 1:S 11 Mar 2024 14:07:20.201 * Loading RDB produced by version 7.2.4
[slave2]    | 1:S 11 Mar 2024 14:07:20.201 * RDB age 0 seconds
[slave2]    | 1:S 11 Mar 2024 14:07:20.201 * RDB memory usage when created 1.16 Mb
[slave2]    | 1:S 11 Mar 2024 14:07:20.201 * Done loading RDB, keys loaded: 0, keys expired: 0.
[slave2]    | 1:S 11 Mar 2024 14:07:20.201 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 0
[slave1]    | 1:S 11 Mar 2024 14:07:20.201 * Loading RDB produced by version 7.2.4
[slave1]    | 1:S 11 Mar 2024 14:07:20.201 * RDB age 0 seconds
[slave1]    | 1:S 11 Mar 2024 14:07:20.201 * RDB memory usage when created 1.16 Mb
[slave1]    | 1:S 11 Mar 2024 14:07:20.201 * Done loading RDB, keys loaded: 0, keys expired: 0.
[slave1]    | 1:S 11 Mar 2024 14:07:20.201 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 0
[slave1]    | 1:S 11 Mar 2024 14:07:20.201 * <example> [EventHandler] Master Replication Link Up
[slave1]    | 1:S 11 Mar 2024 14:07:20.201 * MASTER <-> REPLICA sync: Finished with success
[slave1]    | 1:S 11 Mar 2024 14:07:20.201 * Creating AOF incr file temp-appendonly.aof.incr on background rewrite
[slave1]    | 1:S 11 Mar 2024 14:07:20.201 * Background append only file rewriting started by pid 98
[slave2]    | 1:S 11 Mar 2024 14:07:20.201 * <example> [EventHandler] Master Replication Link Up
[slave2]    | 1:S 11 Mar 2024 14:07:20.201 * MASTER <-> REPLICA sync: Finished with success
[master]    | 1:M 11 Mar 2024 14:07:20.201 * Background RDB transfer terminated with success
[master]    | 1:M 11 Mar 2024 14:07:20.201 * Streamed RDB transfer with replica 10.89.5.3:6379 succeeded (socket). Waiting for REPLCONF ACK from replica to enable streaming
[master]    | 1:M 11 Mar 2024 14:07:20.201 * Synchronization with replica 10.89.5.3:6379 succeeded
[master]    | 1:M 11 Mar 2024 14:07:20.201 * Streamed RDB transfer with replica 10.89.5.4:6379 succeeded (socket). Waiting for REPLCONF ACK from replica to enable streaming
[master]    | 1:M 11 Mar 2024 14:07:20.201 * Synchronization with replica 10.89.5.4:6379 succeeded
[slave2]    | 1:S 11 Mar 2024 14:07:20.201 * Creating AOF incr file temp-appendonly.aof.incr on background rewrite
[slave2]    | 1:S 11 Mar 2024 14:07:20.202 * Background append only file rewriting started by pid 99
[slave1]    | 98:C 11 Mar 2024 14:07:20.203 * Successfully created the temporary AOF base file temp-rewriteaof-bg-98.aof
[slave2]    | 99:C 11 Mar 2024 14:07:20.203 * Successfully created the temporary AOF base file temp-rewriteaof-bg-99.aof
[slave1]    | 98:C 11 Mar 2024 14:07:20.203 * Fork CoW for AOF rewrite: current 0 MB, peak 0 MB, average 0 MB
[slave2]    | 99:C 11 Mar 2024 14:07:20.203 * Fork CoW for AOF rewrite: current 0 MB, peak 0 MB, average 0 MB
[slave2]    | 1:S 11 Mar 2024 14:07:20.227 * Background AOF rewrite terminated with success
[slave2]    | 1:S 11 Mar 2024 14:07:20.227 * Successfully renamed the temporary AOF base file temp-rewriteaof-bg-99.aof into appendonly.aof.2.base.rdb
[slave2]    | 1:S 11 Mar 2024 14:07:20.227 * Successfully renamed the temporary AOF incr file temp-appendonly.aof.incr into appendonly.aof.2.incr.aof
[slave1]    | 1:S 11 Mar 2024 14:07:20.228 * Background AOF rewrite terminated with success
[slave1]    | 1:S 11 Mar 2024 14:07:20.228 * Successfully renamed the temporary AOF base file temp-rewriteaof-bg-98.aof into appendonly.aof.2.base.rdb
[slave1]    | 1:S 11 Mar 2024 14:07:20.228 * Successfully renamed the temporary AOF incr file temp-appendonly.aof.incr into appendonly.aof.2.incr.aof
[slave2]    | 1:S 11 Mar 2024 14:07:20.228 * Removing the history file appendonly.aof.1.incr.aof in the background
[slave2]    | 1:S 11 Mar 2024 14:07:20.228 * Removing the history file appendonly.aof.1.base.rdb in the background
[slave2]    | 1:S 11 Mar 2024 14:07:20.229 * Background AOF rewrite finished successfully
[slave1]    | 1:S 11 Mar 2024 14:07:20.230 * Removing the history file appendonly.aof.1.incr.aof in the background
[slave1]    | 1:S 11 Mar 2024 14:07:20.230 * Removing the history file appendonly.aof.1.base.rdb in the background
[slave1]    | 1:S 11 Mar 2024 14:07:20.231 * Background AOF rewrite finished successfully
[sentinel3] | 1:X 11 Mar 14:07:20.318 * +sentinel sentinel 68bdcf22b4195c8f41007c295d1513e9859476a0 10.89.5.6 26379 @ mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:20.320 * +sentinel sentinel 68bdcf22b4195c8f41007c295d1513e9859476a0 10.89.5.6 26379 @ mymaster 10.89.5.2 6379
[sentinel2] | 1:X 11 Mar 14:07:21.323 * +sentinel sentinel ce11e66f8b9a401cfaee85959e6f8cff710df519 10.89.5.7 26379 @ mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:21.323 * +sentinel sentinel ce11e66f8b9a401cfaee85959e6f8cff710df519 10.89.5.7 26379 @ mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:30.440 * +fix-slave-config slave 10.89.5.4:6379 10.89.5.4 6379 @ mymaster 10.89.5.2 6379
[slave2]    | 1:M 11 Mar 2024 14:07:30.441 * Connection with master lost.
[master]    | 1:M 11 Mar 2024 14:07:30.441 * Connection with replica 10.89.5.4:6379 lost.
[slave2]    | 1:M 11 Mar 2024 14:07:30.441 * Caching the disconnected master state.
[slave2]    | 1:M 11 Mar 2024 14:07:30.441 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
[slave2]    | 1:M 11 Mar 2024 14:07:30.441 * <example> [EventHandler] Master Replication Link Down
[slave2]    | 1:S 11 Mar 2024 14:07:30.441 * <example> [EventHandler] Event Handler EVENT 0 SUBEVENT 1
[slave2]    | 1:S 11 Mar 2024 14:07:30.441 * <example> [EventHandler] Became Replica
[slave2]    | 1:S 11 Mar 2024 14:07:30.441 * <example> [KAU] AAAAA replica set
[slave2]    | 1:S 11 Mar 2024 14:07:30.441 * Connecting to MASTER 10.89.5.2:6379
[slave2]    | 1:S 11 Mar 2024 14:07:30.442 * MASTER <-> REPLICA sync started
[slave2]    | 1:S 11 Mar 2024 14:07:30.442 * REPLICAOF 10.89.5.2:6379 enabled (user request from 'id=4 addr=10.89.5.5:40478 laddr=10.89.5.4:6379 fd=10 name=sentinel-ea7537e2-cmd age=13 idle=0 flags=x db=0 sub=0 psub=0 ssub=0 multi=3 qbuf=148 qbuf-free=20326 argv-mem=4 multi-mem=125 rbs=1024 rbp=1024 obl=36 oll=0 omem=0 tot-mem=22649 events=r cmd=exec user=default redir=-1 resp=2 lib-name= lib-ver=')
[slave2]    | 1:S 11 Mar 2024 14:07:30.443 # Could not create tmp config file (Permission denied)
[slave2]    | 1:S 11 Mar 2024 14:07:30.443 # CONFIG REWRITE failed: Permission denied
[slave2]    | 1:S 11 Mar 2024 14:07:30.443 * Non blocking connect for SYNC fired the event.
[slave2]    | 1:S 11 Mar 2024 14:07:30.444 * Master replied to PING, replication can continue...
[slave2]    | 1:S 11 Mar 2024 14:07:30.444 * Trying a partial resynchronization (request c08f0bded9a7d84ce9b8484b182a402a54e5cd57:2189).
[master]    | 1:M 11 Mar 2024 14:07:30.444 * Replica 10.89.5.4:6379 asks for synchronization
[master]    | 1:M 11 Mar 2024 14:07:30.444 * Partial resynchronization request from 10.89.5.4:6379 accepted. Sending 0 bytes of backlog starting from offset 2189.
[slave2]    | 1:S 11 Mar 2024 14:07:30.444 * Successful partial resynchronization with master.
[slave2]    | 1:S 11 Mar 2024 14:07:30.444 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 0
[slave2]    | 1:S 11 Mar 2024 14:07:30.444 * <example> [EventHandler] Master Replication Link Up
[slave2]    | 1:S 11 Mar 2024 14:07:30.445 * MASTER <-> REPLICA sync: Master accepted a Partial Resynchronization.
[sentinel2] | 1:X 11 Mar 14:07:30.455 * +fix-slave-config slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.2 6379
[slave1]    | 1:M 11 Mar 2024 14:07:30.456 * Connection with master lost.
[slave1]    | 1:M 11 Mar 2024 14:07:30.456 * Caching the disconnected master state.
[slave1]    | 1:M 11 Mar 2024 14:07:30.456 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
[slave1]    | 1:M 11 Mar 2024 14:07:30.456 * <example> [EventHandler] Master Replication Link Down
[slave1]    | 1:S 11 Mar 2024 14:07:30.456 * <example> [EventHandler] Event Handler EVENT 0 SUBEVENT 1
[slave1]    | 1:S 11 Mar 2024 14:07:30.456 * <example> [EventHandler] Became Replica
[slave1]    | 1:S 11 Mar 2024 14:07:30.456 * <example> [KAU] AAAAA replica set
[slave1]    | 1:S 11 Mar 2024 14:07:30.456 * Connecting to MASTER 10.89.5.2:6379
[slave1]    | 1:S 11 Mar 2024 14:07:30.456 * MASTER <-> REPLICA sync started
[slave1]    | 1:S 11 Mar 2024 14:07:30.456 * REPLICAOF 10.89.5.2:6379 enabled (user request from 'id=6 addr=10.89.5.6:45182 laddr=10.89.5.3:6379 fd=12 name=sentinel-68bdcf22-cmd age=12 idle=0 flags=x db=0 sub=0 psub=0 ssub=0 multi=3 qbuf=148 qbuf-free=20326 argv-mem=4 multi-mem=125 rbs=1024 rbp=1024 obl=36 oll=0 omem=0 tot-mem=22649 events=r cmd=exec user=default redir=-1 resp=2 lib-name= lib-ver=')
[master]    | 1:M 11 Mar 2024 14:07:30.456 * Connection with replica 10.89.5.3:6379 lost.
[slave1]    | 1:S 11 Mar 2024 14:07:30.457 # Could not create tmp config file (Permission denied)
[slave1]    | 1:S 11 Mar 2024 14:07:30.457 # CONFIG REWRITE failed: Permission denied
[slave1]    | 1:S 11 Mar 2024 14:07:30.457 * Non blocking connect for SYNC fired the event.
[slave1]    | 1:S 11 Mar 2024 14:07:30.458 * Master replied to PING, replication can continue...
[slave1]    | 1:S 11 Mar 2024 14:07:30.458 * Trying a partial resynchronization (request c08f0bded9a7d84ce9b8484b182a402a54e5cd57:2189).
[master]    | 1:M 11 Mar 2024 14:07:30.458 * Replica 10.89.5.3:6379 asks for synchronization
[master]    | 1:M 11 Mar 2024 14:07:30.458 * Partial resynchronization request from 10.89.5.3:6379 accepted. Sending 0 bytes of backlog starting from offset 2189.
[slave1]    | 1:S 11 Mar 2024 14:07:30.458 * Successful partial resynchronization with master.
[slave1]    | 1:S 11 Mar 2024 14:07:30.458 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 0
[slave1]    | 1:S 11 Mar 2024 14:07:30.458 * <example> [EventHandler] Master Replication Link Up
[slave1]    | 1:S 11 Mar 2024 14:07:30.458 * MASTER <-> REPLICA sync: Master accepted a Partial Resynchronization.
[sentinel2] | 1:X 11 Mar 14:07:58.401 # +sdown master mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:58.417 # +sdown master mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:58.508 # +odown master mymaster 10.89.5.2 6379 #quorum 2/2
[sentinel1] | 1:X 11 Mar 14:07:58.508 # +new-epoch 1
[sentinel1] | 1:X 11 Mar 14:07:58.508 # +try-failover master mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:58.510 # +vote-for-leader ea7537e2ae8dce2499f3ca5bfffa84d3c54f13b6 1
[sentinel2] | 1:X 11 Mar 14:07:58.512 # +new-epoch 1
[sentinel2] | 1:X 11 Mar 14:07:58.512 # +vote-for-leader ea7537e2ae8dce2499f3ca5bfffa84d3c54f13b6 1
[sentinel1] | 1:X 11 Mar 14:07:58.513 # 68bdcf22b4195c8f41007c295d1513e9859476a0 voted for ea7537e2ae8dce2499f3ca5bfffa84d3c54f13b6 1
[sentinel3] | 1:X 11 Mar 14:07:58.512 # +new-epoch 1
[sentinel3] | 1:X 11 Mar 14:07:58.513 # +vote-for-leader ea7537e2ae8dce2499f3ca5bfffa84d3c54f13b6 1
[sentinel1] | 1:X 11 Mar 14:07:58.513 # ce11e66f8b9a401cfaee85959e6f8cff710df519 voted for ea7537e2ae8dce2499f3ca5bfffa84d3c54f13b6 1
[sentinel3] | 1:X 11 Mar 14:07:58.516 # +sdown master mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:58.562 # +elected-leader master mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:58.562 # +failover-state-select-slave master mymaster 10.89.5.2 6379
[sentinel3] | 1:X 11 Mar 14:07:58.587 # +odown master mymaster 10.89.5.2 6379 #quorum 3/2
[sentinel3] | 1:X 11 Mar 14:07:58.588 # Next failover delay: I will not start a failover before Mon Mar 11 14:08:08 2024
[sentinel1] | 1:X 11 Mar 14:07:58.620 # +selected-slave slave 10.89.5.4:6379 10.89.5.4 6379 @ mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:58.620 * +failover-state-send-slaveof-noone slave 10.89.5.4:6379 10.89.5.4 6379 @ mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:58.707 * +failover-state-wait-promotion slave 10.89.5.4:6379 10.89.5.4 6379 @ mymaster 10.89.5.2 6379
[slave2]    | 1:S 11 Mar 2024 14:07:58.707 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
[slave2]    | 1:S 11 Mar 2024 14:07:58.707 * <example> [EventHandler] Master Replication Link Down
[slave2]    | 1:M 11 Mar 2024 14:07:58.707 * Connection with master lost.
[slave2]    | 1:M 11 Mar 2024 14:07:58.707 * Caching the disconnected master state.
[slave2]    | 1:M 11 Mar 2024 14:07:58.707 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
[slave2]    | 1:M 11 Mar 2024 14:07:58.707 * <example> [EventHandler] Master Replication Link Down
[slave2]    | 1:M 11 Mar 2024 14:07:58.707 * Discarding previously cached master state.
[slave2]    | 1:M 11 Mar 2024 14:07:58.707 * Setting secondary replication ID to c08f0bded9a7d84ce9b8484b182a402a54e5cd57, valid up to offset: 6606. New replication ID is 156c0c16bd9509dd1a124a5a95f8911881ff07ed
[slave2]    | 1:M 11 Mar 2024 14:07:58.707 * <example> [EventHandler] Event Handler EVENT 0 SUBEVENT 0
[slave2]    | 1:M 11 Mar 2024 14:07:58.707 * <example> [EventHandler] Became Master
[slave2]    | 1:M 11 Mar 2024 14:07:58.707 * <example> [KAU] AAAAA master set
[slave2]    | 1:M 11 Mar 2024 14:07:58.707 * MASTER MODE enabled (user request from 'id=4 addr=10.89.5.5:40478 laddr=10.89.5.4:6379 fd=10 name=sentinel-ea7537e2-cmd age=41 idle=0 flags=x db=0 sub=0 psub=0 ssub=0 multi=3 qbuf=140 qbuf-free=20334 argv-mem=4 multi-mem=117 rbs=2048 rbp=1024 obl=36 oll=0 omem=0 tot-mem=23665 events=r cmd=exec user=default redir=-1 resp=2 lib-name= lib-ver=')
[slave2]    | 1:M 11 Mar 2024 14:07:58.709 # Could not create tmp config file (Permission denied)
[slave2]    | 1:M 11 Mar 2024 14:07:58.709 # CONFIG REWRITE failed: Permission denied
[sentinel2] | 1:X 11 Mar 14:07:59.498 # +odown master mymaster 10.89.5.2 6379 #quorum 3/2
[sentinel2] | 1:X 11 Mar 14:07:59.498 # Next failover delay: I will not start a failover before Mon Mar 11 14:08:09 2024
[sentinel1] | 1:X 11 Mar 14:07:59.590 # +promoted-slave slave 10.89.5.4:6379 10.89.5.4 6379 @ mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:59.590 # +failover-state-reconf-slaves master mymaster 10.89.5.2 6379
[sentinel2] | 1:X 11 Mar 14:07:59.666 # +config-update-from sentinel ea7537e2ae8dce2499f3ca5bfffa84d3c54f13b6 10.89.5.5 26379 @ mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:07:59.665 * +slave-reconf-sent slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.2 6379
[sentinel2] | 1:X 11 Mar 14:07:59.666 # +switch-master mymaster 10.89.5.2 6379 10.89.5.4 6379
[sentinel2] | 1:X 11 Mar 14:07:59.666 * +slave slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.4 6379
[sentinel2] | 1:X 11 Mar 14:07:59.666 * +slave slave 10.89.5.2:6379 10.89.5.2 6379 @ mymaster 10.89.5.4 6379
[sentinel3] | 1:X 11 Mar 14:07:59.667 # +config-update-from sentinel ea7537e2ae8dce2499f3ca5bfffa84d3c54f13b6 10.89.5.5 26379 @ mymaster 10.89.5.2 6379
[sentinel3] | 1:X 11 Mar 14:07:59.667 # +switch-master mymaster 10.89.5.2 6379 10.89.5.4 6379
[sentinel3] | 1:X 11 Mar 14:07:59.667 * +slave slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.4 6379
[sentinel3] | 1:X 11 Mar 14:07:59.667 * +slave slave 10.89.5.2:6379 10.89.5.2 6379 @ mymaster 10.89.5.4 6379
[slave1]    | 1:M 11 Mar 2024 14:07:59.666 * Connection with master lost.
[slave1]    | 1:M 11 Mar 2024 14:07:59.666 * Caching the disconnected master state.
[slave1]    | 1:M 11 Mar 2024 14:07:59.666 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
[slave1]    | 1:M 11 Mar 2024 14:07:59.666 * <example> [EventHandler] Master Replication Link Down
[slave1]    | 1:S 11 Mar 2024 14:07:59.666 * <example> [EventHandler] Event Handler EVENT 0 SUBEVENT 1
[slave1]    | 1:S 11 Mar 2024 14:07:59.666 * <example> [EventHandler] Became Replica
[slave1]    | 1:S 11 Mar 2024 14:07:59.666 * <example> [KAU] AAAAA replica set
[slave1]    | 1:S 11 Mar 2024 14:07:59.666 * Connecting to MASTER 10.89.5.4:6379
[slave1]    | 1:S 11 Mar 2024 14:07:59.666 * MASTER <-> REPLICA sync started
[slave1]    | 1:S 11 Mar 2024 14:07:59.666 * REPLICAOF 10.89.5.4:6379 enabled (user request from 'id=13 addr=10.89.5.5:54786 laddr=10.89.5.3:6379 fd=10 name=sentinel-ea7537e2-cmd age=29 idle=0 flags=x db=0 sub=0 psub=0 ssub=0 multi=3 qbuf=162 qbuf-free=20312 argv-mem=4 multi-mem=125 rbs=4096 rbp=2048 obl=36 oll=0 omem=0 tot-mem=25721 events=r cmd=exec user=default redir=-1 resp=2 lib-name= lib-ver=')
[slave1]    | 1:S 11 Mar 2024 14:07:59.669 # Could not create tmp config file (Permission denied)
[slave1]    | 1:S 11 Mar 2024 14:07:59.669 # CONFIG REWRITE failed: Permission denied
[slave2]    | 1:M 11 Mar 2024 14:07:59.670 * Replica 10.89.5.3:6379 asks for synchronization
[slave2]    | 1:M 11 Mar 2024 14:07:59.670 * Partial resynchronization request from 10.89.5.3:6379 accepted. Sending 190 bytes of backlog starting from offset 6606.
[slave1]    | 1:S 11 Mar 2024 14:07:59.670 * Non blocking connect for SYNC fired the event.
[slave1]    | 1:S 11 Mar 2024 14:07:59.670 * Master replied to PING, replication can continue...
[slave1]    | 1:S 11 Mar 2024 14:07:59.670 * Trying a partial resynchronization (request c08f0bded9a7d84ce9b8484b182a402a54e5cd57:6606).
[slave2]    | 1:M 11 Mar 2024 14:07:59.671 * Connection with replica 10.89.5.3:6379 lost.
[slave1]    | 1:S 11 Mar 2024 14:07:59.670 * Successful partial resynchronization with master.
[slave1]    | 1:S 11 Mar 2024 14:07:59.670 * Master replication ID changed to 156c0c16bd9509dd1a124a5a95f8911881ff07ed
[slave1]    | 1:S 11 Mar 2024 14:07:59.670 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 0
[slave1]    | 1:S 11 Mar 2024 14:07:59.670 * <example> [EventHandler] Master Replication Link Up
[slave1]    | 1:S 11 Mar 2024 14:07:59.670 * MASTER <-> REPLICA sync: Master accepted a Partial Resynchronization.
[slave1]    | 1:S 11 Mar 2024 14:07:59.670 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
[slave1]    | 1:S 11 Mar 2024 14:07:59.670 * <example> [EventHandler] Master Replication Link Down
[slave1]    | 1:M 11 Mar 2024 14:07:59.670 * Connection with master lost.
[slave1]    | 1:M 11 Mar 2024 14:07:59.670 * Caching the disconnected master state.
[slave1]    | 1:M 11 Mar 2024 14:07:59.671 * <example> [EventHandler] Event Handler EVENT 7 SUBEVENT 1
[slave1]    | 1:M 11 Mar 2024 14:07:59.671 * <example> [EventHandler] Master Replication Link Down
[slave1]    | 1:M 11 Mar 2024 14:07:59.671 * Discarding previously cached master state.
[slave1]    | 1:M 11 Mar 2024 14:07:59.671 * Setting secondary replication ID to 156c0c16bd9509dd1a124a5a95f8911881ff07ed, valid up to offset: 6629. New replication ID is 930e1fe14242338719bef82574f1b86a024006bf
[slave1]    | 1:M 11 Mar 2024 14:07:59.671 * <example> [EventHandler] Event Handler EVENT 0 SUBEVENT 0
[slave1]    | 1:M 11 Mar 2024 14:07:59.671 * <example> [EventHandler] Became Master
[slave1]    | 1:M 11 Mar 2024 14:07:59.671 * <example> [KAU] AAAAA master set
[slave1]    | 
[slave1]    | 
[slave1]    | === REDIS BUG REPORT START: Cut & paste starting from here ===
[slave1]    | 1:M 11 Mar 2024 14:07:59.671 # Redis 7.2.4 crashed by signal: 11, si_code: 1
[slave1]    | 1:M 11 Mar 2024 14:07:59.671 # Accessing address: 0xffffffffffffffff
[slave1]    | 1:M 11 Mar 2024 14:07:59.671 # Crashed running the instruction at: 0x558791e7f41b
[slave1]    | 
[slave1]    | ------ STACK TRACE ------
[slave1]    | EIP:
[slave1]    | redis-server 0.0.0.0:6379(getClientMemoryUsage+0x4b)[0x558791e7f41b]
[slave1]    | 
[slave1]    | Backtrace:
[slave1]    | /lib/x86_64-linux-gnu/libpthread.so.0(+0x13140)[0x7fd1d48a3140]
[slave1]    | redis-server 0.0.0.0:6379(getClientMemoryUsage+0x4b)[0x558791e7f41b]
[slave1]    | redis-server 0.0.0.0:6379(catClientInfoString+0x16e)[0x558791e8368e]
[slave1]    | redis-server 0.0.0.0:6379(replicaofCommand+0x17c)[0x558791e9d06c]
[slave1]    | redis-server 0.0.0.0:6379(call+0x170)[0x558791e5f740]
[slave1]    | redis-server 0.0.0.0:6379(processCommand+0xb69)[0x558791e609e9]
[slave1]    | redis-server 0.0.0.0:6379(processInputBuffer+0xf7)[0x558791e84b37]
[slave1]    | redis-server 0.0.0.0:6379(readQueryFromClient+0x350)[0x558791e850a0]
[slave1]    | redis-server 0.0.0.0:6379(+0x1affd8)[0x558791f77fd8]
[slave1]    | redis-server 0.0.0.0:6379(aeMain+0xf9)[0x558791e55d09]
[slave1]    | redis-server 0.0.0.0:6379(main+0x3cd)[0x558791e4aecd]
[slave1]    | /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xea)[0x7fd1d46dfd0a]
[slave1]    | redis-server 0.0.0.0:6379(_start+0x2a)[0x558791e4b64a]
[slave1]    | 
[slave1]    | ------ REGISTERS ------
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # 
[slave1]    | RAX:0000000000000000 RBX:00007fd1d430df80
[slave1]    | RCX:00000000000000ff RDX:0000000000000000
[slave1]    | RDI:0000000000000000 RSI:00007ffc3fa74e88
[slave1]    | RBP:00007fd1d430df80 RSP:00007ffc3fa74da0
[slave1]    | R8 :00007fd1d432331b R9 :0000000000000000
[slave1]    | R10:00000000032ab720 R11:00007fd1d46b81c0
[slave1]    | R12:0000000000000000 R13:00007ffc3fa74e90
[slave1]    | R14:0000558791f823e0 R15:00007ffc3fa74f80
[slave1]    | RIP:0000558791e7f41b EFL:0000000000010206
[slave1]    | CSGSFS:002b000000000033
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74daf) -> 000000dc4e6504ae
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74dae) -> 0000000000000000
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74dad) -> 0000000000000000
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74dac) -> 0000000000000000
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74dab) -> 0000000000000000
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74daa) -> 0000000000000000
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74da9) -> 0000000000000000
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74da8) -> 0000000000000040
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74da7) -> 0000000000000000
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74da6) -> 0000000000000000
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74da5) -> 0000558791e8368e
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74da4) -> 0000558791f823e0
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74da3) -> 00007ffc3fa74e90
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74da2) -> 00007fd1d42638a0
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74da1) -> 00007fd1d430df80
[slave1]    | 1:M 11 Mar 2024 14:07:59.672 # (00007ffc3fa74da0) -> 00007fd1d430df80
[slave1]    | 
[slave1]    | ------ INFO OUTPUT ------
[slave1]    | # Server
[slave1]    | redis_version:7.2.4
[slave1]    | redis_git_sha1:00000000
[slave1]    | redis_git_dirty:0
[slave1]    | redis_build_id:5480667114e70c31
[slave1]    | redis_mode:standalone
[slave1]    | os:Linux 5.14.0-284.18.1.el9_2.x86_64 x86_64
[slave1]    | arch_bits:64
[slave1]    | monotonic_clock:POSIX clock_gettime
[slave1]    | multiplexing_api:epoll
[slave1]    | atomicvar_api:c11-builtin
[slave1]    | gcc_version:10.2.1
[slave1]    | process_id:1
[slave1]    | process_supervised:no
[slave1]    | run_id:2fa43e8238934541345e14115ab87ddae13d43ff
[slave1]    | tcp_port:6379
[slave1]    | server_time_usec:1710166079670896
[slave1]    | uptime_in_seconds:44
[slave1]    | uptime_in_days:0
[slave1]    | hz:10
[slave1]    | configured_hz:10
[slave1]    | lru_clock:15667263
[slave1]    | executable:/redis-server
[slave1]    | config_file:/opt/bitnami/redis/etc/redis.conf
[slave1]    | io_threads_active:0
[slave1]    | listener0:name=tcp,bind=0.0.0.0,bind=::,port=6379
[slave1]    | 
[slave1]    | # Clients
[slave1]    | connected_clients:2
[slave1]    | cluster_connections:0
[slave1]    | maxclients:10000
[slave1]    | client_recent_max_input_buffer:20480
[slave1]    | client_recent_max_output_buffer:0
[slave1]    | blocked_clients:0
[slave1]    | tracking_clients:0
[slave1]    | clients_in_timeout_table:0
[slave1]    | total_blocking_keys:0
[slave1]    | total_blocking_keys_on_nokey:0
[slave1]    | 
[slave1]    | # Memory
[slave1]    | used_memory:1270608
[slave1]    | used_memory_human:1.21M
[slave1]    | used_memory_rss:14585856
[slave1]    | used_memory_rss_human:13.91M
[slave1]    | used_memory_peak:1432528
[slave1]    | used_memory_peak_human:1.37M
[slave1]    | used_memory_peak_perc:88.70%
[slave1]    | used_memory_overhead:952172
[slave1]    | used_memory_startup:883280
[slave1]    | used_memory_dataset:318436
[slave1]    | used_memory_dataset_perc:82.21%
[slave1]    | allocator_allocated:1645848
[slave1]    | allocator_active:1978368
[slave1]    | allocator_resident:5201920
[slave1]    | total_system_memory:8060624896
[slave1]    | total_system_memory_human:7.51G
[slave1]    | used_memory_lua:31744
[slave1]    | used_memory_vm_eval:31744
[slave1]    | used_memory_lua_human:31.00K
[slave1]    | used_memory_scripts_eval:0
[slave1]    | number_of_cached_scripts:0
[slave1]    | number_of_functions:0
[slave1]    | number_of_libraries:0
[slave1]    | used_memory_vm_functions:32768
[slave1]    | used_memory_vm_total:64512
[slave1]    | used_memory_vm_total_human:63.00K
[slave1]    | used_memory_functions:184
[slave1]    | used_memory_scripts:184
[slave1]    | used_memory_scripts_human:184B
[slave1]    | maxmemory:0
[slave1]    | maxmemory_human:0B
[slave1]    | maxmemory_policy:noeviction
[slave1]    | allocator_frag_ratio:1.20
[slave1]    | allocator_frag_bytes:332520
[slave1]    | allocator_rss_ratio:2.63
[slave1]    | allocator_rss_bytes:3223552
[slave1]    | rss_overhead_ratio:2.80
[slave1]    | rss_overhead_bytes:9383936
[slave1]    | mem_fragmentation_ratio:10.70
[slave1]    | mem_fragmentation_bytes:13223008
[slave1]    | mem_not_counted_for_evict:160
[slave1]    | mem_replication_backlog:20508
[slave1]    | mem_total_replication_buffers:20504
[slave1]    | mem_clients_slaves:0
[slave1]    | mem_clients_normal:47928
[slave1]    | mem_cluster_links:0
[slave1]    | mem_aof_buffer:160
[slave1]    | mem_allocator:jemalloc-5.3.0
[slave1]    | active_defrag_running:0
[slave1]    | lazyfree_pending_objects:0
[slave1]    | lazyfreed_objects:0
[slave1]    | 
[slave1]    | # Persistence
[slave1]    | loading:0
[slave1]    | async_loading:0
[slave1]    | current_cow_peak:0
[slave1]    | current_cow_size:0
[slave1]    | current_cow_size_age:0
[slave1]    | current_fork_perc:0.00
[slave1]    | current_save_keys_processed:0
[slave1]    | current_save_keys_total:0
[slave1]    | rdb_changes_since_last_save:3
[slave1]    | rdb_bgsave_in_progress:0
[slave1]    | rdb_last_save_time:1710166035
[slave1]    | rdb_last_bgsave_status:ok
[slave1]    | rdb_last_bgsave_time_sec:-1
[slave1]    | rdb_current_bgsave_time_sec:-1
[slave1]    | rdb_saves:0
[slave1]    | rdb_last_cow_size:0
[slave1]    | rdb_last_load_keys_expired:0
[slave1]    | rdb_last_load_keys_loaded:0
[slave1]    | aof_enabled:1
[slave1]    | aof_rewrite_in_progress:0
[slave1]    | aof_rewrite_scheduled:0
[slave1]    | aof_last_rewrite_time_sec:0
[slave1]    | aof_current_rewrite_time_sec:-1
[slave1]    | aof_last_bgrewrite_status:ok
[slave1]    | aof_rewrites:1
[slave1]    | aof_rewrites_consecutive_failures:0
[slave1]    | aof_last_write_status:ok
[slave1]    | aof_last_cow_size:282624
[slave1]    | module_fork_in_progress:0
[slave1]    | module_fork_last_cow_size:0
[slave1]    | aof_current_size:195
[slave1]    | aof_base_size:88
[slave1]    | aof_pending_rewrite:0
[slave1]    | aof_buffer_length:0
[slave1]    | aof_pending_bio_fsync:0
[slave1]    | aof_delayed_fsync:0
[slave1]    | 
[slave1]    | # Stats
[slave1]    | total_connections_received:8
[slave1]    | total_commands_processed:281
[slave1]    | instantaneous_ops_per_sec:6
[slave1]    | total_net_input_bytes:17668
[slave1]    | total_net_output_bytes:179999
[slave1]    | total_net_repl_input_bytes:6898
[slave1]    | total_net_repl_output_bytes:0
[slave1]    | instantaneous_input_kbps:0.24
[slave1]    | instantaneous_output_kbps:18.29
[slave1]    | instantaneous_input_repl_kbps:0.00
[slave1]    | instantaneous_output_repl_kbps:0.00
[slave1]    | rejected_connections:0
[slave1]    | sync_full:0
[slave1]    | sync_partial_ok:0
[slave1]    | sync_partial_err:0
[slave1]    | expired_keys:0
[slave1]    | expired_stale_perc:0.00
[slave1]    | expired_time_cap_reached_count:0
[slave1]    | expire_cycle_cpu_milliseconds:0
[slave1]    | evicted_keys:0
[slave1]    | evicted_clients:0
[slave1]    | total_eviction_exceeded_time:0
[slave1]    | current_eviction_exceeded_time:0
[slave1]    | keyspace_hits:0
[slave1]    | keyspace_misses:0
[slave1]    | pubsub_channels:1
[slave1]    | pubsub_patterns:0
[slave1]    | pubsubshard_channels:0
[slave1]    | latest_fork_usec:249
[slave1]    | total_forks:1
[slave1]    | migrate_cached_sockets:0
[slave1]    | slave_expires_tracked_keys:0
[slave1]    | active_defrag_hits:0
[slave1]    | active_defrag_misses:0
[slave1]    | active_defrag_key_hits:0
[slave1]    | active_defrag_key_misses:0
[slave1]    | total_active_defrag_time:0
[slave1]    | current_active_defrag_time:0
[slave1]    | tracking_total_keys:0
[slave1]    | tracking_total_items:0
[slave1]    | tracking_total_prefixes:0
[slave1]    | unexpected_error_replies:0
[slave1]    | total_error_replies:2
[slave1]    | dump_payload_sanitizations:0
[slave1]    | total_reads_processed:257
[slave1]    | total_writes_processed:545
[slave1]    | io_threaded_reads_processed:0
[slave1]    | io_threaded_writes_processed:0
[slave1]    | reply_buffer_shrinks:19
[slave1]    | reply_buffer_expands:18
[slave1]    | eventloop_cycles:714
[slave1]    | eventloop_duration_sum:80821
[slave1]    | eventloop_duration_cmd_sum:8021
[slave1]    | instantaneous_eventloop_cycles_per_sec:15
[slave1]    | instantaneous_eventloop_duration_usec:107
[slave1]    | acl_access_denied_auth:0
[slave1]    | acl_access_denied_cmd:0
[slave1]    | acl_access_denied_key:0
[slave1]    | acl_access_denied_channel:0
[slave1]    | 
[slave1]    | # Replication
[slave1]    | role:master
[slave1]    | connected_slaves:0
[slave1]    | master_failover_state:no-failover
[slave1]    | master_replid:930e1fe14242338719bef82574f1b86a024006bf
[slave1]    | master_replid2:156c0c16bd9509dd1a124a5a95f8911881ff07ed
[slave1]    | master_repl_offset:6628
[slave1]    | second_repl_offset:6629
[slave1]    | repl_backlog_active:1
[slave1]    | repl_backlog_size:1048576
[slave1]    | repl_backlog_first_byte_offset:157
[slave1]    | repl_backlog_histlen:6472
[slave1]    | 
[slave1]    | # CPU
[slave1]    | used_cpu_sys:0.078963
[slave1]    | used_cpu_user:0.036047
[slave1]    | used_cpu_sys_children:0.102556
[slave1]    | used_cpu_user_children:0.047502
[slave1]    | used_cpu_sys_main_thread:0.076714
[slave1]    | used_cpu_user_main_thread:0.035739
[slave1]    | 
[slave1]    | # Modules
[slave1]    | module:name=example,ver=1,api=1,filters=0,usedby=[],using=[],options=[]
[slave1]    | 
[slave1]    | # Commandstats
[slave1]    | cmdstat_publish:calls=107,usec=409,usec_per_call=3.82,rejected_calls=0,failed_calls=0
[slave1]    | cmdstat_set:calls=3,usec=17,usec_per_call=5.67,rejected_calls=0,failed_calls=0
[slave1]    | cmdstat_client|kill:calls=2,usec=124,usec_per_call=62.00,rejected_calls=0,failed_calls=0
[slave1]    | cmdstat_client|setname:calls=8,usec=20,usec_per_call=2.50,rejected_calls=0,failed_calls=0
[slave1]    | cmdstat_ping:calls=125,usec=167,usec_per_call=1.34,rejected_calls=0,failed_calls=0
[slave1]    | cmdstat_slaveof:calls=2,usec=916,usec_per_call=458.00,rejected_calls=0,failed_calls=0
[slave1]    | cmdstat_subscribe:calls=3,usec=6,usec_per_call=2.00,rejected_calls=0,failed_calls=0
[slave1]    | cmdstat_select:calls=2,usec=2,usec_per_call=1.00,rejected_calls=0,failed_calls=0
[slave1]    | cmdstat_multi:calls=2,usec=2,usec_per_call=1.00,rejected_calls=0,failed_calls=0
[slave1]    | cmdstat_config|rewrite:calls=2,usec=4295,usec_per_call=2147.50,rejected_calls=0,failed_calls=2
[slave1]    | cmdstat_exec:calls=2,usec=5378,usec_per_call=2689.00,rejected_calls=0,failed_calls=0
[slave1]    | cmdstat_info:calls=23,usec=2037,usec_per_call=88.57,rejected_calls=0,failed_calls=0
[slave1]    | 
[slave1]    | # Errorstats
[slave1]    | errorstat_ERR:count=2
[slave1]    | 
[slave1]    | # Latencystats
[slave1]    | latency_percentiles_usec_publish:p50=3.007,p99=19.071,p99.9=21.119
[slave1]    | latency_percentiles_usec_set:p50=4.015,p99=9.023,p99.9=9.023
[slave1]    | latency_percentiles_usec_client|kill:p50=59.135,p99=65.023,p99.9=65.023
[slave1]    | latency_percentiles_usec_client|setname:p50=1.003,p99=9.023,p99.9=9.023
[slave1]    | latency_percentiles_usec_ping:p50=1.003,p99=31.103,p99.9=36.095
[slave1]    | latency_percentiles_usec_slaveof:p50=294.911,p99=622.591,p99.9=622.591
[slave1]    | latency_percentiles_usec_subscribe:p50=2.007,p99=2.007,p99.9=2.007
[slave1]    | latency_percentiles_usec_select:p50=1.003,p99=1.003,p99.9=1.003
[slave1]    | latency_percentiles_usec_multi:p50=0.001,p99=2.007,p99.9=2.007
[slave1]    | latency_percentiles_usec_config|rewrite:p50=1286.143,p99=3031.039,p99.9=3031.039
[slave1]    | latency_percentiles_usec_exec:p50=1679.359,p99=3719.167,p99.9=3719.167
[slave1]    | latency_percentiles_usec_info:p50=59.135,p99=360.447,p99.9=360.447
[slave1]    | 
[slave1]    | # Cluster
[slave1]    | cluster_enabled:0
[slave1]    | 
[slave1]    | # Keyspace
[slave1]    | db0:keys=2,expires=0,avg_ttl=0
[slave1]    | 
[slave1]    | ------ CLIENT LIST OUTPUT ------
[slave1]    | id=13 addr=10.89.5.5:54786 laddr=10.89.5.3:6379 fd=10 name=sentinel-ea7537e2-cmd age=29 idle=0 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 qbuf=0 qbuf-free=20474 argv-mem=0 multi-mem=0 rbs=4096 rbp=2048 obl=0 oll=0 omem=0 tot-mem=25472 events=r cmd=ping user=default redir=-1 resp=2 lib-name= lib-ver=
[slave1]    | id=5 addr=10.89.5.5:35960 laddr=10.89.5.3:6379 fd=11 name=sentinel-ea7537e2-pubsub age=42 idle=0 flags=P db=0 sub=1 psub=0 ssub=0 multi=-1 qbuf=0 qbuf-free=20474 argv-mem=0 multi-mem=0 rbs=1024 rbp=133 obl=0 oll=0 omem=0 tot-mem=22456 events=r cmd=subscribe user=default redir=-1 resp=2 lib-name= lib-ver=
[slave1]    | 
[slave1]    | ------ EXECUTING CLIENT INFO ------
exit code: 139
[sentinel1] | 1:X 11 Mar 14:08:00.690 # -odown master mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:08:04.664 # +failover-end-for-timeout master mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:08:04.664 # +failover-end master mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:08:04.664 * +slave-reconf-sent-be slave 10.89.5.4:6379 10.89.5.4 6379 @ mymaster 10.89.5.2 6379
[sentinel1] | 1:X 11 Mar 14:08:04.664 # +switch-master mymaster 10.89.5.2 6379 10.89.5.4 6379
[sentinel1] | 1:X 11 Mar 14:08:04.665 * +slave slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.4 6379
[sentinel1] | 1:X 11 Mar 14:08:04.665 * +slave slave 10.89.5.2:6379 10.89.5.2 6379 @ mymaster 10.89.5.4 6379
[sentinel3] | 1:X 11 Mar 14:08:04.725 # +sdown slave 10.89.5.2:6379 10.89.5.2 6379 @ mymaster 10.89.5.4 6379
[sentinel3] | 1:X 11 Mar 14:08:04.725 # +sdown slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.4 6379
[sentinel2] | 1:X 11 Mar 14:08:04.759 # +sdown slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.4 6379
[sentinel2] | 1:X 11 Mar 14:08:04.759 # +sdown slave 10.89.5.2:6379 10.89.5.2 6379 @ mymaster 10.89.5.4 6379
[sentinel1] | 1:X 11 Mar 14:08:09.695 # +sdown slave 10.89.5.2:6379 10.89.5.2 6379 @ mymaster 10.89.5.4 6379
[sentinel1] | 1:X 11 Mar 14:08:09.695 # +sdown slave 10.89.5.3:6379 10.89.5.3 6379 @ mymaster 10.89.5.4 6379

@Mauraza
Copy link
Contributor

Mauraza commented Mar 14, 2024

Hi @wgnathanael,

The error maybe is related to cmdstat_config|rewrite:calls=2,usec=4295,usec_per_call=2147.50,rejected_calls=0,failed_calls=2
Could you check the volumes and if that error changes the container or is always slave1?

@wgnathanael
Copy link
Author

I don't 100% know if I'm understanding what you are asking but if slave1 isn't the one that becomes master then it changes, It depends on which node becomes master - but whichever node does crashes.

@Mauraza
Copy link
Contributor

Mauraza commented Mar 25, 2024

Hi @wgnathanael,

Could you check the events of the pod and the PVC?

@wgnathanael
Copy link
Author

Hello Mauraza,

These tests are being run in podman after seeing the issue in k8s. There's no PVC and the pod running under podman has crashed and I'm not sure there are events I could check in this testing scenario. At least I'm not aware of any...

It should be really easy to replicate this on your end using either podman or docker by compiling that really small custom module. Fire up a multi pod non-k8s deployment and pause the master. It'll crash. No k8s involvement required. Same with the reference tilt issue.

Copy link

This Issue has been automatically marked as "stale" because it has not had recent activity (for 15 days). It will be closed if no further activity occurs. Thanks for the feedback.

@github-actions github-actions bot added the stale 15 days without activity label Apr 10, 2024
Copy link

Due to the lack of activity in the last 5 days since it was marked as "stale", we proceed to close this Issue. Do not hesitate to reopen it later if necessary.

@bitnami-bot bitnami-bot closed this as not planned Won't fix, can't repro, duplicate, stale Apr 15, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
redis solved stale 15 days without activity tech-issues The user has a technical issue about an application
Projects
None yet
Development

No branches or pull requests

4 participants