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 <mmich...@redhat.com> --- lib/automake.mk | 2 + lib/stopwatch.c | 483 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++ lib/stopwatch.h | 41 +++++ 3 files changed, 526 insertions(+) create mode 100644 lib/stopwatch.c create mode 100644 lib/stopwatch.h diff --git a/lib/automake.mk b/lib/automake.mk index c7eda6e31..0161a946b 100644 --- a/lib/automake.mk +++ b/lib/automake.mk @@ -224,6 +224,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..d33976c28 --- /dev/null +++ b/lib/stopwatch.c @@ -0,0 +1,483 @@ +/* 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 void +stopwatch_start_sample_protected(const struct stopwatch_packet *pkt) +{ + struct stopwatch *sw = shash_find_data(&stopwatches, pkt->name); + if (!sw || sw->sample_in_progress) { + return; + } + + sw->sample_start = pkt->time; + sw->sample_in_progress = true; +} + +static void +stopwatch_end_sample_protected(const struct stopwatch_packet *pkt) +{ + struct stopwatch *sw = shash_find_data(&stopwatches, pkt->name); + if (!sw || !sw->sample_in_progress) { + return; + } + + add_sample(sw, pkt->time - sw->sample_start); + sw->sample_in_progress = false; +} + +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 d...@openvswitch.org https://mail.openvswitch.org/mailman/listinfo/ovs-dev