redict/tests/unit/introspection-2.tcl
Meir Shpilraien (Spielrein) aa856b39f2
Sort out the mess around Lua error messages and error stats (#10329)
This PR fix 2 issues on Lua scripting:
* Server error reply statistics (some errors were counted twice).
* Error code and error strings returning from scripts (error code was missing / misplaced).

## Statistics
a Lua script user is considered part of the user application, a sophisticated transaction,
so we want to count an error even if handled silently by the script, but when it is
propagated outwards from the script we don't wanna count it twice. on the other hand,
if the script decides to throw an error on its own (using `redis.error_reply`), we wanna
count that too.
Besides, we do count the `calls` in command statistics for the commands the script calls,
we we should certainly also count `failed_calls`.
So when a simple `eval "return redis.call('set','x','y')" 0` fails, it should count the failed call
to both SET and EVAL, but the `errorstats` and `total_error_replies` should be counted only once.

The PR changes the error object that is raised on errors. Instead of raising a simple Lua
string, Redis will raise a Lua table in the following format:

```
{
    err='<error message (including error code)>',
    source='<User source file name>',
    line='<line where the error happned>',
    ignore_error_stats_update=true/false,
}
```

The `luaPushError` function was modified to construct the new error table as describe above.
The `luaRaiseError` was renamed to `luaError` and is now simply called `lua_error` to raise
the table on the top of the Lua stack as the error object.
The reason is that since its functionality is changed, in case some Redis branch / fork uses it,
it's better to have a compilation error than a bug.

The `source` and `line` fields are enriched by the error handler (if possible) and the
`ignore_error_stats_update` is optional and if its not present then the default value is `false`.
If `ignore_error_stats_update` is true, the error will not be counted on the error stats.

When parsing Redis call reply, each error is translated to a Lua table on the format describe
above and the `ignore_error_stats_update` field is set to `true` so we will not count errors
twice (we counted this error when we invoke the command).

The changes in this PR might have been considered as a breaking change for users that used
Lua `pcall` function. Before, the error was a string and now its a table. To keep backward
comparability the PR override the `pcall` implementation and extract the error message from
the error table and return it.

Example of the error stats update:

```
127.0.0.1:6379> lpush l 1
(integer) 2
127.0.0.1:6379> eval "return redis.call('get', 'l')" 0
(error) WRONGTYPE Operation against a key holding the wrong kind of value. script: e471b73f1ef44774987ab00bdf51f21fd9f7974a, on @user_script:1.

127.0.0.1:6379> info Errorstats
# Errorstats
errorstat_WRONGTYPE:count=1

127.0.0.1:6379> info commandstats
# Commandstats
cmdstat_eval:calls=1,usec=341,usec_per_call=341.00,rejected_calls=0,failed_calls=1
cmdstat_info:calls=1,usec=35,usec_per_call=35.00,rejected_calls=0,failed_calls=0
cmdstat_lpush:calls=1,usec=14,usec_per_call=14.00,rejected_calls=0,failed_calls=0
cmdstat_get:calls=1,usec=10,usec_per_call=10.00,rejected_calls=0,failed_calls=1
```

## error message
We can now construct the error message (sent as a reply to the user) from the error table,
so this solves issues where the error message was malformed and the error code appeared
in the middle of the error message:

```diff
127.0.0.1:6379> eval "return redis.call('set','x','y')" 0
-(error) ERR Error running script (call to 71e6319f97b0fe8bdfa1c5df3ce4489946dda479): @user_script:1: OOM command not allowed when used memory > 'maxmemory'.
+(error) OOM command not allowed when used memory > 'maxmemory' @user_script:1. Error running script (call to 71e6319f97b0fe8bdfa1c5df3ce4489946dda479)
```

```diff
127.0.0.1:6379> eval "redis.call('get', 'l')" 0
-(error) ERR Error running script (call to f_8a705cfb9fb09515bfe57ca2bd84a5caee2cbbd1): @user_script:1: WRONGTYPE Operation against a key holding the wrong kind of value
+(error) WRONGTYPE Operation against a key holding the wrong kind of value script: 8a705cfb9fb09515bfe57ca2bd84a5caee2cbbd1, on @user_script:1.
```

Notica that `redis.pcall` was not change:
```
127.0.0.1:6379> eval "return redis.pcall('get', 'l')" 0
(error) WRONGTYPE Operation against a key holding the wrong kind of value
```


## other notes
Notice that Some commands (like GEOADD) changes the cmd variable on the client stats so we
can not count on it to update the command stats. In order to be able to update those stats correctly
we needed to promote `realcmd` variable to be located on the client struct.

Tests was added and modified to verify the changes.

Related PR's: #10279, #10218, #10278, #10309

Co-authored-by: Oran Agra <oran@redislabs.com>
2022-02-27 13:40:57 +02:00

180 lines
6.3 KiB
Tcl

proc cmdstat {cmd} {
return [cmdrstat $cmd r]
}
start_server {tags {"introspection"}} {
test {TTL, TYPE and EXISTS do not alter the last access time of a key} {
r set foo bar
after 3000
r ttl foo
r type foo
r exists foo
assert {[r object idletime foo] >= 2}
}
test {TOUCH alters the last access time of a key} {
r set foo bar
after 3000
r touch foo
assert {[r object idletime foo] < 2}
}
test {TOUCH returns the number of existing keys specified} {
r flushdb
r set key1{t} 1
r set key2{t} 2
r touch key0{t} key1{t} key2{t} key3{t}
} 2
test {command stats for GEOADD} {
r config resetstat
r GEOADD foo 0 0 bar
assert_match {*calls=1,*} [cmdstat geoadd]
assert_match {} [cmdstat zadd]
} {} {needs:config-resetstat}
test {errors stats for GEOADD} {
r config resetstat
# make sure geo command will failed
r set foo 1
assert_error {WRONGTYPE Operation against a key holding the wrong kind of value*} {r GEOADD foo 0 0 bar}
assert_match {*calls=1*,rejected_calls=0,failed_calls=1*} [cmdstat geoadd]
assert_match {} [cmdstat zadd]
} {} {needs:config-resetstat}
test {command stats for EXPIRE} {
r config resetstat
r SET foo bar
r EXPIRE foo 0
assert_match {*calls=1,*} [cmdstat expire]
assert_match {} [cmdstat del]
} {} {needs:config-resetstat}
test {command stats for BRPOP} {
r config resetstat
r LPUSH list foo
r BRPOP list 0
assert_match {*calls=1,*} [cmdstat brpop]
assert_match {} [cmdstat rpop]
} {} {needs:config-resetstat}
test {command stats for MULTI} {
r config resetstat
r MULTI
r set foo{t} bar
r GEOADD foo2{t} 0 0 bar
r EXPIRE foo2{t} 0
r EXEC
assert_match {*calls=1,*} [cmdstat multi]
assert_match {*calls=1,*} [cmdstat exec]
assert_match {*calls=1,*} [cmdstat set]
assert_match {*calls=1,*} [cmdstat expire]
assert_match {*calls=1,*} [cmdstat geoadd]
} {} {needs:config-resetstat}
test {command stats for scripts} {
r config resetstat
r set mykey myval
r eval {
redis.call('set', KEYS[1], 0)
redis.call('expire', KEYS[1], 0)
redis.call('geoadd', KEYS[1], 0, 0, "bar")
} 1 mykey
assert_match {*calls=1,*} [cmdstat eval]
assert_match {*calls=2,*} [cmdstat set]
assert_match {*calls=1,*} [cmdstat expire]
assert_match {*calls=1,*} [cmdstat geoadd]
} {} {needs:config-resetstat}
test {COMMAND GETKEYS GET} {
assert_equal {key} [r command getkeys get key]
}
test {COMMAND GETKEYSANDFLAGS} {
assert_equal {{k1 {OW update}}} [r command getkeysandflags set k1 v1]
assert_equal {{k1 {OW update}} {k2 {OW update}}} [r command getkeysandflags mset k1 v1 k2 v2]
assert_equal {{k1 {RW access delete}} {k2 {RW insert}}} [r command getkeysandflags LMOVE k1 k2 left right]
assert_equal {{k1 {RO access}} {k2 {OW update}}} [r command getkeysandflags sort k1 store k2]
}
test {COMMAND GETKEYS MEMORY USAGE} {
assert_equal {key} [r command getkeys memory usage key]
}
test {COMMAND GETKEYS XGROUP} {
assert_equal {key} [r command getkeys xgroup create key groupname $]
}
test {COMMAND GETKEYS EVAL with keys} {
assert_equal {key} [r command getkeys eval "return 1" 1 key]
}
test {COMMAND GETKEYS EVAL without keys} {
assert_equal {} [r command getkeys eval "return 1" 0]
}
test {COMMAND GETKEYS LCS} {
assert_equal {key1 key2} [r command getkeys lcs key1 key2]
}
test "COMMAND LIST syntax error" {
assert_error "ERR syntax error*" {r command list bad_arg}
assert_error "ERR syntax error*" {r command list filterby bad_arg}
assert_error "ERR syntax error*" {r command list filterby bad_arg bad_arg2}
}
test "COMMAND LIST WITHOUT FILTERBY" {
set commands [r command list]
assert_not_equal [lsearch $commands "set"] -1
assert_not_equal [lsearch $commands "client|list"] -1
}
test "COMMAND LIST FILTERBY ACLCAT against non existing category" {
assert_equal {} [r command list filterby aclcat non_existing_category]
}
test "COMMAND LIST FILTERBY ACLCAT - list all commands/subcommands" {
set commands [r command list filterby aclcat scripting]
assert_not_equal [lsearch $commands "eval"] -1
assert_not_equal [lsearch $commands "script|kill"] -1
# Negative check, a command that should not be here
assert_equal [lsearch $commands "set"] -1
}
test "COMMAND LIST FILTERBY PATTERN - list all commands/subcommands" {
# Exact command match.
assert_equal {set} [r command list filterby pattern set]
assert_equal {get} [r command list filterby pattern get]
# Return the parent command and all the subcommands below it.
set commands [r command list filterby pattern config*]
assert_not_equal [lsearch $commands "config"] -1
assert_not_equal [lsearch $commands "config|get"] -1
# We can filter subcommands under a parent command.
set commands [r command list filterby pattern config|*re*]
assert_not_equal [lsearch $commands "config|resetstat"] -1
assert_not_equal [lsearch $commands "config|rewrite"] -1
# We can filter subcommands across parent commands.
set commands [r command list filterby pattern cl*help]
assert_not_equal [lsearch $commands "client|help"] -1
assert_not_equal [lsearch $commands "cluster|help"] -1
# Negative check, command that doesn't exist.
assert_equal {} [r command list filterby pattern non_exists]
assert_equal {} [r command list filterby pattern non_exists*]
}
test "COMMAND LIST FILTERBY MODULE against non existing module" {
# This should be empty, the real one is in subcommands.tcl
assert_equal {} [r command list filterby module non_existing_module]
}
test {COMMAND INFO of invalid subcommands} {
assert_equal {{}} [r command info get|key]
assert_equal {{}} [r command info config|get|key]
}
}