You can enable logging in the asyncio module in order to record additional info, warning, and debug messages.

The asyncio module will log messages automatically which is helpful if we are using the logging module in our application, as the log messages will be captured along with our application log messages.

The asyncio module logging can provide additional insight into issues in our programs, such as never-retrieved exceptions and coroutines that block the event loop for too long.

In this tutorial, you will discover how to enable asyncio module logging.

Let’s get started.

The Asyncio Module Logs

The asyncio module performs logging.

The logging performed is mostly related to the internals of the asyncio runtime.

Most log messages are WARNING and DEBUG level, although there are some INFO messages as well.

We can discover all logging performed by the asyncio module by searching the code in the asyncio module for use of the module “logger” global variable in the asyncio/ directory. This global variable is set up in asyncio/log.py file.

Log messages include:

• Debug messages about the creation of subprocesses and their PID.
• Debug messages about data communication with subprocesses.
• Debug messages about new connections and read errors from I/O.
• Info messages about running a socket server.
• Debug messages about handling new incoming socket connections.
• Debug messages about receiving an EOF.
• Debug messages about which selector the event loop is using.
• Warning messages about tasks that block the event loop for too long.

And more.

Access to the log messages from the asyncio module can be helpful when debugging an asyncio program, especially if it involves problems with non-blocking reads and writes with subprocesses and sockets.

How can we enable asyncio module logging in our programs in order to see these and related log messages?

How to Enable Asyncio Module Logging

We can enable the asyncio module to log messages.

This can be achieved by configuring the root logger to an appropriate log level.

For example, we can configure the root logger to log all messages with a DEBUG level and above:

Alternatively, if we are using an application log or a module-level logging in our program (not a root logger), we can specifically set the log level for the asyncio module directly.

For example:

This will allow the asyncio module log messages to be visible and stored along with the application log messages.

Additionally, many of the debug and warning level messages are not logged unless the asyncio event loop is run in debug mode.

This can be achieved by setting the “debug” argument to True when starting the event loop.

For example:

Now that we know how to enable asyncio module logging, let’s look at some worked examples.

Example of Asyncio Module Logging

We can explore an example of enabling asyncio module logging.

In this case, we can define a task that logs a message, sleeps, and logs a done message. We can then start this task in and await it from the main coroutine. This provides some normal application-level logging.

We will set the root logger to DEBUG level so that all application-level logs and all asyncio module log messages are reported.

The complete example is listed below.

Running the example first configures the root logger to log all messages with a DEBUG level and above. This ensures the application log messages are reported. This level propagates to all module-level loggers, ensuring that the asyncio module log messages are also reported.

The event loop is started and the main() coroutine is run.

As part of starting the event loop, DEBUG level message is reported with the details of the selector that is being used.

The main() coroutine runs and logs a start message. It creates and schedules the work() coroutine to run in the background then sleeps for two seconds.

The work() task runs, logs a start message, sleeps for a second, then logs a done message.

The main() coroutine resumes and logs a final message.

This example highlights how we can enable asyncio module logging as part of normal application logging and how some asyncio module DEBUG messages will begin to be reported automatically.

Next, let’s look at the asyncio module logging of never-retrieved exceptions.

Example of Asyncio Module Logging Never-Retrieved Exception

We can explore the asyncio module logging of never-retrieved exceptions.

Recall that if an asyncio task fails with an exception and the exception is never retrieved or re-raised is referred to as a never-retrieved exception. It is a good practice to handle or log these exceptions.

You can learn more about how to log never-retrieved exceptions in the tutorial:

• Asyncio Task Exception Was Never Retrieved

The asyncio event loop will report never-retrieved exceptions automatically when it is closed.

If the asyncio module logging is enabled, these exceptions are logged as exceptions automatically.

This includes an ERROR-level log message and the stack trace of the exception reported when the asyncio event loop is enabled.

We can develop an asyncio task that fails with an exception that is never retrieved. With asyncio module logging enabled, the expectation is that this exception will be logged automatically when the program is terminated.

The complete example is listed below.

Running the example first configures the root logger to log all messages with a DEBUG level and above. This ensures the application log messages are reported. This level propagates to all module-level loggers, ensuring that the asyncio module log messages are also reported.

The event loop is started and the main() coroutine is run.

As part of starting the event loop, DEBUG level message is reported with the details of the selector that is being used.

The main() coroutine runs and logs a start message. It creates and schedules the work() coroutine to run in the background then sleeps for two seconds.

The work() task runs, logs a start message, sleeps for a second, then resumes and fails with an exception. This exception is not handled and is considered a never-retrieved exception.

The main() coroutine resumes and logs a final message.

The event loop is shut down and discovers the never-retrieved exception. An ERROR-level message is logged including the details of the task and the stack trace for the exception.

This highlights that when asyncio module logging is enabled it will log never-retrieved exceptions including details of the task and stack trace of the exception.

Next, let’s look at asyncio module logging when the event loop is in debug mode.

Example of Asyncio Module Logging in Debug Mode

We can explore an example of asyncio module logging when the event loop is configured to run in debug mode.

In this case, we will update the above example so that the work() task does not fail with an exception.

We will also configure the event loop to run in debug mode by setting the “debug” argument to True when calling asyncio.run().

For example:

The expectation is that when the event loop is run in debug mode, it will emit additional log messages.

Tying this together, the complete example is listed below.

Running the example first configures the root logger to log all messages with a DEBUG level and above. This ensures the application log messages are reported. This level propagates to all module-level loggers, ensuring that the asyncio module log messages are also reported.

The event loop is started in debug mode and the main() coroutine is run.

As part of starting the event loop, DEBUG level message is reported with the details of the selector that is being used.

The main() coroutine runs and logs a start message. It creates and schedules the work() coroutine to run in the background then sleeps for two seconds.

The work() task runs, logs a start message, sleeps for a second, then resumes and logs a final message before terminating.

The main() coroutine resumes and logs a final message.

Before the event loop is terminated, a final debug message is logged by the asyncio module indicating the event loop status, including that it is no longer running, that it is not yet closed, and that it was run in debug.

This highlights how we can enable logging for the asyncio module when the event loop is run in debug mode, exposing additional log messages.

Next, let’s look at asyncio module logging when the event loop is in debug mode with a task that blocks the event loop for too long.

Example of Asyncio Module Logging Debug Mode With Long Running Task

We can explore an example of asyncio module logging in debug mode that logs coroutines that block the event loop for too long.

In this case, we can update the above example that uses logging and runs the event loop in debug mode to block the event loop for too long.

This can be achieved by updating the work() coroutine to call the time.sleep() function instead of waiting for the asyncio.sleep() coroutine.

This will block the event loop and cause a debug message to be reported that the task took too long.

Tying this together, the complete example is listed below.

Running the example first configures the root logger to log all messages with a DEBUG level and above. This ensures the application log messages are reported. This level propagates to all module-level loggers, ensuring that the asyncio module log messages are also reported.

The event loop is started in debug mode and the main() coroutine is run.

As part of starting the event loop, DEBUG level message is reported with the details of the selector that is being used.

The main() coroutine runs and logs a start message. It creates and schedules the work() coroutine to run in the background then sleeps for two seconds.

The work() task runs, logs a start message, sleeps and blocks the event loop for a second, then resumes and logs a final message before terminating.

The termination of the work() task causes a warning message to be logged by the asyncio module indicating the task blocked the event loop for too long.

The main() coroutine resumes and logs a final message.

Before the event loop is terminated, a final debug message is logged by the asyncio module indicating the event loop status, including that it is no longer running, that it is not yet closed, and that it was run in debug mode.

This highlights that enabling asyncio module logging while running the event loop in debug mode allows the logging of warning messages for tasks that block the event loop for too long.

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

• Python Asyncio: The Complete Guide
• Python Asynchronous Programming

APIs

• asyncio — Asynchronous I/O
• Asyncio Coroutines and Tasks
• Asyncio Streams
• Asyncio Subprocesses
• Asyncio Queues
• Asyncio Synchronization Primitives

References

• Asynchronous I/O, Wikipedia.
• Coroutine, Wikipedia.

Takeaways

You now know how to enable asyncio module logging.

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 Bernard Hermant on Unsplash