Logging is essential when we need to diganose problems in our code. I used to print all my debugging statements. Well, it works for small scripts but it’s really hard to scale for larger applications.

Python has a built-in module logging to structure our logs. It’s really easy to configure and use. This helps to solve a small part of the problem.

Getting Start with Python logging

The simplest way to start is to import logging module in your code.

#!/usr/bin/python3
import logging
logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)

logger.info("Hello World")
logger.critical("Hello World")
logger.warning("Hello World")
logger.error("Hello World")

Basically, we setup a basic configuration to start logging. The line level=logging.INFO says that we are going to log anything that is above the INFO level.

We can write both user and debugging statements at this level but it’s not going to be very useful if we have tonnes of logs.

What we can do is to configure our logging level to DEBUG.

logging.basicConfig(level=logging.DEBUG)

Then, we can configure to write all the DEBUG messages and ERROR messages to different file stream. This helps us to differentiate the type of messages for different use cases. For instance, if you want to trace back the error logs, you can view the error.log.

import logging
logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)

handler = logging.FileHandler("debug.log")
handler.setLevel(logging.DEBUG)

logger.addHandler(handler)

handler = logging.FileHandler("error.log")
handler.setLevel(logging.ERROR)

logger.addHandler(handler)

This is very useful when you are dealing with tremendous amount of logs. You can also pretty print the log output so that you can identify the source of the message:

import logging
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

# create ouput to stdoutput at ERROR level
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)

# create a format for that
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(formatter)

logger.addHandler(ch)

logger.error("Hello World")

This is what you will get on your screen: 2017-12-23 10:31:49,624 - __main__ - ERROR - Hello World

Much better, isn’t it?

Getting Started With structlog and pythonjsonlogger

I use structlog very often to structure my log format. Imagine you have 2 logging variables, error_code and error_msg. You can use this library to add them like normal variables.

from structlog import get_logger
log = get_logger()
log.info("log for fun", error_code=0, error_msg="for fun")

This is the output: 2017-12-23 10:36.54 log for fun error_code=0 error_msg=for fun

Sometimes it might be necessary to output your logs into json or dict format.

By default, logging does not support such format. One can argue that you can do it through the formatter but I will prefer to have modules to do it for me easily.

Imagine you have to create a dict for every type of logging that you want to do in your project, I think you will take more time formatting your log than to write your actual debugging messages.

I used python-json-logger to format my structlog messages with its JSON formatter.

from pythonjsonlogger import jsonlogger
import structlog
import logging

# configure structlog to render logging-based Formatter
structlog.configure(
    processors=[
        structlog.stdlib.filter_by_level,
        structlog.stdlib.add_logger_name,
        structlog.stdlib.add_log_level,
        structlog.stdlib.PositionalArgumentsFormatter(),
        structlog.processors.StackInfoRenderer(),
        structlog.processors.format_exc_info,
        structlog.processors.UnicodeDecoder(),
        structlog.stdlib.render_to_log_kwargs,
    ],
    context_class=dict,
    logger_factory=structlog.stdlib.LoggerFactory(),
    wrapper_class=structlog.stdlib.BoundLogger,
    cache_logger_on_first_use=True,
)

# configure logging formatter just like before with python-json-logger's formatter
handler = logging.StreamHandler()
handler.setFormatter(jsonlogger.JsonFormatter())

logger = logging.getLogger()
logger.addHandler(handler)

structlog.get_logger("log for fun").warning("hello", error=0, type="for funs")

This is what you will get in the output screen:

{"message": "hello", "logger": "log for fun", "type": "for funs", "level": "warning", "error": 0}

The beauty of logging lies in your effort in making the output readable and useful. Hopefully this can help anyone who’s struggling to keep up their logs.