fixes bug in render_to_log_kwargs

CHANGELOG.md

@@ -39,6 +39,12 @@ You can find our backwards-compatibility policy [here](https://github.com/hynek/
  [#606](https://github.com/hynek/structlog/pull/606)
 
 
+### Fixed
+
+- `structlog.stdlib.render_to_log_kwargs` now correctly passes stacklevel as a kwarg to stdlib logging.
+ [#619](https://github.com/hynek/structlog/pull/620)
+
+
 
 ## [24.1.0](https://github.com/hynek/structlog/compare/23.3.0...24.1.0) - 2024-01-08
 

src/structlog/stdlib.py

@@ -878,6 +878,7 @@ def render_to_log_kwargs(
 ) -> EventDict:
  """
  Render ``event_dict`` into keyword arguments for `logging.log`.
+ See `logging.Logger`'s ``_log`` method for kwargs reference.
 
  The ``event`` field is translated into ``msg`` and the rest of the
  *event_dict* is added as ``extra``.
@@ -886,15 +887,17 @@ def render_to_log_kwargs(
 
  .. versionadded:: 17.1.0
  .. versionchanged:: 22.1.0
- ``exc_info``, ``stack_info``, and ``stackLevel`` are passed as proper
+ ``exc_info``, ``stack_info``, and ``stacklevel`` are passed as proper
  kwargs and not put into ``extra``.
+ .. versionchanged:: 24.2.0
+ ``stackLevel`` corrected to ``stacklevel``.
  """
  return {
  "msg": event_dict.pop("event"),
  "extra": event_dict,
  **{
  kw: event_dict.pop(kw)
- for kw in ("exc_info", "stack_info", "stackLevel")
+ for kw in ("exc_info", "stack_info", "stacklevel")
  if kw in event_dict
  },
  }

tests/test_stdlib.py

@@ -13,6 +13,7 @@
 
 from io import StringIO
 from typing import Any, Callable, Collection, Dict
+from unittest.mock import patch
 
 import pytest
 import pytest_asyncio
@@ -24,6 +25,7 @@
  ReturnLogger,
  configure,
  get_context,
+ wrap_logger,
 )
 from structlog._config import _CONFIG
 from structlog._log_levels import CRITICAL, NAME_TO_LEVEL, WARN
@@ -671,16 +673,32 @@ def _copy_allowed(
  }
 
 
+@pytest.fixture(name="stdlib_logger")
+def _stdlib_logger():
+ logger = logging.getLogger("test_logger")
+ logger.setLevel(logging.DEBUG)
+
+ yield logger
+
+ logging.basicConfig()
+
+
 class TestRenderToLogKW:
- def test_default(self):
+ def test_default(self, stdlib_logger):
  """
  Translates `event` to `msg` and handles otherwise empty `event_dict`s.
  """
  d = render_to_log_kwargs(None, None, {"event": "message"})
 
  assert {"msg": "message", "extra": {}} == d
 
- def test_add_extra_event_dict(self, event_dict):
+ # now check stdlib logger likes those kwargs
+ with patch.object(stdlib_logger, "_log") as mock_log:
+ stdlib_logger.info(**d)
+
+ mock_log.assert_called_once_with(logging.INFO, "message", (), extra={})
+
+ def test_add_extra_event_dict(self, event_dict, stdlib_logger):
  """
  Adds all remaining data from `event_dict` into `extra`.
  """
@@ -689,9 +707,17 @@ def test_add_extra_event_dict(self, event_dict):
 
  assert {"msg": "message", "extra": event_dict} == d
 
- def test_handles_special_kw(self, event_dict):
+ # now check stdlib logger likes those kwargs
+ with patch.object(stdlib_logger, "_log") as mock_log:
+ stdlib_logger.info(**d)
+
+ mock_log.assert_called_once_with(
+ logging.INFO, "message", (), extra=event_dict
+ )
+
+ def test_handles_special_kw(self, event_dict, stdlib_logger):
  """
- "exc_info", "stack_info", and "stackLevel" aren't passed as extras.
+ "exc_info", "stack_info", and "stacklevel" aren't passed as extras.
 
  Cf. https://github.com/hynek/structlog/issues/424
  """
@@ -700,22 +726,68 @@ def test_handles_special_kw(self, event_dict):
 
  event_dict["exc_info"] = True
  event_dict["stack_info"] = False
- event_dict["stackLevel"] = 1
+ event_dict["stacklevel"] = 1
+ event_dict["stackLevel"] = 1 # not a reserved kw
 
  d = render_to_log_kwargs(None, None, event_dict)
-
- assert {
+ expected = {
  "msg": "message",
  "exc_info": True,
  "stack_info": False,
- "stackLevel": 1,
+ "stacklevel": 1,
  "extra": {
  "b": [3, 4],
  "x": 7,
  "y": "test",
  "z": (1, 2),
+ "stackLevel": 1,
  },
- } == d
+ }
+
+ assert expected == d
+
+ # now check stdlib logger likes those kwargs
+ with patch.object(stdlib_logger, "_log") as mock_log:
+ stdlib_logger.info(**d)
+
+ expected.pop("msg")
+ mock_log.assert_called_once_with(
+ logging.INFO, "message", (), **expected
+ )
+
+ def test_integration_special_kw(self, event_dict, stdlib_logger):
+ """
+ render_to_log_kwargs with a wrapped logger calls the stdlib logger
+ correctly
+
+ reserved stdlib keywords are in logging.Logger._log
+ https://github.com/python/cpython/blob/ae7b17673f29efe17b416cbcfbf43b5b3ff5977c/Lib/logging/__init__.py#L1632
+ """
+ expected = {
+ "msg": "message",
+ "exc_info": True,
+ "stack_info": False,
+ "stacklevel": 1,
+ "extra": {**event_dict},
+ }
+
+ event_dict["exc_info"] = True
+ event_dict["stack_info"] = False
+ event_dict["stacklevel"] = 1
+
+ struct_logger = wrap_logger(
+ stdlib_logger,
+ processors=[render_to_log_kwargs],
+ )
+
+ # now check struct logger passes those kwargs to stdlib
+ with patch.object(stdlib_logger, "_log") as mock_log:
+ struct_logger.info("message", **event_dict)
+
+ expected.pop("msg")
+ mock_log.assert_called_once_with(
+ logging.INFO, "message", (), **expected
+ )
 
 
 @pytest.fixture(name="configure_for_processor_formatter")