You can log without blocking in asyncio programs by using aiologger.
In this tutorial, you will discover how to log in asyncio programs without blocking using the aiologger library.
Let’s get started.
Logging From Asyncio is Blocking
Logging from an asyncio program is blocking.
This means that logging a is a function call that will prevent the asyncio event loop from progressing.
Often this is not a problem, such as when logging a few messages to standard output.
It does become a problem when there are a large number of log messages and/or the target of the logging infrastructure is a blocking I/O call, such as storing messages to a file, database, or network connection.
… it should be noted that when logging from async code, network and even file handlers could lead to problems (blocking the event loop) because some logging is done from asyncio internals.
— Logging Cookbook
Therefore, it is recommended to perform logging from asyncio using a different thread.
Naively, this could be achieved by wrapping each call to the logging infrastructure in a call like asyncio.to_thread() so that it happens in a new Python thread.
This is cumbersome.
Instead, a better approach is to configure the logging infrastructure so that messages are issued using a data structure and a separate logging thread is responsible for storing log messages and performing any blocking calls to files or network resources.
Network logging can block the event loop. It is recommended to use a separate thread for handling logs or use non-blocking IO.
— Developing with asyncio
Now that we know that logging in asyncio is blocking, let’s explore how we might log in asyncio without blocking.
Run loops using all CPUs, download your FREE book to learn how.
How to Log Without Blocking With aiologger
One approach to logging in asyncio programs without blocking is to log in a separate thread.
This can be achieved by using a QueueHandler and QueueListener with the built-in logging module.
This can be a lot of work.
You can learn more about how to manually log without blocking in the tutorial:
An alternative to manually logging in asyncio programs without blocking is to use the aiologger library.
This library does all the heavy lifting for us, providing a ready-to-use logging module for asyncio programs that will perform the log operations in a separate thread, behind the scenes.
The builtin python logger is IO blocking. This means that using the builtin logging module will interfere with your asynchronous application performance. aiologger aims to be the standard Asynchronous non blocking logging for python and asyncio.
— Welcome to aiologger docs!
Let’s look at how we can log without blocking in our asyncio programs using aiologger.
How to Install aiologger
The first step is to install the aiologger library.
You can install aiologger using your favorite package manager, such as pip.
For example:
1 |
pip install aiologger |
How to Use aiologger
Once aiologger is installed, we can use it in our asyncio programs.
This requires first importing the aiologger.Logger class.
1 |
from aiologger import Logger |
Once imported, we can then configure the Logger class in terms of the log name, handlers, and log level we wish to use.
This can be achieved via the Logger.with_default_handlers() function.
For example:
1 2 3 |
... # configure the logger logger = Logger.with_default_handlers(name='my-logger') |
We can use the aiologger.LogLevel enum to configure the log level.
For example:
1 2 3 |
... # configure the logger logger = Logger.with_default_handlers(level=LogLevel.DEBUG) |
The instance of the Logger class must be used as a global variable throughout our asyncio program.
For example, we can use the Logger instance to log directly, without blocking.
For example:
1 2 3 |
... # log a message logger.debug("something happened") |
We can also await the log message.
1 2 3 |
... # log a message await logger.debug("something happened") |
Note that this is unlike the built-in logging module in Python, where logging can be performed using module functions instead of an object instance.
This makes converting a large Python program that uses the built-in logging to use the aiologger library, possibly quite cumbersome.
Once our application is finished, we can explicitly shut down the aiologger.
I suspect that internally this purges any remaining log messages on internal queues and terminates any background threads.
This can be achieved via the shutdown() method.
for example:
1 2 3 |
... # shutdown the logger await logger.shutdown() |
And that’s it.
Now that we know how to use the aiologger library, let’s look at some worked examples.
Example of Non-Blocking Logging With aiologger
We can explore an example of logging without blocking in an asyncio program using the aiologger library.
In this example, we will define a task that blocks for a fraction of 5 seconds and logs a message when it begins and ends. The main coroutine will log the beginning of the program, then start 10 copies of our task to run concurrently, before reporting a final message before shutdown.
Firstly, we can define our task that will sleep for a random fraction of 5 seconds and log some messages.
1 2 3 4 5 6 7 8 |
# task that does work and logs async def task(value): # log a message logger.info(f'Task {value} is starting') # simulate doing work await asyncio.sleep(random() * 5) # log a message logger.info(f'Task {value} is done') |
Next, we can define our main() coroutine that logs start and done messages and uses an asyncio.TaskGroup to issue 10 copies of our task() coroutine and blocking until all tasks are down.
Before the main() coroutine ends, it explicitly shuts down the logger.
1 2 3 4 5 6 7 8 9 10 11 12 |
# main coroutine async def main(): # log a message logger.info(f'Main is starting') # issue many tasks async with asyncio.TaskGroup() as group: for i in range(10): _ = group.create_task(task(i)) # log a message logger.info(f'Main is done') # shutdown the logger await logger.shutdown() |
If you are new to the asyncio.TaskGroup, you can learn how to use it in the tutorial:
Finally, we can initialize the log to report all messages with a DEBUG level and above.
The aiologger.Logger instance is maintained as a global variable that can be accessed throughout our asyncio program.
1 2 3 |
... # get the root logger, define a global var logger = Logger.with_default_handlers(level=LogLevel.DEBUG) |
We can then start the asyncio event loop and run our main() coroutine.
1 2 3 |
... # 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 |
# SuperFastPython.com # example of non-blocking logging with aiologger from aiologger import Logger from aiologger.levels import LogLevel from random import random import asyncio # task that does work and logs async def task(value): # log a message logger.info(f'Task {value} is starting') # simulate doing work await asyncio.sleep(random() * 5) # log a message logger.info(f'Task {value} is done') # main coroutine async def main(): # log a message logger.info(f'Main is starting') # issue many tasks async with asyncio.TaskGroup() as group: for i in range(10): _ = group.create_task(task(i)) # log a message logger.info(f'Main is done') # shutdown the logger await logger.shutdown() # get the root logger, define a global var logger = Logger.with_default_handlers(level=LogLevel.DEBUG) # start the event loop asyncio.run(main()) |
Running the example creates an instance of the aiologger.Logger class configured to report all messages with a DEBUG level and above.
The asyncio event loop is then started and the main() coroutine is executed.
The main() coroutine runs and uses the “logger” global variable to log a start message. It then creates a TaskGroup and then issues 10 copies of the task() task and waits for them to complete.
The task() tasks run and log a start message using the same logger global variable before sleeping for some fraction of 5 seconds. The tasks resume and log a final done message.
Once all of the issued tasks are done the TaskGroup contact manager returns and the main() coroutine logs a final message before explicitly shutting down the aiologger.
This highlights how we can use the aiologger in our asyncio program to log without blocking.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 |
Main is starting Task 0 is starting Task 1 is starting Task 2 is starting Task 3 is starting Task 4 is starting Task 5 is starting Task 6 is starting Task 7 is starting Task 8 is starting Task 9 is starting Task 9 is done Task 4 is done Task 0 is done Task 6 is done Task 8 is done Task 5 is done Task 1 is done Task 3 is done Task 7 is done Task 2 is done |
Next, let’s explore how we might use the aiologger by awaiting calls that log messages.
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.
Example of Non-Blocking Logging With aiologger and Awaits
We can explore logging with aiologger by awaiting log messages.
Some asyncio programmers prefer that all calls made in their programs are awaited. This helps to avoid performing any calls that might block the event loop.
It forces consideration of whether tasks should be performed in separate threads or child processes.
The aiologger library supports this philosophy by allowing all methods used to report log messages to be awaitable.
In this case, we will update the above example to explicitly await all log messages made using aiologger.
For example, the updated task() coroutine with this change is listed below.
1 2 3 4 5 6 7 8 |
# task that does work and logs async def task(value): # log a message await logger.info(f'Task {value} is starting') # simulate doing work await asyncio.sleep(random() * 5) # log a message await logger.info(f'Task {value} is done') |
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 |
# SuperFastPython.com # example of non-blocking logging with aiologger and awaits from aiologger import Logger from aiologger.levels import LogLevel from random import random import asyncio # task that does work and logs async def task(value): # log a message await logger.info(f'Task {value} is starting') # simulate doing work await asyncio.sleep(random() * 5) # log a message await logger.info(f'Task {value} is done') # main coroutine async def main(): # log a message await logger.info(f'Main is starting') # issue many tasks async with asyncio.TaskGroup() as group: for i in range(10): _ = group.create_task(task(i)) # log a message await logger.info(f'Main is done') # shutdown the logger await logger.shutdown() # get the root logger, define a global var logger = Logger.with_default_handlers(level=LogLevel.DEBUG) # start the event loop asyncio.run(main()) |
Running the example creates an instance of the aiologger.Logger class configured to report all messages with a DEBUG level and above.
The asyncio event loop is then started and the main() coroutine is executed.
The main() coroutine runs and uses the “logger” global variable to log and await a start message. It then creates a TaskGroup and then issues 10 copies of the task() task and waits for them to complete.
The task() tasks run and log and await a start message using the same logger global variable before sleeping for some fraction of 5 seconds. The tasks resume and log and await a final done message.
Once all of the issued tasks are done the TaskGroup contact manager returns and the main() coroutine logs a final message before explicitly shutting down the aiologger.
This highlights how we can use the aiologger without blocking and explicitly await all logging methods.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 |
Main is starting Task 0 is starting Task 1 is starting Task 2 is starting Task 3 is starting Task 4 is starting Task 5 is starting Task 6 is starting Task 7 is starting Task 8 is starting Task 9 is starting Task 2 is done Task 6 is done Task 4 is done Task 0 is done Task 3 is done Task 9 is done Task 7 is done Task 5 is done Task 1 is done Task 8 is done Main is done |
Overwhelmed by the python concurrency APIs?
Find relief, download my FREE Python Concurrency Mind Maps
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 in asyncio programs without blocking using the aiologger library.
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 Claude Piché on Unsplash
Do you have any questions?