You mean, like in the note I've had on my whiteboard all day? Sure :-)
On Wed, Apr 25, 2012 at 07:09:43PM -0700, Ethan Jackson wrote:
> Justin made a good point: It would be nice if as a follow up patch
> ovs-bugtool could store the result of this command.
>
> Ethan
>
> On Wed, Apr 25, 2012 at 19:04, Ethan Jackson <et...@nicira.com> wrote:
> > Looks good, thanks.
> >
> > Ethan
> >
> > On Fri, Apr 20, 2012 at 14:10, Ben Pfaff <b...@nicira.com> wrote:
> >> I've had a few complaints that ovs-vswitchd logs its coverage counters
> >> at WARN level, but this is mainly wrong: ovs-vswitchd only logs coverage
> >> counters at WARN level when the "coverage/log" command is used through
> >> ovs-appctl. This was even documented.
> >>
> >> The reason to log at such a high level was to make it fairly certain that
> >> these messages specifically requested by the admin would not be filtered
> >> out before making it to the log. But it's even better if the admin just
> >> gets the coverage counters as a reply to the ovs-appctl command. So that
> >> is what this commit does.
> >>
> >> This commit also improves the documentation of the ovs-appctl command.
> >>
> >> Signed-off-by: Ben Pfaff <b...@nicira.com>
> >> ---
> >> NEWS | 3 +
> >> lib/automake.mk | 1 +
> >> lib/coverage-unixctl.man | 11 +++++
> >> lib/coverage.c | 91
> >> ++++++++++++++++++++++++++++----------------
> >> lib/coverage.h | 4 +-
> >> lib/timeval.c | 6 +--
> >> manpages.mk | 2 +
> >> ovsdb/ovsdb-server.1.in | 1 +
> >> vswitchd/ovs-vswitchd.8.in | 2 -
> >> 9 files changed, 79 insertions(+), 42 deletions(-)
> >> create mode 100644 lib/coverage-unixctl.man
> >>
> >> diff --git a/NEWS b/NEWS
> >> index 9c73352..e717a4a 100644
> >> --- a/NEWS
> >> +++ b/NEWS
> >> @@ -12,6 +12,9 @@ post-v1.6.0
> >> - Added support for spawning ovs-test server from the client.
> >> - Now ovs-test is able to automatically create test bridges and
> >> ports.
> >> - "ovs-dpctl dump-flows" now prints observed TCP flags in TCP flows.
> >> + - The "coverage/log" command previously available through ovs-appctl
> >> + has been replaced by "coverage/show". The new command replies with
> >> + coverage counter values, instead of logging them.
> >>
> >>
> >> v1.6.0 - xx xxx xxxx
> >> diff --git a/lib/automake.mk b/lib/automake.mk
> >> index 5ce287f..2d2617e 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 0000000..9718894
> >> --- /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 ff20f5e..ee27af0 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 b7db6c4..0f389bf 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 9829100..b60ece9 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
> >> diff --git a/manpages.mk b/manpages.mk
> >> index 14bb41f..1773263 100644
> >> --- a/manpages.mk
> >> +++ b/manpages.mk
> >> @@ -34,6 +34,7 @@ ovsdb/ovsdb-server.1: \
> >> ovsdb/ovsdb-server.1.in \
> >> lib/common-syn.man \
> >> lib/common.man \
> >> + lib/coverage-unixctl.man \
> >> lib/daemon-syn.man \
> >> lib/daemon.man \
> >> lib/ssl-bootstrap-syn.man \
> >> @@ -51,6 +52,7 @@ ovsdb/ovsdb-server.1: \
> >> ovsdb/ovsdb-server.1.in:
> >> lib/common-syn.man:
> >> lib/common.man:
> >> +lib/coverage-unixctl.man:
> >> lib/daemon-syn.man:
> >> lib/daemon.man:
> >> lib/ssl-bootstrap-syn.man:
> >> diff --git a/ovsdb/ovsdb-server.1.in b/ovsdb/ovsdb-server.1.in
> >> index 9e2d79a..dfe9208 100644
> >> --- a/ovsdb/ovsdb-server.1.in
> >> +++ b/ovsdb/ovsdb-server.1.in
> >> @@ -123,6 +123,7 @@ This command might be useful for debugging issues with
> >> database
> >> clients.
> >> .
> >> .so lib/vlog-unixctl.man
> >> +.so lib/coverage-unixctl.man
> >> .so lib/stress-unixctl.man
> >> .SH "SEE ALSO"
> >> .
> >> diff --git a/vswitchd/ovs-vswitchd.8.in b/vswitchd/ovs-vswitchd.8.in
> >> index 1abae6f..6c9f3e4 100644
> >> --- a/vswitchd/ovs-vswitchd.8.in
> >> +++ b/vswitchd/ovs-vswitchd.8.in
> >> @@ -108,8 +108,6 @@ how to configure Open vSwitch.
> >> .SS "GENERAL COMMANDS"
> >> .IP "\fBexit\fR"
> >> Causes \fBovs\-vswitchd\fR to gracefully terminate.
> >> -.IP "\fBcoverage/log\fR"
> >> -Logs coverage counters at level warn.
> >> .IP "\fBqos/show\fR \fIinterface\fR"
> >> Queries the kernel for Quality of Service configuration and statistics
> >> associated with the given \fIinterface\fR.
> >> --
> >> 1.7.2.5
> >>
> >> _______________________________________________
> >> dev mailing list
> >> dev@openvswitch.org
> >> http://openvswitch.org/mailman/listinfo/dev
_______________________________________________
dev mailing list
dev@openvswitch.org
http://openvswitch.org/mailman/listinfo/dev
