log-with-context: Enrich your Python logging messages

At Neocrym, we love logging. Occasionally we want to emit log messages from somewhere deep in our call stack—but paired with annotations from higher up in the call stack. I wrote log-with-context to help keep track of the context surrounding every log message. You can find log-with-context here on GitHub and PyPI. You can install it with the command 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 log-with-context alongside JSON-log-formatter

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.