Learn About Simple Python Logging

By | February 17, 2017

Logging can offer much more flexibility than simply printing a message to the console but it can be difficult to know where to start. This post looks a some examples of simple python logging to get you started.

Why ‘log’ instead of ‘print’?

Printing to the console is usually one of the first things you learn with any language. It’s easy to use ‘print()‘ to give messages to your users, display debugging for you, and output error messages and warnings.

But it’s also easy to get in a muddle with commenting and uncommenting print statements when you are trying to debug.

Instead of using print we can use logging which allows us to:

  • specify different levels of message,
  • control when messages are logged
  • direct outputs to files, screen, and elsewhere

The standard module for logging in python is called ‘logging‘. Below are some simple examples of how you could use logging if you haven’t used it before.

Read more about good logging practice in python

Simple logging in python

A Simple Example

Logging can be very simple. This example shows how by just importing the logging module and setting the logging level you can do everything that you were previously doing with print, but with greater flexibility.

import logging
# Set the logging level to log all messages 'debug' and higher

# Write log messages at different levels
logging.debug("write this to the log - debug")
logging.info("write this to the log - info")
logging.error("write this to the log - error")
logging.warning("write this to the log - warning")
logging.critical("write this to the log - critical")

Which will print the following output:

DEBUG:root:save this to the log - debug
INFO:root:save this to the log - info
ERROR:root:save this to the log - error
WARNING:root:save this to the log - warning
CRITICAL:root:save this to the log - critical

For normal use, you will probably want the logging level set to ‘info’ or perhaps ‘warning’, and go to ‘debug’ when you want see debugging messages.

Now, rather than commenting and uncommenting print statements, we can just use different levels of logging.

Logging Levels

When you send messages to the logger, you specify their level. This esssentially means that you can filter out messages depending on their logging level. For example it’s unlikely that you would want to print out the results of each iteration of a loop during normal use, but this can be very useful for debugging.

Logging Level
Use it for
Debug Instead of having a print statement that you comment out, you use the debugging logging level. Examples might include showing the index and values in a loop, or checking that a variable stores the value you expect.
Info You can use this logging level for things like printing messages to the user, returning results of functions that the user will want to see (i.e. not debugging info).
Warning You could I suppose just use ‘info’ for this. For important messages that the user may want to intervene on – e.g. incorrect login info, loading large files and so on
Error Use this when something goes wrong – can also be combined with exception handling.
Critical There probably aren’t all that many situations that warrant a ‘critical’ message over an ‘error’ message. This option is here nevertheless.

Output to file rather than the console

Often it is more useful to output the log to a separate log file, rather than to the console. This example will create a log file ‘example.log’, and save to it the same logging outputs as before.

import logging
LOG_FILENAME = 'example.log'
logging.debug("write this message to log file - debug")

Note: this will stop logging information being directed to the console. See below for how to have output to both the console and a file.

Adding a timestamp to the output

The basic logging does not include any date or timestamp of when the log was made. To add a timestamp was can set the formatting to the logging basicConfig:

import logging
format_string = '%(levelname)s: %(asctime)s: %(message)s'
logging.basicConfig(level=logging.DEBUG, filename="example.log", format=format_string)
logging.debug("write this to the log - debug")

Which will output the log message with the log level, the date and time, along with our message.

DEBUG: 2017-02-14 20:38:01,457   write this to the log - debug

Output to a file and the console

In the simple examples above we have had to chose between either output to the console, or output to a file. It is also possible to output to both the console and to a file. We’ll need to do a little be more set up for this, however.

The first difference is that we will create an instance of logging (called ‘logger’ in this case). Creating our logger object will give us the flexibility we need to set outputs for console and log files.

import logging
logging_format = '%(levelname)s: %(asctime)s: %(message)s'
logging.basicConfig(level=logging.DEBUG, format=logging_format)
logger = logging.getLogger()

# create a file handler
handler = logging.FileHandler('console_and_file.log')
# create a logging format
formatter = logging.Formatter(logging_format)
# add the handlers to the logger


logger.info("save this to the log")

Customise the logger further

Change the logging level

It’s quite common to want to be able to output a different level of detail to the console and the log file. It might be that we want all messages to go to the log file, but only the most important (say warning and above) to be directed to the screen. We may also want the log file to be timestamped, but the console output to not take a timestamp. We can do that by modifying the above example.

import logging
#set different formats for logging output
console_logging_format = '%(levelname)s:  %(message)s'
file_logging_format = '%(levelname)s: %(asctime)s: %(message)s'

# configure logger
logging.basicConfig(level=logging.DEBUG, format=console_logging_format)
logger = logging.getLogger()
# create a file handler for output file
handler = logging.FileHandler('console_and_file.log')

# set the logging level for log file
# create a logging format
formatter = logging.Formatter(file_logging_format)

# add the handlers to the logger

# output logging messages
logger.info("save this to the log - info logger")
logger.debug("save this to the log - debug logger")
logger.error("save this to the log - error - logger")
logger.warning("save this to the log - warning - logger")
logger.critical("save this to the log - critical - logger")

The file output is now:

INFO: 2017-02-12 15:10:52,325   save this to the log - info logger
ERROR: 2017-02-12 15:10:52,328   save this to the log - error - logger
WARNING: 2017-02-12 15:10:52,329   save this to the log - warning - logger
CRITICAL: 2017-02-12 15:10:52,330   save this to the log - critical - logger

Which has a timestamp, but is not capturing the debug and info level messages.

The console output on the other hand is:

INFO:  save this to the log - info logger
DEBUG:  save this to the log - debug logger
ERROR:  save this to the log - error - logger
WARNING:  save this to the log - warning - logger
CRITICAL:  save this to the log - critical - logge

Which keeps the debug level info, but does not have a timestamp.