changeset:   89095:32dc137f5e26
parent:      89093:28aef6e22736
user:        Victor Stinner <victor.stinner@gmail.com>
date:        Mon Feb 10 11:47:50 2014 +0100
files:       Lib/asyncio/base_events.py Lib/test/test_asyncio/test_events.py
description:
Issue #20505: Add debug info to analyze sporaric failures of
test_timeout_rounding() on Windows XP buildbots.


diff -r 28aef6e22736 -r 32dc137f5e26 Lib/asyncio/base_events.py
--- a/Lib/asyncio/base_events.py	Sun Feb 09 22:22:38 2014 -0800
+++ b/Lib/asyncio/base_events.py	Mon Feb 10 11:47:50 2014 +0100
@@ -633,7 +633,13 @@
             else:
                 logger.log(level, 'poll took %.3f seconds', t1-t0)
         else:
+            t0 = self.time()
             event_list = self._selector.select(timeout)
+            dt = self.time() - t0
+            if not event_list and timeout and dt < timeout:
+                print("asyncio: selector.select(%.3f ms) took %.3f ms"
+                      % (timeout*1e3, dt*1e3),
+                      file=sys.__stderr__, flush=True)
         self._process_events(event_list)
 
         # Handle 'later' callbacks that are ready.
diff -r 28aef6e22736 -r 32dc137f5e26 Lib/test/test_asyncio/test_events.py
--- a/Lib/test/test_asyncio/test_events.py	Sun Feb 09 22:22:38 2014 -0800
+++ b/Lib/test/test_asyncio/test_events.py	Mon Feb 10 11:47:50 2014 +0100
@@ -1182,7 +1182,10 @@
         # may sleep at little bit less than timeout depending on the resolution
         # of the clock used by the kernel. Tolerate 2 useless calls on these
         # platforms.
-        self.assertLessEqual(self.loop._run_once_counter, 8)
+        self.assertLessEqual(self.loop._run_once_counter, 8,
+            {'time_info': time.get_clock_info('time'),
+             'monotonic_info': time.get_clock_info('monotonic'),
+             'selector': self.loop._selector.__class__.__name__})
 
 
 class SubprocessTestsMixin: