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.

Sign up for GitHub

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

Jump to bottom

redis 3.2.8 crash：==> db.c:161 'retval == DICT_OK' is not true #5548

Open
weim0000 opened this issue Nov 11, 2018 · 7 comments
Open

redis 3.2.8 crash：==> db.c:161 'retval == DICT_OK' is not true #5548

weim0000 opened this issue Nov 11, 2018 · 7 comments

Comments

@weim0000
Copy link
Contributor

=== REDIS BUG REPORT START: Cut & paste starting from here ===
2711359:M 11 Nov 14:17:39.231 # === ASSERTION FAILED OBJECT CONTEXT ===
2711359:M 11 Nov 14:17:39.231 # Object type: 0
2711359:M 11 Nov 14:17:39.231 # Object encoding: 0
2711359:M 11 Nov 14:17:39.231 # Object refcount: 1
2711359:M 11 Nov 14:17:39.231 # Object raw string len: 26
2711359:M 11 Nov 14:17:39.231 # Object raw string content: "comment-0-1616050915108900"
2711359:M 11 Nov 14:17:39.231 # === ASSERTION FAILED ===
2711359:M 11 Nov 14:17:39.231 # ==> db.c:161 'retval == DICT_OK' is not true
2711359:M 11 Nov 14:17:39.231 # (forcing SIGSEGV to print the bug report.)
2711359:M 11 Nov 14:17:39.231 # Redis 3.2.8.1 crashed by signal: 11
2711359:M 11 Nov 14:17:39.231 # Crashed running the instuction at: 0x45dc2a
2711359:M 11 Nov 14:17:39.231 # Accessing address: 0xffffffffffffffff
2711359:M 11 Nov 14:17:39.231 # Failed assertion: retval == DICT_OK (db.c:161)

------ STACK TRACE ------
EIP:
./redis-server 127.0.0.1:6380(_serverAssert+0x6a)[0x45dc2a]

Backtrace:
./redis-server 127.0.0.1:6380(logStackTrace+0x29)[0x45f6e9]
./redis-server 127.0.0.1:6380(sigsegvHandler+0xa6)[0x45fd86]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xf890)[0x7f3916555890]
./redis-server 127.0.0.1:6380(_serverAssert+0x6a)[0x45dc2a]
./redis-server 127.0.0.1:6380(dbAdd+0x7f)[0x43b22f]
./redis-server 127.0.0.1:6380(rdbLoad+0x20a)[0x44455a]
./redis-server 127.0.0.1:6380(loadDataFromDisk+0x34)[0x42be34]
./redis-server 127.0.0.1:6380(main+0x37c)[0x41f51c]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5)[0x7f39161bcb45]
./redis-server 127.0.0.1:6380[0x41f7ff]

------ INFO OUTPUT ------

Server

redis_version:3.2.8.1
redis_git_sha1:0bd2c5a1
redis_git_dirty:1
redis_build_id:37b8462b2e39fe36
redis_mode:standalone
os:Linux 4.14.52.bm.6-amd64 x86_64
arch_bits:64
multiplexing_api:epoll
gcc_version:4.9.2
process_id:2711359
run_id:887e29d0eb4c6d16e592fd39063ab3fbf8a4bd22
tcp_port:6380
uptime_in_seconds:35
uptime_in_days:0
hz:10
lru_clock:15190368
executable:/data00/users/weimeng.555/redis_toutiao_ugc_counter_lf_3970.bak/./redis-server
config_file:/data00/users/weimeng.555/redis_toutiao_ugc_counter_lf_3970.bak/./redis.conf

Clients

connected_clients:0
client_longest_output_list:0
client_biggest_input_buf:0
blocked_clients:0

Memory

used_memory:3263154728
used_memory_human:3.04G
used_memory_rss:0
used_memory_rss_human:0B
used_memory_peak:3263154728
used_memory_peak_human:3.04G
total_system_memory:99453394944
total_system_memory_human:92.62G
used_memory_lua:37888
used_memory_lua_human:37.00K
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
mem_fragmentation_ratio:0.00
mem_allocator:jemalloc-4.2.1

Persistence

loading:1
rdb_changes_since_last_save:0
rdb_bgsave_in_progress:0
rdb_last_save_time:1541917024
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:-1
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
loading_start_time:1541917024
loading_total_bytes:1725338654
loading_loaded_bytes:1484783611
loading_loaded_perc:86.06
loading_eta_seconds:5

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
evicted_keys:0
keyspace_hits:0
keyspace_misses:0
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:0
migrate_cached_sockets:0

Replication

role:master
connected_slaves:0
master_repl_offset:0
repl_backlog_active:0
repl_backlog_size:1048576
repl_backlog_first_byte_offset:0
repl_backlog_histlen:0

CPU

used_cpu_sys:1.71
used_cpu_user:33.30
used_cpu_sys_children:0.00
used_cpu_user_children:0.00

Commandstats

Cluster

cluster_enabled:0

Keyspace

db0:keys=49272678,expires=0,avg_ttl=0
hash_init_value: 1540211659

------ CLIENT LIST OUTPUT ------

------ REGISTERS ------
2711359:M 11 Nov 14:17:39.231 #
RAX:0000000000000000 RBX:00000000000000a1
RCX:00000000004257e6 RDX:0000000000000000
RDI:00007f39165412a0 RSI:00007f39165427a0
RBP:00000000004f81dd RSP:00007fff50d33290
R8 :00007f391707d780 R9 :00007f39161e699a
R10:00007f391653f6a0 R11:0000000000000000
R12:00000000004f5f54 R13:0000000000000000
R14:0000000000000000 R15:00007f38593cc890
RIP:000000000045dc2a EFL:0000000000010202
CSGSFS:002b000000000033
2711359:M 11 Nov 14:17:39.231 # (00007fff50d3329f) -> 0000000000471050
2711359:M 11 Nov 14:17:39.231 # (00007fff50d3329e) -> 0000000000471030
2711359:M 11 Nov 14:17:39.231 # (00007fff50d3329d) -> 0000003000000000
2711359:M 11 Nov 14:17:39.231 # (00007fff50d3329c) -> 0000000000000000
2711359:M 11 Nov 14:17:39.231 # (00007fff50d3329b) -> 0000000000000007
2711359:M 11 Nov 14:17:39.231 # (00007fff50d3329a) -> 000000000086c470
2711359:M 11 Nov 14:17:39.231 # (00007fff50d33299) -> 00007f3915419683
2711359:M 11 Nov 14:17:39.231 # (00007fff50d33298) -> 0000000000000002
2711359:M 11 Nov 14:17:39.231 # (00007fff50d33297) -> 000000000044455a
2711359:M 11 Nov 14:17:39.231 # (00007fff50d33296) -> 00000167016a9fdc
2711359:M 11 Nov 14:17:39.231 # (00007fff50d33295) -> 00007f391542a800
2711359:M 11 Nov 14:17:39.231 # (00007fff50d33294) -> ffffffffffffffff
2711359:M 11 Nov 14:17:39.231 # (00007fff50d33293) -> 000000000043b22f
2711359:M 11 Nov 14:17:39.231 # (00007fff50d33292) -> 00007f391542a800
2711359:M 11 Nov 14:17:39.231 # (00007fff50d33291) -> 00007f38593cc890
2711359:M 11 Nov 14:17:39.231 # (00007fff50d33290) -> 00007f391541abc0

------ FAST MEMORY TEST ------
2711359:M 11 Nov 14:17:39.232 # Bio thread for job type #0 terminated
2711359:M 11 Nov 14:17:39.232 # Bio thread for job type #1 terminated
*** Preparing to test memory region 73d000 (90112 bytes)
*** Preparing to test memory region 85f000 (135168 bytes)
*** Preparing to test memory region 7f384ca00000 (2097152 bytes)
*** Preparing to test memory region 7f384d000000 (3332374528 bytes)
*** Preparing to test memory region 7f3913bfe000 (8388608 bytes)
*** Preparing to test memory region 7f39143ff000 (8388608 bytes)
*** Preparing to test memory region 7f3914c00000 (8388608 bytes)
*** Preparing to test memory region 7f3915400000 (2097152 bytes)
*** Preparing to test memory region 7f3915e00000 (2097152 bytes)
*** Preparing to test memory region 7f3916542000 (16384 bytes)
*** Preparing to test memory region 7f391675f000 (16384 bytes)
*** Preparing to test memory region 7f391707d000 (16384 bytes)
*** Preparing to test memory region 7f391708b000 (20480 bytes)
*** Preparing to test memory region 7f3917092000 (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: 0x45dbc0)
Module: ./redis-server 127.0.0.1:6380 (base 0x400000)
$ xxd -r -p /tmp/dump.hex /tmp/dump.bin
$ objdump --adjust-vma=0x45dbc0 -D -b binary -m i386:x86-64 /tmp/dump.bin

2711359:M 11 Nov 14:17:47.516 # dump of function (hexdump of 234 bytes):
8b0586052e0041544989fc554889f55389d385c07505e8f5fdffffbea6c84f00bf0300000031c0e8b47cfcff4d89e089d94889eabebfc84f00bf0300000031c0e89b7cfcffbe50ba4f00bf0300000031c04c892520052e0048892d21052e00891d23052e00e8767cfcffc60425ffffffff785b5d415cc3660f1f8400000000004154554989fc534883c4808b15fb042e0085d20f84e700000031c0be80ba4f00bf03000000e8367cfcff418b94249800000031c0bedac84f00bf0300000031ed31dbe8197cfcff418b54240831c0beedc84f00bf03000000e8037cfcff418b54243831c0befdc84f00bf
Function at 0x4258a0 is serverLog

=== 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.
@weim0000
Copy link
Contributor Author

I have checked the rdb file.
There are 2 same keys:"comment-0-1616050915108900", type is string, value is 1

@weim0000
Copy link
Contributor Author

"comment-0-1616050915108900":"1",
"comment-0-1616050915108900":"1",

@weim0000
Copy link
Contributor Author

I use redis-rdb-tools export commands from rdb file.
15634702 "comment-0-1616050915108900":"1",
49272680 "comment-0-1616050915108900":"1",

15634702 and 49272680 are line numbers. total lines 57247938

@weim0000
Copy link
Contributor Author

I start slave，and fullsync from master , then slave load rdb, then crash

@Echo-19
Copy link

Echo-19 commented Aug 20, 2020

I ran into the same problem，could you please tell me how to solve it?

@oranagra
Copy link
Member

@Echo-19 did you get the same assertion in dbAdd inside rdbLoad?
This assertion indicates that the RDB file contains two keys of the same name.
Please post the crash log, and tell us which redis version you're using, and how was the RDB file produced.

@Echo-19
Copy link

Echo-19 commented Aug 21, 2020 •
edited by oranagra

I used rdbtool to analyze the rdb file and confirmed that there are indeed two keys owned same name when loading the rdb file. the rdb file is generated by the master during the master-slave full synchronization​​ and the version of redis is 3.2.3.
Here is the same keys：
0,hash,jh:r:09b7c01f6adf15913aee,179,ziplist,16,8,
0,hash,jh:r:09b7c01f6adf15913aee,101,ziplist,3,8,
Here is the error message：

=== REDIS BUG REPORT START: Cut & paste starting from here ===
476438:M 20 Aug 14:21:00.516 # === ASSERTION FAILED OBJECT CONTEXT ===
476438:M 20 Aug 14:21:00.516 # Object type: 0
476438:M 20 Aug 14:21:00.516 # Object encoding: 0
476438:M 20 Aug 14:21:00.516 # Object refcount: 1
476438:M 20 Aug 14:21:00.516 # Object raw string len: 25
476438:M 20 Aug 14:21:00.516 # Object raw string content: "jh:r:09b7c01f6adf15913aee"
476438:M 20 Aug 14:21:00.516 # === ASSERTION FAILED ===
476438:M 20 Aug 14:21:00.516 # ==> db.c:161 'retval == DICT_OK' is not true
476438:M 20 Aug 14:21:00.516 # (forcing SIGSEGV to print the bug report.)
476438:M 20 Aug 14:21:00.516 # Redis 3.2.3 crashed by signal: 11
476438:M 20 Aug 14:21:00.516 # Crashed running the instuction at: 0x45b92f
476438:M 20 Aug 14:21:00.516 # Accessing address: 0xffffffffffffffff
476438:M 20 Aug 14:21:00.516 # Failed assertion: retval == DICT_OK (db.c:161)

------ STACK TRACE ------
EIP:
/home/service/app/redis/install/redis-3.2.3/bin/redis-server 10.35.224.14:6711 [cluster](_serverAssert+0x6f)[0x45b92f]

Backtrace:
/home/service/app/redis/install/redis-3.2.3/bin/redis-server 10.35.224.14:6711 [cluster](logStackTrace+0x3c)[0x45bd3c]
/home/service/app/redis/install/redis-3.2.3/bin/redis-server 10.35.224.14:6711 [cluster](sigsegvHandler+0xa1)[0x45cc21]
/lib64/libpthread.so.0[0x329200f7e0]
/home/service/app/redis/install/redis-3.2.3/bin/redis-server 10.35.224.14:6711 [cluster](_serverAssert+0x6f)[0x45b92f]
/home/service/app/redis/install/redis-3.2.3/bin/redis-server 10.35.224.14:6711 [cluster](dbAdd+0xaf)[0x43976f]
/home/service/app/redis/install/redis-3.2.3/bin/redis-server 10.35.224.14:6711 [cluster](rdbLoad+0x272)[0x442c82]
/home/service/app/redis/install/redis-3.2.3/bin/redis-server 10.35.224.14:6711 [cluster](loadDataFromDisk+0x1e)[0x425e6e]
/home/service/app/redis/install/redis-3.2.3/bin/redis-server 10.35.224.14:6711 [cluster](main+0x2da)[0x42718a]
/lib64/libc.so.6(__libc_start_main+0xfd)[0x3291c1ed1d]
/home/service/app/redis/install/redis-3.2.3/bin/redis-server 10.35.224.14:6711 [cluster][0x41d039]

------ INFO OUTPUT ------
# Server
redis_version:3.2.3
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:3bea8e32e3bcdb48
redis_mode:cluster
os:Linux 2.6.32-696.el6.x86_64 x86_64
arch_bits:64
multiplexing_api:epoll
gcc_version:4.4.7
process_id:476438
run_id:e5a0cc51d601719f105955a225c899dfcd2519f7
tcp_port:6711
uptime_in_seconds:340
uptime_in_days:0
hz:10
lru_clock:4068600

# Clients
connected_clients:0
client_longest_output_list:0
client_biggest_input_buf:0
blocked_clients:0

# Memory
used_memory:7836361440
used_memory_human:7.30G
used_memory_rss:0
used_memory_rss_human:0B
used_memory_peak:7836361440
used_memory_peak_human:7.30G
total_system_memory:406086299648
total_system_memory_human:378.20G
used_memory_lua:37888
used_memory_lua_human:37.00K
maxmemory:13958643712
maxmemory_human:13.00G
maxmemory_policy:volatile-lru
mem_fragmentation_ratio:0.00
mem_allocator:jemalloc-4.0.3

# Persistence
loading:1
rdb_changes_since_last_save:0
rdb_bgsave_in_progress:0
rdb_last_save_time:1597904120
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:-1
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
loading_start_time:1597904120
loading_total_bytes:3506528706
loading_loaded_bytes:2575302648
loading_loaded_perc:73.44
loading_eta_seconds:122

# Stats
total_connections_received:24
total_commands_processed:39
instantaneous_ops_per_sec:0
total_net_input_bytes:2346
total_net_output_bytes:33874
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
evicted_keys:0
keyspace_hits:0
keyspace_misses:0
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:0
migrate_cached_sockets:0

# Replication
role:master
connected_slaves:0
master_repl_offset:0
repl_backlog_active:0
repl_backlog_size:10000000
repl_backlog_first_byte_offset:0
repl_backlog_histlen:0

# CPU
used_cpu_sys:4.77
used_cpu_user:335.13
used_cpu_sys_children:0.00
used_cpu_user_children:0.00

# Commandstats
cmdstat_auth:calls=26,usec=48,usec_per_call=1.85
cmdstat_info:calls=13,usec=652,usec_per_call=50.15

# Cluster
cluster_enabled:1

# Keyspace
db0:keys=28964293,expires=10731364,avg_ttl=0
hash_init_value: 1597298764

------ CLIENT LIST OUTPUT ------

------ REGISTERS ------
476438:M 20 Aug 14:21:00.517 # 
RAX:0000000000000000 RBX:00000000000000a1
RCX:00000000ffffffff RDX:0000000000000000
RDI:0000000000000000 RSI:0000000000000000
RBP:00000000004e3b41 RSP:00007ffd3ee8cb30
R8 :00000000ffffffff R9 :0000000000000000
R10:7562206568742074 R11:0000000000000000
R12:00000000004e1dbc R13:00000000016198f0
R14:00007fc6a05b14f0 R15:ffffffffffffffff
RIP:000000000045b92f EFL:0000000000010206
CSGSFS:0000000000000033
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb3f) -> 0000003291c7430a
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb3e) -> 00007fc8863fc017
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb3d) -> 0000000091c60037
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb3c) -> 3030305349444552
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb3b) -> 00007ffd00000007
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb3a) -> 00007fc600000000
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb39) -> 00007ffd3ee8cb90
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb38) -> 00007ffd3ee8cbe0
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb37) -> 0000000000442c82
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb36) -> 000001740a81ec3a
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb35) -> 00007fc87fe27800
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb34) -> 00007ffd3ee8cf90
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb33) -> 000000000043976f
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb32) -> 00007fc87fe27800
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb31) -> 00007fc6a05b1500
476438:M 20 Aug 14:21:00.517 # (00007ffd3ee8cb30) -> 00007fc6a05b14f0

------ FAST MEMORY TEST ------
476438:M 20 Aug 14:21:00.517 # Bio thread for job type #0 terminated
476438:M 20 Aug 14:21:00.517 # Bio thread for job type #1 terminated
*** Preparing to test memory region 721000 (94208 bytes)
*** Preparing to test memory region 160c000 (135168 bytes)
*** Preparing to test memory region 3291622000 (4096 bytes)
*** Preparing to test memory region 3291f90000 (16384 bytes)
*** Preparing to test memory region 3292219000 (16384 bytes)
*** Preparing to test memory region 7fc6a03ff000 (8019513344 bytes)
*** Preparing to test memory region 7fc87e5ff000 (10485760 bytes)
*** Preparing to test memory region 7fc87f000000 (16777216 bytes)
*** Preparing to test memory region 7fc886000000 (2097152 bytes)
*** Preparing to test memory region 7fc8863ef000 (16384 bytes)
*** Preparing to test memory region 7fc8863fc000 (12288 bytes)
.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.
=== 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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@oranagra @weim0000 @Echo-19