From 655ab909c455de622963b14ad8de4feb3c3f56e3 Mon Sep 17 00:00:00 2001 From: Andy Zhou Date: Mon, 25 Mar 2013 19:49:13 -0700 Subject: [PATCH] ofproto-dpif: Keep track of exact-match flow info This patch adds more flow related stats to the output of "ovs-appctl dpif/show". Specifically, the follow information are added per ofproto: - Max flow table size - Average flow table size - Average flow table add rate - Average flow table delete rate - Average flow entry life in milliseconds Feature #15366 Signed-off-by: Andy Zhou Signed-off-by: Ben Pfaff --- ofproto/ofproto-dpif.c | 178 ++++++++++++++++++++++++++++++++++++++++- tests/ofproto-dpif.at | 44 ++++++++-- tests/tunnel.at | 39 ++++++--- 3 files changed, 241 insertions(+), 20 deletions(-) diff --git a/ofproto/ofproto-dpif.c b/ofproto/ofproto-dpif.c index 915d2d01e..d6121f1f8 100644 --- a/ofproto/ofproto-dpif.c +++ b/ofproto/ofproto-dpif.c @@ -370,6 +370,7 @@ struct subfacet { int key_len; long long int used; /* Time last used; time created if not used. */ + long long int created; /* Time created. */ uint64_t dp_packet_count; /* Last known packet count in the datapath. */ uint64_t dp_byte_count; /* Last known byte count in the datapath. */ @@ -669,6 +670,13 @@ odp_port_to_ofport(const struct dpif_backer *, uint32_t odp_port); static void dpif_stats_update_hit_count(struct ofproto_dpif *ofproto, uint64_t delta); +struct avg_subfacet_rates { + double add_rate; /* Moving average of new flows created per minute. */ + double del_rate; /* Moving average of flows deleted per minute. */ +}; +static void show_dp_rates(struct ds *ds, const char *heading, + const struct avg_subfacet_rates *rates); +static void exp_mavg(double *avg, int base, double new); struct ofproto_dpif { struct hmap_node all_ofproto_dpifs_node; /* In 'all_ofproto_dpifs'. */ @@ -724,7 +732,48 @@ struct ofproto_dpif { /* Per ofproto's dpif stats. */ uint64_t n_hit; uint64_t n_missed; + + /* Subfacet statistics. + * + * These keep track of the total number of subfacets added and deleted and + * flow life span. They are useful for computing the flow rates stats + * exposed via "ovs-appctl dpif/show". The goal is to learn about + * traffic patterns in ways that we can use later to improve Open vSwitch + * performance in new situations. */ + long long int created; /* Time when it is created. */ + unsigned int max_n_subfacet; /* Maximum number of flows */ + + /* The average number of subfacets... */ + struct avg_subfacet_rates hourly; /* ...over the last hour. */ + struct avg_subfacet_rates daily; /* ...over the last day. */ + long long int last_minute; /* Last time 'hourly' was updated. */ + + /* Number of subfacets added or deleted since 'last_minute'. */ + unsigned int subfacet_add_count; + unsigned int subfacet_del_count; + + /* Number of subfacets added or deleted from 'created' to 'last_minute.' */ + unsigned long long int total_subfacet_add_count; + unsigned long long int total_subfacet_del_count; + + /* Sum of the number of milliseconds that each subfacet existed, + * over the subfacets that have been added and then later deleted. */ + unsigned long long int total_subfacet_life_span; + + /* Incremented by the number of currently existing subfacets, each + * time we pull statistics from the kernel. */ + unsigned long long int total_subfacet_count; + + /* Number of times we pull statistics from the kernel. */ + unsigned long long int n_update_stats; }; +static unsigned long long int avg_subfacet_life_span( + const struct ofproto_dpif *); +static double avg_subfacet_count(const struct ofproto_dpif *ofproto); +static void update_moving_averages(struct ofproto_dpif *ofproto); +static void dpif_stats_update_hit_count(struct ofproto_dpif *ofproto, + uint64_t delta); +static void update_max_subfacet_count(struct ofproto_dpif *ofproto); /* Defer flow mod completion until "ovs-appctl ofproto/unclog"? (Useful only * for debugging the asynchronous flow_mod implementation.) */ @@ -1305,6 +1354,19 @@ construct(struct ofproto *ofproto_) ofproto->n_hit = 0; ofproto->n_missed = 0; + ofproto->max_n_subfacet = 0; + ofproto->created = time_msec(); + ofproto->last_minute = ofproto->created; + memset(&ofproto->hourly, 0, sizeof ofproto->hourly); + memset(&ofproto->daily, 0, sizeof ofproto->daily); + ofproto->subfacet_add_count = 0; + ofproto->subfacet_del_count = 0; + ofproto->total_subfacet_add_count = 0; + ofproto->total_subfacet_del_count = 0; + ofproto->total_subfacet_life_span = 0; + ofproto->total_subfacet_count = 0; + ofproto->n_update_stats = 0; + return error; } @@ -4033,6 +4095,9 @@ expire(struct dpif_backer *backer) continue; } + /* Keep track of the max number of flows per ofproto_dpif. */ + update_max_subfacet_count(ofproto); + /* Expire subfacets that have been idle too long. */ dp_max_idle = subfacet_max_idle(ofproto); expire_subfacets(ofproto, dp_max_idle); @@ -4153,6 +4218,10 @@ update_stats(struct dpif_backer *backer) continue; } + ofproto->total_subfacet_count += hmap_count(&ofproto->subfacets); + ofproto->n_update_stats++; + update_moving_averages(ofproto); + ofport = get_ofp_port(ofproto, flow.in_port); if (ofport && ofport->tnl_port) { netdev_vport_inc_rx(ofport->up.netdev, stats); @@ -5059,6 +5128,7 @@ subfacet_create(struct facet *facet, struct flow_miss *miss, subfacet->key = xmemdup(key, key_len); subfacet->key_len = key_len; subfacet->used = now; + subfacet->created = now; subfacet->dp_packet_count = 0; subfacet->dp_byte_count = 0; subfacet->actions_len = 0; @@ -5070,6 +5140,7 @@ subfacet_create(struct facet *facet, struct flow_miss *miss, subfacet->initial_vals = miss->initial_vals; subfacet->odp_in_port = miss->odp_in_port; + ofproto->subfacet_add_count++; return subfacet; } @@ -5081,6 +5152,10 @@ subfacet_destroy__(struct subfacet *subfacet) struct facet *facet = subfacet->facet; struct ofproto_dpif *ofproto = ofproto_dpif_cast(facet->rule->up.ofproto); + /* Update ofproto stats before uninstall the subfacet. */ + ofproto->subfacet_del_count++; + ofproto->total_subfacet_life_span += (time_msec() - subfacet->created); + subfacet_uninstall(subfacet); hmap_remove(&ofproto->subfacets, &subfacet->hmap_node); list_remove(&subfacet->list_node); @@ -8091,14 +8166,40 @@ show_dp_format(const struct ofproto_dpif *ofproto, struct ds *ds) { const struct shash_node **ports; int i; + struct avg_subfacet_rates lifetime; + unsigned long long int minutes; + const int min_ms = 60 * 1000; /* milliseconds in one minute. */ + + minutes = (time_msec() - ofproto->created) / min_ms; + + if (minutes > 0) { + lifetime.add_rate = (double)ofproto->total_subfacet_add_count + / minutes; + lifetime.del_rate = (double)ofproto->total_subfacet_del_count + / minutes; + }else { + lifetime.add_rate = 0.0; + lifetime.del_rate = 0.0; + } ds_put_format(ds, "%s (%s):\n", ofproto->up.name, dpif_name(ofproto->backer->dpif)); ds_put_format(ds, "\tlookups: hit:%"PRIu64" missed:%"PRIu64"\n", ofproto->n_hit, ofproto->n_missed); - ds_put_format(ds, "\tflows: %zu\n", - hmap_count(&ofproto->subfacets)); + ds_put_format(ds, "\tflows: cur: %zu, avg: %5.3f, max: %d," + " life span: %llu(ms)\n", + hmap_count(&ofproto->subfacets), + avg_subfacet_count(ofproto), + ofproto->max_n_subfacet, + avg_subfacet_life_span(ofproto)); + if (minutes >= 60) { + show_dp_rates(ds, "\t\thourly avg:", &ofproto->hourly); + } + if (minutes >= 60 * 24) { + show_dp_rates(ds, "\t\tdaily avg:", &ofproto->daily); + } + show_dp_rates(ds, "\t\toverall avg:", &lifetime); ports = shash_sort(&ofproto->up.port_by_name); for (i = 0; i < shash_count(&ofproto->up.port_by_name); i++) { @@ -8515,6 +8616,79 @@ odp_port_to_ofp_port(const struct ofproto_dpif *ofproto, uint32_t odp_port) return OFPP_NONE; } } +static unsigned long long int +avg_subfacet_life_span(const struct ofproto_dpif *ofproto) +{ + unsigned long long int dc; + unsigned long long int avg; + + dc = ofproto->total_subfacet_del_count + ofproto->subfacet_del_count; + avg = dc ? ofproto->total_subfacet_life_span / dc : 0; + + return avg; +} + +static double +avg_subfacet_count(const struct ofproto_dpif *ofproto) +{ + double avg_c = 0.0; + + if (ofproto->n_update_stats) { + avg_c = (double)ofproto->total_subfacet_count + / ofproto->n_update_stats; + } + + return avg_c; +} + +static void +show_dp_rates(struct ds *ds, const char *heading, + const struct avg_subfacet_rates *rates) +{ + ds_put_format(ds, "%s add rate: %5.3f/min, del rate: %5.3f/min\n", + heading, rates->add_rate, rates->del_rate); +} + +static void +update_max_subfacet_count(struct ofproto_dpif *ofproto) +{ + ofproto->max_n_subfacet = MAX(ofproto->max_n_subfacet, + hmap_count(&ofproto->subfacets)); +} + +/* Compute exponentially weighted moving average, adding 'new' as the newest, + * most heavily weighted element. 'base' designates the rate of decay: after + * 'base' further updates, 'new''s weight in the EWMA decays to about 1/e + * (about .37). */ +static void +exp_mavg(double *avg, int base, double new) +{ + *avg = (*avg * (base - 1) + new) / base; +} + +static void +update_moving_averages(struct ofproto_dpif *ofproto) +{ + const int min_ms = 60 * 1000; /* milliseconds in one minute. */ + + /* Update hourly averages on the minute boundaries. */ + if (time_msec() - ofproto->last_minute >= min_ms) { + exp_mavg(&ofproto->hourly.add_rate, 60, ofproto->subfacet_add_count); + exp_mavg(&ofproto->hourly.del_rate, 60, ofproto->subfacet_del_count); + + /* Update daily averages on the hour boundaries. */ + if ((ofproto->last_minute - ofproto->created) / min_ms % 60 == 59) { + exp_mavg(&ofproto->daily.add_rate, 24, ofproto->hourly.add_rate); + exp_mavg(&ofproto->daily.del_rate, 24, ofproto->hourly.del_rate); + } + + ofproto->total_subfacet_add_count += ofproto->subfacet_add_count; + ofproto->total_subfacet_del_count += ofproto->subfacet_del_count; + ofproto->subfacet_add_count = 0; + ofproto->subfacet_del_count = 0; + ofproto->last_minute += min_ms; + } +} static void dpif_stats_update_hit_count(struct ofproto_dpif *ofproto, uint64_t delta) diff --git a/tests/ofproto-dpif.at b/tests/ofproto-dpif.at index f390f2924..a692d9047 100644 --- a/tests/ofproto-dpif.at +++ b/tests/ofproto-dpif.at @@ -1481,13 +1481,15 @@ ADD_OF_PORTS([br1], [3]) AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (dummy) p2 2/2: (dummy) br1 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br1 65534/101: (dummy) p3 3/3: (dummy) ]) @@ -1495,7 +1497,8 @@ br1 (dummy@ovs-dummy): AT_CHECK([ovs-appctl dpif/show br0], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (dummy) p2 2/2: (dummy) @@ -1588,13 +1591,15 @@ warped AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:9 missed:1 - flows: 1 + flows: cur: 1, avg: 1.000, max: 1, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p2 2/2: (dummy) pbr0 1/none: (patch: peer=pbr1) br1 (dummy@ovs-dummy): lookups: hit:4 missed:1 - flows: 1 + flows: cur: 1, avg: 1.000, max: 1, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br1 65534/101: (dummy) p3 3/3: (dummy) pbr1 1/none: (patch: peer=pbr0) @@ -1621,3 +1626,32 @@ OFPST_PORT reply (xid=0x4): 1 ports OVS_VSWITCHD_STOP AT_CLEANUP + +AT_SETUP([ofproto-dpif - ovs-appctl dpif/show rates]) +OVS_VSWITCHD_START([set Bridge br0 fail-mode=secure]) +ADD_OF_PORTS([br0], 1, 2) + +AT_CHECK([ovs-ofctl add-flow br0 actions=LOCAL,output:1,output:2]) + +for i in $(seq 1 61); do + ovs-appctl netdev-dummy/receive br0 'in_port(1),eth(src=50:54:00:00:00:05,dst=50:54:00:00:00:07),eth_type(0x0800),ipv4(src=192.168.0.1,dst=192.168.0.2,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)' + ovs-appctl time/warp 10000 + ovs-appctl time/warp 50000 +done + +AT_CHECK([ovs-appctl time/warp 10000], [0], [warped +]) + +AT_CHECK([ovs-appctl dpif/show], [0], [dnl +br0 (dummy@ovs-dummy): + lookups: hit:0 missed:61 + flows: cur: 0, avg: 1.000, max: 1, life span: 10001(ms) + hourly avg: add rate: 0.641/min, del rate: 0.635/min + overall avg: add rate: 1.000/min, del rate: 0.984/min + br0 65534/100: (dummy) + p1 1/1: (dummy) + p2 2/2: (dummy) +]) + +OVS_VSWITCHD_STOP +AT_CLEANUP diff --git a/tests/tunnel.at b/tests/tunnel.at index aee543eb7..78e43f517 100644 --- a/tests/tunnel.at +++ b/tests/tunnel.at @@ -17,7 +17,8 @@ AT_CHECK([ovs-ofctl add-flows br0 flows.txt]) AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (gre: remote_ip=1.1.1.1) p2 2/1: (gre: local_ip=2.2.2.2, remote_ip=1.1.1.1) @@ -43,7 +44,8 @@ AT_CHECK([ovs-vsctl set Interface p2 type=gre options:local_ip=2.2.2.3 \ AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (gre: remote_ip=1.1.1.1) p2 2/1: (gre: csum=true, df_default=false, local_ip=2.2.2.3, remote_ip=1.1.1.1, ttl=1) @@ -81,7 +83,8 @@ AT_CHECK([ovs-ofctl add-flows br0 flows.txt]) AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (gre: remote_ip=1.1.1.1) p2 2/2: (dummy) @@ -128,7 +131,8 @@ AT_CHECK([ovs-ofctl add-flows br0 flows.txt]) AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (gre: key=5, local_ip=2.2.2.2, remote_ip=1.1.1.1) p2 2/2: (dummy) @@ -163,7 +167,8 @@ AT_CHECK([ovs-ofctl add-flows br0 flows.txt]) AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (gre: remote_ip=1.1.1.1, tos=inherit, ttl=inherit) p2 2/2: (dummy) @@ -208,7 +213,8 @@ AT_CHECK([ovs-ofctl add-flows br0 flows.txt]) AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (gre: key=flow, remote_ip=1.1.1.1) p2 2/1: (gre: key=flow, remote_ip=2.2.2.2) @@ -243,7 +249,8 @@ AT_CHECK([ovs-ofctl add-flows br0 flows.txt]) AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (gre: key=1, remote_ip=1.1.1.1) p2 2/1: (gre: in_key=2, out_key=3, remote_ip=1.1.1.1) @@ -298,7 +305,8 @@ AT_CHECK([ovs-ofctl add-flows br0 flows.txt]) AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (gre: key=flow, remote_ip=1.1.1.1) p2 2/1: (gre: key=3, remote_ip=3.3.3.3) @@ -337,7 +345,8 @@ OVS_VSWITCHD_START([add-port br0 p1 -- set Interface p1 type=vxlan \ AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (vxlan: remote_ip=1.1.1.1) ]) @@ -352,7 +361,8 @@ OVS_VSWITCHD_START([add-port br0 p1 -- set Interface p1 type=lisp \ AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (lisp: remote_ip=1.1.1.1) ]) @@ -367,7 +377,8 @@ OVS_VSWITCHD_START([add-port br0 p1 -- set Interface p1 type=vxlan \ AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (vxlan: dst_port=4341, remote_ip=1.1.1.1) ]) @@ -379,7 +390,8 @@ AT_CHECK([ovs-vsctl -- set Interface p1 options:dst_port=5000]) AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/2: (vxlan: dst_port=5000, remote_ip=1.1.1.1) ]) @@ -391,7 +403,8 @@ AT_CHECK([ovs-vsctl -- set Interface p1 options:dst_port=8472]) AT_CHECK([ovs-appctl dpif/show], [0], [dnl br0 (dummy@ovs-dummy): lookups: hit:0 missed:0 - flows: 0 + flows: cur: 0, avg: 0.000, max: 0, life span: 0(ms) + overall avg: add rate: 0.000/min, del rate: 0.000/min br0 65534/100: (dummy) p1 1/1: (vxlan: remote_ip=1.1.1.1) ]) -- 2.43.0