[FIXED] How to find the cause of CancelledError in asyncio?

Issue

I have a big project which depends some third-party libraries, and sometimes its execution gets interrupted by a CancelledError.

To demonstrate the issue, let's look at a small example:

import asyncio


async def main():
    task = asyncio.create_task(foo())

    # Cancel the task in 1 second.
    loop = asyncio.get_event_loop()
    loop.call_later(1.0, lambda: task.cancel())

    await task


async def foo():
    await asyncio.sleep(999)


if __name__ == '__main__':
    asyncio.run(main())

Traceback:

Traceback (most recent call last):
  File "/Users/ss/Library/Application Support/JetBrains/PyCharm2021.2/scratches/async.py", line 19, in <module>
    asyncio.run(main())
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/runners.py", line 43, in run
    return loop.run_until_complete(main)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete
    return future.result()
concurrent.futures._base.CancelledError

As you can see, there's no information about the place the CancelledError originates from. How do I find out the exact cause of it?

One approach that I came up with is to place a lot of try/except blocks which would catch the CancelledError and narrow down the place where it comes from. But that's quite tedious.

Solution

I've solved it by applyting a decorator to every async function in the project. The decorator's job is simple - log a message when a CancelledError is raised from the function. This way we will see which functions (and more importantly, in which order) get cancelled.

Here's the decorator code:

def log_cancellation(f):
    async def wrapper(*args, **kwargs):
        try:
            return await f(*args, **kwargs)
        except asyncio.CancelledError:
            print(f"Cancelled {f}")
            raise
    return wrapper

In order to add this decorator everywhere I used regex. Find: (.*)(async def). Replace with: $1@log_cancellation\n$1$2.

Also to avoid importing log_cancellation in every file I modified the builtins: builtins.log_cancellation = log_cancellation

Answered By - MMM