Improve traceback of cancelled tasks / add cancel() msg argument #75216
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
assignee = None closed_at = <Date 2020-05-18.05:56:13.267> created_at = <Date 2017-07-25.13:21:40.773> labels = ['type-feature', '3.9', 'expert-asyncio'] title = 'Improve traceback of cancelled tasks / add cancel() msg argument' updated_at = <Date 2020-05-19.02:14:19.517> user = 'https://github.com/socketpair'
activity = <Date 2020-05-19.02:14:19.517> actor = 'lukasz.langa' assignee = 'none' closed = True closed_date = <Date 2020-05-18.05:56:13.267> closer = 'chris.jerdonek' components = ['asyncio'] creation = <Date 2017-07-25.13:21:40.773> creator = 'socketpair' dependencies =  files =  hgrepos =  issue_num = 31033 keywords = ['patch'] message_count = 23.0 messages = ['299079', '299083', '299084', '299101', '299103', '299107', '299112', '299891', '300152', '314953', '314954', '341967', '368236', '368243', '368405', '368987', '368988', '368993', '369173', '369179', '369180', '369305', '369315'] nosy_count = 8.0 nosy_names = ['carljm', 'chris.jerdonek', 'lukasz.langa', 'socketpair', 'yselivanov', 'matrixise', 'thehesiod', 'miss-islington'] pr_nums = ['19951', '19979', '20173', '20202'] priority = 'normal' resolution = 'fixed' stage = 'resolved' status = 'closed' superseder = None type = 'enhancement' url = 'https://bugs.python.org/issue31033' versions = ['Python 3.9']
The text was updated successfully, but these errors were encountered:
First, I tried to debug code around asyncio.Task() cancelling. So I wrote:
When task was cancelled, an empty string printed. I wondered why. So I change the code to
and it printed 'CancelledError' as expected.
Next, I tried:
It prints empty string too!
So I came up to propose API change. I propose to add argument to the .cancel() methods (for Task and for Future). This argument should be passed to the CancelledError constructor. This will greatly improves debugging -- it allows to easily know why Future/Task was cancelled.
Also, this change does not break current code. Argument must be optional.
I'm not opposed to the idea, btw. If we do decide to add an argument to 'cancel', we probably should do the same for concurrent.futures.
Another possibility would be to allow cancellation via Future.set_exception:
I was thinking about this:
Although now, that I'm looking at it, I don't like this idea, because setting as exception is a different operation from cancelling a task/future, and we shouldn't mix them. It's OK to set a CancelledError without cancelling. Also this would be a backwards incompatible change.
So back to square one -- we can consider passing extra args to .cancel() methods.
A couple thoughts on this issue:
First, I think the OP's original issue could perhaps largely be addressed without having to change cancel()'s signature. Namely, simply passing a hard-coded string to CancelledError in the couple spots that CancelledError is raised would cause the exception to display:
The "raise CancelledError" could be changed to "raise CancelledError('future is cancelled')", a bit like how InvalidStateError is handled a couple lines later:
if self._state == _CANCELLED: raise CancelledError if self._state != _FINISHED: raise InvalidStateError('Result is not ready.')
Second, in terms of making cancellations easier to debug, is it a deliberate design decision that the CancelledError traceback "swallows" / doesn't show the point at which the coroutine was cancelled?
For example, running the following code--
async def run(): await asyncio.sleep(1000000) loop = asyncio.new_event_loop() task = asyncio.ensure_future(run(), loop=loop) loop.call_later(2, task.cancel) loop.run_until_complete(task)
Results in the following output:
Traceback (most recent call last): File "test-cancel.py", line 46, in <module> loop.run_until_complete(task) File "/Users/.../python3.6/asyncio/base_events.py", line 466, in run_until_complete return future.result() concurrent.futures._base.CancelledError
In particular, it doesn't show that the task was waiting on asyncio.sleep(1000000) when the task was cancelled. It would be very useful to see full tracebacks in these cases. (Sorry in advance if this second point is off-topic for this issue.)
I was about to open a new bug, but I think my idea overlaps with this one. From what I understand there are two ways to cancel tasks:
with #2 you can get a traceback by catching the exception which yields why the task was cancelled (per callstack, and you create the CancelledError with a custom message).
#1 I think is what this is talking about.
The most useful information IMHO is the callstack, and via #1 this callstack is completely lost.
I like the idea of having an argument to construct the CancelledError with, but I like even more the ability to tell the exception that will be raised to have the traceback of the point where the task was originally cancelled.
Right now I have to use forbidden fruit to override the Task.cancel method and store the callstack in a custom attribute.
I was talking with asvetlov and and he thought perhaps there could be an environment variable to enable this by default and then when the cancellation error is raised it can have the caller's callstack...I think ideally this would be the default if it could be done cheaply (given if a regular exception throw contains the callstack, then a cancellation exception should always as well.
Ideally I think when a task is cancelled it instantiates the exception with the callstack at that point, and then does something like a "with e" to raise the exception from the future so you get it when it's raised.
Why don't we make CancelledErrors having proper traceback a default behaviour?
I just posted a draft, proof-of-concept PR for one aspect of this issue: #19951
Namely, the PR makes it so that cancelled tasks have full tracebacks, all the way to where the code first gets interrupted. I did the C implementation, but I still need to do the pure Python implementation. (Note that it doesn't show where
As an example, for this code--
import asyncio async def nested(): await asyncio.sleep(1) async def run(): task = asyncio.create_task(nested()) await asyncio.sleep(0) task.cancel() await task loop = asyncio.new_event_loop() try: loop.run_until_complete(run()) finally: loop.close()
Python currently (before the PR) does this:
Traceback (most recent call last): File "/.../cpython/test-cancel.py", line 15, in <module> loop.run_until_complete(run()) File "/.../cpython/Lib/asyncio/base_events.py", line 642, in run_until_complete return future.result() asyncio.exceptions.CancelledError
With the PR, it looks like this. In particular, you can see that it includes "await asyncio.sleep(1)", as well as the intermediate await:
Traceback (most recent call last): File "/.../cpython/test-cancel.py", line 5, in nested await asyncio.sleep(1) File "/.../cpython/Lib/asyncio/tasks.py", line 657, in sleep return await future asyncio.exceptions.CancelledError During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/.../cpython/test-cancel.py", line 11, in run await task asyncio.exceptions.CancelledError During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/.../cpython/test-cancel.py", line 15, in <module> loop.run_until_complete(run()) File "/.../cpython/Lib/asyncio/base_events.py", line 642, in run_until_complete return future.result() asyncio.exceptions.CancelledError
I just want to flag one issue after rebasing my traceback PR onto what was merged. If task.cancel() is called like this--
task.cancel("POSSIBLY LONG CANCEL MESSAGE")
There is the question of whether the passed message should be repeated each time the CancelledError is raised, or only show it in the innermost, originating exception. My preference is to do the latter because it is simpler, less verbose, and seems more correct from a Python perspective. But I wanted to flag this because the message won't be visible in the leading, outermost exception.
There is a third alternative which is to mutate the exception each time (delete the message from the earlier exception and add it to the new exception). But that seems more fraught and what I'd consider surprising behavior.
Lastly, to illustrate, here is the more verbose option (the one I think it **shouldn't** look like):
Traceback (most recent call last): File "/.../cpython/test-cancel.py", line 4, in nested await asyncio.sleep(1) File "/.../cpython/Lib/asyncio/tasks.py", line 670, in sleep return await future asyncio.exceptions.CancelledError: POSSIBLY LONG CANCEL MESSAGE During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/.../cpython/test-cancel.py", line 11, in run await task asyncio.exceptions.CancelledError: POSSIBLY LONG CANCEL MESSAGE During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/.../cpython/test-cancel.py", line 15, in <module> loop.run_until_complete(run()) File "/.../cpython/Lib/asyncio/base_events.py", line 642, in run_until_complete return future.result() asyncio.exceptions.CancelledError: POSSIBLY LONG CANCEL MESSAGE