Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

A newer, better thread-local API #225

Merged
merged 14 commits into from
Sep 23, 2019
4 changes: 3 additions & 1 deletion CHANGELOG.rst
Original file line number Diff line number Diff line change
Expand Up @@ -51,7 +51,9 @@ Changes:
So far, the configuration proxy, ``structlog.processor.TimeStamper``, ``structlog.BoundLogger``, ``structlog.PrintLogger`` and ``structlog.dev.ConsoleLogger`` have been made pickelable.
Please report if you need any another class ported.
`#126 <https://github.com/hynek/structlog/issues/126>`_

- Added a new thread-local API that allows binding values to a thread-local context explicitly without affecting the default behavior of ``bind()``.
`#222 <https://github.com/hynek/structlog/issues/222>`_,
`#225 <https://github.com/hynek/structlog/issues/225>`_,

----

Expand Down
6 changes: 6 additions & 0 deletions docs/api.rst
Original file line number Diff line number Diff line change
Expand Up @@ -77,6 +77,12 @@ API Reference

.. automodule:: structlog.threadlocal

.. autofunction:: merge_threadlocal_context

.. autofunction:: clear_threadlocal

.. autofunction:: bind_threadlocal

.. autofunction:: wrap_dict

.. autofunction:: tmp_bind(logger, **tmp_values)
Expand Down
52 changes: 51 additions & 1 deletion docs/thread-local.rst
Original file line number Diff line number Diff line change
Expand Up @@ -30,7 +30,57 @@ If you are willing to do that, you should stick to it because `immutable state <
Sooner or later, global state and mutable data lead to unpleasant surprises.

However, in the case of conventional web development, we realize that passing loggers around seems rather cumbersome, intrusive, and generally against the mainstream culture.
And since it's more important that people actually *use* ``structlog`` than to be pure and snobby, ``structlog`` contains a dirty but convenient trick: thread local context storage which you may already know from `Flask <http://flask.pocoo.org/docs/design/#thread-locals>`_:
And since it's more important that people actually *use* ``structlog`` than to be pure and snobby, ``structlog`` contains a couple of mechanisms to help here.


The ``merge_threadlocal_context`` processor
-------------------------------------------

``structlog`` provides a simple set of functions that allow explicitly binding certain fields to a global (thread-local) context.
These functions are :func:`structlog.threadlocal.merge_threadlocal_context`, :func:`structlog.threadlocal.clear_threadlocal`, and :func:`structlog.threadlocal.bind_threadlocal`.

The general flow of using these functions is:

- Use :func:`structlog.configure` with :func:`structlog.threadlocal.merge_threadlocal_context` as your first processor.
- Call :func:`structlog.threadlocal.clear_threadlocal` at the beginning of your request handler (or whenever you want to reset the thread-local context).
- Call :func:`structlog.threadlocal.bind_threadlocal` as an alternative to :func:`structlog.BoundLogger.bind` when you want to bind a particular variable to the thread-local context.
- Use ``structlog`` as normal.
Loggers act as the always do, but the :func:`structlog.threadlocal.merge_threadlocal_context` processor ensures that any thread-local binds get included in all of your log messages.

.. doctest::

>>> from structlog.threadlocal import (
... bind_threadlocal,
... clear_threadlocal,
... merge_threadlocal_context,
... )
>>> from structlog import configure
>>> configure(
... processors=[
... merge_threadlocal_context,
... 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_threadlocal()
>>> bind_threadlocal(a=1)
>>> # Then use loggers as per normal
>>> # (perhaps by using structlog.get_logger() to create them).
>>> log.msg("hi")
a=1 event='hi'
>>> # And when we clear the threadlocal state again, it goes away.
>>> clear_threadlocal()
>>> log.msg("hi there")
event='hi there'


Thread-local contexts
---------------------

``structlog`` also provides thread local context storage which you may already know from `Flask <http://flask.pocoo.org/docs/design/#thread-locals>`_:

Thread local storage makes your logger's context global but *only within the current thread*\ [*]_.
In the case of web frameworks this usually means that your context becomes global to the current request.
Expand Down
44 changes: 44 additions & 0 deletions src/structlog/threadlocal.py
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
from __future__ import absolute_import, division, print_function

import contextlib
import threading
import uuid

from structlog._config import BoundLoggerLazyProxy
Expand Down Expand Up @@ -162,3 +163,46 @@ def __len__(self):
def __getattr__(self, name):
method = getattr(self._dict, name)
return method


_CONTEXT = threading.local()


def merge_threadlocal_context(logger, method_name, event_dict):
"""
A processor that merges in a global (thread-local) context.

Use this as your first processor in :func:`structlog.configure` to ensure
thread-local context is included in all log calls.
"""
context = _get_context().copy()
context.update(event_dict)
return context


def clear_threadlocal():
"""
Clear the thread-local context.

The typical use-case for this function is to invoke it early in
request-handling code.
"""
_CONTEXT.context = {}


def bind_threadlocal(**kwargs):
"""
Put keys and values into the thread-local context.

Use this instead of :func:`~structlog.BoundLogger.bind` when you want some
hynek marked this conversation as resolved.
Show resolved Hide resolved
context to be global (thread-local).
"""
_get_context().update(kwargs)


def _get_context():
try:
return _CONTEXT.context
except AttributeError:
_CONTEXT.context = {}
return _CONTEXT.context
48 changes: 47 additions & 1 deletion tests/test_threadlocal.py
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,14 @@
from structlog._base import BoundLoggerBase
from structlog._config import wrap_logger
from structlog._loggers import ReturnLogger
from structlog.threadlocal import as_immutable, tmp_bind, wrap_dict
from structlog.threadlocal import (
as_immutable,
bind_threadlocal,
clear_threadlocal,
merge_threadlocal_context,
tmp_bind,
wrap_dict,
)


try:
Expand Down Expand Up @@ -262,3 +269,42 @@ def test_new_class(self, D):
The context of a new wrapped class is empty.
"""
assert 0 == len(D())


class TestNewThreadLocal(object):
def test_bind_and_merge(self):
hynek marked this conversation as resolved.
Show resolved Hide resolved
"""
Binding a variable causes it to be included in the result of
merge_threadlocal_context.
"""
bind_threadlocal(a=1)
assert {"a": 1, "b": 2} == merge_threadlocal_context(
None, None, {"b": 2}
)

def test_clear(self):
"""
The thread-local context can be cleared, causing any previously bound
variables to not be included in merge_threadlocal_context's result.
"""
bind_threadlocal(a=1)
clear_threadlocal()
assert {"b": 2} == merge_threadlocal_context(None, None, {"b": 2})

def test_merge_works_without_bind(self):
"""
merge_threadlocal_context returns values as normal even when there has
been no previous calls to bind_threadlocal.
"""
assert {"b": 2} == merge_threadlocal_context(None, None, {"b": 2})

def test_multiple_binds(self):
"""
Multiple calls to bind_threadlocal accumulate values instead of
replacing them.
"""
bind_threadlocal(a=1, b=2)
bind_threadlocal(c=3)
assert {"a": 1, "b": 2, "c": 3} == merge_threadlocal_context(
None, None, {"b": 2}
)