XGROUP CREATE s:foo g:foo $ MKSTREAM
XADD s:foo MAXLEN ~ 1 * foo 1
XADD s:foo MAXLEN ~ 1 * foo 2
XADD s:foo MAXLEN ~ 1 * foo 3
XADD s:foo MAXLEN ~ 1 * foo 4
XADD s:foo MAXLEN ~ 1 * foo 5
XREADGROUP GROUP g:foo c:1 COUNT 1 STREAMS s:foo >
XREADGROUP GROUP g:foo c:1 COUNT 1 STREAMS s:foo >
XREADGROUP GROUP g:foo c:1 COUNT 1 STREAMS s:foo >
XREADGROUP GROUP g:foo c:1 COUNT 1 STREAMS s:foo >
XREADGROUP GROUP g:foo c:1 COUNT 1 STREAMS s:foo >
XTRIM s:foo MAXLEN = 1
XREADGROUP GROUP g:foo c:1 COUNT 10 STREAMS s:foo 0
XAUTOCLAIM s:foo g:foo c:1 10 0 COUNT 1
This doesn't always crash the redis server.
=== REDIS BUG REPORT START: Cut & paste starting from here ===
1:M 13 Jul 2022 03:52:39.436 # Redis 7.0.3 crashed by signal: 11, si_code: 1
1:M 13 Jul 2022 03:52:39.436 # Accessing address: 0x7f3196beb080
1:M 13 Jul 2022 03:52:39.436 # Crashed running the instruction at: 0x55b57c25f846
------ STACK TRACE ------
EIP:
redis-server *:6379(raxRemove+0x2a6)[0x55b57c25f846]
Backtrace:
/lib/x86_64-linux-gnu/libpthread.so.0(+0x14140)[0x7f3178655140]
redis-server *:6379(raxRemove+0x2a6)[0x55b57c25f846]
redis-server *:6379(xautoclaimCommand+0x559)[0x55b57c2698a9]
redis-server *:6379(call+0xcb)[0x55b57c1b417b]
redis-server *:6379(processCommand+0x775)[0x55b57c1b67e5]
redis-server *:6379(processInputBuffer+0xde)[0x55b57c1cd33e]
redis-server *:6379(readQueryFromClient+0x300)[0x55b57c1d0da0]
redis-server *:6379(+0x13dfa8)[0x55b57c277fa8]
redis-server *:6379(aeProcessEvents+0x1ca)[0x55b57c1ab86a]
redis-server *:6379(aeMain+0x1d)[0x55b57c1abc0d]
redis-server *:6379(main+0x311)[0x55b57c1a7591]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xea)[0x7f31784a2d0a]
redis-server *:6379(_start+0x2a)[0x55b57c1a7bea]
------ REGISTERS ------
1:M 13 Jul 2022 03:52:39.438 #
RAX:000000001eb5df58 RBX:00007ffe7b6388b8
RCX:00007f31780634b0 RDX:00007f317808d128
RDI:0000000000000004 RSI:00007f317808d128
RBP:0000000000000008 RSP:00007ffe7b638880
R8 :000000001eb5df6c R9 :0000000000000008
R10:00007f317808d100 R11:000000001eb5df58
R12:0000000000000000 R13:00007f317808d020
R14:00007f31780633d8 R15:00007f3178063300
RIP:000055b57c25f846 EFL:0000000000010206
CSGSFS:002b000000000033
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b63888f) -> 000055b57c1bd9f3
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b63888e) -> 0000000000000001
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b63888d) -> 00007ffe7b6388f0
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b63888c) -> 00007ffe7b638960
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b63888b) -> 000055b500000020
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b63888a) -> 00007f3178027020
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b638889) -> 00007f3178063510
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b638888) -> 00007f31780634b0
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b638887) -> 00007f31780633d8
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b638886) -> 0000000000000020
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b638885) -> 0000000000000000
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b638884) -> 00007ffe7b6388b8
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b638883) -> 00007f317808d120
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b638882) -> 000000007b638aa0
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b638881) -> 0000000000000000
1:M 13 Jul 2022 03:52:39.438 # (00007ffe7b638880) -> 0000000000000000
------ INFO OUTPUT ------
# Server
redis_version:7.0.3
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:7e8634db15543dd
redis_mode:standalone
os:Linux 5.10.102.1-microsoft-standard-WSL2 x86_64
arch_bits:64
monotonic_clock:POSIX clock_gettime
multiplexing_api:epoll
atomicvar_api:c11-builtin
gcc_version:10.2.1
process_id:1
process_supervised:no
run_id:d92c5458259504c781b8a8315eb1a670873ed861
tcp_port:6379
server_time_usec:1657684359436885
uptime_in_seconds:548
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:13517191
executable:/data/redis-server
config_file:
io_threads_active:0
# Clients
connected_clients:1
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:8
client_recent_max_output_buffer:0
blocked_clients:0
tracking_clients:0
clients_in_timeout_table:0
# Memory
used_memory:1016072
used_memory_human:992.26K
used_memory_rss:13639680
used_memory_rss_human:13.01M
used_memory_peak:1089760
used_memory_peak_human:1.04M
used_memory_peak_perc:93.24%
used_memory_overhead:864824
used_memory_startup:862768
used_memory_dataset:151248
used_memory_dataset_perc:98.66%
allocator_allocated:1393464
allocator_active:1642496
allocator_resident:5058560
total_system_memory:8148529152
total_system_memory_human:7.59G
used_memory_lua:31744
used_memory_vm_eval:31744
used_memory_lua_human:31.00K
used_memory_scripts_eval:0
number_of_cached_scripts:0
number_of_functions:0
number_of_libraries:0
used_memory_vm_functions:32768
used_memory_vm_total:64512
used_memory_vm_total_human:63.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:249032
allocator_rss_ratio:3.08
allocator_rss_bytes:3416064
rss_overhead_ratio:2.70
rss_overhead_bytes:8581120
mem_fragmentation_ratio:13.72
mem_fragmentation_bytes:12645808
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_total_replication_buffers:0
mem_clients_slaves:0
mem_clients_normal:1800
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:21
rdb_bgsave_in_progress:0
rdb_last_save_time:1657683811
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:-1
rdb_saves: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_rewrites:0
aof_rewrites_consecutive_failures:0
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:14
instantaneous_ops_per_sec:0
total_net_input_bytes:1212
total_net_output_bytes:171375
total_net_repl_input_bytes:0
total_net_repl_output_bytes:0
instantaneous_input_kbps:0.00
instantaneous_output_kbps:0.00
instantaneous_input_repl_kbps:0.00
instantaneous_output_repl_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
expire_cycle_cpu_milliseconds:9
evicted_keys:0
evicted_clients:0
total_eviction_exceeded_time:0
current_eviction_exceeded_time:0
keyspace_hits:13
keyspace_misses:0
pubsub_channels:0
pubsub_patterns:0
pubsubshard_channels:0
latest_fork_usec:0
total_forks: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
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:0
dump_payload_sanitizations:0
total_reads_processed:15
total_writes_processed:16
io_threaded_reads_processed:0
io_threaded_writes_processed:0
reply_buffer_shrinks:1
reply_buffer_expands:0
# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:f3e83c9d77d754ae9331e1151c98649df94bee49
master_replid2:0000000000000000000000000000000000000000
master_repl_offset:0
second_repl_offset:-1
repl_backlog_active:0
repl_backlog_size:1048576
repl_backlog_first_byte_offset:0
repl_backlog_histlen:0
# CPU
used_cpu_sys:0.531926
used_cpu_user:0.437161
used_cpu_sys_children:0.002881
used_cpu_user_children:0.004468
used_cpu_sys_main_thread:0.523717
used_cpu_user_main_thread:0.440399
# Modules
# Commandstats
cmdstat_xtrim:calls=1,usec=67,usec_per_call=67.00,rejected_calls=0,failed_calls=0
cmdstat_xgroup|create:calls=1,usec=55,usec_per_call=55.00,rejected_calls=0,failed_calls=0
cmdstat_xreadgroup:calls=6,usec=160,usec_per_call=26.67,rejected_calls=0,failed_calls=0
cmdstat_command|docs:calls=1,usec=1036,usec_per_call=1036.00,rejected_calls=0,failed_calls=0
cmdstat_xadd:calls=5,usec=120,usec_per_call=24.00,rejected_calls=0,failed_calls=0
# Errorstats
# Latencystats
latency_percentiles_usec_xtrim:p50=67.071,p99=67.071,p99.9=67.071
latency_percentiles_usec_xgroup|create:p50=55.039,p99=55.039,p99.9=55.039
latency_percentiles_usec_xreadgroup:p50=24.063,p99=39.167,p99.9=39.167
latency_percentiles_usec_command|docs:p50=1036.287,p99=1036.287,p99.9=1036.287
latency_percentiles_usec_xadd:p50=15.039,p99=62.207,p99.9=62.207
# Cluster
cluster_enabled:0
# Keyspace
db0:keys=1,expires=0,avg_ttl=0
------ CLIENT LIST OUTPUT ------
id=3 addr=127.0.0.1:55662 laddr=127.0.0.1:6379 fd=8 name= age=114 idle=0 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 qbuf=85 qbuf-free=20389 argv-mem=32 multi-mem=0 rbs=1024 rbp=4 obl=4 oll=2 omem=80 tot-mem=22448 events=r cmd=xautoclaim user=default redir=-1 resp=2
------ CURRENT CLIENT INFO ------
id=3 addr=127.0.0.1:55662 laddr=127.0.0.1:6379 fd=8 name= age=114 idle=0 flags=N db=0 sub=0 psub=0 ssub=0 multi=-1 qbuf=85 qbuf-free=20389 argv-mem=32 multi-mem=0 rbs=1024 rbp=4 obl=4 oll=2 omem=80 tot-mem=22448 events=r cmd=xautoclaim user=default redir=-1 resp=2
argv[0]: '"XAUTOCLAIM"'
argv[1]: '"s:foo"'
argv[2]: '"g:foo"'
argv[3]: '"c:1"'
argv[4]: '"10"'
argv[5]: '"0"'
argv[6]: '"COUNT"'
argv[7]: '"1"'
1:M 13 Jul 2022 03:52:39.438 # key 's:foo' found in DB containing the following object:
1:M 13 Jul 2022 03:52:39.438 # Object type: 6
1:M 13 Jul 2022 03:52:39.438 # Object encoding: 10
1:M 13 Jul 2022 03:52:39.438 # Object refcount: 1
------ MODULES INFO OUTPUT ------
------ CONFIG DEBUG OUTPUT ------
lazyfree-lazy-server-del no
lazyfree-lazy-user-del no
list-compress-depth 0
lazyfree-lazy-expire no
io-threads-do-reads no
sanitize-dump-payload no
repl-diskless-sync yes
slave-read-only yes
proto-max-bulk-len 512mb
activedefrag no
io-threads 1
client-query-buffer-limit 1gb
lazyfree-lazy-eviction no
replica-read-only yes
repl-diskless-load disabled
lazyfree-lazy-user-flush no
------ FAST MEMORY TEST ------
1:M 13 Jul 2022 03:52:39.438 # Bio thread for job type #0 terminated
1:M 13 Jul 2022 03:52:39.439 # Bio thread for job type #1 terminated
1:M 13 Jul 2022 03:52:39.439 # Bio thread for job type #2 terminated
*** Preparing to test memory region 55b57c40a000 (2301952 bytes)
*** Preparing to test memory region 55b57d23f000 (270336 bytes)
*** Preparing to test memory region 7f3175bfd000 (8388608 bytes)
*** Preparing to test memory region 7f31763fe000 (8388608 bytes)
*** Preparing to test memory region 7f3176bff000 (8388608 bytes)
*** Preparing to test memory region 7f3177400000 (8388608 bytes)
*** Preparing to test memory region 7f3177c00000 (8388608 bytes)
*** Preparing to test memory region 7f3178476000 (24576 bytes)
*** Preparing to test memory region 7f317863d000 (16384 bytes)
*** Preparing to test memory region 7f317865f000 (16384 bytes)
*** Preparing to test memory region 7f3178953000 (16384 bytes)
*** Preparing to test memory region 7f3178b34000 (8192 bytes)
*** Preparing to test memory region 7f3178b64000 (4096 bytes)
.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: raxRemove (base: 0x55b57c25f5a0)
Module: redis-server *:6379 (base 0x55b57c13a000)
$ xxd -r -p /tmp/dump.hex /tmp/dump.bin
$ objdump --adjust-vma=0x55b57c25f5a0 -D -b binary -m i386:x86-64 /tmp/dump.bin
------
1:M 13 Jul 2022 03:52:39.528 # dump of function (hexdump of 806 bytes):
41574531c04989ff4156415541544989cc554889d5534881ec48010000488d5c2438488d44242048c74424280000000048895c2420488d4c24184883ec0848c744243820000000c784244001000000000000c744241c00000000504c8d4c2424e82befffff595e4839c50f8538040000488b6c24180fb64500a8040f8517040000a8010f841f0400004d85e4740c4889efe85af3ffff49890424806500fe8b450049836f080183e0f80f8521040000493b2f750fe9200400000f1f80000000004889fd4889efe8751df6ff488b44242849836f10014885c00f84f275f4ff4c8b4424204883e8014889442428498b3cc00fb60748897c2418a8017513a804750a8b0783e0f883f808750549393f75b14885ed0f84c60300004889eee820fdffff488b4c24184889c24839c8744f488b4424284885c00f84bd030000488b742420488b7cc6f84885ff0f84aa0300008b37c1ee038d460448f7d883e0074801f0488d440704483b0874100f1f80000000004883c008483b0875f74889108b0283e0f983f8080f854f03000048895424188b84243801000085c00f853b030000488b442428488b7424204885c00f84af0300000f1f80000000004883e8014c8b34c64d85f60f8473030000410fb616f6c2010f855203000083e204750f418b1683e2f883fa080f853e0300004c897424184885c075c448c74424280000000048c744240800000000418b1689d0c1e80383e2f84189c34d89d80f84bc020000410fb6164c89f6bf0100000041b908000000eb370f1f80000000008b004189c34183e3f84183fb080f85c5020000c1e8034189c34b8d2c034881fdffffff1f0f87ae02000083c7014989e883c0044a8d2cdd0000000048f7d883e007f6c204490f45e983e2034531e480fa01410f94c44f8d5ce3fc4c01d880fa010f95c24801ee0fb6d2488d54d6f8488b040248894424180fb6104889c6f6c2010f8552020000f6c2040f8471ffffff448b204489e0c1e8034189c34b8d2c034881fdffffff1f0f872c02000083c7014183e4f80f8574ffffff48c7c0fcffffff4829e883e007488d7c050ce86816f6ff4989c44885c00f844002000089e88d14ed040000004189142425ffffff1f
=== REDIS BUG REPORT END. Make sure to include from START to END. ===
Comment From: sundb
Thanks for your report, I reproduced your crash and perhaps you found a rax crash that we hadn't been able to reproduce before.
Comment From: enjoy-binbin
so look like it was introduced in #10227? @guybe7 FYI
Comment From: sundb
~~@enjoy-binbin Good catch.~~
~~It should be wrong to use raxRemove in iterator.~~
~~https://github.com/redis/redis/blob/599e59ebc57283f52c60a8de56ec5f44d053109a/src/t_stream.c#L3418~~
Already re-raxSeek behide it.
Comment From: oranagra
@iplaylf2 thanks for reporting. We'll include a fix in the next release. Meanwhile, if you're suffering from this bug, a much bigger COUNT value for XAUTOCLAIM could hide it. Or just switch to XCLAIM.