diff --git a/scrapy/utils/log.py b/scrapy/utils/log.py index 7645b235e..ee357c031 100644 --- a/scrapy/utils/log.py +++ b/scrapy/utils/log.py @@ -245,7 +245,7 @@ class LogCounterHandler(logging.Handler): def logformatter_adapter( logkws: LogFormatterResult, -) -> tuple[int, str, dict[str, Any] | tuple[Any, ...]]: +) -> tuple[Any, ...]: """ Helper that takes the dictionary output from the methods in LogFormatter and adapts it into a tuple of positional arguments for logger.log calls. @@ -253,10 +253,14 @@ def logformatter_adapter( level = logkws.get("level", logging.INFO) message = logkws.get("msg") or "" - # NOTE: This also handles 'args' being an empty dict, that case doesn't - # play well in logger.log calls - args = cast("dict[str, Any]", logkws) if not logkws.get("args") else logkws["args"] - + args = logkws.get("args") + # logging interpolates the message whenever it receives any positional + # argument, so empty args are left out. Tuple args become one positional + # argument each, while a dict is a single positional argument. + if not args: + return (level, message) + if isinstance(args, tuple): + return (level, message, *args) return (level, message, args) diff --git a/tests/test_utils_log.py b/tests/test_utils_log.py index 7f5301387..42b2b95fd 100644 --- a/tests/test_utils_log.py +++ b/tests/test_utils_log.py @@ -5,7 +5,7 @@ import logging import re import sys from io import StringIO -from typing import TYPE_CHECKING, Any +from typing import TYPE_CHECKING, Any, cast import pytest from twisted.python.failure import Failure @@ -16,6 +16,7 @@ from scrapy.utils.log import ( StreamLogger, TopLevelFormatter, failure_to_exc_info, + logformatter_adapter, ) from scrapy.utils.test import get_crawler from tests.spiders import LogSpider @@ -24,6 +25,7 @@ if TYPE_CHECKING: from collections.abc import Generator, Mapping, MutableMapping from scrapy.crawler import Crawler + from scrapy.logformatter import LogFormatterResult class TestFailureToExcInfo: @@ -311,3 +313,36 @@ class TestLoggingWithExtra: assert log_contents["message"] == log_message assert self.regex_pattern.match(log_contents["spider"]) assert log_contents["important_info"] == extra["important_info"] + + +class TestLogformatterAdapter: + @staticmethod + def _log(caplog: pytest.LogCaptureFixture, logkws: LogFormatterResult) -> str: + with caplog.at_level(logging.INFO): + logging.getLogger(__name__).log(*logformatter_adapter(logkws)) + return caplog.records[-1].getMessage() + + @pytest.mark.parametrize("args", [None, {}, ()]) + def test_empty_args( + self, + caplog: pytest.LogCaptureFixture, + args: dict[str, Any] | tuple[Any, ...] | None, + ) -> None: + logkws = cast( + "LogFormatterResult", + {"level": logging.INFO, "msg": "90% done", "args": args}, + ) + assert self._log(caplog, logkws) == "90% done" + + @pytest.mark.parametrize( + ("msg", "args"), + [("%(pct)d%% done", {"pct": 90}), ("%d%% done", (90,))], + ) + def test_args( + self, + caplog: pytest.LogCaptureFixture, + msg: str, + args: dict[str, Any] | tuple[Any, ...], + ) -> None: + logkws: LogFormatterResult = {"level": logging.INFO, "msg": msg, "args": args} + assert self._log(caplog, logkws) == "90% done"