Power-Up Your Python Logging

A guide to take you from beginner to pro with Python’s built-in logging tools

David Tippett
Oct 29 · 6 min read

Debugging a large application sucks. Especially when you have a bug that shows itself in production but can’t be reproduced in the dev environment. Finding these can be made easier with the use of Python’s built-in logging tools.

This guide is designed to help newcomers understand Python’s logging module. Heaven knows it confused me when I first started. In the end, we will have a working logger that is able to throw errors to a discord channel.

The code for this problem can be found in the civicsoft/ieddit GitHub repository.


Quick Overview of Logging

One note before we get into logging: both loggers and handlers below use, what we call, levels. This is a hierarchy of how things are handled.

For example, when we set a handler to the DEBUG level, it will receive debug statements and all the levels above it. These levels are used to filter data by its importance.


Loggers

A logger is simply a named instance of the logging object. All loggers are “global” within your program. Here is an example of what that looks like.

We have defined a logger named app in app.py.

Now, if we wanted to, we could drop into another file and have access to that same logger instance we created before.

This is what that would look like:

Now the utils.py has access to that same logger instance! This means that we can declare all the loggers we want before they are ever needed, which we will see a little later.

Side note here: the best practice is to use the __name__ attribute for naming loggers like this: logging.getLogger(__name__). This way, each file has its own unique logger name.

Logger’s core job is to send LogRecords out to different handlers. LogRecords capture the details of what happened when they were called.

Above is an example of what it means to emit an event. Events are emitted with a level attached. This lets the logger know how urgent the LogRecord is.

The problem with the code above is that we haven’t told the logger where these records are supposed to go. This is where handlers step in.


Handlers

The handlers control where the LogRecords go. Handlers are standalone objects that can be attached to logger instances.

The above code is telling the logger that, any time a LogRecord is created, it should be sent to the file ieddit.log. The problem right now, is that ieddit.log will get stuffed with a ton of logs.

Setting the level that a handler is supposed to manage helps us filter down our logs.

Above is how we can use the level to filter out logs. Using the chart from the beginning of this section, we can see that ERROR is higher than WARNING so it will be handled. Info is below warning so the handler will ignore that record.

There are several types of handlers that can be used. For the complete list, see the documentation for handlers.

StreamHandler will send output to the console. File handlers send info to an output file. The most dynamic handlers are the QueueHandler and QueueListener, but more on those later.


Formatters

Only having a message saying: “There was an error” isn’t helpful. This is where the formatters come in. Formatters live on handlers as the handlers process the log records.

They can add additional information, such as where, what, why, when, and how.

Above is the output in the console that was created.

The formatter inserts the time, logger name, level of the record, and message. Note here we put __main__ in manually but if you use __name__ it will be the module name here.


Top to Bottom

This is what we know so far about logging.

First, we create a logger that can be accessed by its name anywhere. This logger creates log records with an associated level. Those records are handled by one or more of the handlers that are associated. If there is a formatter present the handler will format the output accordingly.


QueueHandler and QueueListener

Now here is where the real fun starts. Anytime you put logger.info(“message”) into your code, your program has to wait for that to finish.

Not a big problem if you are simply outputting to the console, right?

If you send logs to a database, waiting for the record to be created could take some time. Then, your program would need to pause every time a log record is created.

This is where the QueueHandler and QueueListener come in. QueueHandler puts the message in a queue that lives on a separate thread. Then, QueueListener steps in to send the log record to all the other handlers.

This way, your program doesn't have to stop to wait for the log record to be created.

Here, I will point you to Rob Blackbourn’s article, How to use Python logging QueueHandler with dictConfig. To save length here, I will tell you to read his article and come back here to see how this can be used in our custom logger.

Add the code from his article into a file named something like logging_util.py.

In the above example, the data will flow like this:

If the queue handler was not in place, the program would have to wait until the end to continue. This would consume valuable time if you are waiting for HTTP calls to resolve.


Custom Discord Handler

Now we can get into some of the more fun stuff. Ieddit.com has a Discord server. Because of how the site is set up, only the creator had access to the error logs that were put out by the website.

The only logical remedy was to have the errors output to a Discord channel. So that is what we have done. Some set up is required for this. See the discord-webhook’s documentation to configure.

The above code creates a class that extends the logging.Handler class. When it is initialized, it sets its webhook URL based on the config file. Then, when a record is emitted, it gets forwarded on to Discord.


Using a File to Initialize Loggers

The last thing to do is create a file to initialize all of our loggers. Creating them before they are needed saves us from duplicating code. We can create and attach all our loggers in one place.

Here is what a sample config file looks like. Note, for things such as classes, we use the module name as it is defined.

Next, we can use a logger_init.py file to grab all these components and generate the loggers.

With this fairly short bit of code, we can initialize all of the loggers and handlers that we want.

Then, to use them, we simply need to import the logger_init.py into our top-level file. Then, in all the others, we import logging and set our logger!

To see this code in action check out ieddit.com’s GitHub page, where all the samples are being utilized.

Thanks for reading and stay tuned for more Python and programming content. Special thanks again to Rob Blackbourn for allowing me to use his code in this post.

Better Programming

Advice for programmers.

David Tippett

Written by

A developer looking to find his way around this technical world.

Better Programming

Advice for programmers.

Welcome to a place where words matter. On Medium, smart voices and original ideas take center stage - with no ads in sight. Watch
Follow all the topics you care about, and we’ll deliver the best stories for you to your homepage and inbox. Explore
Get unlimited access to the best stories on Medium — and support writers while you’re at it. Just $5/month. Upgrade