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

[CRASH] Guru Meditation: Unknown btype in replyToBlockedClientTimedOut(). #blocked.cpp:246 #659

Closed
duckasylum opened this issue May 24, 2023 · 3 comments · Fixed by #662
Closed

Comments

@duckasylum
Copy link

Crash report

Paste the complete crash log between the quotes below. Please include a few lines from the log preceding the crash report to provide some context.

This is basically the same crash as #605 which is tagged as "more info needed" I am willing to supply any additional info needed. I can say that the crash is recurring every

49395:49394:M 24 May 2023 16:13:36.143 * The server is now ready to accept connections at /var/run/keydb/keydb.sock
49395:49408:M 24 May 2023 16:13:36.143 * Thread 0 alive.
49395:49409:M 24 May 2023 16:13:36.143 * Thread 1 alive.
49395:49411:M 24 May 2023 16:13:36.143 * Thread 3 alive.
49395:49410:M 24 May 2023 16:13:36.143 * Thread 2 alive.


=== KEYDB BUG REPORT START: Cut & paste starting from here ===
49395:49409:M 24 May 2023 16:15:36.337 # ------------------------------------------------
49395:49409:M 24 May 2023 16:15:36.337 # !!! Software Failure. Press left mouse button to continue
49395:49409:M 24 May 2023 16:15:36.337 # Guru Meditation: Unknown btype in replyToBlockedClientTimedOut(). #blocked.cpp:246

------ STACK TRACE ------

Backtrace:
/usr/bin/keydb-server 127.0.0.1:6379(replyToBlockedClientTimedOut(client*)+0x72) [0x5596cda6cb12]
/usr/bin/keydb-server 127.0.0.1:6379(checkBlockedClientTimeout(client*, long long)+0x3e) [0x5596cda2ce7e]
/usr/bin/keydb-server 127.0.0.1:6379(handleBlockedClientsTimeout()+0x110) [0x5596cda2cfb0]
/usr/bin/keydb-server 127.0.0.1:6379(beforeSleep(aeEventLoop*)+0x171) [0x5596cdb1fb41]
/usr/bin/keydb-server 127.0.0.1:6379(aeProcessEvents+0x3d0) [0x5596cdb2afc0]
/usr/bin/keydb-server 127.0.0.1:6379(aeMain+0x3a) [0x5596cdb2e6fa]
/usr/bin/keydb-server 127.0.0.1:6379(workerThreadMain(void*)+0x84) [0x5596cdb16fd4]
/lib/x86_64-linux-gnu/libc.so.6(+0x94b43) [0x7f0fa7888b43]
/lib/x86_64-linux-gnu/libc.so.6(+0x126a00) [0x7f0fa791aa00]

------ INFO OUTPUT ------
# Server
redis_version:6.3.3
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:704d39d025097a6
redis_mode:standalone
os:Linux 5.15.0-72-generic x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:9.3.0
process_id:49395
process_supervised:no
run_id:3fcd6f9f5319ff264f070bf14a1dd5bc36715d8d
tcp_port:6379
server_time_usec:1684934136338633
uptime_in_seconds:120
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:7212536
executable:/usr/bin/keydb-server
config_file:/etc/keydb/keydb.conf

# Clients
connected_clients:34
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:40968
client_recent_max_output_buffer:0
blocked_clients:17
tracking_clients:0
clients_in_timeout_table:17
current_client_thread:1
thread_0_clients:20
thread_1_clients:14
thread_2_clients:0
thread_3_clients:0

# Memory
used_memory:5966664
used_memory_human:5.69M
used_memory_rss:14618624
used_memory_rss_human:13.94M
used_memory_peak:6636616
used_memory_peak_human:6.33M
used_memory_peak_perc:89.91%
used_memory_overhead:4488972
used_memory_startup:3240856
used_memory_dataset:1477692
used_memory_dataset_perc:54.21%
allocator_allocated:7759504
allocator_active:8994816
allocator_resident:12636160
total_system_memory:8335007744
total_system_memory_human:7.76G
used_memory_lua:37888
used_memory_lua_human:37.00K
used_memory_scripts:480
used_memory_scripts_human:480B
number_of_cached_scripts:2
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.16
allocator_frag_bytes:1235312
allocator_rss_ratio:1.40
allocator_rss_bytes:3641344
rss_overhead_ratio:1.16
rss_overhead_bytes:1982464
mem_fragmentation_ratio:2.44
mem_fragmentation_bytes:8633376
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:1224092
mem_aof_buffer:0
mem_allocator:jemalloc-5.2.1
active_defrag_running:0
lazyfree_pending_objects:0
lazyfreed_objects:0
storage_provider:none

# 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:668
rdb_bgsave_in_progress:0
rdb_last_save_time:1684934016
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:-1
rdb_last_cow_size:0
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

# Stats
total_connections_received:34
total_commands_processed:13479
instantaneous_ops_per_sec:4
total_net_input_bytes:32807833
total_net_output_bytes:1418563
instantaneous_input_kbps:123.57
instantaneous_output_kbps:0.02
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:2438
keyspace_misses:8955
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:0
total_forks:0
migrate_cached_sockets:0
slave_expires_tracked_keys:0
active_defrag_hits:0
active_defrag_misses:0
active_defrag_key_hits:0
active_defrag_key_misses:0
tracking_total_keys:0
tracking_total_items:0
tracking_total_prefixes:0
unexpected_error_replies:0
total_error_replies:1
dump_payload_sanitizations:0
total_reads_processed:13069
total_writes_processed:11816
instantaneous_lock_contention:2
avg_lock_contention:0.046875
storage_provider_read_hits:0
storage_provider_read_misses:0

# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:dd172158989aa831849a8e62a641ce4b87cde723
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:0.553190
used_cpu_user:1.014983
used_cpu_sys_children:0.000000
used_cpu_user_children:0.000000
server_threads:4
long_lock_waits:0
used_cpu_sys_main_thread:0.239896
used_cpu_user_main_thread:0.172001

# Modules

# Commandstats
cmdstat_evalsha:calls=50,usec=934,usec_per_call=18.68,rejected_calls=0,failed_calls=1
cmdstat_exec:calls=48,usec=709,usec_per_call=14.77,rejected_calls=0,failed_calls=0
cmdstat_hset:calls=28,usec=75,usec_per_call=2.68,rejected_calls=0,failed_calls=0
cmdstat_hgetall:calls=1663,usec=4594,usec_per_call=2.76,rejected_calls=0,failed_calls=0
cmdstat_lpush:calls=86,usec=267,usec_per_call=3.10,rejected_calls=0,failed_calls=0
cmdstat_scard:calls=54,usec=167,usec_per_call=3.09,rejected_calls=0,failed_calls=0
cmdstat_brpop:calls=1211,usec=169409,usec_per_call=139.89,rejected_calls=0,failed_calls=0
cmdstat_rpop:calls=24,usec=19,usec_per_call=0.79,rejected_calls=0,failed_calls=0
cmdstat_ltrim:calls=28,usec=69,usec_per_call=2.46,rejected_calls=0,failed_calls=0
cmdstat_script:calls=1,usec=61,usec_per_call=61.00,rejected_calls=0,failed_calls=0
cmdstat_multi:calls=48,usec=35,usec_per_call=0.73,rejected_calls=0,failed_calls=0
cmdstat_expire:calls=96,usec=112,usec_per_call=1.17,rejected_calls=0,failed_calls=0
cmdstat_unlink:calls=24,usec=51,usec_per_call=2.12,rejected_calls=0,failed_calls=0
cmdstat_llen:calls=5894,usec=3833,usec_per_call=0.65,rejected_calls=0,failed_calls=0
cmdstat_scan:calls=1,usec=19,usec_per_call=19.00,rejected_calls=0,failed_calls=0
cmdstat_set:calls=66,usec=371,usec_per_call=5.62,rejected_calls=0,failed_calls=0
cmdstat_lrange:calls=2954,usec=3392,usec_per_call=1.15,rejected_calls=0,failed_calls=0
cmdstat_get:calls=65,usec=146,usec_per_call=2.25,rejected_calls=0,failed_calls=0
cmdstat_zrange:calls=7,usec=11,usec_per_call=1.57,rejected_calls=0,failed_calls=0
cmdstat_zcard:calls=28,usec=25,usec_per_call=0.89,rejected_calls=0,failed_calls=0
cmdstat_lrem:calls=29,usec=133,usec_per_call=4.59,rejected_calls=0,failed_calls=0
cmdstat_smembers:calls=24,usec=542,usec_per_call=22.58,rejected_calls=0,failed_calls=0
cmdstat_hmset:calls=24,usec=140,usec_per_call=5.83,rejected_calls=0,failed_calls=0
cmdstat_del:calls=71,usec=133,usec_per_call=1.87,rejected_calls=0,failed_calls=0
cmdstat_exists:calls=60,usec=67,usec_per_call=1.12,rejected_calls=0,failed_calls=0
cmdstat_sadd:calls=53,usec=104,usec_per_call=1.96,rejected_calls=0,failed_calls=0
cmdstat_sscan:calls=588,usec=2440,usec_per_call=4.15,rejected_calls=0,failed_calls=0
cmdstat_zremrangebyscore:calls=28,usec=86,usec_per_call=3.07,rejected_calls=0,failed_calls=0
cmdstat_eval:calls=13,usec=287,usec_per_call=22.08,rejected_calls=0,failed_calls=0
cmdstat_hget:calls=7,usec=19,usec_per_call=2.71,rejected_calls=0,failed_calls=0
cmdstat_zrem:calls=1,usec=2,usec_per_call=2.00,rejected_calls=0,failed_calls=0
cmdstat_zrangebyscore:calls=49,usec=247,usec_per_call=5.04,rejected_calls=0,failed_calls=0
cmdstat_ping:calls=32,usec=20,usec_per_call=0.62,rejected_calls=0,failed_calls=0
cmdstat_zadd:calls=28,usec=174,usec_per_call=6.21,rejected_calls=0,failed_calls=0
cmdstat_incrby:calls=96,usec=252,usec_per_call=2.62,rejected_calls=0,failed_calls=0

# Errorstats
errorstat_NOSCRIPT:count=1

# Cluster
cluster_enabled:0

# Keyspace
db0:keys=256,expires=42,avg_ttl=63597091782,cached_keys=256

# KeyDB
mvcc_depth:1

------ CLIENT LIST OUTPUT ------
id=20 addr=127.0.0.1:54196 laddr=127.0.0.1:6379 fd=43 name= age=120 idle=2 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=21 addr=127.0.0.1:54210 laddr=127.0.0.1:6379 fd=44 name= age=120 idle=0 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=24072 events=r cmd=brpop user=default redir=-1
id=22 addr=127.0.0.1:54222 laddr=127.0.0.1:6379 fd=45 name= age=120 idle=0 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=24072 events=r cmd=brpop user=default redir=-1
id=32 addr=127.0.0.1:47756 laddr=127.0.0.1:6379 fd=55 name= age=115 idle=1 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=23 addr=127.0.0.1:54224 laddr=127.0.0.1:6379 fd=46 name= age=120 idle=2 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=24 addr=127.0.0.1:54234 laddr=127.0.0.1:6379 fd=47 name= age=120 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=34 qbuf-free=40920 argv-mem=14574 obl=0 oll=0 omem=0 tot-mem=79598 events=r cmd=brpop user=default redir=-1
id=25 addr=127.0.0.1:54248 laddr=127.0.0.1:6379 fd=48 name= age=120 idle=17 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=20504 events=r cmd=scard user=default redir=-1
id=35 addr=127.0.0.1:54404 laddr=127.0.0.1:6379 fd=58 name= age=90 idle=90 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=20528 events=r cmd=set user=default redir=-1
id=36 addr=127.0.0.1:54406 laddr=127.0.0.1:6379 fd=59 name= age=90 idle=90 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=20528 events=r cmd=set user=default redir=-1
id=26 addr=127.0.0.1:54260 laddr=127.0.0.1:6379 fd=49 name= age=120 idle=0 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=40954 argv-mem=48 obl=0 oll=0 omem=0 tot-mem=61536 events=r cmd=scan user=default redir=-1
id=6 addr=127.0.0.1:54110 laddr=127.0.0.1:6379 fd=29 name= age=120 idle=120 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=20496 events=r cmd=ping user=default redir=-1
id=37 addr=127.0.0.1:44396 laddr=127.0.0.1:6379 fd=60 name= age=80 idle=5 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=20504 events=r cmd=get user=default redir=-1
id=27 addr=127.0.0.1:54266 laddr=127.0.0.1:6379 fd=50 name= age=120 idle=1 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=40954 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=87797 events=r cmd=brpop user=default redir=-1
id=28 addr=127.0.0.1:54278 laddr=127.0.0.1:6379 fd=51 name= age=120 idle=32 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=20504 events=r cmd=del user=default redir=-1
id=29 addr=127.0.0.1:54290 laddr=127.0.0.1:6379 fd=52 name= age=120 idle=120 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=20504 events=r cmd=exists user=default redir=-1
id=7 addr=127.0.0.1:54120 laddr=127.0.0.1:6379 fd=30 name= age=120 idle=1 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=38 addr=127.0.0.1:40590 laddr=127.0.0.1:6379 fd=61 name= age=50 idle=50 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=20504 events=r cmd=get user=default redir=-1
id=8 addr=127.0.0.1:54130 laddr=127.0.0.1:6379 fd=31 name= age=120 idle=1 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=9 addr=127.0.0.1:54136 laddr=127.0.0.1:6379 fd=32 name= age=120 idle=1 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=10 addr=127.0.0.1:54146 laddr=127.0.0.1:6379 fd=33 name= age=120 idle=1 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=30 addr=127.0.0.1:54296 laddr=127.0.0.1:6379 fd=53 name= age=120 idle=32 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=20528 events=r cmd=set user=default redir=-1
id=33 addr=127.0.0.1:34866 laddr=127.0.0.1:6379 fd=56 name= age=99 idle=9 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=20528 events=r cmd=zrange user=default redir=-1
id=31 addr=127.0.0.1:54308 laddr=127.0.0.1:6379 fd=54 name= age=120 idle=32 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=20528 events=r cmd=eval user=default redir=-1
id=11 addr=127.0.0.1:54154 laddr=127.0.0.1:6379 fd=34 name= age=120 idle=1 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=12 addr=127.0.0.1:54158 laddr=127.0.0.1:6379 fd=35 name= age=120 idle=3 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=20504 events=r cmd=scard user=default redir=-1
id=39 addr=127.0.0.1:55004 laddr=127.0.0.1:6379 fd=62 name= age=35 idle=35 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=20504 events=r cmd=get user=default redir=-1
id=34 addr=127.0.0.1:54394 laddr=127.0.0.1:6379 fd=57 name= age=90 idle=32 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=20528 events=r cmd=set user=default redir=-1
id=13 addr=127.0.0.1:54162 laddr=127.0.0.1:6379 fd=36 name= age=120 idle=1 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=40954 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=87797 events=r cmd=brpop user=default redir=-1
id=14 addr=127.0.0.1:54166 laddr=127.0.0.1:6379 fd=37 name= age=120 idle=0 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=40954 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=87797 events=r cmd=brpop user=default redir=-1
id=15 addr=127.0.0.1:54170 laddr=127.0.0.1:6379 fd=38 name= age=120 idle=2 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=16 addr=127.0.0.1:54172 laddr=127.0.0.1:6379 fd=39 name= age=120 idle=2 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=17 addr=127.0.0.1:54182 laddr=127.0.0.1:6379 fd=40 name= age=120 idle=0 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=40954 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=87797 events=r cmd=brpop user=default redir=-1
id=18 addr=127.0.0.1:54190 laddr=127.0.0.1:6379 fd=41 name= age=120 idle=2 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=46845 events=r cmd=brpop user=default redir=-1
id=19 addr=127.0.0.1:54194 laddr=127.0.0.1:6379 fd=42 name= age=120 idle=0 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=40954 argv-mem=22773 obl=0 oll=0 omem=0 tot-mem=87797 events=r cmd=brpop user=default redir=-1

------ MODULES INFO OUTPUT ------

------ FAST MEMORY TEST ------
49395:49409:M 24 May 2023 16:15:36.339 # main thread terminated
49395:49409:M 24 May 2023 16:15:36.339 # Bio thread for job type #0 terminated
49395:49409:M 24 May 2023 16:15:36.339 # Bio thread for job type #1 terminated
49395:49409:M 24 May 2023 16:15:36.339 # Bio thread for job type #2 terminated

Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible.

=== KEYDB BUG REPORT END. Make sure to include from START to END. ===

       Please report the crash by opening an issue on github:

           https://github.com/JohnSully/KeyDB/issues

  Suspect RAM error? Use keydb-server --test-memory to verify it.

49456:49455:C 24 May 2023 16:15:36.653 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
49456:49455:C 24 May 2023 16:15:36.653 # KeyDB version=6.3.3, bits=64, commit=00000000, modified=0, pid=49456, just started
49456:49455:C 24 May 2023 16:15:36.653 # Configuration loaded

Aditional information

  1. OS distribution and version
PRETTY_NAME="Ubuntu 22.04.2 LTS"
NAME="Ubuntu"
VERSION_ID="22.04"
VERSION="22.04.2 LTS (Jammy Jellyfish)"
VERSION_CODENAME=jammy
ID=ubuntu
ID_LIKE=debian
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
UBUNTU_CODENAME=jammy
  1. Steps to reproduce (if any)
none
  1. Additional information
The KeyDB database is running as a Redis replacement for Gitlab (on the same system). The system is a Hyper-V Gen 2 virtual machine running in Windows 10. 

Also the crash is happening every two minutes:

49334:49333:C 24 May 2023 16:11:35.967 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
49395:49394:C 24 May 2023 16:13:36.140 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
49456:49455:C 24 May 2023 16:15:36.653 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
49529:49528:C 24 May 2023 16:17:37.905 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
49585:49584:C 24 May 2023 16:19:38.132 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
49650:49649:C 24 May 2023 16:21:38.137 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
49710:49709:C 24 May 2023 16:23:40.139 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
49773:49772:C 24 May 2023 16:25:40.392 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
49830:49829:C 24 May 2023 16:27:40.395 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
49894:49893:C 24 May 2023 16:29:40.395 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
@msotheeswaran-sc
Copy link
Collaborator

msotheeswaran-sc commented May 26, 2023

@duckasylum Can you provide the steps you took to reproduce the issue, I have not been able to reproduce it.

@duckasylum
Copy link
Author

There is no deliberate action to take to produce this. It just happens. My c++ skills are limited but I managed to find the code part responsible in blocked.cpp:

/* This function gets called when a blocked client timed out in order to
 * send it a reply of some kind. After this function is called,
 * unblockClient() will be called with the same client as argument. */
void replyToBlockedClientTimedOut(client *c) {
    if (c->btype == BLOCKED_LIST ||
        c->btype == BLOCKED_ZSET ||
        c->btype == BLOCKED_STREAM) {
        addReplyNullArray(c);
    } else if (c->btype == BLOCKED_WAIT) {
        addReplyLongLong(c,replicationCountAcksByOffset(c->bpop.reploffset));
    } else if (c->btype == BLOCKED_MODULE) {
        moduleBlockedClientTimedOut(c);
    } else {
        serverPanic("Unknown btype in replyToBlockedClientTimedOut().");
    }
}

The crash/serverpanic is triggered because this function gets c->btype == 7 i.e., BLOCKED_ASYNC. (I compiled the binary from source and added a line to dump the c->btype value). No idea if this helps.

Additional weird thing is that on very rare occasions the server can run for almost an hour before crashing - today I got two such streaks.

Maybe possible culprits here are:
System suspend - the vm is suspended on occasion, but wouldn't that be cleared by restarting the service? Or the client application is doing something somehow that it is not supposed to? Is that possible with KeyDB (like sending some weirdly formatted command)?

@msotheeswaran-sc
Copy link
Collaborator

Yeah c->btype == 7 helps, this function shouldn't be called for that type since it should not timeout. The issue is if a command that does timeout was called before, the timeout was not cleared and this function was incorrectly called. #662 fixes this. Thanks for the help!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants