Originally faced here:
https://stackoverflow.com/q/46306660/1113207

Simple code to reproduce:

    import asyncio 
    import time


    async def main():
        while True:
            asyncio.ensure_future(asyncio.sleep(1))

            t0 = time.time()
            await asyncio.sleep(0.1)
            t1 = time.time()

            print(t1 - t0)
            if t1 - t0 < 0.1:
                print('bug ^')
                break


    loop = asyncio.get_event_loop()
    loop.run_until_complete(main())

I thought that it may be related to event loop's internal clock, but changing time.time() with asyncio.get_event_loop().time() doesn't help.

Tested on Windows 10 x64, Python 3.6.2.

I can't reproduce this on a linux VM with 3.7 tip.  I don't currently have a windows instance to test against.

AFAIR the Windows clock has a 15ms granularity, so I'm not really surprised. In other words, I don't think `asyncio.sleep` sleeps less than expected, but that it's the imprecision of time.time() which gives you that impression.

What happens if you replace `time.time()` with `time.perf_counter()` in the code above?

Clocks is a very complex topic, especially when you care of portability. See my PEP 418.

asyncio uses time.monotonic() clock to not be impacted when the system clock ("wall clock") is updated by the administrator or automatically by NTP.

On Windows, time.monotonic() is implemented with GetTickCount64() which has a bad resolution: around 15 ms. The exact resolution depends on the hardware.

See my PEP 418 which added time.monotonic() for Python 3.3 for much more information:
https://www.python.org/dev/peps/pep-0418/#monotonic-clocks

To get the clock resolution, use:

>>> import time; print(time.get_clock_info('monotonic'))

Example on Linux:

>>> import time; print(time.get_clock_info('monotonic'))
namespace(adjustable=False, implementation='clock_gettime(CLOCK_MONOTONIC)', monotonic=True, resolution=1e-09)

Well, the announced resolution is 1 nanosecond, but in practice it's more around 500 ns. At least, it's better than 15 ms :-)

--

asyncio rounds timings using the clock resolution, time.get_clock_info('monotonic').resolution. Search for self._clock_resolution in Lib/asyncio/base_events.py.

asyncio is not designed for real time.

STINNER Victor, thanks for explanation!

I don't know if this issue has practical disadvantages, but such behavior seems to be confusing, especially, since it can be reproduced with event_loop.time() and asyncio doc says nothing about resolution -
https://docs.python.org/3/library/asyncio-eventloop.html#delayed-calls

Do you think this issue should be closed?
Should I make PR to add info about clock's resolution to asyncio documentation?

Technically, asyncii cannot wait exactly 100 ms on Windows. It will be more
likely a sleep between 100-15 ms and 100+15 ms. Real time is really a
complex topic. CPython with its stop-the-world garbage collector are not
designed for real time.

I don't think the bug is about real time here, rather about minimal sleep time expectations; i.e. it's expected that the sleep time may be *more* than asked for, but not less than.

(and I would share that expectation myself)

> it's expected that the sleep time may be *more* than asked for, but not less than.

Exactly, and asyncio tries to ensure that.  It looks like "time.get_clock_info('monotonic').resolution" lies about monotonic clock resolution on Windows so that might be the actual issue we want to address.

IMHO we should either just close the issue, ir document the bad clock
resolution on Windows in the asyncio doc.

Yury: asyncio can trigger events earlier than scheduled for performance
reasons. See end_time in asyncio core loop.

Le 21/09/2017 à 23:31, STINNER Victor a écrit :
> 
> Yury: asyncio can trigger events earlier than scheduled for performance
> reasons.

If that's true, then it sounds like a bug.  If there is a rationale for
a "fast and imprecise" API, then it would seem ok to add such an API.
But the default API for event scheduling should not take such shortcuts
IMHO.  Most users don't schedule thousands of events at a time, however
they expect timeouts to be observed as rigorously as is possible given
the usual implementation constraints such as GC pauses.

So here's the relevant piece of code:

        end_time = self.time() + self._clock_resolution
        while self._scheduled:
            handle = self._scheduled[0]
            if handle._when >= end_time:
                break
            handle = heapq.heappop(self._scheduled)
            handle._scheduled = False
            self._ready.append(handle)


As I see it, currently we peek into the future time.  Why don't we do 

        end_time = self.time() - self._clock_resolution

to guarantee that timeouts will always be triggered *after* the requested time, not before?  I don't see how the performance can become worse if we do this.

Issues:
- bpo-20320
- bpo-20452
- bpo-20505
- bpo-20311

The performance issue was that the asyncio core loop was running in a loop
but did nothing because of time rounding. When the next event was in a few
nanoseconds, the e event burnt the CPU during <clock resolution> seconds.
It can be 15 ms on Windows or 1 ms when using poll() for example. It's not
just clock resolution, also the resolution of the selector.

Hopefully, select and selectors now round towards +inf (rather than
rounding down, towards zero or -inf) and so the selector resolution is no
more an issue if I recall correctly.

> The performance issue was that the asyncio core loop was running in a loop
but did nothing because of time rounding. When the next event was in a few
nanoseconds, the e event burnt the CPU during <clock resolution> seconds.
It can be 15 ms on Windows or 1 ms when using poll() for example. It's not
just clock resolution, also the resolution of the selector.

Hm.  I glanced through the issues you linked, and it looks like it's a valid concern for a micro-benchmark.  But I don't see how a performance of a real-world application can be affected here.  IOW, the "self.time() + self._clock_resolution" line looks like an optimization for a particular micro-benchmark.  I'm sure we can construct another micro-benchmark that would benefit from "self.time() - self._clock_resolution".

I think we should value correctness more than micro-benchmarks.

When the fine tuning options for install-directories are set, the default directories "lib", "bin" and "include" are still created with essential content. Even if options like --libdir are set.

Markus, your comment does not seem relevant to this issue. Maybe you meant to add it to a different issue, or you meant to create a new issue?