Tests: fix time.sleep(0) # yield. Reduce sleep related log messages. 64/18164/2
authorPaul Vinciguerra <pvinci@vinciconsulting.com>
Sun, 10 Mar 2019 16:10:54 +0000 (09:10 -0700)
committerOle Trøan <otroan@employees.org>
Mon, 11 Mar 2019 08:10:34 +0000 (08:10 +0000)
Reduce the incidence of:
20:04:23,606 unexpected time.sleep() result - slept for 2.187967e-03s instead of ~6.837845e-04s!

Change-Id: Ic576fda7f75e571c9019111588a6a936ee2cf5c2
Signed-off-by: Paul Vinciguerra <pvinci@vinciconsulting.com>
test/framework.py
test/test_bfd.py
test/vpp_papi_provider.py
test/vpp_pg_interface.py

index 778832f..2c1c829 100644 (file)
@@ -390,7 +390,7 @@ class VppTestCase(unittest.TestCase):
             if os.path.exists(cls.stats_sock):
                 ok = True
                 break
-            time.sleep(0.8)
+            cls.sleep(0.8)
         if not ok:
             cls.logger.critical("Couldn't stat : {}".format(cls.stats_sock))
 
@@ -951,13 +951,26 @@ class VppTestCase(unittest.TestCase):
 
     @classmethod
     def sleep(cls, timeout, remark=None):
+
+        # /* Allow sleep(0) to maintain win32 semantics, and as decreed
+        #  * by Guido, only the main thread can be interrupted.
+        # */
+        # https://github.com/python/cpython/blob/6673decfa0fb078f60587f5cb5e98460eea137c2/Modules/timemodule.c#L1892  # noqa
+        if timeout == 0:
+            # yield quantum
+            if hasattr(os, 'sched_yield'):
+                os.sched_yield()
+            else:
+                time.sleep(0)
+            return
+
         if hasattr(cls, 'logger'):
             cls.logger.debug("Starting sleep for %es (%s)", timeout, remark)
         before = time.time()
         time.sleep(timeout)
         after = time.time()
         if hasattr(cls, 'logger') and after - before > 2 * timeout:
-            cls.logger.error("unexpected time.sleep() result - "
+            cls.logger.error("unexpected self.sleep() result - "
                              "slept for %es instead of ~%es!",
                              after - before, timeout)
         if hasattr(cls, 'logger'):
index a450a33..7b47422 100644 (file)
@@ -1065,7 +1065,7 @@ class BFD4TestCase(VppTestCase):
             / USEC_IN_SEC
         count = 0
         for dummy in range(self.test_session.detect_mult * 2):
-            time.sleep(transmit_time)
+            self.sleep(transmit_time)
             self.test_session.send_packet(demand)
             try:
                 p = wait_for_bfd_packet(self, timeout=0)
@@ -1448,7 +1448,7 @@ class BFD4TestCase(VppTestCase):
             / USEC_IN_SEC
         count = 0
         for dummy in range(self.test_session.detect_mult * 2):
-            time.sleep(transmit_time)
+            self.sleep(transmit_time)
             self.test_session.send_packet(demand)
             try:
                 p = wait_for_bfd_packet(self, timeout=0)
index 37f63c0..fca57c3 100644 (file)
@@ -303,7 +303,7 @@ class VppPapiProvider(object):
                 self.test_class.logger.debug("Returning event %s:%s" %
                                              (name, e))
                 return e
-            time.sleep(0)  # yield
+            self.test_class.sleep(0)  # yield
         raise Exception("Event did not occur within timeout")
 
     def __call__(self, name, event):
index 1300f1f..b22a933 100644 (file)
@@ -285,7 +285,7 @@ class VppPGInterface(VppInterface):
         while time.time() < deadline:
             if os.path.isfile(self.out_path):
                 break
-            time.sleep(0)  # yield
+            self._test.sleep(0)  # yield
         if os.path.isfile(self.out_path):
             self.test.logger.debug("Capture file appeared after %fs" %
                                    (time.time() - (deadline - timeout)))
@@ -353,7 +353,7 @@ class VppPGInterface(VppInterface):
             self.test.logger.debug("Polling for packet")
         while time.time() < deadline or poll:
             if not self.verify_enough_packet_data_in_pcap():
-                time.sleep(0)  # yield
+                self._test.sleep(0)  # yield
                 poll = False
                 continue
             p = self._pcap_reader.recv()
@@ -367,7 +367,7 @@ class VppPGInterface(VppInterface):
                         "Packet received after %fs" %
                         (time.time() - (deadline - timeout)))
                     return p
-            time.sleep(0)  # yield
+            self._test.sleep(0)  # yield
             poll = False
         self.test.logger.debug("Timeout - no packets received")
         raise CaptureTimeoutError("Packet didn't arrive within timeout")