Redis server failed with zero limit
Closed this issue · 1 comments
molfar commented
When I try to simulate many parallel calls with zero limit param:
1000.times { redis.call 'CL.THROTTLE', 'test', 0, 0, 60, 1 }
Redis server has failed and stopped with following report
=== REDIS BUG REPORT START: Cut & paste starting from here ===
1:M 05 Apr 2020 18:38:24.582 # Redis 5.0.8 crashed by signal: 11
1:M 05 Apr 2020 18:38:24.582 # Crashed running the instruction at: 0x7fa355b70611
1:M 05 Apr 2020 18:38:24.582 # Accessing address: (nil)
1:M 05 Apr 2020 18:38:24.582 # Failed assertion: <no assertion failed> (<no file>:0)
redis_1 |
------ STACK TRACE ------
thread '<unnamed>' panicked at 'assertion failed: nsec >= 0 && nsec < NSEC_PER_SEC', /cargo/registry/src/github.com-1ecc6299db9ec823/time-0.1.42/src/lib.rs:86:9
note: Run with `RUST_BACKTRACE=1` environment variable to display a backtrace.
fatal runtime error: failed to initiate panic, error 5
EIP:
/lib/x86_64-linux-gnu/libc.so.6(abort+0x1fd)[0x7fa355b70611]
redis_1 |
Backtrace:
redis-server *:6379(logStackTrace+0x32)[0x55741d7dc592]
redis-server *:6379(sigsegvHandler+0x9e)[0x55741d7dcc6e]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12730)[0x7fa355d21730]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x1fd)[0x7fa355b70611]
/usr/local/etc/redis/libredis_cell.so(+0x97757)[0x7fa354f85757]
/usr/local/etc/redis/libredis_cell.so(+0x85031)[0x7fa354f73031]
/usr/local/etc/redis/libredis_cell.so(rust_panic+0x7a)[0x7fa354f74fba]
/usr/local/etc/redis/libredis_cell.so(_ZN3std9panicking20rust_panic_with_hook17h744417edfe714d72E+0x2d2)[0x7fa354f74e72]
/usr/local/etc/redis/libredis_cell.so(+0x5d975)[0x7fa354f4b975]
/usr/local/etc/redis/libredis_cell.so(_ZN50_$LT$time..Tm$u20$as$u20$core..cmp..PartialOrd$GT$11partial_cmp17h44a03615e3a2ca19E+0x197)[0x7fa354f49ff7]
/usr/local/etc/redis/libredis_cell.so(+0x55301)[0x7fa354f43301]
/usr/local/etc/redis/libredis_cell.so(_ZN74_$LT$redis_cell..ThrottleCommand$u20$as$u20$redis_cell..redis..Command$GT$3run17h1e54095770ea729bE+0x258)[0x7fa354f44d98]
/usr/local/etc/redis/libredis_cell.so(+0x4fb55)[0x7fa354f3db55]
redis-server *:6379(RedisModuleCommandDispatcher+0x54)[0x55741d808d84]
redis-server *:6379(call+0x9b)[0x55741d79835b]
redis-server *:6379(processCommand+0x51e)[0x55741d798c1e]
redis-server *:6379(processInputBuffer+0x171)[0x55741d7a8e21]
redis-server *:6379(aeProcessEvents+0x101)[0x55741d792311]
redis-server *:6379(aeMain+0x2b)[0x55741d79271b]
redis-server *:6379(main+0x4ca)[0x55741d78f57a]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb)[0x7fa355b7209b]
redis-server *:6379(_start+0x2a)[0x55741d78f7da]
redis_1 |
------ INFO OUTPUT ------
# Server
redis_version:5.0.8
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:f5de7c59791f2d0a
redis_mode:standalone
os:Linux 4.19.76-linuxkit x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:8.3.0
process_id:1
run_id:ecbdfa470a829ff934bea5e4fec66b7cd1ca9ef6
tcp_port:6379
uptime_in_seconds:94
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:9053600
executable:/data/redis-server
config_file:
redis_1 |
# Clients
connected_clients:1
client_recent_max_input_buffer:2
client_recent_max_output_buffer:0
blocked_clients:0
redis_1 |
# Memory
used_memory:854112
used_memory_human:834.09K
used_memory_rss:4956160
used_memory_rss_human:4.73M
used_memory_peak:854112
used_memory_peak_human:834.09K
used_memory_peak_perc:100.14%
used_memory_overhead:840710
used_memory_startup:790888
used_memory_dataset:13402
used_memory_dataset_perc:21.20%
allocator_allocated:943392
allocator_active:1126400
allocator_resident:3534848
total_system_memory:4129947648
total_system_memory_human:3.85G
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.19
allocator_frag_bytes:183008
allocator_rss_ratio:3.14
allocator_rss_bytes:2408448
rss_overhead_ratio:1.40
rss_overhead_bytes:1421312
mem_fragmentation_ratio:6.10
mem_fragmentation_bytes:4144272
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:49694
mem_aof_buffer:0
mem_allocator:jemalloc-5.1.0
active_defrag_running:0
lazyfree_pending_objects:0
redis_1 |
# Persistence
loading:0
rdb_changes_since_last_save:0
rdb_bgsave_in_progress:0
rdb_last_save_time:1586111810
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:-1
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
redis_1 |
# Stats
total_connections_received:1
total_commands_processed:52
instantaneous_ops_per_sec:0
total_net_input_bytes:3051
total_net_output_bytes:1834
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:51
expired_stale_perc:0.26
expired_time_cap_reached_count:0
evicted_keys:0
keyspace_hits:1
keyspace_misses:52
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec: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
redis_1 |
# Replication
role:master
connected_slaves:0
master_replid:94a55afbe34d3d42c9e09cbbd7073f0b8ef88e0a
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
redis_1 |
# CPU
used_cpu_sys:0.042171
used_cpu_user:0.034461
used_cpu_sys_children:0.002327
used_cpu_user_children:0.003539
redis_1 |
# Commandstats
cmdstat_cl.throttle:calls=52,usec=3994,usec_per_call=76.81
redis_1 |
# Cluster
cluster_enabled:0
redis_1 |
# Keyspace
db0:keys=1,expires=1,avg_ttl=0
redis_1 |
------ CLIENT LIST OUTPUT ------
id=3 addr=172.19.0.1:41424 fd=8 name= age=51 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=61 qbuf-free=32707 obl=0 oll=0 omem=0 events=r cmd=cl.throttle
redis_1 |
------ CURRENT CLIENT INFO ------
id=3 addr=172.19.0.1:41424 fd=8 name= age=51 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=61 qbuf-free=32707 obl=0 oll=0 omem=0 events=r cmd=cl.throttle
argv[0]: 'CL.THROTTLE'
argv[1]: 'test'
argv[2]: '0'
argv[3]: '0'
argv[4]: '60'
argv[5]: '1'
1:M 05 Apr 2020 18:38:24.583 # key 'test' found in DB containing the following object:
1:M 05 Apr 2020 18:38:24.583 # Object type: 0
1:M 05 Apr 2020 18:38:24.583 # Object encoding: 0
1:M 05 Apr 2020 18:38:24.583 # Object refcount: 1
1:M 05 Apr 2020 18:38:24.583 # Object raw string len: 20
1:M 05 Apr 2020 18:38:24.583 # Object raw string content: "-7637260132274145208"
redis_1 |
------ REGISTERS ------
1:M 05 Apr 2020 18:38:24.583 #
RAX:0000000000000000 RBX:0000000000000000
RCX:0000000000000000 RDX:0000000000000000
RDI:0000000000000002 RSI:00007ffca62dcac0
RBP:00007fa354fbfd88 RSP:00007ffca62dcbe0
R8 :0000000000000000 R9 :00007ffca62dcac0
R10:0000000000000008 R11:0000000000000246
R12:0000000000000000 R13:0000000000000046
R14:0000000000000009 R15:0000000000000001
RIP:00007fa355b70611 EFL:0000000000010246
CSGSFS:002b000000000033
1:M 05 Apr 2020 18:38:24.583 # (00007ffca62dcbef) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.583 # (00007ffca62dcbee) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbed) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbec) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbeb) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbea) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbe9) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbe8) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbe7) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbe6) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbe5) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbe4) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbe3) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbe2) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbe1) -> 0000000000000000
1:M 05 Apr 2020 18:38:24.584 # (00007ffca62dcbe0) -> 0000000000000020
redis_1 |
------ FAST MEMORY TEST ------
1:M 05 Apr 2020 18:38:24.584 # Bio thread for job type #0 terminated
1:M 05 Apr 2020 18:38:24.584 # Bio thread for job type #1 terminated
1:M 05 Apr 2020 18:38:24.585 # Bio thread for job type #2 terminated
*** Preparing to test memory region 55741d90a000 (2248704 bytes)
*** Preparing to test memory region 55741e036000 (135168 bytes)
*** Preparing to test memory region 7fa3536ec000 (8388608 bytes)
*** Preparing to test memory region 7fa353eed000 (8388608 bytes)
*** Preparing to test memory region 7fa3546ee000 (8388608 bytes)
*** Preparing to test memory region 7fa355200000 (8388608 bytes)
*** Preparing to test memory region 7fa355b48000 (24576 bytes)
*** Preparing to test memory region 7fa355d0b000 (16384 bytes)
*** Preparing to test memory region 7fa355d2c000 (16384 bytes)
*** Preparing to test memory region 7fa355ec2000 (8192 bytes)
*** Preparing to test memory region 7fa355eef000 (4096 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_1 |
------ DUMPING CODE AROUND EIP ------
Symbol: abort (base: 0x7fa355b70414)
Module: /lib/x86_64-linux-gnu/libc.so.6 (base 0x7fa355b4e000)
$ xxd -r -p /tmp/dump.hex /tmp/dump.bin
$ objdump --adjust-vma=0x7fa355b70414 -D -b binary -m i386:x86-64 /tmp/dump.bin
------
1:M 05 Apr 2020 18:38:24.737 # dump of function (hexdump of 637 bytes):
4881ec2801000064488b042528000000488984241801000031c064488b142510000000483915faa819007444be01000000833da4e2190000740cf00fb135daa81900750beb230fb135cfa81900741a488d3dc6a819004881ec80000000e88a420e004881c480000000488915b4a81900ff05aaa81900833dafa81900007536c705a3a8190001000000b81000000048ffc84889e64883f8ff740a48c704c600000000ebea31d2bf0100000048830c2420e8875501008b0571a8190083f8010f85bd000000ff0d56a81900c70558a8190000000000754148c70543a8190000000000833df4e1190000740bf0ff0d2ba81900750aeb22ff0d21a81900741a488d3d18a819004881ec80000000e80c420e004881c480000000bf06000000e87b51010064488b142510000000483915f3a719007446be0100000031c0833d9be1190000740cf00fb135d1a71900750beb230fb135c6a71900741a488d3dbda719004881ec80000000e881410e004881c480000000488915aba71900ff05a1a71900eb0583f8027547488db4248000000031c0b9260000004883caffc70589a71900030000004889f7f3abb810000000488914c648ffc875f731d2bf06000000c784240801000000000000e83f540100833d58a71900037514c7054ca7190004000000bf06000000e8b2500100833d3ba7190004750bc7052fa7190005000000f4833d27a71900057514c7051ba7190006000000bf7f000000e871430a00f4ebfde8ddfdffffe8d8fdffffe8d3fdffffe8cefdffffe8c9fdffffe8c4fdffffe8bffdffffe8bafdffff836374ebf70300800000753f488b9388000000836a0401753248c7420800000000833d6ee01900007407f0ff0a7506eb1aff0a7416488d
Function at 0x7fa355b85a50 is sigprocmask
Function at 0x7fa355b856b0 is gsignal
Function at 0x7fa355b85a20 is sigaction
Function at 0x7fa355c149a0 is _exit
Function at 0x7fa355b70414 is abort
redis_1 |
=== REDIS BUG REPORT END. Make sure to include from START to END. ===
brandur commented
Thanks for the report!
As it turns out, the GCRA algorithm in use by this project to do the underlying rate limiting doesn't support zero rates all that well, so instead of complicating things too much I'm going to disallow them for the time being. 0.2.5 now errors when they're specified.