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 <azhou@nicira.com>
Signed-off-by: Ben Pfaff <blp@nicira.com>

diff --git a/ofproto/ofproto-dpif.c b/ofproto/ofproto-dpif.c
index df18244..7fa44e8 100644 (file)
--- a/ofproto/ofproto-dpif.c
+++ b/ofproto/ofproto-dpif.c
@@ -367,6 +367,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. */
@@ -663,6 +664,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'. */
@@ -718,7 +726,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.) */
@@ -1299,6 +1348,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;
 }
 
@@ -4043,6 +4105,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);
@@ -4163,6 +4228,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);
@@ -5064,6 +5133,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;
@@ -5075,6 +5145,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;
 }
 
@@ -5086,6 +5157,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);
@@ -7967,14 +8042,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++) {
@@ -8391,6 +8492,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 70a3ec3..ece1b6f 100644 (file)
--- a/tests/ofproto-dpif.at
+++ b/tests/ofproto-dpif.at
@@ -1227,13 +1227,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)
 ])
@@ -1241,7 +1243,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)
@@ -1334,13 +1337,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)
@@ -1367,3 +1372,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 61037b1..a0688f1 100644 (file)
--- 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=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)
 ])
@@ -364,7 +374,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)
 ])
@@ -376,7 +387,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)
 ])