From de88bc63d5eff769a385b1e51bba75997a969177 Mon Sep 17 00:00:00 2001 From: antirez Date: Tue, 1 Jul 2014 17:19:08 +0200 Subject: [PATCH] Latency monitor: more hooks around the code. --- src/aof.c | 20 ++++++++++++++++++++ src/rdb.c | 6 ++++++ src/redis.c | 19 ++++++++++++++----- 3 files changed, 40 insertions(+), 5 deletions(-) diff --git a/src/aof.c b/src/aof.c index 5e69399f..9e193a2c 100644 --- a/src/aof.c +++ b/src/aof.c @@ -230,6 +230,7 @@ int startAppendOnly(void) { void flushAppendOnlyFile(int force) { ssize_t nwritten; int sync_in_progress = 0; + mstime_t latency; if (sdslen(server.aof_buf) == 0) return; @@ -266,7 +267,11 @@ void flushAppendOnlyFile(int force) { * While this will save us against the server being killed I don't think * there is much to do about the whole server stopping for power problems * or alike */ + latencyStartMonitor(latency); nwritten = write(server.aof_fd,server.aof_buf,sdslen(server.aof_buf)); + latencyEndMonitor(latency); + latencyAddSampleIfNeeded("aof-write",latency); + if (nwritten != (signed)sdslen(server.aof_buf)) { static time_t last_write_error_log = 0; int can_log = 0; @@ -360,7 +365,10 @@ void flushAppendOnlyFile(int force) { if (server.aof_fsync == AOF_FSYNC_ALWAYS) { /* aof_fsync is defined as fdatasync() for Linux in order to avoid * flushing metadata. */ + latencyStartMonitor(latency); aof_fsync(server.aof_fd); /* Let's try to get this data on the disk */ + latencyEndMonitor(latency); + latencyAddSampleIfNeeded("aof-fsync-always",latency); server.aof_last_fsync = server.unixtime; } else if ((server.aof_fsync == AOF_FSYNC_EVERYSEC && server.unixtime > server.aof_last_fsync)) { @@ -1032,6 +1040,7 @@ int rewriteAppendOnlyFileBackground(void) { } else { /* Parent */ server.stat_fork_time = ustime()-start; + latencyAddSampleIfNeeded("fork",server.stat_fork_time/1000); if (childpid == -1) { redisLog(REDIS_WARNING, "Can't rewrite append only file in background: fork: %s", @@ -1081,13 +1090,17 @@ void aofRemoveTempFile(pid_t childpid) { * to the current length, that is much faster. */ void aofUpdateCurrentSize(void) { struct redis_stat sb; + mstime_t latency; + latencyStartMonitor(latency); if (redis_fstat(server.aof_fd,&sb) == -1) { redisLog(REDIS_WARNING,"Unable to obtain the AOF file length. stat: %s", strerror(errno)); } else { server.aof_current_size = sb.st_size; } + latencyEndMonitor(latency); + latencyAddSampleIfNeeded("aof-fstat",latency); } /* A background append only file rewriting (BGREWRITEAOF) terminated its work. @@ -1097,12 +1110,14 @@ void backgroundRewriteDoneHandler(int exitcode, int bysignal) { int newfd, oldfd; char tmpfile[256]; long long now = ustime(); + mstime_t latency; redisLog(REDIS_NOTICE, "Background AOF rewrite terminated with success"); /* Flush the differences accumulated by the parent to the * rewritten AOF. */ + latencyStartMonitor(latency); snprintf(tmpfile,256,"temp-rewriteaof-bg-%d.aof", (int)server.aof_child_pid); newfd = open(tmpfile,O_WRONLY|O_APPEND); @@ -1118,6 +1133,8 @@ void backgroundRewriteDoneHandler(int exitcode, int bysignal) { close(newfd); goto cleanup; } + latencyEndMonitor(latency); + latencyAddSampleIfNeeded("aof-rewrite-diff-write",latency); redisLog(REDIS_NOTICE, "Parent diff successfully flushed to the rewritten AOF (%lu bytes)", aofRewriteBufferSize()); @@ -1163,6 +1180,7 @@ void backgroundRewriteDoneHandler(int exitcode, int bysignal) { /* Rename the temporary file. This will not unlink the target file if * it exists, because we reference it with "oldfd". */ + latencyStartMonitor(latency); if (rename(tmpfile,server.aof_filename) == -1) { redisLog(REDIS_WARNING, "Error trying to rename the temporary AOF file: %s", strerror(errno)); @@ -1170,6 +1188,8 @@ void backgroundRewriteDoneHandler(int exitcode, int bysignal) { if (oldfd != -1) close(oldfd); goto cleanup; } + latencyEndMonitor(latency); + latencyAddSampleIfNeeded("aof-rename",latency); if (server.aof_fd == -1) { /* AOF disabled, we don't need to set the AOF file descriptor diff --git a/src/rdb.c b/src/rdb.c index 50b3cc1a..9af98504 100644 --- a/src/rdb.c +++ b/src/rdb.c @@ -745,6 +745,7 @@ int rdbSaveBackground(char *filename) { } else { /* Parent */ server.stat_fork_time = ustime()-start; + latencyAddSampleIfNeeded("fork",server.stat_fork_time/1000); if (childpid == -1) { server.lastbgsave_status = REDIS_ERR; redisLog(REDIS_WARNING,"Can't save in background: fork: %s", @@ -1200,9 +1201,14 @@ void backgroundSaveDoneHandler(int exitcode, int bysignal) { redisLog(REDIS_WARNING, "Background saving error"); server.lastbgsave_status = REDIS_ERR; } else { + mstime_t latency; + redisLog(REDIS_WARNING, "Background saving terminated by signal %d", bysignal); + latencyStartMonitor(latency); rdbRemoveTempFile(server.rdb_child_pid); + latencyEndMonitor(latency); + latencyAddSampleIfNeeded("rdb-unlink-temp-file",latency); /* SIGUSR1 is whitelisted, so we have a way to kill a child without * tirggering an error conditon. */ if (bysignal != SIGUSR1) diff --git a/src/redis.c b/src/redis.c index c993dc06..359052eb 100644 --- a/src/redis.c +++ b/src/redis.c @@ -858,10 +858,11 @@ void activeExpireCycle(int type) { * expire. So after a given amount of milliseconds return to the * caller waiting for the other active expire cycle. */ iteration++; - if ((iteration & 0xf) == 0 && /* check once every 16 iterations. */ - (ustime()-start) > timelimit) - { - timelimit_exit = 1; + if ((iteration & 0xf) == 0) { /* check once every 16 iterations. */ + long long elapsed = ustime()-start; + + latencyAddSampleIfNeeded("expire-cycle",elapsed/1000); + if (elapsed > timelimit) timelimit_exit = 1; } if (timelimit_exit) return; /* We don't repeat the cycle if there are less than 25% of keys @@ -3120,6 +3121,7 @@ void evictionPoolPopulate(dict *sampledict, dict *keydict, struct evictionPoolEn int freeMemoryIfNeeded(void) { size_t mem_used, mem_tofree, mem_freed; int slaves = listLength(server.slaves); + mstime_t latency; /* Remove the size of slaves output buffers and AOF buffer from the * count of used memory. */ @@ -3152,6 +3154,7 @@ int freeMemoryIfNeeded(void) { /* Compute how much memory we need to free. */ mem_tofree = mem_used - server.maxmemory; mem_freed = 0; + latencyStartMonitor(latency); while (mem_freed < mem_tofree) { int j, k, keys_freed = 0; @@ -3265,8 +3268,14 @@ int freeMemoryIfNeeded(void) { if (slaves) flushSlavesOutputBuffers(); } } - if (!keys_freed) return REDIS_ERR; /* nothing to free... */ + if (!keys_freed) { + latencyEndMonitor(latency); + latencyAddSampleIfNeeded("eviction-cycle",latency); + return REDIS_ERR; /* nothing to free... */ + } } + latencyEndMonitor(latency); + latencyAddSampleIfNeeded("eviction-cycle",latency); return REDIS_OK; }