diff options
Diffstat (limited to 'lib')
| -rw-r--r-- | lib/automake.mk | 1 | ||||
| -rw-r--r-- | lib/coverage-unixctl.man | 11 | ||||
| -rw-r--r-- | lib/coverage.c | 91 | ||||
| -rw-r--r-- | lib/coverage.h | 4 | ||||
| -rw-r--r-- | lib/timeval.c | 6 |
5 files changed, 73 insertions, 40 deletions
diff --git a/lib/automake.mk b/lib/automake.mk index 5ce287f8..2d2617ea 100644 --- a/lib/automake.mk +++ b/lib/automake.mk @@ -253,6 +253,7 @@ EXTRA_DIST += \ MAN_FRAGMENTS += \ lib/common.man \ lib/common-syn.man \ + lib/coverage-unixctl.man \ lib/daemon.man \ lib/daemon-syn.man \ lib/leak-checker.man \ diff --git a/lib/coverage-unixctl.man b/lib/coverage-unixctl.man new file mode 100644 index 00000000..97188941 --- /dev/null +++ b/lib/coverage-unixctl.man @@ -0,0 +1,11 @@ +.SS "COVERAGE COMMANDS" +These commands manage \fB\*(PN\fR's ``coverage counters,'' which count +the number of times particular events occur during a daemon's runtime. +In addition to these commands, \fB\*(PN\fR automatically logs coverage +counter values, at \fBINFO\fR level, when it detects that the daemon's +main loop takes unusually long to run. +.PP +Coverage counters are useful mainly for performance analysis and +debugging. +.IP "\fBcoverage/show\fR" +Displays the values of all of the coverage counters. diff --git a/lib/coverage.c b/lib/coverage.c index ff20f5e9..ee27af02 100644 --- a/lib/coverage.c +++ b/lib/coverage.c @@ -20,6 +20,7 @@ #include <stdlib.h> #include "dynamic-string.h" #include "hash.h" +#include "svec.h" #include "timeval.h" #include "unixctl.h" #include "util.h" @@ -48,19 +49,28 @@ struct coverage_counter *coverage_counters[] = { static unsigned int epoch; +static void coverage_read(struct svec *); + static void -coverage_unixctl_log(struct unixctl_conn *conn, int argc OVS_UNUSED, +coverage_unixctl_show(struct unixctl_conn *conn, int argc OVS_UNUSED, const char *argv[] OVS_UNUSED, void *aux OVS_UNUSED) { - coverage_log(VLL_WARN, false); - unixctl_command_reply(conn, NULL); + struct svec lines; + char *reply; + + svec_init(&lines); + coverage_read(&lines); + reply = svec_join(&lines, "\n", "\n"); + unixctl_command_reply(conn, reply); + free(reply); + svec_destroy(&lines); } void coverage_init(void) { - unixctl_command_register("coverage/log", "", 0, 0, - coverage_unixctl_log, NULL); + unixctl_command_register("coverage/show", "", 0, 0, + coverage_unixctl_show, NULL); } /* Sorts coverage counters in descending order by count, within equal counts @@ -144,60 +154,75 @@ coverage_hit(uint32_t hash) } } +/* Logs the coverage counters, unless a similar set of events has already been + * logged. + * + * This function logs at log level VLL_INFO. Use care before adjusting this + * level, because depending on its configuration, syslogd can write changes + * synchronously, which can cause the coverage messages to take several seconds + * to write. */ +void +coverage_log(void) +{ + static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 3); + + if (!VLOG_DROP_INFO(&rl)) { + 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); + } else { + struct svec lines; + const char *line; + size_t i; + + svec_init(&lines); + coverage_read(&lines); + SVEC_FOR_EACH (i, line, &lines) { + VLOG_INFO("%s", line); + } + svec_destroy(&lines); + } + } +} + static void -coverage_log_counter(enum vlog_level level, const struct coverage_counter *c) +coverage_read_counter(struct svec *lines, const struct coverage_counter *c) { - VLOG(level, "%-24s %5u / %9llu", c->name, c->count, c->count + c->total); + svec_add_nocopy(lines, xasprintf("%-24s %5u / %9llu", + c->name, c->count, c->count + c->total)); } -/* Logs the coverage counters at the given vlog 'level'. If - * 'suppress_dups' is true, then duplicate events are not displayed. - * Care should be taken in the value used for 'level'. Depending on the - * configuration, syslog can write changes synchronously, which can - * cause the coverage messages to take several seconds to write. */ -void -coverage_log(enum vlog_level level, bool suppress_dups) +/* Adds coverage counter information to 'lines'. */ +static void +coverage_read(struct svec *lines) { - static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 3); size_t n_never_hit; uint32_t hash; size_t i; - if (suppress_dups - ? !vlog_is_enabled(THIS_MODULE, level) - : vlog_should_drop(THIS_MODULE, level, &rl)) { - return; - } - hash = coverage_hash(); - if (suppress_dups) { - if (coverage_hit(hash)) { - VLOG(level, "Skipping details of duplicate event coverage for " - "hash=%08"PRIx32" in epoch %u", hash, epoch); - return; - } - } n_never_hit = 0; - VLOG(level, "Event coverage (epoch %u/entire run), hash=%08"PRIx32":", - epoch, hash); + svec_add_nocopy(lines, xasprintf("Event coverage (epoch %u/entire run), " + "hash=%08"PRIx32":", epoch, hash)); for (i = 0; i < n_coverage_counters; i++) { struct coverage_counter *c = coverage_counters[i]; if (c->count) { - coverage_log_counter(level, c); + coverage_read_counter(lines, c); } } for (i = 0; i < n_coverage_counters; i++) { struct coverage_counter *c = coverage_counters[i]; if (!c->count) { if (c->total) { - coverage_log_counter(level, c); + coverage_read_counter(lines, c); } else { n_never_hit++; } } } - VLOG(level, "%zu events never hit", n_never_hit); + 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. */ diff --git a/lib/coverage.h b/lib/coverage.h index b7db6c47..0f389bfe 100644 --- a/lib/coverage.h +++ b/lib/coverage.h @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, 2010, 2011 Nicira Networks. + * Copyright (c) 2009, 2010, 2011, 2012 Nicira Networks. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -56,7 +56,7 @@ struct coverage_counter { #define COVERAGE_ADD(COUNTER, AMOUNT) counter_##COUNTER.count += (AMOUNT); void coverage_init(void); -void coverage_log(enum vlog_level, bool suppress_dups); +void coverage_log(void); void coverage_clear(void); /* Implementation detail. */ diff --git a/lib/timeval.c b/lib/timeval.c index 98291003..b60ece9e 100644 --- a/lib/timeval.c +++ b/lib/timeval.c @@ -499,11 +499,7 @@ log_poll_interval(long long int last_wakeup) rusage.ru_nivcsw - last_rusage->ru_nivcsw); } } - /* Care should be taken in the value chosen for logging. Depending - * on the configuration, syslog can write changes synchronously, - * which can cause the coverage messages to take longer to log - * than the processing delay that triggered it. */ - coverage_log(VLL_INFO, true); + coverage_log(); } /* Update exponentially weighted moving average. With these parameters, a |