Permalink
Browse files

slow log merged into 2.4

  • Loading branch information...
1 parent c755c63 commit 99509ab2576210ae00d4fcfcb831741afd314ace @antirez antirez committed Jul 1, 2011
Showing with 253 additions and 8 deletions.
  1. +3 −3 deps/hiredis/hiredis.c
  2. +24 −0 redis.conf
  3. +6 −3 src/Makefile
  4. +22 −0 src/config.c
  5. +6 −0 src/debug.c
  6. +11 −2 src/redis.c
  7. +9 −0 src/redis.h
  8. +115 −0 src/slowlog.c
  9. +15 −0 src/slowlog.h
  10. +1 −0 tests/test_helper.tcl
  11. +41 −0 tests/unit/slowlog.tcl
View
@@ -50,7 +50,7 @@ typedef struct redisReader {
size_t pos; /* buffer cursor */
size_t len; /* buffer length */
- redisReadTask rstack[3]; /* stack of read tasks */
+ redisReadTask rstack[9]; /* stack of read tasks */
int ridx; /* index of stack */
void *privdata; /* user-settable arbitrary field */
} redisReader;
@@ -347,9 +347,9 @@ static int processMultiBulkItem(redisReader *r) {
int root = 0;
/* Set error for nested multi bulks with depth > 1 */
- if (r->ridx == 2) {
+ if (r->ridx == 8) {
redisSetReplyReaderError(r,sdscatprintf(sdsempty(),
- "No support for nested multi bulk replies with depth > 1"));
+ "No support for nested multi bulk replies with depth > 7"));
return -1;
}
View
@@ -312,6 +312,30 @@ no-appendfsync-on-rewrite no
auto-aof-rewrite-percentage 100
auto-aof-rewrite-min-size 64mb
+################################## SLOW LOG ###################################
+
+# The Redis 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 Redis
+# 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
+
+# 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-log-len 1024
+
################################ VIRTUAL MEMORY ###############################
### WARNING! Virtual Memory is deprecated in Redis 2.4
View
@@ -58,7 +58,7 @@ PREFIX= /usr/local
INSTALL_BIN= $(PREFIX)/bin
INSTALL= cp -p
-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 vm.o pubsub.o multi.o debug.o sort.o intset.o syncio.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 vm.o pubsub.o multi.o debug.o sort.o intset.o syncio.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
@@ -113,12 +113,15 @@ redis-check-aof.o: redis-check-aof.c fmacros.h config.h
redis-check-dump.o: redis-check-dump.c lzf.h
redis-cli.o: redis-cli.c fmacros.h version.h help.h sds.c sds.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
+ zmalloc.h anet.h zipmap.h ziplist.h intset.h version.h slowlog.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
sds.o: sds.c sds.h zmalloc.h
sha1.o: sha1.c sha1.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 \
+ 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 pqsort.h
syncio.o: syncio.c redis.h fmacros.h config.h ae.h sds.h dict.h adlist.h \
@@ -191,7 +194,7 @@ clean:
rm -rf $(PRGNAME) $(BENCHPRGNAME) $(CLIPRGNAME) $(CHECKDUMPPRGNAME) $(CHECKAOFPRGNAME) *.o *.gcda *.gcno *.gcov
dep:
- $(CC) -MM *.c
+ $(CC) -MM *.c -I ../deps/hiredis -I ../deps/linenoise
test: redis-server
(cd ..; tclsh8.5 tests/test_helper.tcl --tags "${TAGS}" --file "${FILE}")
View
@@ -309,6 +309,12 @@ void loadServerConfig(char *filename) {
err = "Target command name already exists"; goto loaderr;
}
}
+ } else if (!strcasecmp(argv[0],"slowlog-log-slower-than") &&
+ argc == 2)
+ {
+ server.slowlog_log_slower_than = strtoll(argv[1],NULL,10);
+ } else if (!strcasecmp(argv[0],"slowlog-max-len") && argc == 2) {
+ server.slowlog_max_len = strtoll(argv[1],NULL,10);
} else {
err = "Bad directive or wrong number of arguments"; goto loaderr;
}
@@ -489,6 +495,12 @@ void configSetCommand(redisClient *c) {
} else if (!strcasecmp(c->argv[2]->ptr,"zset-max-ziplist-value")) {
if (getLongLongFromObject(o,&ll) == REDIS_ERR || ll < 0) goto badfmt;
server.zset_max_ziplist_value = ll;
+ } else if (!strcasecmp(c->argv[2]->ptr,"slowlog-log-slower-than")) {
+ if (getLongLongFromObject(o,&ll) == REDIS_ERR) goto badfmt;
+ server.slowlog_log_slower_than = ll;
+ } else if (!strcasecmp(c->argv[2]->ptr,"slowlog-max-len")) {
+ if (getLongLongFromObject(o,&ll) == REDIS_ERR || ll < 0) goto badfmt;
+ server.slowlog_max_len = (unsigned)ll;
} else {
addReplyErrorFormat(c,"Unsupported CONFIG parameter: %s",
(char*)c->argv[2]->ptr);
@@ -660,6 +672,16 @@ void configGetCommand(redisClient *c) {
addReplyBulkLongLong(c,server.zset_max_ziplist_value);
matches++;
}
+ if (stringmatch(pattern,"slowlog-log-slower-than",0)) {
+ addReplyBulkCString(c,"slowlog-log-slower-than");
+ addReplyBulkLongLong(c,server.slowlog_log_slower_than);
+ matches++;
+ }
+ if (stringmatch(pattern,"slowlog-max-len",0)) {
+ addReplyBulkCString(c,"slowlog-max-len");
+ addReplyBulkLongLong(c,server.slowlog_max_len);
+ matches++;
+ }
setDeferredMultiBulkLength(c,replylen,matches*2);
}
View
@@ -324,6 +324,12 @@ void debugCommand(redisClient *c) {
d = sdscatprintf(d, "%02x",digest[j]);
addReplyStatus(c,d);
sdsfree(d);
+ } else if (!strcasecmp(c->argv[1]->ptr,"sleep") && c->argc == 3) {
+ double dtime = strtod(c->argv[2]->ptr,NULL);
+ long long utime = dtime*1000000;
+
+ usleep(utime);
+ addReply(c,shared.ok);
} else {
addReplyError(c,
"Syntax error, try DEBUG [SEGFAULT|OBJECT <key>|SWAPIN <key>|SWAPOUT <key>|RELOAD]");
View
@@ -28,6 +28,7 @@
*/
#include "redis.h"
+#include "slowlog.h"
#ifdef HAVE_BACKTRACE
#include <execinfo.h>
@@ -189,7 +190,8 @@ struct redisCommand readonlyCommandTable[] = {
{"watch",watchCommand,-2,0,NULL,0,0,0},
{"unwatch",unwatchCommand,1,0,NULL,0,0,0},
{"object",objectCommand,-2,0,NULL,0,0,0},
- {"client",clientCommand,-2,0,NULL,0,0,0}
+ {"client",clientCommand,-2,0,NULL,0,0,0},
+ {"slowlog",slowlogCommand,-2,0,NULL,0,0,0}
};
/*============================ Utility functions ============================ */
@@ -868,6 +870,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() {
@@ -956,6 +962,7 @@ void initServer() {
}
if (server.vm_enabled) vmInit();
+ slowlogInit();
srand(time(NULL)^getpid());
}
@@ -991,11 +998,13 @@ 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;
+ long long dirty, start = ustime(), duration;
dirty = server.dirty;
cmd->proc(c);
dirty = server.dirty-dirty;
+ duration = ustime()-start;
+ slowlogPushEntryIfNeeded(c->argv,c->argc,duration);
if (server.appendonly && dirty)
feedAppendOnlyFile(cmd,c->db->id,c->argv,c->argc);
View
@@ -51,6 +51,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% */
@@ -402,8 +404,15 @@ struct redisServer {
long long stat_evictedkeys; /* number of evicted keys (maxmemory) */
long long stat_keyspace_hits; /* number of successful lookups of keys */
long long stat_keyspace_misses; /* number of failed lookups of keys */
+<<<<<<< HEAD
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_entry_id;
+ long long slowlog_log_slower_than;
+ unsigned long slowlog_max_len;
+>>>>>>> ad6347b... Slowlog backported to 2.2
/* Configuration */
int verbosity;
int maxidletime;
View
@@ -0,0 +1,115 @@
+#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;
+ se->id = server.slowlog_entry_id++;
+ 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();
+ 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(robj **argv, int argc, long long duration) {
+ if (server.slowlog_log_slower_than < 0) return; /* Slowlog disabled */
+ 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,4);
+ addReplyLongLong(c,se->id);
+ 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.");
+ }
+}
View
@@ -0,0 +1,15 @@
+/* This structure defines an entry inside the slow log list */
+typedef struct slowlogEntry {
+ robj **argv;
+ int argc;
+ long long id; /* Unique entry identifier. */
+ 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);
View
@@ -132,6 +132,7 @@ proc execute_everything {} {
execute_tests "integration/aof"
# execute_tests "integration/redis-cli"
execute_tests "unit/pubsub"
+ execute_tests "unit/slowlog"
# run tests with VM enabled
if 0 {
Oops, something went wrong.

0 comments on commit 99509ab

Please sign in to comment.