This commit changes the "ovs-appclt coverage/show" command to show the per-second, per-minute and per-hour rates of function invocation. More importantly, this makes using coverage counter an easy way to monitor the execution of specific functions.
Signed-off-by: Alex Wang <al...@nicira.com> --- v2 -> v3: - rebase to current master. v1 -> v2: - abandon the wakeup timer and coverage_wait() function. - now the coverage_run() will run only when more than 5 seconds have passed since last run. --- lib/coverage-unixctl.man | 3 +- lib/coverage.c | 95 +++++++++++++++++++++++++++++++++++++++------- lib/coverage.h | 17 +++++++-- lib/timeval.c | 1 - vswitchd/ovs-vswitchd.c | 2 + 5 files changed, 99 insertions(+), 19 deletions(-) diff --git a/lib/coverage-unixctl.man b/lib/coverage-unixctl.man index 9718894..2d283dc 100644 --- a/lib/coverage-unixctl.man +++ b/lib/coverage-unixctl.man @@ -8,4 +8,5 @@ main loop takes unusually long to run. Coverage counters are useful mainly for performance analysis and debugging. .IP "\fBcoverage/show\fR" -Displays the values of all of the coverage counters. +Displays the per-second, per-minute and per-hour rates, and total count +of all of the coverage counters. diff --git a/lib/coverage.c b/lib/coverage.c index f152474..e3e7610 100644 --- a/lib/coverage.c +++ b/lib/coverage.c @@ -47,9 +47,21 @@ struct coverage_counter *coverage_counters[] = { #define n_coverage_counters ARRAY_SIZE(coverage_counters) #endif /* !USE_LINKER_SECTIONS */ -static unsigned int epoch; +/* Makes coverage_run run every 5 seconds. */ +#define COVERAGE_RUN_INTERVAL 5000 +static long long int coverage_run_time = LLONG_MIN; + +/* Defines the moving average array index variables. */ +static unsigned int min_idx = 0; +static unsigned int hr_idx = 0; + +/* Index counter used to compute the moving average array's index. */ +static unsigned int idx_count = 0; static void coverage_read(struct svec *); +static unsigned int coverage_array_sum(const unsigned int *arr, + const unsigned int len); + static void coverage_unixctl_show(struct unixctl_conn *conn, int argc OVS_UNUSED, @@ -170,7 +182,7 @@ coverage_log(void) uint32_t hash = coverage_hash(); if (coverage_hit(hash)) { VLOG_INFO("Skipping details of duplicate event coverage for " - "hash=%08"PRIx32" in epoch %u", hash, epoch); + "hash=%08"PRIx32, hash); } else { struct svec lines; const char *line; @@ -189,8 +201,16 @@ coverage_log(void) static void coverage_read_counter(struct svec *lines, const struct coverage_counter *c) { - svec_add_nocopy(lines, xasprintf("%-24s %5u / %9llu", - c->name, c->count, c->count + c->total)); + /* The per second rate is calculated via averaging the counts in + * last 5-second interval. */ + svec_add_nocopy(lines, + xasprintf("%-24s %5.1f/sec %7u/min " + "%9u/hr total: %llu", + c->name, + c->sec_to_min[(min_idx + 11) % MIN_LEN] / 5.0, + coverage_array_sum(c->sec_to_min, MIN_LEN), + coverage_array_sum(c->min_to_hr, HR_LEN), + c->count + c->total)); } /* Adds coverage counter information to 'lines'. */ @@ -204,8 +224,8 @@ coverage_read(struct svec *lines) hash = coverage_hash(); n_never_hit = 0; - svec_add_nocopy(lines, xasprintf("Event coverage (epoch %u/entire run), " - "hash=%08"PRIx32":", epoch, hash)); + svec_add_nocopy(lines, xasprintf("Event coverage (frequency), " + "hash=%08"PRIx32":", hash)); for (i = 0; i < n_coverage_counters; i++) { struct coverage_counter *c = coverage_counters[i]; if (c->count) { @@ -225,16 +245,65 @@ coverage_read(struct svec *lines) svec_add_nocopy(lines, xasprintf("%zu events never hit", n_never_hit)); } -/* Advances to the next epoch of coverage, resetting all the counters to 0. */ +/* Runs every second to update the coverage counters' + * sec_to_min array and min_to_hr array. */ void -coverage_clear(void) +coverage_run(void) { + long long int cur_time = time_msec(); + + /* Initialize the coverage_run_time. */ + if (coverage_run_time == LLONG_MIN) { + coverage_run_time = time_msec(); + } + + if (cur_time >= coverage_run_time) { + size_t i, j; + /* Computes the number of 5-second slots. */ + int slots = (cur_time - coverage_run_time) / COVERAGE_RUN_INTERVAL + + 1; + + /* This loop is necessary, since it is possible that the actual + * run interval is multiple of 5 seconds. */ + for (i = 0; i < slots; i++) { + /* Updates the index variables. */ + /* The min_idx is increased from 0 to 11. Every time the + * min_idx finishes a cycle (a cycle is one minute), + * the hr_idx is incremented by 1. */ + min_idx = idx_count % MIN_LEN; + hr_idx = idx_count / MIN_LEN; + + for (j = 0; j < n_coverage_counters; j++) { + struct coverage_counter *c = coverage_counters[j]; + /* Calculates the portion to be added, which is the average + * of counts over the time. Note, the last loop will also + * include the remainder. */ + int portion = c->count / slots + (i == slots - 1 ? + c->count % slots : 0); + + c->total += portion; + c->count = (i == slots -1 ? 0 : c->count) ; + c->sec_to_min[min_idx] = portion; + /* Note, only adds up the latest count portion here. */ + c->min_to_hr[hr_idx] = min_idx == 0 ? + portion : (c->min_to_hr[hr_idx] + portion); + } + /* This is to guarantee that mov_avg_hr_idx ranges from 0 to 59. */ + idx_count = (idx_count + 1) % 720; + /* Updates the run time. */ + coverage_run_time += COVERAGE_RUN_INTERVAL; + } + } +} + +static unsigned int +coverage_array_sum(const unsigned int *arr, const unsigned int len) +{ + unsigned int sum = 0; size_t i; - epoch++; - for (i = 0; i < n_coverage_counters; i++) { - struct coverage_counter *c = coverage_counters[i]; - c->total += c->count; - c->count = 0; + for (i = 0; i < len; i++) { + sum += arr[i]; } + return sum; } diff --git a/lib/coverage.h b/lib/coverage.h index 968c489..26837ed 100644 --- a/lib/coverage.h +++ b/lib/coverage.h @@ -29,11 +29,19 @@ #include "vlog.h" +/* Defines the moving average array length. */ +#define MIN_LEN 12 /* 12 * 5 seconds = 1 minute */ +#define HR_LEN 60 /* 60 * 1 minute = 1 hour */ + /* A coverage counter. */ struct coverage_counter { const char *name; /* Textual name. */ - unsigned int count; /* Count within the current epoch. */ - unsigned long long int total; /* Total count over all epochs. */ + unsigned int count; /* Count within the current second. */ + unsigned long long int total; /* Total count over all time. */ + + /* The moving average arrays. */ + unsigned int sec_to_min[MIN_LEN]; + unsigned int min_to_hr[HR_LEN]; }; /* Defines COUNTER. There must be exactly one such definition at file scope @@ -57,11 +65,12 @@ struct coverage_counter { void coverage_init(void); void coverage_log(void); -void coverage_clear(void); +void coverage_run(void); /* Implementation detail. */ #define COVERAGE_DEFINE__(COUNTER) \ extern struct coverage_counter counter_##COUNTER; \ - struct coverage_counter counter_##COUNTER = { #COUNTER, 0, 0 } + struct coverage_counter counter_##COUNTER = { #COUNTER, 0, 0, \ + {0}, {0} } #endif /* coverage.h */ diff --git a/lib/timeval.c b/lib/timeval.c index faf8e7b..2380a0a 100644 --- a/lib/timeval.c +++ b/lib/timeval.c @@ -304,7 +304,6 @@ time_poll(struct pollfd *pollfds, int n_pollfds, long long int timeout_when, if (*last_wakeup) { log_poll_interval(*last_wakeup); } - coverage_clear(); start = time_msec(); blocked = false; diff --git a/vswitchd/ovs-vswitchd.c b/vswitchd/ovs-vswitchd.c index bc45dac..a9db1fd 100644 --- a/vswitchd/ovs-vswitchd.c +++ b/vswitchd/ovs-vswitchd.c @@ -28,6 +28,7 @@ #include "bridge.h" #include "command-line.h" #include "compiler.h" +#include "coverage.h" #include "daemon.h" #include "dirs.h" #include "dpif.h" @@ -119,6 +120,7 @@ main(int argc, char *argv[]) bridge_run_fast(); unixctl_server_run(unixctl); netdev_run(); + coverage_run(); signal_wait(sighup); memory_wait(); -- 1.7.9.5 _______________________________________________ dev mailing list dev@openvswitch.org http://openvswitch.org/mailman/listinfo/dev