ofproto-dpif: Don't rate limit facet_learn() with fin_timeouts.
[sliver-openvswitch.git] / ofproto / ofproto-dpif.c
index 18c5b7d..47830c1 100644 (file)
@@ -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. */
@@ -491,6 +492,8 @@ struct facet {
      * always be valid, since it could have been removed after newer
      * subfacets were pushed onto the 'subfacets' list.) */
     struct subfacet one_subfacet;
+
+    long long int learn_rl;      /* Rate limiter for facet_learn(). */
 };
 
 static struct facet *facet_create(struct rule_dpif *,
@@ -512,6 +515,7 @@ static void facet_reset_counters(struct facet *);
 static void facet_push_stats(struct facet *);
 static void facet_learn(struct facet *);
 static void facet_account(struct facet *);
+static void push_all_stats(void);
 
 static struct subfacet *facet_get_subfacet(struct facet *);
 
@@ -594,6 +598,7 @@ static void port_run_fast(struct ofport_dpif *);
 static void port_wait(struct ofport_dpif *);
 static int set_cfm(struct ofport *, const struct cfm_settings *);
 static void ofport_clear_priorities(struct ofport_dpif *);
+static void run_fast_rl(void);
 
 struct dpif_completion {
     struct list list_node;
@@ -667,6 +672,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'. */
@@ -693,6 +705,7 @@ struct ofproto_dpif {
     struct hmap facets;
     struct hmap subfacets;
     struct governor *governor;
+    long long int consistency_rl;
 
     /* Revalidation. */
     struct table_dpif tables[N_TABLES];
@@ -721,7 +734,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.) */
@@ -855,6 +909,7 @@ lookup_ofproto_dpif_by_port_name(const char *name)
 static int
 type_run(const char *type)
 {
+    static long long int push_timer = LLONG_MIN;
     struct dpif_backer *backer;
     char *devname;
     int error;
@@ -868,6 +923,16 @@ type_run(const char *type)
 
     dpif_run(backer->dpif);
 
+    /* The most natural place to push facet statistics is when they're pulled
+     * from the datapath.  However, when there are many flows in the datapath,
+     * this expensive operation can occur so frequently, that it reduces our
+     * ability to quickly set up flows.  To reduce the cost, we push statistics
+     * here instead. */
+    if (time_msec() > push_timer) {
+        push_timer = time_msec() + 2000;
+        push_all_stats();
+    }
+
     if (backer->need_revalidate
         || !tag_set_is_empty(&backer->revalidate_set)) {
         struct tag_set revalidate_set = backer->revalidate_set;
@@ -955,6 +1020,7 @@ type_run(const char *type)
                 if (need_revalidate
                     || tag_set_intersects(&revalidate_set, facet->tags)) {
                     facet_revalidate(facet);
+                    run_fast_rl();
                 }
             }
         }
@@ -1022,18 +1088,10 @@ type_run(const char *type)
 }
 
 static int
-type_run_fast(const char *type)
+dpif_backer_run_fast(struct dpif_backer *backer, int max_batch)
 {
-    struct dpif_backer *backer;
     unsigned int work;
 
-    backer = shash_find_data(&all_dpif_backers, type);
-    if (!backer) {
-        /* This is not necessarily a problem, since backers are only
-         * created on demand. */
-        return 0;
-    }
-
     /* Handle one or more batches of upcalls, until there's nothing left to do
      * or until we do a fixed total amount of work.
      *
@@ -1044,8 +1102,8 @@ type_run_fast(const char *type)
      * optimizations can make major improvements on some benchmarks and
      * presumably for real traffic as well. */
     work = 0;
-    while (work < FLOW_MISS_MAX_BATCH) {
-        int retval = handle_upcalls(backer, FLOW_MISS_MAX_BATCH - work);
+    while (work < max_batch) {
+        int retval = handle_upcalls(backer, max_batch - work);
         if (retval <= 0) {
             return -retval;
         }
@@ -1055,6 +1113,58 @@ type_run_fast(const char *type)
     return 0;
 }
 
+static int
+type_run_fast(const char *type)
+{
+    struct dpif_backer *backer;
+
+    backer = shash_find_data(&all_dpif_backers, type);
+    if (!backer) {
+        /* This is not necessarily a problem, since backers are only
+         * created on demand. */
+        return 0;
+    }
+
+    return dpif_backer_run_fast(backer, FLOW_MISS_MAX_BATCH);
+}
+
+static void
+run_fast_rl(void)
+{
+    static long long int port_rl = LLONG_MIN;
+    static unsigned int backer_rl = 0;
+
+    if (time_msec() >= port_rl) {
+        struct ofproto_dpif *ofproto;
+        struct ofport_dpif *ofport;
+
+        HMAP_FOR_EACH (ofproto, all_ofproto_dpifs_node, &all_ofproto_dpifs) {
+
+            HMAP_FOR_EACH (ofport, up.hmap_node, &ofproto->up.ports) {
+                port_run_fast(ofport);
+            }
+        }
+        port_rl = time_msec() + 200;
+    }
+
+    /* XXX: We have to be careful not to do too much work in this function.  If
+     * we call dpif_backer_run_fast() too often, or with too large a batch,
+     * performance improves signifcantly, but at a cost.  It's possible for the
+     * number of flows in the datapath to increase without bound, and for poll
+     * loops to take 10s of seconds.   The correct solution to this problem,
+     * long term, is to separate flow miss handling into it's own thread so it
+     * isn't affected by revalidations, and expirations.  Until then, this is
+     * the best we can do. */
+    if (++backer_rl >= 10) {
+        struct shash_node *node;
+
+        backer_rl = 0;
+        SHASH_FOR_EACH (node, &all_dpif_backers) {
+            dpif_backer_run_fast(node->data, 1);
+        }
+    }
+}
+
 static void
 type_wait(const char *type)
 {
@@ -1250,6 +1360,7 @@ construct(struct ofproto *ofproto_)
     hmap_init(&ofproto->facets);
     hmap_init(&ofproto->subfacets);
     ofproto->governor = NULL;
+    ofproto->consistency_rl = LLONG_MIN;
 
     for (i = 0; i < N_TABLES; i++) {
         struct table_dpif *table = &ofproto->tables[i];
@@ -1301,6 +1412,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;
 }
 
@@ -1474,10 +1598,13 @@ run(struct ofproto *ofproto_)
     mac_learning_run(ofproto->ml, &ofproto->backer->revalidate_set);
 
     /* Check the consistency of a random facet, to aid debugging. */
-    if (!hmap_is_empty(&ofproto->facets)
+    if (time_msec() >= ofproto->consistency_rl
+        && !hmap_is_empty(&ofproto->facets)
         && !ofproto->backer->need_revalidate) {
         struct facet *facet;
 
+        ofproto->consistency_rl = time_msec() + 250;
+
         facet = CONTAINER_OF(hmap_random_node(&ofproto->facets),
                              struct facet, hmap_node);
         if (!tag_set_intersects(&ofproto->backer->revalidate_set,
@@ -2868,6 +2995,8 @@ mirror_get_stats(struct ofproto *ofproto_, void *aux,
         return 0;
     }
 
+    push_all_stats();
+
     *packets = mirror->packet_count;
     *bytes = mirror->byte_count;
 
@@ -3126,6 +3255,8 @@ port_get_stats(const struct ofport *ofport_, struct netdev_stats *stats)
     struct ofport_dpif *ofport = ofport_dpif_cast(ofport_);
     int error;
 
+    push_all_stats();
+
     error = netdev_get_stats(ofport->up.netdev, stats);
 
     if (!error && ofport_->ofp_port == OFPP_LOCAL) {
@@ -4026,6 +4157,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);
@@ -4087,7 +4221,6 @@ update_subfacet_stats(struct subfacet *subfacet,
         facet_account(facet);
         facet->accounted_bytes = facet->byte_count;
     }
-    facet_push_stats(facet);
 }
 
 /* 'key' with length 'key_len' bytes is a flow in 'dpif' that we know nothing
@@ -4146,6 +4279,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);
@@ -4173,6 +4310,7 @@ update_stats(struct dpif_backer *backer)
             delete_unexpected_flow(ofproto, key, key_len);
             break;
         }
+        run_fast_rl();
     }
     dpif_flow_dump_done(&dump);
 }
@@ -4371,6 +4509,8 @@ facet_create(struct rule_dpif *rule, const struct flow *flow, uint32_t hash)
     netflow_flow_init(&facet->nf_flow);
     netflow_flow_update_time(ofproto->netflow, &facet->nf_flow, facet->used);
 
+    facet->learn_rl = time_msec() + 500;
+
     return facet;
 }
 
@@ -4445,8 +4585,15 @@ facet_learn(struct facet *facet)
     struct ofproto_dpif *ofproto = ofproto_dpif_cast(facet->rule->up.ofproto);
     struct subfacet *subfacet= CONTAINER_OF(list_front(&facet->subfacets),
                                             struct subfacet, list_node);
+    long long int now = time_msec();
     struct action_xlate_ctx ctx;
 
+    if (!facet->has_fin_timeout && now < facet->learn_rl) {
+        return;
+    }
+
+    facet->learn_rl = now + 500;
+
     if (!facet->has_learn
         && !facet->has_normal
         && (!facet->has_fin_timeout
@@ -4953,6 +5100,28 @@ facet_push_stats(struct facet *facet)
     }
 }
 
+static void
+push_all_stats(void)
+{
+    static long long int rl = LLONG_MIN;
+    struct ofproto_dpif *ofproto;
+
+    if (time_msec() < rl) {
+        return;
+    }
+
+    HMAP_FOR_EACH (ofproto, all_ofproto_dpifs_node, &all_ofproto_dpifs) {
+        struct facet *facet;
+
+        HMAP_FOR_EACH (facet, hmap_node, &ofproto->facets) {
+            facet_push_stats(facet);
+            run_fast_rl();
+        }
+    }
+
+    rl = time_msec() + 100;
+}
+
 static void
 rule_credit_stats(struct rule_dpif *rule, const struct dpif_flow_stats *stats)
 {
@@ -5044,6 +5213,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;
@@ -5055,6 +5225,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;
 }
 
@@ -5066,6 +5237,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);
@@ -5113,6 +5288,7 @@ subfacet_destroy_batch(struct ofproto_dpif *ofproto,
         subfacet_reset_dp_stats(subfacets[i], &stats[i]);
         subfacets[i]->path = SF_NOT_INSTALLED;
         subfacet_destroy(subfacets[i]);
+        run_fast_rl();
     }
 }
 
@@ -5428,6 +5604,8 @@ rule_get_stats(struct rule *rule_, uint64_t *packets, uint64_t *bytes)
     struct rule_dpif *rule = rule_dpif_cast(rule_);
     struct facet *facet;
 
+    push_all_stats();
+
     /* Start from historical data for 'rule' itself that are no longer tracked
      * in facets.  This counts, for example, facets that have expired. */
     *packets = rule->packet_count;
@@ -8071,14 +8249,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++) {
@@ -8495,6 +8699,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)