Add add_extra Processor function

This processor function will add extra attributres from LogRecord
objects to the event_dict, and can be useful for making values passed
in the extra parameter of the logging module's log methods pass through
to output as additional properties.

Fixes #209

CHANGELOG.rst

@@ -39,6 +39,9 @@ Changes:
 
 - Added the ``structlog.processors.LogfmtRenderer`` processor to render log lines using the `logfmt <https://brandur.org/logfmt>`_ format.
   `#376 <https://github.com/hynek/structlog/pull/376>`_
+- Added the ``structlog.stdlib.ExtraAdder`` processor that adds extra attributes of ``logging.LogRecord`` objects to the event dictionary.
+  This processor can be used for adding data passed in the ``extra`` parameter of the ``logging`` module's log methods to the event dictionary.
+  `#377 <https://github.com/hynek/structlog/pull/377>`_
 
 
 ----

docs/api.rst

@@ -302,6 +302,8 @@ Please see :doc:`thread-local` for details.
 
 .. autofunction:: add_logger_name
 
+.. autofunction:: ExtraAdder
+
 .. autoclass:: PositionalArgumentsFormatter
 
 .. autoclass:: ProcessorFormatter

docs/standard-library.rst

@@ -76,6 +76,11 @@ Processors
 `add_logger_name`:
    Adds the name of the logger to the event dictionary under the key ``logger``.
 
+`ExtraAdder`:
+   Add extra attributes of `logging.LogRecord` objects to the event dictionary.
+
+   This processor can be used for adding data passed in the ``extra`` parameter of the `logging` module's log methods to the event dictionary.
+
 :func:`~structlog.stdlib.add_log_level`:
    Adds the log level to the event dictionary under the key ``level``.
 
@@ -413,6 +418,10 @@ For example, to use the standard library's `logging.config.dictConfig` to log co
         # Add the log level and a timestamp to the event_dict if the log entry
         # is not from structlog.
         structlog.stdlib.add_log_level,
+        # Add extra attributes of LogRecord objects to the event dictionary
+        # so that values passed in the extra parameter of log methods pass
+        # through to log output.
+        structlog.stdlib.ExtraAdder(),
         timestamper,
     ]
 

src/structlog/stdlib.py

@@ -10,13 +10,15 @@
 """
 
 import asyncio
+import functools
 import logging
 import sys
 
 from functools import partial
 from typing import (
     Any,
     Callable,
+    Collection,
     Dict,
     Iterable,
     List,
@@ -43,6 +45,7 @@
     "add_log_level_number",
     "add_log_level",
     "add_logger_name",
+    "ExtraAdder",
     "BoundLogger",
     "filter_by_level",
     "get_logger",
@@ -664,6 +667,66 @@ def add_logger_name(
     return event_dict
 
 
+_LOG_RECORD_KEYS = logging.LogRecord(
+    "name", 0, "pathname", 0, "msg", tuple(), None
+).__dict__.keys()
+
+
+class ExtraAdder:
+    """
+    Add extra attributes of `logging.LogRecord` objects to the event
+    dictionary.
+
+    This processor can be used for adding data passed in the ``extra``
+    parameter of the `logging` module's log methods to the event dictionary.
+
+    :param allow: An optional collection of attributes that, if present in
+        `logging.LogRecord` objects, will be copied to event dictionaries.
+
+        If ``allow`` is None all attributes of `logging.LogRecord` objects that
+        do not exist on a standard `logging.LogRecord` object will be copied to
+        event dictionaries.
+
+    .. versionadded:: 21.5.0
+    """
+
+    __slots__ = ["_copier"]
+
+    def __init__(self, allow: Optional[Collection[str]] = None) -> None:
+        self._copier: Callable[[EventDict, logging.LogRecord], None]
+        if allow is not None:
+            self._copier = functools.partial(self._copy_allowed, [*allow])
+        else:
+            self._copier = self._copy_all
+
+    def __call__(
+        self, logger: logging.Logger, name: str, event_dict: EventDict
+    ) -> EventDict:
+        record: Optional[logging.LogRecord] = event_dict.get("_record")
+        if record is not None:
+            self._copier(event_dict, record)
+        return event_dict
+
+    @classmethod
+    def _copy_all(
+        cls, event_dict: EventDict, record: logging.LogRecord
+    ) -> None:
+        for key, value in record.__dict__.items():
+            if key not in _LOG_RECORD_KEYS:
+                event_dict[key] = value
+
+    @classmethod
+    def _copy_allowed(
+        cls,
+        allow: Collection[str],
+        event_dict: EventDict,
+        record: logging.LogRecord,
+    ) -> None:
+        for key in allow:
+            if key in record.__dict__:
+                event_dict[key] = record.__dict__[key]
+
+
 def render_to_log_kwargs(
     _: logging.Logger, __: str, event_dict: EventDict
 ) -> EventDict:

tests/test_stdlib.py

@@ -9,6 +9,9 @@
 import os
 import sys
 
+from io import StringIO
+from typing import Any, Callable, Collection, Dict, Optional, Set
+
 import pytest
 
 from pretend import call_recorder, stub
@@ -27,6 +30,7 @@
 from structlog.stdlib import (
     AsyncBoundLogger,
     BoundLogger,
+    ExtraAdder,
     LoggerFactory,
     PositionalArgumentsFormatter,
     ProcessorFormatter,
@@ -39,7 +43,7 @@
     render_to_log_kwargs,
 )
 from structlog.testing import CapturedCall
-from structlog.types import BindableLogger
+from structlog.types import BindableLogger, EventDict
 
 from .additional_frame import additional_frame
 
@@ -428,8 +432,8 @@ def test_log_level_alias_normalized(self):
         assert "warning" == event_dict["level"]
 
 
-@pytest.fixture
-def log_record():
+@pytest.fixture(name="make_log_record")
+def _make_log_record():
     """
     A LogRecord factory.
     """
@@ -461,17 +465,146 @@ def test_logger_name_added(self):
 
         assert name == event_dict["logger"]
 
-    def test_logger_name_added_with_record(self, log_record):
+    def test_logger_name_added_with_record(self, make_log_record):
         """
         The logger name is deduced from the LogRecord if provided.
         """
         name = "sample-name"
-        record = log_record(name=name)
+        record = make_log_record(name=name)
         event_dict = add_logger_name(None, None, {"_record": record})
 
         assert name == event_dict["logger"]
 
 
+def extra_dict() -> Dict[str, Any]:
+    """
+    A dict to be passed in the `extra` parameter of the `logging` module's log
+    methods.
+    """
+    return {
+        "this": "is",
+        "some": "extra values",
+        "x_int": 4,
+        "x_bool": True,
+    }
+
+
+@pytest.fixture(name="extra_dict")
+def extra_dict_fixture():
+    return extra_dict()
+
+
+class TestExtraAdder:
+    @pytest.mark.parametrize(
+        "allow, misses",
+        [
+            (None, None),
+            ({}, None),
+            *[({key}, None) for key in extra_dict().keys()],
+            ({"missing"}, {"missing"}),
+            ({"missing", "keys"}, {"missing"}),
+            ({"this", "x_int"}, None),
+        ],
+    )
+    def test_add_extra(
+        self,
+        make_log_record: Callable[[], logging.LogRecord],
+        extra_dict: Dict[str, Any],
+        allow: Optional[Collection[str]],
+        misses: Optional[Set[str]],
+    ):
+        """
+        Extra attributes of a LogRecord object are added to the event dict.
+        """
+        record: logging.LogRecord = make_log_record()
+        record.__dict__.update(extra_dict)
+        event_dict = {"_record": record, "ed_key": "ed_value"}
+        expected = self._copy_allowed(event_dict, extra_dict, allow)
+
+        if allow is None:
+            actual = ExtraAdder()(None, None, event_dict)
+            assert expected == actual
+        actual = ExtraAdder(allow)(None, None, event_dict)
+        assert expected == actual
+        if misses:
+            assert misses.isdisjoint(expected.keys())
+
+    def test_no_record(self):
+        """
+        If the event_dict has no LogRecord, do nothing.
+        """
+        actual = ExtraAdder()(None, None, {})
+
+        assert {} == actual
+
+    @pytest.mark.parametrize(
+        "allow, misses",
+        [
+            (None, None),
+            ({}, None),
+            *[({key}, None) for key in extra_dict().keys()],
+            ({"missing"}, {"missing"}),
+            ({"missing", "keys"}, {"missing"}),
+            ({"this", "x_int"}, None),
+        ],
+    )
+    def test_add_extra_e2e(
+        self,
+        extra_dict: Dict[str, Any],
+        allow: Optional[Collection[str]],
+        misses: Optional[Set[str]],
+    ):
+        """
+        Values passed in the `extra` parameter of the `logging` module's log
+        methods pass through to log output.
+        """
+        logger = logging.Logger(sys._getframe().f_code.co_name)
+        string_io = StringIO()
+        handler = logging.StreamHandler(string_io)
+        formatter = ProcessorFormatter(
+            foreign_pre_chain=[ExtraAdder(allow)],
+            processors=[JSONRenderer()],
+        )
+        handler.setFormatter(formatter)
+        handler.setLevel(0)
+        logger.addHandler(handler)
+        logger.setLevel(0)
+        logging.warning("allow = %s", allow)
+
+        event_dict = {"event": "Some text"}
+        expected = self._copy_allowed(event_dict, extra_dict, allow)
+
+        logger.info("Some %s", "text", extra=extra_dict)
+        actual = {
+            key: value
+            for key, value in json.loads(string_io.getvalue()).items()
+            if not key.startswith("_")
+        }
+
+        assert expected == actual
+        if misses:
+            assert misses.isdisjoint(expected.keys())
+
+    @classmethod
+    def _copy_allowed(
+        cls,
+        event_dict: EventDict,
+        extra_dict: Dict[str, Any],
+        allow: Optional[Collection[str]],
+    ) -> EventDict:
+        if allow is None:
+            return {**event_dict, **extra_dict}
+        else:
+            return {
+                **event_dict,
+                **{
+                    key: value
+                    for key, value in extra_dict.items()
+                    if key in allow
+                },
+            }
+
+
 class TestRenderToLogKW:
     def test_default(self):
         """

typing_examples.py

@@ -91,7 +91,14 @@ def bytes_dumps(
 
 formatter = structlog.stdlib.ProcessorFormatter(
     processor=structlog.dev.ConsoleRenderer(),
-    foreign_pre_chain=shared_processors,
+    foreign_pre_chain=[
+        structlog.stdlib.ExtraAdder(),
+        structlog.stdlib.ExtraAdder(allow=None),
+        structlog.stdlib.ExtraAdder(None),
+        structlog.stdlib.ExtraAdder(allow=["k1", "k2"]),
+        structlog.stdlib.ExtraAdder({"k1", "k2"}),
+        *shared_processors,
+    ],
 )