Fix #201 - Add support for contextvars

conftest.py

@@ -6,6 +6,8 @@
 
 from __future__ import absolute_import, division, print_function
 
+import sys
+
 import pytest
 
 from six.moves import cStringIO as StringIO
@@ -30,3 +32,8 @@ def __repr__(self):
             return r"<A(\o/)>"
 
     return {"a": A(), "b": [3, 4], "x": 7, "y": "test", "z": (1, 2)}
+
+
+collect_ignore = []
+if sys.version_info[:2] < (3, 7):
+    collect_ignore.extend(["tests/test_contextvars.py"])

docs/contextvars.rst

@@ -0,0 +1,70 @@
+.. _contextvars:
+
+contextvars
+===========
+
+.. testsetup:: *
+
+   import structlog
+
+.. testcleanup:: *
+
+   import structlog
+   structlog.reset_defaults()
+
+Historically, ``structlog`` only supported thread-local context binding.
+With the introduction of ``contextvars`` in Python 3.7, there is now a way of having a global context that is local to the current context and even works in concurrent code.
+
+The ``merge_context_local`` Processor
+-------------------------------------
+
+``structlog`` provides a set of functions to bind variables to a context-local context.
+This context is safe to be used in asynchronous code.
+The functions are:
+
+- :func:`structlog.contextvars.merge_context_local`,
+- :func:`structlog.contextvars.clear_context_local`,
+- :func:`structlog.contextvars.bind_context_local`,
+- :func:`structlog.contextvars.unbind_context_local`,
+
+The general flow of using these functions is:
+
+- Use :func:`structlog.configure` with :func:`structlog.contextvars.merge_context_local` as your first processor.
+- Call :func:`structlog.contextvars.clear_context_local` at the beginning of your request handler (or whenever you want to reset the context-local context).
+- Call :func:`structlog.contextvars.bind_context_local` and :func:`structlog.contextvars.unbind_context_local` instead of :func:`structlog.BoundLogger.bind` and :func:`structlog.BoundLogger.unbind` when you want to (un)bind a particular variable to the context-local context.
+- Use ``structlog`` as normal.
+  Loggers act as the always do, but the :func:`structlog.contextvars.merge_context_local` processor ensures that any context-local binds get included in all of your log messages.
+
+.. doctest::
+
+   >>> from structlog.contextvars import (
+   ...     bind_context_local,
+   ...     clear_context_local,
+   ...     merge_context_local,
+   ...     unbind_context_local,
+   ... )
+   >>> from structlog import configure
+   >>> configure(
+   ...     processors=[
+   ...         merge_context_local,
+   ...         structlog.processors.KeyValueRenderer(),
+   ...     ]
+   ... )
+   >>> log = structlog.get_logger()
+   >>> # At the top of your request handler (or, ideally, some general
+   >>> # middleware), clear the threadlocal context and bind some common
+   >>> # values:
+   >>> clear_context_local()
+   >>> bind_context_local(a=1, b=2)
+   >>> # Then use loggers as per normal
+   >>> # (perhaps by using structlog.get_logger() to create them).
+   >>> log.msg("hello")
+   a=1 b=2 event='hello'
+   >>> # Use unbind_context_local to remove a variable from the context
+   >>> unbind_context_local("b")
+   >>> log.msg("world")
+   a=1 event='world'
+   >>> # And when we clear the threadlocal state again, it goes away.
+   >>> clear_context_local()
+   >>> log.msg("hi there")
+   event='hi there'

docs/index.rst

@@ -31,6 +31,7 @@ Basics
    loggers
    configuration
    thread-local
+   contextvars
    processors
    examples
    development

setup.py

@@ -39,6 +39,7 @@
         "freezegun>=0.2.8",
         "pretend",
         "pytest>=3.3.0",
+        "pytest-asyncio; python_version>='3.7'",
         "python-rapidjson; python_version>='3.6'",
         "simplejson",
     ],

src/structlog/contextvars.py

@@ -0,0 +1,68 @@
+# This file is dual licensed under the terms of the Apache License, Version
+# 2.0, and the MIT License.  See the LICENSE file in the root of this
+# repository for complete details.
+
+"""
+Primitives to deal with a concurrency supporting context, as introduced in
+Python 3.7 as ``contextvars``.
+"""
+
+from __future__ import absolute_import, division, print_function
+
+import contextvars
+
+
+_CONTEXT = contextvars.ContextVar("structlog_context")
+
+
+def merge_context_local(logger, method_name, event_dict):
+    """
+    A processor that merges in a global (context-local) context.
+
+    Use this as your first processor in :func:`structlog.configure` to ensure
+    context-local context is included in all log calls.
+    """
+    ctx = _get_context().copy()
+    ctx.update(event_dict)
+    return ctx
+
+
+def clear_context_local():
+    """
+    Clear the context-local context.
+
+    The typical use-case for this function is to invoke it early in request-
+    handling code.
+    """
+    ctx = _get_context()
+    ctx.clear()
+
+
+def bind_context_local(**kwargs):
+    """
+    Put keys and values into the context-local context.
+
+    Use this instead of :func:`~structlog.BoundLogger.bind` when you want some
+    context to be global (context-local).
+    """
+    _get_context().update(kwargs)
+
+
+def unbind_context_local(*args):
+    """
+    Remove keys from the context-local context.
+
+    Use this instead of :func:`~structlog.BoundLogger.unbind` when you want to
+    remove keys from a global (context-local) context.
+    """
+    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()

tests/test_contextvars.py

@@ -0,0 +1,135 @@
+# This file is dual licensed under the terms of the Apache License, Version
+# 2.0, and the MIT License.  See the LICENSE file in the root of this
+# repository for complete details.
+
+import pytest
+
+from structlog.contextvars import (
+    bind_context_local,
+    clear_context_local,
+    merge_context_local,
+    unbind_context_local,
+)
+
+
+# All test coroutines will be treated as marked.
+pytestmark = pytest.mark.asyncio
+
+
+class TestNewContextvars(object):
+    async def test_bind(self, event_loop):
+        """
+        Binding a variable causes it to be included in the result of
+        merge_context_local.
+        """
+
+        async def coro():
+            bind_context_local(a=1)
+            return merge_context_local(None, None, {"b": 2})
+
+        assert {"a": 1, "b": 2} == await event_loop.create_task(coro())
+
+    async def test_multiple_binds(self, event_loop):
+        """
+        Multiple calls to bind_context_local accumulate values instead of
+        replacing them. But they override redefined ones.
+        """
+
+        async def coro():
+            bind_context_local(a=1, c=3)
+            bind_context_local(c=333, d=4)
+            return merge_context_local(None, None, {"b": 2})
+
+        assert {
+            "a": 1,
+            "b": 2,
+            "c": 333,
+            "d": 4,
+        } == await event_loop.create_task(coro())
+
+    async def test_nested_async_bind(self, event_loop):
+        """
+        Context is passed correctly between "nested" concurrent operations.
+        """
+
+        async def coro():
+            bind_context_local(a=1)
+            await event_loop.create_task(nested_coro())
+            return merge_context_local(None, None, {"b": 2})
+
+        async def nested_coro():
+            bind_context_local(c=3)
+
+        assert {"a": 1, "b": 2, "c": 3} == await event_loop.create_task(coro())
+
+    async def test_merge_works_without_bind(self, event_loop):
+        """
+        merge_context_local returns values as normal even when there has
+        been no previous calls to bind_context_local.
+        """
+
+        async def coro():
+            return merge_context_local(None, None, {"b": 2})
+
+        assert {"b": 2} == await event_loop.create_task(coro())
+
+    async def test_merge_overrides_bind(self, event_loop):
+        """
+        Variables included in merge_context_local override previously bound
+        variables.
+        """
+
+        async def coro():
+            bind_context_local(a=1)
+            return merge_context_local(None, None, {"a": 111, "b": 2})
+
+        assert {"a": 111, "b": 2} == await event_loop.create_task(coro())
+
+    async def test_clear(self, event_loop):
+        """
+        The context-local context can be cleared, causing any previously bound
+        variables to not be included in merge_context_local's result.
+        """
+
+        async def coro():
+            bind_context_local(a=1)
+            clear_context_local()
+            return merge_context_local(None, None, {"b": 2})
+
+        assert {"b": 2} == await event_loop.create_task(coro())
+
+    async def test_clear_without_bind(self, event_loop):
+        """
+        The context-local context can be cleared, causing any previously bound
+        variables to not be included in merge_context_local's result.
+        """
+
+        async def coro():
+            clear_context_local()
+            return merge_context_local(None, None, {})
+
+        assert {} == await event_loop.create_task(coro())
+
+    async def test_undbind(self, event_loop):
+        """
+        Unbinding a previously bound variable causes it to be removed from the
+        result of merge_context_local.
+        """
+
+        async def coro():
+            bind_context_local(a=1)
+            unbind_context_local("a")
+            return merge_context_local(None, None, {"b": 2})
+
+        assert {"b": 2} == await event_loop.create_task(coro())
+
+    async def test_undbind_not_bound(self, event_loop):
+        """
+        Unbinding a not bound variable causes doesn't raise an exception.
+        """
+
+        async def coro():
+            unbind_context_local("a")
+            return merge_context_local(None, None, {"b": 2})
+
+        assert {"b": 2} == await event_loop.create_task(coro())

tox.ini

@@ -50,7 +50,7 @@ commands = coverage run --parallel -m pytest {posargs}
 deps = twisted
 setenv =
     PYTHONHASHSEED = 0
-commands = coverage run --parallel -m pytest {posargs}
+commands = coverage run --parallel -m pytest --ignore=tests/test_contextvars.py {posargs}
 
 
 [testenv:py27-colorama]
@@ -59,7 +59,7 @@ deps =
    twisted
 setenv =
     PYTHONHASHSEED = 0
-commands = coverage run --parallel -m pytest {posargs}
+commands = coverage run --parallel -m pytest --ignore=tests/test_contextvars.py {posargs}
 
 
 [testenv:docs]