BFD: immediately honor reduced remote_min_rx interval

Change-Id: I7f09b45c926557d2ad0e2706b38fa56ff8194a3d
Signed-off-by: Klement Sekera <ksekera@cisco.com>
diff --git a/src/vnet/bfd/bfd_main.c b/src/vnet/bfd/bfd_main.c
index e25eadf..62be184 100644
--- a/src/vnet/bfd/bfd_main.c
+++ b/src/vnet/bfd/bfd_main.c
@@ -126,38 +126,36 @@
       if (bs->local_detect_mult > 1)
 	{
 	  /* common case - 75-100% of transmit interval */
-	  bs->tx_timeout_clocks = now +
+	  bs->tx_timeout_clocks = bs->last_tx_clocks +
 	    (1 - .25 * (random_f64 (&bm->random_seed))) *
 	    bs->transmit_interval_clocks;
 	  if (bs->tx_timeout_clocks < now)
 	    {
-	      /* huh, we've missed it already, skip the missed events */
-	      const u64 missed =
-		(now - bs->tx_timeout_clocks) / bs->transmit_interval_clocks;
-	      BFD_ERR ("Missed %lu transmit events (now is %lu, calc "
-		       "tx_timeout is %lu)!",
-		       missed, now, bs->tx_timeout_clocks);
-	      bs->tx_timeout_clocks +=
-		(missed + 1) * bs->transmit_interval_clocks;
+	      /* huh, we've missed it already, transmit now */
+	      BFD_DBG ("Missed %lu transmit events (now is %lu, calc "
+		       "tx_timeout is %lu)",
+		       (now - bs->tx_timeout_clocks) /
+		       bs->transmit_interval_clocks,
+		       now, bs->tx_timeout_clocks);
+	      bs->tx_timeout_clocks = now;
 	    }
 	}
       else
 	{
 	  /* special case - 75-90% of transmit interval */
 	  bs->tx_timeout_clocks =
-	    now +
+	    bs->last_tx_clocks +
 	    (.9 - .15 * (random_f64 (&bm->random_seed))) *
 	    bs->transmit_interval_clocks;
 	  if (bs->tx_timeout_clocks < now)
 	    {
-	      /* huh, we've missed it already, skip the missed events */
-	      const u64 missed =
-		(now - bs->tx_timeout_clocks) / bs->transmit_interval_clocks;
-	      BFD_ERR ("Missed %lu transmit events (now is %lu, calc "
-		       "tx_timeout is %lu)!",
-		       missed, now, bs->tx_timeout_clocks);
-	      bs->tx_timeout_clocks +=
-		(missed + 1) * bs->transmit_interval_clocks;
+	      /* huh, we've missed it already, transmit now */
+	      BFD_DBG ("Missed %lu transmit events (now is %lu, calc "
+		       "tx_timeout is %lu)",
+		       (now - bs->tx_timeout_clocks) /
+		       bs->transmit_interval_clocks,
+		       now, bs->tx_timeout_clocks);
+	      bs->tx_timeout_clocks = now;
 	    }
 	}
     }
@@ -485,7 +483,7 @@
   pkt->your_disc = bs->remote_discr;
   pkt->des_min_tx = clib_host_to_net_u32 (bs->desired_min_tx_us);
   pkt->req_min_rx = clib_host_to_net_u32 (bs->required_min_rx_us);
-  pkt->req_min_echo_rx = clib_host_to_net_u32 (0);	/* FIXME */
+  pkt->req_min_echo_rx = clib_host_to_net_u32 (bs->required_min_echo_rx_us);
   b->current_length = bfd_length;
 }
 
@@ -519,6 +517,7 @@
 	}
       bfd_init_control_frame (b, bs);
       bfd_add_transport_layer (vm, b, bs);
+      bs->last_tx_clocks = now;
       bfd_calc_next_tx (bm, bs, now);
     }
   else
@@ -537,6 +536,7 @@
   bfd_init_control_frame (b, bs);
   bfd_pkt_set_final (vlib_buffer_get_current (b));
   bfd_add_transport_layer (vm, b, bs);
+  bs->last_tx_clocks = clib_cpu_time_now ();
 }
 
 static void
@@ -946,6 +946,7 @@
 		 "bfd.LocalDiag=%s, "
 		 "bfd.DesiredMinTxInterval=%u, "
 		 "bfd.RequiredMinRxInterval=%u, "
+		 "bfd.RequiredMinEchoRxInterval=%u, "
 		 "bfd.RemoteMinRxInterval=%u, "
 		 "bfd.DemandMode=%s, "
 		 "bfd.RemoteDemandMode=%s, "
@@ -954,7 +955,8 @@
 		 bfd_state_string (bs->remote_state), bs->local_discr,
 		 bs->remote_discr, bfd_diag_code_string (bs->local_diag),
 		 bs->desired_min_tx_us, bs->required_min_rx_us,
-		 bs->remote_min_rx_us, (bs->local_demand ? "yes" : "no"),
+		 bs->required_min_echo_rx_us, bs->remote_min_rx_us,
+		 (bs->local_demand ? "yes" : "no"),
 		 (bs->remote_demand ? "yes" : "no"), bs->local_detect_mult);
 }
 
diff --git a/src/vnet/bfd/bfd_main.h b/src/vnet/bfd/bfd_main.h
index c72ea92..cc82c83 100644
--- a/src/vnet/bfd/bfd_main.h
+++ b/src/vnet/bfd/bfd_main.h
@@ -75,16 +75,19 @@
   /* desired min tx interval (clocks) */
   u64 desired_min_tx_clocks;
 
-  /* required min rx interval */
+  /* required min rx interval (microseconds) */
   u32 required_min_rx_us;
 
+  /* required min echo rx interval (microseconds) */
+  u32 required_min_echo_rx_us;
+
   /* remote min rx interval (microseconds) */
   u32 remote_min_rx_us;
 
   /* remote min rx interval (clocks) */
   u64 remote_min_rx_clocks;
 
-  /* remote desired min tx interval */
+  /* remote desired min tx interval (microseconds) */
   u32 remote_desired_min_tx_us;
 
   /* 1 if in demand mode, 0 otherwise */
@@ -108,6 +111,9 @@
   /* next time at which to transmit a packet */
   u64 tx_timeout_clocks;
 
+  /* timestamp of last packet transmitted */
+  u64 last_tx_clocks;
+
   /* timestamp of last packet received */
   u64 last_rx_clocks;
 
diff --git a/src/vnet/bfd/bfd_udp.c b/src/vnet/bfd/bfd_udp.c
index 3c747d8..677f1e2 100644
--- a/src/vnet/bfd/bfd_udp.c
+++ b/src/vnet/bfd/bfd_udp.c
@@ -146,6 +146,7 @@
     }
   bs->config_desired_min_tx_us = desired_min_tx_us;
   bs->required_min_rx_us = required_min_rx_us;
+  bs->required_min_echo_rx_us = required_min_rx_us; /* FIXME */
   bs->local_detect_mult = detect_mult;
   bfd_session_start (bum->bfd_main, bs);
   return 0;
diff --git a/test/test_bfd.py b/test/test_bfd.py
index 1ea69f5..4aa9953 100644
--- a/test/test_bfd.py
+++ b/test/test_bfd.py
@@ -7,6 +7,8 @@
 from framework import *
 from util import ppp
 
+us_in_sec = 1000000
+
 
 class BFDAPITestCase(VppTestCase):
     """Bidirectional Forwarding Detection (BFD) - API"""
@@ -74,6 +76,7 @@
 
 
 class BFDTestSession(object):
+    """ BFD session as seen from test framework side """
 
     def __init__(self, test, interface, detect_mult=3):
         self.test = test
@@ -90,7 +93,9 @@
 
     def create_packet(self):
         packet = create_packet(self.interface)
+        self.test.logger.debug("BFD: Creating packet")
         for name, value in self.bfd_values.iteritems():
+            self.test.logger.debug("BFD: setting packet.%s=%s", name, value)
             packet[BFD].setfieldval(name, value)
         return packet
 
@@ -134,11 +139,12 @@
         self.vpp_session.add_vpp_config()
         self.vpp_session.admin_up()
         self.test_session = BFDTestSession(self, self.pg0)
+        self.test_session.update(required_min_rx_interval=100000)
 
     def tearDown(self):
-        self.vapi.want_bfd_events(enable_disable=0)
         self.vapi.collect_events()  # clear the event queue
         if not self.vpp_dead:
+            self.vapi.want_bfd_events(enable_disable=0)
             self.vpp_session.remove_vpp_config()
         super(BFDTestCase, self).tearDown()
 
@@ -167,8 +173,16 @@
         self.assert_equal(e.state, expected_state, BFDState)
 
     def wait_for_bfd_packet(self, timeout=1):
+        """ wait for BFD packet
+
+        :param timeout: how long to wait max
+
+        :returns: tuple (packet, time spent waiting for packet)
+        """
         self.logger.info("BFD: Waiting for BFD packet")
+        before = time.time()
         p = self.pg0.wait_for_packet(timeout=timeout)
+        after = time.time()
         bfd = p[BFD]
         if bfd is None:
             raise Exception(ppp("Unexpected or invalid BFD packet:", p))
@@ -177,7 +191,26 @@
         verify_ip(self, p, self.pg0.local_ip4, self.pg0.remote_ip4)
         verify_udp(self, p)
         self.test_session.verify_packet(p)
-        return p
+        return p, after - before
+
+    def bfd_session_up(self):
+        self.pg_enable_capture([self.pg0])
+        self.logger.info("BFD: Waiting for slow hello")
+        p, ttp = self.wait_for_bfd_packet()
+        self.logger.info("BFD: Sending Init")
+        self.test_session.update(my_discriminator=randint(0, 40000000),
+                                 your_discriminator=p[BFD].my_discriminator,
+                                 state=BFDState.init)
+        self.test_session.send_packet()
+        self.logger.info("BFD: Waiting for event")
+        e = self.vapi.wait_for_event(1, "bfd_udp_session_details")
+        self.verify_event(e, expected_state=BFDState.up)
+        self.logger.info("BFD: Session is Up")
+        self.test_session.update(state=BFDState.up)
+
+    def test_session_up(self):
+        """ bring BFD session up """
+        self.bfd_session_up()
 
     def test_slow_timer(self):
         """ verify slow periodic control frames while session down """
@@ -198,7 +231,7 @@
     def test_zero_remote_min_rx(self):
         """ no packets when zero BFD RemoteMinRxInterval """
         self.pg_enable_capture([self.pg0])
-        p = self.wait_for_bfd_packet(2)
+        p, timeout = self.wait_for_bfd_packet(2)
         self.test_session.update(my_discriminator=randint(0, 40000000),
                                  your_discriminator=p[BFD].my_discriminator,
                                  state=BFDState.init,
@@ -213,26 +246,6 @@
             return
         raise Exception(ppp("Received unexpected BFD packet:", p))
 
-    def bfd_session_up(self):
-        self.pg_enable_capture([self.pg0])
-        self.logger.info("BFD: Waiting for slow hello")
-        p = self.wait_for_bfd_packet(2)
-        self.logger.info("BFD: Sending Init")
-        self.test_session.update(my_discriminator=randint(0, 40000000),
-                                 your_discriminator=p[BFD].my_discriminator,
-                                 state=BFDState.init,
-                                 required_min_rx_interval=100000)
-        self.test_session.send_packet()
-        self.logger.info("BFD: Waiting for event")
-        e = self.vapi.wait_for_event(1, "bfd_udp_session_details")
-        self.verify_event(e, expected_state=BFDState.up)
-        self.logger.info("BFD: Session is Up")
-        self.test_session.update(state=BFDState.up)
-
-    def test_session_up(self):
-        """ bring BFD session up """
-        self.bfd_session_up()
-
     def test_hold_up(self):
         """ hold BFD session up """
         self.bfd_session_up()
@@ -260,7 +273,7 @@
         self.test_session.send_packet()
         now = time.time()
         count = 0
-        while time.time() < now + interval / 1000000:
+        while time.time() < now + interval / us_in_sec:
             try:
                 p = self.wait_for_bfd_packet()
                 if count > 1:
@@ -270,6 +283,31 @@
                 pass
         self.assert_in_range(count, 0, 1, "number of packets received")
 
+    def test_immediate_remote_min_rx_reduce(self):
+        """ immediately honor remote min rx reduction """
+        self.vpp_session.remove_vpp_config()
+        self.vpp_session = VppBFDUDPSession(self, self.pg0, self.pg0.remote_ip4,
+                                            desired_min_tx=10000)
+        self.vpp_session.add_vpp_config()
+        self.test_session.update(desired_min_tx_interval=1000000,
+                                 required_min_rx_interval=1000000)
+        self.bfd_session_up()
+        self.wait_for_bfd_packet()
+        interval = 100000
+        self.test_session.update(required_min_rx_interval=interval)
+        self.test_session.send_packet()
+        p, ttp = self.wait_for_bfd_packet()
+        # allow extra 10% to work around timing issues, first packet is special
+        self.assert_in_range(ttp, 0, 1.10 * interval / us_in_sec,
+                             "time between BFD packets")
+        p, ttp = self.wait_for_bfd_packet()
+        self.assert_in_range(ttp, .9 * .75 * interval / us_in_sec,
+                             1.10 * interval / us_in_sec,
+                             "time between BFD packets")
+        p, ttp = self.wait_for_bfd_packet()
+        self.assert_in_range(ttp, .9 * .75 * interval / us_in_sec,
+                             1.10 * interval / us_in_sec,
+                             "time between BFD packets")
 
 if __name__ == '__main__':
     unittest.main(testRunner=VppTestRunner)