From 25e6884e2f24d554e3527cbe20ff001913cc5863 Mon Sep 17 00:00:00 2001 From: Adrian Date: Mon, 27 Jul 2026 17:34:10 +0200 Subject: [PATCH] Address recursion and media ignore-request reporting issues (#7673) * Address recursion and media ignore-request reporting issues * Improve test coverage * Address feedback --- scrapy/core/engine.py | 21 ++++--- scrapy/downloadermiddlewares/offsite.py | 2 +- scrapy/pipelines/files.py | 36 ++++++----- scrapy/pipelines/media.py | 24 +++++++- tests/test_downloadermiddleware_offsite.py | 14 +++++ tests/test_engine_download.py | 20 ++++++ tests/test_pipeline_files.py | 72 +++++++++++++++++++++- tests/test_pipeline_media.py | 18 +++++- 8 files changed, 176 insertions(+), 31 deletions(-) diff --git a/scrapy/core/engine.py b/scrapy/core/engine.py index 1033e874f..efac5f71c 100644 --- a/scrapy/core/engine.py +++ b/scrapy/core/engine.py @@ -470,16 +470,17 @@ class ExecutionEngine: """ if self.spider is None: raise RuntimeError(f"No open spider to crawl: {request}") - try: - response_or_request = await maybe_deferred_to_future( - self._download(request) - ) - finally: - assert self._slot is not None - self._slot.remove_request(request) - if isinstance(response_or_request, Request): - return await self.download_async(response_or_request) - return response_or_request + while True: + try: + response_or_request = await maybe_deferred_to_future( + self._download(request) + ) + finally: + assert self._slot is not None + self._slot.remove_request(request) + if not isinstance(response_or_request, Request): + return response_or_request + request = response_or_request @inlineCallbacks def _download( diff --git a/scrapy/downloadermiddlewares/offsite.py b/scrapy/downloadermiddlewares/offsite.py index e03dc040e..db85b62a1 100644 --- a/scrapy/downloadermiddlewares/offsite.py +++ b/scrapy/downloadermiddlewares/offsite.py @@ -61,7 +61,7 @@ class OffsiteMiddleware: ) self.stats.inc_value("offsite/domains") self.stats.inc_value("offsite/filtered") - raise IgnoreRequest + raise IgnoreRequest(f"Filtered offsite request to {domain!r}") def should_follow(self, request: Request, spider: Spider) -> bool: regex = self.host_regex diff --git a/scrapy/pipelines/files.py b/scrapy/pipelines/files.py index 70dc36e35..8e8082332 100644 --- a/scrapy/pipelines/files.py +++ b/scrapy/pipelines/files.py @@ -27,7 +27,15 @@ from twisted.internet.defer import Deferred, maybeDeferred from scrapy.exceptions import IgnoreRequest, NotConfigured, ScrapyDeprecationWarning from scrapy.http import Request, Response from scrapy.http.request import NO_CALLBACK -from scrapy.pipelines.media import FileInfo, FileInfoOrError, MediaPipeline +from scrapy.pipelines.media import ( + FileException as FileException, # noqa: PLC0414 # re-exported for backward compatibility +) +from scrapy.pipelines.media import ( + FileInfo, + FileInfoOrError, + MediaPipeline, + _MediaRequestFiltered, +) from scrapy.utils.asyncio import run_in_thread from scrapy.utils.boto import is_botocore_available from scrapy.utils.datatypes import CaseInsensitiveDict @@ -75,10 +83,6 @@ def _md5sum(file: IO[bytes]) -> str: return m.hexdigest() -class FileException(Exception): - """General media error exception""" - - class StatInfo(TypedDict, total=False): checksum: str last_modified: float @@ -597,20 +601,20 @@ class FilesPipeline(MediaPipeline): def media_failed( self, failure: Failure, request: Request, info: MediaPipeline.SpiderInfo ) -> NoReturn: - if not isinstance(failure.value, IgnoreRequest): - referer = referer_str(request) - logger.warning( - "File (unknown-error): Error downloading %(medianame)s from " - "%(request)s referred in <%(referer)s>: %(exception)s", - { - "medianame": self.MEDIA_NAME, - "request": request, - "referer": referer, - "exception": failure.value, - }, + referer = referer_str(request) + if isinstance(failure.value, IgnoreRequest): + logger.debug( + f"File (filtered): Not downloading {self.MEDIA_NAME} from " + f"{request} referred in <{referer}>: {failure.value}", extra={"spider": info.spider}, ) + raise _MediaRequestFiltered(str(failure.value)) from failure.value + logger.warning( + f"File (unknown-error): Error downloading {self.MEDIA_NAME} from " + f"{request} referred in <{referer}>: {failure.value}", + extra={"spider": info.spider}, + ) raise FileException async def media_downloaded( diff --git a/scrapy/pipelines/media.py b/scrapy/pipelines/media.py index 5b5d2dcb2..764f82a78 100644 --- a/scrapy/pipelines/media.py +++ b/scrapy/pipelines/media.py @@ -55,6 +55,25 @@ FileInfoOrError: TypeAlias = ( logger = logging.getLogger(__name__) +class FileException(Exception): + """General media error exception""" + + +class _MediaRequestFiltered(FileException): + """Raised internally by media pipelines when a media request is filtered + out (e.g. as an offsite request) instead of being downloaded. + + It is a subclass of :exc:`FileException` for backward compatibility, but + unlike an actual download error it is logged at the ``DEBUG`` level and + without a traceback, since filtering a request is expected behavior rather + than an error. + """ + + +def _media_request_filtered(failure: Failure) -> bool: + return isinstance(failure.value, _MediaRequestFiltered) + + class MediaPipeline(ABC): LOG_FAILED_RESULTS: bool = True @@ -193,7 +212,8 @@ class MediaPipeline(ABC): result = await self._check_media_to_download(request, info, item=item) except Exception: result = Failure() - logger.exception(result) + if not _media_request_filtered(result): + logger.exception(result) self._cache_result_and_execute_waiters(result, fp, info) return await maybe_deferred_to_future(wad) # it must return wad at last @@ -304,6 +324,8 @@ class MediaPipeline(ABC): for ok, value in results: if not ok: assert isinstance(value, Failure) + if _media_request_filtered(value): + continue logger.error( "%(class)s found errors processing %(item)s", {"class": self.__class__.__name__, "item": item}, diff --git a/tests/test_downloadermiddleware_offsite.py b/tests/test_downloadermiddleware_offsite.py index c0b8dc4dd..78efb0191 100644 --- a/tests/test_downloadermiddleware_offsite.py +++ b/tests/test_downloadermiddleware_offsite.py @@ -1,3 +1,5 @@ +import re + import pytest from scrapy import Request, Spider @@ -231,3 +233,15 @@ def test_repeated_offsite_domain(): mw.process_request(req2) assert crawler.stats.get_value("offsite/domains") == 1 # not incremented again assert crawler.stats.get_value("offsite/filtered") == 2 + + +def test_ignore_request_reason(): + crawler = get_crawler(Spider) + crawler.spider = crawler._create_spider(name="a", allowed_domains=["example.com"]) + mw = OffsiteMiddleware.from_crawler(crawler) + mw.spider_opened(crawler.spider) + request = Request("http://other.org/1") + with pytest.raises( + IgnoreRequest, match=re.escape("Filtered offsite request to 'other.org'") + ): + mw.process_request(request) diff --git a/tests/test_engine_download.py b/tests/test_engine_download.py index f15bfd5e2..962808d96 100644 --- a/tests/test_engine_download.py +++ b/tests/test_engine_download.py @@ -1,5 +1,6 @@ from __future__ import annotations +import sys from unittest.mock import Mock, call import pytest @@ -73,6 +74,25 @@ class TestEngineDownloadAsync: [call(original_request), call(redirect_request)] ) + @coroutine_test + async def test_download_async_many_redirects(self, engine): + """A long chain of requests being replaced by new ones is handled + iteratively, without hitting the recursion limit.""" + count = sys.getrecursionlimit() * 2 + requests = [Request(f"http://example.com/{i}") for i in range(count)] + final_response = Response("http://example.com/final", body=b"done") + engine.downloader.fetch.side_effect = [ + *(defer.succeed(request) for request in requests[1:]), + defer.succeed(final_response), + ] + engine.spider = Mock() + engine._slot.add_request = Mock() + engine._slot.remove_request = Mock() + + result = await self._download(engine, requests[0]) + assert result == final_response + assert engine.downloader.fetch.call_count == count + @coroutine_test async def test_download_async_no_spider(self, engine): """Test async download attempt when no spider is available.""" diff --git a/tests/test_pipeline_files.py b/tests/test_pipeline_files.py index a0ae3635b..4f6fa21a0 100644 --- a/tests/test_pipeline_files.py +++ b/tests/test_pipeline_files.py @@ -2,6 +2,7 @@ import base64 import dataclasses import logging import random +import re import time from abc import ABC, abstractmethod from datetime import datetime @@ -19,18 +20,20 @@ import attr import pytest from itemadapter import ItemAdapter from twisted.internet.defer import Deferred +from twisted.python.failure import Failure -from scrapy.exceptions import NotConfigured +from scrapy.exceptions import IgnoreRequest, NotConfigured from scrapy.http import Request, Response from scrapy.item import Field, Item from scrapy.pipelines.files import ( + FileException, FilesPipeline, FSFilesStore, FTPFilesStore, GCSFilesStore, S3FilesStore, ) -from scrapy.pipelines.media import MediaPipeline +from scrapy.pipelines.media import MediaPipeline, _MediaRequestFiltered from scrapy.settings import Settings from scrapy.utils.asyncio import call_later from scrapy.utils.defer import maybe_deferred_to_future @@ -290,6 +293,71 @@ class TestFilesPipeline: request = Request("http://example.com") assert file_path(request, item=item) == "full/path-to-store-file" + def test_media_failed_filtered_request( + self, caplog: pytest.LogCaptureFixture + ) -> None: + """A filtered media request (IgnoreRequest) is reported as a + _MediaRequestFiltered exception and logged at the DEBUG level, instead + of as a download error with a traceback.""" + request = Request("http://example.com/file.pdf") + reason = "Filtered offsite request to 'example.com'" + failure = Failure(IgnoreRequest(reason)) + + with ( + caplog.at_level(logging.DEBUG), + pytest.raises(_MediaRequestFiltered, match=re.escape(reason)), + ): + self.pipeline.media_failed(failure, request, self.pipeline.spiderinfo) + + assert len(caplog.records) == 1 + record = caplog.records[0] + assert record.levelname == "DEBUG" + assert record.exc_info is None + assert reason in record.getMessage() + + def test_media_failed_download_error( + self, caplog: pytest.LogCaptureFixture + ) -> None: + """A genuine download error is reported as a FileException and logged as + a warning.""" + request = Request("http://example.com/file.pdf") + failure = Failure(Exception("boom")) + + with caplog.at_level(logging.WARNING), pytest.raises(FileException): + self.pipeline.media_failed(failure, request, self.pipeline.spiderinfo) + + assert len(caplog.records) == 1 + assert caplog.records[0].levelname == "WARNING" + + @coroutine_test + async def test_process_item_filtered_request( + self, caplog: pytest.LogCaptureFixture + ) -> None: + """A filtered (e.g. offsite) media request is processed as a failed + result without being logged as an error with a traceback.""" + item_url = "http://example.com/file.pdf" + item = _create_item_with_files(item_url) + request = Request( + item_url, + meta={ + "response": IgnoreRequest("Filtered offsite request to 'example.com'") + }, + ) + with ( + caplog.at_level(logging.DEBUG), + mock.patch.object( + FilesPipeline, "get_media_requests", return_value=[request] + ), + ): + result = await self.pipeline.process_item(item) + + assert result["files"] == [] + assert not any(r.levelname in ("WARNING", "ERROR") for r in caplog.records) + assert any( + "Filtered offsite request to 'example.com'" in r.getMessage() + for r in caplog.records + ) + @pytest.mark.parametrize( "bad_type", [ diff --git a/tests/test_pipeline_media.py b/tests/test_pipeline_media.py index ee7a576db..be471e5fe 100644 --- a/tests/test_pipeline_media.py +++ b/tests/test_pipeline_media.py @@ -1,5 +1,6 @@ from __future__ import annotations +import logging from unittest.mock import MagicMock import pytest @@ -10,7 +11,7 @@ from scrapy import signals from scrapy.exceptions import ScrapyDeprecationWarning from scrapy.http import Request, Response from scrapy.pipelines.files import FileException -from scrapy.pipelines.media import MediaPipeline +from scrapy.pipelines.media import MediaPipeline, _MediaRequestFiltered from scrapy.utils.defer import _defer_sleep_async from scrapy.utils.log import failure_to_exc_info from scrapy.utils.signal import disconnect_all @@ -152,6 +153,21 @@ class TestBaseMediaPipeline: assert new_item is item assert len(log.records) == 0 + def test_item_completed_filtered_request_not_logged( + self, caplog: pytest.LogCaptureFixture + ) -> None: + """Filtered media requests (e.g. offsite ones) are not logged as errors + by item_completed(), as they are not download errors.""" + item = {"name": "name"} + fail = Failure(_MediaRequestFiltered("Filtered offsite request")) + results = [(True, 1), (False, fail)] + + with caplog.at_level(logging.DEBUG): + new_item = self.pipe.item_completed(results, item, self.info) + + assert new_item is item + assert len(caplog.records) == 0 + @coroutine_test async def test_default_process_item(self): item = {"name": "name"}