Repository navigation
epoll.poll(timeout) and PollSelector.select(timeout) must round the timeout to the upper bound #64510
Description
| BPO | 20311 |
|---|---|
| Nosy | @gvanrossum, @birkenfeld, @pitrou, @vstinner, @ericsnowcurrently |
| Files |
Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.
Show more details
GitHub fields:
assignee = None
closed_at = <Date 2014-02-02.20:24:02.306>
created_at = <Date 2014-01-20.10:33:28.464>
labels = []
title = 'epoll.poll(timeout) and PollSelector.select(timeout) must round the timeout to the upper bound'
updated_at = <Date 2014-02-10.21:04:38.598>
user = 'https://github.com/vstinner'bugs.python.org fields:
activity = <Date 2014-02-10.21:04:38.598>
actor = 'python-dev'
assignee = 'none'
closed = True
closed_date = <Date 2014-02-02.20:24:02.306>
closer = 'vstinner'
components = []
creation = <Date 2014-01-20.10:33:28.464>
creator = 'vstinner'
dependencies = []
files = ['33563', '33564', '33680']
hgrepos = []
issue_num = 20311
keywords = ['patch']
message_count = 54.0
messages = ['208532', '208533', '208534', '208539', '208540', '208588', '208595', '208596', '208597', '208599', '208601', '208602', '208696', '208927', '208928', '208976', '209001', '209005', '209006', '209008', '209015', '209016', '209019', '209021', '209039', '209040', '209056', '209164', '209197', '209198', '209199', '209201', '209213', '209238', '209245', '209247', '209248', '209249', '209250', '209251', '209252', '209253', '209286', '209340', '209774', '210008', '210023', '210024', '210029', '210034', '210042', '210058', '210060', '210865']
nosy_count = 7.0
nosy_names = ['gvanrossum', 'georg.brandl', 'pitrou', 'vstinner', 'neologix', 'python-dev', 'eric.snow']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = None
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue20311'
versions = ['Python 3.3', 'Python 3.4']
Activity
vstinner commentedon Jan 20, 2014
Hi, while comparing performances of Tulip and Trollius projects (asyncio module), I found a bug. The event loop is called too many times when a callback is scheduled with a timeout and the epoll selector is used, especially for timeout close to one millisecond.
In my opinion, it's a bug in epoll.poll(): it should wait *at least* timeout seconds if no event is received, not shorter.
Pseudo-code of Tulip:
---
The problem is that "scheduled[0].when > time.monotonic()" test fails because epoll.poll() returns in less than timeout seconds.
The difference between the timeout and elapsed time is very small, less than 1 millisecond.
Attached patch fixes this issue by rounding the timeout to the upper bound.
The rounding is different than datetime.timedelta constructor for example, because the usecase is different. epoll.poll(0.0001) calls epoll_wait() with a timemout of 1 millisecond (1e-4 rounded to 1e-3).
epoll.poll(0.0) still calls epoll_wait() with a timeout of 0 millisecond. I don't think that it's possible to write a reliable unit test for that on our slow buildbots.
vstinner commentedon Jan 20, 2014
Bug report in Tulip project, the bug affects also the new asyncio module of Python 3.4:
http://code.google.com/p/tulip/issues/detail?id=106
pitrou commentedon Jan 20, 2014
Looks good to me on the principle.
neologix commentedon Jan 20, 2014
AFAICT, this also affects poll().
Although it's supposed to be passed an integer, passing a float will result
in a truncation towards 0:
"""
$ strace -e poll python -c "import select; p = select.poll(); p.poll(0.9)"
poll(0x23321b0, 0, 0) = 0 (Timeout)
"""
See also this line in PollSelector:
"""
def select(self, timeout=None):
timeout = None if timeout is None else max(int(1000 * timeout),
0)
"""
This will round timeout=1e-4 to 0.
vstinner commentedon Jan 20, 2014
select.select(), selectors.PollSelector.select(), select.epoll.poll(), select.kqueue.control() have the bug.
OS multiplexers:
_PyTime_ObjectToTimeval() is used in various places:
_PyTime_ObjectToTimespec() is used in various places:
A new parameter should be added to _PyTime_ObjectToTimeval() and _PyTime_ObjectToTimespec() to choose the rounding method.
--
I saw the bug with poll and epoll because these functions have the worst resolution (millisecond). Attached patch fixes poll and epoll, and add a generic test on all selectors: select_round_timeout.patch.
According to my test, select.select() has an effective resolution of 0.1 ms (10^4) on my Fedora 19 (Linux kernel 3.12), so I don't think that the select rounding issue is important. Tell me if you consider that _PyTime_ObjectToTime*() (select, kqueue) should be fixed. If yes, I will open a separated issue (because the implementation is different and it may impact other unrelated functions).
[-]epoll.poll(timeout) must round the timeout to the upper bound[/-][+]epoll.poll(timeout) and PollSelector.select(timeout) must round the timeout to the upper bound[/+]pitrou commentedon Jan 20, 2014
That doesn't sound necessary. Just fix the select and selectors module so that the final (OS-level) timeout is always > 0 when the user timeout is > 0.
python-dev commentedon Jan 21, 2014
New changeset 033137c12d88 by Victor Stinner in branch '3.3':
Issue bpo-20311: select.epoll.poll() now rounds the timeout away from zero,
http://hg.python.org/cpython/rev/033137c12d88
New changeset 02f9db3e684e by Victor Stinner in branch 'default':
(Merge 3.3) Issue bpo-20311: select.epoll.poll() now rounds the timeout away from
http://hg.python.org/cpython/rev/02f9db3e684e
python-dev commentedon Jan 21, 2014
New changeset e042ea77a152 by Victor Stinner in branch 'default':
Issue bpo-20311: selector.PollSelector.select() now rounds the timeout away from
http://hg.python.org/cpython/rev/e042ea77a152
vstinner commentedon Jan 21, 2014
Rounding issues with poll() and epoll() have been fixed in Python 3.3 and 3.4. I'm now waiting for buildbots before closing the issue.
I created a new issue bpo-20320 to address the rounding issue with select() and kqueue (and signal.sigtimedwait).
vstinner commentedon Jan 21, 2014
The epoll test failed on a buildbot. The test uses a short delay (10 milliseconds) and compare two different clocks: time.perf_counter() and select.epoll.poll(). I didn't expect a failure very the greatest delay, the test uses even shorter delay (the shortest is 0.1 ms).
The best would be to trace syscalls to check if epoll_wait() is called with a non-zero timeout, but tracing syscalls is overkill and too low level for such test.
It's maybe better to drop this unstable test? Unstable on our slow buildbots.
http://buildbot.python.org/all/builders/x86%20Gentoo%20Non-Debug%203.3/builds/1392/steps/test/logs/stdio
======================================================================
FAIL: test_timeout_rounding (test.test_epoll.TestEPoll)
----------------------------------------------------------------------
vstinner commentedon Jan 21, 2014
Another failure:
http://buildbot.python.org/all/builders/x86%20Ubuntu%20Shared%203.3/builds/1360/steps/test/logs/stdio
======================================================================
FAIL: test_timeout_rounding (test.test_epoll.TestEPoll)
----------------------------------------------------------------------
python-dev commentedon Jan 21, 2014
New changeset e1619465c49d by Victor Stinner in branch '3.3':
Issue bpo-20311: Try to fix the unit test, use time.monotonic() instead of
http://hg.python.org/cpython/rev/e1619465c49d
New changeset 26c54e9a933b by Victor Stinner in branch 'default':
(Merge 3.3) Issue bpo-20311: Try to fix the unit test, use time.monotonic()
http://hg.python.org/cpython/rev/26c54e9a933b
python-dev commentedon Jan 21, 2014
New changeset 7ce7295393c2 by Victor Stinner in branch 'default':
Issue bpo-20311: EpollSelector now also rounds the timeout towards zero, as
http://hg.python.org/cpython/rev/7ce7295393c2
vstinner commentedon Jan 23, 2014
http://buildbot.python.org/all/builders/x86%20Ubuntu%20Shared%203.x/builds/9552
======================================================================
FAIL: test_timeout_rounding (test.test_epoll.TestEPoll)
----------------------------------------------------------------------
27 remaining items
vstinner commentedon Jan 25, 2014
Oh, I didn't watch buildbots, sorry. It should be fixed by f453443c96e4.
My first attempt used an attribute using a default value of None, but
it was harder to use: I had to check if the value is None or not. I
prefer to enforce an implementation to define the resolution. Or do
you know a selector which has no resolution?
neologix commentedon Jan 26, 2014
Still, you fail to provide an example: you will only perform another call
if you pass a tilmeout really close to an exact multiple of the
granularity, *and* the syscall returns early.
Just perform a test on your machine, you'll see that early wakeups are
*really* rare.
And even if that's the case, I argue that performing an extra loop isn't a
problem: for example, noone ever complained about the way timpeouts are
rounded in the select module.
If you think otherwise, please back your claim by an example.
Don't apply it to 3.3 then.
I disagree with the introduction of a granularity to selectors.
If you really want to keep the change in asyncio, just introduce a fixed
"slack" value, e.g. 1e-3 seconds.
gvanrossum commentedon Jan 26, 2014
AFAICT the changes to selectmodule.c have been rolled back, both in the 3.3 and the 3.4 (default) branches. That takes care of backwards compatibility. :-)
So what we're talking about is whether (a) the selectors module (new in 3.3) should export a resolution property and what asyncio should do.
The selectors module in the repo does export a resolution property. It is 1 usec for select, 1msec for poll and epoll, and 1 nsec for kqueue. AFAIK these values are derived from the data type and scale used by the corresponding syscall.
The latest code in the asyncio module uses that resolution for exactly one purpose: if, after waking up from a selector.select() call, any events we are waiting for are less than the resolution in the future, we consider them ready.
I like this approach -- it trusts the syscall to do approximately the right thing most of the time, but it doesn't fall into the busy-wait trap. This trap is especially egregious for [e]poll, where the timing resolution is limited to 1 msec due to the syscall interface.
To explain the trap once more: suppose you have an event scheduled 0.9 msec in the future. Because of the 1 msec resolution of the [e]poll syscall API, the syscall is made with an argument of 0, which means it returns (almost) immediately. Given a fast CPU and no other IO ready, this might well take only a few usec. So the event loop does essentially nothing and then comes back to the poll call. The same event is now e.g. 0.89 msec in the future. So we call [e]poll with a timeout of 0 again, and we keep going around without ever releasing the CPU for the full 0.9 msec -- which nowadays is serious time in which a lot of other, more useful things could be accomplished by other threads or processes.
I think what's currently in the repo is all a fine solution to all that. Because the resolution is specified on a per-selector-class basis, we compensate appropriately for [e]poll but don't apply such a coarse granularity to the other syscalls, which are (potentially) more accurate.
If in the future we find that on some systems the kernel systematically rounds the timeout down using some coarser clock resolution we can add a system-specific compensation to the selectors module, and asyncio itself doesn't have to worry about it. (Though I personally don't expect we'll find this behavior.)
One final comment: IIUC the earlier fix involved using ceil() and other cleverness was essentially trying to predict *when* the next tick would wake us up, assuming that if the resolution is R, the kernel would wake us up at times that are integral multiples of R since the clock epoch. I don't think we can assume this at all, so I'm glad Victor rolled that back. :-)
python-dev commentedon Jan 31, 2014
New changeset f9a09b40bc17 by Victor Stinner in branch 'default':
Issue bpo-20311, bpo-20452: poll and epoll now round the timeout away from zero,
http://hg.python.org/cpython/rev/f9a09b40bc17
vstinner commentedon Feb 2, 2014
Buildbots are happy, I close the issue.
neologix commentedon Feb 2, 2014
Well, now that timeouts are properly rounded, the granularity is useless.
vstinner commentedon Feb 2, 2014
I don't think so. Please read again the issue bpo-20452, for example this message:
http://bugs.python.org/issue20452#msg209772
neologix commentedon Feb 2, 2014
"""
Ok, it looks better: waiting 99.9 ms took 99.6 ms and 99.9 ms, and waiting
9.9 ms took 9.7 ms. So as I said, the granularity (of 1 ms) is still needed
in asyncio (dt < timeout is sometimes False, but dt+granulary >= timeout is
always True).
"""
Sorry, I still fail to see how waking up after 99.6ms instead of 99.9ms is
an issue: I've asked you several times to provide an actual example of a
problem, and you still haven't.
Once again: a slight early wakeup isn't an issue, you'll just call
epoll()/select() once again.
All even loops work this way, and noone ever complained.
vstinner commentedon Feb 2, 2014
That's your opinion, but I disagree.
Please open a new issue with a patch, or reopen at least this issue because it is now closed.
I already spent to much time on this issue. Buildbots are now happy, I don't want to change this again.
neologix commentedon Feb 2, 2014
So, to sum up:
Fine, keep it this way, but I'm done with this, I've lost enough time.
vstinner commentedon Feb 3, 2014
My goal is to ensure that each call to asyncio.BaseEventLoop._run_once() executes at least an handle. It is now described as a unit test in Lib/test/test_asyncio/test_events.py: test_timeout_rounding(). There is one exception: I don't care if the selector was interrupted by a signal. (As I wrote, it's not interesting to loop on the selector, it's fine to re-execute the whole _run_once() method.)
If I understood correctly your opinion, you don't want to reach this exact goal, and you would prefer to keep the code simpler. So you don't care if sometimes _run_once() exit without executing any task. Did I understand correctly your opinion?
But I don't understand if you would prefer to revert all my changes, or keep the rounding away from zero in selectors?
gvanrossum commentedon Feb 3, 2014
neologix, you are getting dangerously close to attacking the person instead of the issue. Can you live with the current state of the code? If so, let us know (or be silent if you prefer). If you cannot live with it, please show example code that fails or is inefficient with the current version.
python-dev commentedon Feb 10, 2014
New changeset d393df09e139 by Georg Brandl in branch '3.3':
bpo-20311: revert changes to 3.3 branch for now until experts have decided how to resolve the issue.
http://hg.python.org/cpython/rev/d393df09e139