Logging in python
Logging is the module in the standard library of python. Logging is an important tool for a programmer or developer, as it gives more insights about the code and any errors in it. In this tutorial, we will learn all about the python logging module. Right from replacing the print function with logging, logging to file, formatting the logging messages to using loggers, file handlers, formatters, etc.
Python logging module has five functions for five different levels of severity as under:-
Level | Function | Usage | Numeric Value |
---|---|---|---|
DEBUG | debug() | Detailed information for diagnosing. | 10 |
INFO | info() | For confirming that the code is working without errors. | 20 |
WARNING | warning() | Indication of something wrong like 'low disk space' etc. | 30 |
ERROR | error() | Error in execution of some function in the program. | 40 |
CRITICAL | critical() | The program itself has failed to operate due to some error. | 50 |
Using the python logging module
Using python logging module is as easy as:-
import logging
The default or out-of-box level of the python logging module is ‘WARNING’. It means that the logging module will track the event of level ‘WARNING’ or above, unless you configure it to track the lower levels i.e. ‘DEBUG’ and ‘INFO’.
# python_logging.py
import logging
logging.debug('Debug message')
logging.info('Info message')
logging.warning('Warning message')
logging.error('Error message')
logging.critical('Critical message')
# output
WARNING:root:Warning message
ERROR:root:Error message
CRITICAL:root:Critical message
In the above example, we have set no level for logging. Hence, the logging module has automatically logged for the level ‘WARNING’ and above.
Replacing the print function with logging
Every programmer not using the python logging module uses print() function for most of the debugging. There is no harm in using the print() but use it only for displaying the ordinary console output of the script. But using python logging provides some important data to the programmer which can be used in multiple ways.
The following simple division function uses the print() function to show the output on the console:-
# python_logging.py
import logging
def divide(x, y):
return x / y
num_1 = 10
num_2 = 2
result = divide(num_1, num_2)
print(f'{num_1}/{num_2} is {result}')
# Output
10/2 is 5.0
Now, we will replace the print function with logging. The above output is just an information and since logging’s default level is ‘WARNING’, we will change the level to ‘DEBUG’ using logging.basicConfig().
# python_logging.py
import logging
logging.basicConfig(level=logging.DEBUG)
def divide(x, y):
return x / y
num_1 = 10
num_2 = 2
result = divide(num_1, num_2)
logging.debug(f'{num_1}/{num_2} is {result}')
# Output
DEBUG:root:10/2 is 5.0
Here, the output comprises the level, root, and message as we have configured. ‘root’ is a logger and we will learn about it in the latter part of the tutorial.
Python logging to a file
Instead of logging the information to the console, we can also write it to a file by passing the filename in logging.basicConfig().
# python_logging.py
logging.basicConfig(filename = 'tutorial.log', level=logging.DEBUG)
If we will run the python script now, there will be no output on the console. But, a logging file with the log information will be created in the same directory. By default, on subsequent runs, the logs will be appended to that file. However, you can change the mode as under:-
# python_logging.py
logging.basicConfig(filename = 'tutorial.log', filemode = 'w' level=logging.DEBUG)
Formatting the logging message
We can also format the logging message by passing the argument format to basicConfig() function. We can get various logging format methods from here.
# python_logging.py
import logging
fmt = '%(levelname)s : %(asctime)s : %(message)s'
logging.basicConfig(level=logging.DEBUG, format=fmt)
# output
DEBUG : 2019-09-19 16:07:11,131 : 10/2 is 5.0
We can also log the variable data using python f-string as under:-
# python_logging.py
import logging
name = "Udit"
logging.warning(f'This is a warning for {name}.')
# output
WARNING:root:This is a warning for Udit
Using loggers, handlers and formatters
Till now, we were using the default logger called ‘root’ and logging.basicConfig() to set the logging output (console or file) and logging format. Using the default logger with basicConfig has some disadvantages while working with multiple modules.
To illustrate the same, create two files - ‘first_file.py’, second_file.py.
# first_file.py
import logging
import second_file
fmt = '%(levelname)s : %(asctime)s : %(message)s'
logging.basicConfig(level=logging.DEBUG, format=fmt)
def divide(x, y):
return x / y
num_1 = 10
num_2 = 2
result = divide(num_1, num_2)
logging.debug(f'{num_1}/{num_2} is {result}')
# second_file.py
import logging
fmt = '%(levelname)s : %(message)s'
logging.basicConfig(level=logging.INFO, format=fmt)
logging.info('This is logged from the second file.')
Now, for the first file, we have set the logging level as ‘DEBUG’ and for the second file we have set the level as ‘INFO’. When we import the second_file to the first_file.py, the whole code of the second_file will run. Hence, the root logger will be configured based on the second file and hence the level is set at ‘INFO’. So, when we will run the first_file.py, we will get the following output:-
INFO : This is logged from the second file.
If we change the last line of first_file.py:-
logging.info(f'{num_1}/{num_2} is {result}')
Then we will get the following output:-
INFO : This is logged from the second file.
INFO : 10/2 is 5.0
Here, the logging has retained the format of the second_file and it is not clear that which log is from which module/file.
To overcome this issue, the following classes of logging come handy:-
Class | Usage | Application |
---|---|---|
Logger | It is used to call the logging function and set the name to our logger | logging.getLogger('name\_of\_the\_logger'). General convention is to use logging.getLogger(__name__) |
Handler | It set the output destination for the log like console, file, etc. It has subclasses like StreamHandler, FileHandler, SMTPHandler, HTTPHandler, etc. | logging.FileHandler(), logging.StreamHandler() etc. and then logger_name.addHandler(name_of_the_handler) |
Formatter | To specify the format of the output. | logging.Formatter() and then file_handler.setFormatter('formatter_name') |
Now, we will edit our python files accordingly.
# second_file.py
import logging
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
handler = logging.StreamHandler()
fmt = logging.Formatter('%(levelname)s : %(name)s : %(message)s')
handler.setFormatter(fmt)
logger.addHandler(handler)
logger.info('This is logged from the second file.')
We have done the following:-
- Created the new logger with logging.getLogger(). We have used the variable __name__ as per general convention. You can read more about it in our tutorial here.
- Then, we have set the level to ‘DEBUG’.
- Created a new handler. We have used the StreamHandler() to display the output on the console itself.
- Set the format and added it to the handler and finally added the handler to the logger created above.
We will get the following output on running second_file.py. Here, the root is replaced by __main__, because we are running the file individually:-
INFO : __main__ : This is logged from the second file.
On running the first file without using logger etc. We will get the following output:-
# first_file.py
import logging
import second_file
fmt = '%(levelname)s : %(name)s : %(asctime)s : %(message)s'
logging.basicConfig(level=logging.DEBUG, format=fmt)
def divide(x, y):
return x / y
num_1 = 10
num_2 = 2
result = divide(num_1, num_2)
logging.debug(f'{num_1}/{num_2} is {result}')
# Output
INFO : second_file : This is logged from the second file.
DEBUG : root : 2019-09-20 12:41:06,284 : 10/2 is 5.0
The second file ran first. Since it has its own logger, it didn’t mess with the first file and both the logs with different level are displayed on the console. We can and should use the logger and all with the first file also.
One more advantage of using loggers, handlers, etc. in logging is that you can set different levels for different handlers. Like, you can log ‘ERROR’ and above on the file and ‘INFO’ and above on the console. This can be done by setting the level using setLevel().
# second_file.py
import logging
logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)
handler = logging.StreamHandler()
file_handler = logging.FileHandler('example.log')
fmt = logging.Formatter('%(levelname)s : %(name)s : %(message)s')
handler.setFormatter(fmt)
file_handler.setFormatter(fmt)
file_handler.setLevel('ERROR')
logger.addHandler(handler)
logger.addHandler(file_handler)
logger.info('This will be displayed on the console only.')
logger.error('This will be logged on the file also.')
# Ouptut on the console
INFO : __main__ : This will be displayed on the console only.
ERROR : __main__ : This will be logged on the file also.
# Output on the file ('example.log')
ERROR : __main__ : This will be logged on the file also.
Capturing exception traces in logging
If you are using try and exception in your function/script and you use logging.error(), then it won’t capture the traces of the exception.
# python_logging
import logging
fmt = '%(levelname)s : %(name)s : %(asctime)s : %(message)s'
logging.basicConfig(level=logging.DEBUG, format=fmt)
def divide(x, y):
try:
return x / y
except ZeroDivisionError as e:
logging.error('Trying to Divide a number by Zero.')
num_1 = 10
num_2 = 0
divide(num_1, num_2)
# output
ERROR : root : 2019-09-20 13:02:14,990 : Trying to Divide a number by Zero.
There are two ways of capturing the exception trace:
- Using logging.error() with an argument ‘exc_info=True’.
- Using logging.exception().
logging.error('Trying to Divide a number by Zero.', exc_info=True)
logging.exception('Trying to Divide a number by Zero.')
ERROR : root : 2019-09-20 15:13:49,277 : Trying to Divide a number by Zero.
Traceback (most recent call last):
File "/Users/uditvashisht/newprojects/utility/python_logging.py", line 11, in divide
return x / y
ZeroDivisionError: division by zero
So, now you know almost everything about python logging module. Ditch the print() statement for debugging and jump into logging.
If you have liked our tutorial, there are various ways to support us, the easiest is to share this post. You can also follow us on facebook, twitter and youtube.
In case of any query, you can leave the comment below.
If you want to support our work. You can do it using patreon.