On Wed, Mar 7, 2018 at 9:01 AM, Mark Michelson <[email protected]> wrote: > > This is similar to the existing coverage and perf-counter APIs in OVS. > However, rather than keeping counters, this is aimed at timing how long > operations take to perform. "Operations" in this case can be anything > from a loop iteration, to a function, to something more complex. > > The library allows for named stopwatches to be created. From there, the > stopwatch can be started and stopped via stopwatch_start() and > stopwatch_stop(). After each run, statistics for the stopwatch will be > calculated. > > Statistics for a particular stopwatch can be queried from the command > line by using ovs-appctl -t <target> stopwatch/show <stopwatch name>. > > Statistics can be reset from the command line using > ovs-appctl -t <target> stopwatch/reset <stopwatch name> > > Signed-off-by: Mark Michelson <[email protected]> > --- > lib/automake.mk | 2 + > lib/stopwatch.c | 497 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++ > lib/stopwatch.h | 41 +++++ > 3 files changed, 540 insertions(+) > create mode 100644 lib/stopwatch.c > create mode 100644 lib/stopwatch.h > > diff --git a/lib/automake.mk b/lib/automake.mk > index 5c26e0f33..7784057c9 100644 > --- a/lib/automake.mk > +++ b/lib/automake.mk > @@ -222,6 +222,8 @@ lib_libopenvswitch_la_SOURCES = \ > lib/pcap-file.h \ > lib/perf-counter.h \ > lib/perf-counter.c \ > + lib/stopwatch.h \ > + lib/stopwatch.c \ > lib/poll-loop.c \ > lib/process.c \ > lib/process.h \ > diff --git a/lib/stopwatch.c b/lib/stopwatch.c > new file mode 100644 > index 000000000..9b7847bf5 > --- /dev/null > +++ b/lib/stopwatch.c > @@ -0,0 +1,497 @@ > +/* Copyright (c) 2017 Red Hat, Inc. > + * > + * Licensed under the Apache License, Version 2.0 (the "License"); > + * you may not use this file except in compliance with the License. > + * You may obtain a copy of the License at: > + * > + * http://www.apache.org/licenses/LICENSE-2.0 > + * > + * Unless required by applicable law or agreed to in writing, software > + * distributed under the License is distributed on an "AS IS" BASIS, > + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. > + * See the License for the specific language governing permissions and > + * limitations under the License. > + */ > + > +#include <config.h> > + > +#include "stopwatch.h" > +#include "openvswitch/shash.h" > +#include "openvswitch/vlog.h" > +#include "unixctl.h" > +#include "openvswitch/dynamic-string.h" > +#include "openvswitch/poll-loop.h" > +#include "ovs-thread.h" > +#include <unistd.h> > +#include "socket-util.h" > + > +VLOG_DEFINE_THIS_MODULE(stopwatch); > + > +struct average { > + double average; /* Moving average */ > + double alpha; /* Weight given to new samples */ > +}; > + > +#define MARKERS 5 > + > +/* Number of samples to collect before reporting P-square calculated > + * percentile > + */ > +#define P_SQUARE_MIN 50 > + > +/* The naming of these fields is based on the naming used in the > + * P-square algorithm paper. > + */ > +struct percentile { > + int n[MARKERS]; > + double n_prime[MARKERS]; > + double q[MARKERS]; > + double dn[MARKERS]; > + unsigned long long samples[P_SQUARE_MIN]; > + double percentile; > +}; > + > +struct stopwatch { > + enum stopwatch_units units; > + unsigned long long n_samples; > + unsigned long long max; > + unsigned long long min; > + struct percentile pctl; > + struct average short_term; > + struct average long_term; > + unsigned long long sample_start; > + bool sample_in_progress; > +}; > + > +enum stopwatch_op { > + OP_START_SAMPLE, > + OP_END_SAMPLE, > + OP_RESET, > + OP_SHUTDOWN, > +}; > + > +struct stopwatch_packet { > + enum stopwatch_op op; > + char name[32]; > + unsigned long long time; > +}; > + > +static struct shash stopwatches = SHASH_INITIALIZER(&stopwatches); > +static struct ovs_mutex stopwatches_lock = OVS_MUTEX_INITIALIZER; > + > +static int stopwatch_pipe[2]; > +static pthread_t stopwatch_thread_id; > + > +static const char *unit_name[] = { > + [SW_MS] = "msec", > + [SW_US] = "usec", > + [SW_NS] = "nsec", > +}; > + > +/* Percentile value we are calculating */ > +#define P 0.95 > + > +static int > +comp_samples(const void *left, const void *right) > +{ > + const double *left_d = left; > + const double *right_d = right; > + > + return (int) *right_d - *left_d; > +} > + > +/* Calculate the percentile using the P-square algorithm. For more > + * information, see https://www1.cse.wustl.edu/~jain/papers/ftp/psqr.pdf > + */ > +static void > +calc_percentile(unsigned long long n_samples, struct percentile *pctl, > + unsigned long long new_sample) > +{ > + > + if (n_samples < P_SQUARE_MIN) { > + pctl->samples[n_samples - 1] = new_sample; > + } > + > + /* For the first MARKERS samples, we calculate the percentile > + * in the traditional way in the pct->q array. > + */ > + if (n_samples <= MARKERS) { > + pctl->q[n_samples - 1] = new_sample; > + qsort(pctl->q, n_samples, sizeof *pctl->q, comp_samples); > + if (n_samples == MARKERS) { > + pctl->n[0] = 0; > + pctl->n[1] = 1; > + pctl->n[2] = 2; > + pctl->n[3] = 3; > + pctl->n[4] = 4; > + > + pctl->n_prime[0] = 0; > + pctl->n_prime[1] = 2 * P; > + pctl->n_prime[2] = 4 * P; > + pctl->n_prime[3] = 2 + 2 * P; > + pctl->n_prime[4] = 4; > + > + pctl->dn[0] = 0; > + pctl->dn[1] = P / 2; > + pctl->dn[2] = P; > + pctl->dn[3] = (1 + P) / 2; > + pctl->dn[4] = 1; > + } > + pctl->percentile = pctl->q[(int) P * n_samples]; > + return; > + } > + > + /* From here on, update the markers using quadratic spline calculations */ > + int k; > + if (new_sample < pctl->q[0]) { > + k = 0; > + pctl->q[0] = new_sample; > + } else if (new_sample < pctl->q[1]) { > + k = 0; > + } else if (new_sample < pctl->q[2]) { > + k = 1; > + } else if (new_sample < pctl->q[3]) { > + k = 2; > + } else if (new_sample <= pctl->q[4]) { > + k = 3; > + } else { > + k = 3; > + pctl->q[4] = new_sample; > + } > + > + for (int i = k + 1; i < MARKERS; i++) { > + pctl->n[i]++; > + } > + > + for (int i = 0; i < MARKERS; i++) { > + pctl->n_prime[i] += pctl->dn[i]; > + } > + > + for (int i = 1; i < MARKERS - 1; i++) { > + double d = pctl->n_prime[i] - pctl->n[i]; > + > + if ((d >= 1 && pctl->n[i + 1] - pctl->n[i] > 1) || > + (d <= -1 && pctl->n[i - 1] - pctl->n[i] < -1)) { > + d = d >= 0 ? 1 : -1; > + > + double a = d / (pctl->n[i + 1] - pctl->n[i - 1]); > + double b = (pctl->n[i] - pctl->n[i - 1] + d) * > + (pctl->q[i + 1] - pctl->q[i]) / (pctl->n[i + 1] - pctl->n[i]); > + double c = (pctl->n[i + 1] - pctl->n[i] - d) * > + (pctl->q[i] - pctl->q[i - 1]) / (pctl->n[i] - pctl->n[i - 1]); > + > + double candidate = pctl->q[i] + a * (b + c); > + if (pctl->q[i - 1] < candidate && candidate < pctl->q[i + 1]) { > + pctl->q[i] = candidate; > + } else { > + pctl->q[i] = pctl->q[i] + > + (d * (pctl->q[i + (int)d] - pctl->q[i]) / > + (pctl->n[i +(int)d] - pctl->n[i])); > + } > + > + pctl->n[i] += d; > + } > + } > + > + /* Without enough samples, P-square is not very accurate. Until we reach > + * P_SQUARE_MIN, use a traditional calculation for the percentile. > + */ > + if (n_samples < P_SQUARE_MIN) { > + qsort(pctl->samples, n_samples, sizeof *pctl->samples, comp_samples); > + pctl->percentile = pctl->samples[(int) (P * n_samples)]; > + } else { > + pctl->percentile = pctl->q[2]; > + } > +} > + > +static void > +calc_average(struct average *avg, double new_sample) > +{ > + avg->average = new_sample * avg->alpha + (1 - avg->alpha) * avg->average; > +} > + > +static void > +add_sample(struct stopwatch *sw, unsigned long long new_sample) > +{ > + if (new_sample > sw->max) { > + sw->max = new_sample; > + } > + > + if (new_sample < sw->min || sw->n_samples == 0) { > + sw->min = new_sample; > + } > + > + calc_percentile(sw->n_samples, &sw->pctl, new_sample); > + > + if (sw->n_samples++ == 0) { > + sw->short_term.average = sw->long_term.average = new_sample; > + return; > + } > + > + calc_average(&sw->short_term, new_sample); > + calc_average(&sw->long_term, new_sample); > +} > + > +static void > +stopwatch_print(struct stopwatch *sw, const char *name, > + struct ds *s) > +{ > + ds_put_format(s, "Statistics for '%s'\n", name); > + > + const char *units = unit_name[sw->units]; > + ds_put_format(s, "\t Total samples: %llu\n", sw->n_samples); > + ds_put_format(s, "\t Maximum: %llu %s\n", sw->max, units); > + ds_put_format(s, "\t Minimum: %llu %s\n", sw->min, units); > + ds_put_format(s, "\t 95th percentile: %f %s\n", > + sw->pctl.percentile, units); > + ds_put_format(s, "\t Short term average: %f %s\n", > + sw->short_term.average, units); > + ds_put_format(s, "\t Long term average: %f %s\n", > + sw->long_term.average, units); > +} > + > +static bool > +stopwatch_show_protected(int argc, const char *argv[], struct ds *s) > +{ > + struct stopwatch *sw; > + > + if (argc > 1) { > + sw = shash_find_data(&stopwatches, argv[1]); > + if (!sw) { > + ds_put_cstr(s, "No such stopwatch"); > + return false; > + } > + stopwatch_print(sw, argv[1], s); > + } else { > + struct shash_node *node; > + SHASH_FOR_EACH (node, &stopwatches) { > + sw = node->data; > + stopwatch_print(sw, node->name, s); > + } > + } > + > + return true; > +} > + > +static void > +stopwatch_show(struct unixctl_conn *conn, int argc OVS_UNUSED, > + const char *argv[], void *ignore OVS_UNUSED) > +{ > + struct ds s = DS_EMPTY_INITIALIZER; > + bool success; > + > + ovs_mutex_lock(&stopwatches_lock); > + success = stopwatch_show_protected(argc, argv, &s); > + ovs_mutex_unlock(&stopwatches_lock); > + > + if (success) { > + unixctl_command_reply(conn, ds_cstr(&s)); > + } else { > + unixctl_command_reply_error(conn, ds_cstr(&s)); > + } > + ds_destroy(&s); > +} > + > +static void > +stopwatch_reset(struct unixctl_conn *conn, int argc OVS_UNUSED, > + const char *argv[], void *ignore OVS_UNUSED) > +{ > + struct stopwatch_packet pkt = { > + .op = OP_RESET, > + }; > + if (argc > 1) { > + ovs_strlcpy(pkt.name, argv[1], sizeof(pkt.name)); > + } > + write(stopwatch_pipe[1], &pkt, sizeof(pkt)); > + unixctl_command_reply(conn, ""); > +} > + > +static bool > +stopwatch_start_sample_protected(const struct stopwatch_packet *pkt) > +{ > + struct stopwatch *sw = shash_find_data(&stopwatches, pkt->name); > + if (!sw) { > + return false; > + } > + > + /* We already started sampling. Need an end before > + * we start another sample > + */ > + if (sw->sample_in_progress) { > + return false; > + } > + > + sw->sample_start = pkt->time; > + sw->sample_in_progress = true; > + return true; > +} > + > +static bool The return value is not used. Any consideration of using it in the future to report error when start/stop doesn't match? Or just not needed, and return void? > +stopwatch_end_sample_protected(const struct stopwatch_packet *pkt) > +{ > + struct stopwatch *sw = shash_find_data(&stopwatches, pkt->name); > + if (!sw) { > + return false; > + } > + > + /* We can't end a sample if we haven't started one */ > + if (!sw->sample_in_progress) { > + return false; > + } > + > + add_sample(sw, pkt->time - sw->sample_start); > + sw->sample_in_progress = false; > + return true; > +} > + > +static void reset_stopwatch(struct stopwatch *sw) > +{ > + sw->short_term.average = 0; > + sw->long_term.average = 0; > + sw->pctl.percentile = 0; > + sw->n_samples = 0; > + sw->max = 0; > + sw->min = 0; > + /* Don't reset sw->sample_start or sw->sample_in_progress. > + * This way, if a sample was currently in progress, it can be > + * concluded properly after the reset. > + */ > +} > + > +static void > +stopwatch_reset_protected(const struct stopwatch_packet *pkt) > +{ > + if (pkt->name[0]) { > + struct stopwatch *sw = shash_find_data(&stopwatches, pkt->name); > + if (!sw) { > + return; > + } > + reset_stopwatch(sw); > + return; > + } > + > + struct shash_node *node; > + SHASH_FOR_EACH (node, &stopwatches) { > + struct stopwatch *sw = node->data; > + reset_stopwatch(sw); > + } > +} > + > +static void * > +stopwatch_thread(void *ign OVS_UNUSED) > +{ > + bool should_exit = false; > + > + while (!should_exit) { > + struct stopwatch_packet pkt; > + while (read(stopwatch_pipe[0], &pkt, sizeof(pkt)) > 0) { > + ovs_mutex_lock(&stopwatches_lock); > + switch (pkt.op) { > + case OP_START_SAMPLE: > + stopwatch_start_sample_protected(&pkt); > + break; > + case OP_END_SAMPLE: > + stopwatch_end_sample_protected(&pkt); > + break; > + case OP_RESET: > + stopwatch_reset_protected(&pkt); > + break; > + case OP_SHUTDOWN: > + should_exit = true; > + break; > + } > + ovs_mutex_unlock(&stopwatches_lock); > + } > + > + if (!should_exit) { > + poll_fd_wait(stopwatch_pipe[0], POLLIN); > + poll_block(); > + } > + } > + > + return NULL; > +} > + > +static void > +stopwatch_exit(void) > +{ > + struct shash_node *node, *node_next; > + struct stopwatch_packet pkt = { > + .op = OP_SHUTDOWN, > + }; > + > + write(stopwatch_pipe[1], &pkt, sizeof pkt); > + xpthread_join(stopwatch_thread_id, NULL); > + > + /* Process is exiting and we have joined the only > + * other competing thread. We are now the sole owners > + * of all data in the file. > + */ > + SHASH_FOR_EACH_SAFE (node, node_next, &stopwatches) { > + struct stopwatch *sw = node->data; > + shash_delete(&stopwatches, node); > + free(sw); > + } > + shash_destroy(&stopwatches); > + ovs_mutex_destroy(&stopwatches_lock); > +} > + > +static void > +do_init_stopwatch(void) > +{ > + unixctl_command_register("stopwatch/show", "[NAME]", 0, 1, > + stopwatch_show, NULL); > + unixctl_command_register("stopwatch/reset", "[NAME]", 0, 1, > + stopwatch_reset, NULL); > + xpipe_nonblocking(stopwatch_pipe); > + stopwatch_thread_id = ovs_thread_create( > + "stopwatch", stopwatch_thread, NULL); > + atexit(stopwatch_exit); > +} > + > +static void > +stopwatch_init(void) > +{ > + static struct ovsthread_once once = OVSTHREAD_ONCE_INITIALIZER; > + if (ovsthread_once_start(&once)) { > + do_init_stopwatch(); > + ovsthread_once_done(&once); > + } > +} > + > +void > +stopwatch_create(const char *name, enum stopwatch_units units) > +{ > + stopwatch_init(); > + > + struct stopwatch *sw = xzalloc(sizeof *sw); > + sw->units = units; > + sw->short_term.alpha = 0.50; > + sw->long_term.alpha = 0.01; > + > + ovs_mutex_lock(&stopwatches_lock); > + shash_add(&stopwatches, name, sw); > + ovs_mutex_unlock(&stopwatches_lock); > +} > + > +void > +stopwatch_start(const char *name, unsigned long long ts) > +{ > + struct stopwatch_packet pkt = { > + .op = OP_START_SAMPLE, > + .time = ts, > + }; > + ovs_strlcpy(pkt.name, name, sizeof(pkt.name)); > + write(stopwatch_pipe[1], &pkt, sizeof(pkt)); > +} > + > +void > +stopwatch_stop(const char *name, unsigned long long ts) > +{ > + struct stopwatch_packet pkt = { > + .op = OP_END_SAMPLE, > + .time = ts, > + }; > + ovs_strlcpy(pkt.name, name, sizeof(pkt.name)); > + write(stopwatch_pipe[1], &pkt, sizeof(pkt)); > +} > diff --git a/lib/stopwatch.h b/lib/stopwatch.h > new file mode 100644 > index 000000000..61f814523 > --- /dev/null > +++ b/lib/stopwatch.h > @@ -0,0 +1,41 @@ > +/* Copyright (c) 2017 Red Hat, Inc. > + * > + * Licensed under the Apache License, Version 2.0 (the "License"); > + * you may not use this file except in compliance with the License. > + * You may obtain a copy of the License at: > + * > + * http://www.apache.org/licenses/LICENSE-2.0 > + * > + * Unless required by applicable law or agreed to in writing, software > + * distributed under the License is distributed on an "AS IS" BASIS, > + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. > + * See the License for the specific language governing permissions and > + * limitations under the License. > + */ > + > +#ifndef STOPWATCH_H > +#define STOPWATCH_H 1 > + > +#include <stdbool.h> > + > +enum stopwatch_units { > + SW_MS, > + SW_US, > + SW_NS, > +}; > + > +/* Create a new stopwatch. > + * The "units" are not used for any calculations but are printed when > + * statistics are requested. > + */ > +void stopwatch_create(const char *name, enum stopwatch_units units); > + > +/* Start a stopwatch. */ > +void stopwatch_start(const char *name, unsigned long long ts); > + > +/* Stop a stopwatch. The elapsed time will be used for updating statistics > + * for this stopwatch. > + */ > +void stopwatch_stop(const char *name, unsigned long long ts); > + > +#endif /* stopwatch.h */ > -- > 2.14.3 > > _______________________________________________ > dev mailing list > [email protected] > https://mail.openvswitch.org/mailman/listinfo/ovs-dev
Acked-by: Han Zhou <[email protected]> _______________________________________________ dev mailing list [email protected] https://mail.openvswitch.org/mailman/listinfo/ovs-dev
