From 95857aeb274c8b5fd838a2f6ceb7f72ef751873c Mon Sep 17 00:00:00 2001 From: Iwan Aucamp Date: Thu, 9 Dec 2021 01:10:00 +0100 Subject: [PATCH] Change add_extra to ExtraAdder This is so ExtraAdder can be configured with what keys it should copy. --- src/structlog/stdlib.py | 52 +++++++++++++++--- tests/test_stdlib.py | 115 ++++++++++++++++++++++++++++++++++------ 2 files changed, 142 insertions(+), 25 deletions(-) diff --git a/src/structlog/stdlib.py b/src/structlog/stdlib.py index 34e63c99..1c8b1776 100644 --- a/src/structlog/stdlib.py +++ b/src/structlog/stdlib.py @@ -10,6 +10,7 @@ """ import asyncio +import functools import logging import sys @@ -670,24 +671,59 @@ def add_logger_name( ) -def add_extra( - logger: logging.Logger, method_name: str, event_dict: EventDict -) -> EventDict: +class ExtraAdder: """ - Add extra `logging.LogRecord` keys to the event dictionary. + Add extra `logging.LogRecord` attributes to the event dictionary. - This function is useful for adding data passed in the ``extra`` parameter + This processor is useful for adding data passed in the ``extra`` parameter of the `logging` module's log methods to the event dictionary. + :param allow: An optional list of keys to allow to pass through from + `logging.LogRecord` objects to event dictionaries. + + If `allow` is set to None, then all extra `log` + .. versionadded:: 21.5.0 """ - record: Optional[logging.LogRecord] = event_dict.get("_record") - if record is not None: + __slots__ = ["_allow", "_copier"] + + def __init__(self, allow: Optional[Sequence[str]] = None) -> None: + self._allow = allow + self._copier: Callable[[EventDict, logging.LogRecord], None] + if self._allow is not None: + # this is to convince mypy that the value being passed as the first + # argument to _copy_allowed is in fact not an optional. + _allow = self._allow + 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 _BLANK_LOGRECORD.__dict__: event_dict[key] = value - return event_dict + @classmethod + def _copy_allowed( + cls, + allow: Sequence[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 diff --git a/tests/test_stdlib.py b/tests/test_stdlib.py index e3c60f7c..53e661e1 100644 --- a/tests/test_stdlib.py +++ b/tests/test_stdlib.py @@ -10,6 +10,7 @@ import sys from io import StringIO +from typing import Any, Dict, Optional, Sequence import pytest @@ -29,6 +30,7 @@ from structlog.stdlib import ( AsyncBoundLogger, BoundLogger, + ExtraAdder, LoggerFactory, PositionalArgumentsFormatter, ProcessorFormatter, @@ -42,7 +44,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 @@ -475,19 +477,82 @@ def test_logger_name_added_with_record(self, log_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 TestAddExtra: - def test_add_extra(self, log_record): + @pytest.mark.parametrize( + "allow", + [ + None, + {}, + *[{key} for key in extra_dict().keys()], + {"missing"}, + {"missing", "keys"}, + {"this", "x_int"}, + ], + ) + def test_add_extra( + self, + log_record: logging.LogRecord, + extra_dict: Dict[str, Any], + allow: Optional[Sequence[str]], + ): """ Extra attributes of a LogRecord are added to the event dict. """ - extra = {"x_this": "is", "x_the": 3, "x_extra": "values"} + # extra = {"x_this": "is", "x_the": 3, "x_extra": "values"} record: logging.LogRecord = log_record() - record.__dict__.update(extra) - event_dict = {"_record": record} - event_dict_out = add_extra(None, None, event_dict) - assert {**event_dict, **extra} == event_dict_out + record.__dict__.update(extra_dict) + event_dict = {"_record": record, "ed_key": "ed_value"} + expected_result: EventDict + if allow is None: + expected_result = {**event_dict, **extra_dict} + else: + expected_result = { + **event_dict, + **{ + key: value + for key, value in extra_dict.items() + if key in allow + }, + } + + if allow is None: + actual_result = ExtraAdder()(None, None, event_dict) + assert expected_result == actual_result + actual_result = ExtraAdder(allow)(None, None, event_dict) + assert expected_result == actual_result - def test_add_extra_e2e(self): + @pytest.mark.parametrize( + "allow", + [ + None, + {}, + *[{key} for key in extra_dict().keys()], + {"missing"}, + {"missing", "keys"}, + {"this", "x_int"}, + ], + ) + def test_add_extra_e2e( + self, extra_dict: Dict[str, Any], allow: Optional[Sequence[str]] + ): """ Values passed in the extra parameter of log methods are added as members of JSON output objects. @@ -496,21 +561,37 @@ def test_add_extra_e2e(self): string_io = StringIO() handler = logging.StreamHandler(string_io) formatter = ProcessorFormatter( - foreign_pre_chain=[add_extra], + foreign_pre_chain=[ExtraAdder(allow)], processors=[JSONRenderer()], ) handler.setFormatter(formatter) handler.setLevel(0) logger.addHandler(handler) logger.setLevel(0) - extra = {"with": "values", "from": "extra"} - logger.info("Some %s", "text", extra=extra) - out_item_set = set(json.loads(string_io.getvalue()).items()) - expected_item_set = set({"event": "Some text", **extra}.items()) - assert expected_item_set.issubset(out_item_set), ( - f"expected_item_set={expected_item_set} should" - f"be a subset of out_item_set={out_item_set}" - ) + logging.warning("allow = %s", allow) + + event_dict = {"event": "Some text"} + expected_result: EventDict + if allow is None: + expected_result = {**event_dict, **extra_dict} + else: + expected_result = { + **event_dict, + **{ + key: value + for key, value in extra_dict.items() + if key in allow + }, + } + + logger.info("Some %s", "text", extra=extra_dict) + actual_result = { + key: value + for key, value in json.loads(string_io.getvalue()).items() + if not key.startswith("_") + } + + assert expected_result == actual_result class TestRenderToLogKW: