From 95c16aa9af7c51f26ba3ea8512b4ba782f5d216f Mon Sep 17 00:00:00 2001 From: Adrian Date: Mon, 10 Aug 2026 18:29:53 +0200 Subject: [PATCH] Deprecate interpolating log formatter messages with the returned dict (#7971) --- scrapy/utils/log.py | 20 ++++++++++++++++++++ tests/test_utils_log.py | 20 ++++++++++++++++++-- 2 files changed, 38 insertions(+), 2 deletions(-) diff --git a/scrapy/utils/log.py b/scrapy/utils/log.py index bfa39169f..d221ed6f9 100644 --- a/scrapy/utils/log.py +++ b/scrapy/utils/log.py @@ -2,7 +2,9 @@ from __future__ import annotations import logging import pprint +import re import sys +import warnings from collections.abc import MutableMapping from logging.config import dictConfig from typing import TYPE_CHECKING, Any, cast @@ -12,6 +14,7 @@ from twisted.python import log as twisted_log from twisted.python.failure import Failure import scrapy +from scrapy.exceptions import ScrapyDeprecationWarning from scrapy.settings import Settings from scrapy.utils.versions import get_versions @@ -242,6 +245,9 @@ class LogCounterHandler(logging.Handler): self.crawler.stats.inc_value(sname) +_MSG_MAPPING_PLACEHOLDER = re.compile(r"%\(\w+\)") + + def logformatter_adapter( logkws: LogFormatterResult, ) -> tuple[Any, ...]: @@ -257,6 +263,20 @@ def logformatter_adapter( # 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: + if _MSG_MAPPING_PLACEHOLDER.search(message): + # The log formatter method has already returned, so there is no + # frame of it left in the stack to point at. msg is part of the + # warning message instead, so that each offending method gets its + # own warning. + warnings.warn( + f"A log formatter method returned msg {message!r} with " + f"%(name)s placeholders and no args. Interpolating msg with " + f"the returned dict is deprecated, return those values under " + f"args instead.", + ScrapyDeprecationWarning, + stacklevel=1, + ) + return (level, message, logkws) return (level, message) if isinstance(args, tuple): return (level, message, *args) diff --git a/tests/test_utils_log.py b/tests/test_utils_log.py index 42b2b95fd..3ea82ba8c 100644 --- a/tests/test_utils_log.py +++ b/tests/test_utils_log.py @@ -4,12 +4,14 @@ import json import logging import re import sys +import warnings from io import StringIO from typing import TYPE_CHECKING, Any, cast import pytest from twisted.python.failure import Failure +from scrapy.exceptions import ScrapyDeprecationWarning from scrapy.utils.log import ( LogCounterHandler, SpiderLoggerAdapter, @@ -332,7 +334,9 @@ class TestLogformatterAdapter: "LogFormatterResult", {"level": logging.INFO, "msg": "90% done", "args": args}, ) - assert self._log(caplog, logkws) == "90% done" + with warnings.catch_warnings(): + warnings.simplefilter("error", ScrapyDeprecationWarning) + assert self._log(caplog, logkws) == "90% done" @pytest.mark.parametrize( ("msg", "args"), @@ -345,4 +349,16 @@ class TestLogformatterAdapter: args: dict[str, Any] | tuple[Any, ...], ) -> None: logkws: LogFormatterResult = {"level": logging.INFO, "msg": msg, "args": args} - assert self._log(caplog, logkws) == "90% done" + with warnings.catch_warnings(): + warnings.simplefilter("error", ScrapyDeprecationWarning) + assert self._log(caplog, logkws) == "90% done" + + def test_msg_mapping_placeholders_without_args( + self, caplog: pytest.LogCaptureFixture + ) -> None: + logkws = cast( + "LogFormatterResult", + {"level": logging.INFO, "msg": "%(pct)d%% done", "pct": 90}, + ) + with pytest.warns(ScrapyDeprecationWarning, match="no args"): + assert self._log(caplog, logkws) == "90% done"