Last Updated on September 12, 2022
You can log directly from multiple threads because the logging module is thread-safe.
In this tutorial you will discover how to log safely from many threads.
Let’s get started.
Need to Log From Multiple Threads
A thread is a thread of execution in a computer program.
Every Python program has at least one thread of execution called the main thread. Both processes and threads are created and managed by the underlying operating system.
Sometimes we may need to create additional threads in our program in order to execute code concurrently.
Python provides the ability to create and manage new threads via the threading module and the threading.Thread class.
You can learn more about Python threads in the guide:
In concurrent programming, we may need to log from multiple threads in the application.
This may be for many reasons, such as:
- Different threads may perform different tasks and may encounter a range of events.
- Worker threads may encounter exceptions that need to be stored, but should not halt the program.
- Background tasks may need to report progress over the duration of the program.
What is logging, and is it safe to use from multiple threads?
Run loops using all CPUs, download your FREE book to learn how.
What is Logging
Logging is a way of tracking events within a program.
There are many types of events that may be logged within a program, ranging in different levels of severity, such as debugging and information to warnings, errors and critical events.
The logging module provides infrastructure for logging within Python programs.
This module defines functions and classes which implement a flexible event logging system for applications and libraries.
— logging — Logging facility for Python
Logging is achieved by first configuring the log handler and then adding calls to the logging infrastructure at key points in the program.
Handler objects are responsible for dispatching the appropriate log messages (based on the log messages’ severity) to the handler’s specified destination.
— Handles, Logging HOWTO
The default handler will report log messages on the command prompt (e.g. terminal or system output stream).
Alternate handlers can be configured to write log messages to file, to a database, or to custom target locations. The handler can specify the severity of messages to store.
For example, we can log to file by calling the logging.basicConfig() function and specifying the file name and path to log to (e.g. application.log), the level of logging to capture to the file (e.g. from logging.DEBUG to logging.CRITICAL).
1 2 3 |
... # log everything to file logging.basicConfig(filename='application.log', level=logging.DEBUG) |
Events are logged via function calls based on the type of event performed, e.g. logging.debug() for debugging messages.
Logging provides a set of convenience functions for simple logging usage. These are debug(), info(), warning(), error() and critical().
— Logging HOWTO
For example, we may add information messages to application code by calling logging.info() and passing in the string details of the event.
1 2 3 |
... # log that data was loaded successfully logger.info('All data was loaded successfully') |
We may also log failures, such as exceptions that are important but not critical to the program via the logger.error() or logger.exception() functions.
For example:
1 2 3 4 5 6 |
... # try a thing try: # ... except Exception as err: logger.exception(f'Unable to perform task because: {err.message} ') |
These function calls can then be added throughout an application to capture events of different types, and the log handler or runtime configuration can be used to filter the severity of the messages that are actually stored.
This provides a quick crash-course to Python logging, you can learn more here:
Next, let’s consider logging from multiple threads.
How to Log From Multiple Threads
The logging module can be used directly from multiple threads.
The reason is because the logging module is thread-safe.
The logging module is intended to be thread-safe without any special work needing to be done by its clients.
— Thread Safety, logging — Logging facility for Python.
This is achieved using locks.
Internally, the logging module uses mutual exclusion (mutex) locks to ensure that logging handlers are protected from race conditions from multiple threads.
For example, locks are used to ensure that only one thread writes to a log file or log stream at a time. This ensures that log messages are serialized and are not corrupted.
It achieves this though using threading locks; there is one lock to serialize access to the module’s shared data, and each handler also creates a lock to serialize access to its underlying I/O.
— Thread Safety, logging — Logging facility for Python.
Therefore, once the logging module is configured for your process, you can log directly from threads.
Next, let’s look at some examples of logging from multiple threads.
Free Python Threading Course
Download your FREE threading PDF cheat sheet and get BONUS access to my free 7-day crash course on the threading API.
Discover how to use the Python threading module including how to create and start new threads and how to use a mutex locks and semaphores
Example of Thread-Safe Logging
We can explore how to log safely from multiple threads.
In this example, we will create five worker threads, each of which will execute a task. The task will loop five times and each iteration it will generate a random number between 0 and 1, block for that many seconds, then if the number is below a threshold, the thread will stop.
We will log whether the task was stopped as a warning message and we will log whether the task was completed successfully as an information message.
All threads will log the information message and some subset of threads will report a warning message.
Firstly, we will define a function to execute in each worker thread.
The task will take a unique integer to represent the thread, and a threshold value as arguments. The task will loop five times, generate a random number, block with a call to time.sleep() and check the value of the number to see if the task should stop.
The task() function below implements this, with warning and info level log messages.
1 2 3 4 5 6 7 8 9 10 11 12 13 |
# task to be executed by worker threads def task(number, threshold): # simulate doing work for i in range(5): # generate value value = random() # block sleep(value) # check if is a problem if value < threshold: logging.warning(f'Thread {number} value less than {threshold}, stopping.') break logging.info(f'Thread {number} completed successfully.') |
Next, in the main thread, will first configure the logger.
First, will acquire an instance of the root logger and then set the level of messages to log to be debug or higher, essentially all messages.
1 2 3 4 |
... # configure the log to report all messages logger = logging.getLogger() logger.setLevel(logging.DEBUG) |
We will then create five threads configured to execute our task function, each passed a unique integer and a threshold value of 0.1. This is performed in a list comprehension.
1 2 3 |
... # start the threads threads = [Thread(target=task, args=(i, 0.1)) for i in range(5)] |
We then start all worker threads, and the main thread will block until all tasks are complete.
1 2 3 4 5 6 7 |
... # start threads for thread in threads: thread.start() # wait for threads to finish for thread in threads: thread.join() |
Tying this together, the complete example of logging from multiple threads 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 |
# SuperFastPython.com # example of logging from multiple threads from random import random from time import sleep from threading import Thread import logging # task to be executed by worker threads def task(number, threshold): # simulate doing work for i in range(5): # generate value value = random() # block sleep(value) # check if is a problem if value < threshold: logging.warning(f'Thread {number} value less than {threshold}, stopping.') break logging.info(f'Thread {number} completed successfully.') # configure the log to report all messages logger = logging.getLogger() logger.setLevel(logging.DEBUG) # start the threads threads = [Thread(target=task, args=(i, 0.1)) for i in range(5)] # start threads for thread in threads: thread.start() # wait for threads to finish for thread in threads: thread.join() |
Running the example first configures the log to report all messages.
The default logger reports messages to the console (e.g. standard out).
The five threads are then created and started and the main thread blocks until the tasks are complete.
Each worker thread then iterates the task loop, generating a random number, blocking and then checking if the generated number was below the threshold. If below the threshold, a warning message is reported and the task loop is broken.
In this case, we can see that three of the tasks generated random numbers below the threshold and broke the task.
Note, your specific results will differ each time the program is run given the use of random numbers.
1 2 3 4 5 6 7 8 |
WARNING:root:Thread 2 value less than 0.1, stopping. INFO:root:Thread 2 completed successfully. WARNING:root:Thread 1 value less than 0.1, stopping. INFO:root:Thread 1 completed successfully. WARNING:root:Thread 3 value less than 0.1, stopping. INFO:root:Thread 3 completed successfully. INFO:root:Thread 0 completed successfully. INFO:root:Thread 4 completed successfully. |
This demonstrates how we can directly log from multiple threads in a thread-safe manner.
If logging was not thread-safe, then the log messages would not be serialized correctly, possibly overlapping and corrupting as multiple threads attempted to write to the standard output stream concurrently.
Next, let’s look at how we might log to a file from multiple threads.
Overwhelmed by the python concurrency APIs?
Find relief, download my FREE Python Concurrency Mind Maps
Example of Thread-Safe Logging to File
We can explore how multiple threads may log to file in a thread-safe manner.
This can be achieved by configuring the logger to store messages at or above the desired level to a filename and path.
For example, we can update the above example to log all messages at debug level or above to a file in the same directory as the Python program named ‘application.log‘.
This can be achieved with a single line that configures the logger with a filename and level.
1 2 3 |
... # configure the log to report all messages to file logging.basicConfig(filename='application.log', encoding='utf-8', level=logging.DEBUG) |
Because we are logging to a file, perhaps we can capture more information for later review.
In this case, we will update the task() function to add an information message for the thread starting the task, and a debug message reporting the specific value generated each iteration.
The updated version of the task() function with these changes is listed below.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
# task to be executed by worker threads def task(number, threshold): logging.info(f'Thread {number} starting.') # simulate doing work for i in range(5): # generate value value = random() # log all values generated logging.debug(f'Thread {number} got {value}.') # block sleep(value) # check if is a problem if value < threshold: logging.warning(f'Thread {number} value less than {threshold}, stopping.') break logging.info(f'Thread {number} completed successfully.') |
Tying this together, the complete example of logging to file from multiple threads 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 |
# SuperFastPython.com # example of logging to file from multiple threads from random import random from time import sleep from threading import Thread import logging # task to be executed by worker threads def task(number, threshold): logging.info(f'Thread {number} starting.') # simulate doing work for i in range(5): # generate value value = random() # log all values generated logging.debug(f'Thread {number} got {value}.') # block sleep(value) # check if is a problem if value < threshold: logging.warning(f'Thread {number} value less than {threshold}, stopping.') break logging.info(f'Thread {number} completed successfully.') # configure the log to report all messages to file logging.basicConfig(filename='application.log', encoding='utf-8', level=logging.DEBUG) # start the threads threads = [Thread(target=task, args=(i, 0.1)) for i in range(5)] # start threads for thread in threads: thread.start() # wait for threads to finish for thread in threads: thread.join() |
Running the example first configures the root logger for the process to log all messages at debug level or above to a file named ‘application.log‘.
Note, this file will be located in the same directory as your Python script, e.g. your current working directory.
The five threads are then configured and started, then the main thread blocks until the tasks are complete.
Each thread then executes the task function, logging information messages at the beginning and end of the task, as well as debug messages for each number generated and a warning if a value below the threshold is generated.
In this case, only two tasks failed, although now we can see a log of all values generated by all threads.
A sample of the application.log file is provided below.
Note, your specific results will differ each time the program is run given the use of random numbers.
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 |
INFO:root:Thread 0 starting. DEBUG:root:Thread 0 got 0.6872681866195555. INFO:root:Thread 1 starting. INFO:root:Thread 2 starting. DEBUG:root:Thread 1 got 0.5305569731755968. INFO:root:Thread 3 starting. DEBUG:root:Thread 3 got 0.402768468886029. INFO:root:Thread 4 starting. DEBUG:root:Thread 2 got 0.6521552026743789. DEBUG:root:Thread 4 got 0.39398558409115936. DEBUG:root:Thread 4 got 0.5914867417636379. DEBUG:root:Thread 3 got 0.5632969425212079. DEBUG:root:Thread 1 got 0.6574309780583252. DEBUG:root:Thread 2 got 0.2816326597231996. DEBUG:root:Thread 0 got 0.24898050248914583. DEBUG:root:Thread 0 got 0.7851953102843077. DEBUG:root:Thread 2 got 0.5426480165988804. DEBUG:root:Thread 3 got 0.06815851358033809. DEBUG:root:Thread 4 got 0.28349789050752416. WARNING:root:Thread 3 value less than 0.1, stopping. INFO:root:Thread 3 completed successfully. DEBUG:root:Thread 1 got 0.4748495190874048. DEBUG:root:Thread 4 got 0.04795736017794938. WARNING:root:Thread 4 value less than 0.1, stopping. INFO:root:Thread 4 completed successfully. DEBUG:root:Thread 2 got 0.68465010542898. DEBUG:root:Thread 1 got 0.4359601833807665. DEBUG:root:Thread 0 got 0.5281234755758193. DEBUG:root:Thread 1 got 0.8275183394617339. DEBUG:root:Thread 2 got 0.6190758962270743. DEBUG:root:Thread 0 got 0.20781719936237797. INFO:root:Thread 0 completed successfully. INFO:root:Thread 2 completed successfully. INFO:root:Thread 1 completed successfully. |
This demonstrates how we can log to file from multiple threads in a thread-safe manner.
Next, let’s look at how we might automatically include thread information in log messages.
Example of Automatically Logging Thread Details
We can automatically include details about threads in the log messages.
This can be achieved by changing the format of log messages to include attributes such as the thread name or the thread identifier.
In the previous examples, we manually assigned each thread a unique integer which was used in log messages to differentiate each thread. We can remove this unique integer and include each thread’s default and uniquely assigned name in the log messages.
You can learn more about thread names in this tutorial:
Firstly, we can create a new logging.FileHandler instance, configured to log all messages at debug level or higher to a file named ‘application2.log‘.
1 2 3 4 |
... # configure log handler to report all messages to file with thread names handler = logging.FileHandler('application2.log') handler.setLevel(logging.DEBUG) |
We can then create a new instance of a logging.Formatter instance specifying the attributes to include in each message. We will include the same attributes as in prior messages with the addition of the thread name.
1 2 |
... handler.setFormatter(logging.Formatter('[%(levelname)s] %(name)s: [%(threadName)s] %(message)s')) |
You can see a list of all attributes that you could include in log messages here:
Finally, we can configure the logging infrastructure to use our log handler and to log all messages at debug level or above to the handler.
1 2 3 4 5 |
... # set the new log handler logger = logging.getLogger() logger.setLevel(logging.DEBUG) logger.addHandler(handler) |
We can then update the task() function to no longer take a unique integer for the thread and to remove it from all log messages.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
# task to be executed by worker threads def task(threshold): logging.info(f'Thread starting.') # simulate doing work for i in range(5): # generate value value = random() # log all values generated logging.debug(f'Thread got {value}.') # block sleep(value) # check if is a problem if value < threshold: logging.warning(f'Thread value less than {threshold}, stopping.') break logging.info(f'Thread completed successfully.') |
Finally, we can update the configuration of the new threads to no longer pass each thread a unique integer.
1 2 3 |
... # start the threads threads = [Thread(target=task, args=(0.1,)) for i in range(5)] |
Tying this together, the complete example of including thread name in log messages 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 |
# SuperFastPython.com # example of logging to file from multiple threads from random import random from time import sleep from threading import Thread import logging # task to be executed by worker threads def task(threshold): logging.info(f'Thread starting.') # simulate doing work for i in range(5): # generate value value = random() # log all values generated logging.debug(f'Thread got {value}.') # block sleep(value) # check if is a problem if value < threshold: logging.warning(f'Thread value less than {threshold}, stopping.') break logging.info(f'Thread completed successfully.') # configure log handler to report all messages to file with thread names handler = logging.FileHandler('application2.log') handler.setLevel(logging.DEBUG) handler.setFormatter(logging.Formatter('[%(levelname)s] %(name)s: [%(threadName)s] %(message)s')) # set the new log handler logger = logging.getLogger() logger.setLevel(logging.DEBUG) logger.addHandler(handler) # start the threads threads = [Thread(target=task, args=(0.1,)) for i in range(5)] # start threads for thread in threads: thread.start() # wait for threads to finish for thread in threads: thread.join() |
Running the example first configures the logging infrastructure to log all messages at debug level or above to a file named application2.log located in the current working directory.
The threads are then configured and started.
Each thread performs the task, reporting information messages at the beginning and end, debug messages each iteration and a possible warning message if the threshold is crossed.
Below is a sample of the content of the log file.
We can see that each message includes the name of the thread executing the task, taken from the “name” attribute on the threading.Thread instance, assigned automatically when the thread was created.
Note, your specific results will differ each time the program is run given the use of random numbers.
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 |
[INFO] root: [Thread-1] Thread starting. [INFO] root: [Thread-2] Thread starting. [DEBUG] root: [Thread-1] Thread got 0.09587355831874278. [INFO] root: [Thread-3] Thread starting. [DEBUG] root: [Thread-2] Thread got 0.45934779035061424. [INFO] root: [Thread-4] Thread starting. [INFO] root: [Thread-5] Thread starting. [DEBUG] root: [Thread-5] Thread got 0.25582402199510756. [DEBUG] root: [Thread-4] Thread got 0.7909623659909202. [DEBUG] root: [Thread-3] Thread got 0.37683810897376424. [WARNING] root: [Thread-1] Thread value less than 0.1, stopping. [INFO] root: [Thread-1] Thread completed successfully. [DEBUG] root: [Thread-5] Thread got 0.11073163782595619. [DEBUG] root: [Thread-5] Thread got 0.8807436123562962. [DEBUG] root: [Thread-3] Thread got 0.7628568192811082. [DEBUG] root: [Thread-2] Thread got 0.31602229981136387. [DEBUG] root: [Thread-2] Thread got 0.34218000315346264. [DEBUG] root: [Thread-4] Thread got 0.985050898270823. [DEBUG] root: [Thread-2] Thread got 0.7913950145467007. [DEBUG] root: [Thread-3] Thread got 0.48335839478464804. [DEBUG] root: [Thread-5] Thread got 0.449662466956699. [DEBUG] root: [Thread-3] Thread got 0.27453085353883955. [DEBUG] root: [Thread-5] Thread got 0.9245155683900323. [DEBUG] root: [Thread-4] Thread got 0.7435539607849608. [DEBUG] root: [Thread-3] Thread got 0.21712663205469285. [DEBUG] root: [Thread-2] Thread got 0.935221427815125. [INFO] root: [Thread-3] Thread completed successfully. [DEBUG] root: [Thread-4] Thread got 0.6809414273496055. [INFO] root: [Thread-5] Thread completed successfully. [INFO] root: [Thread-2] Thread completed successfully. [DEBUG] root: [Thread-4] Thread got 0.9068906611016891. [INFO] root: [Thread-4] Thread completed successfully. |
Further Reading
This section provides additional resources that you may find helpful.
Python Threading Books
- Python Threading Jump-Start, Jason Brownlee (my book!)
- Threading API Interview Questions
- Threading Module API Cheat Sheet
I also recommend specific chapters in the following books:
- Python Cookbook, David Beazley and Brian Jones, 2013.
- See: Chapter 12: Concurrency
- Effective Python, Brett Slatkin, 2019.
- See: Chapter 7: Concurrency and Parallelism
- Python in a Nutshell, Alex Martelli, et al., 2017.
- See: Chapter: 14: Threads and Processes
Guides
- Python Threading: The Complete Guide
- Python ThreadPoolExecutor: The Complete Guide
- Python ThreadPool: The Complete Guide
APIs
References
Takeaways
You now know how to log safely from multiple threads.
Do you have any questions?
Ask your questions in the comments below and I will do my best to answer.
Gururaj says
i need to log to postgresql by logging. Can you please suggest me a way.
Jason Brownlee says
Maybe try LogToPG: https://pypi.org/project/LogToPG/
Albert says
How can these examples be extended to logging from multiple threads sharing multiple modules?
Jason Brownlee says
You can log directly as the logging module is thread-safe.