wait_for(gather(...)) logs weird error message

[tecki]

BPO	29432
Nosy	@gvanrossum, @cjerdonek, @1st1, @tecki
PRs	A few README tweaks #73

^{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 = None
created_at = <Date 2017-02-03.11:25:24.324>
labels = ['type-bug', '3.7', 'expert-asyncio']
title = 'wait_for(gather(...)) logs weird error message'
updated_at = <Date 2017-08-07.23:45:23.642>
user = 'https://github.com/tecki'

bugs.python.org fields:

activity = <Date 2017-08-07.23:45:23.642>
actor = 'chris.jerdonek'
assignee = 'none'
closed = False
closed_date = None
closer = None
components = ['asyncio']
creation = <Date 2017-02-03.11:25:24.324>
creator = 'Martin.Teichmann'
dependencies = []
files = []
hgrepos = []
issue_num = 29432
keywords = []
message_count = 4.0
messages = ['286858', '287312', '299847', '299878']
nosy_count = 4.0
nosy_names = ['gvanrossum', 'chris.jerdonek', 'yselivanov', 'Martin.Teichmann']
pr_nums = ['73']
priority = 'normal'
resolution = None
stage = None
status = 'open'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue29432'
versions = ['Python 3.4', 'Python 3.5', 'Python 3.6', 'Python 3.7']

[tecki]

when waiting for a gather that times out, everything works as expected, yet a weird error message is logged. To give a minimal example:

    import asyncio

    @asyncio.coroutine
    def main():
        try:
            sleep = asyncio.sleep(0.2)
            yield from asyncio.wait_for(asyncio.gather(sleep),
                                        timeout=0.1)
        except asyncio.TimeoutError:
            print("timed out: fine")
        yield from asyncio.sleep(0.1)

asyncio.get_event_loop().run_until_complete(main())

This outputs:

timed out: fine
_GatheringFuture exception was never retrieved
future: <_GatheringFuture finished exception=CancelledError()>
concurrent.futures._base.CancelledError

As you can see, I used the pre-3.5 syntax so I could test whether it works on older systems. No, it doesn't.

I wrote a unit test for this problem, unfortunately I couldn't solve it yet.

[tecki]

I added a solution to this problem. I just silence the bad error message by overwriting _GatheringFuture.__del__ to do nothing. This may have undesired side effects, though.

[cjerdonek]

I noticed that the future defined by asyncio.gather(sleep) is in a "pending" state immediately after the asyncio.TimeoutError.

One workaround is to wait for the cancellation to finish:

    @asyncio.coroutine
    def main():
        sleep = asyncio.sleep(0.2)
        future = asyncio.gather(sleep)
        try:
            yield from asyncio.wait_for(future, timeout=0.1)
        except asyncio.TimeoutError:
            print(f'future: {future}')
            try:
                yield from future
            except asyncio.CancelledError:
                print(f'future: {future}')
        yield from asyncio.sleep(0.1)

asyncio.get_event_loop().run_until_complete(main())

Outputs:

future: <_GatheringFuture pending>
future: <_GatheringFuture finished exception=CancelledError()>

Another option is to pass return_exceptions=True to gather(). This appears to make the log messages you were concerned about go away:

future: <_GatheringFuture pending>

[cjerdonek]

By the way, I see this exact issue was also raised and discussed here, with a couple responses by Guido, too:
python/asyncio#253

[graingert]

it looks like this was fixed in python 3.9:

 graingert@superjacent  ~/projects  python3.9 demo.py 
/home/graingert/projects/demo.py:4: DeprecationWarning: "@coroutine" decorator is deprecated since Python 3.8, use "async def" instead
  def main():
timed out: fine
 graingert@superjacent  ~/projects  python3.8 demo.py 
demo.py:4: DeprecationWarning: "@coroutine" decorator is deprecated since Python 3.8, use "async def" instead
  def main():
timed out: fine
_GatheringFuture exception was never retrieved
future: <_GatheringFuture finished exception=CancelledError()>
asyncio.exceptions.CancelledError

[graingert]

looks like it was fixed by this https://github.com/python/cpython/pull/20054/files#diff-429f4ed1e0f89ea2c92e2a8e8548ea8ae1a3d528979554fbfa4c38329e951529R503

[gvanrossum]

Happy to close it.