diff --git a/cmake/Modules/SourceFiles.cmake b/cmake/Modules/SourceFiles.cmake index 80c3f0c876..e51f9b7600 100644 --- a/cmake/Modules/SourceFiles.cmake +++ b/cmake/Modules/SourceFiles.cmake @@ -47,7 +47,7 @@ set(VALKEY_SERVER_SRCS ${CMAKE_SOURCE_DIR}/src/cluster_slot_stats.c ${CMAKE_SOURCE_DIR}/src/crc16.c ${CMAKE_SOURCE_DIR}/src/endianconv.c - ${CMAKE_SOURCE_DIR}/src/slowlog.c + ${CMAKE_SOURCE_DIR}/src/commandlog.c ${CMAKE_SOURCE_DIR}/src/eval.c ${CMAKE_SOURCE_DIR}/src/bio.c ${CMAKE_SOURCE_DIR}/src/rio.c diff --git a/src/Makefile b/src/Makefile index 9e4075660d..7a951193e4 100644 --- a/src/Makefile +++ b/src/Makefile @@ -416,7 +416,7 @@ endif ENGINE_NAME=valkey SERVER_NAME=$(ENGINE_NAME)-server$(PROG_SUFFIX) ENGINE_SENTINEL_NAME=$(ENGINE_NAME)-sentinel$(PROG_SUFFIX) -ENGINE_SERVER_OBJ=threads_mngr.o adlist.o quicklist.o ae.o anet.o dict.o hashtable.o kvstore.o server.o sds.o zmalloc.o lzf_c.o lzf_d.o pqsort.o zipmap.o sha1.o ziplist.o release.o memory_prefetch.o io_threads.o networking.o util.o object.o db.o replication.o rdb.o t_string.o t_list.o t_set.o t_zset.o t_hash.o config.o aof.o pubsub.o multi.o debug.o sort.o intset.o syncio.o cluster.o cluster_legacy.o cluster_slot_stats.o crc16.o endianconv.o slowlog.o eval.o bio.o rio.o rand.o memtest.o syscheck.o crcspeed.o crccombine.o crc64.o bitops.o sentinel.o notify.o setproctitle.o blocked.o hyperloglog.o latency.o sparkline.o valkey-check-rdb.o valkey-check-aof.o geo.o lazyfree.o module.o evict.o expire.o geohash.o geohash_helper.o childinfo.o allocator_defrag.o defrag.o siphash.o rax.o t_stream.o listpack.o localtime.o lolwut.o lolwut5.o lolwut6.o acl.o tracking.o socket.o tls.o sha256.o timeout.o setcpuaffinity.o monotonic.o mt19937-64.o resp_parser.o call_reply.o script_lua.o script.o functions.o function_lua.o commands.o strl.o connection.o unix.o logreqres.o rdma.o scripting_engine.o +ENGINE_SERVER_OBJ=threads_mngr.o adlist.o quicklist.o ae.o anet.o dict.o hashtable.o kvstore.o server.o sds.o zmalloc.o lzf_c.o lzf_d.o pqsort.o zipmap.o sha1.o ziplist.o release.o memory_prefetch.o io_threads.o networking.o util.o object.o db.o replication.o rdb.o t_string.o t_list.o t_set.o t_zset.o t_hash.o config.o aof.o pubsub.o multi.o debug.o sort.o intset.o syncio.o cluster.o cluster_legacy.o cluster_slot_stats.o crc16.o endianconv.o commandlog.o eval.o bio.o rio.o rand.o memtest.o syscheck.o crcspeed.o crccombine.o crc64.o bitops.o sentinel.o notify.o setproctitle.o blocked.o hyperloglog.o latency.o sparkline.o valkey-check-rdb.o valkey-check-aof.o geo.o lazyfree.o module.o evict.o expire.o geohash.o geohash_helper.o childinfo.o allocator_defrag.o defrag.o siphash.o rax.o t_stream.o listpack.o localtime.o lolwut.o lolwut5.o lolwut6.o acl.o tracking.o socket.o tls.o sha256.o timeout.o setcpuaffinity.o monotonic.o mt19937-64.o resp_parser.o call_reply.o script_lua.o script.o functions.o function_lua.o commands.o strl.o connection.o unix.o logreqres.o rdma.o scripting_engine.o ENGINE_CLI_NAME=$(ENGINE_NAME)-cli$(PROG_SUFFIX) ENGINE_CLI_OBJ=anet.o adlist.o dict.o valkey-cli.o zmalloc.o release.o ae.o serverassert.o crcspeed.o crccombine.o crc64.o siphash.o crc16.o monotonic.o cli_common.o mt19937-64.o strl.o cli_commands.o ENGINE_BENCHMARK_NAME=$(ENGINE_NAME)-benchmark$(PROG_SUFFIX) diff --git a/src/blocked.c b/src/blocked.c index d2d6a5d314..1edb7728cc 100644 --- a/src/blocked.c +++ b/src/blocked.c @@ -61,7 +61,7 @@ */ #include "server.h" -#include "slowlog.h" +#include "commandlog.h" #include "latency.h" #include "monotonic.h" #include "cluster_slot_stats.h" @@ -117,15 +117,15 @@ void blockClient(client *c, int btype) { * he will attempt to reprocess the command which will update the statistics. * However in case the client was timed out or in case of module blocked client is being unblocked * the command will not be reprocessed and we need to make stats update. - * This function will make updates to the commandstats, slot-stats, slowlog and monitors. + * This function will make updates to the commandstats, slot-stats, commandlog and monitors. * The failed_or_rejected parameter is an indication that the blocked command was either failed internally or * rejected/aborted externally. In case the command was rejected the value ERROR_COMMAND_REJECTED should be passed. * In case the command failed internally, ERROR_COMMAND_FAILED should be passed. * A value of zero indicate no error was reported after the command was unblocked */ void updateStatsOnUnblock(client *c, long blocked_us, long reply_us, int failed_or_rejected) { - const ustime_t total_cmd_duration = c->duration + blocked_us + reply_us; - c->lastcmd->microseconds += total_cmd_duration; - clusterSlotStatsAddCpuDuration(c, total_cmd_duration); + c->duration += blocked_us + reply_us; + c->lastcmd->microseconds += c->duration; + clusterSlotStatsAddCpuDuration(c, c->duration); c->lastcmd->calls++; c->commands_processed++; server.stat_numcommands++; @@ -139,9 +139,9 @@ void updateStatsOnUnblock(client *c, long blocked_us, long reply_us, int failed_ debugServerAssertWithInfo(c, NULL, 0); } if (server.latency_tracking_enabled) - updateCommandLatencyHistogram(&(c->lastcmd->latency_histogram), total_cmd_duration * 1000); - /* Log the command into the Slow log if needed. */ - slowlogPushCurrentCommand(c, c->lastcmd, total_cmd_duration); + updateCommandLatencyHistogram(&(c->lastcmd->latency_histogram), c->duration * 1000); + /* Log the command into the commandlog if needed. */ + commandlogPushCurrentCommand(c, c->lastcmd); c->duration = 0; /* Log the reply duration event. */ latencyAddSampleIfNeeded("command-unblocking", reply_us / 1000); diff --git a/src/commandlog.c b/src/commandlog.c new file mode 100644 index 0000000000..cf25cbf2c2 --- /dev/null +++ b/src/commandlog.c @@ -0,0 +1,265 @@ +/* Commandlog implements a system that is able to remember the latest N + * queries that took more than M microseconds to execute, or consumed + * too much network bandwidth and memory for input/output buffers. + * + * The execution time to reach to be logged in the slow log is set + * using the 'commandlog-execution-slower-than' config directive, that is also + * readable and writable using the CONFIG SET/GET command. + * + * Other configurations such as `commandlog-request-larger-than` and + * `commandlog-reply-larger-than` can be found with more detailed + * explanations in the config file. + * + * The command log is actually not "logged" in the server log file + * but is accessible thanks to the COMMANDLOG command. + * + * ---------------------------------------------------------------------------- + * + * Copyright Valkey Contributors. + * All rights reserved. + * SPDX-License-Identifier: BSD 3-Clause + */ + +#include "commandlog.h" +#include "script.h" + +/* Create a new commandlog entry. + * Incrementing the ref count of all the objects retained is up to + * this function. */ +static commandlogEntry *commandlogCreateEntry(client *c, robj **argv, int argc, long long value, int type) { + commandlogEntry *ce = zmalloc(sizeof(*ce)); + int j, ceargc = argc; + + if (ceargc > COMMANDLOG_ENTRY_MAX_ARGC) ceargc = COMMANDLOG_ENTRY_MAX_ARGC; + ce->argc = ceargc; + ce->argv = zmalloc(sizeof(robj *) * ceargc); + for (j = 0; j < ceargc; j++) { + /* Logging too many arguments is a useless memory waste, so we stop + * at COMMANDLOG_ENTRY_MAX_ARGC, but use the last argument to specify + * how many remaining arguments there were in the original command. */ + if (ceargc != argc && j == ceargc - 1) { + ce->argv[j] = + createObject(OBJ_STRING, sdscatprintf(sdsempty(), "... (%d more arguments)", argc - ceargc + 1)); + } else { + /* Trim too long strings as well... */ + if (argv[j]->type == OBJ_STRING && sdsEncodedObject(argv[j]) && + sdslen(argv[j]->ptr) > COMMANDLOG_ENTRY_MAX_STRING) { + sds s = sdsnewlen(argv[j]->ptr, COMMANDLOG_ENTRY_MAX_STRING); + + s = sdscatprintf(s, "... (%lu more bytes)", + (unsigned long)sdslen(argv[j]->ptr) - COMMANDLOG_ENTRY_MAX_STRING); + ce->argv[j] = createObject(OBJ_STRING, s); + } else if (argv[j]->refcount == OBJ_SHARED_REFCOUNT) { + ce->argv[j] = argv[j]; + } else { + /* Here we need to duplicate the string objects composing the + * argument vector of the command, because those may otherwise + * end shared with string objects stored into keys. Having + * shared objects between any part of the server, and the data + * structure holding the data, is a problem: FLUSHALL ASYNC + * may release the shared string object and create a race. */ + ce->argv[j] = dupStringObject(argv[j]); + } + } + } + ce->time = time(NULL); + ce->value = value; + ce->id = server.commandlog[type].entry_id++; + ce->peerid = sdsnew(getClientPeerId(c)); + ce->cname = c->name ? sdsnew(c->name->ptr) : sdsempty(); + return ce; +} + +/* Free a command log entry. The argument is void so that the prototype of this + * function matches the one of the 'free' method of adlist.c. + * + * This function will take care to release all the retained object. */ +static void commandlogFreeEntry(void *ceptr) { + commandlogEntry *ce = ceptr; + int j; + + for (j = 0; j < ce->argc; j++) decrRefCount(ce->argv[j]); + zfree(ce->argv); + sdsfree(ce->peerid); + sdsfree(ce->cname); + zfree(ce); +} + +/* Initialize the command log. This function should be called a single time + * at server startup. */ +void commandlogInit(void) { + for (int i = 0; i < COMMANDLOG_TYPE_NUM; i++) { + server.commandlog[i].entries = listCreate(); + server.commandlog[i].entry_id = 0; + listSetFreeMethod(server.commandlog[i].entries, commandlogFreeEntry); + } +} + +/* Push a new entry into the command log. + * This function will make sure to trim the command log accordingly to the + * configured max length. */ +static void commandlogPushEntryIfNeeded(client *c, robj **argv, int argc, long long value, int type) { + if (server.commandlog[type].threshold < 0 || server.commandlog[type].max_len == 0) return; /* The corresponding commandlog disabled */ + if (value >= server.commandlog[type].threshold) + listAddNodeHead(server.commandlog[type].entries, commandlogCreateEntry(c, argv, argc, value, type)); + + /* Remove old entries if needed. */ + while (listLength(server.commandlog[type].entries) > server.commandlog[type].max_len) listDelNode(server.commandlog[type].entries, listLast(server.commandlog[type].entries)); +} + +/* Remove all the entries from the current command log of the specified type. */ +static void commandlogReset(int type) { + while (listLength(server.commandlog[type].entries) > 0) listDelNode(server.commandlog[type].entries, listLast(server.commandlog[type].entries)); +} + +/* Reply command logs to client. */ +static void commandlogGetReply(client *c, int type, long count) { + listIter li; + listNode *ln; + commandlogEntry *ce; + + if (count > (long)listLength(server.commandlog[type].entries)) { + count = listLength(server.commandlog[type].entries); + } + addReplyArrayLen(c, count); + listRewind(server.commandlog[type].entries, &li); + while (count--) { + int j; + + ln = listNext(&li); + ce = ln->value; + addReplyArrayLen(c, 6); + addReplyLongLong(c, ce->id); + addReplyLongLong(c, ce->time); + addReplyLongLong(c, ce->value); + addReplyArrayLen(c, ce->argc); + for (j = 0; j < ce->argc; j++) addReplyBulk(c, ce->argv[j]); + addReplyBulkCBuffer(c, ce->peerid, sdslen(ce->peerid)); + addReplyBulkCBuffer(c, ce->cname, sdslen(ce->cname)); + } +} + +/* Log the last command a client executed into the commandlog. */ +void commandlogPushCurrentCommand(client *c, struct serverCommand *cmd) { + /* Some commands may contain sensitive data that should not be available in the commandlog. + */ + if (cmd->flags & CMD_SKIP_COMMANDLOG) return; + + /* If command argument vector was rewritten, use the original + * arguments. */ + robj **argv = c->original_argv ? c->original_argv : c->argv; + int argc = c->original_argv ? c->original_argc : c->argc; + + /* If a script is currently running, the client passed in is a + * fake client. Or the client passed in is the original client + * if this is a EVAL or alike, doesn't matter. In this case, + * use the original client to get the client information. */ + c = scriptIsRunning() ? scriptGetCaller() : c; + + commandlogPushEntryIfNeeded(c, argv, argc, c->duration, COMMANDLOG_TYPE_SLOW); + commandlogPushEntryIfNeeded(c, argv, argc, c->net_input_bytes_curr_cmd, COMMANDLOG_TYPE_LARGE_REQUEST); + commandlogPushEntryIfNeeded(c, argv, argc, c->net_output_bytes_curr_cmd, COMMANDLOG_TYPE_LARGE_REPLY); +} + +/* The SLOWLOG command. Implements all the subcommands needed to handle the + * slow log. */ +void slowlogCommand(client *c) { + if (c->argc == 2 && !strcasecmp(c->argv[1]->ptr, "help")) { + const char *help[] = { + "GET []", + " Return top entries from the slowlog (default: 10, -1 mean all).", + " Entries are made of:", + " id, timestamp, time in microseconds, arguments array, client IP and port,", + " client name", + "LEN", + " Return the length of the slowlog.", + "RESET", + " Reset the slowlog.", + NULL, + }; + addReplyHelp(c, help); + } else if (c->argc == 2 && !strcasecmp(c->argv[1]->ptr, "reset")) { + commandlogReset(COMMANDLOG_TYPE_SLOW); + addReply(c, shared.ok); + } else if (c->argc == 2 && !strcasecmp(c->argv[1]->ptr, "len")) { + addReplyLongLong(c, listLength(server.commandlog[COMMANDLOG_TYPE_SLOW].entries)); + } else if ((c->argc == 2 || c->argc == 3) && !strcasecmp(c->argv[1]->ptr, "get")) { + long count = 10; + + if (c->argc == 3) { + /* Consume count arg. */ + if (getRangeLongFromObjectOrReply(c, c->argv[2], -1, LONG_MAX, &count, + "count should be greater than or equal to -1") != C_OK) + return; + + if (count == -1) { + /* We treat -1 as a special value, which means to get all slow logs. + * Simply set count to the length of server.commandlog. */ + count = listLength(server.commandlog[COMMANDLOG_TYPE_SLOW].entries); + } + } + + commandlogGetReply(c, COMMANDLOG_TYPE_SLOW, count); + } else { + addReplySubcommandSyntaxError(c); + } +} + +static int commandlogGetTypeOrReply(client *c, robj *o) { + if (!strcasecmp(o->ptr, "slow")) return COMMANDLOG_TYPE_SLOW; + if (!strcasecmp(o->ptr, "large-request")) return COMMANDLOG_TYPE_LARGE_REQUEST; + if (!strcasecmp(o->ptr, "large-reply")) return COMMANDLOG_TYPE_LARGE_REPLY; + addReplyError(c, "type should be one of the following: slow, large-request, large-reply"); + return -1; +} + +/* The COMMANDLOG command. Implements all the subcommands needed to handle the + * command log. */ +void commandlogCommand(client *c) { + int type; + if (c->argc == 2 && !strcasecmp(c->argv[1]->ptr, "help")) { + const char *help[] = { + "GET ", + " Return top entries of the specified from the commandlog (-1 mean all).", + " Entries are made of:", + " id, timestamp,", + " time in microseconds for type of slow,", + " or size in bytes for type of large-request,", + " or size in bytes for type of large-reply", + " arguments array, client IP and port,", + " client name", + "LEN ", + " Return the length of the specified type of commandlog.", + "RESET ", + " Reset the specified type of commandlog.", + NULL, + }; + addReplyHelp(c, help); + } else if (c->argc == 3 && !strcasecmp(c->argv[1]->ptr, "reset")) { + if ((type = commandlogGetTypeOrReply(c, c->argv[2])) == -1) return; + commandlogReset(type); + addReply(c, shared.ok); + } else if (c->argc == 3 && !strcasecmp(c->argv[1]->ptr, "len")) { + if ((type = commandlogGetTypeOrReply(c, c->argv[2])) == -1) return; + addReplyLongLong(c, listLength(server.commandlog[type].entries)); + } else if (c->argc == 4 && !strcasecmp(c->argv[1]->ptr, "get")) { + long count; + + /* Consume count arg. */ + if (getRangeLongFromObjectOrReply(c, c->argv[2], -1, LONG_MAX, &count, + "count should be greater than or equal to -1") != C_OK) + return; + + if ((type = commandlogGetTypeOrReply(c, c->argv[3])) == -1) return; + + if (count == -1) { + /* We treat -1 as a special value, which means to get all command logs. + * Simply set count to the length of server.commandlog. */ + count = listLength(server.commandlog[type].entries); + } + + commandlogGetReply(c, type, count); + } else { + addReplySubcommandSyntaxError(c); + } +} diff --git a/src/slowlog.h b/src/commandlog.h similarity index 71% rename from src/slowlog.h rename to src/commandlog.h index 12d9097ffa..825014746e 100644 --- a/src/slowlog.h +++ b/src/commandlog.h @@ -27,27 +27,26 @@ * POSSIBILITY OF SUCH DAMAGE. */ -#ifndef __SLOWLOG_H__ -#define __SLOWLOG_H__ +#ifndef __COMMANDLOG_H__ +#define __COMMANDLOG_H__ #include "server.h" -#define SLOWLOG_ENTRY_MAX_ARGC 32 -#define SLOWLOG_ENTRY_MAX_STRING 128 +#define COMMANDLOG_ENTRY_MAX_ARGC 32 +#define COMMANDLOG_ENTRY_MAX_STRING 128 -/* This structure defines an entry inside the slow log list */ -typedef struct slowlogEntry { +/* This structure defines an entry inside the command log list */ +typedef struct commandlogEntry { robj **argv; int argc; - long long id; /* Unique entry identifier. */ - long long duration; /* Time spent by the query, in microseconds. */ - time_t time; /* Unix time at which the query was executed. */ - sds cname; /* Client name. */ - sds peerid; /* Client network address. */ -} slowlogEntry; + long long id; /* Unique entry identifier. */ + long long value; /* The meaning is determined by the type of command log. */ + time_t time; /* Unix time at which the query was executed. */ + sds cname; /* Client name. */ + sds peerid; /* Client network address. */ +} commandlogEntry; /* Exported API */ -void slowlogInit(void); -void slowlogPushEntryIfNeeded(client *c, robj **argv, int argc, long long duration); +void commandlogInit(void); -#endif /* __SLOWLOG_H__ */ +#endif /* __COMMANDLOG_H__ */ diff --git a/src/commands.def b/src/commands.def index cd919a80e1..613eb16c9b 100644 --- a/src/commands.def +++ b/src/commands.def @@ -6668,6 +6668,147 @@ const char *COMMAND_Tips[] = { #define COMMAND_Keyspecs NULL #endif +/********** COMMANDLOG GET ********************/ + +#ifndef SKIP_CMD_HISTORY_TABLE +/* COMMANDLOG GET history */ +#define COMMANDLOG_GET_History NULL +#endif + +#ifndef SKIP_CMD_TIPS_TABLE +/* COMMANDLOG GET tips */ +const char *COMMANDLOG_GET_Tips[] = { +"request_policy:all_nodes", +"nondeterministic_output", +}; +#endif + +#ifndef SKIP_CMD_KEY_SPECS_TABLE +/* COMMANDLOG GET key specs */ +#define COMMANDLOG_GET_Keyspecs NULL +#endif + +/* COMMANDLOG GET type argument table */ +struct COMMAND_ARG COMMANDLOG_GET_type_Subargs[] = { +{MAKE_ARG("slow",ARG_TYPE_STRING,-1,NULL,NULL,NULL,CMD_ARG_NONE,0,NULL)}, +{MAKE_ARG("large-request",ARG_TYPE_STRING,-1,NULL,NULL,NULL,CMD_ARG_NONE,0,NULL)}, +{MAKE_ARG("large-reply",ARG_TYPE_STRING,-1,NULL,NULL,NULL,CMD_ARG_NONE,0,NULL)}, +}; + +/* COMMANDLOG GET argument table */ +struct COMMAND_ARG COMMANDLOG_GET_Args[] = { +{MAKE_ARG("count",ARG_TYPE_INTEGER,-1,NULL,NULL,NULL,CMD_ARG_NONE,0,NULL)}, +{MAKE_ARG("type",ARG_TYPE_ONEOF,-1,NULL,NULL,NULL,CMD_ARG_NONE,3,NULL),.subargs=COMMANDLOG_GET_type_Subargs}, +}; + +/********** COMMANDLOG HELP ********************/ + +#ifndef SKIP_CMD_HISTORY_TABLE +/* COMMANDLOG HELP history */ +#define COMMANDLOG_HELP_History NULL +#endif + +#ifndef SKIP_CMD_TIPS_TABLE +/* COMMANDLOG HELP tips */ +#define COMMANDLOG_HELP_Tips NULL +#endif + +#ifndef SKIP_CMD_KEY_SPECS_TABLE +/* COMMANDLOG HELP key specs */ +#define COMMANDLOG_HELP_Keyspecs NULL +#endif + +/********** COMMANDLOG LEN ********************/ + +#ifndef SKIP_CMD_HISTORY_TABLE +/* COMMANDLOG LEN history */ +#define COMMANDLOG_LEN_History NULL +#endif + +#ifndef SKIP_CMD_TIPS_TABLE +/* COMMANDLOG LEN tips */ +const char *COMMANDLOG_LEN_Tips[] = { +"request_policy:all_nodes", +"response_policy:agg_sum", +"nondeterministic_output", +}; +#endif + +#ifndef SKIP_CMD_KEY_SPECS_TABLE +/* COMMANDLOG LEN key specs */ +#define COMMANDLOG_LEN_Keyspecs NULL +#endif + +/* COMMANDLOG LEN type argument table */ +struct COMMAND_ARG COMMANDLOG_LEN_type_Subargs[] = { +{MAKE_ARG("slow",ARG_TYPE_STRING,-1,NULL,NULL,NULL,CMD_ARG_NONE,0,NULL)}, +{MAKE_ARG("large-request",ARG_TYPE_STRING,-1,NULL,NULL,NULL,CMD_ARG_NONE,0,NULL)}, +{MAKE_ARG("large-reply",ARG_TYPE_STRING,-1,NULL,NULL,NULL,CMD_ARG_NONE,0,NULL)}, +}; + +/* COMMANDLOG LEN argument table */ +struct COMMAND_ARG COMMANDLOG_LEN_Args[] = { +{MAKE_ARG("type",ARG_TYPE_ONEOF,-1,NULL,NULL,NULL,CMD_ARG_NONE,3,NULL),.subargs=COMMANDLOG_LEN_type_Subargs}, +}; + +/********** COMMANDLOG RESET ********************/ + +#ifndef SKIP_CMD_HISTORY_TABLE +/* COMMANDLOG RESET history */ +#define COMMANDLOG_RESET_History NULL +#endif + +#ifndef SKIP_CMD_TIPS_TABLE +/* COMMANDLOG RESET tips */ +const char *COMMANDLOG_RESET_Tips[] = { +"request_policy:all_nodes", +"response_policy:all_succeeded", +}; +#endif + +#ifndef SKIP_CMD_KEY_SPECS_TABLE +/* COMMANDLOG RESET key specs */ +#define COMMANDLOG_RESET_Keyspecs NULL +#endif + +/* COMMANDLOG RESET type argument table */ +struct COMMAND_ARG COMMANDLOG_RESET_type_Subargs[] = { +{MAKE_ARG("slow",ARG_TYPE_STRING,-1,NULL,NULL,NULL,CMD_ARG_NONE,0,NULL)}, +{MAKE_ARG("large-request",ARG_TYPE_STRING,-1,NULL,NULL,NULL,CMD_ARG_NONE,0,NULL)}, +{MAKE_ARG("large-reply",ARG_TYPE_STRING,-1,NULL,NULL,NULL,CMD_ARG_NONE,0,NULL)}, +}; + +/* COMMANDLOG RESET argument table */ +struct COMMAND_ARG COMMANDLOG_RESET_Args[] = { +{MAKE_ARG("type",ARG_TYPE_ONEOF,-1,NULL,NULL,NULL,CMD_ARG_NONE,3,NULL),.subargs=COMMANDLOG_RESET_type_Subargs}, +}; + +/* COMMANDLOG command table */ +struct COMMAND_STRUCT COMMANDLOG_Subcommands[] = { +{MAKE_CMD("get","Returns the specified command log's entries.","O(N) where N is the number of entries returned","8.1.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,COMMANDLOG_GET_History,0,COMMANDLOG_GET_Tips,2,commandlogCommand,4,CMD_ADMIN|CMD_LOADING|CMD_STALE,0,COMMANDLOG_GET_Keyspecs,0,NULL,2),.args=COMMANDLOG_GET_Args}, +{MAKE_CMD("help","Show helpful text about the different subcommands","O(1)","8.1.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,COMMANDLOG_HELP_History,0,COMMANDLOG_HELP_Tips,0,commandlogCommand,2,CMD_LOADING|CMD_STALE,0,COMMANDLOG_HELP_Keyspecs,0,NULL,0)}, +{MAKE_CMD("len","Returns the number of entries in the specified type of command log.","O(1)","8.1.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,COMMANDLOG_LEN_History,0,COMMANDLOG_LEN_Tips,3,commandlogCommand,3,CMD_ADMIN|CMD_LOADING|CMD_STALE,0,COMMANDLOG_LEN_Keyspecs,0,NULL,1),.args=COMMANDLOG_LEN_Args}, +{MAKE_CMD("reset","Clears all entries from the specified type of command log.","O(N) where N is the number of entries in the commandlog","8.1.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,COMMANDLOG_RESET_History,0,COMMANDLOG_RESET_Tips,2,commandlogCommand,3,CMD_ADMIN|CMD_LOADING|CMD_STALE,0,COMMANDLOG_RESET_Keyspecs,0,NULL,1),.args=COMMANDLOG_RESET_Args}, +{0} +}; + +/********** COMMANDLOG ********************/ + +#ifndef SKIP_CMD_HISTORY_TABLE +/* COMMANDLOG history */ +#define COMMANDLOG_History NULL +#endif + +#ifndef SKIP_CMD_TIPS_TABLE +/* COMMANDLOG tips */ +#define COMMANDLOG_Tips NULL +#endif + +#ifndef SKIP_CMD_KEY_SPECS_TABLE +/* COMMANDLOG key specs */ +#define COMMANDLOG_Keyspecs NULL +#endif + /********** CONFIG GET ********************/ #ifndef SKIP_CMD_HISTORY_TABLE @@ -7831,10 +7972,10 @@ const char *SLOWLOG_RESET_Tips[] = { /* SLOWLOG command table */ struct COMMAND_STRUCT SLOWLOG_Subcommands[] = { -{MAKE_CMD("get","Returns the slow log's entries.","O(N) where N is the number of entries returned","2.2.12",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,SLOWLOG_GET_History,1,SLOWLOG_GET_Tips,2,slowlogCommand,-2,CMD_ADMIN|CMD_LOADING|CMD_STALE,0,SLOWLOG_GET_Keyspecs,0,NULL,1),.args=SLOWLOG_GET_Args}, -{MAKE_CMD("help","Show helpful text about the different subcommands","O(1)","6.2.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,SLOWLOG_HELP_History,0,SLOWLOG_HELP_Tips,0,slowlogCommand,2,CMD_LOADING|CMD_STALE,0,SLOWLOG_HELP_Keyspecs,0,NULL,0)}, -{MAKE_CMD("len","Returns the number of entries in the slow log.","O(1)","2.2.12",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,SLOWLOG_LEN_History,0,SLOWLOG_LEN_Tips,3,slowlogCommand,2,CMD_ADMIN|CMD_LOADING|CMD_STALE,0,SLOWLOG_LEN_Keyspecs,0,NULL,0)}, -{MAKE_CMD("reset","Clears all entries from the slow log.","O(N) where N is the number of entries in the slowlog","2.2.12",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,SLOWLOG_RESET_History,0,SLOWLOG_RESET_Tips,2,slowlogCommand,2,CMD_ADMIN|CMD_LOADING|CMD_STALE,0,SLOWLOG_RESET_Keyspecs,0,NULL,0)}, +{MAKE_CMD("get","Returns the slow log's entries.","O(N) where N is the number of entries returned","2.2.12",CMD_DOC_DEPRECATED,"`COMMANDLOG GET SLOW`","8.1.0","server",COMMAND_GROUP_SERVER,SLOWLOG_GET_History,1,SLOWLOG_GET_Tips,2,slowlogCommand,-2,CMD_ADMIN|CMD_LOADING|CMD_STALE,0,SLOWLOG_GET_Keyspecs,0,NULL,1),.args=SLOWLOG_GET_Args}, +{MAKE_CMD("help","Show helpful text about the different subcommands","O(1)","6.2.0",CMD_DOC_DEPRECATED,"`COMMANDLOG HELP`","8.1.0","server",COMMAND_GROUP_SERVER,SLOWLOG_HELP_History,0,SLOWLOG_HELP_Tips,0,slowlogCommand,2,CMD_LOADING|CMD_STALE,0,SLOWLOG_HELP_Keyspecs,0,NULL,0)}, +{MAKE_CMD("len","Returns the number of entries in the slow log.","O(1)","2.2.12",CMD_DOC_DEPRECATED,"`COMMANDLOG LEN SLOW`","8.1.0","server",COMMAND_GROUP_SERVER,SLOWLOG_LEN_History,0,SLOWLOG_LEN_Tips,3,slowlogCommand,2,CMD_ADMIN|CMD_LOADING|CMD_STALE,0,SLOWLOG_LEN_Keyspecs,0,NULL,0)}, +{MAKE_CMD("reset","Clears all entries from the slow log.","O(N) where N is the number of entries in the slowlog","2.2.12",CMD_DOC_DEPRECATED,"`COMMANDLOG RESET SLOW`","8.1.0","server",COMMAND_GROUP_SERVER,SLOWLOG_RESET_History,0,SLOWLOG_RESET_Tips,2,slowlogCommand,2,CMD_ADMIN|CMD_LOADING|CMD_STALE,0,SLOWLOG_RESET_Keyspecs,0,NULL,0)}, {0} }; @@ -11043,6 +11184,7 @@ struct COMMAND_STRUCT serverCommandTable[] = { {MAKE_CMD("bgrewriteaof","Asynchronously rewrites the append-only file to disk.","O(1)","1.0.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,BGREWRITEAOF_History,0,BGREWRITEAOF_Tips,0,bgrewriteaofCommand,1,CMD_NO_ASYNC_LOADING|CMD_ADMIN|CMD_NOSCRIPT,0,BGREWRITEAOF_Keyspecs,0,NULL,0)}, {MAKE_CMD("bgsave","Asynchronously saves the database(s) to disk.","O(1)","1.0.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,BGSAVE_History,2,BGSAVE_Tips,0,bgsaveCommand,-1,CMD_NO_ASYNC_LOADING|CMD_ADMIN|CMD_NOSCRIPT,0,BGSAVE_Keyspecs,0,NULL,1),.args=BGSAVE_Args}, {MAKE_CMD("command","Returns detailed information about all commands.","O(N) where N is the total number of commands","2.8.13",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,COMMAND_History,0,COMMAND_Tips,1,commandCommand,-1,CMD_LOADING|CMD_STALE|CMD_SENTINEL,ACL_CATEGORY_CONNECTION,COMMAND_Keyspecs,0,NULL,0),.subcommands=COMMAND_Subcommands}, +{MAKE_CMD("commandlog","A container for command log commands.","Depends on subcommand.","8.1.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,COMMANDLOG_History,0,COMMANDLOG_Tips,0,NULL,-2,0,0,COMMANDLOG_Keyspecs,0,NULL,0),.subcommands=COMMANDLOG_Subcommands}, {MAKE_CMD("config","A container for server configuration commands.","Depends on subcommand.","2.0.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,CONFIG_History,0,CONFIG_Tips,0,NULL,-2,0,0,CONFIG_Keyspecs,0,NULL,0),.subcommands=CONFIG_Subcommands}, {MAKE_CMD("dbsize","Returns the number of keys in the database.","O(1)","1.0.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,DBSIZE_History,0,DBSIZE_Tips,2,dbsizeCommand,1,CMD_READONLY|CMD_FAST,ACL_CATEGORY_KEYSPACE,DBSIZE_Keyspecs,0,NULL,0)}, {MAKE_CMD("debug","A container for debugging commands.","Depends on subcommand.","1.0.0",CMD_DOC_SYSCMD,NULL,NULL,"server",COMMAND_GROUP_SERVER,DEBUG_History,0,DEBUG_Tips,0,debugCommand,-2,CMD_ADMIN|CMD_NOSCRIPT|CMD_LOADING|CMD_STALE|CMD_PROTECTED,0,DEBUG_Keyspecs,0,NULL,0)}, @@ -11064,7 +11206,7 @@ struct COMMAND_STRUCT serverCommandTable[] = { {MAKE_CMD("save","Synchronously saves the database(s) to disk.","O(N) where N is the total number of keys in all databases","1.0.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,SAVE_History,0,SAVE_Tips,0,saveCommand,1,CMD_NO_ASYNC_LOADING|CMD_ADMIN|CMD_NOSCRIPT|CMD_NO_MULTI,0,SAVE_Keyspecs,0,NULL,0)}, {MAKE_CMD("shutdown","Synchronously saves the database(s) to disk and shuts down the server.","O(N) when saving, where N is the total number of keys in all databases when saving data, otherwise O(1)","1.0.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,SHUTDOWN_History,1,SHUTDOWN_Tips,0,shutdownCommand,-1,CMD_ADMIN|CMD_NOSCRIPT|CMD_LOADING|CMD_STALE|CMD_NO_MULTI|CMD_SENTINEL|CMD_ALLOW_BUSY,0,SHUTDOWN_Keyspecs,0,NULL,1),.args=SHUTDOWN_Args}, {MAKE_CMD("slaveof","Sets a server as a replica of another, or promotes it to being a primary.","O(1)","1.0.0",CMD_DOC_DEPRECATED,"`REPLICAOF`","5.0.0","server",COMMAND_GROUP_SERVER,SLAVEOF_History,0,SLAVEOF_Tips,0,replicaofCommand,3,CMD_NO_ASYNC_LOADING|CMD_ADMIN|CMD_NOSCRIPT|CMD_STALE,0,SLAVEOF_Keyspecs,0,NULL,1),.args=SLAVEOF_Args}, -{MAKE_CMD("slowlog","A container for slow log commands.","Depends on subcommand.","2.2.12",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,SLOWLOG_History,0,SLOWLOG_Tips,0,NULL,-2,0,0,SLOWLOG_Keyspecs,0,NULL,0),.subcommands=SLOWLOG_Subcommands}, +{MAKE_CMD("slowlog","A container for slow log commands.","Depends on subcommand.","2.2.12",CMD_DOC_DEPRECATED,"`COMMANDLOG`","8.1.0","server",COMMAND_GROUP_SERVER,SLOWLOG_History,0,SLOWLOG_Tips,0,NULL,-2,0,0,SLOWLOG_Keyspecs,0,NULL,0),.subcommands=SLOWLOG_Subcommands}, {MAKE_CMD("swapdb","Swaps two databases.","O(N) where N is the count of clients watching or blocking on keys from both databases.","4.0.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,SWAPDB_History,0,SWAPDB_Tips,0,swapdbCommand,3,CMD_WRITE|CMD_FAST,ACL_CATEGORY_KEYSPACE|ACL_CATEGORY_DANGEROUS,SWAPDB_Keyspecs,0,NULL,2),.args=SWAPDB_Args}, {MAKE_CMD("sync","An internal command used in replication.",NULL,"1.0.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,SYNC_History,0,SYNC_Tips,0,syncCommand,1,CMD_NO_ASYNC_LOADING|CMD_ADMIN|CMD_NO_MULTI|CMD_NOSCRIPT,0,SYNC_Keyspecs,0,NULL,0)}, {MAKE_CMD("time","Returns the server time.","O(1)","2.6.0",CMD_DOC_NONE,NULL,NULL,"server",COMMAND_GROUP_SERVER,TIME_History,0,TIME_Tips,1,timeCommand,1,CMD_LOADING|CMD_STALE|CMD_FAST,0,TIME_Keyspecs,0,NULL,0)}, @@ -11163,7 +11305,7 @@ struct COMMAND_STRUCT serverCommandTable[] = { {MAKE_CMD("substr","Returns a substring from a string value.","O(N) where N is the length of the returned string. The complexity is ultimately determined by the returned length, but because creating a substring from an existing string is very cheap, it can be considered O(1) for small strings.","1.0.0",CMD_DOC_DEPRECATED,"`GETRANGE`","2.0.0","string",COMMAND_GROUP_STRING,SUBSTR_History,0,SUBSTR_Tips,0,getrangeCommand,4,CMD_READONLY,ACL_CATEGORY_STRING,SUBSTR_Keyspecs,1,NULL,3),.args=SUBSTR_Args}, /* transactions */ {MAKE_CMD("discard","Discards a transaction.","O(N), when N is the number of queued commands","2.0.0",CMD_DOC_NONE,NULL,NULL,"transactions",COMMAND_GROUP_TRANSACTIONS,DISCARD_History,0,DISCARD_Tips,0,discardCommand,1,CMD_NOSCRIPT|CMD_LOADING|CMD_STALE|CMD_FAST|CMD_ALLOW_BUSY,ACL_CATEGORY_TRANSACTION,DISCARD_Keyspecs,0,NULL,0)}, -{MAKE_CMD("exec","Executes all commands in a transaction.","Depends on commands in the transaction","1.2.0",CMD_DOC_NONE,NULL,NULL,"transactions",COMMAND_GROUP_TRANSACTIONS,EXEC_History,0,EXEC_Tips,0,execCommand,1,CMD_NOSCRIPT|CMD_LOADING|CMD_STALE|CMD_SKIP_SLOWLOG,ACL_CATEGORY_TRANSACTION,EXEC_Keyspecs,0,NULL,0)}, +{MAKE_CMD("exec","Executes all commands in a transaction.","Depends on commands in the transaction","1.2.0",CMD_DOC_NONE,NULL,NULL,"transactions",COMMAND_GROUP_TRANSACTIONS,EXEC_History,0,EXEC_Tips,0,execCommand,1,CMD_NOSCRIPT|CMD_LOADING|CMD_STALE|CMD_SKIP_COMMANDLOG,ACL_CATEGORY_TRANSACTION,EXEC_Keyspecs,0,NULL,0)}, {MAKE_CMD("multi","Starts a transaction.","O(1)","1.2.0",CMD_DOC_NONE,NULL,NULL,"transactions",COMMAND_GROUP_TRANSACTIONS,MULTI_History,0,MULTI_Tips,0,multiCommand,1,CMD_NOSCRIPT|CMD_LOADING|CMD_STALE|CMD_FAST|CMD_NO_MULTI|CMD_ALLOW_BUSY,ACL_CATEGORY_TRANSACTION,MULTI_Keyspecs,0,NULL,0)}, {MAKE_CMD("unwatch","Forgets about watched keys of a transaction.","O(1)","2.2.0",CMD_DOC_NONE,NULL,NULL,"transactions",COMMAND_GROUP_TRANSACTIONS,UNWATCH_History,0,UNWATCH_Tips,0,unwatchCommand,1,CMD_NOSCRIPT|CMD_LOADING|CMD_STALE|CMD_FAST|CMD_ALLOW_BUSY,ACL_CATEGORY_TRANSACTION,UNWATCH_Keyspecs,0,NULL,0)}, {MAKE_CMD("watch","Monitors changes to keys to determine the execution of a transaction.","O(1) for every key.","2.2.0",CMD_DOC_NONE,NULL,NULL,"transactions",COMMAND_GROUP_TRANSACTIONS,WATCH_History,0,WATCH_Tips,0,watchCommand,-2,CMD_NOSCRIPT|CMD_LOADING|CMD_STALE|CMD_FAST|CMD_NO_MULTI|CMD_ALLOW_BUSY,ACL_CATEGORY_TRANSACTION,WATCH_Keyspecs,1,NULL,1),.args=WATCH_Args}, diff --git a/src/commands/commandlog-get.json b/src/commands/commandlog-get.json new file mode 100644 index 0000000000..00a5a01b0f --- /dev/null +++ b/src/commands/commandlog-get.json @@ -0,0 +1,85 @@ +{ + "GET": { + "summary": "Returns the specified command log's entries.", + "complexity": "O(N) where N is the number of entries returned", + "group": "server", + "since": "8.1.0", + "arity": 4, + "container": "COMMANDLOG", + "function": "commandlogCommand", + "command_flags": [ + "ADMIN", + "LOADING", + "STALE" + ], + "command_tips": [ + "REQUEST_POLICY:ALL_NODES", + "NONDETERMINISTIC_OUTPUT" + ], + "reply_schema": { + "type": "array", + "description": "Entries from the command log in chronological order.", + "uniqueItems": true, + "items": { + "type": "array", + "minItems": 6, + "maxItems": 6, + "items": [ + { + "type": "integer", + "description": "Command log entry ID." + }, + { + "type": "integer", + "description": "The unix timestamp at which the logged command was processed.", + "minimum": 0 + }, + { + "type": "integer", + "description": "Determined by the type parameter.", + "minimum": 0 + }, + { + "type": "array", + "description": "The arguments of the command.", + "items": { + "type": "string" + } + }, + { + "type": "string", + "description": "Client IP address and port." + }, + { + "type": "string", + "description": "Client name if set via the CLIENT SETNAME command." + } + ] + } + }, + "arguments": [ + { + "name": "count", + "type": "integer" + }, + { + "name": "type", + "type": "oneof", + "arguments": [ + { + "name": "slow", + "type": "string" + }, + { + "name": "large-request", + "type": "string" + }, + { + "name": "large-reply", + "type": "string" + } + ] + } + ] + } +} diff --git a/src/commands/commandlog-help.json b/src/commands/commandlog-help.json new file mode 100644 index 0000000000..dacf7d6209 --- /dev/null +++ b/src/commands/commandlog-help.json @@ -0,0 +1,22 @@ +{ + "HELP": { + "summary": "Show helpful text about the different subcommands", + "complexity": "O(1)", + "group": "server", + "since": "8.1.0", + "arity": 2, + "container": "COMMANDLOG", + "function": "commandlogCommand", + "command_flags": [ + "LOADING", + "STALE" + ], + "reply_schema": { + "type": "array", + "description": "Helpful text about subcommands.", + "items": { + "type": "string" + } + } + } +} diff --git a/src/commands/commandlog-len.json b/src/commands/commandlog-len.json new file mode 100644 index 0000000000..4f1bb44075 --- /dev/null +++ b/src/commands/commandlog-len.json @@ -0,0 +1,46 @@ +{ + "LEN": { + "summary": "Returns the number of entries in the specified type of command log.", + "complexity": "O(1)", + "group": "server", + "since": "8.1.0", + "arity": 3, + "container": "COMMANDLOG", + "function": "commandlogCommand", + "command_flags": [ + "ADMIN", + "LOADING", + "STALE" + ], + "command_tips": [ + "REQUEST_POLICY:ALL_NODES", + "RESPONSE_POLICY:AGG_SUM", + "NONDETERMINISTIC_OUTPUT" + ], + "reply_schema": { + "type": "integer", + "description": "Number of entries in the command log.", + "minimum": 0 + }, + "arguments": [ + { + "name": "type", + "type": "oneof", + "arguments": [ + { + "name": "slow", + "type": "string" + }, + { + "name": "large-request", + "type": "string" + }, + { + "name": "large-reply", + "type": "string" + } + ] + } + ] + } +} diff --git a/src/commands/commandlog-reset.json b/src/commands/commandlog-reset.json new file mode 100644 index 0000000000..e43c4d4404 --- /dev/null +++ b/src/commands/commandlog-reset.json @@ -0,0 +1,43 @@ +{ + "RESET": { + "summary": "Clears all entries from the specified type of command log.", + "complexity": "O(N) where N is the number of entries in the commandlog", + "group": "server", + "since": "8.1.0", + "arity": 3, + "container": "COMMANDLOG", + "function": "commandlogCommand", + "command_flags": [ + "ADMIN", + "LOADING", + "STALE" + ], + "command_tips": [ + "REQUEST_POLICY:ALL_NODES", + "RESPONSE_POLICY:ALL_SUCCEEDED" + ], + "reply_schema": { + "const": "OK" + }, + "arguments": [ + { + "name": "type", + "type": "oneof", + "arguments": [ + { + "name": "slow", + "type": "string" + }, + { + "name": "large-request", + "type": "string" + }, + { + "name": "large-reply", + "type": "string" + } + ] + } + ] + } +} diff --git a/src/commands/commandlog.json b/src/commands/commandlog.json new file mode 100644 index 0000000000..2ff2376436 --- /dev/null +++ b/src/commands/commandlog.json @@ -0,0 +1,9 @@ +{ + "COMMANDLOG": { + "summary": "A container for command log commands.", + "complexity": "Depends on subcommand.", + "group": "server", + "since": "8.1.0", + "arity": -2 + } +} diff --git a/src/commands/exec.json b/src/commands/exec.json index 5f03d76e08..3b1b1faff1 100644 --- a/src/commands/exec.json +++ b/src/commands/exec.json @@ -10,7 +10,7 @@ "NOSCRIPT", "LOADING", "STALE", - "SKIP_SLOWLOG" + "SKIP_COMMANDLOG" ], "acl_categories": [ "TRANSACTION" diff --git a/src/commands/slowlog-get.json b/src/commands/slowlog-get.json index ffc54b5454..3f57b87ed8 100644 --- a/src/commands/slowlog-get.json +++ b/src/commands/slowlog-get.json @@ -7,6 +7,11 @@ "arity": -2, "container": "SLOWLOG", "function": "slowlogCommand", + "deprecated_since": "8.1.0", + "replaced_by": "`COMMANDLOG GET SLOW`", + "doc_flags": [ + "DEPRECATED" + ], "history": [ [ "4.0.0", diff --git a/src/commands/slowlog-help.json b/src/commands/slowlog-help.json index dde8fd4598..1db5520e1f 100644 --- a/src/commands/slowlog-help.json +++ b/src/commands/slowlog-help.json @@ -7,6 +7,11 @@ "arity": 2, "container": "SLOWLOG", "function": "slowlogCommand", + "deprecated_since": "8.1.0", + "replaced_by": "`COMMANDLOG HELP`", + "doc_flags": [ + "DEPRECATED" + ], "command_flags": [ "LOADING", "STALE" diff --git a/src/commands/slowlog-len.json b/src/commands/slowlog-len.json index 717a8ad416..8b4e2b86c8 100644 --- a/src/commands/slowlog-len.json +++ b/src/commands/slowlog-len.json @@ -7,6 +7,11 @@ "arity": 2, "container": "SLOWLOG", "function": "slowlogCommand", + "deprecated_since": "8.1.0", + "replaced_by": "`COMMANDLOG LEN SLOW`", + "doc_flags": [ + "DEPRECATED" + ], "command_flags": [ "ADMIN", "LOADING", diff --git a/src/commands/slowlog-reset.json b/src/commands/slowlog-reset.json index cfc1e4da7f..d5fd4b02a2 100644 --- a/src/commands/slowlog-reset.json +++ b/src/commands/slowlog-reset.json @@ -7,6 +7,11 @@ "arity": 2, "container": "SLOWLOG", "function": "slowlogCommand", + "deprecated_since": "8.1.0", + "replaced_by": "`COMMANDLOG RESET SLOW`", + "doc_flags": [ + "DEPRECATED" + ], "command_flags": [ "ADMIN", "LOADING", diff --git a/src/commands/slowlog.json b/src/commands/slowlog.json index 1b9526b191..0120d55eda 100644 --- a/src/commands/slowlog.json +++ b/src/commands/slowlog.json @@ -4,6 +4,11 @@ "complexity": "Depends on subcommand.", "group": "server", "since": "2.2.12", - "arity": -2 + "arity": -2, + "deprecated_since": "8.1.0", + "replaced_by": "`COMMANDLOG`", + "doc_flags": [ + "DEPRECATED" + ] } } diff --git a/src/config.c b/src/config.c index 5b90ebbd60..6bbb82bf52 100644 --- a/src/config.c +++ b/src/config.c @@ -818,7 +818,7 @@ void configSetCommand(client *c) { /* Note: it's important we run over ALL passed configs and check if we need to call * `redactClientCommandArgument()`. This is in order to avoid anyone using this command for a - * log/slowlog/monitor/etc. displaying sensitive info. So even if we encounter an error we still continue + * log/commandlog/monitor/etc. displaying sensitive info. So even if we encounter an error we still continue * running over the remaining arguments. */ if (config->flags & SENSITIVE_CONFIG) { redactClientCommandArgument(c, 2 + i * 2 + 1); @@ -3302,7 +3302,9 @@ standardConfig static_configs[] = { /* Unsigned Long configs */ createULongConfig("active-defrag-max-scan-fields", NULL, MODIFIABLE_CONFIG, 1, LONG_MAX, server.active_defrag_max_scan_fields, 1000, INTEGER_CONFIG, NULL, NULL), /* Default: keys with more than 1000 fields will be processed separately */ - createULongConfig("slowlog-max-len", NULL, MODIFIABLE_CONFIG, 0, LONG_MAX, server.slowlog_max_len, 128, INTEGER_CONFIG, NULL, NULL), + createULongConfig("commandlog-slow-execution-max-len", "slowlog-max-len", MODIFIABLE_CONFIG, 0, LONG_MAX, server.commandlog[COMMANDLOG_TYPE_SLOW].max_len, 128, INTEGER_CONFIG, NULL, NULL), + createULongConfig("commandlog-large-request-max-len", NULL, MODIFIABLE_CONFIG, 0, LONG_MAX, server.commandlog[COMMANDLOG_TYPE_LARGE_REQUEST].max_len, 128, INTEGER_CONFIG, NULL, NULL), + createULongConfig("commandlog-large-reply-max-len", NULL, MODIFIABLE_CONFIG, 0, LONG_MAX, server.commandlog[COMMANDLOG_TYPE_LARGE_REPLY].max_len, 128, INTEGER_CONFIG, NULL, NULL), createULongConfig("acllog-max-len", NULL, MODIFIABLE_CONFIG, 0, LONG_MAX, server.acllog_max_len, 128, INTEGER_CONFIG, NULL, NULL), createULongConfig("cluster-blacklist-ttl", NULL, MODIFIABLE_CONFIG, 0, ULONG_MAX, server.cluster_blacklist_ttl, 60, INTEGER_CONFIG, NULL, NULL), @@ -3310,7 +3312,9 @@ standardConfig static_configs[] = { createLongLongConfig("busy-reply-threshold", "lua-time-limit", MODIFIABLE_CONFIG, 0, LONG_MAX, server.busy_reply_threshold, 5000, INTEGER_CONFIG, NULL, NULL), /* milliseconds */ createLongLongConfig("cluster-node-timeout", NULL, MODIFIABLE_CONFIG, 0, LLONG_MAX, server.cluster_node_timeout, 15000, INTEGER_CONFIG, NULL, NULL), createLongLongConfig("cluster-ping-interval", NULL, MODIFIABLE_CONFIG | HIDDEN_CONFIG, 0, LLONG_MAX, server.cluster_ping_interval, 0, INTEGER_CONFIG, NULL, NULL), - createLongLongConfig("slowlog-log-slower-than", NULL, MODIFIABLE_CONFIG, -1, LLONG_MAX, server.slowlog_log_slower_than, 10000, INTEGER_CONFIG, NULL, NULL), + createLongLongConfig("commandlog-execution-slower-than", "slowlog-log-slower-than", MODIFIABLE_CONFIG, -1, LLONG_MAX, server.commandlog[COMMANDLOG_TYPE_SLOW].threshold, 10000, INTEGER_CONFIG, NULL, NULL), + createLongLongConfig("commandlog-request-larger-than", NULL, MODIFIABLE_CONFIG, -1, LLONG_MAX, server.commandlog[COMMANDLOG_TYPE_LARGE_REQUEST].threshold, 1024 * 1024, INTEGER_CONFIG, NULL, NULL), + createLongLongConfig("commandlog-reply-larger-than", NULL, MODIFIABLE_CONFIG, -1, LLONG_MAX, server.commandlog[COMMANDLOG_TYPE_LARGE_REPLY].threshold, 1024 * 1024, INTEGER_CONFIG, NULL, NULL), createLongLongConfig("latency-monitor-threshold", NULL, MODIFIABLE_CONFIG, 0, LLONG_MAX, server.latency_monitor_threshold, 0, INTEGER_CONFIG, NULL, NULL), createLongLongConfig("proto-max-bulk-len", NULL, DEBUG_CONFIG | MODIFIABLE_CONFIG, 1024 * 1024, LONG_MAX, server.proto_max_bulk_len, 512ll * 1024 * 1024, MEMORY_CONFIG, NULL, NULL), /* Bulk request max size */ createLongLongConfig("stream-node-max-entries", NULL, MODIFIABLE_CONFIG, 0, LLONG_MAX, server.stream_node_max_entries, 100, INTEGER_CONFIG, NULL, NULL), diff --git a/src/latency.c b/src/latency.c index 2beb4859d1..812be28249 100644 --- a/src/latency.c +++ b/src/latency.c @@ -266,10 +266,10 @@ sds createLatencyReport(void) { /* Potentially commands. */ if (!strcasecmp(event, "command")) { - if (server.slowlog_log_slower_than < 0 || server.slowlog_max_len == 0) { + if (server.commandlog[COMMANDLOG_TYPE_SLOW].threshold < 0 || server.commandlog[COMMANDLOG_TYPE_SLOW].max_len == 0) { advise_slowlog_enabled = 1; advices++; - } else if (server.slowlog_log_slower_than / 1000 > server.latency_monitor_threshold) { + } else if (server.commandlog[COMMANDLOG_TYPE_SLOW].threshold / 1000 > server.latency_monitor_threshold) { advise_slowlog_tuning = 1; advices++; } diff --git a/src/module.c b/src/module.c index 75dcd81cd6..d03be51b87 100644 --- a/src/module.c +++ b/src/module.c @@ -53,7 +53,7 @@ #include "server.h" #include "cluster.h" -#include "slowlog.h" +#include "commandlog.h" #include "rdb.h" #include "monotonic.h" #include "script.h" @@ -1221,7 +1221,8 @@ int64_t commandFlagsFromString(char *s) { else if (!strcasecmp(t,"blocking")) flags |= CMD_BLOCKING; else if (!strcasecmp(t,"allow-stale")) flags |= CMD_STALE; else if (!strcasecmp(t,"no-monitor")) flags |= CMD_SKIP_MONITOR; - else if (!strcasecmp(t,"no-slowlog")) flags |= CMD_SKIP_SLOWLOG; + else if (!strcasecmp(t,"no-slowlog")) flags |= CMD_SKIP_COMMANDLOG; + else if (!strcasecmp(t,"no-commandlog")) flags |= CMD_SKIP_COMMANDLOG; else if (!strcasecmp(t,"fast")) flags |= CMD_FAST; else if (!strcasecmp(t,"no-auth")) flags |= CMD_NO_AUTH; else if (!strcasecmp(t,"may-replicate")) flags |= CMD_MAY_REPLICATE; @@ -1296,7 +1297,8 @@ ValkeyModuleCommand *moduleCreateCommandProxy(struct ValkeyModule *module, * this means. * * **"no-monitor"**: Don't propagate the command on monitor. Use this if * the command has sensitive data among the arguments. - * * **"no-slowlog"**: Don't log this command in the slowlog. Use this if + * * **"no-slowlog"**: Deprecated, please use "no-commandlog". + * * **"no-commandlog"**: Don't log this command in the commandlog. Use this if * the command has sensitive data among the arguments. * * **"fast"**: The command time complexity is not greater * than O(log(N)) where N is the size of the collection or diff --git a/src/multi.c b/src/multi.c index 9e3aad9d3c..0318c418cc 100644 --- a/src/multi.c +++ b/src/multi.c @@ -250,7 +250,7 @@ void execCommand(client *c) { c->mstate->commands[j].argv_len = c->argv_len; c->mstate->commands[j].cmd = c->cmd; - /* The original argv has already been processed for slowlog and monitor, + /* The original argv has already been processed for commandlog and monitor, * so we can safely free it before proceeding to the next command. */ freeClientOriginalArgv(c); } diff --git a/src/networking.c b/src/networking.c index 0ff0fed4c0..093d579ef4 100644 --- a/src/networking.c +++ b/src/networking.c @@ -4297,7 +4297,7 @@ void securityWarningCommand(client *c) { freeClientAsync(c); } -/* This function preserves the original command arguments for accurate slowlog recording. +/* This function preserves the original command arguments for accurate commandlog recording. * * It performs the following operations: * - Stores the initial command vector if not already saved @@ -4348,7 +4348,7 @@ static void backupAndUpdateClientArgv(client *c, int new_argc, robj **new_argv) } /* Redact a given argument to prevent it from being shown - * in the slowlog. This information is stored in the + * in the commandlog. This information is stored in the * original_argv array. */ void redactClientCommandArgument(client *c, int argc) { backupAndUpdateClientArgv(c, c->argc, NULL); diff --git a/src/server.c b/src/server.c index 144841eff9..cedfae088b 100644 --- a/src/server.c +++ b/src/server.c @@ -31,7 +31,7 @@ #include "monotonic.h" #include "cluster.h" #include "cluster_slot_stats.h" -#include "slowlog.h" +#include "commandlog.h" #include "bio.h" #include "latency.h" #include "mt19937-64.h" @@ -2906,7 +2906,7 @@ void initServer(void) { if (functionsInit() == C_ERR) { serverPanic("Functions initialization failed, check the server logs."); } - slowlogInit(); + commandlogInit(); latencyMonitorInit(); initSharedQueryBuf(); @@ -3476,25 +3476,6 @@ void preventCommandReplication(client *c) { c->flag.prevent_repl_prop = 1; } -/* Log the last command a client executed into the slowlog. */ -void slowlogPushCurrentCommand(client *c, struct serverCommand *cmd, ustime_t duration) { - /* Some commands may contain sensitive data that should not be available in the slowlog. */ - if (cmd->flags & CMD_SKIP_SLOWLOG) return; - - /* If command argument vector was rewritten, use the original - * arguments. */ - robj **argv = c->original_argv ? c->original_argv : c->argv; - int argc = c->original_argv ? c->original_argc : c->argc; - - /* If a script is currently running, the client passed in is a - * fake client. Or the client passed in is the original client - * if this is a EVAL or alike, doesn't matter. In this case, - * use the original client to get the client information. */ - c = scriptIsRunning() ? scriptGetCaller() : c; - - slowlogPushEntryIfNeeded(c, argv, argc, duration); -} - /* This function is called in order to update the total command histogram duration. * The latency unit is nano-seconds. * If needed it will allocate the histogram memory and trim the duration to the upper/lower tracking limits*/ @@ -3648,7 +3629,7 @@ void call(client *c, int flags) { server.executing_client = c; /* When call() is issued during loading the AOF we don't want commands called - * from module, exec or LUA to go into the slowlog or to populate statistics. */ + * from module, exec or LUA to go into the commandlog or to populate statistics. */ int update_command_stats = !isAOFLoadingContext(); /* We want to be aware of a client which is making a first time attempt to execute this command @@ -3745,9 +3726,9 @@ void call(client *c, int flags) { if (server.execution_nesting == 0) durationAddSample(EL_DURATION_TYPE_CMD, duration); } - /* Log the command into the Slow log if needed. - * If the client is blocked we will handle slowlog when it is unblocked. */ - if (update_command_stats && !c->flag.blocked) slowlogPushCurrentCommand(c, real_cmd, c->duration); + /* Log the command into the commandlog if needed. + * If the client is blocked we will handle commandlog when it is unblocked. */ + if (update_command_stats && !c->flag.blocked) commandlogPushCurrentCommand(c, real_cmd); /* Send the command to clients in MONITOR mode if applicable, * since some administrative commands are considered too dangerous to be shown. @@ -4714,7 +4695,7 @@ void addReplyFlagsForCommand(client *c, struct serverCommand *cmd) { {CMD_LOADING, "loading"}, {CMD_STALE, "stale"}, {CMD_SKIP_MONITOR, "skip_monitor"}, - {CMD_SKIP_SLOWLOG, "skip_slowlog"}, + {CMD_SKIP_COMMANDLOG, "skip_commandlog"}, {CMD_ASKING, "asking"}, {CMD_FAST, "fast"}, {CMD_NO_AUTH, "no_auth"}, diff --git a/src/server.h b/src/server.h index 8f4fb6a6b4..f5a4d4951b 100644 --- a/src/server.h +++ b/src/server.h @@ -230,7 +230,7 @@ extern int configOOMScoreAdjValuesDefaults[CONFIG_OOM_COUNT]; #define CMD_LOADING (1ULL << 9) #define CMD_STALE (1ULL << 10) #define CMD_SKIP_MONITOR (1ULL << 11) -#define CMD_SKIP_SLOWLOG (1ULL << 12) +#define CMD_SKIP_COMMANDLOG (1ULL << 12) #define CMD_ASKING (1ULL << 13) #define CMD_FAST (1ULL << 14) #define CMD_NO_AUTH (1ULL << 15) @@ -382,6 +382,22 @@ typedef enum blocking_type { buffer configuration. Just the first \ three: normal, replica, pubsub. */ +/* Type of commandlog */ +typedef enum { + COMMANDLOG_TYPE_SLOW = 0, + COMMANDLOG_TYPE_LARGE_REQUEST, + COMMANDLOG_TYPE_LARGE_REPLY, + COMMANDLOG_TYPE_NUM +} commandlog_type; + +/* Configuration and entry list of different types of command logs */ +typedef struct commandlog { + list *entries; + long long entry_id; + long long threshold; + unsigned long max_len; +} commandlog; + /* Replica replication state. Used in server.repl_state for replicas to remember * what to do next. */ typedef enum { @@ -1688,10 +1704,7 @@ struct valkeyServer { long long stat_sync_full; /* Number of full resyncs with replicas. */ long long stat_sync_partial_ok; /* Number of accepted PSYNC requests. */ long long stat_sync_partial_err; /* Number of unaccepted PSYNC requests. */ - list *slowlog; /* SLOWLOG list of commands */ - long long slowlog_entry_id; /* SLOWLOG current entry ID */ - long long slowlog_log_slower_than; /* SLOWLOG time limit (to get logged) */ - unsigned long slowlog_max_len; /* SLOWLOG max number of items logged */ + commandlog commandlog[COMMANDLOG_TYPE_NUM]; /* Logs of commands. */ struct malloc_stats cron_malloc_stats; /* sampled in serverCron(). */ long long stat_net_input_bytes; /* Bytes read from network. */ long long stat_net_output_bytes; /* Bytes written to network. */ @@ -2339,7 +2352,7 @@ typedef int serverGetKeysProc(struct serverCommand *cmd, robj **argv, int argc, * * CMD_SKIP_MONITOR: Do not automatically propagate the command on MONITOR. * - * CMD_SKIP_SLOWLOG: Do not automatically propagate the command to the slowlog. + * CMD_SKIP_COMMANDLOG: Do not automatically propagate the command to the commandlog. * * CMD_ASKING: Perform an implicit ASKING for this command, so the * command will be accepted in cluster mode if the slot is marked @@ -3151,7 +3164,7 @@ void forceCommandPropagation(client *c, int flags); void preventCommandPropagation(client *c); void preventCommandAOF(client *c); void preventCommandReplication(client *c); -void slowlogPushCurrentCommand(client *c, struct serverCommand *cmd, ustime_t duration); +void commandlogPushCurrentCommand(client *c, struct serverCommand *cmd); void updateCommandLatencyHistogram(struct hdr_histogram **latency_histogram, int64_t duration_hist); int prepareForShutdown(client *c, int flags); void replyToClientsBlockedOnShutdown(void); @@ -3632,6 +3645,7 @@ void bgsaveCommand(client *c); void bgrewriteaofCommand(client *c); void shutdownCommand(client *c); void slowlogCommand(client *c); +void commandlogCommand(client *c); void moveCommand(client *c); void copyCommand(client *c); void renameCommand(client *c); diff --git a/src/slowlog.c b/src/slowlog.c deleted file mode 100644 index b98a2dda43..0000000000 --- a/src/slowlog.c +++ /dev/null @@ -1,193 +0,0 @@ -/* Slowlog implements a system that is able to remember the latest N - * queries that took more than M microseconds to execute. - * - * The execution time to reach to be logged in the slow log is set - * using the 'slowlog-log-slower-than' config directive, that is also - * readable and writable using the CONFIG SET/GET command. - * - * The slow queries log is actually not "logged" in the server log file - * but is accessible thanks to the SLOWLOG command. - * - * ---------------------------------------------------------------------------- - * - * Copyright (c) 2009-2012, 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. - */ - -#include "slowlog.h" - -/* Create a new slowlog entry. - * Incrementing the ref count of all the objects retained is up to - * this function. */ -slowlogEntry *slowlogCreateEntry(client *c, robj **argv, int argc, long long duration) { - slowlogEntry *se = zmalloc(sizeof(*se)); - int j, slargc = argc; - - if (slargc > SLOWLOG_ENTRY_MAX_ARGC) slargc = SLOWLOG_ENTRY_MAX_ARGC; - se->argc = slargc; - se->argv = zmalloc(sizeof(robj *) * slargc); - for (j = 0; j < slargc; j++) { - /* Logging too many arguments is a useless memory waste, so we stop - * at SLOWLOG_ENTRY_MAX_ARGC, but use the last argument to specify - * how many remaining arguments there were in the original command. */ - if (slargc != argc && j == slargc - 1) { - se->argv[j] = - createObject(OBJ_STRING, sdscatprintf(sdsempty(), "... (%d more arguments)", argc - slargc + 1)); - } else { - /* Trim too long strings as well... */ - if (argv[j]->type == OBJ_STRING && sdsEncodedObject(argv[j]) && - sdslen(argv[j]->ptr) > SLOWLOG_ENTRY_MAX_STRING) { - sds s = sdsnewlen(argv[j]->ptr, SLOWLOG_ENTRY_MAX_STRING); - - s = sdscatprintf(s, "... (%lu more bytes)", - (unsigned long)sdslen(argv[j]->ptr) - SLOWLOG_ENTRY_MAX_STRING); - se->argv[j] = createObject(OBJ_STRING, s); - } else if (argv[j]->refcount == OBJ_SHARED_REFCOUNT) { - se->argv[j] = argv[j]; - } else { - /* Here we need to duplicate the string objects composing the - * argument vector of the command, because those may otherwise - * end shared with string objects stored into keys. Having - * shared objects between any part of the server, and the data - * structure holding the data, is a problem: FLUSHALL ASYNC - * may release the shared string object and create a race. */ - se->argv[j] = dupStringObject(argv[j]); - } - } - } - se->time = time(NULL); - se->duration = duration; - se->id = server.slowlog_entry_id++; - se->peerid = sdsnew(getClientPeerId(c)); - se->cname = c->name ? sdsnew(c->name->ptr) : sdsempty(); - return se; -} - -/* Free a slow log entry. The argument is void so that the prototype of this - * function matches the one of the 'free' method of adlist.c. - * - * This function will take care to release all the retained object. */ -void slowlogFreeEntry(void *septr) { - slowlogEntry *se = septr; - int j; - - for (j = 0; j < se->argc; j++) decrRefCount(se->argv[j]); - zfree(se->argv); - sdsfree(se->peerid); - sdsfree(se->cname); - zfree(se); -} - -/* Initialize the slow log. This function should be called a single time - * at server startup. */ -void slowlogInit(void) { - server.slowlog = listCreate(); - server.slowlog_entry_id = 0; - listSetFreeMethod(server.slowlog, slowlogFreeEntry); -} - -/* Push a new entry into the slow log. - * This function will make sure to trim the slow log accordingly to the - * configured max length. */ -void slowlogPushEntryIfNeeded(client *c, robj **argv, int argc, long long duration) { - if (server.slowlog_log_slower_than < 0 || server.slowlog_max_len == 0) return; /* Slowlog disabled */ - if (duration >= server.slowlog_log_slower_than) - listAddNodeHead(server.slowlog, slowlogCreateEntry(c, argv, argc, duration)); - - /* Remove old entries if needed. */ - while (listLength(server.slowlog) > server.slowlog_max_len) listDelNode(server.slowlog, listLast(server.slowlog)); -} - -/* Remove all the entries from the current slow log. */ -void slowlogReset(void) { - while (listLength(server.slowlog) > 0) listDelNode(server.slowlog, listLast(server.slowlog)); -} - -/* The SLOWLOG command. Implements all the subcommands needed to handle the - * slow log. */ -void slowlogCommand(client *c) { - if (c->argc == 2 && !strcasecmp(c->argv[1]->ptr, "help")) { - const char *help[] = { - "GET []", - " Return top entries from the slowlog (default: 10, -1 mean all).", - " Entries are made of:", - " id, timestamp, time in microseconds, arguments array, client IP and port,", - " client name", - "LEN", - " Return the length of the slowlog.", - "RESET", - " Reset the slowlog.", - NULL, - }; - addReplyHelp(c, help); - } else if (c->argc == 2 && !strcasecmp(c->argv[1]->ptr, "reset")) { - slowlogReset(); - addReply(c, shared.ok); - } else if (c->argc == 2 && !strcasecmp(c->argv[1]->ptr, "len")) { - addReplyLongLong(c, listLength(server.slowlog)); - } else if ((c->argc == 2 || c->argc == 3) && !strcasecmp(c->argv[1]->ptr, "get")) { - long count = 10; - listIter li; - listNode *ln; - slowlogEntry *se; - - if (c->argc == 3) { - /* Consume count arg. */ - if (getRangeLongFromObjectOrReply(c, c->argv[2], -1, LONG_MAX, &count, - "count should be greater than or equal to -1") != C_OK) - return; - - if (count == -1) { - /* We treat -1 as a special value, which means to get all slow logs. - * Simply set count to the length of server.slowlog.*/ - count = listLength(server.slowlog); - } - } - - if (count > (long)listLength(server.slowlog)) { - count = listLength(server.slowlog); - } - addReplyArrayLen(c, count); - listRewind(server.slowlog, &li); - while (count--) { - int j; - - ln = listNext(&li); - se = ln->value; - addReplyArrayLen(c, 6); - addReplyLongLong(c, se->id); - addReplyLongLong(c, se->time); - addReplyLongLong(c, se->duration); - addReplyArrayLen(c, se->argc); - for (j = 0; j < se->argc; j++) addReplyBulk(c, se->argv[j]); - addReplyBulkCBuffer(c, se->peerid, sdslen(se->peerid)); - addReplyBulkCBuffer(c, se->cname, sdslen(se->cname)); - } - } else { - addReplySubcommandSyntaxError(c); - } -} diff --git a/tests/unit/commandlog.tcl b/tests/unit/commandlog.tcl new file mode 100644 index 0000000000..39038d7950 --- /dev/null +++ b/tests/unit/commandlog.tcl @@ -0,0 +1,361 @@ +start_server {tags {"commandlog"} overrides {commandlog-execution-slower-than 1000000 commandlog-request-larger-than 1048576 commandlog-reply-larger-than 1048576}} { + test {COMMANDLOG - check that it starts with an empty log} { + if {$::external} { + r commandlog reset slow + r commandlog reset large-request + r commandlog reset large-reply + } + assert_equal [r commandlog len slow] 0 + assert_equal [r commandlog len large-request] 0 + assert_equal [r commandlog len large-reply] 0 + } + + test {COMMANDLOG - only logs commands exceeding the threshold} { + # for slow + r config set commandlog-execution-slower-than 100000 + r ping + assert_equal [r commandlog len slow] 0 + r debug sleep 0.2 + assert_equal [r commandlog len slow] 1 + + # for large-request + r config set commandlog-request-larger-than 1024 + r ping + assert_equal [r commandlog len large-request] 0 + set value [string repeat A 1024] + r set testkey $value + assert_equal [r commandlog len large-request] 1 + + # for large-reply + r config set commandlog-reply-larger-than 1024 + r ping + assert_equal [r commandlog len large-reply] 0 + r get testkey + assert_equal [r commandlog len large-reply] 1 + } {} {needs:debug} + + test {COMMANDLOG - zero max length is correctly handled} { + r commandlog reset slow + r commandlog reset large-request + r commandlog reset large-reply + r config set commandlog-slow-execution-max-len 0 + r config set commandlog-execution-slower-than 0 + r config set commandlog-large-request-max-len 0 + r config set commandlog-request-larger-than 0 + r config set commandlog-large-reply-max-len 0 + r config set commandlog-reply-larger-than 0 + for {set i 0} {$i < 100} {incr i} { + r ping + } + assert_equal [r commandlog len slow] 0 + assert_equal [r commandlog len large-request] 0 + assert_equal [r commandlog len large-reply] 0 + } + + test {COMMANDLOG - max entries is correctly handled} { + r config set commandlog-execution-slower-than 0 + r config set commandlog-slow-execution-max-len 10 + r config set commandlog-large-request-max-len 10 + r config set commandlog-request-larger-than 0 + r config set commandlog-large-reply-max-len 10 + r config set commandlog-reply-larger-than 0 + for {set i 0} {$i < 100} {incr i} { + r ping + } + assert_equal [r commandlog len slow] 10 + assert_equal [r commandlog len large-request] 10 + assert_equal [r commandlog len large-reply] 10 + } + + test {COMMANDLOG - GET optional argument to limit output len works} { + assert_equal 5 [llength [r commandlog get 5 slow]] + assert_equal 10 [llength [r commandlog get -1 slow]] + assert_equal 10 [llength [r commandlog get 20 slow]] + + assert_equal 5 [llength [r commandlog get 5 large-request]] + assert_equal 10 [llength [r commandlog get -1 large-request]] + assert_equal 10 [llength [r commandlog get 20 large-request]] + + assert_equal 5 [llength [r commandlog get 5 large-reply]] + assert_equal 10 [llength [r commandlog get -1 large-reply]] + assert_equal 10 [llength [r commandlog get 20 large-reply]] + } + + test {COMMANDLOG - RESET subcommand works} { + r config set commandlog-execution-slower-than 100000 + r config set commandlog-request-larger-than 1024 + r config set commandlog-reply-larger-than 1024 + r commandlog reset slow + r commandlog reset large-request + r commandlog reset large-reply + assert_equal [r commandlog len slow] 0 + assert_equal [r commandlog len large-request] 0 + assert_equal [r commandlog len large-reply] 0 + } + + test {COMMANDLOG - logged entry sanity check} { + r client setname foobar + + # for slow + r debug sleep 0.2 + set e [lindex [r commandlog get -1 slow] 0] + assert_equal [llength $e] 6 + if {!$::external} { + assert_equal [lindex $e 0] 118 + } + assert_equal [expr {[lindex $e 2] > 100000}] 1 + assert_equal [lindex $e 3] {debug sleep 0.2} + assert_equal {foobar} [lindex $e 5] + + # for large-request + set value [string repeat A 1024] + r set testkey $value + set e [lindex [r commandlog get -1 large-request] 0] + assert_equal [llength $e] 6 + if {!$::external} { + assert_equal [lindex $e 0] 118 + } + assert_equal [expr {[lindex $e 2] > 1024}] 1 + assert_equal [lindex $e 3] {set testkey {AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA... (896 more bytes)}} + assert_equal {foobar} [lindex $e 5] + + # for large-reply + r get testkey + set e [lindex [r commandlog get -1 large-reply] 0] + assert_equal [llength $e] 6 + if {!$::external} { + assert_equal [lindex $e 0] 117 + } + assert_equal [expr {[lindex $e 2] > 1024}] 1 + assert_equal [lindex $e 3] {get testkey} + assert_equal {foobar} [lindex $e 5] + } {} {needs:debug} + + test {COMMANDLOG slow - Certain commands are omitted that contain sensitive information} { + r config set commandlog-slow-execution-max-len 100 + r config set commandlog-execution-slower-than 0 + r commandlog reset slow + catch {r acl setuser "slowlog test user" +get +set} _ + r config set primaryuser "" + r config set primaryauth "" + r config set requirepass "" + r config set tls-key-file-pass "" + r config set tls-client-key-file-pass "" + r acl setuser slowlog-test-user +get +set + r acl getuser slowlog-test-user + r acl deluser slowlog-test-user non-existing-user + r config set commandlog-execution-slower-than 0 + r config set commandlog-execution-slower-than -1 + set slowlog_resp [r commandlog get -1 slow] + + # Make sure normal configs work, but the two sensitive + # commands are omitted or redacted + assert_equal 11 [llength $slowlog_resp] + assert_equal {commandlog reset slow} [lindex [lindex $slowlog_resp 10] 3] + assert_equal {acl setuser (redacted) (redacted) (redacted)} [lindex [lindex $slowlog_resp 9] 3] + assert_equal {config set primaryuser (redacted)} [lindex [lindex $slowlog_resp 8] 3] + assert_equal {config set primaryauth (redacted)} [lindex [lindex $slowlog_resp 7] 3] + assert_equal {config set requirepass (redacted)} [lindex [lindex $slowlog_resp 6] 3] + assert_equal {config set tls-key-file-pass (redacted)} [lindex [lindex $slowlog_resp 5] 3] + assert_equal {config set tls-client-key-file-pass (redacted)} [lindex [lindex $slowlog_resp 4] 3] + assert_equal {acl setuser (redacted) (redacted) (redacted)} [lindex [lindex $slowlog_resp 3] 3] + assert_equal {acl getuser (redacted)} [lindex [lindex $slowlog_resp 2] 3] + assert_equal {acl deluser (redacted) (redacted)} [lindex [lindex $slowlog_resp 1] 3] + assert_equal {config set commandlog-execution-slower-than 0} [lindex [lindex $slowlog_resp 0] 3] + } {} {needs:repl} + + test {COMMANDLOG slow - Some commands can redact sensitive fields} { + r config set commandlog-execution-slower-than 0 + r commandlog reset slow + r migrate [srv 0 host] [srv 0 port] key 9 5000 + r migrate [srv 0 host] [srv 0 port] key 9 5000 AUTH user + r migrate [srv 0 host] [srv 0 port] key 9 5000 AUTH2 user password + r config set commandlog-execution-slower-than -1 + set slowlog_resp [r commandlog get -1 slow] + + # Make sure all 3 commands were logged, but the sensitive fields are omitted + assert_equal 4 [llength $slowlog_resp] + assert_match {* key 9 5000} [lindex [lindex $slowlog_resp 2] 3] + assert_match {* key 9 5000 AUTH (redacted)} [lindex [lindex $slowlog_resp 1] 3] + assert_match {* key 9 5000 AUTH2 (redacted) (redacted)} [lindex [lindex $slowlog_resp 0] 3] + } {} {needs:repl} + + test {COMMANDLOG slow - Rewritten commands are logged as their original command} { + r config set commandlog-execution-slower-than 0 + + # Test rewriting client arguments + r sadd set a b c d e + r commandlog reset slow + + # SPOP is rewritten as DEL when all keys are removed + r spop set 10 + assert_equal {spop set 10} [lindex [lindex [r commandlog get -1 slow] 0] 3] + + # Test replacing client arguments + r commandlog reset slow + + # GEOADD is replicated as ZADD + r geoadd cool-cities -122.33207 47.60621 Seattle + assert_equal {geoadd cool-cities -122.33207 47.60621 Seattle} [lindex [lindex [r commandlog get -1 slow] 0] 3] + + # Test replacing a single command argument + r set A 5 + r commandlog reset slow + + # GETSET is replicated as SET + r getset a 5 + assert_equal {getset a 5} [lindex [lindex [r commandlog get -1 slow] 0] 3] + + # INCRBYFLOAT calls rewrite multiple times, so it's a special case + r set A 0 + r commandlog reset slow + + # INCRBYFLOAT is replicated as SET + r INCRBYFLOAT A 1.0 + assert_equal {INCRBYFLOAT A 1.0} [lindex [lindex [r commandlog get -1 slow] 0] 3] + + # blocked BLPOP is replicated as LPOP + set rd [valkey_deferring_client] + $rd blpop l 0 + wait_for_blocked_clients_count 1 50 100 + r multi + r lpush l foo + r commandlog reset slow + r exec + $rd read + $rd close + assert_equal {blpop l 0} [lindex [lindex [r commandlog get -1 slow] 0] 3] + } + + test {COMMANDLOG slow - commands with too many arguments are trimmed} { + r config set commandlog-execution-slower-than 0 + r commandlog reset slow + r sadd set 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 + set e [lindex [r commandlog get -1 slow] end-1] + lindex $e 3 + } {sadd set 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 {... (2 more arguments)}} + + test {COMMANDLOG slow - too long arguments are trimmed} { + r config set commandlog-execution-slower-than 0 + r commandlog reset slow + set arg [string repeat A 129] + r sadd set foo $arg + set e [lindex [r commandlog get -1 slow] end-1] + lindex $e 3 + } {sadd set foo {AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA... (1 more bytes)}} + + test {COMMANDLOG slow - EXEC is not logged, just executed commands} { + r config set commandlog-execution-slower-than 100000 + r commandlog reset slow + assert_equal [r commandlog len slow] 0 + r multi + r debug sleep 0.2 + r exec + assert_equal [r commandlog len slow] 1 + set e [lindex [r commandlog get -1 slow] 0] + assert_equal [lindex $e 3] {debug sleep 0.2} + } {} {needs:debug} + + test {COMMANDLOG slow - can clean older entries} { + r client setname lastentry_client + r config set commandlog-slow-execution-max-len 1 + r debug sleep 0.2 + assert {[llength [r commandlog get -1 slow]] == 1} + set e [lindex [r commandlog get -1 slow] 0] + assert_equal {lastentry_client} [lindex $e 5] + } {} {needs:debug} + + test {COMMANDLOG slow - can be disabled} { + r config set commandlog-slow-execution-max-len 1 + r config set commandlog-execution-slower-than 1 + r commandlog reset slow + r debug sleep 0.2 + assert_equal [r commandlog len slow] 1 + r config set commandlog-execution-slower-than -1 + r commandlog reset slow + r debug sleep 0.2 + assert_equal [r commandlog len slow] 0 + } {} {needs:debug} + + test {COMMANDLOG slow - count must be >= -1} { + assert_error "ERR count should be greater than or equal to -1" {r commandlog get -2 slow} + assert_error "ERR count should be greater than or equal to -1" {r commandlog get -222 slow} + } + + test {COMMANDLOG slow - get all slow logs} { + r config set commandlog-execution-slower-than 0 + r config set commandlog-slow-execution-max-len 3 + r commandlog reset slow + + r set key test + r sadd set a b c + r incr num + r lpush list a + + assert_equal [r commandlog len slow] 3 + assert_equal 0 [llength [r commandlog get 0 slow]] + assert_equal 1 [llength [r commandlog get 1 slow]] + assert_equal 3 [llength [r commandlog get -1 slow]] + assert_equal 3 [llength [r commandlog get 3 slow]] + } + + test {COMMANDLOG slow - blocking command is reported only after unblocked} { + # Cleanup first + r del mylist + # create a test client + set rd [valkey_deferring_client] + + # config the slowlog and reset + r config set commandlog-execution-slower-than 0 + r config set commandlog-slow-execution-max-len 110 + r commandlog reset slow + + $rd BLPOP mylist 0 + wait_for_blocked_clients_count 1 50 20 + assert_equal 0 [llength [regexp -all -inline (?=BLPOP) [r commandlog get -1 slow]]] + + r LPUSH mylist 1 + wait_for_blocked_clients_count 0 50 20 + assert_equal 1 [llength [regexp -all -inline (?=BLPOP) [r commandlog get -1 slow]]] + + $rd close + } + + foreach is_eval {0 1} { + test "COMMANDLOG slow - the commands in script are recorded normally - is_eval: $is_eval" { + if {$is_eval == 0} { + r function load replace "#!lua name=mylib \n redis.register_function('myfunc', function(KEYS, ARGS) server.call('ping') end)" + } + + r client setname test-client + r config set commandlog-execution-slower-than 0 + r commandlog reset slow + + if {$is_eval} { + r eval "server.call('ping')" 0 + } else { + r fcall myfunc 0 + } + set slowlog_resp [r commandlog get 2 slow] + assert_equal 2 [llength $slowlog_resp] + + # The first one is the script command, and the second one is the ping command executed in the script + # Each slowlog contains: id, timestamp, execution time, command array, ip:port, client name + set script_cmd [lindex $slowlog_resp 0] + set ping_cmd [lindex $slowlog_resp 1] + + # Make sure the command are logged. + if {$is_eval} { + assert_equal {eval server.call('ping') 0} [lindex $script_cmd 3] + } else { + assert_equal {fcall myfunc 0} [lindex $script_cmd 3] + } + assert_equal {ping} [lindex $ping_cmd 3] + + # Make sure the client info are the logged. + assert_equal [lindex $script_cmd 4] [lindex $ping_cmd 4] + assert_equal {test-client} [lindex $script_cmd 5] + assert_equal {test-client} [lindex $ping_cmd 5] + } + } +} diff --git a/valkey.conf b/valkey.conf index e23aea39de..1838357058 100644 --- a/valkey.conf +++ b/valkey.conf @@ -1969,29 +1969,70 @@ aof-timestamp-enabled no # cluster-announce-port 0 # cluster-announce-bus-port 6380 -################################## SLOW LOG ################################### - -# The server Slow Log is a system to log queries that exceeded a specified -# execution time. The execution time does not include the I/O operations -# like talking with the client, sending the reply and so forth, -# but just the time needed to actually execute the command (this is the only -# stage of command execution where the thread is blocked and can not serve -# other requests in the meantime). -# -# You can configure the slow log with two parameters: one tells the server -# what is the execution time, in microseconds, to exceed in order for the -# command to get logged, and the other parameter is the length of the -# slow log. When a new command is logged the oldest one is removed from the -# queue of logged commands. - -# The following time is expressed in microseconds, so 1000000 is equivalent -# to one second. Note that a negative number disables the slow log, while -# a value of zero forces the logging of every command. -slowlog-log-slower-than 10000 - +################################## COMMAND LOG ################################### + +# The Command Log system is used to record commands that consume significant resources +# during server operation, including CPU, memory, and network bandwidth. +# These commands and the data they access may lead to abnormal instance operations, +# the commandlog can help users quickly and intuitively locate issues. +# +# Currently, three types of command logs are supported: +# +# SLOW: Logs commands that exceed a specified execution time. This excludes time spent +# on I/O operations like client communication and focuses solely on the command's +# processing time, where the main thread is blocked. +# +# LARGE-REQUEST: Logs commands with requests exceeding a defined size. This helps +# identify potentially problematic commands that send excessive data to the server. +# +# LARGE-REPLY: Logs commands that generate replies exceeding a defined size. This +# helps identify commands that return unusually large amounts of data, which may +# impact network performance or client processing. +# +# Each log type has two key parameters: +# 1. A threshold value that determines when a command is logged. This threshold is specific +# to the type of log (e.g., execution time, request size, or reply size). A negative value disables +# logging. A value of 0 logs all commands. +# 2. A maximum length that specifies the number of entries to retain in the log. Increasing +# the length allows more entries to be stored but consumes additional memory. To clear all +# entries for a specific log type and reclaim memory, use the `COMMANDLOG RESET` +# subcommand followed by the log type. +# +# SLOW Command Logs +# The SLOW log records commands that exceed a specified execution time. The execution time +# does not include I/O operations, such as client communication or sending responses. +# It only measures the time spent executing the command, during which the thread is blocked +# and cannot handle other requests. +# +# The threshold is measured in microseconds. +# +# Backward Compatibility: The parameter `slowlog-log-slower-than` is still supported but +# deprecated in favor of `commandlog-slow-execution`. +commandlog-execution-slower-than 10000 # There is no limit to this length. Just be aware that it will consume memory. -# You can reclaim memory used by the slow log with SLOWLOG RESET. -slowlog-max-len 128 +# You can reclaim memory used by the slow log with SLOWLOG RESET or COMMANDLOG RESET SLOW. +commandlog-slow-execution-max-len 128 +# +# LARGE_REQUEST Command Logs +# The LARGE_REQUEST log tracks commands with requests exceeding a specified size. The request size +# includes the command itself and all its arguments. For example, in `SET KEY VALUE`, the size is +# determined by the combined size of the key and value. Commands that consume excessive network +# bandwidth or query buffer space are recorded here. +# +# The threshold is measured in bytes. +commandlog-request-larger-than 1048576 +# Record the number of commands. +commandlog-large-request-max-len 128 +# +# LARGE_REPLY Command Logs +# The LARGE_REPLY log records commands that produce replies exceeding a specified size. These replies +# may consume significant network bandwidth or client output buffer space. Examples include commands +# like `KEYS` or `HGETALL` that return large datasets. Even a `GET` command may qualify if the value +# is substantial. +# +# The threshold is measured in bytes. +commandlog-reply-larger-than 1048576 +commandlog-large-reply-max-len 128 ################################ LATENCY MONITOR ##############################