Skip to content

Commit e271aab

Browse files
committed
Fix timers firing up to 1ms early
libuv resamples its internal clock as the floor of the current monotonic time truncated to whole milliseconds, then schedules a timer for loop->time + timeout. Since the fractional millisecond already elapsed at the moment of sampling is discarded, the timer can fire up to ~1ms before the requested delay has actually passed. This made asyncio.sleep(n) occasionally return slightly under n, as reported in #739. Pad the timeout handed to uv_timer_start() by 1ms to compensate, while leaving the reported deadline (get_when()/TimerHandle.when()) as the originally requested value.
1 parent e8efea4 commit e271aab

2 files changed

Lines changed: 29 additions & 1 deletion

File tree

tests/test_base.py

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -220,6 +220,24 @@ def cb():
220220
finished = int(round(self.loop.time() * 1000))
221221
self.assertGreaterEqual(finished - started, 69)
222222

223+
def test_call_later_not_early(self):
224+
# Refs #739: asyncio.sleep()/call_later() must never fire before
225+
# the requested delay has actually elapsed, as measured by a
226+
# wall-clock source independent of the loop's own (millisecond-
227+
# truncated) internal clock. The underlying bug only manifests
228+
# when the loop's internal clock happens to be sampled close to
229+
# a millisecond boundary, so run enough iterations to make a
230+
# regression here reliably observable.
231+
async def main():
232+
delay = 0.01
233+
for _ in range(300):
234+
started = time.monotonic()
235+
await asyncio.sleep(delay)
236+
elapsed = time.monotonic() - started
237+
self.assertGreaterEqual(elapsed, delay)
238+
239+
self.loop.run_until_complete(main())
240+
223241
def test_call_at(self):
224242
if (os.environ.get('TRAVIS_OS_NAME')
225243
or os.environ.get('GITHUB_WORKFLOW')):

uvloop/handles/timer.pyx

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -50,9 +50,19 @@ cdef class UVTimer(UVHandle):
5050
uv.uv_update_time(self._loop.uvloop) # void
5151
self.start_t = uv.uv_now(self._loop.uvloop)
5252

53+
# libuv's internal clock (loop->time, just refreshed above) is
54+
# the current monotonic time truncated ("floored") to whole
55+
# milliseconds, discarding up to just under 1ms. uv_timer_start()
56+
# schedules the callback for loop->time + timeout, so without
57+
# compensation the timer can fire up to ~1ms sooner than
58+
# `self.timeout` milliseconds of actual wall-clock time have
59+
# elapsed. Pad the timeout given to libuv by 1ms so the timer
60+
# never fires earlier than requested; self.timeout (and thus
61+
# get_when()/TimerHandle.when()) is left untouched so it keeps
62+
# reporting the originally requested deadline.
5363
err = uv.uv_timer_start(<uv.uv_timer_t*>self._handle,
5464
__uvtimer_callback,
55-
self.timeout, 0)
65+
self.timeout + 1, 0)
5666
if err < 0:
5767
exc = convert_error(err)
5868
self._fatal_error(exc, True)

0 commit comments

Comments
 (0)