From: Ben Pfaff Date: Sat, 18 Aug 2012 06:27:40 +0000 (-0700) Subject: ofproto-dpif: Make sure one-packet flows have zero duration (again). X-Git-Tag: sliver-openvswitch-1.8.90-0~48^2~18 X-Git-Url: http://git.onelab.eu/?p=sliver-openvswitch.git;a=commitdiff_plain;h=459b16a1e2882e4122440121742e4df92300f335 ofproto-dpif: Make sure one-packet flows have zero duration (again). commit 6a0a5bbbc (ofproto-dpif: Make sure one-packet flows have zero duration.) was supposed to fix failures in the "ofproto-dpif - NetFlow flow expiration" test, but it didn't fix the whole problem. That commit eliminated one reason why a one-packet flow might be shown as having an nonzero duration, but missed another. The other reason was that the call to dpif_flow_stats_extract() could obtain a time later than the time that a new facet was created. (This wasn't obvious because dpif_flow_stats_extract() obtained the time internally instead of taking it from the caller.) This commit fixes that problem, by using the facet creation there too for the first packet in a facet. This problem has suddenly started showing up in a lot of builds. I think it's probably because of the recent change that makes x86-64 skip the timer optimizations, so that the return value of time_msec() changes every 1 ms, not just every 100 ms. I've tested this by running the test in question in a loop for several minutes, without any failures. Signed-off-by: Ben Pfaff --- diff --git a/ofproto/ofproto-dpif.c b/ofproto/ofproto-dpif.c index 2fcb025ef..b83a50f74 100644 --- a/ofproto/ofproto-dpif.c +++ b/ofproto/ofproto-dpif.c @@ -368,7 +368,8 @@ struct subfacet { static struct subfacet *subfacet_create(struct facet *, enum odp_key_fitness, const struct nlattr *key, - size_t key_len, ovs_be16 initial_tci); + size_t key_len, ovs_be16 initial_tci, + long long int now); static struct subfacet *subfacet_find(struct ofproto_dpif *, const struct nlattr *key, size_t key_len); static void subfacet_destroy(struct subfacet *); @@ -2904,9 +2905,17 @@ handle_flow_miss_without_facet(struct flow_miss *miss, } /* Handles 'miss', which matches 'facet'. May add any required datapath - * operations to 'ops', incrementing '*n_ops' for each new op. */ + * operations to 'ops', incrementing '*n_ops' for each new op. + * + * All of the packets in 'miss' are considered to have arrived at time 'now'. + * This is really important only for new facets: if we just called time_msec() + * here, then the new subfacet or its packets could look (occasionally) as + * though it was used some time after the facet was used. That can make a + * one-packet flow look like it has a nonzero duration, which looks odd in + * e.g. NetFlow statistics. */ static void handle_flow_miss_with_facet(struct flow_miss *miss, struct facet *facet, + long long int now, struct flow_miss_op *ops, size_t *n_ops) { struct ofproto_dpif *ofproto = ofproto_dpif_cast(facet->rule->up.ofproto); @@ -2916,7 +2925,7 @@ handle_flow_miss_with_facet(struct flow_miss *miss, struct facet *facet, subfacet = subfacet_create(facet, miss->key_fitness, miss->key, miss->key_len, - miss->initial_tci); + miss->initial_tci, now); LIST_FOR_EACH (packet, list_node, &miss->packets) { struct flow_miss_op *op = &ops[*n_ops]; @@ -2930,7 +2939,7 @@ handle_flow_miss_with_facet(struct flow_miss *miss, struct facet *facet, subfacet_make_actions(subfacet, packet, &odp_actions); } - dpif_flow_stats_extract(&facet->flow, packet, time_msec(), &stats); + dpif_flow_stats_extract(&facet->flow, packet, now, &stats); subfacet_update_stats(subfacet, &stats); if (subfacet->actions_len) { @@ -2984,6 +2993,7 @@ handle_flow_miss(struct ofproto_dpif *ofproto, struct flow_miss *miss, struct flow_miss_op *ops, size_t *n_ops) { struct facet *facet; + long long int now; uint32_t hash; /* The caller must ensure that miss->hmap_node.hash contains @@ -3000,8 +3010,11 @@ handle_flow_miss(struct ofproto_dpif *ofproto, struct flow_miss *miss, } facet = facet_create(rule, &miss->flow, hash); + now = facet->used; + } else { + now = time_msec(); } - handle_flow_miss_with_facet(miss, facet, ops, n_ops); + handle_flow_miss_with_facet(miss, facet, now, ops, n_ops); } /* Like odp_flow_key_to_flow(), this function converts the 'key_len' bytes of @@ -4248,7 +4261,8 @@ subfacet_find__(struct ofproto_dpif *ofproto, * subfacet_make_actions(). */ static struct subfacet * subfacet_create(struct facet *facet, enum odp_key_fitness key_fitness, - const struct nlattr *key, size_t key_len, ovs_be16 initial_tci) + const struct nlattr *key, size_t key_len, + ovs_be16 initial_tci, long long int now) { struct ofproto_dpif *ofproto = ofproto_dpif_cast(facet->rule->up.ofproto); uint32_t key_hash = odp_flow_key_hash(key, key_len); @@ -4256,14 +4270,6 @@ subfacet_create(struct facet *facet, enum odp_key_fitness key_fitness, if (list_is_empty(&facet->subfacets)) { subfacet = &facet->one_subfacet; - - /* This subfacet should conceptually be created, and have its first - * packet pass through, at the same time that its facet was created. - * If we called time_msec() here, then the subfacet could look - * (occasionally) as though it was used some time after the facet was - * used. That can make a one-packet flow look like it has a nonzero - * duration, which looks odd in e.g. NetFlow statistics. */ - subfacet->used = facet->used; } else { subfacet = subfacet_find__(ofproto, key, key_len, key_hash, &facet->flow); @@ -4278,7 +4284,6 @@ subfacet_create(struct facet *facet, enum odp_key_fitness key_fitness, } subfacet = xmalloc(sizeof *subfacet); - subfacet->used = time_msec(); } hmap_insert(&ofproto->subfacets, &subfacet->hmap_node, key_hash); @@ -4292,6 +4297,7 @@ subfacet_create(struct facet *facet, enum odp_key_fitness key_fitness, subfacet->key = NULL; subfacet->key_len = 0; } + subfacet->used = now; subfacet->dp_packet_count = 0; subfacet->dp_byte_count = 0; subfacet->actions_len = 0;