You can log CancelledError exceptions within the task that is canceled or in the caller that requested that the task be canceled.
Logging the CancelledError exception provides help when debugging an asyncio program later, confirming that tasks were canceled. By logging the CancelledError exception at the point of cancellation, the log will also include details of the task or coroutine that requested the target cancel in the message if needed, and in the stack trace.
In this tutorial, you will discover how to log CancelledError exceptions in asyncio programs.
Let’s get started.
What is a CancelledError Exception
A CancelledError exception is raised in an asyncio task when it is canceled.
When a task is cancelled, asyncio.CancelledError will be raised in the task at the next opportunity.
— Coroutines and Tasks
Recall that an asyncio task can be called via the cancel() method.
This requests that the task be canceled and causes a CancelledError exception to be raised in the task the next time it resumes executing.
You can learn more about how to cancel a task in the tutorial:
Run loops using all CPUs, download your FREE book to learn how.
Log CancelledError Exceptions
It can be a good practice to log task cancellations.
Logging CancelledError exceptions in an asyncio program can be a good idea for several reasons, such as:
- Debugging and Diagnostics: When a task is canceled, it’s often useful to know why it was canceled. Logging CancelledError exceptions allows you to capture information about the cancellation, such as which part of your code initiated it or under what conditions it occurred. This information can be invaluable for debugging and diagnosing issues in your asyncio application.
- Traceability: In a complex asyncio application with multiple tasks and asynchronous operations, tracking down the source of a cancellation can be challenging. Logging CancelledError exceptions with contextual information can help you trace back the sequence of events leading to the cancellation, making it easier to understand the flow of your program.
- Auditing and Monitoring: In production environments, logging canceled tasks can be part of auditing and monitoring efforts. It provides insights into how often tasks are being canceled and whether cancellations are occurring due to unexpected conditions. Monitoring canceled tasks can help you detect and address issues that impact the stability and performance of your application.
- Documentation and Insights: Keeping a log of CancelledError exceptions can serve as documentation for your codebase. It provides insights into the design decisions and asynchronous flow of your program, which can be helpful for both current and future developers working on the project.
- Alerts and Notifications: In some cases, you might want to set up alerts or notifications when certain tasks are canceled. For example, if a critical task is canceled unexpectedly, it could indicate a problem that requires immediate attention. Logging cancellations can be a trigger for such alerts.
While logging CancelledError exceptions can provide valuable insights, it’s essential to strike a balance.
Excessive logging of cancellations can clutter logs and make it challenging to distinguish critical information from routine cancellations.
Therefore, it’s important to log cancellations judiciously and consider log-level settings to control the verbosity of cancellation-related logs.
Log The Source of Cancellation
Not knowing why a task was canceled is perhaps one of the biggest complaints about task cancellation in asyncio programs.
The main reason to log CancelledError is so that the logs capture what task was canceled when and which task requested the cancellation.
Logging the trace of the CancelledError exception ensures that the source of the cancellation is captured and recorded.
This means that when logging CancelledError exceptions, we must ensure that we also log the stack trace of the exception.
We can achieve this by logging messages within a try-except block and using the logging.exception() function. In these conditions, the logging infrastructure will automatically log the trace of the exception.
Exception info is added to the logging message. This function should only be called from an exception handler.
— logging — Logging facility for Python
Also, if possible, the CancelledError exception should be logged at the point where it is handled, e.g. suppressed. Most commonly, this is the point at which the request was made to cancel the task. This ensures that the trace includes information about the source of the cancellation, e.g. module/file and line number information.
Next, let’s look at how exactly we can log CancelledError exceptions.
Free Python Asyncio Course
Download your FREE Asyncio PDF cheat sheet and get BONUS access to my free 7-day crash course on the Asyncio API.
Discover how to use the Python asyncio module including how to define, create, and run new coroutines and how to use non-blocking I/O.
How to Log CancelledError Exceptions
There are two ways that we might log CancelledError exceptions in our asyncio programs, they are:
- Log CancelledError within the task.
- Log CancelledError within the caller.
Log CancelledError in Task
We can log CancelledError exceptions in the task that was canceled.
This can be achieved by wrapping the body of the task in a try-except structure.
We can handle the raised CancelledError, log it using logging.exception() to ensure the trace of the exception is also logged automatically, then re-raise.
For example:
|
1 2 3 4 5 6 7 8 9 |
async def work(): try: # body of the task ... except asyncio.CancelledError: # log the cancellation logging.exception(f'Task was cancelled, details: {asyncio.current_task()}') # re-raise the exception raise |
It is important to re-raise the CancelledError exception so that the task is canceled correctly and that the contract with the cancel() method is kept (e.g. the task does not consume the CancelledError exception).
You can learn more about tasks consuming CancelledError exceptions in the tutorial:
Log CancelledError in Caller
It is common to suppress the CancelledError exception at the point where the request to cancel the task was made.
If the task is suppressed using a try-except block, then we can choose to log the CancelledError exception at this point.
This can be achieved using a cancel-and-wait pattern that involves first requesting that the task be canceled and awaiting the task so that the expected CancelledError is raised and handled.
In the except block, we can then log a message using logging.exception() to ensure that the trace of the exception is logged automatically.
For example:
|
1 2 3 4 5 6 7 8 |
... # cancel the task task.cancel() try: # wait for the task to cancel await task except asyncio.CancelledError: logging.exception(f'Confirmed that task {task} was cancelled.') |
This is the preferred way to log CancelledError exceptions as the stack trace will include information about the source of the cancellation request.
You can learn more about the cancel-and-wait pattern in the tutorial:
You can learn more about suppressing the CancelledError exception at the point of requested cancellation in the tutorial:
Now that we know how to log CancelledError exceptions, let’s look at some worked examples.
Overwhelmed by the python concurrency APIs?
Find relief, download my FREE Python Concurrency Mind Maps
Example of Logging CancelledError In Task
We can explore an example of logging the CancelledError exception from within the task.
In this example, we will define a task that does some work. The task handles the CancelledError exception and logs it before re-raising it. The main coroutine creates the task, lets it run for a moment, then cancels it.
This will log the CancelledError exception with stack trace information, but will not capture the cause of the cancellation.
Firstly, we can define the task.
The task logs a start message, sleeps for one second, then logs a done message.
The body of the task is wrapped in a try-except block and handles the CancelledError exception. The exception is logged with details of the task and re-raised.
The work() coroutine below implements this.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 |
# task that does work and logs async def work(): try: # log a message logging.info(f'Task is starting') # simulate doing work await asyncio.sleep(1) # log a message logging.info(f'Task is done') except asyncio.CancelledError: # log the cancellation logging.exception(f'Task was cancelled, details: {asyncio.current_task()}') # re-raise the exception raise |
Next, we can define the main coroutine.
It starts by logging a start message. It then creates and schedules a task for the work() coroutine and suspends with a sleep for half a second, allowing the task to run.
The main coroutine then cancels the task and awaits the cancellation, ignoring the raised CancelledError exception before logging a final message.
The main() coroutine below implements this.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 |
# main coroutine async def main(): # log a message logging.info(f'Main is starting') # schedule a task task = asyncio.create_task(work()) # wait around await asyncio.sleep(0.5) # cancel the task task.cancel() try: # wait for the task to cancel await task except asyncio.CancelledError: pass # log a message logging.info(f'Main is done') |
Finally, we can configure the logging infrastructure to log all messages at a DEBUG level and higher, then start the event loop.
|
1 2 3 4 5 |
... # prepare the logger logging.basicConfig(level=logging.DEBUG) # start the event loop asyncio.run(main()) |
Tying this together, the complete example is listed below.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 |
# SuperFastPython.com # example of logging a cancellederror within the task import logging import asyncio # task that does work and logs async def work(): try: # log a message logging.info(f'Task is starting') # simulate doing work await asyncio.sleep(1) # log a message logging.info(f'Task is done') except asyncio.CancelledError: # log the cancellation logging.exception(f'Task was cancelled, details: {asyncio.current_task()}') # re-raise the exception raise # main coroutine async def main(): # log a message logging.info(f'Main is starting') # schedule a task task = asyncio.create_task(work()) # wait around await asyncio.sleep(0.5) # cancel the task task.cancel() try: # wait for the task to cancel await task except asyncio.CancelledError: pass # log a message logging.info(f'Main is done') # prepare the logger logging.basicConfig(level=logging.DEBUG) # start the event loop asyncio.run(main()) |
Running the example first configures the logging infrastructure, then starts the asyncio event loop and runs the main() coroutine.
The main() coroutine runs and logs a start message.
It then creates and schedules a task for the work() coroutine and suspends for a fraction of a second.
The work() task runs and logs a start message then suspends with a sleep for one second.
The main() coroutine resumes and cancels the work() task and then awaits it.
The work() task resumes. A CancelledError exception is raised in the work() task causing the sleep() to be interrupted.
The CancelledError is caught and logged as an exception. This includes an error message with the details of the task and the stack trace of the exception.
The work() task then re-raises the CancelledError exception and terminates.
The main() coroutine resumes and handles the CancelledError exception, ignoring it. It then logs a final message and terminates.
This highlights how we can log a CancelledError exception from within the task.
|
1 2 3 4 5 6 7 8 9 10 11 12 |
DEBUG:asyncio:Using selector: KqueueSelector INFO:root:Main is starting INFO:root:Task is starting ERROR:root:Task was cancelled, details: <Task cancelling name='Task-2' coro=<work() running at ...:17> cb=[Task.task_wakeup()]> Traceback (most recent call last): File "...", line 12, in work await asyncio.sleep(1) File ".../asyncio/tasks.py", line 639, in sleep return await future ^^^^^^^^^^^^ asyncio.exceptions.CancelledError INFO:root:Main is done |
Next, let’s look at an example of logging a CancelledError exception from the caller that requested the task be canceled.
Example of Logging CancelledError In Caller
We can explore an example of logging a CancelledError exception in the caller that requested that the target task be canceled.
In this case, we can update the above example so that the work() coroutine no longer handles the CancelledError exception.
|
1 2 3 4 5 6 7 8 |
# task that does work and logs async def work(): # log a message logging.info(f'Task is starting') # simulate doing work await asyncio.sleep(1) # log a message logging.info(f'Task is done') |
We can then update the main() coroutine so that it logs the CancelledError exception raised by the target task, rather than ignores it.
|
1 2 3 4 5 6 7 8 |
... # cancel the task task.cancel() try: # wait for the task to cancel await task except asyncio.CancelledError: logging.exception(f'Confirmed that task {task} was cancelled.') |
Logging the CancelledError exception at the point that the request to cancel was made will allow the details of the cause of the cancellation to be included in the stack trace that is logged along with the exception. This can be helpful later when reviewing logs and attempting to identify the cause of cancellation.
And that’s it.
Tying this together, the complete example is listed below.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 |
# SuperFastPython.com # example of logging a cancellederror within the caller import logging import asyncio # task that does work and logs async def work(): # log a message logging.info(f'Task is starting') # simulate doing work await asyncio.sleep(1) # log a message logging.info(f'Task is done') # main coroutine async def main(): # log a message logging.info(f'Main is starting') # schedule a task task = asyncio.create_task(work()) # wait around await asyncio.sleep(0.5) # cancel the task task.cancel() try: # wait for the task to cancel await task except asyncio.CancelledError: logging.exception(f'Confirmed that task {task} was cancelled.') # log a message logging.info(f'Main is done') # prepare the logger logging.basicConfig(level=logging.DEBUG) # start the event loop asyncio.run(main()) |
Running the example first configures the logging infrastructure, then starts the asyncio event loop and runs the main() coroutine.
The main() coroutine runs and logs a start message.
It then creates and schedules a task for the work() coroutine and suspends for a fraction of a second.
The work() task runs and logs a start message then suspends with a sleep for one second.
The main() coroutine resumes and cancels the work() task and then awaits it.
The work() task resumes and a CancelledError exception is raised in the work() task causing the sleep() to be interrupted. The CancelledError exception bubbles up and causes the work() task to be terminated.
The main() coroutine resumes and the CancelledError exception is raised. It is handled and logged as an exception. This includes an ERROR level message with the details of the task, as well as a stack trace for the exception. The trace includes the awaiting of the task after cancellation, which is part of the cause of the cancellation.
The main() coroutine resumes and reports a final done message.
This highlights how we can log a CancelledError exception from the caller that requested the target task be canceled. The output shows that logging the CancelledError exception in this way can include details of the caller who requested that the task be canceled, which can be helpful when reviewing the log at a later date.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 |
DEBUG:asyncio:Using selector: KqueueSelector INFO:root:Main is starting INFO:root:Task is starting ERROR:root:Confirmed that task <Task cancelled name='Task-2' coro=<work() done, defined at ...:7>> was cancelled. Traceback (most recent call last): File "...", line 27, in main await task File "...", line 11, in work await asyncio.sleep(1) File ".../asyncio/tasks.py", line 639, in sleep return await future ^^^^^^^^^^^^ asyncio.exceptions.CancelledError INFO:root:Main is done |
Further Reading
This section provides additional resources that you may find helpful.
Python Asyncio Books
- Python Asyncio Mastery, Jason Brownlee (my book!)
- Python Asyncio Jump-Start, Jason Brownlee.
- Python Asyncio Interview Questions, Jason Brownlee.
- Asyncio Module API Cheat Sheet
I also recommend the following books:
- Python Concurrency with asyncio, Matthew Fowler, 2022.
- Using Asyncio in Python, Caleb Hattingh, 2020.
- asyncio Recipes, Mohamed Mustapha Tahrioui, 2019.
Guides
APIs
- asyncio — Asynchronous I/O
- Asyncio Coroutines and Tasks
- Asyncio Streams
- Asyncio Subprocesses
- Asyncio Queues
- Asyncio Synchronization Primitives
References
Takeaways
You now know how to log CancelledError exceptions in asyncio programs.
Did I make a mistake? See a typo?
I’m a simple humble human. Correct me, please!
Do you have any additional tips?
I’d love to hear about them!
Do you have any questions?
Ask your questions in the comments below and I will do my best to answer.
Photo by Nick Fewings on Unsplash
Leave a Reply