controller: Fix mac-cache race condition causing extra ARP.

Usually mac_binding_stats_run and mac_binding_probe_stats_run are executed
either both with (since_updated < threshold->cooldown_period), and sb is
not updated, or both with (since_updated >= threshold->cooldown_period),
and sb is updated but ARP is not sent
(until stats->idle_age_ms > threshold->value).

However, if mac_binding_stats_run is executed as
(since_updated < threshold->cooldown_period), it does not update
mac_binding, as expected.
Then, if mac_binding_probe_stats_run is executed just afterwards, but with
(since_updated_ms >= threshold->cooldown_period), ARP is sent.

Fix this by calling time_wall_msec() once in statctrl_run() and passing it
to all stats_run functions.

This was identified through random failures of test
"MAC binding aging - probing GW router Dynamic Neigh".

Fixes: 1e4d440 ("controller: Send ARP/ND for stale mac_bindings entries.")
Signed-off-by: Xavier Simonart <xsimonar@redhat.com>
Acked-by: Ales Musil <amusil@redhat.com>
Signed-off-by: Ales Musil <amusil@redhat.com>
(cherry picked from commit a68cf33)

Author: simonartxavier

controller/mac-cache.c

@@ -412,10 +412,9 @@ mac_binding_update_log(const char *action,
 
 void
 mac_binding_stats_run(struct ovs_list *stats_list, uint64_t *req_delay,
-                      void *data)
+                      void *data, long long timewall_now)
 {
     struct mac_cache_data *cache_data = data;
-    long long timewall_now = time_wall_msec();
 
     struct mac_cache_stats *stats;
     LIST_FOR_EACH_POP (stats, list_node, stats_list) {
@@ -511,10 +510,10 @@ fdb_update_log(const char *action,
 }
 
 void
-fdb_stats_run(struct ovs_list *stats_list, uint64_t *req_delay, void *data)
+fdb_stats_run(struct ovs_list *stats_list, uint64_t *req_delay, void *data,
+              long long timewall_now)
 {
     struct mac_cache_data *cache_data = data;
-    long long timewall_now = time_wall_msec();
 
     struct mac_cache_stats *stats;
     LIST_FOR_EACH_POP (stats, list_node, stats_list) {
@@ -891,9 +890,8 @@ mac_binding_probe_stats_process_flow_stats(
 
 void
 mac_binding_probe_stats_run(struct ovs_list *stats_list, uint64_t *req_delay,
-                            void *data)
+                            void *data, long long timewall_now)
 {
-    long long timewall_now = time_wall_msec();
     struct mac_binding_probe_data *probe_data = data;
     struct mac_cache_data *cache_data = probe_data->cache_data;
 

controller/mac-cache.h

@@ -189,14 +189,14 @@ mac_binding_stats_process_flow_stats(struct ovs_list *stats_list,
                                      struct ofputil_flow_stats *ofp_stats);
 
 void mac_binding_stats_run(struct ovs_list *stats_list, uint64_t *req_delay,
-                           void *data);
+                           void *data, long long timewall_now);
 
 /* FDB stat processing. */
 void fdb_stats_process_flow_stats(struct ovs_list *stats_list,
                                   struct ofputil_flow_stats *ofp_stats);
 
 void fdb_stats_run(struct ovs_list *stats_list, uint64_t *req_delay,
-                   void *data);
+                   void *data, long long timewall_now);
 
 void mac_cache_stats_destroy(struct ovs_list *stats_list);
 
@@ -234,6 +234,7 @@ void mac_binding_probe_stats_process_flow_stats(
         struct ofputil_flow_stats *ofp_stats);
 
 void mac_binding_probe_stats_run(struct ovs_list *stats_list,
-                                 uint64_t *req_delay, void *data);
+                                 uint64_t *req_delay, void *data,
+                                 long long timewall_now);
 
 #endif /* controller/mac-cache.h */

controller/statctrl.c

@@ -64,7 +64,8 @@ struct stats_node {
                                struct ofputil_flow_stats *ofp_stats);
     /* Function to process the parsed stats.
      * This function runs in main thread locked behind mutex. */
-    void (*run)(struct ovs_list *stats_list, uint64_t *req_delay, void *data);
+    void (*run)(struct ovs_list *stats_list, uint64_t *req_delay, void *data,
+                long long timewall_now);
     /* Name of the stats node corresponding stopwatch. */
     const char *stopwatch_name;
 };
@@ -197,6 +198,7 @@ statctrl_run(struct ovsdb_idl_txn *ovnsb_idl_txn,
 
     bool schedule_updated = false;
     long long now = time_msec();
+    long long timewall_now = time_wall_msec();
 
     ovs_mutex_lock(&mutex);
     statctrl_ctx.new_main_seq = seq_read(statctrl_ctx.main_seq);
@@ -205,7 +207,8 @@ statctrl_run(struct ovsdb_idl_txn *ovnsb_idl_txn,
         uint64_t prev_delay = node->request_delay;
 
         stopwatch_start(node->stopwatch_name, time_msec());
-        node->run(&node->stats_list, &node->request_delay, node_data[i]);
+        node->run(&node->stats_list, &node->request_delay,
+                  node_data[i], timewall_now);
         stopwatch_stop(node->stopwatch_name, time_msec());
 
         schedule_updated |=