Uh oh!
There was an error while loading.Please reload this page.
- Notifications
You must be signed in to change notification settings - Fork34.2k
Description
Recently, I modified asyncio tests to add a CLOCK_RES constant. Example of test_time_and_call_at() change:
+CLOCK_RES = 0.020(...)- self.assertGreaterEqual(dt, delay - 0.050, dt)+ self.assertGreaterEqual(dt, delay - test_utils.CLOCK_RES)So the test now tolerates only 20 ms difference instead of 50 ms. Problem, the test failed on GHA Windows x64 CI :-(
asyncio usestime.monotonic() asloop.time(). test.pythoninfo reports a clock resolution of 15.6 ms.
call_at() creates a TimerHandle ._run_once() usesself._scheduled[0]._when - self.time() timeout to callself._selector.select(timeout). asyncio usesself._clock_resolution = time.get_clock_info('monotonic').resolution to decide in_run_once() if an event should be scheduled or not.
# Handle 'later' callbacks that are ready.end_time=self.time()+self._clock_resolutionwhileself._scheduled:handle=self._scheduled[0]ifhandle._when>=end_time:break
Maybe there is a rounding issue and sometimes a callback scheduled in 100 ms is actually run in 78 ms.
A timeout of 100 ms should wait 6 or 7 monotonic clock ticks, whereas 78 ms is around 5 clock ticks:
>>>k=0.015625>>>0.07799999999997453/k4.99199999999837>>>0.100/k6.4
The test reads the clock twice, maybet0 is 1 tick ahead ofwhen:
when = self.loop.time() + delay self.loop.call_at(when, cb) t0 = self.loop.time()It seems like the callback was called 2 ticks before the expected timeout when taking rounding issue in account:
>>> (0.100//k-1)*k, (0.100//k+1)*k(0.078125, 0.109375)The callback should be called between 78.1 ms (2 clicks before) and 109.4 ms (1 click after). It would be nice to only have an error of a maximum of 1 click:
>>> (0.100//k)*k, (0.100//k+1)*k(0.09375, 0.109375)Between 93.8 ms (1 click before) and 109.4 ms (1 click after).
I'm not sure what's going on.
GHA Windows x64:
FAIL: test_time_and_call_at (test.test_asyncio.test_base_events.BaseEventLoopTests.test_time_and_call_at)----------------------------------------------------------------------Traceback (most recent call last): File "D:\a\cpython\cpython\Lib\test\test_asyncio\test_base_events.py", line 285, in test_time_and_call_at self.assertGreaterEqual(dt, delay - test_utils.CLOCK_RES)AssertionError: 0.07799999999997453 not greater than or equal to 0.08test.pythoninfo:
time.altzone: -3600time.daylight: 0time.get_clock_info(monotonic): namespace(implementation='GetTickCount64()', monotonic=True, adjustable=False, resolution=0.015625)time.get_clock_info(perf_counter): namespace(implementation='QueryPerformanceCounter()', monotonic=True, adjustable=False, resolution=1e-07)time.get_clock_info(process_time): namespace(implementation='GetProcessTimes()', monotonic=True, adjustable=False, resolution=1e-07)time.get_clock_info(thread_time): namespace(implementation='GetThreadTimes()', monotonic=True, adjustable=False, resolution=1e-07)time.get_clock_info(time): namespace(implementation='GetSystemTimeAsFileTime()', monotonic=False, adjustable=True, resolution=0.015625)time.time: 1696993710.9453082time.timezone: 0time.tzname: ('Coordinated Universal Time', 'Coordinated Universal Time')build:https://github.com/python/cpython/actions/runs/6477453109/job/17587684818?pr=110677
Linked PRs
Metadata
Metadata
Assignees
Projects
Status