[ovs-dev] [PATCH V1 1/3] coverage: Reimplement the "ovs-appclt coverage/show" command

Alex Wang alexw at nicira.com
Wed Jun 12 18:38:41 UTC 2013


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 <alexw at nicira.com>
---
Possible Issue:

The "coverage_run" runs every second. And the number of addition operations is
not very large. If it is still considered to be time-consuming, I'll adjust
further.

---
 lib/coverage-unixctl.man |    3 +-
 lib/coverage.c           |   76 +++++++++++++++++++++++++++++++++++++---------
 lib/coverage.h           |   33 +++++++++++++++++---
 lib/timeval.c            |    1 -
 vswitchd/ovs-vswitchd.c  |    3 ++
 5 files changed, 96 insertions(+), 20 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..814c741 100644
--- a/lib/coverage.c
+++ b/lib/coverage.c
@@ -47,7 +47,19 @@ 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 second. */
+#define COVERAGE_WAKEUP_INTERVAL    1000
+static long long int coverage_wakeup_timer = LLONG_MIN;
+
+#define HR_TIME 3600    /* 3600 seconds in one hour. */
+
+/* Defines the moving average array index variables. */
+static unsigned int mov_avg_sec_idx = 0;
+static unsigned int mov_avg_min_idx = 0;
+static unsigned int mov_avg_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 *);
 
@@ -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,17 @@ 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 recent
+     * five seconds. */
+    svec_add_nocopy(lines,
+            xasprintf("%-24s %5.1f/sec %7u/min "
+                      "%9u/hr   total: %llu",
+                      c->name,
+                      coverage_array_sum(c->mov_avg_sec, MOV_AVG_SEC_LEN)
+                          / (float) MOV_AVG_SEC_LEN,
+                      coverage_array_sum(c->mov_avg_min, MOV_AVG_MIN_LEN),
+                      coverage_array_sum(c->mov_avg_hr, MOV_AVG_HR_LEN),
+                      c->count + c->total));
 }
 
 /* Adds coverage counter information to 'lines'. */
@@ -204,8 +225,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 +246,43 @@ 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. */
+/* Causes the following call to poll_block() to wake up every second. */
 void
-coverage_clear(void)
+coverage_wait(void)
 {
-    size_t i;
+    poll_timer_wait_until(coverage_wakeup_timer);
+}
 
-    epoch++;
-    for (i = 0; i < n_coverage_counters; i++) {
-        struct coverage_counter *c = coverage_counters[i];
-        c->total += c->count;
-        c->count = 0;
+/* Runs every second to update the coverage counters' mov_avg_sec array,
+ * mov_avg_min array and mov_avg_hr array. */
+void
+coverage_run(void)
+{
+    if (time_msec() >= coverage_wakeup_timer) {
+        size_t i;
+
+        /* Updates the index variables. */
+        mov_avg_sec_idx = idx_count % MOV_AVG_SEC_LEN;
+        mov_avg_min_idx = (idx_count / MOV_AVG_SEC_LEN) % MOV_AVG_MIN_LEN;
+        mov_avg_hr_idx  = idx_count / MOV_AVG_HR_LEN;
+
+        for (i = 0; i < n_coverage_counters; i++) {
+            struct coverage_counter *c = coverage_counters[i];
+
+            c->total += c->count;
+            c->mov_avg_sec[mov_avg_sec_idx] = c->count;
+            /* Note, only adds up the latest count here. */
+            c->mov_avg_min[mov_avg_min_idx] = mov_avg_sec_idx == 0 ?
+                    c->count : (c->mov_avg_min[mov_avg_min_idx] + c->count);
+            /* The summation here is for fast sync change to per-hour rate.
+             * should be modified when it becomes very time consuming. */
+            c->mov_avg_hr[mov_avg_hr_idx] =
+                    coverage_array_sum(c->mov_avg_min, mov_avg_min_idx + 1);
+            c->count = 0;
+        }
+
+        /* Always updates the wakeup timer and idx_count. */
+        coverage_wakeup_timer = time_msec() + COVERAGE_WAKEUP_INTERVAL;
+        idx_count = (idx_count + 1) % HR_TIME;
     }
 }
diff --git a/lib/coverage.h b/lib/coverage.h
index 968c489..60c5107 100644
--- a/lib/coverage.h
+++ b/lib/coverage.h
@@ -27,13 +27,24 @@
  * for traditional coverage instrumentation with e.g. "gcov", but it is still
  * a useful debugging tool. */
 
+#include "poll-loop.h"
 #include "vlog.h"
 
+/* Defines the moving average array length. */
+#define MOV_AVG_SEC_LEN 5    /* 1 * 5 second = 5 seconds */
+#define MOV_AVG_MIN_LEN 12   /* 12 * 5 seconds = 1 minute */
+#define MOV_AVG_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 mov_avg_sec[MOV_AVG_SEC_LEN];
+    unsigned int mov_avg_min[MOV_AVG_MIN_LEN];
+    unsigned int mov_avg_hr[MOV_AVG_HR_LEN];
 };
 
 /* Defines COUNTER.  There must be exactly one such definition at file scope
@@ -57,11 +68,25 @@ struct coverage_counter {
 
 void coverage_init(void);
 void coverage_log(void);
-void coverage_clear(void);
+void coverage_wait(void);
+void coverage_run(void);
+
+static inline unsigned int
+coverage_array_sum(const unsigned int arr[], unsigned int len)
+{
+    unsigned int sum = 0;
+    size_t i;
+
+    for (i = 0; i < len; i++) {
+        sum += arr[i];
+    }
+    return sum;
+}
 
 /* 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}, {0} }
 
 #endif /* coverage.h */
diff --git a/lib/timeval.c b/lib/timeval.c
index 5ff59bc..fe4f2a7 100644
--- a/lib/timeval.c
+++ b/lib/timeval.c
@@ -333,7 +333,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 e11febd..9bf4664 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"
@@ -126,6 +127,7 @@ main(int argc, char *argv[])
         bridge_run_fast();
         unixctl_server_run(unixctl);
         netdev_run();
+        coverage_run();
 
         worker_wait();
         signal_wait(sighup);
@@ -133,6 +135,7 @@ main(int argc, char *argv[])
         bridge_wait();
         unixctl_server_wait(unixctl);
         netdev_wait();
+        coverage_wait();
         if (exiting) {
             poll_immediate_wake();
         }
-- 
1.7.9.5




More information about the dev mailing list