Latency monitor: basic samples collection.

src/Makefile

@@ -107,7 +107,7 @@ endif
 
 REDIS_SERVER_NAME=redis-server
 REDIS_SENTINEL_NAME=redis-sentinel
-REDIS_SERVER_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 migrate.o endianconv.o slowlog.o scripting.o bio.o rio.o rand.o memtest.o crc64.o bitops.o sentinel.o notify.o setproctitle.o hyperloglog.o
+REDIS_SERVER_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 migrate.o endianconv.o slowlog.o scripting.o bio.o rio.o rand.o memtest.o crc64.o bitops.o sentinel.o notify.o setproctitle.o hyperloglog.o latency.o
 REDIS_CLI_NAME=redis-cli
 REDIS_CLI_OBJ=anet.o sds.o adlist.o redis-cli.o zmalloc.o release.o anet.o ae.o crc64.o
 REDIS_BENCHMARK_NAME=redis-benchmark

src/latency.c

+/* The latency monitor allows to easily observe the sources of latency
+ * in a Redis instance using the LATENCY command. Different latency
+ * sources are monitored, like disk I/O, execution of commands, fork
+ * system call, and so forth.
+ *
+ * ----------------------------------------------------------------------------
+ *
+ * Copyright (c) 2014, Salvatore Sanfilippo <antirez at gmail dot com>
+ * 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 "redis.h"
+
+/* Dictionary type for latency events. Key/Val destructors are set to NULL
+ * since we never delete latency time series at runtime. */
+int dictStringKeyCompare(void *privdata, const void *key1, const void *key2) {
+    return strcmp(key1,key2) == 0;
+}
+
+unsigned int dictStringHash(const void *key) {
+    return dictGenHashFunction(key, strlen(key));
+}
+
+dictType latencyTimeSeriesDictType = {
+    dictStringHash,             /* hash function */
+    NULL,                       /* key dup */
+    NULL,                       /* val dup */
+    dictStringKeyCompare,       /* key compare */
+    NULL,                       /* key destructor */
+    NULL                        /* val destructor */
+};
+
+/* ---------------------------- Latency API --------------------------------- */
+
+/* Latency monitor initialization. We just need to create the dictionary
+ * of time series, each time serie is craeted on demand in order to avoid
+ * having a fixed list to maintain. */
+void latencyMonitorInit(void) {
+    server.latency_events = dictCreate(&latencyTimeSeriesDictType,NULL);
+}
+
+/* Add the specified sample to the specified time series "event".
+ * This function is usually called via latencyAddSampleIfNeeded(), that
+ * is a macro that only adds the sample if the latency is higher than
+ * server.latency_monitor_threshold. */
+void latencyAddSample(char *event, mstime_t latency) {
+    struct latencyTimeSeries *ts = dictFetchValue(server.latency_events,event);
+
+    /* Create the time series if it does not exist. */
+    if (ts == NULL) {
+        ts = zmalloc(sizeof(*ts));
+        ts->idx = 0;
+        ts->max = 0;
+        memset(ts->samples,0,sizeof(ts->samples));
+        dictAdd(server.latency_events,zstrdup(event),ts);
+    }
+
+    ts->samples[ts->idx].time = time(NULL);
+    ts->samples[ts->idx].latency = latency;
+    if (latency > ts->max) ts->max = latency;
+
+    ts->idx++;
+    if (ts->idx == LATENCY_TS_LEN) ts->idx = 0;
+}
+
+/* ---------------------- Latency command implementation -------------------- */
+
+void latencyCommand(redisClient *c) {
+}

src/latency.h

+#ifndef __LATENCY_H
+#define __LATENCY_H
+
+#define LATENCY_TS_LEN 160 /* History length for every monitored event. */
+
+/* Representation of a latency sample: the sampling time and the latency
+ * observed in milliseconds. */
+struct latencySample {
+    int32_t time; /* We don't use time_t to force 4 bytes usage everywhere. */
+    uint32_t latency; /* Latency in milliseconds. */
+};
+
+/* The latency time series for a given event. */
+struct latencyTimeSeries {
+    int idx; /* Index of the next sample to store. */
+    mstime_t max; /* Max latency observed for this event. */
+    struct latencySample samples[LATENCY_TS_LEN]; /* Latest history. */
+};
+
+void latencyMonitorInit(void);
+void latencyAddSample(char *event, mstime_t latency);
+
+/* Latency monitoring macros. */
+
+/* Start monitoring an event. We just set the current time. */
+#define latencyStartMonitor(var) if (server.latency_monitor_threshold) { \
+    var = mstime(); \
+}
+
+/* End monitoring an event, compute the difference with the current time
+ * to check the amount of time elapsed. */
+#define latencyEndMonitor(var) if (server.latency_monitor_threshold) { \
+    var = mstime() - var; \
+}
+
+/* Add the sample only if the elapsed time is >= to the configured threshold. */
+#define latencyAddSampleIfNeeded(event,var) \
+    if (server.latency_monitor_threshold && \\
+        var >= server.latency_monitor_threshold) \
+          latencyAddSample(event,var);
+
+#endif /* __LATENCY_H */

src/redis.c

@@ -1427,6 +1427,9 @@ void initServerConfig() {
     server.slowlog_log_slower_than = REDIS_SLOWLOG_LOG_SLOWER_THAN;
     server.slowlog_max_len = REDIS_SLOWLOG_MAX_LEN;
 
+    /* Latency monitor */
+    server.latency_monitor_threshold = REDIS_DEFAULT_LATENCY_MONITOR_THRESHOLD;
+
     /* Debugging */
     server.assert_failed = "<no assertion failed>";
     server.assert_file = "<no file>";
@@ -1730,6 +1733,7 @@ void initServer() {
     replicationScriptCacheInit();
     scriptingInit();
     slowlogInit();
+    latencyMonitorInit();
     bioInit();
 }
 

src/redis.h

@@ -51,6 +51,8 @@
 #include <lua.h>
 #include <signal.h>
 
+typedef long long mstime_t; /* millisecond time type. */
+
 #include "ae.h"      /* Event driven programming library */
 #include "sds.h"     /* Dynamic safe strings */
 #include "dict.h"    /* Hash tables */
@@ -61,6 +63,7 @@
 #include "intset.h"  /* Compact integer set structure */
 #include "version.h" /* Version macro */
 #include "util.h"    /* Misc functions useful in many places */
+#include "latency.h" /* Latency monitor API */
 
 /* Error codes */
 #define REDIS_OK                0
@@ -124,6 +127,7 @@
 #define REDIS_PEER_ID_LEN (REDIS_IP_STR_LEN+32) /* Must be enough for ip:port */
 #define REDIS_BINDADDR_MAX 16
 #define REDIS_MIN_RESERVED_FDS 32
+#define REDIS_DEFAULT_LATENCY_MONITOR_THRESHOLD 10
 
 #define ACTIVE_EXPIRE_CYCLE_LOOKUPS_PER_LOOP 20 /* Loopkups per loop. */
 #define ACTIVE_EXPIRE_CYCLE_FAST_DURATION 1000 /* Microseconds */
@@ -375,8 +379,6 @@
  * Data types
  *----------------------------------------------------------------------------*/
 
-typedef long long mstime_t; /* millisecond time type. */
-
 /* A redis object, that is a type able to hold a string / list / set */
 
 /* The actual Redis Object */
@@ -786,6 +788,9 @@ struct redisServer {
     int lua_timedout;     /* True if we reached the time limit for script
                              execution. */
     int lua_kill;         /* Kill the script if true. */
+    /* Latency monitor */
+    long long latency_monitor_threshold;
+    dict *latency_events;
     /* Assert & bug reporting */
     char *assert_failed;
     char *assert_file;