Unverified Commit 4ba47d2d authored by guybe7's avatar guybe7 Committed by GitHub
Browse files

Add reply_schema to command json files (internal for now) (#10273)

Work in progress towards implementing a reply schema as part of COMMAND DOCS, see #9845
Since ironing the details of the reply schema of each and every command can take a long time, we
would like to merge this PR when the infrastructure is ready, and let this mature in the unstable branch.
Meanwhile the changes of this PR are internal, they are part of the repo, but do not affect the produced build.

### Background
In #9656 we add a lot of information about Redis commands, but we are missing information about the replies

### Motivation
1. Documentation. This is the primary goal.
2. It should be possible, based on the output of COMMAND, to be able to generate client code in typed
  languages. In order to do that, we need Redis to tell us, in detail, what each reply looks like.
3. We would like to build a fuzzer that verifies the reply structure (for now we use the existing
  testsuite, see the "Testing" section)

### Schema
The idea is to supply some sort of schema for the various replies of each command.
The schema will describe the conceptual structure of the reply (for generated clients), as defined in RESP3.
Note that the reply structure itself may change, depending on the arguments (e.g. `XINFO STREAM`, with
and without the `FULL` modifier)
We decided to use the standard json-schema (see https://json-schema.org/) as the reply-schema.

Example for `BZPOPMIN`:
```
"reply_schema": {
    "oneOf": [
        {
            "description": "Timeout reached and no elements were popped.",
            "type": "null"
        },
        {
            "description": "The keyname, popped member, and its score.",
            "type": "array",
            "minItems": 3,
            "maxItems": 3,
            "items": [
                {
                    "description": "Keyname",
                    "type": "string"
                },
                {
                    "description": "Member",
                    "type": "string"
                },
                {
                    "description": "Score",
                    "type": "number"
                }
            ]
        }
    ]
}
```

#### Notes
1.  It is ok that some commands' reply structure depends on the arguments and it's the caller's responsibility
  to know which is the relevant one. this comes after looking at other request-reply systems like OpenAPI,
  where the reply schema can also be oneOf and the caller is responsible to know which schema is the relevant one.
2. The reply schemas will describe RESP3 replies only. even though RESP3 is structured, we want to use reply
  schema for documentation (and possibly to create a fuzzer that validates the replies)
3. For documentation, the description field will include an explanation of the scenario in which the reply is sent,
  including any relation to arguments. for example, for `ZRANGE`'s two schemas we will need to state that one
  is with `WITHSCORES` and the other is without.
4. For documentation, there will be another optional field "notes" in which we will add a short description of
  the representation in RESP2, in case it's not trivial (RESP3's `ZRANGE`'s nested array vs. RESP2's flat
  array, for example)

Given the above:
1. We can generate the "return" section of all commands in [redis-doc](https://redis.io/commands/)
  (given that "description" and "notes" are comprehensive enough)
2. We can generate a client in a strongly typed language (but the return type could be a conceptual
  `union` and the caller needs to know which schema is relevant). see the section below for RESP2 support.
3. We can create a fuzzer for RESP3.

### Limitations (because we are using the standard json-schema)
The problem is that Redis' replies are more diverse than what the json format allows. This means that,
when we convert the reply to a json (in order to validate the schema against it), we lose information (see
the "Testing" section below).
The other option would have been to extend the standard json-schema (and json format) to include stuff
like sets, bulk-strings, error-string, etc. but that would mean also extending the schema-validator - and that
seemed like too much work, so we decided to compromise.

Examples:
1. We cannot tell the difference between an "array" and a "set"
2. We cannot tell the difference between simple-string and bulk-string
3. we cannot verify true uniqueness of items in commands like ZRANGE: json-schema doesn't cover the
  case of two identical members with different scores (e.g. `[["m1",6],["m1",7]]`) because `uniqueItems`
  compares (member,score) tuples and not just the member name. 

### Testing
This commit includes some changes inside Redis in order to verify the schemas (existing and future ones)
are indeed correct (i.e. describe the actual response of Redis).
To do that, we added a debugging feature to Redis that causes it to produce a log of all the commands
it executed and their replies.
For that, Redis needs to be compiled with `-DLOG_REQ_RES` and run with
`--reg-res-logfile <file> --client-default-resp 3` (the testsuite already does that if you run it with
`--log-req-res --force-resp3`)
You should run the testsuite with the above args (and `--dont-clean`) in order to make Redis generate
`.reqres` files (same dir as the `stdout` files) which contain request-response pairs.
These files are later on processed by `./utils/req-res-log-validator.py` which does:
1. Goes over req-res files, generated by redis-servers, spawned by the testsuite (see logreqres.c)
2. For each request-response pair, it validates the response against the request's reply_schema
  (obtained from the extended COMMAND DOCS)
5. In order to get good coverage of the Redis commands, and all their different replies, we chose to use
  the existing redis test suite, rather than attempt to write a fuzzer.

#### Notes about RESP2
1. We will not be able to use the testing tool to verify RESP2 replies (we are ok with that, it's time to
  accept RESP3 as the future RESP)
2. Since the majority of the test suite is using RESP2, and we want the server to reply with RESP3
  so that we can validate it, we will need to know how to convert the actual reply to the one expected.
   - number and boolean are always strings in RESP2 so the conversion is easy
   - objects (maps) are always a flat array in RESP2
   - others (nested array in RESP3's `ZRANGE` and others) will need some special per-command
     handling (so the client will not be totally auto-generated)

Example for ZRANGE:
```
"reply_schema": {
    "anyOf": [
        {
            "description": "A list of member elements",
            "type": "array",
            "uniqueItems": true,
            "items": {
                "type": "string"
            }
        },
        {
            "description": "Members and their scores. Returned in case `WITHSCORES` was used.",
            "notes": "In RESP2 this is returned as a flat array",
            "type": "array",
            "uniqueItems": true,
            "items": {
                "type": "array",
                "minItems": 2,
                "maxItems": 2,
                "items": [
                    {
                        "description": "Member",
                        "type": "string"
                    },
                    {
                        "description": "Score",
                        "type": "number"
                    }
                ]
            }
        }
    ]
}
```

### Other changes
1. Some tests that behave differently depending on the RESP are now being tested for both RESP,
  regardless of the special log-req-res mode ("Pub/Sub PING" for example)
2. Update the history field of CLIENT LIST
3. Added basic tests for commands that were not covered at all by the testsuite

### TODO

- [x] (maybe a different PR) add a "condition" field to anyOf/oneOf schemas that refers to args. e.g.
  when `SET` return NULL, the condition is `arguments.get||arguments.condition`, for `OK` the condition
  is `!arguments.get`, and for `string` the condition is `arguments.get` - https://github.com/redis/redis/issues/11896
- [x] (maybe a different PR) also run `runtest-cluster` in the req-res logging mode
- [x] add the new tests to GH actions (i.e. compile with `-DLOG_REQ_RES`, run the tests, and run the validator)
- [x] (maybe a different PR) figure out a way to warn about (sub)schemas that are uncovered by the output
  of the tests - https://github.com/redis/redis/issues/11897
- [x] (probably a separate PR) add all missing schemas
- [x] check why "SDOWN is triggered by misconfigured instance replying with errors" fails with --log-req-res
- [x] move the response transformers to their own file (run both regular, cluster, and sentinel tests - need to
  fight with the tcl including mechanism a bit)
- [x] issue: module API - https://github.com/redis/redis/issues/11898
- [x] (probably a separate PR): improve schemas: add `required` to `object`s - https://github.com/redis/redis/issues/11899

Co-authored-by: default avatarOzan Tezcan <ozantezcan@gmail.com>
Co-authored-by: default avatarHanna Fadida <hanna.fadida@redislabs.com>
Co-authored-by: default avatarOran Agra <oran@redislabs.com>
Co-authored-by: default avatarShaya Potter <shaya@redislabs.com>
parent c46d68d6
/*
* Copyright (c) 2021, Redis Ltd.
* All rights reserved.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions are met:
*
* * Redistributions of source code must retain the above copyright notice,
* this list of conditions and the following disclaimer.
* * Redistributions in binary form must reproduce the above copyright
* notice, this list of conditions and the following disclaimer in the
* documentation and/or other materials provided with the distribution.
* * Neither the name of Redis nor the names of its contributors may be used
* to endorse or promote products derived from this software without
* specific prior written permission.
*
* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
* AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
* IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
* ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE
* LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
* CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
* SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
* INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
* CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
* ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
* POSSIBILITY OF SUCH DAMAGE.
*/
/* This file implements the interface of logging clients' requests and
* responses into a file.
* This feature needs the LOG_REQ_RES macro to be compiled and is turned
* on by the req-res-logfile config."
*
* Some examples:
*
* PING:
*
* 4
* ping
* 12
* __argv_end__
* +PONG
*
* LRANGE:
*
* 6
* lrange
* 4
* list
* 1
* 0
* 2
* -1
* 12
* __argv_end__
* *1
* $3
* ele
*
* The request is everything up until the __argv_end__ marker.
* The format is:
* <number of characters>
* <the argument>
*
* After __argv_end__ the response appears, and the format is
* RESP (2 or 3, depending on what the client has configured)
*/
#include "server.h"
#include <ctype.h>
#ifdef LOG_REQ_RES
/* ----- Helpers ----- */
static int reqresShouldLog(client *c) {
if (!server.req_res_logfile)
return 0;
/* Ignore client with streaming non-standard response */
if (c->flags & (CLIENT_PUBSUB|CLIENT_MONITOR|CLIENT_SLAVE))
return 0;
/* We only work on masters (didn't implement reqresAppendResponse to work on shared slave buffers) */
if (getClientType(c) == CLIENT_TYPE_MASTER)
return 0;
return 1;
}
static size_t reqresAppendBuffer(client *c, void *buf, size_t len) {
if (!c->reqres.buf) {
c->reqres.capacity = max(len, 1024);
c->reqres.buf = zmalloc(c->reqres.capacity);
} else if (c->reqres.capacity - c->reqres.used < len) {
c->reqres.capacity += len;
c->reqres.buf = zrealloc(c->reqres.buf, c->reqres.capacity);
}
memcpy(c->reqres.buf + c->reqres.used, buf, len);
c->reqres.used += len;
return len;
}
/* Functions for requests */
static size_t reqresAppendArg(client *c, char *arg, size_t arg_len) {
char argv_len_buf[LONG_STR_SIZE];
size_t argv_len_buf_len = ll2string(argv_len_buf,sizeof(argv_len_buf),(long)arg_len);
size_t ret = reqresAppendBuffer(c, argv_len_buf, argv_len_buf_len);
ret += reqresAppendBuffer(c, "\r\n", 2);
ret += reqresAppendBuffer(c, arg, arg_len);
ret += reqresAppendBuffer(c, "\r\n", 2);
return ret;
}
/* ----- API ----- */
/* Zero out the clientReqResInfo struct inside the client,
* and free the buffer if needed */
void reqresReset(client *c, int free_buf) {
if (free_buf && c->reqres.buf)
zfree(c->reqres.buf);
memset(&c->reqres, 0, sizeof(c->reqres));
}
/* Save the offset of the reply buffer (or the reply list).
* Should be called when adding a reply (but it will only save the offset
* on the very first time it's called, because of c->reqres.offset.saved)
* The idea is:
* 1. When a client is executing a command, we save the reply offset.
* 2. During the execution, the reply offset may grow, as addReply* functions are called.
* 3. When client is done with the command (commandProcessed), reqresAppendResponse
* is called.
* 4. reqresAppendResponse will append the diff between the current offset and the one from step (1)
* 5. When client is reset before the next command, we clear c->reqres.offset.saved and start again
*
* We cannot reply on c->sentlen to keep track because it depends on the network
* (reqresAppendResponse will always write the whole buffer, unlike writeToClient)
*
* Ideally, we would just have this code inside reqresAppendRequest, which is called
* from processCommand, but we cannot save the reply offset inside processCommand
* because of the following pipe-lining scenario:
* set rd [redis_deferring_client]
* set buf ""
* append buf "SET key vale\r\n"
* append buf "BLPOP mylist 0\r\n"
* $rd write $buf
* $rd flush
*
* Let's assume we save the reply offset in processCommand
* When BLPOP is processed the offset is 5 (+OK\r\n from the SET)
* Then beforeSleep is called, the +OK is written to network, and bufpos is 0
* When the client is finally unblocked, the cached offset is 5, but bufpos is already
* 0, so we would miss the first 5 bytes of the reply.
**/
void reqresSaveClientReplyOffset(client *c) {
if (!reqresShouldLog(c))
return;
if (c->reqres.offset.saved)
return;
c->reqres.offset.saved = 1;
c->reqres.offset.bufpos = c->bufpos;
if (listLength(c->reply) && listNodeValue(listLast(c->reply))) {
c->reqres.offset.last_node.index = listLength(c->reply) - 1;
c->reqres.offset.last_node.used = ((clientReplyBlock *)listNodeValue(listLast(c->reply)))->used;
} else {
c->reqres.offset.last_node.index = 0;
c->reqres.offset.last_node.used = 0;
}
}
size_t reqresAppendRequest(client *c) {
robj **argv = c->argv;
int argc = c->argc;
serverAssert(argc);
if (!reqresShouldLog(c))
return 0;
/* Ignore commands that have streaming non-standard response */
sds cmd = argv[0]->ptr;
if (!strcasecmp(cmd,"sync") ||
!strcasecmp(cmd,"psync") ||
!strcasecmp(cmd,"monitor") ||
!strcasecmp(cmd,"subscribe") ||
!strcasecmp(cmd,"unsubscribe") ||
!strcasecmp(cmd,"ssubscribe") ||
!strcasecmp(cmd,"sunsubscribe") ||
!strcasecmp(cmd,"psubscribe") ||
!strcasecmp(cmd,"punsubscribe") ||
!strcasecmp(cmd,"debug") ||
!strcasecmp(cmd,"pfdebug") ||
!strcasecmp(cmd,"lolwut") ||
(!strcasecmp(cmd,"sentinel") && argc > 1 && !strcasecmp(argv[1]->ptr,"debug")))
{
return 0;
}
c->reqres.argv_logged = 1;
size_t ret = 0;
for (int i = 0; i < argc; i++) {
if (sdsEncodedObject(argv[i])) {
ret += reqresAppendArg(c, argv[i]->ptr, sdslen(argv[i]->ptr));
} else if (argv[i]->encoding == OBJ_ENCODING_INT) {
char buf[LONG_STR_SIZE];
size_t len = ll2string(buf,sizeof(buf),(long)argv[i]->ptr);
ret += reqresAppendArg(c, buf, len);
} else {
serverPanic("Wrong encoding in reqresAppendRequest()");
}
}
return ret + reqresAppendArg(c, "__argv_end__", 12);
}
size_t reqresAppendResponse(client *c) {
size_t ret = 0;
if (!reqresShouldLog(c))
return 0;
if (!c->reqres.argv_logged) /* Example: UNSUBSCRIBE */
return 0;
if (!c->reqres.offset.saved) /* Example: module client blocked on keys + CLIENT KILL */
return 0;
/* First append the static reply buffer */
if (c->bufpos > c->reqres.offset.bufpos) {
size_t written = reqresAppendBuffer(c, c->buf + c->reqres.offset.bufpos, c->bufpos - c->reqres.offset.bufpos);
ret += written;
}
int curr_index = 0;
size_t curr_used = 0;
if (listLength(c->reply)) {
curr_index = listLength(c->reply) - 1;
curr_used = ((clientReplyBlock *)listNodeValue(listLast(c->reply)))->used;
}
/* Now, append reply bytes from the reply list */
if (curr_index > c->reqres.offset.last_node.index ||
curr_used > c->reqres.offset.last_node.used)
{
int i = 0;
listIter iter;
listNode *curr;
clientReplyBlock *o;
listRewind(c->reply, &iter);
while ((curr = listNext(&iter)) != NULL) {
size_t written;
/* Skip nodes we had already processed */
if (i < c->reqres.offset.last_node.index) {
i++;
continue;
}
o = listNodeValue(curr);
if (o->used == 0) {
i++;
continue;
}
if (i == c->reqres.offset.last_node.index) {
/* Write the potentially incomplete node, which had data from
* before the current command started */
written = reqresAppendBuffer(c,
o->buf + c->reqres.offset.last_node.used,
o->used - c->reqres.offset.last_node.used);
} else {
/* New node */
written = reqresAppendBuffer(c, o->buf, o->used);
}
ret += written;
i++;
}
}
serverAssert(ret);
/* Flush both request and response to file */
FILE *fp = fopen(server.req_res_logfile, "a");
serverAssert(fp);
fwrite(c->reqres.buf, c->reqres.used, 1, fp);
fclose(fp);
return ret;
}
#else /* #ifdef LOG_REQ_RES */
/* Just mimic the API without doing anything */
void reqresReset(client *c, int free_buf) {
UNUSED(c);
UNUSED(free_buf);
}
inline void reqresSaveClientReplyOffset(client *c) {
UNUSED(c);
}
inline size_t reqresAppendRequest(client *c) {
UNUSED(c);
return 0;
}
inline size_t reqresAppendResponse(client *c) {
UNUSED(c);
return 0;
}
#endif /* #ifdef LOG_REQ_RES */
......@@ -139,7 +139,12 @@ client *createClient(connection *conn) {
uint64_t client_id;
atomicGetIncr(server.next_client_id, client_id, 1);
c->id = client_id;
#ifdef LOG_REQ_RES
reqresReset(c, 0);
c->resp = server.client_default_resp;
#else
c->resp = 2;
#endif
c->conn = conn;
c->name = NULL;
c->bufpos = 0;
......@@ -390,6 +395,10 @@ void _addReplyToBufferOrList(client *c, const char *s, size_t len) {
return;
}
/* We call it here because this function may affect the reply
* buffer offset (see function comment) */
reqresSaveClientReplyOffset(c);
size_t reply_len = _addReplyToBuffer(c,s,len);
if (len > reply_len) _addReplyProtoToList(c,s+reply_len,len-reply_len);
}
......@@ -714,6 +723,10 @@ void *addReplyDeferredLen(client *c) {
return NULL;
}
/* We call it here because this function conceptually affects the reply
* buffer offset (see function comment) */
reqresSaveClientReplyOffset(c);
trimReplyUnusedTailSpace(c);
listAddNodeTail(c->reply,NULL); /* NULL is our placeholder. */
return listLast(c->reply);
......@@ -1575,6 +1588,9 @@ void freeClient(client *c) {
freeClientOriginalArgv(c);
if (c->deferred_reply_errors)
listRelease(c->deferred_reply_errors);
#ifdef LOG_REQ_RES
reqresReset(c, 1);
#endif
/* Unlink the client: this will close the socket, remove the I/O
* handlers, and remove references of the client from different
......@@ -2000,6 +2016,9 @@ void resetClient(client *c) {
c->slot = -1;
c->duration = 0;
c->flags &= ~CLIENT_EXECUTING_COMMAND;
#ifdef LOG_REQ_RES
reqresReset(c, 1);
#endif
if (c->deferred_reply_errors)
listRelease(c->deferred_reply_errors);
......@@ -2357,6 +2376,7 @@ void commandProcessed(client *c) {
* since we have not applied the command. */
if (c->flags & CLIENT_BLOCKED) return;
reqresAppendResponse(c);
resetClient(c);
long long prev_offset = c->reploff;
......
......@@ -3540,16 +3540,18 @@ void processClientsWaitingReplicas(void) {
if (last_offset && last_offset >= c->bstate.reploffset &&
last_numreplicas >= c->bstate.numreplicas)
{
unblockClient(c);
/* Reply before unblocking, because unblock client calls reqresAppendResponse */
addReplyLongLong(c,last_numreplicas);
unblockClient(c);
} else {
int numreplicas = replicationCountAcksByOffset(c->bstate.reploffset);
if (numreplicas >= c->bstate.numreplicas) {
last_offset = c->bstate.reploffset;
last_numreplicas = numreplicas;
unblockClient(c);
/* Reply before unblocking, because unblock client calls reqresAppendResponse */
addReplyLongLong(c,numreplicas);
unblockClient(c);
}
}
}
......
......@@ -2776,7 +2776,9 @@ void sentinelInfoReplyCallback(redisAsyncContext *c, void *reply, void *privdata
link->pending_commands--;
r = reply;
if (r->type == REDIS_REPLY_STRING)
/* INFO reply type is verbatim in resp3. Normally, sentinel will not use
* resp3 but this is required for testing (see logreqres.c). */
if (r->type == REDIS_REPLY_STRING || r->type == REDIS_REPLY_VERB)
sentinelRefreshInstanceInfo(ri,r->str);
}
......@@ -2987,8 +2989,10 @@ void sentinelReceiveHelloMessages(redisAsyncContext *c, void *reply, void *privd
ri->link->pc_last_activity = mstime();
/* Sanity check in the reply we expect, so that the code that follows
* can avoid to check for details. */
if (r->type != REDIS_REPLY_ARRAY ||
* can avoid to check for details.
* Note: Reply type is PUSH in resp3. Normally, sentinel will not use
* resp3 but this is required for testing (see logreqres.c). */
if ((r->type != REDIS_REPLY_ARRAY && r->type != REDIS_REPLY_PUSH) ||
r->elements != 3 ||
r->element[0]->type != REDIS_REPLY_STRING ||
r->element[1]->type != REDIS_REPLY_STRING ||
......
......@@ -3782,6 +3782,9 @@ int processCommand(client *c) {
* this is a reprocessing of this command, so we do not want to perform some of the actions again. */
int client_reprocessing_command = c->cmd ? 1 : 0;
if (!client_reprocessing_command)
reqresAppendRequest(c);
/* Handle possible security attacks. */
if (!strcasecmp(c->argv[0]->ptr,"host:") || !strcasecmp(c->argv[0]->ptr,"post")) {
securityWarningCommand(c);
......@@ -4641,30 +4644,41 @@ void addReplyCommandArgList(client *c, struct redisCommandArg *args, int num_arg
}
}
/* Must match redisCommandRESP2Type */
const char *RESP2_TYPE_STR[] = {
"simple-string",
"error",
"integer",
"bulk-string",
"null-bulk-string",
"array",
"null-array",
};
#ifdef LOG_REQ_RES
/* Must match redisCommandRESP3Type */
const char *RESP3_TYPE_STR[] = {
"simple-string",
"error",
"integer",
"double",
"bulk-string",
"array",
"map",
"set",
"bool",
"null",
};
void addReplyJson(client *c, struct jsonObject *rs) {
addReplyMapLen(c, rs->length);
for (int i = 0; i < rs->length; i++) {
struct jsonObjectElement *curr = &rs->elements[i];
addReplyBulkCString(c, curr->key);
switch (curr->type) {
case (JSON_TYPE_BOOLEAN):
addReplyBool(c, curr->value.boolean);
break;
case (JSON_TYPE_INTEGER):
addReplyLongLong(c, curr->value.integer);
break;
case (JSON_TYPE_STRING):
addReplyBulkCString(c, curr->value.string);
break;
case (JSON_TYPE_OBJECT):
addReplyJson(c, curr->value.object);
break;
case (JSON_TYPE_ARRAY):
addReplyArrayLen(c, curr->value.array.length);
for (int k = 0; k < curr->value.array.length; k++) {
struct jsonObject *object = curr->value.array.objects[k];
addReplyJson(c, object);
}
break;
default:
serverPanic("Invalid JSON type %d", curr->type);
}
}
}
#endif
void addReplyCommandHistory(client *c, struct redisCommand *cmd) {
addReplySetLen(c, cmd->num_history);
......@@ -4862,6 +4876,9 @@ void addReplyCommandDocs(client *c, struct redisCommand *cmd) {
if (cmd->deprecated_since) maplen++;
if (cmd->replaced_by) maplen++;
if (cmd->history) maplen++;
#ifdef LOG_REQ_RES
if (cmd->reply_schema) maplen++;
#endif
if (cmd->args) maplen++;
if (cmd->subcommands_dict) maplen++;
addReplyMapLen(c, maplen);
......@@ -4903,6 +4920,12 @@ void addReplyCommandDocs(client *c, struct redisCommand *cmd) {
addReplyBulkCString(c, "history");
addReplyCommandHistory(c, cmd);
}
#ifdef LOG_REQ_RES
if (cmd->reply_schema) {
addReplyBulkCString(c, "reply_schema");
addReplyJson(c, cmd->reply_schema);
}
#endif
if (cmd->args) {
addReplyBulkCString(c, "arguments");
addReplyCommandArgList(c, cmd->args, cmd->num_args);
......
......@@ -1101,6 +1101,31 @@ typedef struct {
size_t mem_usage_sum;
} clientMemUsageBucket;
#ifdef LOG_REQ_RES
/* Structure used to log client's requests and their
* responses (see logreqres.c) */
typedef struct {
/* General */
int argv_logged; /* 1 if the command was logged */
/* Vars for log buffer */
unsigned char *buf; /* Buffer holding the data (request and response) */
size_t used;
size_t capacity;
/* Vars for offsets within the client's reply */
struct {
/* General */
int saved; /* 1 if we already saved the offset (first time we call addReply*) */
/* Offset within the static reply buffer */
int bufpos;
/* Offset within the reply block list */
struct {
int index;
size_t used;
} last_node;
} offset;
} clientReqResInfo;
#endif
typedef struct client {
uint64_t id; /* Client incremental unique ID. */
uint64_t flags; /* Client flags: CLIENT_* macros. */
......@@ -1212,6 +1237,9 @@ typedef struct client {
int bufpos;
size_t buf_usable_size; /* Usable size of buffer. */
char *buf;
#ifdef LOG_REQ_RES
clientReqResInfo reqres;
#endif
} client;
/* ACL information */
......@@ -1540,6 +1568,11 @@ struct redisServer {
client *current_client; /* The client that triggered the command execution (External or AOF). */
client *executing_client; /* The client executing the current command (possibly script or module). */
#ifdef LOG_REQ_RES
char *req_res_logfile; /* Path of log file for logging all requests and their replies. If NULL, no logging will be performed */
unsigned int client_default_resp;
#endif
/* Stuff for client mem eviction */
clientMemUsageBucket* client_mem_usage_buckets;
......@@ -2106,30 +2139,38 @@ typedef struct redisCommandArg {
int num_args;
} redisCommandArg;
/* Must be synced with RESP2_TYPE_STR and generate-command-code.py */
typedef enum {
RESP2_SIMPLE_STRING,
RESP2_ERROR,
RESP2_INTEGER,
RESP2_BULK_STRING,
RESP2_NULL_BULK_STRING,
RESP2_ARRAY,
RESP2_NULL_ARRAY,
} redisCommandRESP2Type;
/* Must be synced with RESP3_TYPE_STR and generate-command-code.py */
#ifdef LOG_REQ_RES
/* Must be synced with generate-command-code.py */
typedef enum {
RESP3_SIMPLE_STRING,
RESP3_ERROR,
RESP3_INTEGER,
RESP3_DOUBLE,
RESP3_BULK_STRING,
RESP3_ARRAY,
RESP3_MAP,
RESP3_SET,
RESP3_BOOL,
RESP3_NULL,
} redisCommandRESP3Type;
JSON_TYPE_STRING,
JSON_TYPE_INTEGER,
JSON_TYPE_BOOLEAN,
JSON_TYPE_OBJECT,
JSON_TYPE_ARRAY,
} jsonType;
typedef struct jsonObjectElement {
jsonType type;
const char *key;
union {
const char *string;
long long integer;
int boolean;
struct jsonObject *object;
struct {
struct jsonObject **objects;
int length;
} array;
} value;
} jsonObjectElement;
typedef struct jsonObject {
struct jsonObjectElement *elements;
int length;
} jsonObject;
#endif
/* WARNING! This struct must match RedisModuleCommandHistoryEntry */
typedef struct {
......@@ -2280,6 +2321,10 @@ struct redisCommand {
struct redisCommand *subcommands;
/* Array of arguments (may be NULL) */
struct redisCommandArg *args;
#ifdef LOG_REQ_RES
/* Reply schema */
struct jsonObject *reply_schema;
#endif
/* Runtime populated data */
long long microseconds, calls, rejected_calls, failed_calls;
......@@ -2587,6 +2632,12 @@ client *lookupClientByID(uint64_t id);
int authRequired(client *c);
void putClientInPendingWriteQueue(client *c);
/* logreqres.c - logging of requests and responses */
void reqresReset(client *c, int free_buf);
void reqresSaveClientReplyOffset(client *c);
size_t reqresAppendRequest(client *c);
size_t reqresAppendResponse(client *c);
#ifdef __GNUC__
void addReplyErrorFormatEx(client *c, int flags, const char *fmt, ...)
__attribute__((format(printf, 3, 4)));
......
......@@ -74,3 +74,11 @@ test "CLUSTER RESET SOFT test" {
R 1 CLUSTER RESET SOFT
assert {[get_info_field [R 1 cluster info] cluster_current_epoch] eq $last_epoch_node1}
}
test "Coverage: CLUSTER HELP" {
assert_match "*CLUSTER <subcommand> *" [R 0 CLUSTER HELP]
}
test "Coverage: ASKING" {
assert_equal {OK} [R 0 ASKING]
}
......@@ -20,6 +20,12 @@ test "Can't read from replica without READONLY" {
assert {[string range $err 0 4] eq {MOVED}}
}
test "Can't read from replica after READWRITE" {
$replica READWRITE
catch {$replica GET a} err
assert {[string range $err 0 4] eq {MOVED}}
}
test "Can read from replica after READONLY" {
$replica READONLY
assert {[$replica GET a] eq {1}}
......
......@@ -105,6 +105,15 @@ proc spawn_instance {type base_port count {conf {}} {base_conf_file ""}} {
} else {
puts $cfg "port $port"
}
if {$::log_req_res} {
puts $cfg "req-res-logfile stdout.reqres"
}
if {$::force_resp3} {
puts $cfg "client-default-resp 3"
}
puts $cfg "repl-diskless-sync-delay 0"
puts $cfg "dir ./$dirname"
puts $cfg "logfile log.txt"
......@@ -293,6 +302,10 @@ proc parse_options {} {
set ::stop_on_failure 1
} elseif {$opt eq {--loop}} {
set ::loop 1
} elseif {$opt eq {--log-req-res}} {
set ::log_req_res 1
} elseif {$opt eq {--force-resp3}} {
set ::force_resp3 1
} elseif {$opt eq "--help"} {
puts "--single <pattern> Only runs tests specified by pattern."
puts "--dont-clean Keep log files on exit."
......
......@@ -827,7 +827,7 @@ test {corrupt payload: fuzzer findings - set with duplicate elements causes sdif
assert_equal {0 2 4 6 8 _1 _3 _3 _5 _9} [lsort [r smembers _key]]
assert_equal {0 2 4 6 8 _1 _3 _5 _9} [lsort [r sdiff _key]]
}
}
} {} {logreqres:skip} ;# This test violates {"uniqueItems": true}
} ;# tags
......@@ -218,6 +218,7 @@ start_server {} {
test {Test RDB load info} {
r debug populate 1000
r save
assert {[r lastsave] <= [lindex [r time] 0]}
restart_server 0 true false
wait_done_loading r
assert {[s rdb_last_load_keys_expired] == 0}
......
......@@ -25,7 +25,7 @@ proc default_set_get_checks {} {
assert_match {} [cmdstat lrange]
}
start_server {tags {"benchmark network external:skip"}} {
start_server {tags {"benchmark network external:skip logreqres:skip"}} {
start_server {} {
set master_host [srv 0 host]
set master_port [srv 0 port]
......
......@@ -89,6 +89,7 @@ int get_fsl(RedisModuleCtx *ctx, RedisModuleString *keyname, int mode, int creat
create = 0; /* No need to create, key exists in its basic state */
} else {
RedisModule_DeleteKey(key);
*fsl = NULL;
}
} else {
/* Key exists, and has elements in it - no need to create anything */
......
......@@ -72,6 +72,7 @@ test "SDOWN is triggered by masters advertising as slaves" {
ensure_master_up
}
if {!$::log_req_res} { # this test changes 'dir' config to '/' and logreqres.c cannot open protocol dump file under the root directory.
test "SDOWN is triggered by misconfigured instance replying with errors" {
ensure_master_up
set orig_dir [lindex [R 0 config get dir] 1]
......@@ -90,6 +91,7 @@ test "SDOWN is triggered by misconfigured instance replying with errors" {
R 0 bgsave
ensure_master_up
}
}
# We use this test setup to also test command renaming, as a side
# effect of the master going down if we send PONG instead of PING
......
......@@ -28,6 +28,8 @@
package require Tcl 8.5
package provide redis 0.1
source [file join [file dirname [info script]] "response_transformers.tcl"]
namespace eval redis {}
set ::redis::id 0
array set ::redis::fd {}
......@@ -41,6 +43,11 @@ array set ::redis::tls {}
array set ::redis::callback {}
array set ::redis::state {} ;# State in non-blocking reply reading
array set ::redis::statestack {} ;# Stack of states, for nested mbulks
array set ::redis::curr_argv {} ;# Remember the current argv, to be used in response_transformers.tcl
array set ::redis::testing_resp3 {} ;# Indicating if the current client is using RESP3 (only if the test is trying to test RESP3 specific behavior. It won't be on in case of force_resp3)
set ::force_resp3 0
set ::log_req_res 0
proc redis {{server 127.0.0.1} {port 6379} {defer 0} {tls 0} {tlsoptions {}} {readraw 0}} {
if {$tls} {
......@@ -62,6 +69,8 @@ proc redis {{server 127.0.0.1} {port 6379} {defer 0} {tls 0} {tlsoptions {}} {re
set ::redis::deferred($id) $defer
set ::redis::readraw($id) $readraw
set ::redis::reconnect($id) 0
set ::redis::curr_argv($id) 0
set ::redis::testing_resp3($id) 0
set ::redis::tls($id) $tls
::redis::redis_reset_state $id
interp alias {} ::redis::redisHandle$id {} ::redis::__dispatch__ $id
......@@ -123,6 +132,20 @@ proc ::redis::__dispatch__raw__ {id method argv} {
set fd $::redis::fd($id)
}
# Transform HELLO 2 to HELLO 3 if force_resp3
# All set the connection var testing_resp3 in case of HELLO 3
if {[llength $argv] > 0 && [string compare -nocase $method "HELLO"] == 0} {
if {[lindex $argv 0] == 3} {
set ::redis::testing_resp3($id) 1
} else {
set ::redis::testing_resp3($id) 0
if {$::force_resp3} {
# If we are in force_resp3 we run HELLO 3 instead of HELLO 2
lset argv 0 3
}
}
}
set blocking $::redis::blocking($id)
set deferred $::redis::deferred($id)
if {$blocking == 0} {
......@@ -146,6 +169,7 @@ proc ::redis::__dispatch__raw__ {id method argv} {
return -code error "I/O error reading reply"
}
set ::redis::curr_argv($id) [concat $method $argv]
if {!$deferred} {
if {$blocking} {
::redis::redis_read_reply $id $fd
......@@ -200,6 +224,8 @@ proc ::redis::__method__close {id fd} {
catch {unset ::redis::state($id)}
catch {unset ::redis::statestack($id)}
catch {unset ::redis::callback($id)}
catch {unset ::redis::curr_argv($id)}
catch {unset ::redis::testing_resp3($id)}
catch {interp alias {} ::redis::redisHandle$id {}}
}
......@@ -253,7 +279,7 @@ proc ::redis::redis_multi_bulk_read {id fd} {
set err {}
for {set i 0} {$i < $count} {incr i} {
if {[catch {
lappend l [redis_read_reply $id $fd]
lappend l [redis_read_reply_logic $id $fd]
} e] && $err eq {}} {
set err $e
}
......@@ -269,8 +295,8 @@ proc ::redis::redis_read_map {id fd} {
set err {}
for {set i 0} {$i < $count} {incr i} {
if {[catch {
set k [redis_read_reply $id $fd] ; # key
set v [redis_read_reply $id $fd] ; # value
set k [redis_read_reply_logic $id $fd] ; # key
set v [redis_read_reply_logic $id $fd] ; # value
dict set d $k $v
} e] && $err eq {}} {
set err $e
......@@ -296,13 +322,25 @@ proc ::redis::redis_read_bool fd {
return -code error "Bad protocol, '$v' as bool type"
}
proc ::redis::redis_read_double {id fd} {
set v [redis_read_line $fd]
# unlike many other DTs, there is a textual difference between double and a string with the same value,
# so we need to transform to double if we are testing RESP3 (i.e. some tests check that a
# double reply is "1.0" and not "1")
if {[should_transform_to_resp2 $id]} {
return $v
} else {
return [expr {double($v)}]
}
}
proc ::redis::redis_read_verbatim_str fd {
set v [redis_bulk_read $fd]
# strip the first 4 chars ("txt:")
return [string range $v 4 end]
}
proc ::redis::redis_read_reply {id fd} {
proc ::redis::redis_read_reply_logic {id fd} {
if {$::redis::readraw($id)} {
return [redis_read_line $fd]
}
......@@ -314,7 +352,7 @@ proc ::redis::redis_read_reply {id fd} {
: -
( -
+ {return [redis_read_line $fd]}
, {return [expr {double([redis_read_line $fd])}]}
, {return [redis_read_double $id $fd]}
# {return [redis_read_bool $fd]}
= {return [redis_read_verbatim_str $fd]}
- {return -code error [redis_read_line $fd]}
......@@ -340,6 +378,11 @@ proc ::redis::redis_read_reply {id fd} {
}
}
proc ::redis::redis_read_reply {id fd} {
set response [redis_read_reply_logic $id $fd]
::response_transformers::transform_response_if_needed $id $::redis::curr_argv($id) $response
}
proc ::redis::redis_reset_state id {
set ::redis::state($id) [dict create buf {} mbulk -1 bulk -1 reply {}]
set ::redis::statestack($id) {}
......@@ -416,3 +459,8 @@ proc ::redis::redis_readable {fd id} {
}
}
}
# when forcing resp3 some tests that rely on resp2 can fail, so we have to translate the resp3 response to resp2
proc ::redis::should_transform_to_resp2 {id} {
return [expr {$::force_resp3 && !$::redis::testing_resp3($id)}]
}
# Tcl client library - used by the Redis test
# Copyright (C) 2009-2023 Redis Ltd.
# Released under the BSD license like Redis itself
#
# This file contains a bunch of commands whose purpose is to transform
# a RESP3 response to RESP2
# Why is it needed?
# When writing the reply_schema part in COMMAND DOCS we decided to use
# the existing tests in order to verify the schemas (see logreqres.c)
# The problem was that many tests were relying on the RESP2 structure
# of the response (e.g. HRANDFIELD WITHVALUES in RESP2: {f1 v1 f2 v2}
# vs. RESP3: {{f1 v1} {f2 v2}}).
# Instead of adjusting the tests to expect RESP3 responses (a lot of
# changes in many files) we decided to transform the response to RESP2
# when running with --force-resp3
package require Tcl 8.5
namespace eval response_transformers {}
# Transform a map response into an array of tuples (tuple = array with 2 elements)
# Used for XREAD[GROUP]
proc transfrom_map_to_tupple_array {argv response} {
set tuparray {}
foreach {key val} $response {
set tmp {}
lappend tmp $key
lappend tmp $val
lappend tuparray $tmp
}
return $tuparray
}
# Transform an array of tuples to a flat array
proc transfrom_tuple_array_to_flat_array {argv response} {
set flatarray {}
foreach pair $response {
lappend flatarray {*}$pair
}
return $flatarray
}
# With HRANDFIELD, we only need to transform the response if the request had WITHVALUES
# (otherwise the returned response is a flat array in both RESPs)
proc transfrom_hrandfield_command {argv response} {
foreach ele $argv {
if {[string compare -nocase $ele "WITHVALUES"] == 0} {
return [transfrom_tuple_array_to_flat_array $argv $response]
}
}
return $response
}
# With some zset commands, we only need to transform the response if the request had WITHSCORES
# (otherwise the returned response is a flat array in both RESPs)
proc transfrom_zset_withscores_command {argv response} {
foreach ele $argv {
if {[string compare -nocase $ele "WITHSCORES"] == 0} {
return [transfrom_tuple_array_to_flat_array $argv $response]
}
}
return $response
}
# With ZPOPMIN/ZPOPMAX, we only need to transform the response if the request had COUNT (3rd arg)
# (otherwise the returned response is a flat array in both RESPs)
proc transfrom_zpopmin_zpopmax {argv response} {
if {[llength $argv] == 3} {
return [transfrom_tuple_array_to_flat_array $argv $response]
}
return $response
}
set ::trasformer_funcs {
XREAD transfrom_map_to_tupple_array
XREADGROUP transfrom_map_to_tupple_array
HRANDFIELD transfrom_hrandfield_command
ZRANDMEMBER transfrom_zset_withscores_command
ZRANGE transfrom_zset_withscores_command
ZRANGEBYSCORE transfrom_zset_withscores_command
ZRANGEBYLEX transfrom_zset_withscores_command
ZREVRANGE transfrom_zset_withscores_command
ZREVRANGEBYSCORE transfrom_zset_withscores_command
ZREVRANGEBYLEX transfrom_zset_withscores_command
ZUNION transfrom_zset_withscores_command
ZDIFF transfrom_zset_withscores_command
ZINTER transfrom_zset_withscores_command
ZPOPMIN transfrom_zpopmin_zpopmax
ZPOPMAX transfrom_zpopmin_zpopmax
}
proc ::response_transformers::transform_response_if_needed {id argv response} {
if {![::redis::should_transform_to_resp2 $id] || $::redis::readraw($id)} {
return $response
}
set key [string toupper [lindex $argv 0]]
if {![dict exists $::trasformer_funcs $key]} {
return $response
}
set transform [dict get $::trasformer_funcs $key]
return [$transform $argv $response]
}
......@@ -207,6 +207,12 @@ proc tags_acceptable {tags err_return} {
}
}
# some units mess with the client output buffer so we can't really use the req-res logging mechanism.
if {$::log_req_res && [lsearch $tags "logreqres:skip"] >= 0} {
set err "Not supported when running in log-req-res mode"
return 0
}
if {$::external && [lsearch $tags "external:skip"] >= 0} {
set err "Not supported on external server"
return 0
......@@ -511,6 +517,14 @@ proc start_server {options {code undefined}} {
dict unset config $directive
}
if {$::log_req_res} {
dict set config "req-res-logfile" "stdout.reqres"
}
if {$::force_resp3} {
dict set config "client-default-resp" "3"
}
# write new configuration to temporary file
set config_file [tmpfile redis.conf]
create_server_config_file $config_file $config $config_lines
......
......@@ -100,6 +100,7 @@ set ::all_tests {
unit/cluster/hostnames
unit/cluster/multi-slot-operations
unit/cluster/slot-ownership
unit/cluster/links
}
# Index to the next test to run in the ::all_tests list.
set ::next_test 0
......@@ -134,6 +135,7 @@ set ::timeout 1200; # 20 minutes without progresses will quit the test.
set ::last_progress [clock seconds]
set ::active_servers {} ; # Pids of active Redis instances.
set ::dont_clean 0
set ::dont_pre_clean 0
set ::wait_server 0
set ::stop_on_failure 0
set ::dump_logs 0
......@@ -144,6 +146,8 @@ set ::cluster_mode 0
set ::ignoreencoding 0
set ::ignoredigest 0
set ::large_memory 0
set ::log_req_res 0
set ::force_resp3 0
# Set to 1 when we are running in client mode. The Redis test uses a
# server-client model to run tests simultaneously. The server instance
......@@ -319,7 +323,7 @@ proc cleanup {} {
}
proc test_server_main {} {
cleanup
if {!$::dont_pre_clean} cleanup
set tclsh [info nameofexecutable]
# Open a listening socket, trying different ports in order to find a
# non busy one.
......@@ -650,6 +654,10 @@ for {set j 0} {$j < [llength $argv]} {incr j} {
lappend ::global_overrides $arg
lappend ::global_overrides $arg2
incr j 2
} elseif {$opt eq {--log-req-res}} {
set ::log_req_res 1
} elseif {$opt eq {--force-resp3}} {
set ::force_resp3 1
} elseif {$opt eq {--skipfile}} {
incr j
set fp [open $arg r]
......@@ -724,6 +732,8 @@ for {set j 0} {$j < [llength $argv]} {incr j} {
set ::durable 1
} elseif {$opt eq {--dont-clean}} {
set ::dont_clean 1
} elseif {$opt eq {--dont-pre-clean}} {
set ::dont_pre_clean 1
} elseif {$opt eq {--no-latency}} {
set ::no_latency 1
} elseif {$opt eq {--wait-server}} {
......
......@@ -7,6 +7,10 @@ start_server {tags {"acl external:skip"}} {
r ACL setuser newuser
}
test {Coverage: ACL USERS} {
r ACL USERS
} {default newuser}
test {Usernames can not contain spaces or null characters} {
catch {r ACL setuser "a a"} err
set err
......
start_server {tags {"aofrw external:skip"}} {
# This unit has the potential to create huge .reqres files, causing log-req-res-validator.py to run for a very long time...
# Since this unit doesn't do anything worth validating, reply_schema-wise, we decided to skip it
start_server {tags {"aofrw external:skip logreqres:skip"}} {
# Enable the AOF
r config set appendonly yes
r config set auto-aof-rewrite-percentage 0 ; # Disable auto-rewrite.
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment