BFD: fix timing in the main loop

Properly wakeup the main process loop only when necessary to avoid
missed events. Improve BFD unit test reliability and speed. Add
timestamps to logs and replace Queue with more efficient deque.

Change-Id: I01255a02057d3146917b43b669ccdc74f31ef0c8
Signed-off-by: Klement Sekera <ksekera@cisco.com>

1 files changed, 35 insertions, 34 deletions

diff --git a/test/test_bfd.py b/test/test_bfd.py
index 58f12645..b48c3cc4 100644
--- a/test/test_bfd.py
+++ b/test/test_bfd.py
@@ -8,12 +8,12 @@ from framework import *
 from util import ppp
 
 
-class BFDCLITestCase(VppTestCase):
-    """Bidirectional Forwarding Detection (BFD) - CLI"""
+class BFDAPITestCase(VppTestCase):
+    """Bidirectional Forwarding Detection (BFD) - API"""
 
     @classmethod
     def setUpClass(cls):
-        super(BFDCLITestCase, cls).setUpClass()
+        super(BFDAPITestCase, cls).setUpClass()
 
         try:
             cls.create_pg_interfaces([0])
@@ -21,7 +21,7 @@ class BFDCLITestCase(VppTestCase):
             cls.pg0.resolve_arp()
 
         except Exception:
-            super(BFDCLITestCase, cls).tearDownClass()
+            super(BFDAPITestCase, cls).tearDownClass()
             raise
 
     def test_add_bfd(self):
@@ -80,7 +80,7 @@ class BFDTestSession(object):
         self.interface = interface
         self.bfd_values = {
             'my_discriminator': 0,
-            'desired_min_tx_interval': 500000,
+            'desired_min_tx_interval': 100000,
             'detect_mult': detect_mult,
             'diag': BFDDiagCode.no_diagnostic,
         }
@@ -98,7 +98,7 @@ class BFDTestSession(object):
         p = self.create_packet()
         self.test.logger.debug(ppp("Sending packet:", p))
         self.test.pg0.add_stream([p])
-        self.test.pg_start()
+        self.test.pg_start(sleep_time=0)
 
     def verify_packet(self, packet):
         """ Verify correctness of BFD layer. """
@@ -116,7 +116,7 @@ class BFDTestCase(VppTestCase):
     def setUpClass(cls):
         super(BFDTestCase, cls).setUpClass()
         try:
-            cls.create_pg_interfaces([0, 1])
+            cls.create_pg_interfaces([0])
             cls.pg0.config_ip4()
             cls.pg0.generate_remote_hosts()
             cls.pg0.configure_ipv4_neighbors()
@@ -137,6 +137,7 @@ class BFDTestCase(VppTestCase):
 
     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.vpp_session.remove_vpp_config()
         super(BFDTestCase, self).tearDown()
@@ -144,7 +145,7 @@ class BFDTestCase(VppTestCase):
     def verify_event(self, event, expected_state):
         """ Verify correctness of event values. """
         e = event
-        self.logger.debug("Event: %s" % repr(e))
+        self.logger.debug("BFD: Event: %s" % repr(e))
         self.assert_equal(e.bs_index, self.vpp_session.bs_index,
                           "BFD session index")
         self.assert_equal(e.sw_if_index, self.vpp_session.interface.sw_if_index,
@@ -166,6 +167,7 @@ class BFDTestCase(VppTestCase):
         self.assert_equal(e.state, expected_state, BFDState)
 
     def wait_for_bfd_packet(self, timeout=1):
+        self.logger.info("BFD: Waiting for BFD packet")
         p = self.pg0.wait_for_packet(timeout=timeout)
         bfd = p[BFD]
         if bfd is None:
@@ -178,22 +180,23 @@ class BFDTestCase(VppTestCase):
         return p
 
     def test_slow_timer(self):
-        """ Slow timer """
-
+        """ verify slow periodic control frames while session down """
         self.pg_enable_capture([self.pg0])
-        expected_packets = 10
-        self.logger.info("Waiting for %d BFD packets" % expected_packets)
+        expected_packets = 3
+        self.logger.info("BFD: Waiting for %d BFD packets" % expected_packets)
         self.wait_for_bfd_packet()
         for i in range(expected_packets):
             before = time.time()
             self.wait_for_bfd_packet()
             after = time.time()
+            # spec says the range should be <0.75, 1>, allow extra 0.05 margin
+            # to work around timing issues
             self.assert_in_range(
-                after - before, 0.75, 1, "time between slow packets")
+                after - before, 0.70, 1.05, "time between slow packets")
             before = after
 
     def test_zero_remote_min_rx(self):
-        """ Zero RemoteMinRxInterval """
+        """ no packets when zero BFD RemoteMinRxInterval """
         self.pg_enable_capture([self.pg0])
         p = self.wait_for_bfd_packet()
         self.test_session.update(my_discriminator=randint(0, 40000000),
@@ -210,50 +213,48 @@ class BFDTestCase(VppTestCase):
             return
         raise Exception(ppp("Received unexpected BFD packet:", p))
 
-    def bfd_conn_up(self):
+    def bfd_session_up(self):
         self.pg_enable_capture([self.pg0])
-        self.logger.info("Waiting for slow hello")
+        self.logger.info("BFD: Waiting for slow hello")
         p = self.wait_for_bfd_packet()
-        self.logger.info("Sending Init")
+        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=500000)
+                                 required_min_rx_interval=100000)
         self.test_session.send_packet()
-        self.logger.info("Waiting for event")
+        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("Session is Up")
+        self.logger.info("BFD: Session is Up")
         self.test_session.update(state=BFDState.up)
 
-    def test_conn_up(self):
-        """ Basic connection up """
-        self.bfd_conn_up()
+    def test_session_up(self):
+        """ bring BFD session up """
+        self.bfd_session_up()
 
     def test_hold_up(self):
-        """ Hold BFD up """
-        self.bfd_conn_up()
+        """ hold BFD session up """
+        self.bfd_session_up()
         for i in range(5):
             self.wait_for_bfd_packet()
             self.test_session.send_packet()
 
     def test_conn_down(self):
-        """ Session down after inactivity """
-        self.bfd_conn_up()
+        """ verify session goes down after inactivity """
+        self.bfd_session_up()
         self.wait_for_bfd_packet()
-        self.assert_equal(
-            0, len(self.vapi.collect_events()),
-            "number of bfd events")
+        self.assert_equal(len(self.vapi.collect_events()), 0,
+                          "number of bfd events")
         self.wait_for_bfd_packet()
-        self.assert_equal(
-            0, len(self.vapi.collect_events()),
-            "number of bfd events")
+        self.assert_equal(len(self.vapi.collect_events()), 0,
+                          "number of bfd events")
         e = self.vapi.wait_for_event(1, "bfd_udp_session_details")
         self.verify_event(e, expected_state=BFDState.down)
 
     @unittest.skip("this test is not working yet")
     def test_large_required_min_rx(self):
-        self.bfd_conn_up()
+        self.bfd_session_up()
         interval = 5000000
         self.test_session.update(required_min_rx_interval=interval)
         self.test_session.send_packet()