cfm: Warn when delayed sending CCMs.

We've recently seen problems where OVS can get delayed sending CCM
probes by several seconds.  This can cause tunnels to flap, and
generally wreak havoc.  It's easy to detect when this is happening,
so minimally, warning should be helpful to those debugging
problems.

Signed-off-by: Ethan Jackson <ethan@nicira.com>

diff --git a/lib/cfm.c b/lib/cfm.c
index 9859525..357baf0 100644 (file)
--- a/lib/cfm.c
+++ b/lib/cfm.c
@@ -118,7 +118,7 @@ struct cfm {
                                  received. */
     int health_interval;      /* Number of fault_intervals since health was
                                  recomputed. */
-
+    long long int last_tx;    /* Last CCM transmission time. */
 };
 
 /* Remote MPs represent foreign network entities that are configured to have
@@ -299,6 +299,7 @@ cfm_create(const char *name)
     cfm->remote_opup = true;
     cfm->fault_override = -1;
     cfm->health = -1;
+    cfm->last_tx = 0;
     return cfm;
 }
 
@@ -466,6 +467,16 @@ cfm_compose_ccm(struct cfm *cfm, struct ofpbuf *packet,
     if (hmap_is_empty(&cfm->remote_mps)) {
         ccm->flags |= CCM_RDI_MASK;
     }
+
+    if (cfm->last_tx) {
+        long long int delay = time_msec() - cfm->last_tx;
+        if (delay > (cfm->ccm_interval_ms * 3 / 2)) {
+            VLOG_WARN("%s: long delay of %lldms (expected %dms) sending CCM"
+                      " seq %"PRIu32, cfm->name, delay, cfm->ccm_interval_ms,
+                      cfm->seq);
+        }
+    }
+    cfm->last_tx = time_msec();
 }
 
 void