Introduction to Python’s logging library

  • Basic overview of Python’s logging system.
  • Explanation of how each logging module interact with each other.
  • Examples on how to use different types of logging configurations.
  • Things to look out for
  • Recommendations for better logging

The basics

At its simplest form a log message, in python is called a LogRecord, has a string (the message) and a level. The level can be:

  • CRITICAL: Any error that makes the application stop running.
  • ERROR: General error messages.
  • WARNING: General warning messages.
  • INFO: General informational messages.
  • DEBUG: Any messages needed for debugging.
  • NOTSET: Default level used in handlers to process any of the above types of messages.
  • Loggers: the object that implements the main logging API. We use a logger to create logging events by using the corresponding level method, e.g.my_logger.debug("my message"). By default there's a root logger which can be configured usingbasicConfig and we can also createcustom loggers.
  • Formatters: these objects are in charge of creating the correct representation of the logging event. Most of the time we ant to create a human-readable representation but in some cases we can output a specific format like a json object.
  • Filters: We can use filters to avoid printing logging events based on more complicated criteria than logging levels. We can also use filters to modify logging events.
  • Handlers: everything comes together in the handlers. A handler defines which formatters and filter a logger is going to use. A handler is also in charge of sending the loging output to the corresponding place, this could bestdout, email or almost anythihg else we can think of.
This reminds me of a cake
import logging

logging.warning("Warning log message.")
WARNING:root:Warning log message.

What is basicConfig?

To quickly configure any loggers used in your application you can use basicConfig. This method will by default configure the root logger with a StreamHandler to print log messages to stdout and a default formatter (like the one in the example above).

import logging
logging.basicConfig(
format="[%(levelname)s]:%(lineno)s - %(message)s",
level=logging.DEBUG
)
[CRITICAL]:9 - Critical log message.
[ERROR]:10 - Error log message.
[WARNING]:11 - Warning log message.
[INFO]:12 - Info log message.
[DEBUG]:13 - Debug log message.

Custom Loggers

Python’s logging library allow us to create custom loggers which will always be children of the root logger.

+ app # main logger
|
+ app.api # api logger, child of "app" logger
|
- app.api.routes # routes logger, child of "app" and "app.api" loggers
|
- app.api.models # models logger, sibling of "app.api.routes" logger
|
- app.utils # utils logger, sibling of "app.api" logger

How to configure loggers, formatters, filters and handlers

We’ve talked about using basicConfig to configure a logger but there are other ways to configure loggers. The recommended way of creating a logging configuration is using adictConfig. The examples in this article will be using dictConfig .

Python logging flow simplified

  • The diagram above is from the point of view of the logger used.
  • Filters, handlers and formatters are defined once and can be used multiple times.
  • Only the filters and formatters assigned to the parent’s handler are applied to theLogRecord (this is the loop that says "Parent Loggers*")
  1. The logger or the handler configured in the logger are not enabled for the log level used.
  2. A filter configured in the logger or the handler rejects the log event.
  3. A child logger has propagate=False causing events not to be passed to any of the parent loggers.
  4. Your are using a different logger or the logger is not a parent of the one being used.

Formatters

A formatter object transforms a LogRecord instance into a human readable string or a string that will be consumed by an external service. We can use anyLogRecord attribute or anything sent in the logging call as the extra parameter.

# app.api.UserManager.list_users

LOG.info(
"Listing users",
extra={"session_key": session_key, "user_id": user_id}
)
[APP] INFO 2020-11-07 20:47:00,123 user_manager app.api.user_name.list_users:15 [123abcd:api_usr] Listing users

Filters

Filters are very interesting. They can be used both at the logger level or at the handler level, they can be used to stop certain log events from being logged and they can also be used to inject additional context into a LogRecord instance which will be, eventually, logged.

+ app.models
| |
| - app.models.users
|
+ app.views
|
- app.views.users
|
- app.views.products
def custom_filter(record):
"""Filter out records that passes a specific key argument"""

# We can access the log event's argument via record.args
return record.args.get("instrumentation") == "console"

Handlers

Handlers are objects that implement how formatters and filters are used. if we remember the flow diagram we can see that whenever we use a logger the handlers of all the parent loggers are going to be called recursivley. This is where the entire picture comes together and we can take a look at a complete loggin configuration using everything else we’ve talked about.

Full logging configuration example

# app.models.client

import logging

LOG = logging.getLogger(__name__)

class Client:
# ...
# app.__main__import logging
from app.settings.logging import LOGGING_CONFIG # A dictionary
from app.models import Client
logging.config.dictConfig(LOGGING_CONFIG)

Things to lookout for when configuring your loggers

  • Filters can be set both to Loggers and Handlers. If a filter is set at the logger level it will only be used when that specific logger is used and not when any of its descendants are used.
  • File config is still support purely for backwards compatibility. Avoid using file config.
  • () can be used in config dictionaries to specify a custom class/callable to use as formatter, filter or handler. It's assumed a factory is referenced when using() to allow for complete initialization control.
  • Go over the list of cases when a log event is not processed if you don’t see what you expect in your logs.
  • Make sure to set disable_existing_loggers to False when using dict config and creating loggers at the module level.

Recommendations for better logging

  • Take some time to plan how your logs should look like and where are they going to be stored.
  • Make sure your logs are easily parsable both visually and programmatically, like using grep.
  • Most of the time you don’t need to set a filter at the logger level.
  • Filters can be used to add extra context to log events. Make sure any custom filters are fast. In case your filters do external calls consider using a queue handler
  • Log more than errors. Make sure whenever you see an error in the logs you can trace back the state of the data in the logs as well.
  • If you are developing a library, always set a NullHandler handler and let the user define the logging configuration.
  • Use the handlers already offered by Python’s logging library unless is a very special case. Most of the time you can hand off the logs and then process them with a more specialized tool. For example, send logs to syslog using syslogHandler handler and then usersyslog to maintain your logs.
  • Create a new logger using the module’s name to avoid collisions, logging.getLogger(__name__)

--

--

Get the Medium app

A button that says 'Download on the App Store', and if clicked it will lead you to the iOS App store
A button that says 'Get it on, Google Play', and if clicked it will lead you to the Google Play store