Hi, This is a 4.0.12 version rdb, and i try to reload in 4.0.12/6.0.9, but both redis version crashed.
The details is below, many thansk.
=== REDIS BUG REPORT START: Cut & paste starting from here === 10224:M 23 Nov 21:59:16.052 # === ASSERTION FAILED OBJECT CONTEXT === 10224:M 23 Nov 21:59:16.052 # Object type: 0 10224:M 23 Nov 21:59:16.052 # Object encoding: 0 10224:M 23 Nov 21:59:16.052 # Object refcount: 1 10224:M 23 Nov 21:59:16.052 # Object raw string len: 0 10224:M 23 Nov 21:59:16.052 # Object raw string content: "" 10224:M 23 Nov 21:59:16.052 # === ASSERTION FAILED === 10224:M 23 Nov 21:59:16.052 # ==> db.c:171 'retval == DICT_OK' is not true 10224:M 23 Nov 21:59:16.052 # (forcing SIGSEGV to print the bug report.) 10224:M 23 Nov 21:59:16.052 # Redis 4.0.12 crashed by signal: 11 10224:M 23 Nov 21:59:16.052 # Crashed running the instruction at: 0x466cea 10224:M 23 Nov 21:59:16.052 # Accessing address: 0xffffffffffffffff 10224:M 23 Nov 21:59:16.052 # Failed assertion: retval == DICT_OK (db.c:171)
------ STACK TRACE ------ EIP: /opt/app/redis/sbin/redis-server *:6379(_serverAssert+0x6a)[0x466cea]
Backtrace: /opt/app/redis/sbin/redis-server :6379(logStackTrace+0x29)[0x468c19] /opt/app/redis/sbin/redis-server :6379(sigsegvHandler+0xac)[0x4692bc] /lib64/libpthread.so.0(+0xf5e0)[0x7fd11286c5e0] /opt/app/redis/sbin/redis-server :6379(_serverAssert+0x6a)[0x466cea] /opt/app/redis/sbin/redis-server :6379(dbAdd+0x87)[0x440e97] /opt/app/redis/sbin/redis-server :6379(rdbLoadRio+0x1c8)[0x44b248] /opt/app/redis/sbin/redis-server :6379(rdbLoad+0x3b)[0x44b87b] /opt/app/redis/sbin/redis-server :6379(loadDataFromDisk+0x8b)[0x42fd5b] /opt/app/redis/sbin/redis-server :6379(main+0x405)[0x4238c5] /lib64/libc.so.6(__libc_start_main+0xf5)[0x7fd1124bbc05] /opt/app/redis/sbin/redis-server *:6379[0x423c52]
------ INFO OUTPUT ------
Server
redis_version:4.0.12 xredis_version:1.0.2 redis_git_sha1:00000000 redis_git_dirty:0 redis_build_id:c3fee12d0de0775a redis_mode:standalone os:Linux 3.10.0-693.21.1.el7.x86_64 x86_64 arch_bits:64 multiplexing_api:epoll atomicvar_api:atomic-builtin gcc_version:4.8.5 process_id:10224 run_id:f8963f2f75fdee05af0377c4b5a3b8d3a7062b4d tcp_port:6379 uptime_in_seconds:15 uptime_in_days:0 hz:100 lru_clock:10285989 executable:/opt/app/redis/sbin/redis-server config_file:/opt/app/redis/etc/redis6379.conf
Clients
connected_clients:0 client_longest_output_list:0 client_biggest_input_buf:0 blocked_clients:0
Memory
used_memory:2116831688 used_memory_human:1.97G used_memory_rss:0 used_memory_rss_human:0B used_memory_peak:2116831688 used_memory_peak_human:1.97G used_memory_peak_perc:100.02% used_memory_overhead:939546888 used_memory_startup:786768 used_memory_dataset:1177284800 used_memory_dataset_perc:55.64% total_system_memory:25112248320 total_system_memory_human:23.39G used_memory_lua:37888 used_memory_lua_human:37.00K maxmemory:10737418240 maxmemory_human:10.00G maxmemory_policy:volatile-lru mem_fragmentation_ratio:0.00 mem_allocator:jemalloc-4.0.3 active_defrag_running:0 lazyfree_pending_objects:0
Persistence
loading:1 rdb_changes_since_last_save:0 rdb_bgsave_in_progress:0 rdb_last_save_time:1637675941 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 loading_start_time:1637675941 loading_total_bytes:3910824217 loading_loaded_bytes:1212153851 loading_loaded_perc:30.99 loading_eta_seconds:33
Stats
total_connections_received:0 total_commands_processed:0 instantaneous_ops_per_sec:0 total_net_input_bytes:0 total_net_output_bytes:0 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 evicted_keys:0 keyspace_hits:0 keyspace_misses:0 pubsub_channels:0 pubsub_patterns:0 latest_fork_usec: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
Replication
role:master connected_slaves:0 master_replid:8c35b69148c03073383b6b4c6502c19e45074a18 master_replid2:0000000000000000000000000000000000000000 master_repl_offset:0 second_repl_offset:-1 repl_backlog_active:0 repl_backlog_size:536870912 repl_backlog_first_byte_offset:0 repl_backlog_histlen:0
CPU
used_cpu_sys:2.54 used_cpu_user:12.27 used_cpu_sys_children:0.00 used_cpu_user_children:0.00
Commandstats
Cluster
cluster_enabled:0
Keyspace
db0:keys=6279544,expires=6279477,avg_ttl=0
------ CLIENT LIST OUTPUT ------
------ REGISTERS ------ 10224:M 23 Nov 21:59:16.069 # RAX:0000000000000000 RBX:00000000000000ab RCX:0000000001e555f0 RDX:00000000000137d0 RDI:00007fd112856760 RSI:0000000000000000 RBP:00000000004fc94e RSP:00007ffdfd9ae350 R8 :0000000000000001 R9 :00007fd1128567b8 R10:00007fd1128567b8 R11:0000000000000206 R12:00000000004fa10e R13:0000000000000000 R14:000000000000000d R15:00007ffdfd9ae810 RIP:0000000000466cea EFL:0000000000010202 CSGSFS:0000000000000033 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae35f) -> 0000017d4d60350d 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae35e) -> 0000000000000008 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae35d) -> 0000000000000008 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae35c) -> 00007fd089663af0 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae35b) -> 00000000124a3800 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae35a) -> 00007ffdfd9ae8b0 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae359) -> 0000017d4d17bd83 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae358) -> 0000000000000005 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae357) -> 000000000044b248 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae356) -> 00007fd10bb19000 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae355) -> 00007fd089663af0 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae354) -> ffffffffffffffff 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae353) -> 0000000000440e97 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae352) -> 00007fd10bb19000 10224:M 23 Nov 21:59:16.069 # (00007ffdfd9ae351) -> 00007fd089663af0 10224:M 23 Nov 21:59:16.070 # (00007ffdfd9ae350) -> 00007fd089663c00
------ FAST MEMORY TEST ------ 10224:M 23 Nov 21:59:16.070 # Bio thread for job type #0 terminated 10224:M 23 Nov 21:59:16.070 # Bio thread for job type #1 terminated 10224:M 23 Nov 21:59:16.070 # Bio thread for job type #2 terminated *** Preparing to test memory region 745000 (98304 bytes) *** Preparing to test memory region 1e48000 (135168 bytes) *** Preparing to test memory region 7fd089600000 (2157969408 bytes) *** Preparing to test memory region 7fd10a1fe000 (8388608 bytes) *** Preparing to test memory region 7fd10a9ff000 (8388608 bytes) *** Preparing to test memory region 7fd10b200000 (8388608 bytes) *** Preparing to test memory region 7fd10ba00000 (2097152 bytes) *** Preparing to test memory region 7fd112200000 (2097152 bytes) *** Preparing to test memory region 7fd112858000 (20480 bytes) *** Preparing to test memory region 7fd112a75000 (16384 bytes) *** Preparing to test memory region 7fd113194000 (16384 bytes) *** Preparing to test memory region 7fd11319d000 (8192 bytes) *** Preparing to test memory region 7fd11319f000 (4096 bytes) *** Preparing to test memory region 7fd1131a2000 (4096 bytes) .O.O.O.O.O.O.O.O.O.O.O.O.O.O Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible.
------ DUMPING CODE AROUND EIP ------ Symbol: _serverAssert (base: 0x466c80) Module: /opt/app/redis/sbin/redis-server *:6379 (base 0x400000) $ xxd -r -p /tmp/dump.hex /tmp/dump.bin $ objdump --adjust-vma=0x466c80 -D -b binary -m i386:x86-64 /tmp/dump.bin
10224:M 23 Nov 21:59:23.096 # dump of function (hexdump of 234 bytes): 41548b0514092e004989fc554889f585c05389d37505e8f5fdffffbe2e1a5000bf0300000031c0e8f431fcff4d89e089d94889eabe471a5000bf0300000031c0e8db31fcffbec00a5000bf0300000031c04c8925b0082e0048892db1082e00891db3082e00e8b631fcffc60425ffffffff785b5d415cc3660f1f84000000000041544989fc55534883c4808b158b082e0085d20f84e700000031c0bef00a5000bf03000000e87631fcff418b94249800000031c0be621a5000bf0300000031ed31dbe85931fcff418b54240831c0be751a5000bf03000000e84331fcff418b54243831c0be851a5000bf
=== REDIS BUG REPORT END. Make sure to include from START to END. ===
Please report the crash by opening an issue on github:
http://github.com/antirez/redis/issues
Suspect RAM error? Use redis-server --test-memory to verify it.
Comment From: oranagra
looks like for some reason you have two keys with the same name in that RDB file. do you have any idea how it happened? how was that RDB file generated? which commands (or modules) used?
Comment From: gaodg
Thanks you for your reply.
I don't konw how this happened. This is a production instance, and app write/read without any errors. I found this error because i wanted to replace a slave for machine maintenance, the new slave can't load the rdb and crashed. I analyse the rdb file, and the key name in rdb is unique.
Comment From: oranagra
You mean that you verified that there are no two keys in that rdb with the same name? How did you confirm that?
Comment From: gaodg
Sorry, the information i feeded back is not right. I verified with my colleage, he only try to load the rdb, and not analysed the rdb.
I use redis-rdb-tools anlysed the rdb, the step and result are:
- Using rdb tool to extract all all keys details info from rdb
- And extract only database/type/key/size_in_bytes properties
- Sorted the result by key property
- The result is rdb contains multi empty key with type string and hash, like below database type key size_in_bytes 0 string 1072 0 hash 109 0 hash 109 0 string 128 0 string 72 0 hash 80 0 hash 80 0 string 80 top50_key_sorted_bad_rdb.txt rdb_tools_result_sample.txt
It‘s very strange to see multi keys with the same name and same type, and multi keys with the same name with different type. And i can't reproduce this.
127.0.0.1:6379> get '' (nil) 127.0.0.1:6379> set '' test OK 127.0.0.1:6379> get '' "test" 127.0.0.1:6379> hset '' p p1 (error) WRONGTYPE Operation against a key holding the wrong kind of value
Many thanks.
Comment From: oranagra
This is very odd, one thing that comes to mind is that maybe your analysis script doesn't correctly handles some special chars. maybe it's is better to dump the key name with hex notation, or also dump it's length. maybe there's also some bug in redis-rdb-tools when handling some odd key names. either way, we need to figure out (be able to reproduce) how this rdb file was generated in order to proceed.
Comment From: gaodg
Many thanks.
As the redis instance has been destroyed，or else i can dump all keys name.
Comment From: gaodg
This is very odd, one thing that comes to mind is that maybe your analysis script doesn't correctly handles some special chars. maybe it's is better to dump the key name with hex notation, or also dump it's length. maybe there's also some bug in redis-rdb-tools when handling some odd key names. either way, we need to figure out (be able to reproduce) how this rdb file was generated in order to proceed.
@oranagra If you have any new findings, please leave a message. I close this issue now. Thank you!