Support for contextvars

[ryanhiebert]

Does structlog have support for contextvars similar to threadlocal?

They are new to Python 3.7, with a backport package available for Python 3.6 and 3.5, and IIUC correctly they are a reasonable replacement for threadlocal even when thread-local is the only requirement, but they also support async functions that would be run in the same thread.

http://www.structlog.org/en/stable/thread-local.html
https://docs.python.org/3/library/contextvars.html
https://github.com/MagicStack/contextvars

[hynek]

I would love to have support for them and I thought about it, and I think it wouldn't be that hard. But I didn't get around to actually write it because I tend to pass around loggers instead myself.

[ryanhiebert]

Makes sense. Logging is one of the few places globals seems like a pretty good fit to me. Passing around loggers has annoyed me, but to each their own 😄

[decaz]

Tell me please what kind of support for contextvars do you mean and why? I thought it works pretty well out of the box..

test.py:

import asyncio
import contextvars

import structlog

logger = structlog.get_logger()
logger_var = contextvars.ContextVar('logger')


async def f(x):
    log = logger_var.get()
    log = log.bind(x=x)
    await asyncio.sleep(0.1)
    log.info('Done')


async def task(i):
    log = logger.bind(i=i)
    logger_var.set(log)
    for x in range(5):
        await f(x)


async def main():
    tasks = [task(i) for i in range(2)]
    await asyncio.gather(*tasks)


asyncio.run(main())

Results:

$ python test.py
2019-03-24 17:30.52 Done                           i=0 x=0
2019-03-24 17:30.52 Done                           i=1 x=0
2019-03-24 17:30.52 Done                           i=0 x=1
2019-03-24 17:30.52 Done                           i=1 x=1
2019-03-24 17:30.52 Done                           i=0 x=2
2019-03-24 17:30.52 Done                           i=1 x=2
2019-03-24 17:30.52 Done                           i=0 x=3
2019-03-24 17:30.52 Done                           i=1 x=3
2019-03-24 17:30.53 Done                           i=0 x=4
2019-03-24 17:30.53 Done                           i=1 x=4

[ryanhiebert]

I am pretty new to all of this, so I was just comparing it to the extra capabilities given for threadlocal, and anticipating something similar might be a good idea. What you wrote makes sense to me, though, to just have a logger as a contextvar. I'm not sure if additional handling might be need for greenlets, which the threadlocal stuff has IIRC.

[decaz]

That's all right. I've gave the asynchronous example (and it's only case where I use structlog), - maybe @hynek meant synchrounous support of contextvars as it done for thread-local because structlog doesn't work yet there.

[ryanhiebert]

I think this is a little beyond my comprehension ATM, but if you're saying that contextvars and structlog don't mix outside of async, then that would be exactly the problem I'd want to try to solve, because I'm looking to use contextvars in a library that I'd like to be compatible with threads as well as async.

[hynek]

Hm so the main question is what you actually expect.

Adding something like threadlocals should be quite easy. You create a contextvar and write yourself a context type that stores the context in said variable. That's a bunch of copy pasta from the threadlocal module at worst.

But it sounds like y'all would like to have async processors?

[ryanhiebert]

Sorry, I am pretty ignorant on this one. My goals didn't go any further than "I want to make my code support threads, but there's this new contextvars things that's supposed to be compatible with async as well", and then seeing that you've got some special handling for threadlocal, and thinking it might need something similar.

[nealedj]

FYI I ended up hacking it in:

import contextlib
import uuid
from contextvars import ContextVar

from structlog.threadlocal import _ThreadLocalDictWrapper

_LOGGING_CTX = ContextVar('LOGGING_CTX', default=None)


class ContextLocal:
    """
    A dict-like object that can be used like a threadlocal but
    which stores its state in a context var
    """
    def __getattr__(self, name):
        return _LOGGING_CTX.get() or {}

    def __setattr__(self, name, val):
        state = _LOGGING_CTX.get() or {}
        state[name] = val
        _LOGGING_CTX.set(state)

    def __delattr__(self, name):
        state = _LOGGING_CTX.get() or {}
        if name in state:
            del state[name]
        _LOGGING_CTX.set(state)

    def update(self, *args, **kw):
        state = _LOGGING_CTX.get() or {}
        state.update(*args, **kw)
        _LOGGING_CTX.set(state)

    def copy(self):
        return _LOGGING_CTX.get() or {}


def wrap_dict(dict_class):
    """
    Wrap a dict-like class and return the resulting class.
    The wrapped class and used to keep global in the current context.
    :param type dict_class: Class used for keeping context.
    :rtype: `type`
    """
    Wrapped = type(
        "WrappedDict-" + str(uuid.uuid4()), (_ContextLocalDictWrapper,), {}
    )
    Wrapped._tl = ContextLocal()
    Wrapped._dict_class = dict_class
    return Wrapped


class _ContextLocalDictWrapper(_ThreadLocalDictWrapper):
    @property
    def _dict(self):
        """
        Return or create and return the current context.
        """
        return self.__class__._tl

I'm sure it can be implemented better than that but it seemed to do the trick for me.

[hynek]

Have you considered a more lightweight approach like #225?

[MarkusH]

Shouldn't something like this do the job?

import contextvars

_CONTEXT = contextvars.ContextVar('context')

def merge_context(logger, method_name, event_dict):
    context = _get_context().copy()
    context.update(event_dict)
    return context

def clear_context():
    _CONTEXT.context = {}

def bind_context(**kwargs):
    _get_context().update(kwargs)

def unbind_context(*args):
    ctx = _get_context()
    for key in args:
        ctx.pop(key, None)

def _get_context():
    try:
        return _CONTEXT.get()
    except LookupError:
        _CONTEXT.set({})
        return _CONTEXT.get()

[hynek]

Roughly yes! Happy to merge and quick release if someone wants to get it into shape.