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.
7171:M 06 Feb 2022 01:19:58.011 # Server initialized
7171:M 06 Feb 2022 01:19:58.011 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
7171:M 06 Feb 2022 01:19:58.012 * The AOF directory appendonlydir doesn't exist
7171:M 06 Feb 2022 01:19:58.012 * Ready to accept connections
7171:M 06 Feb 2022 01:20:05.549 * Replica 127.0.0.1:<unknown-replica-port> asks for synchronization
7171:M 06 Feb 2022 01:20:05.549 * Replication backlog created, my new replication IDs are '13e422441fb8cec64b82c2e259785a7bba615f39' and '0000000000000000000000000000000000000000'
7171:M 06 Feb 2022 01:20:05.549 * Starting BGSAVE for SYNC with target: disk
7171:M 06 Feb 2022 01:20:05.549 * Background saving started by pid 7179
=== REDIS BUG REPORT START: Cut & paste starting from here ===
7171:M 06 Feb 2022 01:20:05.549 # === ASSERTION FAILED ===
7171:M 06 Feb 2022 01:20:05.549 # ==> networking.c:1048 'c->bufpos == 0 && listLength(c->reply) == 0' is not true
------ STACK TRACE ------
Backtrace:
src/redis-server *:6379(+0x8b0c3)[0x557cbe3e90c3]
src/redis-server *:6379(writeToClient+0x48)[0x557cbe3ea518]
src/redis-server *:6379(handleClientsWithPendingWrites+0x86)[0x557cbe3ea796]
src/redis-server *:6379(handleClientsWithPendingWritesUsingThreads+0x245)[0x557cbe3f1675]
src/redis-server *:6379(beforeSleep+0xf1)[0x557cbe3ce3a1]
src/redis-server *:6379(aeProcessEvents+0xf8)[0x557cbe3c9fa8]
src/redis-server *:6379(aeMain+0x1d)[0x557cbe3ca45d]
src/redis-server *:6379(main+0x312)[0x557cbe3c6192]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0x7f99693af0b3]
src/redis-server *:6379(_start+0x2e)[0x557cbe3c669e]
------ INFO OUTPUT ------
# Server
redis_version:255.255.255
redis_git_sha1:6ebb679f
redis_git_dirty:0
redis_build_id:dead6269609cca88
redis_mode:standalone
os:Linux 5.13.0-28-generic x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:c11-builtin
gcc_version:9.3.0
process_id:7171
process_supervised:no
run_id:ccc3168db2356e8c87a684e924a0204e4792dc0a
tcp_port:6379
server_time_usec:1644128405549859
uptime_in_seconds:7
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:16738453
executable:/home/nikhil/test redis/redis/src/redis-server
config_file:
io_threads_active:0
# Clients
connected_clients:0
cluster_connections:0
maxclients:10000
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:947400
used_memory_human:925.20K
used_memory_rss:6262784
used_memory_rss_human:5.97M
used_memory_peak:1060232
used_memory_peak_human:1.01M
used_memory_peak_perc:89.36%
used_memory_overhead:830060
used_memory_startup:829872
used_memory_dataset:117340
used_memory_dataset_perc:99.84%
allocator_allocated:1006696
allocator_active:1187840
allocator_resident:4042752
total_system_memory:8337719296
total_system_memory_human:7.77G
used_memory_lua:37888
used_memory_vm_eval:37888
used_memory_lua_human:37.00K
used_memory_scripts_eval:0
number_of_cached_scripts:0
number_of_functions:0
number_of_libraries:0
used_memory_vm_functions:37888
used_memory_vm_total:75776
used_memory_vm_total_human:74.00K
used_memory_functions:184
used_memory_scripts:184
used_memory_scripts_human:184B
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.18
allocator_frag_bytes:181144
allocator_rss_ratio:3.40
allocator_rss_bytes:2854912
rss_overhead_ratio:1.55
rss_overhead_bytes:2220032
mem_fragmentation_ratio:7.55
mem_fragmentation_bytes:5432768
mem_not_counted_for_evict:0
mem_replication_backlog:4
mem_total_replication_buffers:0
mem_clients_slaves:0
mem_clients_normal:0
mem_cluster_links:0
mem_aof_buffer:0
mem_allocator:jemalloc-5.2.1
active_defrag_running:0
lazyfree_pending_objects:0
lazyfreed_objects:0
# Persistence
loading:0
async_loading:0
current_cow_peak:0
current_cow_size:0
current_cow_size_age:0
current_fork_perc:0.00
current_save_keys_processed:0
current_save_keys_total:0
rdb_changes_since_last_save:0
rdb_bgsave_in_progress:1
rdb_last_save_time:1644128398
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:0
rdb_last_cow_size:0
rdb_last_load_keys_expired:0
rdb_last_load_keys_loaded: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:3
instantaneous_ops_per_sec:0
total_net_input_bytes:64
total_net_output_bytes:167628
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
evicted_clients:0
total_eviction_exceeded_time:0
current_eviction_exceeded_time:0
keyspace_hits:0
keyspace_misses:0
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:134
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
total_active_defrag_time:0
current_active_defrag_time: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:2
total_writes_processed:4
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:no-failover
master_replid:13e422441fb8cec64b82c2e259785a7bba615f39
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.000000
used_cpu_user:0.009654
used_cpu_sys_children:0.000000
used_cpu_user_children:0.000000
used_cpu_sys_main_thread:0.000000
used_cpu_user_main_thread:0.009577
# Modules
# Commandstats
cmdstat_sync:calls=1,usec=0,usec_per_call=0.00,rejected_calls=0,failed_calls=0
cmdstat_psync:calls=1,usec=194,usec_per_call=194.00,rejected_calls=0,failed_calls=1
cmdstat_command|docs:calls=1,usec=955,usec_per_call=955.00,rejected_calls=0,failed_calls=0
# Errorstats
errorstat_ERR:count=1
# Latencystats
latency_percentiles_usec_sync:p50=0.001,p99=0.001,p99.9=0.001
latency_percentiles_usec_psync:p50=194.559,p99=194.559,p99.9=194.559
latency_percentiles_usec_command|docs:p50=958.463,p99=958.463,p99.9=958.463
# Cluster
cluster_enabled:0
# Keyspace
------ CLIENT LIST OUTPUT ------
id=3 addr=127.0.0.1:38654 laddr=127.0.0.1:6379 fd=8 name= age=0 idle=0 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=20474 argv-mem=0 multi-mem=0 obl=46 oll=0 omem=0 tot-mem=40960 events=r cmd=sync user=default redir=-1 resp=2
------ MODULES INFO OUTPUT ------
------ CONFIG DEBUG OUTPUT ------
io-threads-do-reads no
lazyfree-lazy-eviction no
lazyfree-lazy-expire no
lazyfree-lazy-server-del no
lazyfree-lazy-user-del no
lazyfree-lazy-user-flush no
repl-diskless-sync yes
replica-read-only yes
activedefrag no
repl-diskless-load disabled
sanitize-dump-payload no
io-threads 1
list-compress-depth 0
proto-max-bulk-len 512mb
client-query-buffer-limit 1gb
------ FAST MEMORY TEST ------
7171:M 06 Feb 2022 01:20:05.551 # Bio thread for job type #0 terminated
7171:M 06 Feb 2022 01:20:05.551 # Bio thread for job type #1 terminated
7171:M 06 Feb 2022 01:20:05.551 # Bio thread for job type #2 terminated
*** Preparing to test memory region 557cbe615000 (2293760 bytes)
*** Preparing to test memory region 557cc00e7000 (135168 bytes)
*** Preparing to test memory region 7f9965c1f000 (8388608 bytes)
*** Preparing to test memory region 7f9966420000 (8388608 bytes)
*** Preparing to test memory region 7f9966c21000 (8388608 bytes)
*** Preparing to test memory region 7f9967422000 (8388608 bytes)
*** Preparing to test memory region 7f9968a00000 (8388608 bytes)
*** Preparing to test memory region 7f9969382000 (24576 bytes)
*** Preparing to test memory region 7f9969576000 (16384 bytes)
*** Preparing to test memory region 7f9969599000 (16384 bytes)
*** Preparing to test memory region 7f99696f2000 (8192 bytes)
*** Preparing to test memory region 7f9969737000 (4096 bytes)
.O.O.7179:C 06 Feb 2022 01:20:05.563 * DB saved on disk
7179:C 06 Feb 2022 01:20:05.563 * Fork CoW for RDB: current 1 MB, peak 1 MB, average 1 MB
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. ===
Additional information
- OS distribution and version - Ubuntu 20.04.3 LTS
- Steps to reproduce (if any)
- Build using default make command
- Run single redis server instance with no arguments (i.e. default parameters) -
redis-server - Issue this redis-cli command on terminal -
echo -e 'psync\rget\ra' | redis-cli
Comment From: enjoy-binbin
It should be the same kind of problem https://github.com/redis/redis/pull/10020
Thanks - verified.
Note just input psync a b will crash the server
Comment From: enjoy-binbin
i think the reason is here (getLongLongFromObjectOrReply): https://github.com/redis/redis/blob/6ebb679f061b357b46e07898b4f72505ff5f3778/src/replication.c#L703-L718
we should check the offset in syncCommand, and abort it in this situation