redict/tests/unit/moduleapi/propagate.tcl
ranshid 383d902ce6
reprocess command when client is unblocked on keys (#11012)
*TL;DR*
---------------------------------------
Following the discussion over the issue [#7551](https://github.com/redis/redis/issues/7551)
We decided to refactor the client blocking code to eliminate some of the code duplications
and to rebuild the infrastructure better for future key blocking cases.


*In this PR*
---------------------------------------
1. reprocess the command once a client becomes unblocked on key (instead of running
   custom code for the unblocked path that's different than the one that would have run if
   blocking wasn't needed)
2. eliminate some (now) irrelevant code for handling unblocking lists/zsets/streams etc...
3. modify some tests to intercept the error in cases of error on reprocess after unblock (see
   details in the notes section below)
4. replace '$' on the client argv with current stream id. Since once we reprocess the stream
   XREAD we need to read from the last msg and not wait for new msg  in order to prevent
   endless block loop. 
5. Added statistics to the info "Clients" section to report the:
   * `total_blocking_keys` - number of blocking keys
   * `total_blocking_keys_on_nokey` - number of blocking keys which have at least 1 client
      which would like
   to be unblocked on when the key is deleted.
6. Avoid expiring unblocked key during unblock. Previously we used to lookup the unblocked key
   which might have been expired during the lookup. Now we lookup the key using NOTOUCH and
   NOEXPIRE to avoid deleting it at this point, so propagating commands in blocked.c is no longer needed.
7. deprecated command flags. We decided to remove the CMD_CALL_STATS and CMD_CALL_SLOWLOG
   and make an explicit verification in the call() function in order to decide if stats update should take place.
   This should simplify the logic and also mitigate existing issues: for example module calls which are
   triggered as part of AOF loading might still report stats even though they are called during AOF loading.

*Behavior changes*
---------------------------------------------------

1. As this implementation prevents writing dedicated code handling unblocked streams/lists/zsets,
since we now re-process the command once the client is unblocked some errors will be reported differently.
The old implementation used to issue
``UNBLOCKED the stream key no longer exists``
in the following cases:
   - The stream key has been deleted (ie. calling DEL)
   - The stream and group existed but the key type was changed by overriding it (ie. with set command)
   - The key not longer exists after we swapdb with a db which does not contains this key
   - After swapdb when the new db has this key but with different type.
   
In the new implementation the reported errors will be the same as if the command was processed after effect:
**NOGROUP** - in case key no longer exists, or **WRONGTYPE** in case the key was overridden with a different type.

2. Reprocessing the command means that some checks will be reevaluated once the
client is unblocked.
For example, ACL rules might change since the command originally was executed and
will fail once the client is unblocked.
Another example is OOM condition checks which might enable the command to run and
block but fail the command reprocess once the client is unblocked.

3. One of the changes in this PR is that no command stats are being updated once the
command is blocked (all stats will be updated once the client is unblocked). This implies
that when we have many clients blocked, users will no longer be able to get that information
from the command stats. However the information can still be gathered from the client list.

**Client blocking**
---------------------------------------------------

the blocking on key will still be triggered the same way as it is done today.
in order to block the current client on list of keys, the call to
blockForKeys will still need to be made which will perform the same as it is today:

*  add the client to the list of blocked clients on each key
*  keep the key with a matching list node (position in the global blocking clients list for that key)
   in the client private blocking key dict.
*  flag the client with CLIENT_BLOCKED
*  update blocking statistics
*  register the client on the timeout table

**Key Unblock**
---------------------------------------------------

Unblocking a specific key will be triggered (same as today) by calling signalKeyAsReady.
the implementation in that part will stay the same as today - adding the key to the global readyList.
The reason to maintain the readyList (as apposed to iterating over all clients blocked on the specific key)
is in order to keep the signal operation as short as possible, since it is called during the command processing.
The main change is that instead of going through a dedicated code path that operates the blocked command
we will just call processPendingCommandsAndResetClient.

**ClientUnblock (keys)**
---------------------------------------------------

1. Unblocking clients on keys will be triggered after command is
   processed and during the beforeSleep
8. the general schema is:
9. For each key *k* in the readyList:
```            
For each client *c* which is blocked on *k*:
            in case either:
	          1. *k* exists AND the *k* type matches the current client blocking type
	  	      OR
	          2. *k* exists and *c* is blocked on module command
	    	      OR
	          3. *k* does not exists and *c* was blocked with the flag
	             unblock_on_deleted_key
                 do:
                                  1. remove the client from the list of clients blocked on this key
                                  2. remove the blocking list node from the client blocking key dict
                                  3. remove the client from the timeout list
                                  10. queue the client on the unblocked_clients list
                                  11. *NEW*: call processCommandAndResetClient(c);
```
*NOTE:* for module blocked clients we will still call the moduleUnblockClientByHandle
              which will queue the client for processing in moduleUnblockedClients list.

**Process Unblocked clients**
---------------------------------------------------

The process of all unblocked clients is done in the beforeSleep and no change is planned
in that part.

The general schema will be:
For each client *c* in server.unblocked_clients:

        * remove client from the server.unblocked_clients
        * set back the client readHandler
        * continue processing the pending command and input buffer.

*Some notes regarding the new implementation*
---------------------------------------------------

1. Although it was proposed, it is currently difficult to remove the
   read handler from the client while it is blocked.
   The reason is that a blocked client should be unblocked when it is
   disconnected, or we might consume data into void.

2. While this PR mainly keep the current blocking logic as-is, there
   might be some future additions to the infrastructure that we would
   like to have:
   - allow non-preemptive blocking of client - sometimes we can think
     that a new kind of blocking can be expected to not be preempt. for
     example lets imagine we hold some keys on disk and when a command
     needs to process them it will block until the keys are uploaded.
     in this case we will want the client to not disconnect or be
     unblocked until the process is completed (remove the client read
     handler, prevent client timeout, disable unblock via debug command etc...).
   - allow generic blocking based on command declared keys - we might
     want to add a hook before command processing to check if any of the
     declared keys require the command to block. this way it would be
     easier to add new kinds of key-based blocking mechanisms.

Co-authored-by: Oran Agra <oran@redislabs.com>
Signed-off-by: Ran Shidlansik <ranshid@amazon.com>
2023-01-01 23:35:42 +02:00

764 lines
29 KiB
Tcl

set testmodule [file normalize tests/modules/propagate.so]
set miscmodule [file normalize tests/modules/misc.so]
set keyspace_events [file normalize tests/modules/keyspace_events.so]
tags "modules" {
test {Modules can propagate in async and threaded contexts} {
start_server [list overrides [list loadmodule "$testmodule"]] {
set replica [srv 0 client]
set replica_host [srv 0 host]
set replica_port [srv 0 port]
$replica module load $keyspace_events
start_server [list overrides [list loadmodule "$testmodule"]] {
set master [srv 0 client]
set master_host [srv 0 host]
set master_port [srv 0 port]
$master module load $keyspace_events
# Start the replication process...
$replica replicaof $master_host $master_port
wait_for_sync $replica
after 1000
test {module propagates from timer} {
set repl [attach_to_replication_stream]
$master propagate-test.timer
wait_for_condition 500 10 {
[$replica get timer] eq "3"
} else {
fail "The two counters don't match the expected value."
}
assert_replication_stream $repl {
{select *}
{incr timer}
{incr timer}
{incr timer}
}
close_replication_stream $repl
}
test {module propagation with notifications} {
set repl [attach_to_replication_stream]
$master set x y
assert_replication_stream $repl {
{multi}
{select *}
{incr notifications}
{set x y}
{exec}
}
close_replication_stream $repl
}
test {module propagation with notifications with multi} {
set repl [attach_to_replication_stream]
$master multi
$master set x1 y1
$master set x2 y2
$master exec
assert_replication_stream $repl {
{multi}
{select *}
{incr notifications}
{set x1 y1}
{incr notifications}
{set x2 y2}
{exec}
}
close_replication_stream $repl
}
test {module propagation with notifications with active-expire} {
$master debug set-active-expire 1
set repl [attach_to_replication_stream]
$master set asdf1 1 PX 300
$master set asdf2 2 PX 300
$master set asdf3 3 PX 300
wait_for_condition 500 10 {
[$replica keys asdf*] eq {}
} else {
fail "Not all keys have expired"
}
# Note whenever there's double notification: SET with PX issues two separate
# notifications: one for "set" and one for "expire"
assert_replication_stream $repl {
{multi}
{select *}
{incr notifications}
{incr notifications}
{set asdf1 1 PXAT *}
{exec}
{multi}
{incr notifications}
{incr notifications}
{set asdf2 2 PXAT *}
{exec}
{multi}
{incr notifications}
{incr notifications}
{set asdf3 3 PXAT *}
{exec}
{multi}
{incr notifications}
{incr notifications}
{incr testkeyspace:expired}
{del asdf*}
{exec}
{multi}
{incr notifications}
{incr notifications}
{incr testkeyspace:expired}
{del asdf*}
{exec}
{multi}
{incr notifications}
{incr notifications}
{incr testkeyspace:expired}
{del asdf*}
{exec}
}
close_replication_stream $repl
$master debug set-active-expire 0
}
test {module propagation with notifications with eviction case 1} {
$master flushall
$master set asdf1 1
$master set asdf2 2
$master set asdf3 3
$master config set maxmemory-policy allkeys-random
$master config set maxmemory 1
# Please note the following loop:
# We evict a key and send a notification, which does INCR on the "notifications" key, so
# that every time we evict any key, "notifications" key exist (it happens inside the
# performEvictions loop). So even evicting "notifications" causes INCR on "notifications".
# If maxmemory_eviction_tenacity would have been set to 100 this would be an endless loop, but
# since the default is 10, at some point the performEvictions loop would end.
# Bottom line: "notifications" always exists and we can't really determine the order of evictions
# This test is here only for sanity
# The replica will get the notification with multi exec and we have a generic notification handler
# that performs `RedisModule_Call(ctx, "INCR", "c", "multi");` if the notification is inside multi exec.
# so we will have 2 keys, "notifications" and "multi".
wait_for_condition 500 10 {
[$replica dbsize] eq 2
} else {
fail "Not all keys have been evicted"
}
$master config set maxmemory 0
$master config set maxmemory-policy noeviction
}
test {module propagation with notifications with eviction case 2} {
$master flushall
set repl [attach_to_replication_stream]
$master set asdf1 1 EX 300
$master set asdf2 2 EX 300
$master set asdf3 3 EX 300
# Please note we use volatile eviction to prevent the loop described in the test above.
# "notifications" is not volatile so it always remains
$master config resetstat
$master config set maxmemory-policy volatile-ttl
$master config set maxmemory 1
wait_for_condition 500 10 {
[s evicted_keys] eq 3
} else {
fail "Not all keys have been evicted"
}
$master config set maxmemory 0
$master config set maxmemory-policy noeviction
$master set asdf4 4
# Note whenever there's double notification: SET with EX issues two separate
# notifications: one for "set" and one for "expire"
# Note that although CONFIG SET maxmemory is called in this flow (see issue #10014),
# eviction will happen and will not induce propagation of the CONFIG command (see #10019).
assert_replication_stream $repl {
{multi}
{select *}
{incr notifications}
{incr notifications}
{set asdf1 1 PXAT *}
{exec}
{multi}
{incr notifications}
{incr notifications}
{set asdf2 2 PXAT *}
{exec}
{multi}
{incr notifications}
{incr notifications}
{set asdf3 3 PXAT *}
{exec}
{multi}
{incr notifications}
{del asdf*}
{exec}
{multi}
{incr notifications}
{del asdf*}
{exec}
{multi}
{incr notifications}
{del asdf*}
{exec}
{multi}
{incr notifications}
{set asdf4 4}
{exec}
}
close_replication_stream $repl
}
test {module propagation with timer and CONFIG SET maxmemory} {
set repl [attach_to_replication_stream]
$master config resetstat
$master config set maxmemory-policy volatile-random
$master propagate-test.timer-maxmemory
# Wait until the volatile keys are evicted
wait_for_condition 500 10 {
[s evicted_keys] eq 2
} else {
fail "Not all keys have been evicted"
}
assert_replication_stream $repl {
{multi}
{select *}
{incr notifications}
{incr notifications}
{set timer-maxmemory-volatile-start 1 PXAT *}
{incr timer-maxmemory-middle}
{incr notifications}
{incr notifications}
{set timer-maxmemory-volatile-end 1 PXAT *}
{exec}
{multi}
{incr notifications}
{del timer-maxmemory-volatile-*}
{exec}
{multi}
{incr notifications}
{del timer-maxmemory-volatile-*}
{exec}
}
close_replication_stream $repl
$master config set maxmemory 0
$master config set maxmemory-policy noeviction
}
test {module propagation with timer and EVAL} {
set repl [attach_to_replication_stream]
$master propagate-test.timer-eval
assert_replication_stream $repl {
{multi}
{select *}
{incr notifications}
{incrby timer-eval-start 1}
{incr notifications}
{set foo bar}
{incr timer-eval-middle}
{incr notifications}
{incrby timer-eval-end 1}
{exec}
}
close_replication_stream $repl
}
test {module propagates nested ctx case1} {
set repl [attach_to_replication_stream]
$master propagate-test.timer-nested
wait_for_condition 500 10 {
[$replica get timer-nested-end] eq "1"
} else {
fail "The two counters don't match the expected value."
}
assert_replication_stream $repl {
{multi}
{select *}
{incrby timer-nested-start 1}
{incrby timer-nested-end 1}
{exec}
}
close_replication_stream $repl
# Note propagate-test.timer-nested just propagates INCRBY, causing an
# inconsistency, so we flush
$master flushall
}
test {module propagates nested ctx case2} {
set repl [attach_to_replication_stream]
$master propagate-test.timer-nested-repl
wait_for_condition 500 10 {
[$replica get timer-nested-end] eq "1"
} else {
fail "The two counters don't match the expected value."
}
assert_replication_stream $repl {
{multi}
{select *}
{incrby timer-nested-start 1}
{incr notifications}
{incr using-call}
{incr counter-1}
{incr counter-2}
{incr counter-3}
{incr counter-4}
{incr notifications}
{incr after-call}
{incr notifications}
{incr before-call-2}
{incr notifications}
{incr asdf}
{incr notifications}
{del asdf}
{incr notifications}
{incr after-call-2}
{incr notifications}
{incr timer-nested-middle}
{incrby timer-nested-end 1}
{exec}
}
close_replication_stream $repl
# Note propagate-test.timer-nested-repl just propagates INCRBY, causing an
# inconsistency, so we flush
$master flushall
}
test {module propagates from thread} {
set repl [attach_to_replication_stream]
$master propagate-test.thread
wait_for_condition 500 10 {
[$replica get a-from-thread] eq "3"
} else {
fail "The two counters don't match the expected value."
}
assert_replication_stream $repl {
{multi}
{select *}
{incr a-from-thread}
{incr notifications}
{incr thread-call}
{incr b-from-thread}
{exec}
{multi}
{incr a-from-thread}
{incr notifications}
{incr thread-call}
{incr b-from-thread}
{exec}
{multi}
{incr a-from-thread}
{incr notifications}
{incr thread-call}
{incr b-from-thread}
{exec}
}
close_replication_stream $repl
}
test {module propagates from thread with detached ctx} {
set repl [attach_to_replication_stream]
$master propagate-test.detached-thread
wait_for_condition 500 10 {
[$replica get thread-detached-after] eq "1"
} else {
fail "The key doesn't match the expected value."
}
assert_replication_stream $repl {
{multi}
{select *}
{incr thread-detached-before}
{incr notifications}
{incr thread-detached-1}
{incr notifications}
{incr thread-detached-2}
{incr thread-detached-after}
{exec}
}
close_replication_stream $repl
}
test {module propagates from command} {
set repl [attach_to_replication_stream]
$master propagate-test.simple
$master propagate-test.mixed
assert_replication_stream $repl {
{multi}
{select *}
{incr counter-1}
{incr counter-2}
{exec}
{multi}
{incr notifications}
{incr using-call}
{incr counter-1}
{incr counter-2}
{incr notifications}
{incr after-call}
{exec}
}
close_replication_stream $repl
}
test {module propagates from EVAL} {
set repl [attach_to_replication_stream]
assert_equal [ $master eval { \
redis.call("propagate-test.simple"); \
redis.call("set", "x", "y"); \
redis.call("propagate-test.mixed"); return "OK" } 0 ] {OK}
assert_replication_stream $repl {
{multi}
{select *}
{incr counter-1}
{incr counter-2}
{incr notifications}
{set x y}
{incr notifications}
{incr using-call}
{incr counter-1}
{incr counter-2}
{incr notifications}
{incr after-call}
{exec}
}
close_replication_stream $repl
}
test {module propagates from command after good EVAL} {
set repl [attach_to_replication_stream]
assert_equal [ $master eval { return "hello" } 0 ] {hello}
$master propagate-test.simple
$master propagate-test.mixed
assert_replication_stream $repl {
{multi}
{select *}
{incr counter-1}
{incr counter-2}
{exec}
{multi}
{incr notifications}
{incr using-call}
{incr counter-1}
{incr counter-2}
{incr notifications}
{incr after-call}
{exec}
}
close_replication_stream $repl
}
test {module propagates from command after bad EVAL} {
set repl [attach_to_replication_stream]
catch { $master eval { return "hello" } -12 } e
assert_equal $e {ERR Number of keys can't be negative}
$master propagate-test.simple
$master propagate-test.mixed
assert_replication_stream $repl {
{multi}
{select *}
{incr counter-1}
{incr counter-2}
{exec}
{multi}
{incr notifications}
{incr using-call}
{incr counter-1}
{incr counter-2}
{incr notifications}
{incr after-call}
{exec}
}
close_replication_stream $repl
}
test {module propagates from multi-exec} {
set repl [attach_to_replication_stream]
$master multi
$master propagate-test.simple
$master propagate-test.mixed
$master propagate-test.timer-nested-repl
$master exec
wait_for_condition 500 10 {
[$replica get timer-nested-end] eq "1"
} else {
fail "The two counters don't match the expected value."
}
assert_replication_stream $repl {
{multi}
{select *}
{incr counter-1}
{incr counter-2}
{incr notifications}
{incr using-call}
{incr counter-1}
{incr counter-2}
{incr notifications}
{incr after-call}
{exec}
{multi}
{incrby timer-nested-start 1}
{incr notifications}
{incr using-call}
{incr counter-1}
{incr counter-2}
{incr counter-3}
{incr counter-4}
{incr notifications}
{incr after-call}
{incr notifications}
{incr before-call-2}
{incr notifications}
{incr asdf}
{incr notifications}
{del asdf}
{incr notifications}
{incr after-call-2}
{incr notifications}
{incr timer-nested-middle}
{incrby timer-nested-end 1}
{exec}
}
close_replication_stream $repl
# Note propagate-test.timer-nested just propagates INCRBY, causing an
# inconsistency, so we flush
$master flushall
}
test {module RM_Call of expired key propagation} {
$master debug set-active-expire 0
$master set k1 900 px 100
after 110
set repl [attach_to_replication_stream]
$master propagate-test.incr k1
assert_replication_stream $repl {
{multi}
{select *}
{del k1}
{propagate-test.incr k1}
{exec}
}
close_replication_stream $repl
assert_equal [$master get k1] 1
assert_equal [$master ttl k1] -1
assert_equal [$replica get k1] 1
assert_equal [$replica ttl k1] -1
}
test {module notification on set} {
set repl [attach_to_replication_stream]
$master SADD s foo
wait_for_condition 500 10 {
[$replica SCARD s] eq "1"
} else {
fail "Failed to wait for set to be replicated"
}
$master SPOP s 1
wait_for_condition 500 10 {
[$replica SCARD s] eq "0"
} else {
fail "Failed to wait for set to be replicated"
}
# Currently the `del` command comes after the notification.
# When we fix spop to fire notification at the end (like all other commands),
# the `del` will come first.
assert_replication_stream $repl {
{multi}
{select *}
{incr notifications}
{sadd s foo}
{exec}
{multi}
{incr notifications}
{incr notifications}
{del s}
{exec}
}
close_replication_stream $repl
}
test {module key miss notification do not cause read command to be replicated} {
set repl [attach_to_replication_stream]
$master flushall
$master get unexisting_key
wait_for_condition 500 10 {
[$replica get missed] eq "1"
} else {
fail "Failed to wait for set to be replicated"
}
# Test is checking a wrong!!! behavior that causes a read command to be replicated to replica/aof.
# We keep the test to verify that such a wrong behavior does not cause any crashes.
assert_replication_stream $repl {
{select *}
{flushall}
{multi}
{incr notifications}
{incr missed}
{get unexisting_key}
{exec}
}
close_replication_stream $repl
}
test "Unload the module - propagate-test/testkeyspace" {
assert_equal {OK} [r module unload propagate-test]
assert_equal {OK} [r module unload testkeyspace]
}
assert_equal [s -1 unexpected_error_replies] 0
}
}
}
}
tags "modules aof" {
foreach aofload_type {debug_cmd startup} {
test "Modules RM_Replicate replicates MULTI/EXEC correctly: AOF-load type $aofload_type" {
start_server [list overrides [list loadmodule "$testmodule"]] {
# Enable the AOF
r config set appendonly yes
r config set auto-aof-rewrite-percentage 0 ; # Disable auto-rewrite.
waitForBgrewriteaof r
r propagate-test.simple
r propagate-test.mixed
r multi
r propagate-test.simple
r propagate-test.mixed
r exec
assert_equal [r get counter-1] {}
assert_equal [r get counter-2] {}
assert_equal [r get using-call] 2
assert_equal [r get after-call] 2
assert_equal [r get notifications] 4
# Load the AOF
if {$aofload_type == "debug_cmd"} {
r debug loadaof
} else {
r config rewrite
restart_server 0 true false
wait_done_loading r
}
# This module behaves bad on purpose, it only calls
# RM_Replicate for counter-1 and counter-2 so values
# after AOF-load are different
assert_equal [r get counter-1] 4
assert_equal [r get counter-2] 4
assert_equal [r get using-call] 2
assert_equal [r get after-call] 2
# 4+4+2+2 commands from AOF (just above) + 4 "INCR notifications" from AOF + 4 notifications for these INCRs
assert_equal [r get notifications] 20
assert_equal {OK} [r module unload propagate-test]
assert_equal [s 0 unexpected_error_replies] 0
}
}
test "Modules RM_Call does not update stats during aof load: AOF-load type $aofload_type" {
start_server [list overrides [list loadmodule "$miscmodule"]] {
# Enable the AOF
r config set appendonly yes
r config set auto-aof-rewrite-percentage 0 ; # Disable auto-rewrite.
waitForBgrewriteaof r
r config resetstat
r set foo bar
r EVAL {return redis.call('SET', KEYS[1], ARGV[1])} 1 foo bar2
r test.rm_call_replicate set foo bar3
r EVAL {return redis.call('test.rm_call_replicate',ARGV[1],KEYS[1],ARGV[2])} 1 foo set bar4
r multi
r set foo bar5
r EVAL {return redis.call('SET', KEYS[1], ARGV[1])} 1 foo bar6
r test.rm_call_replicate set foo bar7
r EVAL {return redis.call('test.rm_call_replicate',ARGV[1],KEYS[1],ARGV[2])} 1 foo set bar8
r exec
assert_match {*calls=8,*,rejected_calls=0,failed_calls=0} [cmdrstat set r]
# Load the AOF
if {$aofload_type == "debug_cmd"} {
r config resetstat
r debug loadaof
} else {
r config rewrite
restart_server 0 true false
wait_done_loading r
}
assert_no_match {*calls=*} [cmdrstat set r]
}
}
}
}