diff --git a/src/structlog/processors.py b/src/structlog/processors.py index db9adaa6..a4c88f88 100644 --- a/src/structlog/processors.py +++ b/src/structlog/processors.py @@ -575,20 +575,23 @@ class CallsiteParameterAdder: The keys used for various callsite parameters in the event dictionary are the string values of `CallsiteParameter` members. - :param parameters: A collection of `CallsiteParameter` values that should be - added to the event dictionary. + :param parameters: A collection of `CallsiteParameter` values that should + be added to the event dictionary. :param additional_ignores: Additional names with which the first frame must - not start. + not start. If no additional ignores are supplied then it will default + to `["logging"]`. + + .. note:: When used with `structlog.stdlib.ProcessorFormatter` the most + efficent configuration is to either use this processor in + ``foreign_pre_chain`` of `structlog.stdlib.ProcessorFormatter`` and in + `processors` of `structlog.configure`, or to use it in ``processor`` of + `structlog.stdlib.ProcessorFormatter` without using it in `processors`` + of `structlog.configure` and ``foreign_pre_chain`` of + `structlog.stdlib.ProcessorFormatter`. + - .. warning:: This processor should not be used in the processor parameter of - a `structlog.stdlib.ProcessorFormatter`, as this will result in the - processor running multiple times for the same event dictionary and - adding invalid values. - Instead, this function should be used in the ``foreign_pre_chain`` - parameter of `structlog.stdlib.ProcessorFormatter` and in the processors - parameter of `structlog.configure`. .. versionadded:: 21.5.0 @@ -634,7 +637,9 @@ def __init__( additional_ignores: Optional[List[str]] = None, ) -> None: self._parameters = parameters - self._additional_ignores = additional_ignores + if additional_ignores is None: + additional_ignores = [] + self._additional_ignores = [*additional_ignores, "logging"] self._active_handlers: List[ Tuple[CallsiteParameter, Callable[[str, inspect.Traceback], Any]] ] = [] @@ -653,15 +658,15 @@ def __call__( traceback.print_stack() record: Optional[logging.LogRecord] = event_dict.get("_record") - - if record is not None: - from_structlog: Optional[bool] = event_dict.get("_from_structlog") - if not from_structlog: - for parameter in self._parameters: - event_dict[parameter.value] = record.__dict__[ - parameter.value - ] + from_structlog: Optional[bool] = event_dict.get("_from_structlog") + if record is not None and not from_structlog: + # if from_structlog: + # return event_dict + for parameter in self._parameters: + event_dict[parameter.value] = record.__dict__[parameter.value] else: + # if from_structlog: + # return event_dict frame, module = _find_first_app_frame_and_name( additional_ignores=self._additional_ignores ) diff --git a/tests/test_processors.py b/tests/test_processors.py index 3602282c..937670c4 100644 --- a/tests/test_processors.py +++ b/tests/test_processors.py @@ -14,7 +14,7 @@ import threading from io import StringIO -from typing import Any, Dict, Optional, Set +from typing import Any, Dict, List, Optional, Set import pytest @@ -749,119 +749,30 @@ def test_all_parameters_tested(self) -> None: } @classmethod - def make_processors(cls, parameter_strings: Optional[Set[str]]) -> None: + def make_processors( + cls, + parameter_strings: Optional[Set[str]], + additional_ignores: Optional[List[str]], + ) -> None: processors = [] if parameter_strings is None: - processors.append(CallsiteParameterAdder()) + processors.append( + CallsiteParameterAdder(additional_ignores=additional_ignores) + ) else: parameters = cls.filter_parameters(parameter_strings) - processors.append(CallsiteParameterAdder(parameters=parameters)) + processors.append( + CallsiteParameterAdder( + parameters=parameters, + additional_ignores=additional_ignores, + ) + ) return processors - # @pytest.mark.parametrize( - # "parameter_strings", - # [ - # None, - # *[{parameter} for parameter in parameter_strings], - # set(), - # parameter_strings, - # {"pathname", "filename"}, - # {"module", "funcName"}, - # ], - # ) - # def test_logging_log( - # self, - # parameter_strings: Optional[Set[str]], - # ) -> None: - # """ - # Callsite parameters are added for event dictionaries that originate from - # """ - # processors = self.make_processors(parameter_strings) - # logger = logging.Logger(sys._getframe().f_code.co_name) - # string_io = StringIO() - # handler = logging.StreamHandler(string_io) - - # formatter = ProcessorFormatter( - # processors=[*processors, JSONRenderer()], - # ) - # handler.setFormatter(formatter) - # handler.setLevel(0) - # logger.addHandler(handler) - # logger.setLevel(0) - - # test_message = "test message" - # callsite_params = self.get_callsite_parameters() - # logger.info(test_message) - - # callsite_params = self.filter_parameter_dict( - # callsite_params, parameter_strings - # ) - # actual = { - # key: value - # for key, value in json.loads(string_io.getvalue()).items() - # if not key.startswith("_") - # } - # expected = { - # "event": test_message, - # **callsite_params, - # } - # assert expected == actual - - # @pytest.mark.parametrize( - # "parameter_strings", - # [ - # None, - # *[{parameter} for parameter in parameter_strings], - # set(), - # parameter_strings, - # {"pathname", "filename"}, - # {"module", "funcName"}, - # ], - # ) - # def test_structlog_log( - # self, - # parameter_strings: Optional[Set[str]], - # ) -> None: - # processors = self.make_processors(parameter_strings) - - # logger = logging.Logger(sys._getframe().f_code.co_name) - # string_io = StringIO() - # handler = logging.StreamHandler(string_io) - # formatter = ProcessorFormatter( - # processors=[JSONRenderer()], - # ) - # handler.setFormatter(formatter) - # handler.setLevel(0) - # logger.addHandler(handler) - # logger.setLevel(0) - - # ctx: Dict[str, Any] = {} - # bound_logger = BoundLogger( - # logger, [*processors, ProcessorFormatter.wrap_for_formatter], ctx - # ) - - # test_message = "test message" - # callsite_params = self.get_callsite_parameters() - # bound_logger.info(test_message) - - # callsite_params = self.filter_parameter_dict( - # callsite_params, parameter_strings - # ) - # actual = { - # key: value - # for key, value in json.loads(string_io.getvalue()).items() - # if not key.startswith("_") - # } - # expected = { - # "event": test_message, - # **callsite_params, - # } - # assert expected == actual - @pytest.mark.parametrize( "setup, front, parameter_strings", itertools.product( - ["shared", "pre-with-common"], + ["common-without-pre", "common-with-pre", "shared", "everywhere"], ["logging", "structlog"], [ None, @@ -882,16 +793,40 @@ def test_log( logger = logging.Logger(sys._getframe().f_code.co_name) string_io = StringIO() handler = logging.StreamHandler(string_io) - processors = self.make_processors(parameter_strings) - if setup == "shared": + if setup == "common-without-pre": + processors = self.make_processors( + parameter_strings, additional_ignores=None + ) + common_processors = processors formatter = ProcessorFormatter( processors=[*processors, JSONRenderer()] ) - elif setup == "pre-with-common": + elif setup == "common-with-pre": + processors = self.make_processors( + parameter_strings, additional_ignores=None + ) + common_processors = processors formatter = ProcessorFormatter( foreign_pre_chain=processors, processors=[JSONRenderer()], ) + elif setup == "shared": + processors = self.make_processors( + parameter_strings, additional_ignores=[] + ) + common_processors = [] + formatter = ProcessorFormatter( + processors=[*processors, JSONRenderer()], + ) + elif setup == "everywhere": + processors = self.make_processors( + parameter_strings, additional_ignores=[] + ) + common_processors = processors + formatter = ProcessorFormatter( + foreign_pre_chain=processors, + processors=[*processors, JSONRenderer()], + ) else: raise ValueError(f"invalid setup {setup}") handler.setFormatter(formatter) @@ -907,7 +842,7 @@ def test_log( ctx: Dict[str, Any] = {} bound_logger = BoundLogger( logger, - [*processors, ProcessorFormatter.wrap_for_formatter], + [*common_processors, ProcessorFormatter.wrap_for_formatter], ctx, ) callsite_params = self.get_callsite_parameters()