"Task exception was never retrieved" reported for a canceled task

[MiguelGrinberg]

BPO	30508
Nosy	@ned-deily, @1st1
PRs	bpo-30508: Don't log exceptions if Task/Future "cancel()" method called #2050 [3.6] bpo-30508: Don't log exceptions if Task/Future "cancel()" method was called #2109 [3.5] bpo-30508: Don't log exceptions if Task/Future "cancel()" method was called #2110
Files	never-retrieved.py

^{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 2017-06-11.14:12:51.714>
created_at = <Date 2017-05-30.02:14:06.380>
labels = ['type-bug', '3.7', 'expert-asyncio']
title = '"Task exception was never retrieved" reported for a canceled task'
updated_at = <Date 2017-06-11.15:42:01.895>
user = 'https://bugs.python.org/MiguelGrinberg'

bugs.python.org fields:

activity = <Date 2017-06-11.15:42:01.895>
actor = 'ned.deily'
assignee = 'none'
closed = True
closed_date = <Date 2017-06-11.14:12:51.714>
closer = 'yselivanov'
components = ['asyncio']
creation = <Date 2017-05-30.02:14:06.380>
creator = 'Miguel Grinberg'
dependencies = []
files = ['46911']
hgrepos = []
issue_num = 30508
keywords = []
message_count = 7.0
messages = ['294732', '294733', '295708', '295709', '295711', '295712', '295721']
nosy_count = 3.0
nosy_names = ['ned.deily', 'yselivanov', 'Miguel Grinberg']
pr_nums = ['2050', '2109', '2110']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue30508'
versions = ['Python 3.5', 'Python 3.6', 'Python 3.7']

[MiguelGrinberg]

I am seeing a strange issue that occurs when a task that is awaiting an asyncio.wait_for() is cancelled. I created a simple example that I think demonstrates the issue, even though it isn't exactly how it manifests on my application.

When I run the attached script never-retrieved.py I get the following error:

Task exception was never retrieved
future: <Task finished coro=<crash() done, defined at never-retrieved.py:4> exception=ZeroDivisionError('division by zero',)>
Traceback (most recent call last):
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "never-retrieved.py", line 5, in crash
    a = 1/0
ZeroDivisionError: division by zero

You can see in the script that the future was cancelled, but the cancel() call was made after the task finished in a zero division error. I think the cancel() call should update the internal state of the future so that the "exception was never retrieved" error does not appear.

My application has a more complex setup that I have been unable to reproduce with a simple example. I have a task that is waiting on asyncio.wait_for(fut, timeout), with fut subsequently waiting on a websocket server's receive function. When the websocket client closes the connection, a bunch of cancellations happen, but this future inside the wait_for call crashes before wait_for gets to call cancel() on it. Even though I need to investigate this crash, the fact is that wait_for did cancel this future, but because it already ended in an error the "never retried" error is reported anyway.

[1st1]

Yes, this is a known problem to me, thank you for creating the issue. Will work on a fix soon.

[1st1]

New changeset 7ce1c6f by Yury Selivanov in branch 'master':
bpo-30508: Don't log exceptions if Task/Future "cancel()" method called (bpo-2050)
7ce1c6f

[1st1]

New changeset 176f2eb by Yury Selivanov in branch '3.6':
bpo-30508: Don't log exceptions if Task/Future "cancel()" method was called. (bpo-2109)
176f2eb

[1st1]

New changeset d24c828 by Yury Selivanov in branch '3.5':
bpo-30508: Don't log exceptions if Task/Future "cancel()" method was called. (bpo-2110)
d24c828

[1st1]

Fixed. Ned, this will be included in 3.6.2, right?

[ned-deily]

Yury, yes (3.6.2 cutoff is about 24 hours from now)