[3.11] gh-110088, gh-109878: Fix test_asyncio timeouts (#110092) (#110099)
https://github.com/python/cpython/commit/184ce1414baa7ceb6450d54783ff8e63c90... commit: 184ce1414baa7ceb6450d54783ff8e63c907a6b0 branch: 3.11 author: Victor Stinner <vstinner@python.org> committer: vstinner <vstinner@python.org> date: 2023-09-29T14:16:15+02:00 summary: [3.11] gh-110088, gh-109878: Fix test_asyncio timeouts (#110092) (#110099) gh-110088, gh-109878: Fix test_asyncio timeouts (#110092) Fix test_asyncio timeouts: don't measure the maximum duration, a test should not measure a CI performance. Only measure the minimum duration when a task has a timeout or delay. Add CLOCK_RES to test_asyncio.utils. (cherry picked from commit db0a258e796703e12befea9d6dec04e349ca2f5b) files: A Misc/NEWS.d/next/Tests/2023-09-29-12-48-42.gh-issue-110088.qUhRga.rst M Lib/test/test_asyncio/test_base_events.py M Lib/test/test_asyncio/test_events.py M Lib/test/test_asyncio/test_timeouts.py M Lib/test/test_asyncio/test_waitfor.py M Lib/test/test_asyncio/test_windows_events.py M Lib/test/test_asyncio/utils.py diff --git a/Lib/test/test_asyncio/test_base_events.py b/Lib/test/test_asyncio/test_base_events.py index 6ba602dd619fb..f3f83ad318c95 100644 --- a/Lib/test/test_asyncio/test_base_events.py +++ b/Lib/test/test_asyncio/test_base_events.py @@ -273,7 +273,7 @@ def cb(): self.loop.stop() self.loop._process_events = mock.Mock() - delay = 0.1 + delay = 0.100 when = self.loop.time() + delay self.loop.call_at(when, cb) @@ -282,10 +282,7 @@ def cb(): dt = self.loop.time() - t0 # 50 ms: maximum granularity of the event loop - self.assertGreaterEqual(dt, delay - 0.050, dt) - # tolerate a difference of +800 ms because some Python buildbots - # are really slow - self.assertLessEqual(dt, 0.9, dt) + self.assertGreaterEqual(dt, delay - test_utils.CLOCK_RES) with self.assertRaises(TypeError, msg="when cannot be None"): self.loop.call_at(None, cb) diff --git a/Lib/test/test_asyncio/test_events.py b/Lib/test/test_asyncio/test_events.py index 4e0321a87daec..daf2fb87994a8 100644 --- a/Lib/test/test_asyncio/test_events.py +++ b/Lib/test/test_asyncio/test_events.py @@ -294,10 +294,11 @@ async def coro2(): # 15.6 msec, we use fairly long sleep times here (~100 msec). def test_run_until_complete(self): + delay = 0.100 t0 = self.loop.time() - self.loop.run_until_complete(asyncio.sleep(0.1)) - t1 = self.loop.time() - self.assertTrue(0.08 <= t1-t0 <= 0.8, t1-t0) + self.loop.run_until_complete(asyncio.sleep(delay)) + dt = self.loop.time() - t0 + self.assertGreaterEqual(dt, delay - test_utils.CLOCK_RES) def test_run_until_complete_stopped(self): @@ -1695,7 +1696,6 @@ def _run_once(): self.loop._run_once = _run_once async def wait(): - loop = self.loop await asyncio.sleep(1e-2) await asyncio.sleep(1e-4) await asyncio.sleep(1e-6) diff --git a/Lib/test/test_asyncio/test_timeouts.py b/Lib/test/test_asyncio/test_timeouts.py index cc8feb8d0c1af..5a4093e94707b 100644 --- a/Lib/test/test_asyncio/test_timeouts.py +++ b/Lib/test/test_asyncio/test_timeouts.py @@ -47,7 +47,6 @@ async def test_nested_timeouts(self): self.assertTrue(cm2.expired()) async def test_waiter_cancelled(self): - loop = asyncio.get_running_loop() cancelled = False with self.assertRaises(TimeoutError): async with asyncio.timeout(0.01): @@ -60,39 +59,26 @@ async def test_waiter_cancelled(self): async def test_timeout_not_called(self): loop = asyncio.get_running_loop() - t0 = loop.time() async with asyncio.timeout(10) as cm: await asyncio.sleep(0.01) t1 = loop.time() self.assertFalse(cm.expired()) - # 2 sec for slow CI boxes - self.assertLess(t1-t0, 2) self.assertGreater(cm.when(), t1) async def test_timeout_disabled(self): - loop = asyncio.get_running_loop() - t0 = loop.time() async with asyncio.timeout(None) as cm: await asyncio.sleep(0.01) - t1 = loop.time() self.assertFalse(cm.expired()) self.assertIsNone(cm.when()) - # 2 sec for slow CI boxes - self.assertLess(t1-t0, 2) async def test_timeout_at_disabled(self): - loop = asyncio.get_running_loop() - t0 = loop.time() async with asyncio.timeout_at(None) as cm: await asyncio.sleep(0.01) - t1 = loop.time() self.assertFalse(cm.expired()) self.assertIsNone(cm.when()) - # 2 sec for slow CI boxes - self.assertLess(t1-t0, 2) async def test_timeout_zero(self): loop = asyncio.get_running_loop() @@ -102,8 +88,6 @@ async def test_timeout_zero(self): await asyncio.sleep(10) t1 = loop.time() self.assertTrue(cm.expired()) - # 2 sec for slow CI boxes - self.assertLess(t1-t0, 2) self.assertTrue(t0 <= cm.when() <= t1) async def test_timeout_zero_sleep_zero(self): @@ -114,8 +98,6 @@ async def test_timeout_zero_sleep_zero(self): await asyncio.sleep(0) t1 = loop.time() self.assertTrue(cm.expired()) - # 2 sec for slow CI boxes - self.assertLess(t1-t0, 2) self.assertTrue(t0 <= cm.when() <= t1) async def test_timeout_in_the_past_sleep_zero(self): @@ -126,8 +108,6 @@ async def test_timeout_in_the_past_sleep_zero(self): await asyncio.sleep(0) t1 = loop.time() self.assertTrue(cm.expired()) - # 2 sec for slow CI boxes - self.assertLess(t1-t0, 2) self.assertTrue(t0 >= cm.when() <= t1) async def test_foreign_exception_passed(self): diff --git a/Lib/test/test_asyncio/test_waitfor.py b/Lib/test/test_asyncio/test_waitfor.py index 07dbab3b39ca2..c0cc606825b5e 100644 --- a/Lib/test/test_asyncio/test_waitfor.py +++ b/Lib/test/test_asyncio/test_waitfor.py @@ -66,17 +66,12 @@ async def test_wait_for_timeout_less_then_0_or_0_future_done(self): fut = loop.create_future() fut.set_result('done') - t0 = loop.time() ret = await asyncio.wait_for(fut, 0) - t1 = loop.time() self.assertEqual(ret, 'done') self.assertTrue(fut.done()) - self.assertLess(t1 - t0, 0.1) async def test_wait_for_timeout_less_then_0_or_0_coroutine_do_not_started(self): - loop = asyncio.get_running_loop() - foo_started = False async def foo(): @@ -84,12 +79,9 @@ async def foo(): foo_started = True with self.assertRaises(asyncio.TimeoutError): - t0 = loop.time() await asyncio.wait_for(foo(), 0) - t1 = loop.time() self.assertEqual(foo_started, False) - self.assertLess(t1 - t0, 0.1) async def test_wait_for_timeout_less_then_0_or_0(self): loop = asyncio.get_running_loop() @@ -113,18 +105,14 @@ async def foo(): await started with self.assertRaises(asyncio.TimeoutError): - t0 = loop.time() await asyncio.wait_for(fut, timeout) - t1 = loop.time() self.assertTrue(fut.done()) # it should have been cancelled due to the timeout self.assertTrue(fut.cancelled()) self.assertEqual(foo_running, False) - self.assertLess(t1 - t0, 0.1) async def test_wait_for(self): - loop = asyncio.get_running_loop() foo_running = None async def foo(): @@ -139,13 +127,10 @@ async def foo(): fut = asyncio.create_task(foo()) with self.assertRaises(asyncio.TimeoutError): - t0 = loop.time() await asyncio.wait_for(fut, 0.1) - t1 = loop.time() self.assertTrue(fut.done()) # it should have been cancelled due to the timeout self.assertTrue(fut.cancelled()) - self.assertLess(t1 - t0, support.SHORT_TIMEOUT) self.assertEqual(foo_running, False) async def test_wait_for_blocking(self): diff --git a/Lib/test/test_asyncio/test_windows_events.py b/Lib/test/test_asyncio/test_windows_events.py index a36119a8004f9..6e6c90a247b29 100644 --- a/Lib/test/test_asyncio/test_windows_events.py +++ b/Lib/test/test_asyncio/test_windows_events.py @@ -163,29 +163,25 @@ def test_wait_for_handle(self): # Wait for unset event with 0.5s timeout; # result should be False at timeout - fut = self.loop._proactor.wait_for_handle(event, 0.5) + timeout = 0.5 + fut = self.loop._proactor.wait_for_handle(event, timeout) start = self.loop.time() done = self.loop.run_until_complete(fut) elapsed = self.loop.time() - start self.assertEqual(done, False) self.assertFalse(fut.result()) - # bpo-31008: Tolerate only 450 ms (at least 500 ms expected), - # because of bad clock resolution on Windows - self.assertTrue(0.45 <= elapsed <= 0.9, elapsed) + self.assertGreaterEqual(elapsed, timeout - test_utils.CLOCK_RES) _overlapped.SetEvent(event) # Wait for set event; # result should be True immediately fut = self.loop._proactor.wait_for_handle(event, 10) - start = self.loop.time() done = self.loop.run_until_complete(fut) - elapsed = self.loop.time() - start self.assertEqual(done, True) self.assertTrue(fut.result()) - self.assertTrue(0 <= elapsed < 0.3, elapsed) # asyncio issue #195: cancelling a done _WaitHandleFuture # must not crash @@ -199,11 +195,8 @@ def test_wait_for_handle_cancel(self): # CancelledError should be raised immediately fut = self.loop._proactor.wait_for_handle(event, 10) fut.cancel() - start = self.loop.time() with self.assertRaises(asyncio.CancelledError): self.loop.run_until_complete(fut) - elapsed = self.loop.time() - start - self.assertTrue(0 <= elapsed < 0.1, elapsed) # asyncio issue #195: cancelling a _WaitHandleFuture twice # must not crash diff --git a/Lib/test/test_asyncio/utils.py b/Lib/test/test_asyncio/utils.py index c32494d40ccea..19de8540fdb54 100644 --- a/Lib/test/test_asyncio/utils.py +++ b/Lib/test/test_asyncio/utils.py @@ -37,6 +37,12 @@ from test.support import threading_helper +# Use the maximum known clock resolution (gh-75191, gh-110088): Windows +# GetTickCount64() has a resolution of 15.6 ms. Use 20 ms to tolerate rounding +# issues. +CLOCK_RES = 0.020 + + def data_file(filename): if hasattr(support, 'TEST_HOME_DIR'): fullname = os.path.join(support.TEST_HOME_DIR, filename) diff --git a/Misc/NEWS.d/next/Tests/2023-09-29-12-48-42.gh-issue-110088.qUhRga.rst b/Misc/NEWS.d/next/Tests/2023-09-29-12-48-42.gh-issue-110088.qUhRga.rst new file mode 100644 index 0000000000000..cf44a123c2c92 --- /dev/null +++ b/Misc/NEWS.d/next/Tests/2023-09-29-12-48-42.gh-issue-110088.qUhRga.rst @@ -0,0 +1,4 @@ +Fix test_asyncio timeouts: don't measure the maximum duration, a test should +not measure a CI performance. Only measure the minimum duration when a task has +a timeout or delay. Add ``CLOCK_RES`` to ``test_asyncio.utils``. Patch by +Victor Stinner.
participants (1)
-
vstinner