KeyDB
KeyDB copied to clipboard
Published
20 hours ago •
Snapchat
Snapchat
[CRASH] keys with expire and keys from keydb.cron
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.
=== KEYDB BUG REPORT START: Cut & paste starting from here ===
1:26:M 09 Jul 2022 17:03:00.051 # === ASSERTION FAILED OBJECT CONTEXT ===
1:26:M 09 Jul 2022 17:03:00.051 # Object type: 0
1:26:M 09 Jul 2022 17:03:00.051 # Object encoding: 8
1:26:M 09 Jul 2022 17:03:00.052 # Object refcount: 1
1:26:M 09 Jul 2022 17:03:00.052 # === ASSERTION FAILED ===
1:26:M 09 Jul 2022 17:03:00.052 # ==> db.cpp:2724 'kde != NULL' is not true
------ STACK TRACE ------
Backtrace:
keydb-server 0.0.0.0:6379(redisDbPersistentData::setExpire(redisObject*, redisObject*, long long)+0xb15) [0x55ed58ccd105]
keydb-server 0.0.0.0:6379(setExpire(client*, redisDb*, redisObject*, redisObject*, long long)+0xb8) [0x55ed58ccd2a8]
keydb-server 0.0.0.0:6379(executeCronJobExpireHook(char const*, redisObject*)+0x35d) [0x55ed58d3219d]
keydb-server 0.0.0.0:6379(+0x9cf60) [0x55ed58c9cf60]
keydb-server 0.0.0.0:6379(aeProcessCmd(aeEventLoop*, int, void*, int)+0xe4) [0x55ed58c64f24]
keydb-server 0.0.0.0:6379(ProcessEventCore+0x12d) [0x55ed58c5d03d]
keydb-server 0.0.0.0:6379(aeProcessEvents+0x235) [0x55ed58c5eb45]
keydb-server 0.0.0.0:6379(aeMain+0x47) [0x55ed58c68467]
keydb-server 0.0.0.0:6379(workerThreadMain(void*)+0x73) [0x55ed58d384b3]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76db) [0x7fca52fc36db]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f) [0x7fca52cec61f]
------ INFO OUTPUT ------
# Server
redis_version:6.3.1
redis_git_sha1:ee16abf0
redis_git_dirty:1
redis_build_id:46da54e1e1000581
redis_mode:standalone
os:Linux 5.15.0-40-generic x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:7.5.0
process_id:1
process_supervised:no
run_id:a3ae770e85604e16bb43757da8863f20980400fa
tcp_port:6379
server_time_usec:1657386180066190
uptime_in_seconds:18232
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:13219012
executable:/data/keydb-server
config_file:/etc/keydb/keydb.conf
# Clients
connected_clients:2
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:141
client_recent_max_output_buffer:0
blocked_clients:1
tracking_clients:0
clients_in_timeout_table:0
current_client_thread:0
thread_0_clients:2
thread_1_clients:0
# Memory
used_memory:3610848
used_memory_human:3.44M
used_memory_rss:8454144
used_memory_rss_human:8.06M
used_memory_peak:3748840
used_memory_peak_human:3.58M
used_memory_peak_perc:96.32%
used_memory_overhead:2474677
used_memory_startup:1921432
used_memory_dataset:1136171
used_memory_dataset_perc:67.25%
allocator_allocated:4025096
allocator_active:4657152
allocator_resident:9965568
total_system_memory:7917432832
total_system_memory_human:7.37G
used_memory_lua:792576
used_memory_lua_human:774.00K
used_memory_scripts:188120
used_memory_scripts_human:183.71K
number_of_cached_scripts:1659
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.16
allocator_frag_bytes:632056
allocator_rss_ratio:2.14
allocator_rss_bytes:5308416
rss_overhead_ratio:0.85
rss_overhead_bytes:-1511424
mem_fragmentation_ratio:2.44
mem_fragmentation_bytes:4984448
mem_not_counted_for_evict:1048732
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:41125
mem_aof_buffer:160
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:7442432
current_cow_size_age:301
current_fork_perc:0.00
current_save_keys_processed:1
current_save_keys_total:0
rdb_changes_since_last_save:8296
rdb_bgsave_in_progress:1
rdb_last_save_time:1657385879
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:0
rdb_current_bgsave_time_sec:0
rdb_last_cow_size:7798784
aof_enabled:1
aof_rewrite_in_progress:0
aof_rewrite_scheduled:0
aof_last_rewrite_time_sec:-1
aof_current_rewrite_time_sec:-1
aof_last_bgrewrite_status:ok
aof_last_write_status:ok
aof_last_cow_size:0
module_fork_in_progress:0
module_fork_last_cow_size:0
aof_current_size:36711795
aof_base_size:0
aof_pending_rewrite:0
aof_buffer_length:69
aof_rewrite_buffer_length:0
aof_pending_bio_fsync:0
aof_delayed_fsync:0
# Stats
total_connections_received:41
total_commands_processed:511194
instantaneous_ops_per_sec:0
total_net_input_bytes:629789
total_net_output_bytes:39484
instantaneous_input_kbps:0.00
instantaneous_output_kbps:0.00
rejected_connections:0
sync_full:0
sync_partial_ok:0
sync_partial_err:0
expired_keys:0
expired_stale_perc:0.00
expired_time_cap_reached_count:0
expire_cycle_cpu_milliseconds:0
evicted_keys:0
keyspace_hits:137
keyspace_misses:1664
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:0
dump_payload_sanitizations:0
total_reads_processed:5242
total_writes_processed:5202
instantaneous_lock_contention:2
avg_lock_contention:0.093750
storage_provider_read_hits:0
storage_provider_read_misses:0
# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:06e42c4271069668e6718ad139cabfc7421cb222
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:73.112224
used_cpu_user:160.954854
used_cpu_sys_children:0.001541
used_cpu_user_children:0.005245
server_threads:2
long_lock_waits:169
used_cpu_sys_main_thread:30.785609
used_cpu_user_main_thread:103.192148
# Modules
# Commandstats
cmdstat_exists:calls=1660,usec=6269,usec_per_call=3.78,rejected_calls=0,failed_calls=0
cmdstat_incr:calls=504337,usec=1941446,usec_per_call=3.85,rejected_calls=0,failed_calls=0
cmdstat_get:calls=137,usec=4241,usec_per_call=30.96,rejected_calls=0,failed_calls=0
cmdstat_select:calls=39,usec=155,usec_per_call=3.97,rejected_calls=0,failed_calls=0
cmdstat_keydb.cron:calls=1659,usec=17049,usec_per_call=10.28,rejected_calls=0,failed_calls=0
cmdstat_xreadgroup:calls=2,usec=86,usec_per_call=43.00,rejected_calls=0,failed_calls=0
cmdstat_del:calls=1,usec=4,usec_per_call=4.00,rejected_calls=0,failed_calls=0
cmdstat_xgroup:calls=1,usec=46,usec_per_call=46.00,rejected_calls=0,failed_calls=0
cmdstat_lpush:calls=1659,usec=13958,usec_per_call=8.41,rejected_calls=0,failed_calls=0
cmdstat_set:calls=1661,usec=2794,usec_per_call=1.68,rejected_calls=0,failed_calls=0
cmdstat_ping:calls=38,usec=55,usec_per_call=1.45,rejected_calls=0,failed_calls=0
# Errorstats
# Cluster
cluster_enabled:0
# Keyspace
db0:keys=6637,expires=1659,avg_ttl=19,cached_keys=6637
db1:keys=1,expires=1,avg_ttl=81469377,cached_keys=1
# KeyDB
mvcc_depth:1
------ CLIENT LIST OUTPUT ------
id=4 addr=172.18.0.1:34132 laddr=172.18.0.2:6379 fd=19 name= age=18230 idle=18220 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=53 obl=0 oll=0 omem=0 tot-mem=20621 events=r cmd=xreadgroup user=default redir=-1
id=499403 addr=172.18.0.1:34224 laddr=172.18.0.2:6379 fd=134 name= age=200 idle=196 flags=N db=1 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
------ MODULES INFO OUTPUT ------
------ FAST MEMORY TEST ------
1:26:M 09 Jul 2022 17:03:00.069 # main thread terminated
1:26:M 09 Jul 2022 17:03:00.070 # Bio thread for job type #0 terminated
1:26:M 09 Jul 2022 17:03:00.070 # Bio thread for job type #1 terminated
1:26:M 09 Jul 2022 17:03:00.070 # 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.
1:1:C 09 Jul 2022 17:03:01.338 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
1:1:C 09 Jul 2022 17:03:01.338 # KeyDB version=6.3.1, bits=64, commit=ee16abf0, modified=1, pid=1, just started
1:1:C 09 Jul 2022 17:03:01.338 # Configuration loaded
1:1:M 09 Jul 2022 17:03:01.340 * monotonic clock: POSIX clock_gettime
Aditional information
- OS distribution and version
- Steps to reproduce (if any)
We started keydb 6.3.1 from dockerhub with this config:
bind 0.0.0.0
protected-mode no
port 6379
tcp-backlog 511
timeout 0
tcp-keepalive 300
daemonize no
supervised no
pidfile /var/run/keydb_6379.pid
loglevel notice
logfile ""
databases 3
always-show-logo yes
set-proc-title yes
proc-title-template "{title} {listen-addr} {server-mode}"
save 900 1
save 300 10
save 60 10000
stop-writes-on-bgsave-error yes
rdbcompression yes
rdbchecksum yes
dbfilename dump.rdb
rdb-del-sync-files no
dir ./
replica-serve-stale-data yes
replica-read-only yes
repl-diskless-sync no
repl-diskless-sync-delay 5
repl-diskless-load disabled
repl-disable-tcp-nodelay no
replica-priority 100
acllog-max-len 128
lazyfree-lazy-eviction no
lazyfree-lazy-expire no
lazyfree-lazy-server-del no
replica-lazy-flush no
lazyfree-lazy-user-del no
lazyfree-lazy-user-flush no
oom-score-adj no
oom-score-adj-values 0 200 800
disable-thp yes
appendonly yes
appendfilename "appendonly.aof"
appendfsync everysec
no-appendfsync-on-rewrite no
auto-aof-rewrite-percentage 100
auto-aof-rewrite-min-size 64mb
aof-load-truncated yes
aof-use-rdb-preamble yes
lua-time-limit 5000
slowlog-log-slower-than 10000
slowlog-max-len 128
latency-monitor-threshold 0
notify-keyspace-events ""
hash-max-ziplist-entries 512
hash-max-ziplist-value 64
list-max-ziplist-size -2
list-compress-depth 0
set-max-intset-entries 512
zset-max-ziplist-entries 128
zset-max-ziplist-value 64
hll-sparse-max-bytes 3000
stream-node-max-bytes 4096
stream-node-max-entries 100
activerehashing yes
client-output-buffer-limit normal 0 0 0
client-output-buffer-limit replica 256mb 64mb 60
client-output-buffer-limit pubsub 32mb 8mb 60
hz 10
dynamic-hz yes
aof-rewrite-incremental-fsync yes
rdb-save-incremental-fsync yes
jemalloc-bg-thread yes
server-threads 2
we added some keys with expire time, some keys with incrby, some values with keydb.cron. total keys: 6637. three hours after data inserted into keydb, it crashed
new crash
=== KEYDB BUG REPORT START: Cut & paste starting from here ===
1:28:M 15 Jul 2022 01:10:00.093 # === ASSERTION FAILED OBJECT CONTEXT ===
1:28:M 15 Jul 2022 01:10:00.093 # Object type: 0
1:28:M 15 Jul 2022 01:10:00.093 # Object encoding: 8
1:28:M 15 Jul 2022 01:10:00.093 # Object refcount: 1
1:28:M 15 Jul 2022 01:10:00.093 # === ASSERTION FAILED ===
1:28:M 15 Jul 2022 01:10:00.093 # ==> db.cpp:2724 'kde != NULL' is not true
------ STACK TRACE ------
Backtrace:
keydb-server 0.0.0.0:6379(redisDbPersistentData::setExpire(redisObject*, redisObject*, long long)+0xb15) [0x55a50774d105]
keydb-server 0.0.0.0:6379(setExpire(client*, redisDb*, redisObject*, redisObject*, long long)+0xb8) [0x55a50774d2a8]
keydb-server 0.0.0.0:6379(executeCronJobExpireHook(char const*, redisObject*)+0x35d) [0x55a5077b219d]
keydb-server 0.0.0.0:6379(+0x9cf60) [0x55a50771cf60]
keydb-server 0.0.0.0:6379(aeProcessCmd(aeEventLoop*, int, void*, int)+0xe4) [0x55a5076e4f24]
keydb-server 0.0.0.0:6379(ProcessEventCore+0x12d) [0x55a5076dd03d]
keydb-server 0.0.0.0:6379(aeProcessEvents+0x235) [0x55a5076deb45]
keydb-server 0.0.0.0:6379(aeMain+0x47) [0x55a5076e8467]
keydb-server 0.0.0.0:6379(workerThreadMain(void*)+0x73) [0x55a5077b84b3]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76db) [0x7fb041ecf6db]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f) [0x7fb041bf861f]
------ INFO OUTPUT ------
# Server
redis_version:6.3.1
redis_git_sha1:ee16abf0
redis_git_dirty:1
redis_build_id:46da54e1e1000581
redis_mode:standalone
os:Linux 5.4.0-105-generic x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:7.5.0
process_id:1
process_supervised:no
run_id:2eca8044758e73230cfbd8a7047dc1839d468e66
tcp_port:6379
server_time_usec:1657847400441327
uptime_in_seconds:7887
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:13680232
executable:/data/keydb-server
config_file:/etc/keydb/keydb.conf
# Clients
connected_clients:2
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:141
client_recent_max_output_buffer:0
blocked_clients:1
tracking_clients:0
clients_in_timeout_table:0
current_client_thread:0
thread_0_clients:2
thread_1_clients:0
thread_2_clients:0
thread_3_clients:0
# Memory
used_memory:4739616
used_memory_human:4.52M
used_memory_rss:18554880
used_memory_rss_human:17.70M
used_memory_peak:4881504
used_memory_peak_human:4.66M
used_memory_peak_perc:97.09%
used_memory_overhead:3599221
used_memory_startup:3045368
used_memory_dataset:1140395
used_memory_dataset_perc:67.31%
allocator_allocated:5176464
allocator_active:6328320
allocator_resident:9719808
total_system_memory:8343732224
total_system_memory_human:7.77G
used_memory_lua:770048
used_memory_lua_human:752.00K
used_memory_scripts:188816
used_memory_scripts_human:184.39K
number_of_cached_scripts:1658
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.22
allocator_frag_bytes:1151856
allocator_rss_ratio:1.54
allocator_rss_bytes:3391488
rss_overhead_ratio:1.91
rss_overhead_bytes:8835072
mem_fragmentation_ratio:4.00
mem_fragmentation_bytes:13915536
mem_not_counted_for_evict:1048732
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:41125
mem_aof_buffer:160
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:8966144
current_cow_size_age:301
current_fork_perc:0.00
current_save_keys_processed:1
current_save_keys_total:0
rdb_changes_since_last_save:8291
rdb_bgsave_in_progress:1
rdb_last_save_time:1657847099
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:0
rdb_current_bgsave_time_sec:0
rdb_last_cow_size:9248768
aof_enabled:1
aof_rewrite_in_progress:0
aof_rewrite_scheduled:0
aof_last_rewrite_time_sec:-1
aof_current_rewrite_time_sec:-1
aof_last_bgrewrite_status:ok
aof_last_write_status:ok
aof_last_cow_size:0
module_fork_in_progress:0
module_fork_last_cow_size:0
aof_current_size:19357963
aof_base_size:3674390
aof_pending_rewrite:0
aof_buffer_length:71
aof_rewrite_buffer_length:0
aof_pending_bio_fsync:0
aof_delayed_fsync:0
# Stats
total_connections_received:9
total_commands_processed:269863
instantaneous_ops_per_sec:1
total_net_input_bytes:184132
total_net_output_bytes:41021951
instantaneous_input_kbps:0.03
instantaneous_output_kbps:6.29
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:4
expire_cycle_cpu_milliseconds:0
evicted_keys:0
keyspace_hits:3
keyspace_misses:0
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:19
dump_payload_sanitizations:0
total_reads_processed:7923
total_writes_processed:7915
instantaneous_lock_contention:5
avg_lock_contention:0.250000
storage_provider_read_hits:0
storage_provider_read_misses:0
# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:7b7e9c1675a05117536bc3bb290f6330f3484b8d
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:96.555852
used_cpu_user:313.469603
used_cpu_sys_children:0.000000
used_cpu_user_children:0.010253
server_threads:4
long_lock_waits:108
used_cpu_sys_main_thread:28.589078
used_cpu_user_main_thread:94.014029
# Modules
# Commandstats
cmdstat_incr:calls=218857,usec=879242,usec_per_call=4.02,rejected_calls=0,failed_calls=0
cmdstat_get:calls=1,usec=50,usec_per_call=50.00,rejected_calls=0,failed_calls=0
cmdstat_del:calls=7,usec=129,usec_per_call=18.43,rejected_calls=0,failed_calls=0
cmdstat_info:calls=7882,usec=2070792,usec_per_call=262.72,rejected_calls=0,failed_calls=0
cmdstat_select:calls=6,usec=12921,usec_per_call=2153.50,rejected_calls=0,failed_calls=0
cmdstat_xreadgroup:calls=1,usec=601,usec_per_call=601.00,rejected_calls=19,failed_calls=0
# Errorstats
errorstat_LOADING:count=19
# Cluster
cluster_enabled:0
# Keyspace
db0:keys=6633,expires=1658,avg_ttl=0,cached_keys=6633
db1:keys=1,expires=1,avg_ttl=28978928,cached_keys=1
# KeyDB
mvcc_depth:1
------ CLIENT LIST OUTPUT ------
id=7 addr=172.20.0.4:50444 laddr=172.20.0.2:6379 fd=26 name= age=7887 idle=7886 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=53 obl=0 oll=0 omem=0 tot-mem=20621 events=r cmd=xreadgroup user=default redir=-1
id=1666 addr=172.20.0.3:40662 laddr=172.20.0.2:6379 fd=28 name= age=7881 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=20504 events=r cmd=info user=default redir=-1
------ MODULES INFO OUTPUT ------
------ FAST MEMORY TEST ------
1:28:M 15 Jul 2022 01:10:00.593 # main thread terminated
1:28:M 15 Jul 2022 01:10:00.624 # Bio thread for job type #0 terminated
1:28:M 15 Jul 2022 01:10:00.648 # Bio thread for job type #1 terminated
1:28:M 15 Jul 2022 01:10:00.649 # 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. ===
crash report from keys loaded from aof file and background saving report crash
1:1:M 16 Jul 2022 08:53:21.015 * Reading the remaining AOF tail...
1:1:M 16 Jul 2022 08:54:38.387 * DB loaded from append only file: 77.398 seconds
1:26:M 16 Jul 2022 08:54:38.388 * Thread 0 alive.
1:27:M 16 Jul 2022 08:54:38.388 * Thread 1 alive.
1:26:M 16 Jul 2022 08:54:38.393 * 10000 changes in 60 seconds. Saving...
1:26:M 16 Jul 2022 08:54:38.394 * Background saving started
=== KEYDB BUG REPORT START: Cut & paste starting from here ===
1:26:M 16 Jul 2022 08:54:38.395 # === ASSERTION FAILED OBJECT CONTEXT ===
1:26:M 16 Jul 2022 08:54:38.395 # Object type: 0
1:26:M 16 Jul 2022 08:54:38.395 # Object encoding: 8
1:26:M 16 Jul 2022 08:54:38.395 # Object refcount: 1
1:26:M 16 Jul 2022 08:54:38.395 # === ASSERTION FAILED ===
1:26:M 16 Jul 2022 08:54:38.395 # ==> db.cpp:2724 'kde != NULL' is not true
------ STACK TRACE ------
Backtrace:
keydb-server 0.0.0.0:6379(redisDbPersistentData::setExpire(redisObject*, redisObject*, long long)+0xb15) [0x5639792cd105]
keydb-server 0.0.0.0:6379(setExpire(client*, redisDb*, redisObject*, redisObject*, long long)+0xb8) [0x5639792cd2a8]
keydb-server 0.0.0.0:6379(executeCronJobExpireHook(char const*, redisObject*)+0x35d) [0x56397933219d]
keydb-server 0.0.0.0:6379(+0x9cf60) [0x56397929cf60]
keydb-server 0.0.0.0:6379(aeProcessCmd(aeEventLoop*, int, void*, int)+0xe4) [0x563979264f24]
keydb-server 0.0.0.0:6379(ProcessEventCore+0x12d) [0x56397925d03d]
keydb-server 0.0.0.0:6379(aeProcessEvents+0x235) [0x56397925eb45]
keydb-server 0.0.0.0:6379(aeMain+0x47) [0x563979268467]
keydb-server 0.0.0.0:6379(workerThreadMain(void*)+0x73) [0x5639793384b3]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76db) [0x7fa80e6cc6db]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f) [0x7fa80e3f561f]
------ INFO OUTPUT ------
# Server
redis_version:6.3.1
redis_git_sha1:ee16abf0
redis_git_dirty:1
redis_build_id:46da54e1e1000581
redis_mode:standalone
os:Linux 5.15.0-41-generic x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:7.5.0
process_id:1
process_supervised:no
run_id:6da588e28a7ff3f37c8101afd62deef4cdfe46a7
tcp_port:6379
server_time_usec:1657961678398699
uptime_in_seconds:78
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:13794510
executable:/data/keydb-server
config_file:/etc/keydb/keydb.conf
# Clients
connected_clients:1
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:16
client_recent_max_output_buffer:0
blocked_clients:0
tracking_clients:0
clients_in_timeout_table:0
current_client_thread:0
thread_0_clients:1
thread_1_clients:0
# Memory
used_memory:3589160
used_memory_human:3.42M
used_memory_rss:17960960
used_memory_rss_human:17.13M
used_memory_peak:6376184
used_memory_peak_human:6.08M
used_memory_peak_perc:56.29%
used_memory_overhead:2446400
used_memory_startup:1921432
used_memory_dataset:1142760
used_memory_dataset_perc:68.52%
allocator_allocated:3888848
allocator_active:4222976
allocator_resident:9494528
total_system_memory:7917436928
total_system_memory_human:7.37G
used_memory_lua:794624
used_memory_lua_human:776.00K
used_memory_scripts:188920
used_memory_scripts_human:184.49K
number_of_cached_scripts:1659
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.09
allocator_frag_bytes:334128
allocator_rss_ratio:2.25
allocator_rss_bytes:5271552
rss_overhead_ratio:1.89
rss_overhead_bytes:8466432
mem_fragmentation_ratio:5.13
mem_fragmentation_bytes:14461944
mem_not_counted_for_evict:1048764
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:20496
mem_aof_buffer:192
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:6768782
rdb_bgsave_in_progress:1
rdb_last_save_time:1657961600
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:0
rdb_last_cow_size:0
aof_enabled:1
aof_rewrite_in_progress:0
aof_rewrite_scheduled:0
aof_last_rewrite_time_sec:-1
aof_current_rewrite_time_sec:-1
aof_last_bgrewrite_status:ok
aof_last_write_status:ok
aof_last_cow_size:0
module_fork_in_progress:0
module_fork_last_cow_size:0
aof_current_size:486094966
aof_base_size:486094966
aof_pending_rewrite:0
aof_buffer_length:94
aof_rewrite_buffer_length:0
aof_pending_bio_fsync:0
aof_delayed_fsync:0
# Stats
total_connections_received:3
total_commands_processed:6669608
instantaneous_ops_per_sec:5351
total_net_input_bytes:1721
total_net_output_bytes:1594
instantaneous_input_kbps:0.00
instantaneous_output_kbps:0.00
rejected_connections:0
sync_full:0
sync_partial_ok:0
sync_partial_err:0
expired_keys:0
expired_stale_perc:0.00
expired_time_cap_reached_count:0
expire_cycle_cpu_milliseconds:0
evicted_keys:0
keyspace_hits:0
keyspace_misses:0
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:32
dump_payload_sanitizations:0
total_reads_processed:38
total_writes_processed:36
instantaneous_lock_contention:2
avg_lock_contention:0.031250
storage_provider_read_hits:0
storage_provider_read_misses:0
# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:fa8daf6b1afec88b1949854f7d1d189540390aca
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.828761
used_cpu_user:72.516610
used_cpu_sys_children:0.007868
used_cpu_user_children:0.003089
server_threads:2
long_lock_waits:0
used_cpu_sys_main_thread:0.007892
used_cpu_user_main_thread:0.000000
# Modules
# Commandstats
cmdstat_exists:calls=0,usec=0,usec_per_call=0.00,rejected_calls=24,failed_calls=0
cmdstat_ping:calls=3,usec=6,usec_per_call=2.00,rejected_calls=0,failed_calls=0
cmdstat_select:calls=1,usec=2,usec_per_call=2.00,rejected_calls=0,failed_calls=0
cmdstat_keydb.cron:calls=0,usec=0,usec_per_call=0.00,rejected_calls=8,failed_calls=0
cmdstat_incr:calls=1,usec=11,usec_per_call=11.00,rejected_calls=0,failed_calls=0
# Errorstats
errorstat_LOADING:count=32
# Cluster
cluster_enabled:0
# Keyspace
db0:keys=6633,expires=1658,avg_ttl=9,cached_keys=6633
# KeyDB
mvcc_depth:1
------ CLIENT LIST OUTPUT ------
id=4 addr=172.18.0.1:56002 laddr=172.18.0.2:6379 fd=19 name= age=78 idle=78 flags=N db=1 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
------ MODULES INFO OUTPUT ------
------ FAST MEMORY TEST ------
1:26:M 16 Jul 2022 08:54:38.400 # main thread terminated
1:26:M 16 Jul 2022 08:54:38.400 # Bio thread for job type #0 terminated
1:26:M 16 Jul 2022 08:54:38.400 # Bio thread for job type #1 terminated
1:26:M 16 Jul 2022 08:54:38.400 # 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. ===
Having the same issue, tried to benchmark having 100k cronjobs in KeyDB but only got to creating about 2k before it crashed and when restarted the jobs was gone.
My bug report:
=== KEYDB BUG REPORT START: Cut & paste starting from here ===
1:20:M 12 Nov 2022 16:14:14.024 # === ASSERTION FAILED OBJECT CONTEXT ===
1:20:M 12 Nov 2022 16:14:14.024 # Object type: 0
1:20:M 12 Nov 2022 16:14:14.024 # Object encoding: 8
1:20:M 12 Nov 2022 16:14:14.024 # Object refcount: 1
1:20:M 12 Nov 2022 16:14:14.024 # === ASSERTION FAILED ===
1:20:M 12 Nov 2022 16:14:14.024 # ==> db.cpp:2724 'kde != NULL' is not true
------ STACK TRACE ------
Backtrace:
redisDbPersistentData::setExpire(redisObject*, redisObject*, long long)(+0xa30) [0x00005652b6a95490] sp=0x00007f3061bfde00
setExpire(client*, redisDb*, redisObject*, redisObject*, long long)(+0xb8) [0x00005652b6a96e68] sp=0x00007f3061bfdeb0
executeCronJobExpireHook(char const*, redisObject*)(+0x3be) [0x00005652b69dc0ce] sp=0x00007f3061bfdef0
moduleCount()(+0x20) [0x00005652b69f83e0] sp=0x00007f3061bfdf30
aeProcessCmd(aeEventLoop*, int, void*, int)(+0xa9) [0x00005652b6ad8b19] sp=0x00007f3061bfdf40
ProcessEventCore(+0x10e) [0x00005652b6ad421e] sp=0x00007f3061bfdff0
aeProcessEvents(+0x1ed) [0x00005652b6ad645d] sp=0x00007f3061bfe0a0
aeMain(+0x3a) [0x00005652b6ad95ea] sp=0x00007f3061bfe160
workerThreadMain(void*)(+0x84) [0x00005652b6ac1744] sp=0x00007f3061bfe170
pthread_exit(+0x269) [0x00007f30642e67b7] sp=0x00007f3061bfe1a0
------ INFO OUTPUT ------
# Server
redis_version:6.3.1
redis_git_sha1:ee16abf0
redis_git_dirty:1
redis_build_id:b405fab5015f952a
redis_mode:standalone
os:Linux 6.0.8-arch1-1 x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:9.3.0
process_id:1
process_supervised:no
run_id:d9fa063113392545b7afd4248139bd9ad49d0274
tcp_port:6379
server_time_usec:1668269654026133
uptime_in_seconds:61
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:7325270
executable:/data/keydb-server
config_file:/etc/keydb/keydb.conf
# Clients
connected_clients:5
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:161
client_recent_max_output_buffer:0
blocked_clients:0
tracking_clients:0
clients_in_timeout_table:0
current_client_thread:0
thread_0_clients:5
thread_1_clients:0
# Memory
used_memory:3337080
used_memory_human:3.18M
used_memory_rss:18579456
used_memory_rss_human:17.72M
used_memory_peak:3337080
used_memory_peak_human:3.18M
used_memory_peak_perc:100.05%
used_memory_overhead:2351752
used_memory_startup:1989448
used_memory_dataset:985328
used_memory_dataset_perc:73.12%
allocator_allocated:4039264
allocator_active:4915200
allocator_resident:9838592
total_system_memory:16488841216
total_system_memory_human:15.36G
used_memory_lua:36864
used_memory_lua_human:36.00K
used_memory_scripts:432
used_memory_scripts_human:432B
number_of_cached_scripts:2
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.22
allocator_frag_bytes:875936
allocator_rss_ratio:2.00
allocator_rss_bytes:4923392
rss_overhead_ratio:1.89
rss_overhead_bytes:8740864
mem_fragmentation_ratio:5.92
mem_fragmentation_bytes:15442328
mem_not_counted_for_evict:1048576
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:102592
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:31097
rdb_bgsave_in_progress:1
rdb_last_save_time:1668269593
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:0
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:17
total_commands_processed:31180
instantaneous_ops_per_sec:2333
total_net_input_bytes:330569
total_net_output_bytes:891185
instantaneous_input_kbps:13.23
instantaneous_output_kbps:3.60
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:2
keyspace_misses:0
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:10
dump_payload_sanitizations:0
total_reads_processed:2377
total_writes_processed:2369
instantaneous_lock_contention:2
avg_lock_contention:0.921875
storage_provider_read_hits:0
storage_provider_read_misses:0
# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:ab43755748f289c8731fafed55eb0c4719d3ee0c
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.335737
used_cpu_user:0.787417
used_cpu_sys_children:0.000000
used_cpu_user_children:0.000881
server_threads:2
long_lock_waits:0
used_cpu_sys_main_thread:0.262761
used_cpu_user_main_thread:0.626356
# Modules
# Commandstats
cmdstat_flushdb:calls=1,usec=9,usec_per_call=9.00,rejected_calls=0,failed_calls=0
cmdstat_type:calls=1,usec=4,usec_per_call=4.00,rejected_calls=0,failed_calls=0
cmdstat_scan:calls=12,usec=369,usec_per_call=30.75,rejected_calls=0,failed_calls=0
cmdstat_select:calls=14,usec=24,usec_per_call=1.71,rejected_calls=0,failed_calls=0
cmdstat_incr:calls=28815,usec=48577,usec_per_call=1.69,rejected_calls=0,failed_calls=0
cmdstat_ping:calls=29,usec=33,usec_per_call=1.14,rejected_calls=0,failed_calls=0
cmdstat_info:calls=25,usec=4999,usec_per_call=199.96,rejected_calls=0,failed_calls=0
cmdstat_del:calls=1,usec=9,usec_per_call=9.00,rejected_calls=0,failed_calls=0
cmdstat_ttl:calls=1,usec=13,usec_per_call=13.00,rejected_calls=0,failed_calls=0
cmdstat_keydb.cron:calls=2281,usec=33975,usec_per_call=14.89,rejected_calls=0,failed_calls=0
# Errorstats
errorstat_ERR:count=10
# Cluster
cluster_enabled:0
# Keyspace
db0:keys=4553,expires=2281,avg_ttl=0,cached_keys=4553
# KeyDB
mvcc_depth:1
------ CLIENT LIST OUTPUT ------
id=10 addr=172.32.7.1:32952 laddr=172.32.7.2:6379 fd=20 name= age=58 idle=8 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=20536 events=r cmd=scan user=default redir=-1
id=11 addr=172.32.7.1:32954 laddr=172.32.7.2:6379 fd=21 name= age=57 idle=57 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=ttl user=default redir=-1
id=13 addr=172.32.7.1:32970 laddr=172.32.7.2:6379 fd=22 name= age=57 idle=2 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=info user=default redir=-1
id=19 addr=172.32.7.1:55794 laddr=172.32.7.2:6379 fd=23 name= age=25 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=20552 events=r cmd=keydb.cron user=default redir=-1
id=14289 addr=172.32.7.1:47712 laddr=172.32.7.2:6379 fd=18 name= age=8 idle=8 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=info user=default redir=-1
------ MODULES INFO OUTPUT ------
------ FAST MEMORY TEST ------
1:20:M 12 Nov 2022 16:14:14.026 # main thread terminated
1:20:M 12 Nov 2022 16:14:14.026 # Bio thread for job type #0 terminated
1:20:M 12 Nov 2022 16:14:14.027 # Bio thread for job type #1 terminated
1:20:M 12 Nov 2022 16:14:14.027 # 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. ===
Is there anyone still experiencing this issue, will be helpful to understand how to prioritize this.
