Context Variables

The contextvars module in the Python standard library allows having a global structlog context that is local to the current execution context. The execution context can be thread-local if using threads, stored in the asyncio event loop, or greenlet respectively.

For example, you may want to bind certain values like a request ID or the peer’s IP address at the beginning of a web request and have them logged out along with the local contexts you build within our views.

For that structlog provides the structlog.contextvars module with a set of functions to bind variables to a context-local context. This context is safe to be used both in threaded as well as asynchronous code.

Warning

Since the storage mechanics of your context variables is different for each concurrency method, they are isolated from each other.

This can be a problem in hybrid applications like those based on starlette (this includes FastAPI) where context variables set in a synchronous context don’t appear in logs from an async context and vice versa.

The general flow is:

We’re sorry the word context means three different things in this itemization depending on … context.

>>> from structlog.contextvars import (
...     bind_contextvars,
...     bound_contextvars,
...     clear_contextvars,
...     merge_contextvars,
...     unbind_contextvars,
... )
>>> from structlog import configure
>>> configure(
...     processors=[
...         merge_contextvars,
...         structlog.processors.KeyValueRenderer(key_order=["event", "a"]),
...     ]
... )
>>> log = structlog.get_logger()
>>> # At the top of your request handler (or, ideally, some general
>>> # middleware), clear the contextvars-local context and bind some common
>>> # values:
>>> clear_contextvars()
>>> bind_contextvars(a=1, b=2)
{'a': <Token var=<ContextVar name='structlog_a' default=Ellipsis at ...> at ...>, 'b': <Token var=<ContextVar name='structlog_b' default=Ellipsis at ...> at ...>}
>>> # Then use loggers as per normal
>>> # (perhaps by using structlog.get_logger() to create them).
>>> log.info("hello")
event='hello' a=1 b=2
>>> # Use unbind_contextvars to remove a variable from the context.
>>> unbind_contextvars("b")
>>> log.info("world")
event='world' a=1
>>> # You can also bind key-value pairs temporarily.
>>> with bound_contextvars(b=2):
...    log.info("hi")
event='hi' a=1 b=2
>>> # Now it's gone again.
>>> log.info("hi")
event='hi' a=1
>>> # And when we clear the contextvars state again, it goes away.
>>> # a=None is printed due to the key_order argument passed to
>>> # KeyValueRenderer, but it is NOT present anymore.
>>> clear_contextvars()
>>> log.info("hi there")
event='hi there' a=None

Support for contextvars.Token

If, for example, your request handler calls a helper function that needs to temporarily override some contextvars before restoring them back to their original values, you can use the Tokens returned by bind_contextvars() along with reset_contextvars() to accomplish this (much like how contextvars.ContextVar.reset() works):

def foo():
    bind_contextvars(a=1)
    _helper()
    log.info("a is restored!")  # a=1

def _helper():
    tokens = bind_contextvars(a=2)
    log.info("a is overridden")  # a=2
    reset_contextvars(**tokens)

Example: Flask and thread-local data

Let’s assume you want to bind a unique request ID, the URL path, and the peer’s IP to every log entry by storing it in thread-local storage that is managed by context variables:

import logging
import sys
import uuid

import flask

from .some_module import some_function

import structlog

logger = structlog.get_logger()
app = flask.Flask(__name__)

@app.route("/login", methods=["POST", "GET"])
def some_route():
    # You would put this into some kind of middleware or processor so it's set
    # automatically for all requests in all views.
    structlog.contextvars.clear_contextvars()
    structlog.contextvars.bind_contextvars(
        view=flask.request.path,
        request_id=str(uuid.uuid4()),
        peer=flask.request.access_route[0],
    )
    # End of belongs-to-middleware.

    log = logger.bind()
    # do something
    # ...
    log.info("user logged in", user="test-user")
    # ...
    some_function()
    # ...
    return "logged in!"


if __name__ == "__main__":
    logging.basicConfig(
        format="%(message)s", stream=sys.stdout, level=logging.INFO
    )
    structlog.configure(
        processors=[
            structlog.contextvars.merge_contextvars,  # <--!!!
            structlog.processors.KeyValueRenderer(
                key_order=["event", "view", "peer"]
            ),
        ],
        logger_factory=structlog.stdlib.LoggerFactory(),
    )
    app.run()

some_module.py:

from structlog import get_logger

logger = get_logger()

def some_function():
    # ...
    logger.error("user did something", something="shot_in_foot")
    # ...

This would result among other the following lines to be printed:

event='user logged in' view='/login' peer='127.0.0.1' user='test-user' request_id='e08ddf0d-23a5-47ce-b20e-73ab8877d736'
event='user did something' view='/login' peer='127.0.0.1' something='shot_in_foot' request_id='e08ddf0d-23a5-47ce-b20e-73ab8877d736'

As you can see, view, peer, and request_id are present in both log entries.