Merge pull request #129 from doyoubi/fix/SlowlogCrash

Fix slowlog crash when redirection fails

.travis.yml

@@ -7,6 +7,13 @@ before_install:
   - sudo apt-get install -qq valgrind
 
 install:
+  - wget http://download.redis.io/releases/redis-3.0.7.tar.gz
+  - tar xzf redis-3.0.7.tar.gz
+  - cd redis-3.0.7
+  - make
+  - sudo cp src/redis-server `which redis-server`
+  - cd ../
+
   - sudo mkdir -p /etc/redis /var/lib/redis/cluster/{8000,8001,8002,8003}
 
   - sudo chmod -R 777 /etc/redis
@@ -27,8 +34,11 @@ install:
   - sudo redis-server /etc/redis/redis-cluster-8001.conf
   - sudo redis-server /etc/redis/redis-cluster-8002.conf
   - sudo redis-server /etc/redis/redis-cluster-8003.conf
+  - redis-server -v
 
+  - sudo pip install redis==2.10.5
   - sudo pip install ruskit
+  - pip freeze
   - ruskit create localhost:800{0,1,2}
 
   - sed -i 's/node localhost:8000,localhost:8001,localhost:8002/node 127.0.0.1:8000/' corvus.conf
@@ -49,7 +59,6 @@ before_script:
   - ./src/corvus ./corvus.conf > corvus.log 2>&1 &
 
 script:
-  - redis-server -v
   - awk '/ERROR SUMMARY/ {if ($4 == 0) exit 0; else exit 1}' valgrind.log
   - make clean || true
   - make test

src/command.c

@@ -1120,6 +1120,13 @@ void cmd_mark(struct command *cmd, int fail)
         if (cmd->parent->cmd_done_count == cmd->parent->cmd_count) {
             root = cmd->parent;
         }
+        // In some cases cmd->cmd_fail is true though,
+        // cmd->parent->cmd_fail is not. But since `cmd_fail`
+        // implys a not null `fail_reason` (and maybe some other rules),
+        // now we keep it unchanged.
+        // if (fail) {
+        //     cmd->parent->cmd_fail = true;
+        // }
     }
 
     if (root != NULL && conn_register(root->client) == CORVUS_ERR) {

src/slowlog.c

@@ -111,7 +111,7 @@ struct slowlog_entry *slowlog_create_entry(struct command *cmd, int64_t remote_l
     return entry;
 }
 
-// Return NULL when `cmd` is not a multiple keys command
+// Return NULL when `cmd` is not a multiple keys command or fail to connect to redis
 struct slowlog_entry *slowlog_create_sub_entry(struct command *cmd, int64_t total_latency)
 {
     switch (cmd->cmd_type) {
@@ -135,6 +135,12 @@ struct slowlog_entry *slowlog_create_sub_entry(struct command *cmd, int64_t tota
             slowest_sub_cmd = c;
         }
     }
+    // When corvus fails to redirect commands to redis, the `remote_latency` above
+    // may become zero or nagative and produce a NULL `slowest_sub_cmd`.
+    // In this case we just ignore it.
+    if (NULL == slowest_sub_cmd) {
+        return NULL;
+    }
     return slowlog_create_entry(slowest_sub_cmd, max_remote_latency / 1000, total_latency);
 }
 

tests/test_slowlog.c

@@ -223,10 +223,48 @@ TEST(test_slowlog_statsd) {
     PASS(NULL);
 }
 
+TEST(test_failed_command_slowlog) {
+    struct mbuf buf;
+    struct command cmd;
+    memset(&cmd, 0, sizeof(struct command));
+    STAILQ_INIT(&cmd.sub_cmds);
+
+    struct reader r = {0};
+    const char cmd_data[] = "*2\r\n$4\r\nMGET\r\n$4\r\nkey1\r\n";
+    buf.pos = (uint8_t*)cmd_data;
+    buf.last = (uint8_t*)cmd_data + strlen(cmd_data);
+    reader_init(&r);
+    reader_feed(&r, &buf);
+    ASSERT(parse(&r, MODE_REQ) != -1);
+    cmd.data = r.data;
+    cmd.prefix = NULL;
+
+    struct command sub_cmd;
+    sub_cmd.parent = &cmd;
+    STAILQ_INSERT_TAIL(&cmd.sub_cmds, &sub_cmd, sub_cmd_next);
+
+    // When corvus fails to redirect command, these two fields may be zero.
+    cmd.rep_time[0] = 0;
+    cmd.rep_time[1] = 0;
+    sub_cmd.rep_time[0] = 0;
+    sub_cmd.rep_time[1] = 0;
+
+    struct slowlog_entry *entry = slowlog_create_entry(&cmd, 0, 666233);
+    ASSERT(entry->remote_latency == 0);
+    ASSERT(entry->total_latency == 666233);
+    slowlog_dec_ref(entry);
+    entry = slowlog_create_sub_entry(&cmd, 666233);
+    ASSERT(NULL == entry);
+
+    redis_data_free(&cmd.data);
+    PASS(NULL);
+}
+
 TEST_CASE(test_slowlog) {
     RUN_TEST(test_slowlog_create_entry);
     RUN_TEST(test_slowlog_create_entry_with_prefix);
     RUN_TEST(test_slowlog_create_entry_with_long_arg);
     RUN_TEST(test_slowlog_statsd);
     RUN_TEST(test_entry_get_set);
+    RUN_TEST(test_failed_command_slowlog);
 }