Merge pull request #94 from doyoubi/fix/SlowlogErrCmd

Ignore command with error result in slowlog. Fix some bugs.

Author: wooparadog

src/command.c

@@ -1118,7 +1118,6 @@ void cmd_mark_fail(struct command *cmd, const char *reason)
 void cmd_stats(struct command *cmd, int64_t end_time)
 {
     struct context *ctx = cmd->ctx;
-    struct command *last, *first;
     long long latency;
 
     ATOMIC_INC(ctx->stats.completed_commands, 1);
@@ -1128,20 +1127,14 @@ void cmd_stats(struct command *cmd, int64_t end_time)
     ATOMIC_INC(ctx->stats.total_latency, latency);
     ATOMIC_SET(ctx->last_command_latency, latency);
 
-    if (!STAILQ_EMPTY(&cmd->sub_cmds)) {
-        first = STAILQ_FIRST(&cmd->sub_cmds);
-        last = STAILQ_LAST(&cmd->sub_cmds, command, sub_cmd_next);
-        latency = last->rep_time[1] - first->rep_time[0];
-    } else {
-        latency = cmd->rep_time[1] - cmd->rep_time[0];
-    }
+    latency = cmd->rep_time[1] - cmd->rep_time[0];
 
     if (slowlog_need_log(cmd, latency)) {
         if (slowlog_statsd_enabled()) {
             slowlog_add_count(cmd);
         }
         if (slowlog_cmd_enabled()) {
-            struct slowlog_entry *entry = slowlog_create_entry(cmd, latency);
+            struct slowlog_entry *entry = slowlog_create_entry(cmd, latency / 1000);
             slowlog_set(&cmd->ctx->slowlog, entry);
         }
     }

src/server.c

@@ -64,6 +64,11 @@ void server_make_iov(struct conn_info *info)
             cmd_iov_add(&info->iov, (void*)req_ask, strlen(req_ask), NULL);
         }
         cmd->rep_time[0] = t;
+        if (cmd->parent) {
+            int64_t parent_rep_start_time = cmd->parent->rep_time[0];
+            if (parent_rep_start_time == 0 || parent_rep_start_time > t)
+                cmd->parent->rep_time[0] = t;
+        }
 
         if (cmd->prefix != NULL) {
             cmd_iov_add(&info->iov, (void*)cmd->prefix, strlen(cmd->prefix), NULL);
@@ -234,6 +239,11 @@ int server_read(struct connection *server)
         status = server_read_reply(server, cmd);
 
         cmd->rep_time[1] = now;
+        if (cmd->parent) {
+            int64_t parent_rep_end_time = cmd->parent->rep_time[1];
+            if (parent_rep_end_time == 0 || parent_rep_end_time < now)
+                cmd->parent->rep_time[1] = now;
+        }
 
         switch (status) {
             case CORVUS_ASKING:

src/slowlog.c

@@ -164,7 +164,8 @@ bool slowlog_statsd_enabled()
 bool slowlog_type_need_log(struct command *cmd)
 {
     return cmd->request_type != CMD_EXTRA
-        && cmd->request_type != CMD_UNIMPL;
+        && cmd->request_type != CMD_UNIMPL
+        && cmd->reply_type != REP_ERROR;
 }
 
 bool slowlog_need_log(struct command *cmd, long long latency)