diff --git a/src/latency.c b/src/latency.c index ff8d66069..1eac48191 100644 --- a/src/latency.c +++ b/src/latency.c @@ -530,11 +530,22 @@ void latencyAllCommandsFillCDF(client *c) { int command_with_data = 0; while((de = dictNext(di)) != NULL) { cmd = (struct redisCommand *) dictGetVal(de); - if (!cmd->latency_histogram) - continue; - addReplyBulkCString(c,cmd->name); - fillCommandCDF(c, cmd->latency_histogram); - command_with_data++; + if (cmd->latency_histogram) { + addReplyBulkCString(c,cmd->name); + fillCommandCDF(c, cmd->latency_histogram); + command_with_data++; + } + + if (cmd->subcommands) { + for (int j = 0; cmd->subcommands[j].name; j++) { + struct redisCommand *sub = cmd->subcommands+j; + if (sub->latency_histogram) { + addReplyBulkSds(c,getFullCommandName(sub)); + fillCommandCDF(c, sub->latency_histogram); + command_with_data++; + } + } + } } dictReleaseIterator(di); setDeferredMapLen(c,replylen,command_with_data); @@ -546,18 +557,28 @@ void latencySpecificCommandsFillCDF(client *c) { void *replylen = addReplyDeferredLen(c); int command_with_data = 0; for (int j = 2; j < c->argc; j++){ - struct redisCommand *cmd = dictFetchValue(server.commands, c->argv[j]->ptr); + struct redisCommand *cmd = lookupCommandBySds(c->argv[j]->ptr); /* If the command does not exist we skip the reply */ if (cmd == NULL) { continue; } - /* If no latency info we reply with the same format as non empty histograms */ - if (!cmd->latency_histogram) { - continue; + + if (cmd->latency_histogram) { + addReplyBulkSds(c,getFullCommandName(cmd)); + fillCommandCDF(c, cmd->latency_histogram); + command_with_data++; + } + + if (cmd->subcommands) { + for (int j = 0; cmd->subcommands[j].name; j++) { + struct redisCommand *sub = cmd->subcommands+j; + if (sub->latency_histogram) { + addReplyBulkSds(c,getFullCommandName(sub)); + fillCommandCDF(c, sub->latency_histogram); + command_with_data++; + } + } } - addReplyBulkCString(c,c->argv[j]->ptr); - fillCommandCDF(c, cmd->latency_histogram); - command_with_data++; } setDeferredMapLen(c,replylen,command_with_data); } diff --git a/src/server.c b/src/server.c index 550708acc..339d8147a 100644 --- a/src/server.c +++ b/src/server.c @@ -4808,6 +4808,32 @@ sds genRedisInfoStringCommandStats(sds info, dict *commands) { return info; } +sds genRedisInfoStringLatencyStats(sds info, dict *commands) { + struct redisCommand *c; + dictEntry *de; + dictIterator *di; + di = dictGetSafeIterator(commands); + while((de = dictNext(di)) != NULL) { + char *tmpsafe; + c = (struct redisCommand *) dictGetVal(de); + if (c->latency_histogram) { + sds cmdnamesds = getFullCommandName(c); + + info = fillPercentileDistributionLatencies(info, + getSafeInfoString(cmdnamesds, sdslen(cmdnamesds), &tmpsafe), + c->latency_histogram); + if (tmpsafe != NULL) zfree(tmpsafe); + sdsfree(cmdnamesds); + } + if (c->subcommands_dict) { + info = genRedisInfoStringLatencyStats(info, c->subcommands_dict); + } + } + dictReleaseIterator(di); + + return info; +} + /* Create the string returned by the INFO command. This is decoupled * by the INFO command itself as we need to report the same information * on memory corruption problems. */ @@ -5518,19 +5544,7 @@ sds genRedisInfoString(const char *section) { if (sections++) info = sdscat(info,"\r\n"); info = sdscatprintf(info, "# Latencystats\r\n"); if (server.latency_tracking_enabled) { - struct redisCommand *c; - dictEntry *de; - dictIterator *di; - di = dictGetSafeIterator(server.commands); - while((de = dictNext(di)) != NULL) { - char *tmpsafe; - c = (struct redisCommand *) dictGetVal(de); - if (!c->latency_histogram) - continue; - info = fillPercentileDistributionLatencies(info,getSafeInfoString(c->name, strlen(c->name), &tmpsafe),c->latency_histogram); - if (tmpsafe != NULL) zfree(tmpsafe); - } - dictReleaseIterator(di); + info = genRedisInfoStringLatencyStats(info, server.commands); } } diff --git a/tests/unit/info.tcl b/tests/unit/info.tcl index f9660f2c8..9439c0fc8 100644 --- a/tests/unit/info.tcl +++ b/tests/unit/info.tcl @@ -75,6 +75,16 @@ start_server {tags {"info" "external:skip"}} { $rd close } + test {latencystats: subcommands} { + r config resetstat + r CONFIG SET latency-tracking yes + r CONFIG SET latency-tracking-info-percentiles "50.0 99.0 99.9" + r client id + + assert_match {*p50=*,p99=*,p99.9=*} [latency_percentiles_usec client\\|id] + assert_match {*p50=*,p99=*,p99.9=*} [latency_percentiles_usec config\\|set] + } + test {latencystats: measure latency} { r config resetstat r CONFIG SET latency-tracking yes diff --git a/tests/unit/latency-monitor.tcl b/tests/unit/latency-monitor.tcl index 239b892ba..79de0883c 100644 --- a/tests/unit/latency-monitor.tcl +++ b/tests/unit/latency-monitor.tcl @@ -1,7 +1,3 @@ -proc latency_histogram {cmd} { - return [lindex [r latency histogram $cmd] 1] -} - start_server {tags {"latency-monitor needs:latency"}} { # Set a threshold high enough to avoid spurious latency events. r config set latency-monitor-threshold 200 @@ -9,15 +5,34 @@ start_server {tags {"latency-monitor needs:latency"}} { test {LATENCY HISTOGRAM with empty histogram} { r config resetstat - assert_match {} [latency_histogram set] - assert {[llength [r latency histogram]] == 0} + set histo [dict create {*}[r latency histogram]] + # Config resetstat is recorded + assert_equal [dict size $histo] 1 } test {LATENCY HISTOGRAM all commands} { r config resetstat r set a b r set c d - assert_match {calls 2 histogram_usec *} [latency_histogram set] + set histo [dict create {*}[r latency histogram]] + assert_match {calls 2 histogram_usec *} [dict get $histo set] + assert_match {calls 1 histogram_usec *} [dict get $histo "config|resetstat"] + } + + test {LATENCY HISTOGRAM sub commands} { + r config resetstat + r client id + r client list + # parent command reply with its sub commands + set histo [dict create {*}[r latency histogram client]] + assert {[dict size $histo] == 2} + assert_match {calls 1 histogram_usec *} [dict get $histo "client|id"] + assert_match {calls 1 histogram_usec *} [dict get $histo "client|list"] + + # explicitly ask for one sub-command + set histo [dict create {*}[r latency histogram "client|id"]] + assert {[dict size $histo] == 1} + assert_match {calls 1 histogram_usec *} [dict get $histo "client|id"] } test {LATENCY HISTOGRAM with a subset of commands} { @@ -27,19 +42,20 @@ start_server {tags {"latency-monitor needs:latency"}} { r get a r hset f k v r hgetall f - assert_match {calls 2 histogram_usec *} [latency_histogram set] - assert_match {calls 1 histogram_usec *} [latency_histogram hset] - assert_match {calls 1 histogram_usec *} [latency_histogram hgetall] - assert_match {calls 1 histogram_usec *} [latency_histogram get] - assert {[llength [r latency histogram]] == 8} - assert {[llength [r latency histogram set get]] == 4} + set histo [dict create {*}[r latency histogram set hset]] + assert_match {calls 2 histogram_usec *} [dict get $histo set] + assert_match {calls 1 histogram_usec *} [dict get $histo hset] + assert_equal [dict size $histo] 2 + set histo [dict create {*}[r latency histogram hgetall get zadd]] + assert_match {calls 1 histogram_usec *} [dict get $histo hgetall] + assert_match {calls 1 histogram_usec *} [dict get $histo get] + assert_equal [dict size $histo] 2 } test {LATENCY HISTOGRAM command} { r config resetstat r set a b r get a - assert {[llength [r latency histogram]] == 4} assert {[llength [r latency histogram set get]] == 4} }