{"id":815650,"url":"http://patchwork.ozlabs.org/api/patches/815650/?format=json","web_url":"http://patchwork.ozlabs.org/project/openvswitch/patch/CFF8EF42F1132E4CBE2BF0AB6C21C58D78813F1B@ESESSMB107.ericsson.se/","project":{"id":47,"url":"http://patchwork.ozlabs.org/api/projects/47/?format=json","name":"Open vSwitch","link_name":"openvswitch","list_id":"ovs-dev.openvswitch.org","list_email":"ovs-dev@openvswitch.org","web_url":"http://openvswitch.org/","scm_url":"git@github.com:openvswitch/ovs.git","webscm_url":"https://github.com/openvswitch/ovs","list_archive_url":"","list_archive_url_format":"","commit_url_format":""},"msgid":"","list_archive_url":null,"date":"2017-09-19T16:30:22","name":"[ovs-dev,2/3] dpif-netdev: Detailed performance stats for PMDs","commit_ref":null,"pull_url":null,"state":"superseded","archived":false,"hash":"af0f6c6ccf4713879c347b94062af83a8b0719c5","submitter":{"id":68449,"url":"http://patchwork.ozlabs.org/api/people/68449/?format=json","name":"Jan Scheurich","email":"jan.scheurich@ericsson.com"},"delegate":null,"mbox":"http://patchwork.ozlabs.org/project/openvswitch/patch/CFF8EF42F1132E4CBE2BF0AB6C21C58D78813F1B@ESESSMB107.ericsson.se/mbox/","series":[{"id":3922,"url":"http://patchwork.ozlabs.org/api/series/3922/?format=json","web_url":"http://patchwork.ozlabs.org/project/openvswitch/list/?series=3922","date":"2017-09-19T16:29:52","name":": dpif-netdev: Detailed PMD performance metrics and supervision","version":1,"mbox":"http://patchwork.ozlabs.org/series/3922/mbox/"}],"comments":"http://patchwork.ozlabs.org/api/patches/815650/comments/","check":"pending","checks":"http://patchwork.ozlabs.org/api/patches/815650/checks/","tags":{},"related":[],"headers":{"Return-Path":"","X-Original-To":["incoming@patchwork.ozlabs.org","ovs-dev@openvswitch.org"],"Delivered-To":["patchwork-incoming@bilbo.ozlabs.org","ovs-dev@mail.linuxfoundation.org"],"Authentication-Results":"ozlabs.org;\n\tspf=pass (mailfrom) smtp.mailfrom=openvswitch.org\n\t(client-ip=140.211.169.12; helo=mail.linuxfoundation.org;\n\tenvelope-from=ovs-dev-bounces@openvswitch.org;\n\treceiver=)","Received":["from mail.linuxfoundation.org (mail.linuxfoundation.org\n\t[140.211.169.12])\n\t(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256\n\tbits)) (No client certificate requested)\n\tby ozlabs.org (Postfix) with ESMTPS id 3xxT0h5hznz9ryT\n\tfor ;\n\tWed, 20 Sep 2017 02:31:48 +1000 (AEST)","from mail.linux-foundation.org (localhost [127.0.0.1])\n\tby mail.linuxfoundation.org (Postfix) with ESMTP id 6DC30BB3;\n\tTue, 19 Sep 2017 16:30:29 +0000 (UTC)","from smtp1.linuxfoundation.org (smtp1.linux-foundation.org\n\t[172.17.192.35])\n\tby mail.linuxfoundation.org (Postfix) with ESMTPS id A8F1A92F\n\tfor ; Tue, 19 Sep 2017 16:30:27 +0000 (UTC)","from sessmg23.ericsson.net (sessmg23.ericsson.net [193.180.251.45])\n\tby smtp1.linuxfoundation.org (Postfix) with ESMTPS id B0D2A484\n\tfor ; Tue, 19 Sep 2017 16:30:23 +0000 (UTC)","from ESESSHC019.ericsson.se (Unknown_Domain [153.88.183.75])\n\tby sessmg23.ericsson.net (Symantec Mail Security) with SMTP id\n\tF0.40.06590.F1641C95; Tue, 19 Sep 2017 18:30:23 +0200 (CEST)","from ESESSMB107.ericsson.se ([169.254.7.166]) by\n\tESESSHC019.ericsson.se ([153.88.183.75]) with mapi id 14.03.0352.000; \n\tTue, 19 Sep 2017 18:30:22 +0200"],"X-Greylist":"domain auto-whitelisted by SQLgrey-1.7.6","X-AuditID":"c1b4fb2d-a65ff700000019be-1f-59c1461f3dd0","From":"Jan Scheurich ","To":"\"ovs-dev@openvswitch.org\" ","Thread-Topic":"[PATCH 2/3] dpif-netdev: Detailed performance stats for PMDs","Thread-Index":"AdMxY5adFvikOFe9TzqVcfECdIjnyg==","Date":"Tue, 19 Sep 2017 16:30:22 +0000","Message-ID":"","Accept-Language":"en-US","Content-Language":"en-US","X-MS-Has-Attach":"","X-MS-TNEF-Correlator":"","x-originating-ip":"[153.88.183.17]","MIME-Version":"1.0","X-Brightmail-Tracker":"H4sIAAAAAAAAA+NgFnrGLMWRmVeSWpSXmKPExsUyM2K7t66828FIg45HIhZzPz1ndGD0eHbz\n\tP2MAYxSXTUpqTmZZapG+XQJXxqVHGxgLZvxiq1h2+DVzA+Om36xdjJwcEgImEj0vu5i6GLk4\n\thASOMEpMfzsBylnCKHF0TydbFyMHB5uAgcTs3Q4gDSIC5hInPpxjB7GFBVwl/ky+wQwR95KY\n\tcWArWLmIgJ5E1+NYkDCLgKrE+jvXWUBsXgFfiY3TO8FsRgExie+n1jCB2MwC4hK3nsxngrhH\n\tQGLJnvPMELaoxMvH/1hBRkoIKEos75eDKM+XWP3xERvESEGJkzOfsExgFJyFZNIsJGWzkJRB\n\txHUkFuz+xAZha0ssW/iaGcY+c+AxE7L4Akb2VYyixanFxbnpRsZ6qUWZycXF+Xl6eaklmxiB\n\toX9wy2/dHYyrXzseYhTgYFTi4V3pcjBSiDWxrLgy9xCjBAezkgjvayegEG9KYmVValF+fFFp\n\tTmrxIUZpDhYlcV6HfRcihATSE0tSs1NTC1KLYLJMHJxSDYy5q6T+2/d9maz4xW7qtXOpV47O\n\teLV1PU/wbKPzbwI5vbyn+tjYh5w8Zui43FK13OD0xd3GXj9eHlh18cec7q/lHWcE3jkt32cl\n\tyH4j2EX9oNl91QLp/KDQa++Yp4lOiovKaA12ztBMSb8ttW3n3a1da27t5XjENcH99LUp26Zn\n\t/K3QeGFxw/e1EktxRqKhFnNRcSIAmesEH3kCAAA=","X-Spam-Status":"No, score=-2.3 required=5.0 tests=HTML_MESSAGE,\n\tRCVD_IN_DNSWL_MED autolearn=disabled version=3.3.1","X-Spam-Checker-Version":"SpamAssassin 3.3.1 (2010-03-16) on\n\tsmtp1.linux-foundation.org","X-Content-Filtered-By":"Mailman/MimeDel 2.1.12","Subject":"[ovs-dev] [PATCH 2/3] dpif-netdev: Detailed performance stats for\n\tPMDs","X-BeenThere":"ovs-dev@openvswitch.org","X-Mailman-Version":"2.1.12","Precedence":"list","List-Id":"","List-Unsubscribe":",\n\t","List-Archive":"","List-Post":"","List-Help":"","List-Subscribe":",\n\t","Content-Type":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Sender":"ovs-dev-bounces@openvswitch.org","Errors-To":"ovs-dev-bounces@openvswitch.org"},"content":"This patch instruments the dpif-netdev datapath to record detailed\nstatistics of what is happening in every iteration of a PMD thread.\n\nThe covered metrics per iteration are:\n - cycles\n - packets\n - (rx) batches\n - packets/batch\n - max. vhostuser qlen\n - upcalls\n - cycles spent in upcalls\n\nThis raw recorded data is used threefold:\n\n1. In histograms for each of the following metrics:\n - cycles/iteration (log.)\n - packets/iteration (log.)\n - cycles/packet\n - packets/batch\n - max. vhostuser qlen (log.)\n - upcalls\n - cycles/upcall (log)\n The histograms bins are divided linear or logarithmic.\n\n2. A cyclic history of the above statistics for 1024 iterations\n\n3. A cyclic history of the cummulative/average values per millisecond\n wall clock for the last 1024 milliseconds:\n - number of iterations\n - avg. cycles/iteration\n - packets (Kpps)\n - avg. packets/batch\n - avg. max vhost qlen\n - upcalls\n - avg. cycles/upcall\n\nThe gathered performance statists can be printed at any time with the\nnew CLI command\n\novs-appctl dpif-netdev/pmd-perf-show [-nh] [-it iter_len] [-ms ms_len]\n [-pmd core] [dp]\n\nThe options are\n\n-nh: Suppress the histograms\n-it iter_len: Display the last iter_len iteration stats\n-ms ms_len: Display the last ms_len millisecond stats\n-pmd core: Display only\n\nThe performance statistics are reset with the existing\ndpif-netdev/pmd-stats-clear command.\n\nThe output always contains the following global PMD statistics,\nsimilar to the pmd-stats-show command:\n\nTime: 15:24:55.270\nMeasurement duration: 1.008 s\n\npmd thread numa_id 0 core_id 1:\n\n Cycles: 2419034712 (2.40 GHz)\n Iterations: 572817 (1.76 us/it)\n - idle: 486808 (15.9 % cycles)\n - busy: 86009 (84.1 % cycles)\n Packets: 2399607 (2381 Kpps, 848 cycles/pkt)\n Datapath passes: 3599415 (1.50 passes/pkt)\n - EMC hits: 336472 ( 9.3 %)\n - Megaflow hits: 3262943 (90.7 %, 1.00 subtbl lookups/hit)\n - Upcalls: 0 ( 0.0 %, 0.0 us/upcall)\n - Lost upcalls: 0 ( 0.0 %)\n\nSigned-off-by: Jan Scheurich \n---\n lib/dp-packet.h | 2 +\n lib/dpif-netdev-perf.c | 306 ++++++++++++++++++++++++++++++++++++++++++++++++-\n lib/dpif-netdev-perf.h | 166 ++++++++++++++++++++++++++-\n lib/dpif-netdev.c | 115 ++++++++++++++++++-\n lib/netdev-dpdk.c | 28 ++++-\n lib/netdev-dpdk.h | 14 +++\n ofproto/ofproto-dpif.c | 3 +-\n 7 files changed, 623 insertions(+), 11 deletions(-)\n\n--\n1.9.1","diff":"diff --git a/lib/dp-packet.h b/lib/dp-packet.h\nindex 046f3ab..9f765e7 100644\n--- a/lib/dp-packet.h\n+++ b/lib/dp-packet.h\n@@ -695,8 +695,10 @@ enum { NETDEV_MAX_BURST = 32 }; /* Maximum number packets in a batch. */\n\n struct dp_packet_batch {\n size_t count;\n+ size_t qfill; /* Number of packets in queue when reading rx burst. */\n bool trunc; /* true if the batch needs truncate. */\n struct dp_packet *packets[NETDEV_MAX_BURST];\n+\n };\n\n static inline void\ndiff --git a/lib/dpif-netdev-perf.c b/lib/dpif-netdev-perf.c\nindex 6a8f7c4..42d93a2 100644\n--- a/lib/dpif-netdev-perf.c\n+++ b/lib/dpif-netdev-perf.c\n@@ -15,6 +15,7 @@\n */\n\n #include \n+#include \n\n #ifdef DPDK_NETDEV\n #include \n@@ -27,13 +28,304 @@\n\n VLOG_DEFINE_THIS_MODULE(pmd_perf);\n\n+#ifdef DPDK_NETDEV\n+static uint64_t\n+get_tsc_hz(void)\n+{\n+ return rte_get_tsc_hz();\n+}\n+#else\n+static uint64_t\n+read_tsc(void)\n+{\n+ register uint64_t tsc asm(\"eax\");\n+ asm volatile (\".byte 15, 49\" : : : \"eax\", \"edx\");\n+ return tsc;\n+}\n+\n+static uint64_t\n+get_tsc_hz(void)\n+{\n+ uint64_t tsc_start = read_tsc();\n+ xsleep(1);\n+ return read_tsc() - tsc_start;\n+}\n+#endif\n+\n+static void\n+histogram_walls_set_lin(struct histogram *hist, uint32_t min, uint32_t max)\n+{\n+ int i;\n+\n+ ovs_assert(min < max);\n+ for (i = 0; i < NUM_BINS-1; i++) {\n+ hist->wall[i] = min + (i * (max - min)) / (NUM_BINS - 2);\n+ }\n+ hist->wall[NUM_BINS-1] = UINT32_MAX;\n+}\n+\n+static void\n+histogram_walls_set_log(struct histogram *hist, uint32_t min, uint32_t max)\n+{\n+ int i, start, bins, wall;\n+ double log_min, log_max;\n+\n+ ovs_assert(min < max);\n+ if (min > 0) {\n+ log_min = log(min);\n+ log_max = log(max);\n+ start = 0;\n+ bins = NUM_BINS - 1;\n+ } else {\n+ hist->wall[0] = 0;\n+ log_min = log(1);\n+ log_max = log(max);\n+ start = 1;\n+ bins = NUM_BINS - 2;\n+ }\n+ wall = start;\n+ for (i = 0; i < bins; i++) {\n+ /* Make sure each wall is monotonically increasing. */\n+ wall = MAX(wall, exp(log_min + (i * (log_max - log_min)) / (bins-1)));\n+ hist->wall[start + i] = wall++;\n+ }\n+ if (hist->wall[NUM_BINS-2] < max) {\n+ hist->wall[NUM_BINS-2] = max;\n+ }\n+ hist->wall[NUM_BINS-1] = UINT32_MAX;\n+}\n+\n+uint64_t\n+histogram_samples(const struct histogram *hist)\n+{\n+ uint64_t samples = 0;\n+\n+ for (int i = 0; i < NUM_BINS; i++) {\n+ samples += hist->bin[i];\n+ }\n+ return samples;\n+}\n+\n+static void\n+histogram_clear(struct histogram *hist)\n+{\n+ int i;\n+\n+ for (i = 0; i < NUM_BINS; i++) {\n+ hist->bin[i] = 0;\n+ }\n+}\n+\n+static void\n+history_init(struct history *h)\n+{\n+ memset(h, 0, sizeof(*h));\n+}\n+\n void\n pmd_perf_stats_init(struct pmd_perf_stats *s) {\n- memset(s, 0 , sizeof(*s));\n+ /* The struct has been zeroed at allocation. */\n+ histogram_walls_set_log(&s->cycles, 500, 24000000);\n+ histogram_walls_set_log(&s->pkts, 0, 1000);\n+ histogram_walls_set_lin(&s->cycles_per_pkt, 100, 30000);\n+ histogram_walls_set_lin(&s->pkts_per_batch, 0, 32);\n+ histogram_walls_set_lin(&s->upcalls, 0, 30);\n+ histogram_walls_set_log(&s->cycles_per_upcall, 1000, 1000000);\n+ histogram_walls_set_log(&s->max_vhost_qfill, 0, 512);\n s->start_ms = time_msec();\n }\n\n void\n+pmd_perf_format_overall_stats(struct ds *str, struct pmd_perf_stats *s,\n+ double duration)\n+{\n+ uint64_t stats[PMD_N_STATS];\n+ double us_per_cycle = 1000000.0 / get_tsc_hz();\n+\n+ if (duration == 0) {\n+ return;\n+ }\n+\n+ pmd_perf_read_counters(s, stats);\n+ uint64_t tot_cycles = stats[PMD_CYCLES_ITER_IDLE] +\n+ stats[PMD_CYCLES_ITER_BUSY];\n+ uint64_t packets = stats[PMD_STAT_RECV];\n+ uint64_t passes = stats[PMD_STAT_RECV] +\n+ stats[PMD_STAT_RECIRC];\n+ uint64_t upcalls = stats[PMD_STAT_MISS];\n+ uint64_t upcall_cycles = stats[PMD_CYCLES_UPCALL];\n+ uint64_t tot_iter = histogram_samples(&s->pkts);\n+ uint64_t idle_iter = s->pkts.bin[0];\n+\n+ ds_put_format(str,\n+ \" Cycles: %12\"PRIu64\" (%.2f GHz)\\n\"\n+ \" Iterations: %12\"PRIu64\" (%.2f us/it)\\n\"\n+ \" - idle: %12\"PRIu64\" (%4.1f %% cycles)\\n\"\n+ \" - busy: %12\"PRIu64\" (%4.1f %% cycles)\\n\",\n+ tot_cycles, (tot_cycles / duration) / 1E9,\n+ tot_iter, tot_cycles * us_per_cycle / tot_iter,\n+ idle_iter,\n+ 100.0 * stats[PMD_CYCLES_ITER_IDLE] / tot_cycles,\n+ tot_iter - idle_iter,\n+ 100.0 * stats[PMD_CYCLES_ITER_BUSY] / tot_cycles);\n+ if (packets > 0) {\n+ ds_put_format(str,\n+ \" Packets: %12\"PRIu64\" (%.0f Kpps, %.0f cycles/pkt)\\n\"\n+ \" Datapath passes: %12\"PRIu64\" (%.2f passes/pkt)\\n\"\n+ \" - EMC hits: %12\"PRIu64\" (%4.1f %%)\\n\"\n+ \" - Megaflow hits: %12\"PRIu64\" (%4.1f %%, %.2f subtbl lookups/\"\n+ \"hit)\\n\"\n+ \" - Upcalls: %12\"PRIu64\" (%4.1f %%, %.1f us/upcall)\\n\"\n+ \" - Lost upcalls: %12\"PRIu64\" (%4.1f %%)\\n\"\n+ \"\\n\",\n+ packets, (packets / duration) / 1000,\n+ 1.0 * stats[PMD_CYCLES_ITER_BUSY] / packets,\n+ passes, packets ? 1.0 * passes / packets : 0,\n+ stats[PMD_STAT_EXACT_HIT],\n+ 100.0 * stats[PMD_STAT_EXACT_HIT] / passes,\n+ stats[PMD_STAT_MASKED_HIT],\n+ 100.0 * stats[PMD_STAT_MASKED_HIT] / passes,\n+ 1.0 * stats[PMD_STAT_MASKED_LOOKUP] / stats[PMD_STAT_MASKED_HIT],\n+ upcalls, 100.0 * upcalls / passes,\n+ upcalls ? (upcall_cycles * us_per_cycle) / upcalls : 0,\n+ stats[PMD_STAT_LOST],\n+ 100.0 * stats[PMD_STAT_LOST] / passes);\n+ } else {\n+ ds_put_format(str,\n+ \" Packets: %12\"PRIu64\"\\n\"\n+ \"\\n\",\n+ 0UL);\n+ }\n+}\n+\n+void\n+pmd_perf_format_histograms(struct ds *str, struct pmd_perf_stats *s)\n+{\n+ int i;\n+\n+ ds_put_cstr(str, \"Histograms\\n\");\n+ ds_put_format(str,\n+ \" %-21s %-21s %-21s %-21s %-21s %-21s %-21s\\n\",\n+ \"cycles/it\", \"packets/it\", \"cycles/pkt\", \"pkts/batch\",\n+ \"max vhost qlen\", \"upcalls/it\", \"cycles/upcall\");\n+ for (i = 0; i < NUM_BINS-1; i++) {\n+ ds_put_format(str,\n+ \" %-9d %-11\"PRIu64\" %-9d %-11\"PRIu64\" %-9d %-11\"PRIu64\n+ \" %-9d %-11\"PRIu64\" %-9d %-11\"PRIu64\" %-9d %-11\"PRIu64\n+ \" %-9d %-11\"PRIu64\"\\n\",\n+ s->cycles.wall[i], s->cycles.bin[i],\n+ s->pkts.wall[i],s->pkts.bin[i],\n+ s->cycles_per_pkt.wall[i], s->cycles_per_pkt.bin[i],\n+ s->pkts_per_batch.wall[i], s->pkts_per_batch.bin[i],\n+ s->max_vhost_qfill.wall[i], s->max_vhost_qfill.bin[i],\n+ s->upcalls.wall[i], s->upcalls.bin[i],\n+ s->cycles_per_upcall.wall[i], s->cycles_per_upcall.bin[i]);\n+ }\n+ ds_put_format(str,\n+ \" %-9s %-11\"PRIu64\" %-9s %-11\"PRIu64\" %-9s %-11\"PRIu64\n+ \" %-9s %-11\"PRIu64\" %-9s %-11\"PRIu64\" %-9s %-11\"PRIu64\n+ \" %-9s %-11\"PRIu64\"\\n\",\n+ \">\", s->cycles.bin[i],\n+ \">\", s->pkts.bin[i],\n+ \">\", s->cycles_per_pkt.bin[i],\n+ \">\", s->pkts_per_batch.bin[i],\n+ \">\", s->max_vhost_qfill.bin[i],\n+ \">\", s->upcalls.bin[i],\n+ \">\", s->cycles_per_upcall.bin[i]);\n+ if (s->totals.iterations > 0) {\n+ ds_put_cstr(str,\n+ \"-----------------------------------------------------\"\n+ \"-----------------------------------------------------\"\n+ \"------------------------------------------------\\n\");\n+ ds_put_format(str,\n+ \" %-21s %-21s %-21s %-21s %-21s %-21s %-21s\\n\",\n+ \"cycles/it\", \"packets/it\", \"cycles/pkt\", \"pkts/batch\",\n+ \"vhost qlen\", \"upcalls/it\", \"cycles/upcall\");\n+ ds_put_format(str,\n+ \" %-21\"PRIu64\" %-21.5f %-21\"PRIu64\n+ \" %-21.5f %-21.5f %-21.5f %-21\"PRIu32\"\\n\",\n+ s->totals.cycles / s->totals.iterations,\n+ 1.0 * s->totals.pkts / s->totals.iterations,\n+ s->totals.pkts\n+ ? s->totals.busy_cycles / s->totals.pkts : 0,\n+ s->totals.batches\n+ ? 1.0 * s->totals.pkts / s->totals.batches : 0,\n+ 1.0 * s->totals.max_vhost_qfill / s->totals.iterations,\n+ 1.0 * s->totals.upcalls / s->totals.iterations,\n+ s->totals.upcalls\n+ ? s->totals.upcall_cycles / s->totals.upcalls : 0);\n+ }\n+}\n+\n+void\n+pmd_perf_format_iteration_history(struct ds *str, struct pmd_perf_stats *s,\n+ int n_iter)\n+{\n+ struct iter_stats *is;\n+ size_t index;\n+ int i;\n+\n+ if (n_iter == 0) {\n+ return;\n+ }\n+ ds_put_format(str, \" %-17s %-10s %-10s %-10s %-10s \"\n+ \"%-10s %-10s %-10s\\n\",\n+ \"tsc\", \"cycles\", \"packets\", \"cycles/pkt\", \"pkts/batch\",\n+ \"vhost qlen\", \"upcalls\", \"cycles/upcall\");\n+ for (i = 1; i <= n_iter; i++) {\n+ index = (s->iterations.idx + HISTORY_LEN - i) % HISTORY_LEN;\n+ is = &s->iterations.sample[index];\n+ ds_put_format(str,\n+ \" %-17\"PRIu64\" %-11\"PRIu64\" %-11\"PRIu32\n+ \" %-11\"PRIu64\" %-11\"PRIu32\" %-11\"PRIu32\n+ \" %-11\"PRIu32\" %-11\"PRIu32\"\\n\",\n+ is->timestamp,\n+ is->cycles,\n+ is->pkts,\n+ is->pkts ? is->cycles / is->pkts : 0,\n+ is->batches ? is->pkts / is->batches : 0,\n+ is->max_vhost_qfill,\n+ is->upcalls,\n+ is->upcalls ? is->upcall_cycles / is->upcalls : 0);\n+ }\n+}\n+\n+void\n+pmd_perf_format_ms_history(struct ds *str, struct pmd_perf_stats *s, int n_ms)\n+{\n+ struct iter_stats *is;\n+ size_t index;\n+ int i;\n+\n+ if (n_ms == 0) {\n+ return;\n+ }\n+ ds_put_format(str,\n+ \" %-12s %-10s %-10s %-10s %-10s\"\n+ \" %-10s %-10s %-10s %-10s\\n\",\n+ \"ms\", \"iterations\", \"cycles/it\", \"Kpps\", \"cycles/pkt\",\n+ \"pkts/batch\", \"vhost qlen\", \"upcalls\", \"cycles/upcall\");\n+ for (i = 1; i <= n_ms; i++) {\n+ index = (s->milliseconds.idx + HISTORY_LEN - i) % HISTORY_LEN;\n+ is = &s->milliseconds.sample[index];\n+ ds_put_format(str,\n+ \" %-12\"PRIu64\" %-11\"PRIu32\" %-11\"PRIu64\n+ \" %-11\"PRIu32\" %-11\"PRIu64\" %-11\"PRIu32\n+ \" %-11\"PRIu32\" %-11\"PRIu32\" %-11\"PRIu32\"\\n\",\n+ is->timestamp,\n+ is->iterations,\n+ is->iterations ? is->cycles / is->iterations : 0,\n+ is->pkts,\n+ is->pkts ? is->busy_cycles / is->pkts : 0,\n+ is->batches ? is->pkts / is->batches : 0,\n+ is->iterations\n+ ? is->max_vhost_qfill / is->iterations : 0,\n+ is->upcalls,\n+ is->upcalls ? is->upcall_cycles / is->upcalls : 0);\n+ }\n+}\n+\n+void\n pmd_perf_read_counters(struct pmd_perf_stats *s,\n uint64_t stats[PMD_N_STATS])\n {\n@@ -59,9 +351,21 @@ void\n pmd_perf_stats_clear(struct pmd_perf_stats *s)\n {\n s->start_ms = 0; /* Marks start of clearing. */\n+ memset(&s->current, 0 , sizeof(struct iter_stats));\n+ memset(&s->totals, 0 , sizeof(struct iter_stats));\n for (int i = 0; i < PMD_N_STATS; i++) {\n atomic_read_relaxed(&s->counters.n[i], &s->counters.zero[i]);\n }\n+ histogram_clear(&s->cycles);\n+ histogram_clear(&s->pkts);\n+ histogram_clear(&s->cycles_per_pkt);\n+ histogram_clear(&s->upcalls);\n+ histogram_clear(&s->cycles_per_upcall);\n+ histogram_clear(&s->pkts_per_batch);\n+ histogram_clear(&s->max_vhost_qfill);\n+ history_init(&s->iterations);\n+ history_init(&s->milliseconds);\n s->start_ms = time_msec(); /* Clearing finished. */\n+ s->milliseconds.sample[0].timestamp = s->start_ms;\n }\n\ndiff --git a/lib/dpif-netdev-perf.h b/lib/dpif-netdev-perf.h\nindex f55f7a2..01fde8d 100644\n--- a/lib/dpif-netdev-perf.h\n+++ b/lib/dpif-netdev-perf.h\n@@ -33,6 +33,11 @@\n extern \"C\" {\n #endif\n\n+#define NUM_BINS 32 /* Number of histogram bins. */\n+#define HISTORY_LEN 1000 /* Length of recorded history\n+ (iterations and ms). */\n+#define DEF_HIST_SHOW 20 /* Default number of history samples. */\n+\n enum pmd_stat_type {\n PMD_STAT_EXACT_HIT, /* Packets that had an exact match (emc). */\n PMD_STAT_MASKED_HIT, /* Packets that matched in the flow table. */\n@@ -60,6 +65,28 @@ enum pmd_stat_type {\n PMD_N_STATS\n };\n\n+struct histogram {\n+ uint32_t wall[NUM_BINS];\n+ uint64_t bin[NUM_BINS];\n+};\n+\n+struct iter_stats {\n+ uint64_t timestamp;\n+ uint64_t cycles;\n+ uint64_t busy_cycles;\n+ uint32_t iterations;\n+ uint32_t pkts;\n+ uint32_t upcalls;\n+ uint32_t upcall_cycles;\n+ uint32_t batches;\n+ uint32_t max_vhost_qfill;\n+};\n+\n+struct history {\n+ uint64_t idx;\n+ struct iter_stats sample[HISTORY_LEN];\n+};\n+\n struct pmd_counters {\n atomic_uint64_t n[PMD_N_STATS]; /* Indexed by PMD_STAT_*. */\n uint64_t zero[PMD_N_STATS];\n@@ -69,6 +96,17 @@ struct pmd_perf_stats {\n uint64_t start_ms;\n uint64_t last_tsc;\n struct pmd_counters counters;\n+ struct iter_stats current;\n+ struct iter_stats totals;\n+ struct histogram cycles;\n+ struct histogram pkts;\n+ struct histogram cycles_per_pkt;\n+ struct histogram upcalls;\n+ struct histogram cycles_per_upcall;\n+ struct histogram pkts_per_batch;\n+ struct histogram max_vhost_qfill;\n+ struct history iterations;\n+ struct history milliseconds;\n };\n\n enum pmd_info_type;\n@@ -96,6 +134,63 @@ pmd_perf_update_counter(struct pmd_perf_stats *s,\n atomic_store_relaxed(&s->counters.n[counter], tmp);\n }\n\n+void pmd_perf_format_overall_stats(struct ds *str, struct pmd_perf_stats *s,\n+ double duration);\n+void pmd_perf_format_histograms(struct ds *str, struct pmd_perf_stats *s);\n+void pmd_perf_format_iteration_history(struct ds *str,\n+ struct pmd_perf_stats *s,\n+ int n_iter);\n+void pmd_perf_format_ms_history(struct ds *str, struct pmd_perf_stats *s,\n+ int n_ms);\n+\n+void pmd_perf_show(struct unixctl_conn *conn, int argc,\n+ const char *argv[],\n+ void *aux OVS_UNUSED);\n+static inline void\n+histogram_add_sample(struct histogram *hist, uint32_t val)\n+{\n+ /* TODO: Can do better with binary search? */\n+ for (int i = 0; i < NUM_BINS-1; i++) {\n+ if (val <= hist->wall[i]) {\n+ hist->bin[i]++;\n+ return;\n+ }\n+ }\n+ hist->bin[NUM_BINS-1]++;\n+}\n+\n+uint64_t histogram_samples(const struct histogram *hist);\n+\n+static inline struct iter_stats *\n+history_current(struct history *h)\n+{\n+ return &h->sample[h->idx];\n+}\n+\n+static inline struct iter_stats *\n+history_next(struct history *h)\n+{\n+ struct iter_stats *next;\n+\n+ h->idx++;\n+ if (h->idx == HISTORY_LEN) {\n+ h->idx = 0;\n+ }\n+ next = &h->sample[h->idx];\n+ memset(next, 0, sizeof(*next));\n+ return next;\n+}\n+\n+static inline struct iter_stats *\n+history_store(struct history *h, struct iter_stats *is)\n+{\n+ if (is) {\n+ h->sample[h->idx] = *is;\n+ }\n+ /* Advance the history pointer */\n+ return history_next(h);\n+}\n+\n static inline void\n pmd_perf_start_iteration(struct pmd_perf_stats *s, uint64_t now_tsc)\n {\n@@ -103,14 +198,25 @@ pmd_perf_start_iteration(struct pmd_perf_stats *s, uint64_t now_tsc)\n /* Stats not yet fully initialised. */\n return;\n }\n- s->last_tsc = now_tsc;\n+ memset(&s->current, 0, sizeof(struct iter_stats));\n+ s->current.timestamp = now_tsc;\n }\n\n static inline void\n pmd_perf_end_iteration(struct pmd_perf_stats *s, uint64_t now_tsc,\n int packets)\n {\n- uint64_t cycles = now_tsc - s->last_tsc;\n+ struct iter_stats *cum_ms;\n+ uint64_t cycles, cycles_per_pkt = 0;\n+\n+ if (OVS_UNLIKELY(s->current.timestamp == 0)) {\n+ /* Stats were cleared during the ongoing iteration. */\n+ return;\n+ }\n+\n+ cycles = now_tsc - s->current.timestamp;\n+ s->current.cycles = cycles;\n+ s->current.pkts = packets;\n\n /* No need for atomic updates as only invoked within PMD thread. */\n if (packets > 0) {\n@@ -118,6 +224,62 @@ pmd_perf_end_iteration(struct pmd_perf_stats *s, uint64_t now_tsc,\n } else {\n s->counters.n[PMD_CYCLES_ITER_IDLE] += cycles;\n }\n+ s->counters.n[PMD_CYCLES_UPCALL] += s->current.upcall_cycles;\n+\n+ /* Add iteration sample to histograms. */\n+ histogram_add_sample(&s->cycles, cycles);\n+ histogram_add_sample(&s->pkts, packets);\n+ if (packets > 0) {\n+ cycles_per_pkt = cycles / packets;\n+ histogram_add_sample(&s->cycles_per_pkt, cycles_per_pkt);\n+ }\n+ if (s->current.batches > 0) {\n+ histogram_add_sample(&s->pkts_per_batch, packets / s->current.batches);\n+ }\n+ histogram_add_sample(&s->upcalls, s->current.upcalls);\n+ if (s->current.upcalls > 0) {\n+ histogram_add_sample(&s->cycles_per_upcall,\n+ s->current.upcall_cycles / s->current.upcalls);\n+ }\n+ histogram_add_sample(&s->max_vhost_qfill, s->current.max_vhost_qfill);\n+\n+ /* Add iteration samples to millisecond stats. */\n+ cum_ms = history_current(&s->milliseconds);\n+ cum_ms->iterations++;\n+ cum_ms->cycles += cycles;\n+ if (packets > 0) {\n+ cum_ms->busy_cycles += cycles;\n+ }\n+ cum_ms->pkts += s->current.pkts;\n+ cum_ms->upcalls += s->current.upcalls;\n+ cum_ms->upcall_cycles += s->current.upcall_cycles;\n+ cum_ms->batches += s->current.batches;\n+ cum_ms->max_vhost_qfill += s->current.max_vhost_qfill;\n+\n+ /* Store in iteration history. */\n+ history_store(&s->iterations, &s->current);\n+ if (now_tsc - s->last_tsc > 10000) {\n+ /* Check if ms is completed and store in milliseconds history. */\n+ uint64_t now = time_msec();\n+ if (now != cum_ms->timestamp) {\n+ /* Add ms stats to totals. */\n+ s->totals.iterations += cum_ms->iterations;\n+ s->totals.cycles += cum_ms->cycles;\n+ s->totals.busy_cycles += cum_ms->busy_cycles;\n+ s->totals.pkts += cum_ms->pkts;\n+ s->totals.upcalls += cum_ms->upcalls;\n+ s->totals.upcall_cycles += cum_ms->upcall_cycles;\n+ s->totals.batches += cum_ms->batches;\n+ s->totals.max_vhost_qfill += cum_ms->max_vhost_qfill;\n+ cum_ms = history_next(&s->milliseconds);\n+ cum_ms->timestamp = now;\n+ }\n+ s->last_tsc = now_tsc;\n+ }\n }\n\n+#ifdef __cplusplus\n+}\n+#endif\n+\n #endif /* pmd-perf.h */\ndiff --git a/lib/dpif-netdev.c b/lib/dpif-netdev.c\nindex 46cc9f6..db294ea 100644\n--- a/lib/dpif-netdev.c\n+++ b/lib/dpif-netdev.c\n@@ -52,6 +52,7 @@\n #include \"id-pool.h\"\n #include \"latch.h\"\n #include \"netdev.h\"\n+#include \"netdev-provider.h\"\n #include \"netdev-vport.h\"\n #include \"netlink.h\"\n #include \"odp-execute.h\"\n@@ -749,7 +750,8 @@ get_dp_netdev(const struct dpif *dpif)\n enum pmd_info_type {\n PMD_INFO_SHOW_STATS, /* Show how cpu cycles are spent. */\n PMD_INFO_CLEAR_STATS, /* Set the cycles count to 0. */\n- PMD_INFO_SHOW_RXQ /* Show poll-lists of pmd threads. */\n+ PMD_INFO_SHOW_RXQ, /* Show poll-lists of pmd threads. */\n+ PMD_INFO_PERF_SHOW, /* Show pmd performance details. */\n };\n\n static void\n@@ -828,6 +830,42 @@ pmd_info_show_stats(struct ds *reply,\n stats[PMD_CYCLES_POLL_BUSY], total_packets);\n }\n\n+static void\n+pmd_info_show_perf(struct ds *reply,\n+ struct dp_netdev_pmd_thread *pmd,\n+ struct pmd_perf_params *par)\n+{\n+ if (pmd->core_id != NON_PMD_CORE_ID) {\n+ char *time_str =\n+ xastrftime_msec(\"%H:%M:%S.###\", time_wall_msec(), true);\n+ long long now = time_msec();\n+ double duration = (now - pmd->perf_stats.start_ms) / 1000.0;\n+\n+ ds_put_cstr(reply, \"\\n\");\n+ ds_put_format(reply, \"Time: %s\\n\", time_str);\n+ ds_put_format(reply, \"Measurement duration: %.3f s\\n\", duration);\n+ ds_put_cstr(reply, \"\\n\");\n+ format_pmd_thread(reply, pmd);\n+ ds_put_cstr(reply, \"\\n\");\n+ pmd_perf_format_overall_stats(reply, &pmd->perf_stats, duration);\n+ if (par->histograms) {\n+ ds_put_cstr(reply, \"\\n\");\n+ pmd_perf_format_histograms(reply, &pmd->perf_stats);\n+ }\n+ if (par->iter_hist_len > 0) {\n+ ds_put_cstr(reply, \"\\n\");\n+ pmd_perf_format_iteration_history(reply, &pmd->perf_stats,\n+ par->iter_hist_len);\n+ }\n+ if (par->ms_hist_len > 0) {\n+ ds_put_cstr(reply, \"\\n\");\n+ pmd_perf_format_ms_history(reply, &pmd->perf_stats,\n+ par->ms_hist_len);\n+ }\n+ free(time_str);\n+ }\n+}\n+\n static int\n compare_poll_list(const void *a_, const void *b_)\n {\n@@ -1030,6 +1068,8 @@ dpif_netdev_pmd_info(struct unixctl_conn *conn, int argc, const char *argv[],\n pmd_perf_stats_clear(&pmd->perf_stats);\n } else if (type == PMD_INFO_SHOW_STATS) {\n pmd_info_show_stats(&reply, pmd);\n+ } else if (type == PMD_INFO_PERF_SHOW) {\n+ pmd_info_show_perf(&reply, pmd, (struct pmd_perf_params *)aux);\n }\n }\n free(pmd_list);\n@@ -1039,6 +1079,48 @@ dpif_netdev_pmd_info(struct unixctl_conn *conn, int argc, const char *argv[],\n unixctl_command_reply(conn, ds_cstr(&reply));\n ds_destroy(&reply);\n }\n+\n+static void\n+pmd_perf_show_cmd(struct unixctl_conn *conn, int argc,\n+ const char *argv[],\n+ void *aux OVS_UNUSED)\n+{\n+ struct pmd_perf_params par;\n+ long int it_hist = 0, ms_hist = 0;\n+ par.histograms = true;\n+\n+ while (argc > 1) {\n+ if (!strcmp(argv[1], \"-nh\")) {\n+ par.histograms = false;\n+ argc -= 1;\n+ argv += 1;\n+ } else if (!strcmp(argv[1], \"-it\") && argc > 2) {\n+ it_hist = strtol(argv[2], NULL, 10);\n+ if (it_hist < 0) {\n+ it_hist = 0;\n+ } else if (it_hist > HISTORY_LEN) {\n+ it_hist = HISTORY_LEN;\n+ }\n+ argc -= 2;\n+ argv += 2;\n+ } else if (!strcmp(argv[1], \"-ms\") && argc > 2) {\n+ ms_hist = strtol(argv[2], NULL, 10);\n+ if (ms_hist < 0) {\n+ ms_hist = 0;\n+ } else if (ms_hist > HISTORY_LEN) {\n+ ms_hist = HISTORY_LEN;\n+ }\n+ argc -= 2;\n+ argv += 2;\n+ } else {\n+ break;\n+ }\n+ }\n+ par.iter_hist_len = it_hist;\n+ par.ms_hist_len = ms_hist;\n+ par.command_type = PMD_INFO_PERF_SHOW;\n+ dpif_netdev_pmd_info(conn, argc, argv, &par);\n+}\n\n static int\n dpif_netdev_init(void)\n@@ -1056,6 +1138,12 @@ dpif_netdev_init(void)\n unixctl_command_register(\"dpif-netdev/pmd-rxq-show\", \"[-pmd core] [dp]\",\n 0, 2, dpif_netdev_pmd_info,\n (void *)&poll_aux);\n+ unixctl_command_register(\"dpif-netdev/pmd-perf-show\",\n+ \"[-nh] [-it iter-history-len]\"\n+ \" [-ms ms-history-len]\"\n+ \" [-pmd core] [dp]\",\n+ 0, 7, pmd_perf_show_cmd,\n+ NULL);\n unixctl_command_register(\"dpif-netdev/pmd-rxq-rebalance\", \"[dp]\",\n 0, 1, dpif_netdev_pmd_rebalance,\n NULL);\n@@ -3143,6 +3231,7 @@ dp_netdev_process_rxq_port(struct dp_netdev_pmd_thread *pmd,\n struct netdev_rxq *rx,\n odp_port_t port_no)\n {\n+ struct pmd_perf_stats *s = &pmd->perf_stats;\n struct dp_packet_batch batch;\n int error;\n int batch_cnt = 0;\n@@ -3151,8 +3240,23 @@ dp_netdev_process_rxq_port(struct dp_netdev_pmd_thread *pmd,\n error = netdev_rxq_recv(rx, &batch);\n if (!error) {\n *recirc_depth_get() = 0;\n-\n+ /* Update batch histogram. */\n batch_cnt = batch.count;\n+ s->current.batches++;\n+ histogram_add_sample(&s->pkts_per_batch, batch_cnt);\n+ /* Update the maximum Rx queue fill level. */\n+ uint32_t qfill = batch.qfill;\n+ switch (netdev_dpdk_get_type(netdev_rxq_get_netdev(rx))) {\n+ case DPDK_DEV_VHOST:\n+ if (qfill > s->current.max_vhost_qfill) {\n+ s->current.max_vhost_qfill = qfill;\n+ }\n+ break;\n+ case DPDK_DEV_ETH:\n+ default:\n+ break;\n+ }\n+ /* Process packet batch. */\n dp_netdev_input(pmd, &batch, port_no);\n } else if (error != EAGAIN && error != EOPNOTSUPP) {\n static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);\n@@ -4868,6 +4972,7 @@ handle_packet_upcall(struct dp_netdev_pmd_thread *pmd,\n struct match match;\n ovs_u128 ufid;\n int error = 0;\n+ uint64_t cycles = cycles_counter();\n\n match.tun_md.valid = false;\n miniflow_expand(&key->mf, &match.flow);\n@@ -4921,6 +5026,12 @@ handle_packet_upcall(struct dp_netdev_pmd_thread *pmd,\n ovs_mutex_unlock(&pmd->flow_mutex);\n emc_probabilistic_insert(pmd, key, netdev_flow);\n }\n+ /* Update upcall stats. */\n+ cycles = cycles_counter() - cycles;\n+ struct pmd_perf_stats *s = &pmd->perf_stats;\n+ s->current.upcalls++;\n+ s->current.upcall_cycles += cycles;\n+ histogram_add_sample(&s->cycles_per_upcall, cycles);\n return error;\n }\n\ndiff --git a/lib/netdev-dpdk.c b/lib/netdev-dpdk.c\nindex 648d719..6f04bb9 100644\n--- a/lib/netdev-dpdk.c\n+++ b/lib/netdev-dpdk.c\n@@ -35,6 +35,7 @@\n #include \n #include \n #include \n+#include \n #include \n\n #include \"dirs.h\"\n@@ -196,11 +197,6 @@ enum { DPDK_RING_SIZE = 256 };\n BUILD_ASSERT_DECL(IS_POW2(DPDK_RING_SIZE));\n enum { DRAIN_TSC = 200000ULL };\n\n-enum dpdk_dev_type {\n- DPDK_DEV_ETH = 0,\n- DPDK_DEV_VHOST = 1,\n-};\n-\n /* Quality of Service */\n\n /* An instance of a QoS configuration. Always associated with a particular\n@@ -846,6 +842,13 @@ netdev_dpdk_cast(const struct netdev *netdev)\n return CONTAINER_OF(netdev, struct netdev_dpdk, up);\n }\n\n+enum dpdk_dev_type\n+netdev_dpdk_get_type(const struct netdev *netdev)\n+{\n+ struct netdev_dpdk *dev = netdev_dpdk_cast(netdev);\n+ return dev->type;\n+}\n+\n static struct netdev *\n netdev_dpdk_alloc(void)\n {\n@@ -1656,6 +1659,19 @@ netdev_dpdk_vhost_rxq_recv(struct netdev_rxq *rxq,\n return EAGAIN;\n }\n\n+ batch->qfill = nb_rx;\n+\n+ if (OVS_UNLIKELY(nb_rx == NETDEV_MAX_BURST)) {\n+ /* This vhostuser API call is only implemented in DPDK 17.08.\n+ * The need for this API call disappears when switching to the\n+ * vhostuser PMD. */\n+#if RTE_VERSION >= RTE_VERSION_NUM (17, 8, 0, RTE_VER_RELEASE)\n+ batch->qfill += rte_vhost_rx_queue_count(netdev_dpdk_get_vid(dev),\n+ qid * VIRTIO_QNUM\n+ + VIRTIO_TXQ);\n+#endif\n+ }\n+\n if (policer) {\n dropped = nb_rx;\n nb_rx = ingress_policer_run(policer,\n@@ -1694,6 +1710,8 @@ netdev_dpdk_rxq_recv(struct netdev_rxq *rxq, struct dp_packet_batch *batch)\n return EAGAIN;\n }\n\n+ batch->qfill = nb_rx;\n+\n if (policer) {\n dropped = nb_rx;\n nb_rx = ingress_policer_run(policer,\ndiff --git a/lib/netdev-dpdk.h b/lib/netdev-dpdk.h\nindex b7d02a7..2b357db 100644\n--- a/lib/netdev-dpdk.h\n+++ b/lib/netdev-dpdk.h\n@@ -22,11 +22,18 @@\n #include \"openvswitch/compiler.h\"\n\n struct dp_packet;\n+struct netdev;\n+\n+enum dpdk_dev_type {\n+ DPDK_DEV_ETH = 0,\n+ DPDK_DEV_VHOST = 1,\n+};\n\n #ifdef DPDK_NETDEV\n\n void netdev_dpdk_register(void);\n void free_dpdk_buf(struct dp_packet *);\n+enum dpdk_dev_type netdev_dpdk_get_type(const struct netdev *netdev);\n\n #else\n\n@@ -41,6 +48,13 @@ free_dpdk_buf(struct dp_packet *buf OVS_UNUSED)\n /* Nothing */\n }\n\n+static inline enum dpdk_dev_type\n+netdev_dpdk_get_type(const struct netdev *netdev OVS_UNUSED)\n+{\n+ /* Nothing to do. Return value zero to make compiler happy. */\n+ return DPDK_DEV_ETH;\n+}\n+\n #endif\n\n #endif /* netdev-dpdk.h */\ndiff --git a/ofproto/ofproto-dpif.c b/ofproto/ofproto-dpif.c\nindex 1a8e829..6f42c2b 100644\n--- a/ofproto/ofproto-dpif.c\n+++ b/ofproto/ofproto-dpif.c\n@@ -5308,7 +5308,8 @@ dpif_show_backer(const struct dpif_backer *backer, struct ds *ds)\n\n dpif_get_dp_stats(backer->dpif, &dp_stats);\n ds_put_format(ds, \"%s: hit:%\"PRIu64\" missed:%\"PRIu64\"\\n\",\n- dpif_name(backer->dpif), dp_stats.n_hit, dp_stats.n_missed);\n+ dpif_name(backer->dpif),\n+ dp_stats.n_hit + dp_stats.n_mask_hit, dp_stats.n_missed);\n\n shash_init(&ofproto_shash);\n ofprotos = get_ofprotos(&ofproto_shash);\n","prefixes":["ovs-dev","2/3"]}