Add 'structlog.stdlib.render_to_log_args_and_kwargs' processor

CHANGELOG.md

@@ -15,6 +15,13 @@ You can find our backwards-compatibility policy [here](https://github.com/hynek/
 
 ## [Unreleased](https://github.com/hynek/structlog/compare/24.4.0...HEAD)
 
+### Added
+
+- Add `structlog.stdlib.render_to_log_args_and_kwargs` processor.
+  Same as `structlog.stdlib.render_to_log_kwargs`, but also allows to pass positional arguments to `logging`.
+  With it, you do not need to add `structlog.stdlib.PositionalArgumentsFormatter` processor to format positional arguments from *structlog* loggers.
+  [#668](https://github.com/hynek/structlog/pull/668)
+
 ## Changed
 
 - `structlog.typing.BindableLogger` protocol now returns `Self` instead of `BindableLogger`.

docs/api.rst

@@ -303,6 +303,8 @@ API Reference
 .. autoclass:: LoggerFactory
    :members: __call__
 
+.. autofunction:: render_to_log_args_and_kwargs
+
 .. autofunction:: render_to_log_kwargs
 
 .. autofunction:: filter_by_level
@@ -313,7 +315,7 @@ API Reference
 
 .. autofunction:: add_logger_name
 
-.. autofunction:: ExtraAdder
+.. autoclass:: ExtraAdder
 
 .. autoclass:: PositionalArgumentsFormatter
 

docs/standard-library.md

@@ -77,11 +77,16 @@ To use it, {doc}`configure <configuration>` *structlog* to use `AsyncBoundLogger
 
 *structlog* comes with a few standard library-specific processors:
 
-{func}`~structlog.stdlib.render_to_log_kwargs`:
+{func}`~structlog.stdlib.render_to_log_args_and_kwargs`:
 
-: Renders the event dictionary into keyword arguments for `logging.log` that attaches everything except the `event` field to the *extra* argument.
+: Renders the event dictionary into positional and keyword arguments for `logging.Logger` logging methods.
   This is useful if you want to render your log entries entirely within `logging`.
 
+{func}`~structlog.stdlib.render_to_log_kwargs`:
+
+: Same as above, but does not support passing positional arguments from *structlog* loggers to `logging.Logger` logging methods as positional arguments.
+  *structlog* positional arguments are still passed to `logging` under `positional_args` key of `extra` keyword argument.
+
 {func}`~structlog.stdlib.filter_by_level`:
 
 : Checks the log entry's log level against the configuration of standard library's logging.
@@ -92,12 +97,6 @@ To use it, {doc}`configure <configuration>` *structlog* to use `AsyncBoundLogger
 
 : Adds the name of the logger to the event dictionary under the key `logger`.
 
-{func}`~structlog.stdlib.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`.
@@ -117,6 +116,12 @@ To use it, {doc}`configure <configuration>` *structlog* to use `AsyncBoundLogger
 
   The mapping of names to numbers is in `structlog.stdlib._NAME_TO_LEVEL`.
 
+{func}`~structlog.stdlib.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.PositionalArgumentsFormatter`:
 
 : This processes and formats positional arguments (if any) passed to log methods in the same way the `logging` module would do, for example, `logger.info("Hello, %s", name)`.

src/structlog/stdlib.py

@@ -50,6 +50,7 @@
     "PositionalArgumentsFormatter",
     "ProcessorFormatter",
     "recreate_defaults",
+    "render_to_log_args_and_kwargs",
     "render_to_log_kwargs",
 ]
 
@@ -885,15 +886,50 @@ def _copy_allowed(
                 event_dict[key] = record.__dict__[key]
 
 
+LOG_KWARG_NAMES = ("exc_info", "stack_info", "stacklevel")
+
+
+def render_to_log_args_and_kwargs(
+    _: logging.Logger, __: str, event_dict: EventDict
+) -> tuple[tuple[Any, ...], dict[str, Any]]:
+    """
+    Render ``event_dict`` into positional and keyword arguments for
+    `logging.Logger` logging methods.
+    See `logging.Logger.debug` method for keyword arguments reference.
+
+    The ``event`` field is passed in the first positional argument, positional
+    arguments from ``positional_args`` field are passed in subsequent positional
+    arguments, keyword arguments are extracted from the *event_dict* and the
+    rest of the *event_dict* is added as ``extra``.
+
+    This allows you to defer formatting to `logging`.
+
+    .. versionadded:: 24.5.0
+    """
+    args = (event_dict.pop("event"), *event_dict.pop("positional_args", ()))
+
+    kwargs = {
+        kwarg_name: event_dict.pop(kwarg_name)
+        for kwarg_name in LOG_KWARG_NAMES
+        if kwarg_name in event_dict
+    }
+    if event_dict:
+        kwargs["extra"] = event_dict
+
+    return args, kwargs
+
+
 def render_to_log_kwargs(
     _: logging.Logger, __: str, event_dict: EventDict
 ) -> EventDict:
     """
-    Render ``event_dict`` into keyword arguments for `logging.log`.
-    See `logging.Logger`'s ``_log`` method for kwargs reference.
+    Render ``event_dict`` into keyword arguments for `logging.Logger` logging
+    methods.
+    See `logging.Logger.debug` method for keyword arguments reference.
 
-    The ``event`` field is translated into ``msg`` and the rest of the
-    *event_dict* is added as ``extra``.
+    The ``event`` field is translated into ``msg``, keyword arguments are
+    extracted from the *event_dict* and the rest of the *event_dict* is added as
+    ``extra``.
 
     This allows you to defer formatting to `logging`.
 
@@ -909,7 +945,7 @@ def render_to_log_kwargs(
         "extra": event_dict,
         **{
             kw: event_dict.pop(kw)
-            for kw in ("exc_info", "stack_info", "stacklevel")
+            for kw in LOG_KWARG_NAMES
             if kw in event_dict
         },
     }

tests/test_stdlib.py

@@ -46,6 +46,7 @@
     filter_by_level,
     get_logger,
     recreate_defaults,
+    render_to_log_args_and_kwargs,
     render_to_log_kwargs,
 )
 from structlog.testing import CapturedCall
@@ -706,7 +707,171 @@ def _stdlib_logger():
     logging.basicConfig()
 
 
-class TestRenderToLogKW:
+class TestRenderToLogArgsAndKwargs:
+    def test_default(self, stdlib_logger: logging.Logger):
+        """
+        Passes `event` key from `event_dict` in the first positional argument
+        and handles otherwise empty `event_dict`.
+        """
+        method_name = "debug"
+        event = "message"
+        args, kwargs = render_to_log_args_and_kwargs(
+            stdlib_logger, method_name, {"event": event}
+        )
+
+        assert (event,) == args
+        assert {} == kwargs
+
+        with patch.object(stdlib_logger, "_log") as mock_log:
+            getattr(stdlib_logger, method_name)(*args, **kwargs)
+
+        mock_log.assert_called_once_with(logging.DEBUG, event, ())
+
+    def test_pass_remaining_event_dict_as_extra(
+        self, stdlib_logger: logging.Logger, event_dict: dict[str, Any]
+    ):
+        """
+        Passes remaining `event_dict` as `extra`.
+        """
+        expected_extra = event_dict.copy()
+
+        method_name = "info"
+        event = "message"
+        event_dict["event"] = event
+
+        args, kwargs = render_to_log_args_and_kwargs(
+            stdlib_logger, method_name, event_dict
+        )
+
+        assert (event,) == args
+        assert {"extra": expected_extra} == kwargs
+
+        with patch.object(stdlib_logger, "_log") as mock_log:
+            getattr(stdlib_logger, method_name)(*args, **kwargs)
+
+        mock_log.assert_called_once_with(
+            logging.INFO, event, (), extra=expected_extra
+        )
+
+    def test_pass_positional_args_from_event_dict_as_args(
+        self, stdlib_logger: logging.Logger, event_dict: dict[str, Any]
+    ):
+        """
+        Passes items from "positional_args" key from `event_dict` as positional
+        arguments.
+        """
+        expected_extra = event_dict.copy()
+
+        method_name = "warning"
+        event = "message: a = %s, b = %d"
+        positional_args = ("foo", 123)
+        event_dict["event"] = event
+        event_dict["positional_args"] = positional_args
+
+        args, kwargs = render_to_log_args_and_kwargs(
+            stdlib_logger, method_name, event_dict
+        )
+
+        assert (event, *(positional_args)) == args
+        assert {"extra": expected_extra} == kwargs
+
+        with patch.object(stdlib_logger, "_log") as mock_log:
+            getattr(stdlib_logger, method_name)(*args, **kwargs)
+
+        mock_log.assert_called_once_with(
+            logging.WARNING, event, positional_args, extra=expected_extra
+        )
+
+    def test_pass_kwargs_from_event_dict_as_kwargs(
+        self, stdlib_logger: logging.Logger, event_dict: dict[str, Any]
+    ):
+        """
+        Passes "exc_info", "stack_info", and "stacklevel" keys from `event_dict`
+        as keyword arguments.
+        """
+        expected_extra = event_dict.copy()
+
+        method_name = "info"
+        event = "message"
+        exc_info = True
+        stack_info = False
+        stacklevel = 2
+        event_dict["event"] = event
+        event_dict["exc_info"] = exc_info
+        event_dict["stack_info"] = stack_info
+        event_dict["stacklevel"] = stacklevel
+
+        args, kwargs = render_to_log_args_and_kwargs(
+            stdlib_logger, method_name, event_dict
+        )
+
+        assert (event,) == args
+        assert {
+            "exc_info": exc_info,
+            "stack_info": stack_info,
+            "stacklevel": stacklevel,
+            "extra": expected_extra,
+        } == kwargs
+
+        with patch.object(stdlib_logger, "_log") as mock_log:
+            getattr(stdlib_logger, method_name)(*args, **kwargs)
+
+        mock_log.assert_called_once_with(
+            logging.INFO,
+            event,
+            (),
+            exc_info=exc_info,
+            stack_info=stack_info,
+            stacklevel=stacklevel,
+            extra=expected_extra,
+        )
+
+    def test_integration(
+        self, stdlib_logger: logging.Logger, event_dict: dict[str, Any]
+    ):
+        """
+        `render_to_log_args_and_kwargs` with a wrapped logger calls the stdlib
+        logger correctly.
+
+        Reserved stdlib keyword arguments are in `logging.Logger._log`.
+        https://github.com/python/cpython/blob/60403a5409ff2c3f3b07dd2ca91a7a3e096839c7/Lib/logging/__init__.py#L1640
+        """
+        event = "message: a = %s, b = %d"
+        arg_1 = "foo"
+        arg_2 = 123
+        exc_info = False
+        stack_info = True
+        stacklevel = 3
+
+        struct_logger = wrap_logger(
+            stdlib_logger,
+            processors=[render_to_log_args_and_kwargs],
+            wrapper_class=BoundLogger,
+        )
+
+        with patch.object(stdlib_logger, "_log") as mock_log:
+            struct_logger.info(
+                event,
+                arg_1,
+                arg_2,
+                exc_info=exc_info,
+                stack_info=stack_info,
+                stacklevel=stacklevel,
+                **event_dict,
+            )
+
+        mock_log.assert_called_once_with(
+            logging.INFO,
+            event,
+            (arg_1, arg_2),
+            exc_info=exc_info,
+            stack_info=stack_info,
+            stacklevel=stacklevel,
+            extra=event_dict,
+        )
+
+
+class TestRenderToLogKwargs:
     def test_default(self, stdlib_logger):
         """
         Translates `event` to `msg` and handles otherwise empty `event_dict`s.

tests/typing/api.py

@@ -43,6 +43,14 @@ def bytes_dumps(
     processors=[structlog.processors.JSONRenderer(serializer=bytes_dumps)]
 )
 
+structlog.configure(
+    processors=[
+        structlog.stdlib.render_to_log_args_and_kwargs,
+    ],
+    logger_factory=structlog.stdlib.LoggerFactory(),
+    wrapper_class=structlog.stdlib.BoundLogger,
+    cache_logger_on_first_use=True,
+)
 
 structlog.configure(
     processors=[