KeyDB icon indicating copy to clipboard operation
KeyDB copied to clipboard

[CRASH] dict.cpp:986 'iter->fingerprint == dictFingerprint(iter->d)' is not true

Open jhead-slg opened this issue 3 years ago • 0 comments

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.

Full crash report is to large, available here: https://gist.github.com/jhead-slg/63c808a69a62be13861b4dcf9935dd7e

keydb-0 keydb + exec keydb-server /etc/keydb/redis.conf --active-replica yes --multi-master yes --appendonly yes --bind 0.0.0.0 --port 6379 --protected-mode no --server-threads 4 --masterauth xxx --requirepass xxx --allow-write-during-load yes --client-output-buffer-limit slave 4294967296 1073741824 240 --appendfsync everysec --client-output-buffer-limit normal 0 0 0 --auto-aof-rewrite-min-size 8192mb --client-output-buffer-limit pubsub 33554432 8388608 60 --no-appendfsync-on-rewrite yes --save '""' --slowlog-log-slower-than 25000
keydb-0 keydb 1:1:C 09 Sep 2022 15:30:29.346 * Notice: "active-replica yes" implies "replica-read-only no"
keydb-0 keydb 1:1:C 09 Sep 2022 15:30:29.346 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
keydb-0 keydb 1:1:C 09 Sep 2022 15:30:29.346 # KeyDB version=6.3.1, bits=64, commit=ee16abf0, modified=1, pid=1, just started
keydb-0 keydb 1:1:C 09 Sep 2022 15:30:29.346 # Configuration loaded
keydb-0 keydb 1:1:M 09 Sep 2022 15:30:29.347 * monotonic clock: POSIX clock_gettime
keydb-0 keydb
keydb-0 keydb                   _
keydb-0 keydb                _-(+)-_
keydb-0 keydb             _-- /   \ --_
keydb-0 keydb          _--   /     \   --_            KeyDB  6.3.1 (ee16abf0/1) 64 bit
keydb-0 keydb      __--     /       \     --__
keydb-0 keydb     (+) _    /         \    _ (+)       Running in standalone mode
keydb-0 keydb      |   -- /           \ --   |        Port: 6379
keydb-0 keydb      |     /--_   _   _--\     |        PID: 1
keydb-0 keydb      |    /     -(+)-     \    |
keydb-0 keydb      |   /        |        \   |        https://docs.keydb.dev
keydb-0 keydb      |  /         |         \  |
keydb-0 keydb      | /          |          \ |
keydb-0 keydb     (+)_ -- -- -- | -- -- -- _(+)
keydb-0 keydb         --_       |       _--
keydb-0 keydb             --_   |   _--
keydb-0 keydb                 -(+)-        KeyDB has now joined Snap! See the announcement at:  https://docs.keydb.dev/news
keydb-0 keydb
keydb-0 keydb
keydb-0 keydb 1:1:M 09 Sep 2022 15:30:29.441 # Server initialized
keydb-0 keydb 1:1:M 09 Sep 2022 15:32:32.020 * DB loaded from append only file: 122.579 seconds
keydb-0 keydb 1:408:M 09 Sep 2022 15:32:32.029 * Thread 0 alive.
keydb-0 keydb 1:409:M 09 Sep 2022 15:32:32.029 * Thread 1 alive.
keydb-0 keydb 1:410:M 09 Sep 2022 15:32:32.029 * Thread 2 alive.
keydb-0 keydb 1:411:M 09 Sep 2022 15:32:32.029 * Thread 3 alive.
keydb-0 keydb 1:408:M 09 Sep 2022 15:32:32.090 * 10000 changes in 60 seconds. Saving...
keydb-0 keydb 1:408:M 09 Sep 2022 15:32:32.091 * Background saving started
keydb-0 keydb
keydb-0 keydb
keydb-0 keydb === KEYDB BUG REPORT START: Cut & paste starting from here ===
keydb-0 keydb 1:412:M 09 Sep 2022 15:32:32.179 # === ASSERTION FAILED ===
keydb-0 keydb 1:412:M 09 Sep 2022 15:32:32.179 # ==> dict.cpp:986 'iter->fingerprint == dictFingerprint(iter->d)' is not true
keydb-0 keydb
keydb-0 keydb ------ STACK TRACE ------
keydb-0 keydb
keydb-0 keydb Backtrace:
keydb-0 keydb keydb-server 0.0.0.0:6379(+0x5e468) [0x55db1825e468]
keydb-0 keydb keydb-server 0.0.0.0:6379(rdbSaveObject(_rio*, robj_roptr, robj_roptr)+0x558) [0x55db18367148]
keydb-0 keydb keydb-server 0.0.0.0:6379(rdbSaveKeyValuePair(_rio*, robj_roptr, robj_roptr, expireEntry const*)+0xc4) [0x55db18367704]
keydb-0 keydb keydb-server 0.0.0.0:6379(saveKey(_rio*, redisDbPersistentDataSnapshot const*, int, unsigned long*, char const*, robj_roptr)+0x85) [0x55db1836ae15]
keydb-0 keydb keydb-server 0.0.0.0:6379(+0xc5a7a) [0x55db182c5a7a]
keydb-0 keydb keydb-server 0.0.0.0:6379(redisDbPersistentDataSnapshot::iterate_threadsafe_core(std::function<bool (char const*, robj_roptr)>&, bool, bool, bool) const+0xb6) [0x55db18372036]
keydb-0 keydb keydb-server 0.0.0.0:6379(rdbSaveRio(_rio*, redisDbPersistentDataSnapshot const**, int*, int, rdbSaveInfo*)+0x2fc) [0x55db183646bc]
keydb-0 keydb keydb-server 0.0.0.0:6379(rdbSaveFile(char*, redisDbPersistentDataSnapshot const**, rdbSaveInfo*)+0xd5) [0x55db183649f5]
keydb-0 keydb keydb-server 0.0.0.0:6379(rdbSave(redisDbPersistentDataSnapshot const**, rdbSaveInfo*)+0x66) [0x55db18364d26]
keydb-0 keydb keydb-server 0.0.0.0:6379(rdbSaveThread(void*)+0x32f) [0x55db1836515f]
keydb-0 keydb /lib/x86_64-linux-gnu/libpthread.so.0(+0x76db) [0x7fcf327336db]
keydb-0 keydb /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f) [0x7fcf3245c61f]
keydb-0 keydb
keydb-0 keydb ------ INFO OUTPUT ------
keydb-0 keydb # Server
keydb-0 keydb redis_version:6.3.1
keydb-0 keydb redis_git_sha1:ee16abf0
keydb-0 keydb redis_git_dirty:1
keydb-0 keydb redis_build_id:46da54e1e1000581
keydb-0 keydb redis_mode:standalone
keydb-0 keydb os:Linux 5.15.0-46-generic x86_64
keydb-0 keydb arch_bits:64
keydb-0 keydb multiplexing_api:epoll
keydb-0 keydb atomicvar_api:atomic-builtin
keydb-0 keydb gcc_version:7.5.0
keydb-0 keydb process_id:1
keydb-0 keydb process_supervised:no
keydb-0 keydb run_id:c2033458aa5f4ade217b462b7da97cd99ed2b375
keydb-0 keydb tcp_port:6379
keydb-0 keydb server_time_usec:1662737552179901
keydb-0 keydb uptime_in_seconds:123
keydb-0 keydb uptime_in_days:0
keydb-0 keydb hz:10
keydb-0 keydb configured_hz:10
keydb-0 keydb lru_clock:1793168
keydb-0 keydb executable:/data/keydb-server
keydb-0 keydb config_file:/etc/keydb/redis.conf
keydb-0 keydb
keydb-0 keydb # Clients
keydb-0 keydb connected_clients:821
keydb-0 keydb cluster_connections:0
keydb-0 keydb maxclients:10000
keydb-0 keydb client_recent_max_input_buffer:607
keydb-0 keydb client_recent_max_output_buffer:0
keydb-0 keydb blocked_clients:0
keydb-0 keydb tracking_clients:0
keydb-0 keydb clients_in_timeout_table:0
keydb-0 keydb current_client_thread:-2025978027
keydb-0 keydb thread_0_clients:821
keydb-0 keydb thread_1_clients:0
keydb-0 keydb thread_2_clients:0
keydb-0 keydb thread_3_clients:0
keydb-0 keydb
keydb-0 keydb # Memory
keydb-0 keydb used_memory:155307328
keydb-0 keydb used_memory_human:148.11M
keydb-0 keydb used_memory_rss:339763200
keydb-0 keydb used_memory_rss_human:324.02M
keydb-0 keydb used_memory_peak:334090744
keydb-0 keydb used_memory_peak_human:318.61M
keydb-0 keydb used_memory_peak_perc:46.49%
keydb-0 keydb used_memory_overhead:13633005
keydb-0 keydb used_memory_startup:3196072
keydb-0 keydb used_memory_dataset:141674323
keydb-0 keydb used_memory_dataset_perc:93.14%
keydb-0 keydb allocator_allocated:155051016
keydb-0 keydb allocator_active:175235072
keydb-0 keydb allocator_resident:376496128
keydb-0 keydb total_system_memory:67005956096
keydb-0 keydb total_system_memory_human:62.40G
keydb-0 keydb used_memory_lua:37888
keydb-0 keydb used_memory_lua_human:37.00K
keydb-0 keydb used_memory_scripts:0
keydb-0 keydb used_memory_scripts_human:0B
keydb-0 keydb number_of_cached_scripts:0
keydb-0 keydb maxmemory:0
keydb-0 keydb maxmemory_human:0B
keydb-0 keydb maxmemory_policy:noeviction
keydb-0 keydb allocator_frag_ratio:1.13
keydb-0 keydb allocator_frag_bytes:20184056
keydb-0 keydb allocator_rss_ratio:2.15
keydb-0 keydb allocator_rss_bytes:201261056
keydb-0 keydb rss_overhead_ratio:0.90
keydb-0 keydb rss_overhead_bytes:-36732928
keydb-0 keydb mem_fragmentation_ratio:2.21
keydb-0 keydb mem_fragmentation_bytes:186336584
keydb-0 keydb mem_not_counted_for_evict:1056762
keydb-0 keydb mem_replication_backlog:0
keydb-0 keydb mem_clients_slaves:0
keydb-0 keydb mem_clients_normal:1682325
keydb-0 keydb mem_aof_buffer:8192
keydb-0 keydb mem_allocator:jemalloc-5.2.1
keydb-0 keydb active_defrag_running:0
keydb-0 keydb lazyfree_pending_objects:0
keydb-0 keydb lazyfreed_objects:0
keydb-0 keydb storage_provider:none
keydb-0 keydb
keydb-0 keydb # Persistence
keydb-0 keydb loading:0
keydb-0 keydb current_cow_size:0
keydb-0 keydb current_cow_size_age:0
keydb-0 keydb current_fork_perc:0.00
keydb-0 keydb current_save_keys_processed:0
keydb-0 keydb current_save_keys_total:0
keydb-0 keydb rdb_changes_since_last_save:40186609
keydb-0 keydb rdb_bgsave_in_progress:1
keydb-0 keydb rdb_last_save_time:1662737429
keydb-0 keydb rdb_last_bgsave_status:ok
keydb-0 keydb rdb_last_bgsave_time_sec:-1
keydb-0 keydb rdb_current_bgsave_time_sec:0
keydb-0 keydb rdb_last_cow_size:0
keydb-0 keydb aof_enabled:1
keydb-0 keydb aof_rewrite_in_progress:0
keydb-0 keydb aof_rewrite_scheduled:0
keydb-0 keydb aof_last_rewrite_time_sec:-1
keydb-0 keydb aof_current_rewrite_time_sec:-1
keydb-0 keydb aof_last_bgrewrite_status:ok
keydb-0 keydb aof_last_write_status:ok
keydb-0 keydb aof_last_cow_size:0
keydb-0 keydb module_fork_in_progress:0
keydb-0 keydb module_fork_last_cow_size:0
keydb-0 keydb aof_current_size:10018960142
keydb-0 keydb aof_base_size:10018933780
keydb-0 keydb aof_pending_rewrite:0
keydb-0 keydb aof_buffer_length:6096
keydb-0 keydb aof_rewrite_buffer_length:0
keydb-0 keydb aof_pending_bio_fsync:0
keydb-0 keydb aof_delayed_fsync:0
keydb-0 keydb
keydb-0 keydb # Stats
keydb-0 keydb total_connections_received:888
keydb-0 keydb total_commands_processed:27506041
keydb-0 keydb instantaneous_ops_per_sec:14006
keydb-0 keydb total_net_input_bytes:15357367
keydb-0 keydb total_net_output_bytes:4562618196
keydb-0 keydb instantaneous_input_kbps:6.87
keydb-0 keydb instantaneous_output_kbps:2267.61
keydb-0 keydb rejected_connections:0
keydb-0 keydb sync_full:0
keydb-0 keydb sync_partial_ok:0
keydb-0 keydb sync_partial_err:0
keydb-0 keydb expired_keys:10926
keydb-0 keydb expired_stale_perc:0.00
keydb-0 keydb expired_time_cap_reached_count:3
keydb-0 keydb expire_cycle_cpu_milliseconds:0
keydb-0 keydb evicted_keys:0
keydb-0 keydb keyspace_hits:2172
keydb-0 keydb keyspace_misses:1003
keydb-0 keydb pubsub_channels:0
keydb-0 keydb pubsub_patterns:0
keydb-0 keydb latest_fork_usec:0
keydb-0 keydb total_forks:0
keydb-0 keydb migrate_cached_sockets:0
keydb-0 keydb slave_expires_tracked_keys:0
keydb-0 keydb active_defrag_hits:0
keydb-0 keydb active_defrag_misses:0
keydb-0 keydb active_defrag_key_hits:0
keydb-0 keydb active_defrag_key_misses:0
keydb-0 keydb tracking_total_keys:0
keydb-0 keydb tracking_total_items:0
keydb-0 keydb tracking_total_prefixes:0
keydb-0 keydb unexpected_error_replies:0
keydb-0 keydb total_error_replies:2
keydb-0 keydb dump_payload_sanitizations:0
keydb-0 keydb total_reads_processed:963464
keydb-0 keydb total_writes_processed:963222
keydb-0 keydb instantaneous_lock_contention:1
keydb-0 keydb avg_lock_contention:0.015625
keydb-0 keydb storage_provider_read_hits:0
keydb-0 keydb storage_provider_read_misses:0
keydb-0 keydb
keydb-0 keydb # Replication
keydb-0 keydb role:master
keydb-0 keydb connected_slaves:0
keydb-0 keydb master_failover_state:no-failover
keydb-0 keydb master_replid:9f767a41a4a2626fbbab2df6ce8929dd2b36a85b
keydb-0 keydb master_replid2:0000000000000000000000000000000000000000
keydb-0 keydb master_repl_offset:0
keydb-0 keydb second_repl_offset:-1
keydb-0 keydb repl_backlog_active:0
keydb-0 keydb repl_backlog_size:1048576
keydb-0 keydb repl_backlog_first_byte_offset:0
keydb-0 keydb repl_backlog_histlen:0
keydb-0 keydb
keydb-0 keydb # CPU
keydb-0 keydb used_cpu_sys:18.397959
keydb-0 keydb used_cpu_user:104.404421
keydb-0 keydb used_cpu_sys_children:0.000000
keydb-0 keydb used_cpu_user_children:0.000685
keydb-0 keydb server_threads:4
keydb-0 keydb long_lock_waits:1
keydb-0 keydb used_cpu_sys_main_thread:0.011892
keydb-0 keydb used_cpu_user_main_thread:0.047568
keydb-0 keydb
keydb-0 keydb # Modules
keydb-0 keydb
keydb-0 keydb # Commandstats
keydb-0 keydb cmdstat_smembers:calls=136,usec=49110,usec_per_call=361.10,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_info:calls=962768,usec=27792184,usec_per_call=28.87,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_auth:calls=888,usec=1707,usec_per_call=1.92,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_exists:calls=1806,usec=3343,usec_per_call=1.85,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_hget:calls=137,usec=466,usec_per_call=3.40,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_client:calls=24,usec=39,usec_per_call=1.62,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_hmget:calls=89,usec=293,usec_per_call=3.29,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_hgetall:calls=653,usec=6439,usec_per_call=9.86,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_scard:calls=87,usec=93,usec_per_call=1.07,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_setex:calls=104,usec=418,usec_per_call=4.02,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_slowlog:calls=48,usec=95,usec_per_call=1.98,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_exec:calls=89,usec=553,usec_per_call=6.21,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_hmset:calls=1,usec=33,usec_per_call=33.00,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_get:calls=260,usec=676,usec_per_call=2.60,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_latency:calls=24,usec=31,usec_per_call=1.29,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_ping:calls=44,usec=25,usec_per_call=0.57,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_sismember:calls=6,usec=9,usec_per_call=1.50,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_multi:calls=114,usec=12,usec_per_call=0.11,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_hset:calls=35,usec=950,usec_per_call=27.14,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_config:calls=24,usec=1777,usec_per_call=74.04,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_lpush:calls=1,usec=9,usec_per_call=9.00,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_set:calls=3,usec=20,usec_per_call=6.67,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_lrem:calls=4,usec=53,usec_per_call=13.25,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_del:calls=6,usec=154,usec_per_call=25.67,rejected_calls=0,failed_calls=0
keydb-0 keydb cmdstat_lpop:calls=0,usec=0,usec_per_call=0.00,rejected_calls=2,failed_calls=0
keydb-0 keydb
keydb-0 keydb # Errorstats
keydb-0 keydb errorstat_LOADING:count=2
keydb-0 keydb
keydb-0 keydb # Cluster
keydb-0 keydb cluster_enabled:0
keydb-0 keydb
keydb-0 keydb # Keyspace
keydb-0 keydb db0:keys=133126,expires=115710,avg_ttl=2368,cached_keys=133126
keydb-0 keydb
keydb-0 keydb # KeyDB
keydb-0 keydb mvcc_depth:1
keydb-0 keydb
keydb-0 keydb ------ CLIENT LIST OUTPUT ------
keydb-0 keydb
keydb-0 keydb ------ MODULES INFO OUTPUT ------
keydb-0 keydb
keydb-0 keydb ------ FAST MEMORY TEST ------
keydb-0 keydb 1:412:M 09 Sep 2022 15:32:32.185 # main thread terminated
keydb-0 keydb 1:412:M 09 Sep 2022 15:32:32.185 # Bio thread for job type #0 terminated
keydb-0 keydb 1:412:M 09 Sep 2022 15:32:32.185 # Bio thread for job type #1 terminated
keydb-0 keydb 1:412:M 09 Sep 2022 15:32:32.185 # Bio thread for job type #2 terminated
keydb-0 keydb
keydb-0 keydb Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible.
keydb-0 keydb
keydb-0 keydb === KEYDB BUG REPORT END. Make sure to include from START to END. ===
keydb-0 keydb
keydb-0 keydb        Please report the crash by opening an issue on github:
keydb-0 keydb
keydb-0 keydb            https://github.com/JohnSully/KeyDB/issues
keydb-0 keydb
keydb-0 keydb   Suspect RAM error? Use keydb-server --test-memory to verify it.
keydb-0 keydb

Additional information

The error occurs after upgrading from v6.2.2 => v6.3.1. This is a single instance KeyDB.

  1. OS distribution and version Ubuntu 20.04.4 LTS 5.15.0-46-generic; Running as pod in Kubernetes.

  2. Steps to reproduce (if any) This did not occur in our dev environment. Only once going to production with higher data and traffic.

jhead-slg avatar Sep 09 '22 17:09 jhead-slg