Hello, When I fuzzed the redis server, I found these command will crash redis. Just like:
psync ldecl1 k
failover
set key value
In fact, set key value can be replaced with any command.
Save these command to a file named input, When executing nc 127.0.0.1 6379 < ./input, redis crashed.
I use AddressSanitizer(ASan) to compile redis. Here is the error output:
83901:M 27 Mar 2021 23:57:56.593 * Ready to accept connections
83901:M 27 Mar 2021 23:57:57.978 * Replica 127.0.0.1:<unknown-replica-port> asks for synchronization
83901:M 27 Mar 2021 23:57:57.978 * Replication backlog created, my new replication IDs are 'a3435f53876523650d68711898cb1d4429abd0fa' and '0000000000000000000000000000000000000000'
83901:M 27 Mar 2021 23:57:57.978 * Starting BGSAVE for SYNC with target: disk
83901:M 27 Mar 2021 23:57:57.979 * Background saving started by pid 83907
83901:M 27 Mar 2021 23:57:57.979 * FAILOVER requested to any replica.
=== REDIS BUG REPORT START: Cut & paste starting from here ===
83901:M 27 Mar 2021 23:57:57.980 # === ASSERTION FAILED ===
83901:M 27 Mar 2021 23:57:57.980 # ==> server.c:3570 '!(areClientsPaused() && !server.client_pause_in_transaction)' is not true
------ STACK TRACE ------
Backtrace:
./../src/redis-server *:6379(_serverAssert+0xb2)[0x5610c22ebb8d]
./../src/redis-server *:6379(propagate+0x87)[0x5610c220f431]
./../src/redis-server *:6379(call+0x7b8)[0x5610c220fe2d]
./../src/redis-server *:6379(processCommand+0x1109)[0x5610c2211d4a]
./../src/redis-server *:6379(processCommandAndResetClient+0x32)[0x5610c2247f54]
./../src/redis-server *:6379(processInputBuffer+0xb0)[0x5610c2251066]
./../src/redis-server *:6379(readQueryFromClient+0xb11)[0x5610c2258589]
./../src/redis-server *:6379(+0x28e1c7)[0x5610c23cd1c7]
./../src/redis-server *:6379(aeProcessEvents+0xfbc)[0x5610c21ffb4f]
./../src/redis-server *:6379(aeMain+0x51)[0x5610c21fff22]
./../src/redis-server *:6379(main+0xc9c)[0x5610c221b71d]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xe7)[0x7f591654fbf7]
./../src/redis-server *:6379(_start+0x2a)[0x5610c21f62fa]
------ INFO OUTPUT ------
# Server
redis_version:6.2.1
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:a467c84480d77006
redis_mode:standalone
os:Linux 5.4.0-42-generic x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:c11-builtin
gcc_version:7.5.0
process_id:83901
process_supervised:no
run_id:51a23597d1e785ebcf6394ecc3f7075f5981cc16
tcp_port:6379
server_time_usec:1616914677980015
uptime_in_seconds:1
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:6301941
executable:/home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/tmp/./../src/redis-server
config_file:
io_threads_active:0
# Clients
connected_clients:0
cluster_connections:0
maxclients:4064
client_recent_max_input_buffer:0
client_recent_max_output_buffer:0
blocked_clients:0
tracking_clients:0
clients_in_timeout_table:0
# Memory
used_memory:1643896
used_memory_human:1.57M
used_memory_rss:17989632
used_memory_rss_human:17.16M
used_memory_peak:1643896
used_memory_peak_human:1.57M
used_memory_peak_perc:100.11%
used_memory_overhead:1580024
used_memory_startup:531376
used_memory_dataset:63872
used_memory_dataset_perc:5.74%
allocator_allocated:760032
allocator_active:929792
allocator_resident:3293184
total_system_memory:2055110656
total_system_memory_human:1.91G
used_memory_lua:37888
used_memory_lua_human:37.00K
used_memory_scripts:0
used_memory_scripts_human:0B
number_of_cached_scripts:0
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.22
allocator_frag_bytes:169760
allocator_rss_ratio:3.54
allocator_rss_bytes:2363392
rss_overhead_ratio:5.46
rss_overhead_bytes:14696448
mem_fragmentation_ratio:33.85
mem_fragmentation_bytes:17458256
mem_not_counted_for_evict:0
mem_replication_backlog:1048576
mem_clients_slaves:0
mem_clients_normal:0
mem_aof_buffer:0
mem_allocator:jemalloc-5.1.0
active_defrag_running:0
lazyfree_pending_objects:0
lazyfreed_objects:0
# Persistence
loading:0
current_cow_size:0
current_fork_perc:0.00%
current_save_keys_processed:0
current_save_keys_total:0
rdb_changes_since_last_save:1
rdb_bgsave_in_progress:1
rdb_last_save_time:1616914676
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:0
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
module_fork_in_progress:0
module_fork_last_cow_size:0
# Stats
total_connections_received:1
total_commands_processed:2
instantaneous_ops_per_sec:0
total_net_input_bytes:38
total_net_output_bytes:0
instantaneous_input_kbps:0.00
instantaneous_output_kbps:0.00
rejected_connections:0
sync_full:1
sync_partial_ok:0
sync_partial_err:1
expired_keys:0
expired_stale_perc:0.00
expired_time_cap_reached_count:0
expire_cycle_cpu_milliseconds:0
evicted_keys:0
keyspace_hits:0
keyspace_misses:0
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:1099
total_forks:1
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:1
dump_payload_sanitizations:0
total_reads_processed:1
total_writes_processed:0
io_threaded_reads_processed:0
io_threaded_writes_processed:0
# Replication
role:master
connected_slaves:1
slave0:ip=127.0.0.1,port=0,state=wait_bgsave,offset=0,lag=0
master_failover_state:waiting-for-sync
master_replid:a3435f53876523650d68711898cb1d4429abd0fa
master_replid2:0000000000000000000000000000000000000000
master_repl_offset:0
second_repl_offset:-1
repl_backlog_active:1
repl_backlog_size:1048576
repl_backlog_first_byte_offset:1
repl_backlog_histlen:0
# CPU
used_cpu_sys:0.013550
used_cpu_user:0.011074
used_cpu_sys_children:0.000000
used_cpu_user_children:0.000000
used_cpu_sys_main_thread:0.014362
used_cpu_user_main_thread:0.009574
# Modules
# Commandstats
cmdstat_failover:calls=1,usec=29,usec_per_call=29.00,rejected_calls=0,failed_calls=0
cmdstat_psync:calls=1,usec=1368,usec_per_call=1368.00,rejected_calls=0,failed_calls=1
cmdstat_set:calls=1,usec=18,usec_per_call=18.00,rejected_calls=0,failed_calls=0
# Errorstats
errorstat_ERR:count=1
# Cluster
cluster_enabled:0
# Keyspace
db0:keys=1,expires=0,avg_ttl=0
------ CLIENT LIST OUTPUT ------
id=3 addr=127.0.0.1:48978 laddr=127.0.0.1:6379 fd=8 name= age=0 idle=0 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=38 qbuf-free=40916 argv-mem=11 obl=56 oll=0 omem=0 tot-mem=61475 events=r cmd=set user=default redir=-1
------ CURRENT CLIENT INFO ------
id=3 addr=127.0.0.1:48978 laddr=127.0.0.1:6379 fd=8 name= age=0 idle=0 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=38 qbuf-free=40916 argv-mem=11 obl=56 oll=0 omem=0 tot-mem=61475 events=r cmd=set user=default redir=-1
argv[0]: 'set'
argv[1]: 'key'
argv[2]: 'value'
83901:M 27 Mar 2021 23:57:57.981 # key 'key' found in DB containing the following object:
83901:M 27 Mar 2021 23:57:57.981 # Object type: 0
83901:M 27 Mar 2021 23:57:57.981 # Object encoding: 8
83901:M 27 Mar 2021 23:57:57.981 # Object refcount: 2
------ MODULES INFO OUTPUT ------
------ FAST MEMORY TEST ------
83901:M 27 Mar 2021 23:57:57.981 # Bio thread for job type #0 terminated
83901:M 27 Mar 2021 23:57:57.981 # Bio thread for job type #1 terminated
83907:C 27 Mar 2021 23:57:57.981 * DB saved on disk
83901:M 27 Mar 2021 23:57:57.981 # Bio thread for job type #2 terminated
*** Preparing to test memory region 7fff7000 (268435456 bytes)
*** Preparing to test memory region 2008fff7000 (15392894357504 bytes)
*** Preparing to test memory region 5610c284f000 (2289664 bytes)
*** Preparing to test memory region 602000000000 (65536 bytes)
*** Preparing to test memory region 602e00000000 (65536 bytes)
*** Preparing to test memory region 603000000000 (65536 bytes)
*** Preparing to test memory region 603e00000000 (65536 bytes)
*** Preparing to test memory region 604000000000 (65536 bytes)
*** Preparing to test memory region 604e00000000 (65536 bytes)
*** Preparing to test memory region 606000000000 (65536 bytes)
*** Preparing to test memory region 606e00000000 (65536 bytes)
*** Preparing to test memory region 607000000000 (65536 bytes)
*** Preparing to test memory region 607e00000000 (65536 bytes)
*** Preparing to test memory region 608000000000 (65536 bytes)
*** Preparing to test memory region 608e00000000 (65536 bytes)
*** Preparing to test memory region 60b000000000 (65536 bytes)
*** Preparing to test memory region 60be00000000 (65536 bytes)
*** Preparing to test memory region 60c000000000 (65536 bytes)
*** Preparing to test memory region 60ce00000000 (65536 bytes)
*** Preparing to test memory region 60d000000000 (65536 bytes)
*** Preparing to test memory region 60de00000000 (65536 bytes)
*** Preparing to test memory region 60e000000000 (65536 bytes)
*** Preparing to test memory region 60ee00000000 (65536 bytes)
*** Preparing to test memory region 60f000000000 (65536 bytes)
*** Preparing to test memory region 60fe00000000 (65536 bytes)
*** Preparing to test memory region 610000000000 (65536 bytes)
*** Preparing to test memory region 610e00000000 (65536 bytes)
*** Preparing to test memory region 611000000000 (65536 bytes)
*** Preparing to test memory region 611e00000000 (65536 bytes)
*** Preparing to test memory region 612000000000 (65536 bytes)
*** Preparing to test memory region 612e00000000 (65536 bytes)
*** Preparing to test memory region 613000000000 (65536 bytes)
*** Preparing to test memory region 613e00000000 (65536 bytes)
*** Preparing to test memory region 614000000000 (65536 bytes)
*** Preparing to test memory region 614e00000000 (65536 bytes)
*** Preparing to test memory region 615000000000 (65536 bytes)
*** Preparing to test memory region 615e00000000 (65536 bytes)
*** Preparing to test memory region 616000000000 (65536 bytes)
*** Preparing to test memory region 616e00000000 (65536 bytes)
*** Preparing to test memory region 617000000000 (65536 bytes)
*** Preparing to test memory region 617e00000000 (65536 bytes)
*** Preparing to test memory region 618000000000 (65536 bytes)
*** Preparing to test memory region 618e00000000 (65536 bytes)
*** Preparing to test memory region 619000000000 (65536 bytes)
*** Preparing to test memory region 619e00000000 (65536 bytes)
*** Preparing to test memory region 61a000000000 (65536 bytes)
*** Preparing to test memory region 61ae00000000 (65536 bytes)
*** Preparing to test memory region 61b000000000 (65536 bytes)
*** Preparing to test memory region 61be00000000 (65536 bytes)
*** Preparing to test memory region 61c000000000 (65536 bytes)
*** Preparing to test memory region 61ce00000000 (65536 bytes)
*** Preparing to test memory region 61d000000000 (65536 bytes)
*** Preparing to test memory region 61de00000000 (65536 bytes)
*** Preparing to test memory region 61e000000000 (65536 bytes)
*** Preparing to test memory region 61ee00000000 (65536 bytes)
*** Preparing to test memory region 621000000000 (65536 bytes)
*** Preparing to test memory region 621e00000000 (65536 bytes)
*** Preparing to test memory region 624000000000 (327680 bytes)
*** Preparing to test memory region 624e00000000 (65536 bytes)
*** Preparing to test memory region 640000000000 (12288 bytes)
*** Preparing to test memory region 7f591089e000 (2621440 bytes)
*** Preparing to test memory region 7f5910b1f000 (8388608 bytes)
*** Preparing to test memory region 7f5911320000 (8388608 bytes)
*** Preparing to test memory region 7f5911b21000 (8388608 bytes)
*** Preparing to test memory region 7f5912322000 (8388608 bytes)
*** Preparing to test memory region 7f5912e00000 (8388608 bytes)
*** Preparing to test memory region 7f5913600000 (1048576 bytes)
*** Preparing to test memory region 7f5913800000 (1048576 bytes)
*** Preparing to test memory region 7f5913a00000 (1048576 bytes)
*** Preparing to test memory region 7f5913c00000 (1048576 bytes)
*** Preparing to test memory region 7f5913dbc000 (37036032 bytes)
*** Preparing to test memory region 7f591691b000 (16384 bytes)
*** Preparing to test memory region 7f5916b3a000 (16384 bytes)
*** Preparing to test memory region 7f5917436000 (12996608 bytes)
*** Preparing to test memory region 7f591815f000 (90112 bytes)
*** Preparing to test memory region 7f59181b7000 (1019904 bytes)
*** Preparing to test memory region 7f59182b0000 (81920 bytes)
*** Preparing to test memory region 7f59182c6000 (4096 bytes)
.ASAN:DEADLYSIGNAL
=================================================================
==83901==ERROR: AddressSanitizer: SEGV on unknown address 0x000090016dff (pc 0x5610c23273d0 bp 0x7fffb89d4450 sp 0x7fffb88d4390 T0)
==83901==The signal is caused by a READ memory access.
83907:C 27 Mar 2021 23:57:57.983 * RDB: 0 MB of memory used by copy-on-write
#0 0x5610c23273cf in memcpy /usr/include/x86_64-linux-gnu/bits/string_fortified.h:34
#1 0x5610c23273cf in memtest_preserving_test /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/memtest.c:305
#2 0x5610c22eb2bb in memtest_test_linux_anonymous_maps /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/debug.c:1693
#3 0x5610c22eb477 in doFastMemoryTest /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/debug.c:1734
#4 0x5610c22eb824 in printCrashReport /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/debug.c:1850
#5 0x5610c22ebb91 in _serverAssert /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/debug.c:905
#6 0x5610c220f430 in propagate /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/server.c:3570
#7 0x5610c220fe2c in call /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/server.c:3788
#8 0x5610c2211d49 in processCommand /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/server.c:4178
#9 0x5610c2247f53 in processCommandAndResetClient /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/networking.c:1994
#10 0x5610c2251065 in processInputBuffer /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/networking.c:2088
#11 0x5610c2258588 in readQueryFromClient /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/networking.c:2174
#12 0x5610c23cd1c6 in callHandler /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/connhelpers.h:79
#13 0x5610c23cd1c6 in connSocketEventHandler /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/connection.c:295
#14 0x5610c21ffb4e in aeProcessEvents /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/ae.c:428
#15 0x5610c21fff21 in aeMain /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/ae.c:488
#16 0x5610c221b71c in main /home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/server.c:6277
#17 0x7f591654fbf6 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21bf6)
#18 0x5610c21f62f9 in _start (/home/zer0e/redis/asan_redis-6.2.1/redis-6.2.1/src/redis-server+0xb72f9)
AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV /usr/include/x86_64-linux-gnu/bits/string_fortified.h:34 in memcpy
==83901==ABORTING
My OS platform is Ubuntu 18.04.
Thanks.
FYI: We found this crash by fuzzing(AFL)
Comment From: yossigo
@madolson Looks like this was introduced in #8170.
Comment From: madolson
Ack, taking a look.
Comment From: madolson
Well this is an odd case. So for legacy reasons replica's have been allowed to ignore client pause and send commands any way to their primaries. I believe the intention of this is to allow ping/pong messages for health checks. With the introduction of 6.2, we try to provide stronger safety guarantees and we crash the server if mutating commands are executed during client pause. Since replicas are allowed to get around the client pause, they can sent mutating commands during the pause.
I'm don't think this crash needs to be explicitly fixed. We might want to re-think how the replication links works in the future to be more robust, but I'm not sure a tactical fix here is worthwhile. @oranagra @yossigo thoughts?
Comment From: oranagra
so a replica is sending a SET command to it's master (not something that should happen in real life), and if it happens during a failover, the master crashes on assertion.. i agree, i don't think it is important to fix, but if we do want to fix it, maybe the right thing is to reject any non-administrative command coming from a replica.
Comment From: yossigo
I agree it's not high priority and with @oranagra's solution.