diff --git a/src/Makefile b/src/Makefile index 4a6f27ebad486232f543dd1c8947ae7b28f8b2a0..3636f032dfa58bff98486f9693e1d98bcad3c781 100644 --- a/src/Makefile +++ b/src/Makefile @@ -61,7 +61,7 @@ QUIET_CC = @printf ' %b %b\n' $(CCCOLOR)CC$(ENDCOLOR) $(SRCCOLOR)$@$(ENDCOLOR QUIET_LINK = @printf ' %b %b\n' $(LINKCOLOR)LINK$(ENDCOLOR) $(BINCOLOR)$@$(ENDCOLOR); endif -OBJ = adlist.o ae.o anet.o dict.o redis.o sds.o zmalloc.o lzf_c.o lzf_d.o pqsort.o zipmap.o sha1.o ziplist.o release.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 crc16.o endian.o +OBJ = adlist.o ae.o anet.o dict.o redis.o sds.o zmalloc.o lzf_c.o lzf_d.o pqsort.o zipmap.o sha1.o ziplist.o release.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 crc16.o endian.o slowlog.o BENCHOBJ = ae.o anet.o redis-benchmark.o sds.o adlist.o zmalloc.o CLIOBJ = anet.o sds.o adlist.o redis-cli.o zmalloc.o release.o CHECKDUMPOBJ = redis-check-dump.o lzf_c.o lzf_d.o @@ -86,38 +86,37 @@ ae_kqueue.o: ae_kqueue.c ae_select.o: ae_select.c anet.o: anet.c fmacros.h anet.h aof.o: aof.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h cluster.o: cluster.c redis.h fmacros.h config.h ae.h sds.h dict.h \ - adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h \ + slowlog.h config.o: config.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h crc16.o: crc16.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h db.o: db.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h debug.o: debug.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h sha1.h -dict.o: dict.c fmacros.h dict.h zmalloc.h -diskstore.o: diskstore.c redis.h fmacros.h config.h ae.h sds.h dict.h \ - adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h \ + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h \ sha1.h -dscache.o: dscache.c redis.h fmacros.h config.h ae.h sds.h dict.h \ - adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h +dict.o: dict.c fmacros.h dict.h zmalloc.h endian.o: endian.c intset.o: intset.c intset.h zmalloc.h endian.h lzf_c.o: lzf_c.c lzfP.h lzf_d.o: lzf_d.c lzfP.h multi.o: multi.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h networking.o: networking.c redis.h fmacros.h config.h ae.h sds.h dict.h \ - adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h \ + slowlog.h object.o: object.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h pqsort.o: pqsort.c pubsub.o: pubsub.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h rdb.o: rdb.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h lzf.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h \ + lzf.h redis-benchmark.o: redis-benchmark.c fmacros.h ae.h \ ../deps/hiredis/hiredis.h sds.h adlist.h zmalloc.h redis-check-aof.o: redis-check-aof.c fmacros.h config.h @@ -125,27 +124,33 @@ redis-check-dump.o: redis-check-dump.c lzf.h redis-cli.o: redis-cli.c fmacros.h version.h ../deps/hiredis/hiredis.h \ sds.h zmalloc.h ../deps/linenoise/linenoise.h help.h redis.o: redis.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h \ + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h \ asciilogo.h release.o: release.c release.h replication.o: replication.c redis.h fmacros.h config.h ae.h sds.h dict.h \ - adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h \ + slowlog.h sds.o: sds.c sds.h zmalloc.h sha1.o: sha1.c sha1.h config.h +slowlog.o: slowlog.c redis.h fmacros.h config.h ae.h sds.h dict.h \ + adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h \ + slowlog.h sort.o: sort.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h pqsort.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h \ + pqsort.h syncio.o: syncio.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h t_hash.o: t_hash.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h t_list.o: t_list.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h t_set.o: t_set.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h t_string.o: t_string.c redis.h fmacros.h config.h ae.h sds.h dict.h \ - adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + adlist.h zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h \ + slowlog.h t_zset.o: t_zset.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \ - zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h + zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h util.h slowlog.h util.o: util.c fmacros.h util.h ziplist.o: ziplist.c zmalloc.h util.h ziplist.h endian.h zipmap.o: zipmap.c zmalloc.h endian.h diff --git a/src/redis.c b/src/redis.c index 89efffbabd844aec36ee4d06b220918a2c0acf5d..0b0e4db46a8576b069a9c283e40ee5631184a9f0 100644 --- a/src/redis.c +++ b/src/redis.c @@ -28,6 +28,7 @@ */ #include "redis.h" +#include "slowlog.h" #ifdef HAVE_BACKTRACE #include @@ -192,7 +193,8 @@ struct redisCommand redisCommandTable[] = { {"migrate",migrateCommand,6,0,NULL,0,0,0,0,0}, {"dump",dumpCommand,2,0,NULL,0,0,0,0,0}, {"object",objectCommand,-2,0,NULL,0,0,0,0,0}, - {"client",clientCommand,-2,0,NULL,0,0,0,0,0} + {"client",clientCommand,-2,0,NULL,0,0,0,0,0}, + {"slowlog",slowlogCommand,-2,0,NULL,0,0,0,0,0} }; /*============================ Utility functions ============================ */ @@ -866,6 +868,10 @@ void initServerConfig() { populateCommandTable(); server.delCommand = lookupCommandByCString("del"); server.multiCommand = lookupCommandByCString("multi"); + + /* Slow log */ + server.slowlog_log_slower_than = REDIS_SLOWLOG_LOG_SLOWER_THAN; + server.slowlog_max_len = REDIS_SLOWLOG_MAX_LEN; } void initServer() { @@ -952,6 +958,7 @@ void initServer() { } if (server.cluster_enabled) clusterInit(); + slowlogInit(); srand(time(NULL)^getpid()); } @@ -999,12 +1006,14 @@ struct redisCommand *lookupCommandByCString(char *s) { /* Call() is the core of Redis execution of a command */ void call(redisClient *c, struct redisCommand *cmd) { - long long dirty, start = ustime(); + long long dirty, start = ustime(), duration; dirty = server.dirty; cmd->proc(c); dirty = server.dirty-dirty; - cmd->microseconds += ustime()-start; + duration = ustime()-start; + cmd->microseconds += duration; + slowlogPushEntryIfNeeded(c->argv,c->argc,duration); cmd->calls++; if (server.appendonly && dirty) diff --git a/src/redis.h b/src/redis.h index a5cd15edab1eb5b1f51b4b307b620a1788652005..e74144f22c35524c0edfe8526b2c3b706a5a21d9 100644 --- a/src/redis.h +++ b/src/redis.h @@ -20,17 +20,17 @@ #include #include -#include "ae.h" /* Event driven programming library */ -#include "sds.h" /* Dynamic safe strings */ -#include "dict.h" /* Hash tables */ -#include "adlist.h" /* Linked lists */ +#include "ae.h" /* Event driven programming library */ +#include "sds.h" /* Dynamic safe strings */ +#include "dict.h" /* Hash tables */ +#include "adlist.h" /* Linked lists */ #include "zmalloc.h" /* total memory usage aware version of malloc/free */ -#include "anet.h" /* Networking the easy way */ -#include "zipmap.h" /* Compact string -> string data structure */ +#include "anet.h" /* Networking the easy way */ +#include "zipmap.h" /* Compact string -> string data structure */ #include "ziplist.h" /* Compact list data structure */ -#include "intset.h" /* Compact integer set structure */ -#include "version.h" -#include "util.h" +#include "intset.h" /* Compact integer set structure */ +#include "version.h" /* Version macro */ +#include "util.h" /* Misc functions useful in many places */ /* Error codes */ #define REDIS_OK 0 @@ -52,6 +52,8 @@ #define REDIS_MAX_LOGMSG_LEN 1024 /* Default maximum length of syslog messages */ #define REDIS_AUTO_AOFREWRITE_PERC 100 #define REDIS_AUTO_AOFREWRITE_MIN_SIZE (1024*1024) +#define REDIS_SLOWLOG_LOG_SLOWER_THAN 10000 +#define REDIS_SLOWLOG_MAX_LEN 64 /* Hash table parameters */ #define REDIS_HT_MINFILL 10 /* Minimal hash table fill 10% */ @@ -525,6 +527,9 @@ struct redisServer { long long stat_keyspace_misses; /* number of failed lookups of keys */ size_t stat_peak_memory; /* max used memory record */ long long stat_fork_time; /* time needed to perform latets fork() */ + list *slowlog; + long long slowlog_log_slower_than; + unsigned int slowlog_max_len; /* Configuration */ int verbosity; int maxidletime; diff --git a/src/slowlog.c b/src/slowlog.c new file mode 100644 index 0000000000000000000000000000000000000000..ecaf65080838c794d6bfb110404412e58f5c77d6 --- /dev/null +++ b/src/slowlog.c @@ -0,0 +1,111 @@ +#include "redis.h" +#include "slowlog.h" + +/* 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 Redis log file + * but is accessible thanks to the SLOWLOG command. */ + +/* Create a new slowlog entry. + * Incrementing the ref count of all the objects retained is up to + * this function. */ +slowlogEntry *slowlogCreateEntry(robj **argv, int argc, long long duration) { + slowlogEntry *se = zmalloc(sizeof(*se)); + int j; + + se->argc = argc; + se->argv = zmalloc(sizeof(robj*)*argc); + for (j = 0; j < argc; j++) { + se->argv[j] = argv[j]; + incrRefCount(argv[j]); + } + se->time = time(NULL); + se->duration = duration; + 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); + zfree(se); +} + +/* Initialize the slow log. This function should be called a single time + * at server startup. */ +void slowlogInit(void) { + server.slowlog = listCreate(); + 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(robj **argv, int argc, long long duration) { + if (duration > server.slowlog_log_slower_than) + listAddNodeHead(server.slowlog,slowlogCreateEntry(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 + * Redis slow log. */ +void slowlogCommand(redisClient *c) { + 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, sent = 0; + listIter li; + void *totentries; + listNode *ln; + slowlogEntry *se; + + if (c->argc == 3 && + getLongFromObjectOrReply(c,c->argv[2],&count,NULL) != REDIS_OK) + return; + + listRewind(server.slowlog,&li); + totentries = addDeferredMultiBulkLength(c); + while(count-- && (ln = listNext(&li))) { + int j; + + se = ln->value; + addReplyMultiBulkLen(c,3); + addReplyLongLong(c,se->time); + addReplyLongLong(c,se->duration); + addReplyMultiBulkLen(c,se->argc); + for (j = 0; j < se->argc; j++) + addReplyBulk(c,se->argv[j]); + sent++; + } + setDeferredMultiBulkLength(c,totentries,sent); + } else { + addReplyError(c, + "Unknown SLOWLOG subcommand or wrong # of args. Try GET, RESET, LEN."); + } +} diff --git a/src/slowlog.h b/src/slowlog.h new file mode 100644 index 0000000000000000000000000000000000000000..45a500555df828324c47d3c782f3f17b24cc7452 --- /dev/null +++ b/src/slowlog.h @@ -0,0 +1,14 @@ +/* This structure defines an entry inside the slow log list */ +typedef struct slowlogEntry { + robj **argv; + int argc; + long long duration; /* Time spent by the query, in nanoseconds. */ + time_t time; /* Unix time at which the query was executed. */ +} slowlogEntry; + +/* Exported API */ +void slowlogInit(void); +void slowlogPushEntryIfNeeded(robj **argv, int argc, long long duration); + +/* Exported commands */ +void slowlogCommand(redisClient *c);