Most developers start debugging by sprinkling print()
statements throughout the code. The issue is that the print()
will always run until you delete or comment out each line. With the logging
module a single setting can stop all or just parts of the debugging code.
Even production code there is a need to track events happening in an application. The logging
module gives a quick and simple process to start logging the application. The format of the output can easily be modified from a single point instead of try to find each logging statement.
The logging module comes preinstalled with Python. While it's simple to start using, the customizations that can be done make it a very powerful tool for both debugging and basic logging.
Logging to the terminal.
The default for logging
is to output a message to the console.
import logging
logging.warning('This is a warning')
The output is:
WARNING:root:This is a warning
Each level's method is used in the same way.
logging.debug('A debug message')
logging.info('An info message')
logging.warning('This is a warning')
logging.error('ERROR')
logging.critical('CRITICAL')
By default the level is set at WARNING
, only WARNING
, ERROR
and CRITICAL
will be displayed in the terminal.
Changing the Level
These are five logging levels:
Level | Numeric value |
CRITICAL | 50 |
ERROR | 40 |
WARNING | 30 |
INFO | 20 |
DEBUG | 10 |
NOTSET | 0 |
The numeric value will tell you the which levels will be logged at each setting. For if the level is set to WARNING
then WARNING
, ERROR
and CRITICAL
will be logged.
It is possible to set your own levels, but that's beyond the scope of this tutorial.
The logging.basicConfig()
method is used to setup the configuration. Using the level
attribute the logging level can be set by indicating which level to start at.
logging.basicConfig(level=logging.DEBUG)
Set at DEBUG
all messages will be logged. At CRITICAL
only that one level will be logged.
GOTCHA --> If you already used logging in any way, the logging.basicConfig
will not work. force=True
must be adding so it will overwrite the settings.
Like this:
logging.basicConfig(level=logging.DEBUG, force=True)
Logging to a file
Adding filename='example.log'
to the logging.basicConfig()
method will have logging append the message to that file.
logging.basicConfig(filename='example.log')
It is possible to change it back to the terminal or to change the file, but force=True
would need to be added to the logging.basicConfig()
method.
Clearing the log with each run
In some projects you don't want to append all the messages. The default that logging is using is filemode='a'
. Just like with the open()
method, changing it to filemode='w'
will clear the file each time the script is run.
logging.basicConfig(filename='example.log', filemode='w')
Logging variable data
We've got messages going out to the terminal and a file, now so far, it's just a single string. We need more information.
import logging
account = 'DRT'
country = 'Japan'
logging.warning('%s was stored in account and %s was stored in country', account, country)
Output:
WARNING:root:DRT was stored in account and Japan was stored in country
This is the old style of string formatting it has been kept for backwards compatibility. I mention this because if you work on older code bases, you may see this style of formatting. Notice that the variables that will be inserted into the formatting are added as arguments to the logging method.
logging.warning(f'{account} was stored in account and {country} was stored in country')
f
strings can also be used. This would have the same output.
Formating the messages
What if we wanted to format the messages globally? For example, maybe we want a timestamp in front of each message. We could go through and edit each logging statement. But there is a format option in the logging.basicConfig()
method that allows us to globally change the format of the message.
We're going to use logging's LogRecord Attributes. There are over twenty attributes that can be used to log many different pieces of information.
For this first example the logging format will be the time and then display the message provided during the logging call.
%(levelname)s
-> inserts the level of the logging%(asctime)s
-> inserts the time%(message)s
-> inserts the message provided when the logging method is called
import logging
logging.basicConfig(format='%(levelname)s %(asctime)s %(message)s')
logging.warning('is when this event was logged.')
output
WARNING 2021-12-16 04:28:15,474 is when this event was logged.
import logging
logging.basicConfig(format='%(levelname)s %(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p', force=True)
logging.warning('is when this event was logged.')
output:
WARNING 12/16/2021 04:31:26 AM is when this event was logged.
On from here
The logging module can be used differently in each module. A little planning at the start can give you a lot of flexibility on what each module will log out and where it logs out to.
One important thing to keep in mind is everyone on the team must agree on what type of messages are used on what level. An explanation of each level would be a great addition to any coding style guide that your team is using.