processors: add always_walk_stack to CallsiteParameterAdder

CHANGELOG.md

@@ -45,6 +45,12 @@ You can find our backwards-compatibility policy [here](https://github.com/hynek/
   This is only available for *structlog*-originated events since the standard library has no equivalent (except for the convention of setting the logger's name to `__name__`).
   [#812](https://github.com/hynek/structlog/pull/812)
 
+- `structlog.processors.CallsiteParameterAdder` now takes an *always_walk_stack* argument.
+  When set to `True`, the callsite is always determined by walking the stack, even for foreign `logging.LogRecord` events that would otherwise have their callsite copied verbatim from the record.
+  As a side effect, *additional_ignores* then applies to foreign events too, so frames from third-party packages can be skipped and the callsite of *your* code is reported instead.
+  Defaults to `False` for backwards compatibility.
+  [#816](https://github.com/hynek/structlog/pull/816)
+
 - `structlog.stdlib.BoundLogger` now has `is_enabled_for()` and `get_effective_level()` methods that are snake_case aliases for its `isEnabledFor()` and `getEffectiveLevel()` methods.
   This makes it more compatible with the native `structlog.typing.FilteringBoundLogger`, so you can swap configurations without changing your call sites.
   [#818](https://github.com/hynek/structlog/pull/818)

src/structlog/processors.py

@@ -837,12 +837,14 @@ class CallsiteParameterAdder:
     filename that an event dictionary originated from.
 
     If the event dictionary has an embedded `logging.LogRecord` object and did
-    not originate from *structlog* then the callsite information will be
-    determined from the `logging.LogRecord` object. For event dictionaries
-    without an embedded `logging.LogRecord` object the callsite will be
-    determined from the stack trace, ignoring all intra-structlog calls, calls
-    from the `logging` module, and stack frames from modules with names that
-    start with values in ``additional_ignores``, if it is specified.
+    not originate from *structlog* then the callsite information will, by
+    default, be determined from the `logging.LogRecord` object.
+
+    For event dictionaries without an embedded `logging.LogRecord` object the
+    callsite will be determined from the stack trace, ignoring all
+    intra-*structlog* calls, calls from the `logging` module, and stack frames
+    from modules with names that start with values in *additional_ignores*, if
+    it is specified.
 
     The keys used for callsite parameters in the event dictionary are the
     string values of `CallsiteParameter` enum members.
@@ -856,17 +858,34 @@ class CallsiteParameterAdder:
             Additional names with which a stack frame's module name must not
             start for it to be considered when determening the callsite.
 
+        always_walk_stack:
+            If ``True``, the callsite is always determined by walking the
+            stack, even for events that come from `logging` and carry
+            a `logging.LogRecord`. As a side effect, *additional_ignores* then
+            applies to foreign events too, so frames from third-party packages
+            can be skipped and the callsite of *your* code is reported instead
+            of the package's log invocation line.
+
+            Defaults to ``False``, in which case the callsite information of
+            foreign events is copied verbatim from the `logging.LogRecord`.
+
     .. note::
 
         When used with `structlog.stdlib.ProcessorFormatter` the most efficient
-        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 ``processors`` of
-        `structlog.stdlib.ProcessorFormatter` without using it in
-        ``processors`` of `structlog.configure` and ``foreign_pre_chain`` of
-        `structlog.stdlib.ProcessorFormatter`.
+        configuration is to either:
+
+        - use this processor in *foreign_pre_chain* of
+          `structlog.stdlib.ProcessorFormatter` and in *processors* of
+          `structlog.configure`, or
+
+        - use it in *processors* of `structlog.stdlib.ProcessorFormatter`
+          without using it in *processors* of `structlog.configure` and
+          *foreign_pre_chain* of `structlog.stdlib.ProcessorFormatter`.
 
     .. versionadded:: 21.5.0
+
+    .. versionadded:: 26.1.0
+       *always_walk_stack* parameter.
     """
 
     _handlers: ClassVar[
@@ -903,19 +922,26 @@ class _RecordMapping(NamedTuple):
         event_dict_key: str
         record_attribute: str
 
-    __slots__ = ("_active_handlers", "_additional_ignores", "_record_mappings")
+    __slots__ = (
+        "_active_handlers",
+        "_additional_ignores",
+        "_always_walk_stack",
+        "_record_mappings",
+    )
 
     def __init__(
         self,
         parameters: Collection[CallsiteParameter] = _all_parameters,
         additional_ignores: list[str] | None = None,
+        always_walk_stack: bool = False,
     ) -> None:
         if additional_ignores is None:
             additional_ignores = []
         # Ignore stack frames from the logging module. They will occur if this
         # processor is used in ProcessorFormatter, and additionally the logging
         # module should not be logging using structlog.
         self._additional_ignores = ["logging", *additional_ignores]
+        self._always_walk_stack = always_walk_stack
         self._active_handlers: list[
             tuple[CallsiteParameter, Callable[[str, FrameType], Any]]
         ] = []
@@ -942,7 +968,13 @@ def __call__(
 
         # If the event dictionary has a record, but it comes from structlog,
         # then the callsite parameters of the record will not be correct.
-        if record is not None and not from_structlog:
+        # When always_walk_stack is set, also walk the stack for foreign
+        # records so that additional_ignores can hide library frames.
+        if (
+            record is not None
+            and not from_structlog
+            and not self._always_walk_stack
+        ):
             for mapping in self._record_mappings:
                 event_dict[mapping.event_dict_key] = record.__dict__[
                     mapping.record_attribute

tests/processors/test_processors.py

@@ -480,6 +480,122 @@ def test_additional_ignores(self, monkeypatch: pytest.MonkeyPatch) -> None:
 
         assert expected == actual
 
+    def test_always_walk_stack(self) -> None:
+        """
+        With ``always_walk_stack=True``, the callsite for a foreign
+        `logging.LogRecord` is determined by walking the stack rather than
+        copied from the record, so `additional_ignores` applies.
+        """
+        test_message = "test message"
+        processor = CallsiteParameterAdder(
+            parameters=self._all_parameters,
+            always_walk_stack=True,
+        )
+        record = logging.LogRecord(
+            "name",
+            logging.INFO,
+            "/some/library/path.py",
+            123,
+            test_message,
+            None,
+            None,
+            "library_func",
+        )
+        event_dict: EventDict = {
+            "event": test_message,
+            "_record": record,
+            "_from_structlog": False,
+        }
+
+        # Warning: the next two lines must appear exactly like this to make
+        # line numbers match.
+        callsite_params = self.get_callsite_parameters(1)
+        actual = processor(None, None, event_dict)
+
+        actual = {
+            key: value
+            for key, value in actual.items()
+            if not key.startswith("_")
+        }
+        expected = {"event": test_message, **callsite_params}
+
+        assert expected == actual
+
+    def test_always_walk_stack_skips_additional_ignores(self) -> None:
+        """
+        With ``always_walk_stack=True`` and ``additional_ignores`` set, frames
+        from the ignored module are skipped even when the event carries
+        a foreign `logging.LogRecord`.
+        """
+        processor = CallsiteParameterAdder(
+            parameters={
+                CallsiteParameter.PATHNAME,
+                CallsiteParameter.FUNC_NAME,
+                CallsiteParameter.MODULE,
+            },
+            additional_ignores=["tests.additional_frame"],
+            always_walk_stack=True,
+        )
+        record = logging.LogRecord(
+            "name",
+            logging.INFO,
+            "/some/library/path.py",
+            123,
+            "msg",
+            None,
+            None,
+            "library_func",
+        )
+        event_dict: EventDict = {
+            "event": "msg",
+            "_record": record,
+            "_from_structlog": False,
+        }
+
+        actual = additional_frame(
+            lambda: processor(None, None, dict(event_dict))
+        )
+
+        # The record's values are ignored ...
+        assert "library_func" != actual["func_name"]
+        # ... and this test file is reported as the callsite.
+        assert __file__ == actual["pathname"]
+        assert "test_processors" == actual["module"]
+
+    def test_always_walk_stack_default_uses_record(self) -> None:
+        """
+        By default (``always_walk_stack=False``), the callsite information
+        for foreign records is copied straight from the `logging.LogRecord`.
+        """
+        processor = CallsiteParameterAdder(
+            parameters={
+                CallsiteParameter.PATHNAME,
+                CallsiteParameter.LINENO,
+                CallsiteParameter.FUNC_NAME,
+            },
+        )
+        record = logging.LogRecord(
+            "name",
+            logging.INFO,
+            "/some/library/path.py",
+            123,
+            "msg",
+            None,
+            None,
+            "library_func",
+        )
+        event_dict: EventDict = {
+            "event": "msg",
+            "_record": record,
+            "_from_structlog": False,
+        }
+
+        actual = processor(None, None, event_dict)
+
+        assert "/some/library/path.py" == actual["pathname"]
+        assert 123 == actual["lineno"]
+        assert "library_func" == actual["func_name"]
+
     @pytest.mark.parametrize(
         ("origin", "parameter_strings"),
         itertools.product(