[ovs-dev] [PATCH v3 1/2] Add performance measuring API

Mark Michelson mmichels at redhat.com
Fri Feb 9 23:00:33 UTC 2018


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 will keep track of how long it takes to perform the
particular operations and will maintain statistics of those running
times.

Statistics for a particular operation can be queried from the command
line by using ovs-appctl -t <target> performance/show <operation name>.

The API is designed to be pretty small. The expected steps are as
follows:

1) Create a performance measurement, providing a unique name, using
performance_create()
2) Add calls to start_sample() and end_sample() to mark the start and
stop of the operation you wish to measure.

A background thread will keep track of the provided measurements and
periodically remove old measurements.

Signed-off-by: Mark Michelson <mmichels at redhat.com>
---
 lib/automake.mk   |   2 +
 lib/performance.c | 497 ++++++++++++++++++++++++++++++++++++++++++++++++++++++
 lib/performance.h |  41 +++++
 3 files changed, 540 insertions(+)
 create mode 100644 lib/performance.c
 create mode 100644 lib/performance.h

diff --git a/lib/automake.mk b/lib/automake.mk
index 38d2a999d..60a830715 100644
--- a/lib/automake.mk
+++ b/lib/automake.mk
@@ -207,6 +207,8 @@ lib_libopenvswitch_la_SOURCES = \
 	lib/pcap-file.h \
 	lib/perf-counter.h \
 	lib/perf-counter.c \
+	lib/performance.h \
+	lib/performance.c \
 	lib/poll-loop.c \
 	lib/process.c \
 	lib/process.h \
diff --git a/lib/performance.c b/lib/performance.c
new file mode 100644
index 000000000..f842375cf
--- /dev/null
+++ b/lib/performance.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 "performance.h"
+#include "timer.h"
+#include "timeval.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(performance);
+
+struct sample {
+    unsigned long long start_time; /* Time when we started this sample */
+    unsigned long long end_time;   /* Time when we ended this sample */
+    unsigned long long elapsed;    /* Elapsed time: end_time - start_time */
+};
+
+struct sample_vec {
+    struct sample *samples; /* Dynamic array of samples */
+    size_t n_samples;       /* Number of samples */
+    size_t capacity;        /* Number of allocated samples */
+    size_t max_size;
+};
+
+struct stats {
+    unsigned long long min;         /* Minimum measurement (ms) */
+    unsigned long long max;         /* Maximum measurement (ms) */
+    double average;                 /* Average measurement (ms) */
+    unsigned long long percentile;  /* 95th percentile measurement (ms) */
+    unsigned long long num_samples; /* Total number of measurements */
+};
+
+struct performance {
+    struct sample_vec vec;
+    struct timer timer;
+    struct sample cur_sample;
+    enum performance_units units;
+};
+
+static struct shash performances = SHASH_INITIALIZER(&performances);
+static struct ovs_mutex performances_lock = OVS_MUTEX_INITIALIZER;
+
+static int performance_pipe[2];
+static pthread_t performance_thread_id;
+
+#define PERFORMANCE_INTERVAL 10000
+
+/* Maximum size the sample vector can grow to.
+ * These are generous sizes. In practice, even
+ * with very quick operations going constantly,
+ * it's not likely to exceed a fifth of the
+ * maximum size.*/
+const size_t max_performance_size[] = {
+    [PERF_MS] = 120000,
+    [PERF_US] = 2000000,
+};
+
+/* Oldest sample that can exist in the sample vector */
+const unsigned long long performance_oldest[] = {
+    [PERF_MS] = 60000llu,
+    [PERF_US] = 1000000llu,
+};
+
+const unsigned long long one_min[] = {
+    [PERF_MS] = 60000llu,
+    [PERF_US] = 60000000llu,
+};
+
+const unsigned long long thirty_sec[] = {
+    [PERF_MS] = 30000llu,
+    [PERF_US] = 30000000llu,
+};
+
+const unsigned long long ten_sec[] = {
+    [PERF_MS] = 10000llu,
+    [PERF_US] = 10000000llu,
+};
+
+const char *unit_name[] = {
+    [PERF_MS] = "msec",
+    [PERF_US] = "usec",
+};
+
+static void
+add_sample(struct sample_vec *vec, struct sample *new_sample)
+{
+    if (vec->capacity == vec->n_samples) {
+        if (vec->capacity < vec->max_size) {
+            /* Grow */
+            vec->samples = x2nrealloc(vec->samples, &vec->capacity,
+                                      sizeof *vec->samples);
+        } else {
+            /* Erase oldest sample */
+            memmove(vec->samples, vec->samples + 1,
+                    (vec->n_samples - 1) * sizeof *vec->samples);
+            vec->samples[vec->n_samples - 1] = *new_sample;
+            return;
+        }
+    }
+
+    vec->samples[vec->n_samples++] = *new_sample;
+}
+
+static int
+find_earliest(const struct sample_vec *vec, unsigned long long age)
+{
+    unsigned long long cutoff = time_msec() - age;
+
+    for (int i = 0; i < vec->n_samples; i++) {
+        if (vec->samples[i].end_time >= cutoff) {
+            return i;
+        }
+    }
+
+    /* Either the vector is empty or all times are
+     * older than the cutoff.
+     */
+    return -1;
+}
+
+static double
+average(const struct sample *samples, size_t num_samples)
+{
+    /* Avoid division by zero */
+    if (num_samples == 0) {
+        return 0;
+    }
+
+    long long int sum = 0;
+    for (size_t i = 0; i < num_samples; i++) {
+        sum += samples[i].elapsed;
+    }
+
+    return sum / (double) num_samples;
+}
+
+/* Calculate a specific percentile value.
+ * Valid percentile values range from 0 to 99
+ */
+static long long int
+percentile(const struct sample *samples, size_t num_samples, int percentile)
+{
+    if (num_samples == 0) {
+        return 0;
+    }
+
+    size_t pctl = num_samples * percentile / 100;
+    return samples[pctl].elapsed;
+}
+
+static void
+cull_old_times(struct sample_vec *vec, unsigned long long int age)
+{
+    int i = find_earliest(vec, age);
+
+    if (i <= 0) {
+        return;
+    }
+
+    size_t new_size = vec->n_samples - i;
+    memmove(vec->samples, &vec->samples[i], new_size * sizeof *vec->samples);
+    vec->n_samples = new_size;
+}
+
+static void
+format_stats(struct ds *s, const char *prefix, const struct stats *stats,
+             const char *units)
+{
+    if (stats->num_samples) {
+        ds_put_format(s, "\t%s samples: %llu\n", prefix,
+                      stats->num_samples);
+        ds_put_format(s, "\t%s minimum: %llu %s\n", prefix,
+                      stats->min, units);
+        ds_put_format(s, "\t%s maximum: %llu %s\n", prefix,
+                      stats->max, units);
+        ds_put_format(s, "\t%s average: %.3f %s\n", prefix,
+                      stats->average, units);
+        ds_put_format(s, "\t%s 95th percentile: %llu %s\n\n", prefix,
+                      stats->percentile, units);
+    } else {
+        ds_put_format(s, "\t%s samples: 0\n", prefix);
+        ds_put_format(s, "\t%s minimum: N/A\n", prefix);
+        ds_put_format(s, "\t%s maximum: N/A\n", prefix);
+        ds_put_format(s, "\t%s average: N/A\n", prefix);
+        ds_put_format(s, "\t%s 95th percentile: N/A\n\n", prefix);
+    }
+}
+
+static int
+cmp_times(const void *left_, const void *right_)
+{
+    const struct sample *left = left_;
+    const struct sample *right = right_;
+
+    return left->elapsed == right->elapsed ? 0
+        : left->elapsed > right->elapsed;
+}
+
+static struct sample *
+sorted_copy_times(const struct sample *by_time, size_t vec_size)
+{
+    struct sample *copy = xmemdup(by_time, vec_size * sizeof *copy);
+    qsort(copy, vec_size, sizeof *copy, cmp_times);
+
+    return copy;
+}
+
+static void
+get_stats(const struct sample_vec *vec, long long int age_ms,
+          struct stats *stats)
+{
+    int start_idx = find_earliest(vec, age_ms);
+    if (start_idx < 0) {
+        memset(stats, 0, sizeof *stats);
+        return;
+    }
+    size_t vec_size = vec->n_samples - start_idx;
+
+    struct sample *by_time = &vec->samples[start_idx];
+    struct sample *by_elapsed = sorted_copy_times(by_time, vec_size);
+
+    stats->min = by_elapsed[0].elapsed;
+    stats->max = by_elapsed[vec_size - 1].elapsed;
+    stats->average = average(by_time, vec_size);
+    stats->percentile = percentile(by_elapsed, vec_size, 95);
+    stats->num_samples = vec_size;
+
+    free(by_elapsed);
+}
+
+static void
+performance_print(struct performance *perf, const char *name,
+                  struct ds *s)
+{
+    struct stats ten_sec_stats;
+    struct stats thirty_sec_stats;
+    struct stats one_min_stats;
+    ds_put_format(s, "Statistics for '%s'\n", name);
+
+    get_stats(&perf->vec, ten_sec[perf->units], &ten_sec_stats);
+    get_stats(&perf->vec, thirty_sec[perf->units], &thirty_sec_stats);
+    get_stats(&perf->vec, one_min[perf->units], &one_min_stats);
+
+    const char *units = unit_name[perf->units];
+    format_stats(s, "10 seconds", &ten_sec_stats, units);
+    format_stats(s, "30 seconds", &thirty_sec_stats, units);
+    format_stats(s, " 1 minute", &one_min_stats, units);
+}
+
+static bool
+performance_show_protected(int argc, const char *argv[], struct ds *s)
+{
+    struct performance *perf;
+
+    if (argc > 1) {
+        perf = shash_find_data(&performances, argv[1]);
+        if (!perf) {
+            ds_put_cstr(s, "No such performance");
+            return false;
+        }
+        performance_print(perf, argv[1], s);
+    } else {
+        struct shash_node *node;
+        SHASH_FOR_EACH (node, &performances) {
+            perf = node->data;
+            performance_print(perf, node->name, s);
+        }
+    }
+
+    return true;
+}
+
+static void
+performance_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(&performances_lock);
+    success = performance_show_protected(argc, argv, &s);
+    ovs_mutex_unlock(&performances_lock);
+
+    if (success) {
+        unixctl_command_reply(conn, ds_cstr(&s));
+    } else {
+        unixctl_command_reply_error(conn, ds_cstr(&s));
+    }
+    ds_destroy(&s);
+}
+
+enum performance_op {
+    OP_START_SAMPLE,
+    OP_END_SAMPLE,
+    OP_SHUTDOWN,
+};
+
+struct performance_packet {
+    enum performance_op op;
+    char name[32];
+    unsigned long long time;
+};
+
+static bool
+performance_start_sample_protected(const struct performance_packet *pkt)
+{
+    struct performance *perf = shash_find_data(&performances, pkt->name);
+    if (!perf) {
+        return false;
+    }
+
+    /* We already started sampling. Need an end before
+     * we start another sample
+     */
+    if (perf->cur_sample.start_time) {
+        return false;
+    }
+
+    perf->cur_sample.start_time = pkt->time;
+    return true;
+}
+
+static bool
+performance_end_sample_protected(const struct performance_packet *pkt)
+{
+    struct performance *perf = shash_find_data(&performances, pkt->name);
+    if (!perf) {
+        return false;
+    }
+
+    /* We can't end a sample if we haven't started one */
+    if (!perf->cur_sample.start_time) {
+        return false;
+    }
+
+    perf->cur_sample.end_time = pkt->time;
+    perf->cur_sample.elapsed = perf->cur_sample.end_time
+        - perf->cur_sample.start_time;
+
+    add_sample(&perf->vec, &perf->cur_sample);
+
+    memset(&perf->cur_sample, 0, sizeof perf->cur_sample);
+    return true;
+}
+
+static void *
+performance_thread(void *ign OVS_UNUSED)
+{
+    struct timer timer;
+    bool should_exit = false;
+
+    timer_set_duration(&timer, PERFORMANCE_INTERVAL);
+
+    while (!should_exit) {
+        if (timer_expired(&timer)) {
+            struct shash_node *node;
+            ovs_mutex_lock(&performances_lock);
+            SHASH_FOR_EACH (node, &performances) {
+                struct performance *perf = node->data;
+                cull_old_times(&perf->vec, performance_oldest[perf->units]);
+            }
+            ovs_mutex_unlock(&performances_lock);
+            timer_set_duration(&timer, PERFORMANCE_INTERVAL);
+        }
+
+        struct performance_packet pkt;
+        if (read(performance_pipe[0], &pkt, sizeof(pkt)) > 0) {
+            ovs_mutex_lock(&performances_lock);
+            switch (pkt.op) {
+            case OP_START_SAMPLE:
+                performance_start_sample_protected(&pkt);
+                break;
+            case OP_END_SAMPLE:
+                performance_end_sample_protected(&pkt);
+                break;
+            case OP_SHUTDOWN:
+                should_exit = true;
+                break;
+            }
+            ovs_mutex_unlock(&performances_lock);
+        }
+
+        if (!should_exit) {
+            timer_wait(&timer);
+            poll_fd_wait(performance_pipe[0], POLLIN);
+            poll_block();
+        }
+    }
+
+    return NULL;
+}
+
+static void
+performance_exit(void)
+{
+    struct shash_node *node, *node_next;
+    struct performance_packet pkt = {
+        .op = OP_SHUTDOWN,
+    };
+
+    write(performance_pipe[1], &pkt, sizeof pkt);
+    xpthread_join(performance_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, &performances) {
+        struct performance *perf = node->data;
+        shash_delete(&performances, node);
+        free(perf->vec.samples);
+        free(perf);
+    }
+    shash_destroy(&performances);
+    ovs_mutex_destroy(&performances_lock);
+}
+
+static void
+do_init_performance(void)
+{
+    unixctl_command_register("performance/show", "[NAME]", 0, 1,
+                             performance_show, NULL);
+    xpipe_nonblocking(performance_pipe);
+    performance_thread_id = ovs_thread_create(
+        "performance", performance_thread, NULL);
+    atexit(performance_exit);
+}
+
+static void
+performance_init(void)
+{
+    static struct ovsthread_once once = OVSTHREAD_ONCE_INITIALIZER;
+    if (ovsthread_once_start(&once)) {
+        do_init_performance();
+        ovsthread_once_done(&once);
+    }
+}
+
+void
+performance_create(const char *name, enum performance_units units)
+{
+    performance_init();
+
+    struct performance *perf = xzalloc(sizeof *perf);
+    perf->units = units;
+    perf->vec.max_size = max_performance_size[units];
+
+    ovs_mutex_lock(&performances_lock);
+    shash_add(&performances, name, perf);
+    ovs_mutex_unlock(&performances_lock);
+}
+
+bool
+performance_start_sample(const char *name, unsigned long long ts)
+{
+    struct performance_packet pkt = {
+        .op = OP_START_SAMPLE,
+        .time = ts,
+    };
+    ovs_strlcpy(pkt.name, name, sizeof(pkt.name));
+    write(performance_pipe[1], &pkt, sizeof(pkt));
+
+    return true;
+}
+
+bool
+performance_end_sample(const char *name, unsigned long long ts)
+{
+    struct performance_packet pkt = {
+        .op = OP_END_SAMPLE,
+        .time = ts,
+    };
+    ovs_strlcpy(pkt.name, name, sizeof(pkt.name));
+    write(performance_pipe[1], &pkt, sizeof(pkt));
+
+    return true;
+}
diff --git a/lib/performance.h b/lib/performance.h
new file mode 100644
index 000000000..c51ea7bcd
--- /dev/null
+++ b/lib/performance.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 PERFORMANCE_H
+#define PERFORMANCE_H 1
+
+#include <stdbool.h>
+
+enum performance_units {
+    PERF_MS,
+    PERF_US,
+};
+
+/* Create a new performance measurement.
+ * The "units" are not used for any calculations but are printed when
+ * statistics are requested.
+ */
+void performance_create(const char *name, enum performance_units units);
+
+/* Indicate that a performance measurement is beginning. */
+bool performance_start_sample(const char *name, unsigned long long ts);
+
+/* Indicate that a performance measurement has ended. The
+ * sample will be added to the history of performance
+ * measurements for this tracker
+ */
+bool performance_end_sample(const char *name, unsigned long long ts);
+
+#endif /* performance.h */
-- 
2.13.6



More information about the dev mailing list