我们在集群中有一个大的 redis 节点,我们正在将它重新分片到其他节点。在执行此操作时,我们多次遇到下面报告的错误,这迫使我们使用 kill -9 手动终止实例并重新加载它。
在正常操作中,节点已经工作了几个月,没有任何问题。唯一的特别之处是有一些非常大的键可以迁移;对于那些通常我们预计迁移超时的人,但以前我们没有这个错误迫使我们重新启动节点。
重新分片日志:
Moving slot 7929 from <source-node>:<port> to <target-node>:<port>: .................$
Moving slot 7930 from <source-node>:<port> to <target-node>:<port>: .................$
Moving slot 7931 from <source-node>:<port> to <target-node>:<port>: .................$
Moving slot 7932 from <source-node>:<port> to <target-node>:<port>: .................$
[ERR] Calling MIGRATE: Connection timed out
redis 日志:
=== REDIS BUG REPORT START: Cut & paste starting from here ===
29395:M 31 Jan 22:16:03.248 # Redis 3.2.3 crashed by signal: 11
29395:M 31 Jan 22:16:03.248 # Crashed running the instuction at: 0x468d4d
29395:M 31 Jan 22:16:03.248 # Accessing address: (nil)
29395:M 31 Jan 22:16:03.248 # Failed assertion: <no assertion failed> (<no file>:0)
------ STACK TRACE ------
EIP:
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](migrateCloseSocket+0x5d)[0x468d4d]
Backtrace:
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](logStackTrace+0x29)[0x45e699]
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](sigsegvHandler+0xaa)[0x45ebca]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7ffec32ce340]
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](migrateCloseSocket+0x5d)[0x468d4d]
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](migrateCommand+0x6d6)[0x469526]
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](call+0x85)[0x426fb5]
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](processCommand+0x367)[0x42a0e7]
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](processInputBuffer+0x105)[0x436d05]
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](aeProcessEvents+0x218)[0x421428]
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](aeMain+0x2b)[0x4216db]
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster](main+0x410)[0x41e690]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5)[0x7ffec2f19ec5]
/home/cybranding/redis-3.2.3/redis-stable/src/redis-server *:7010 [cluster][0x41e902]
------ INFO OUTPUT ------
# Server
redis_version:3.2.3
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:4992f89db2d932d
redis_mode:cluster
os:Linux 3.13.0-37-generic x86_64
arch_bits:64
multiplexing_api:epoll
gcc_version:4.8.2
process_id:29395
run_id:ea2b51c12beba3394b49febc23e62ddda85ddf7d
tcp_port:7010
uptime_in_seconds:218901
uptime_in_days:2
hz:10
lru_clock:9505952
executable:/home/cybranding/redis-3.2.3/redis-stable/src/redis-server
config_file:/etc/redis_cluster_client2/redis-3.2.3/7010/redis.conf
# Clients
connected_clients:7
client_longest_output_list:0
client_biggest_input_buf:0
blocked_clients:0
# Memory
used_memory:252229967880
used_memory_human:234.91G
used_memory_rss:226196897792
used_memory_rss_human:210.66G
used_memory_peak:261549868192
used_memory_peak_human:243.59G
total_system_memory:405738954752
total_system_memory_human:377.87G
used_memory_lua:37888
used_memory_lua_human:37.00K
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
mem_fragmentation_ratio:0.90
mem_allocator:jemalloc-4.0.3
# Persistence
loading:0
rdb_changes_since_last_save:2441620072
rdb_bgsave_in_progress:0
rdb_last_save_time:1485682059
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:-1
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_current_size:78198652011
aof_base_size:71141120009
aof_pending_rewrite:0
aof_buffer_length:0
aof_rewrite_buffer_length:0
aof_pending_bio_fsync:0
aof_delayed_fsync:0
# Stats
total_connections_received:50546
total_commands_processed:56092302
instantaneous_ops_per_sec:470
total_net_input_bytes:8820578118
total_net_output_bytes:15465464075
instantaneous_input_kbps:65.53
instantaneous_output_kbps:39.50
rejected_connections:0
sync_full:0
sync_partial_ok:0
sync_partial_err:0
expired_keys:70160
evicted_keys:0
keyspace_hits:25360054
keyspace_misses:16707970
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:0
migrate_cached_sockets:1
# 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:17440.44
used_cpu_user:20364.37
used_cpu_sys_children:0.00
used_cpu_user_children:0.00
# Commandstats
cmdstat_get:calls=3013601,usec=69399477,usec_per_call=23.03
cmdstat_setex:calls=93465,usec=29887340,usec_per_call=319.77
cmdstat_incr:calls=6164797,usec=48002289,usec_per_call=7.79
cmdstat_sadd:calls=6404,usec=171138,usec_per_call=26.72
cmdstat_sismember:calls=1920066,usec=57777586,usec_per_call=30.09
cmdstat_zincrby:calls=29150890,usec=1841876323,usec_per_call=63.18
cmdstat_zrevrange:calls=298356,usec=100612284,usec_per_call=337.22
cmdstat_zscore:calls=2641113,usec=185788620,usec_per_call=70.34
cmdstat_expire:calls=10839539,usec=70516036,usec_per_call=6.51
cmdstat_ping:calls=69,usec=114,usec_per_call=1.65
cmdstat_info:calls=50357,usec=8779396,usec_per_call=174.34
cmdstat_cluster:calls=1034173,usec=262678023,usec_per_call=254.00
cmdstat_migrate:calls=879469,usec=6675930023,usec_per_call=7590.86
cmdstat_command:calls=3,usec=10340,usec_per_call=3446.67
# Cluster
cluster_enabled:1
# Keyspace
db0:keys=141374638,expires=30371,avg_ttl=45048480
hash_init_value: 1485278005
------ CLIENT LIST OUTPUT ------
id=50534 addr=127.0.0.1:43431 fd=10 name= age=828 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=zincrby
id=50535 addr=127.0.0.1:43432 fd=11 name= age=828 idle=7 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=sismember
id=50541 addr=127.0.0.1:58608 fd=16 name= age=346 idle=49 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=get
id=50108 addr=127.0.0.1:55292 fd=18 name= age=39041 idle=6 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=zrevrange
id=50546 addr=127.0.0.1:50654 fd=19 name= age=108 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=migrate
id=50543 addr=127.0.0.1:60246 fd=13 name= age=264 idle=264 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=info
id=50544 addr=127.0.0.1:54748 fd=17 name= age=165 idle=159 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=cluster
------ CURRENT CLIENT INFO ------
id=50546 addr=127.0.0.1:50654 fd=19 name= age=108 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=migrate
argv[0]: 'DEL'
argv[1]: 'nht.tw.urls.dec:쩐다'
------ REGISTERS ------
29395:M 31 Jan 22:16:03.283 #
RAX:00007fcc4d3f30e3 RBX:b8e0a2b8e097b8e0
RCX:0000000000000002 RDX:0000000000000001
RDI:00007fcc4d3f30f9 RSI:00000000004e7857
RBP:00007fdf418f6430 RSP:00007fff08e86490
R8 :0000000000000005 R9 :00007ffec2a0d5a0
R10:0000000000000002 R11:00007ffec2c00180
R12:0000000000000001 R13:00007fc0e9df1d40
R14:0000000000000002 R15:0000000000000000
RIP:0000000000468d4d EFL:0000000000010202
CSGSFS:0000000000000033
29395:M 31 Jan 22:16:03.283 # (00007fff08e8649f) -> 0000000000000058
29395:M 31 Jan 22:16:03.283 # (00007fff08e8649e) -> 0000000004af8cbe
29395:M 31 Jan 22:16:03.284 # (00007fff08e8649d) -> 0000000000000000
29395:M 31 Jan 22:16:03.284 # (00007fff08e8649c) -> 00007fc07adec0f0
29395:M 31 Jan 22:16:03.284 # (00007fff08e8649b) -> 0000000000000000
29395:M 31 Jan 22:16:03.284 # (00007fff08e8649a) -> 00007ffec39f5690
29395:M 31 Jan 22:16:03.284 # (00007fff08e86499) -> 0000000100000000
29395:M 31 Jan 22:16:03.284 # (00007fff08e86498) -> 00007fc000000002
29395:M 31 Jan 22:16:03.284 # (00007fff08e86497) -> 00007fc0ee22c610
29395:M 31 Jan 22:16:03.284 # (00007fff08e86496) -> 00007fec6ad43fa0
29395:M 31 Jan 22:16:03.284 # (00007fff08e86495) -> 00007fc00000000a
29395:M 31 Jan 22:16:03.284 # (00007fff08e86494) -> 00007fc000000000
29395:M 31 Jan 22:16:03.284 # (00007fff08e86493) -> 0000000000469526
29395:M 31 Jan 22:16:03.284 # (00007fff08e86492) -> 0000000000000001
29395:M 31 Jan 22:16:03.284 # (00007fff08e86491) -> 00007fc07adec0f0
29395:M 31 Jan 22:16:03.284 # (00007fff08e86490) -> 00007fc0e9df1d40
------ FAST MEMORY TEST ------
29395:M 31 Jan 22:16:03.284 # Bio thread for job type #0 terminated
29395:M 31 Jan 22:16:03.285 # Bio thread for job type #1 terminated
*** Preparing to test memory region 724000 (94208 bytes)
*** Preparing to test memory region 1907000 (135168 bytes)
*** Preparing to test memory region 7fc053400000 (268131368960 bytes)
*** Preparing to test memory region 7ffec13ff000 (8388608 bytes)
*** Preparing to test memory region 7ffec1c00000 (14680064 bytes)
*** Preparing to test memory region 7ffec2a00000 (4194304 bytes)
*** Preparing to test memory region 7ffec32b9000 (20480 bytes)
*** Preparing to test memory region 7ffec34d8000 (16384 bytes)
*** Preparing to test memory region 7ffec39f5000 (16384 bytes)
*** Preparing to test memory region 7ffec3a01000 (4096 bytes)
*** Preparing to test memory region 7ffec3a02000 (8192 bytes)
*** Preparing to test memory region 7ffec3a06000 (4096 bytes)