log-with-context: Enrich your Python logging messages

Preserve debugging information up and down the call stack.

May 18, 2021

At Neocrym, we love logging.

Occasionally we want to emit log messages from somewhere deep in our call stack—but paired with information from higher up in the call stack.

We wrote log-with-context to help keep track the context surrounding our Python log messages. If you want to use log-with-context:

Releases are available on PyPI
Source code and issues are on GitHub
Or just install it with pip3 install log-with-context

How log-with-context works

log-with-context pushes/pops context values in/out of Python thread-local storage, emitting them as extra fields in the Python logger.

There are various third-party Python logging libraries that claim to solve this problem, but many of them pose a heavier runtime cost than necessary. We wrote log-with-context to be fast and delightfully minimal.

You will still need your own logging formatter to actually display the stored context fields. At Neocrym, we use the JSON-log-formatter library. Here is an example of how to use both libraries together:

        
import logging
import logging.config

from log_with_context import add_logging_context, Logger

logging.config.dictConfig({
    "version": 1,
    "disable_existing_loggers": True,
    "formatters": {
        "json": {"()": "json_log_formatter.JSONFormatter"},
    },
    "handlers": {
        "console": {
            "formatter": "json",
            "class": "logging.StreamHandler",
        }
    },
    "loggers": {
        "": {"handlers": ["console"], "level": "INFO"},
    },
})

LOGGER = Logger(__name__)

LOGGER.info("First message. No context")

with add_logging_context(current_request="hi"):
    LOGGER.info("Level 1")

    with add_logging_context(more_info="this"):
        LOGGER.warning("Level 2")

    LOGGER.info("Back to level 1")

LOGGER.error("No context at all...")

view raw main.py hosted with ❤ by GitHub

And the resulting log messages (in JSON) are:

{"message": "First message. No context", "time": "2021-04-08T16:37:23.126099"} {"current_request": "hi", "message": "Level 1", "time": "2021-04-08T16:37:23.126336"}

{"current_request": "hi", "more_info": "this", "message": "Level 2", "time": "2021-04-08T16:37:23.126389"}  

{"current_request": "hi", "message": "Back to level 1", "time": "2021-04-08T16:37:23.126457"} {"message": "No context at all...", "time": "2021-04-08T16:37:23.126514"}

If you end up using log-with-context, let us know what you think.

Neocrym Tech Blog

log-with-context: Enrich your Python logging messages

Preserve debugging information up and down the call stack.

How log-with-context works