search

Snapchat / KeyDB

A Multithreaded Fork of Redis
https://keydb.dev
BSD 3-Clause "New" or "Revised" License
11.02k stars 564 forks source link

[CRASH] In ae.cpp '!size || size == sizeof(cmd)' is not true #740

Open route opened 7 months ago

route commented 7 months ago

Crash report

=== KEYDB BUG REPORT START: Cut & paste starting from here ===
803:839:M 08 Oct 2023 17:03:46.770 # === ASSERTION FAILED ===
803:839:M 08 Oct 2023 17:03:46.770 # ==> ae.cpp:276 '!size || size == sizeof(cmd)' is not true

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

Backtrace:
/usr/bin/keydb-server *:6379(aePostFunction(aeEventLoop*, std::function<void ()>, bool, bool)+0x10c) [0xaaaab1714544]
/usr/bin/keydb-server *:6379(client::postFunction(std::function<void (client*)>, bool)+0xdc) [0xaaaab1708384]
/usr/bin/keydb-server *:6379(ProcessPendingAsyncWrites()+0x2e4) [0xaaaab16e7014]
/usr/bin/keydb-server *:6379(handleClientsWithPendingWrites(int, int)+0x2b0) [0xaaaab16e73e0]
/usr/bin/keydb-server *:6379(beforeSleep(aeEventLoop*)+0x744) [0xaaaab1704dec]
/usr/bin/keydb-server *:6379(aeProcessEvents+0x394) [0xaaaab170f714]
/usr/bin/keydb-server *:6379(aeMain+0x9c) [0xaaaab1711dcc]
/usr/bin/keydb-server *:6379(workerThreadMain(void*)+0x90) [0xaaaab16f9638]
/lib/aarch64-linux-gnu/libpthread.so.0(+0x7624) [0xffffad4ac624]
/lib/aarch64-linux-gnu/libc.so.6(+0xd149c) [0xffffad40349c]

------ INFO OUTPUT ------
# Server
redis_version:6.3.3
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:a89e2192e9d1d16a
redis_mode:standalone
os:Linux 5.15.0-1047-aws aarch64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:9.3.0
process_id:803
process_supervised:no
run_id:74dd1eb5927be6173307964728d206f3793b21a7
tcp_port:6379
server_time_usec:1696784626773087
uptime_in_seconds:82510
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:2285809
executable:/usr/bin/keydb-server
config_file:/etc/keydb/keydb.conf

# Clients
connected_clients:1468
cluster_connections:0
maxclients:20000
client_recent_max_input_buffer:159
client_recent_max_output_buffer:0
blocked_clients:58
tracking_clients:0
clients_in_timeout_table:58
current_client_thread:1
thread_0_clients:734
thread_1_clients:734

# Memory
used_memory:389633320
used_memory_human:371.58M
used_memory_rss:510365696
used_memory_rss_human:486.72M
used_memory_peak:1530566960
used_memory_peak_human:1.43G
used_memory_peak_perc:25.46%
used_memory_overhead:37570799
used_memory_startup:3935704
used_memory_dataset:352062521
used_memory_dataset_perc:91.28%
allocator_allocated:392756208
allocator_active:469524480
allocator_resident:517472256
total_system_memory:33031823360
total_system_memory_human:30.76G
used_memory_lua:55296
used_memory_lua_human:54.00K
used_memory_scripts:5160
used_memory_scripts_human:5.04K
number_of_cached_scripts:5
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.20
allocator_frag_bytes:76768272
allocator_rss_ratio:1.10
allocator_rss_bytes:47947776
rss_overhead_ratio:0.99
rss_overhead_bytes:-7106560
mem_fragmentation_ratio:1.30
mem_fragmentation_bytes:118732328
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:30152703
mem_aof_buffer:0
mem_allocator:jemalloc-5.2.1
active_defrag_running:0
lazyfree_pending_objects:0
lazyfreed_objects:1
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:0
rdb_bgsave_in_progress:0
rdb_last_save_time:1696784626
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:0
rdb_current_bgsave_time_sec:-1
rdb_last_cow_size:25309184
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:102805
total_commands_processed:1471609995
instantaneous_ops_per_sec:7524
total_net_input_bytes:133582747961
total_net_output_bytes:457481505626
instantaneous_input_kbps:644.05
instantaneous_output_kbps:2054.74
rejected_connections:0
sync_full:0
sync_partial_ok:0
sync_partial_err:0
expired_keys:3374784
expired_stale_perc:0.00
expired_time_cap_reached_count:0
expire_cycle_cpu_milliseconds:0
evicted_keys:0
keyspace_hits:1294157501
keyspace_misses:16169563
pubsub_channels:1
pubsub_patterns:0
latest_fork_usec:14259
total_forks:1269
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:129
dump_payload_sanitizations:0
total_reads_processed:214850904
total_writes_processed:216954786
instantaneous_lock_contention:1
avg_lock_contention:0.953125
storage_provider_read_hits:0
storage_provider_read_misses:0

# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:6729b3c3e71faaccb63a4f8f88f9017b2ba84b91
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:2390.200816
used_cpu_user:9546.085392
used_cpu_sys_children:185.420565
used_cpu_user_children:1233.194281
server_threads:2
long_lock_waits:36146
used_cpu_sys_main_thread:932.144301
used_cpu_user_main_thread:3567.023515

# Modules

# Commandstats
cmdstat_type:calls=32,usec=56,usec_per_call=1.75,rejected_calls=0,failed_calls=0
cmdstat_incrby:calls=3465920,usec=4105047,usec_per_call=1.18,rejected_calls=0,failed_calls=0
cmdstat_srem:calls=993382,usec=397371630,usec_per_call=400.02,rejected_calls=0,failed_calls=0
cmdstat_ping:calls=3688116,usec=1184267,usec_per_call=0.32,rejected_calls=0,failed_calls=0
cmdstat_unlink:calls=3700772,usec=15314284,usec_per_call=4.14,rejected_calls=0,failed_calls=0
cmdstat_bitfield:calls=889372,usec=2248931,usec_per_call=2.53,rejected_calls=0,failed_calls=0
cmdstat_hincrby:calls=3699927,usec=5251914,usec_per_call=1.42,rejected_calls=0,failed_calls=0
cmdstat_info:calls=12909,usec=499873,usec_per_call=38.72,rejected_calls=62,failed_calls=0
cmdstat_hgetall:calls=188757074,usec=591570063,usec_per_call=3.13,rejected_calls=0,failed_calls=0
cmdstat_lmove:calls=57309930,usec=1830551224,usec_per_call=31.94,rejected_calls=0,failed_calls=0
cmdstat_lrange:calls=12,usec=310,usec_per_call=25.83,rejected_calls=0,failed_calls=0
cmdstat_hget:calls=495293398,usec=389596888,usec_per_call=0.79,rejected_calls=0,failed_calls=0
cmdstat_lrem:calls=2120842,usec=7062390,usec_per_call=3.33,rejected_calls=0,failed_calls=0
cmdstat_sismember:calls=959564,usec=1745666,usec_per_call=1.82,rejected_calls=0,failed_calls=0
cmdstat_zremrangebyscore:calls=2457,usec=10735,usec_per_call=4.37,rejected_calls=0,failed_calls=0
cmdstat_zcard:calls=1794955,usec=1605186,usec_per_call=0.89,rejected_calls=0,failed_calls=0
cmdstat_publish:calls=6606110,usec=2449977,usec_per_call=0.37,rejected_calls=0,failed_calls=0
cmdstat_set:calls=649839,usec=1139686,usec_per_call=1.75,rejected_calls=0,failed_calls=0
cmdstat_zadd:calls=47109,usec=183775,usec_per_call=3.90,rejected_calls=0,failed_calls=0
cmdstat_lindex:calls=5983804,usec=6436376,usec_per_call=1.08,rejected_calls=0,failed_calls=0
cmdstat_exec:calls=11277299,usec=488127370,usec_per_call=43.28,rejected_calls=0,failed_calls=0
cmdstat_script:calls=13347,usec=40063,usec_per_call=3.00,rejected_calls=0,failed_calls=0
cmdstat_evalsha:calls=88699,usec=1838343,usec_per_call=20.73,rejected_calls=0,failed_calls=0
cmdstat_scard:calls=5829459,usec=3838343,usec_per_call=0.66,rejected_calls=0,failed_calls=0
cmdstat_del:calls=127,usec=642,usec_per_call=5.06,rejected_calls=0,failed_calls=0
cmdstat_hsetnx:calls=710,usec=625,usec_per_call=0.88,rejected_calls=0,failed_calls=0
cmdstat_multi:calls=11277299,usec=2936013,usec_per_call=0.26,rejected_calls=0,failed_calls=0
cmdstat_mget:calls=2,usec=99,usec_per_call=49.50,rejected_calls=0,failed_calls=0
cmdstat_hmget:calls=491755374,usec=867388707,usec_per_call=1.76,rejected_calls=0,failed_calls=0
cmdstat_subscribe:calls=12908,usec=18980,usec_per_call=1.47,rejected_calls=0,failed_calls=0
cmdstat_sadd:calls=4882560,usec=8046461,usec_per_call=1.65,rejected_calls=0,failed_calls=0
cmdstat_expire:calls=17473298,usec=19212722,usec_per_call=1.10,rejected_calls=0,failed_calls=0
cmdstat_rpop:calls=3688109,usec=4505034,usec_per_call=1.22,rejected_calls=0,failed_calls=0
cmdstat_sscan:calls=97108290,usec=388210223,usec_per_call=4.00,rejected_calls=0,failed_calls=0
cmdstat_blmove:calls=7026230,usec=16203999,usec_per_call=2.31,rejected_calls=0,failed_calls=0
cmdstat_hset:calls=20943406,usec=44751911,usec_per_call=2.14,rejected_calls=0,failed_calls=0
cmdstat_zrem:calls=9389,usec=25341,usec_per_call=2.70,rejected_calls=0,failed_calls=0
cmdstat_hdel:calls=948043,usec=1950950,usec_per_call=2.06,rejected_calls=0,failed_calls=0
cmdstat_hello:calls=102741,usec=447044,usec_per_call=4.35,rejected_calls=0,failed_calls=0
cmdstat_ltrim:calls=2074,usec=5069,usec_per_call=2.44,rejected_calls=0,failed_calls=0
cmdstat_llen:calls=10768621,usec=6933816,usec_per_call=0.64,rejected_calls=0,failed_calls=0
cmdstat_zremrangebyrank:calls=310,usec=1289,usec_per_call=4.16,rejected_calls=0,failed_calls=0
cmdstat_exists:calls=4634999,usec=3635943,usec_per_call=0.78,rejected_calls=0,failed_calls=0
cmdstat_zrange:calls=87190,usec=303998,usec_per_call=3.49,rejected_calls=0,failed_calls=0
cmdstat_scan:calls=19328,usec=35455567,usec_per_call=1834.41,rejected_calls=0,failed_calls=0
cmdstat_auth:calls=66,usec=489,usec_per_call=7.41,rejected_calls=0,failed_calls=66
cmdstat_get:calls=3097056,usec=2888391,usec_per_call=0.93,rejected_calls=0,failed_calls=0
cmdstat_lpush:calls=330110,usec=8240421,usec_per_call=24.96,rejected_calls=0,failed_calls=0
cmdstat_incr:calls=251,usec=603,usec_per_call=2.40,rejected_calls=0,failed_calls=0
cmdstat_smembers:calls=2348284,usec=32970123,usec_per_call=14.04,rejected_calls=0,failed_calls=0
cmdstat_hlen:calls=1908892,usec=1105743,usec_per_call=0.58,rejected_calls=0,failed_calls=0

# Errorstats
errorstat_ERR:count=1
errorstat_NOAUTH:count=62
errorstat_WRONGPASS:count=66

# Cluster
cluster_enabled:0

# Keyspace
db0:keys=21732,expires=21283,avg_ttl=4568411247,cached_keys=21732

# KeyDB
mvcc_depth:0

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

------ FAST MEMORY TEST ------
803:839:M 08 Oct 2023 17:03:46.778 # main thread terminated
803:839:M 08 Oct 2023 17:03:46.778 # Bio thread for job type #0 terminated
803:839:M 08 Oct 2023 17:03:46.778 # Bio thread for job type #1 terminated
803:839:M 08 Oct 2023 17:03:46.778 # 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. ===

Aditional information

  1. OS:

    Description:  Ubuntu 20.04.6 LTS
Release:  20.04
Codename: focal

  2. Looks like an error happened on the termination:

    
803:signal-handler (1696784625) Received SIGTERM scheduling shutdown...
803:signal-handler (1696784625) Received SIGTERM scheduling shutdown...
803:838:M 08 Oct 2023 17:03:45.967 # User requested shutdown...
803:838:M 08 Oct 2023 17:03:45.967 * Saving the final RDB snapshot before exiting.
803:838:M 08 Oct 2023 17:03:46.766 * DB saved on disk
803:838:M 08 Oct 2023 17:03:46.766 * Removing the pid file.
803:838:M 08 Oct 2023 17:03:46.766 # KeyDB is now ready to exit, bye bye...

=== KEYDB BUG REPORT START: Cut & paste starting from here === 803:839:M 08 Oct 2023 17:03:46.770 # === ASSERTION FAILED === 803:839:M 08 Oct 2023 17:03:46.770 # ==> ae.cpp:276 '!size || size == sizeof(cmd)' is not true