Merge 04c27b5477 into d8ba1571e7

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(

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

scrapy/pipelines/files.py

@@ -79,6 +79,17 @@ 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.
+    """
+
+
 class StatInfo(TypedDict, total=False):
     checksum: str
     last_modified: float
@@ -597,20 +608,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(

scrapy/pipelines/media.py

@@ -55,6 +55,12 @@ FileInfoOrError: TypeAlias = (
 logger = logging.getLogger(__name__)
 
 
+def _media_request_filtered(failure: Failure) -> bool:
+    from scrapy.pipelines.files import _MediaRequestFiltered  # noqa: PLC0415
+
+    return isinstance(failure.value, _MediaRequestFiltered)
+
+
 class MediaPipeline(ABC):
     LOG_FAILED_RESULTS: bool = True
 
@@ -193,7 +199,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 +311,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},

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)

tests/test_engine.py

@@ -574,6 +574,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."""

tests/test_pipeline_files.py

@@ -1,6 +1,7 @@
 import dataclasses
 import os
 import random
+import re
 import time
 from abc import ABC, abstractmethod
 from datetime import datetime
@@ -18,17 +19,21 @@ from urllib.parse import urlparse
 import attr
 import pytest
 from itemadapter import ItemAdapter
+from testfixtures import LogCapture
 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,
+    _MediaRequestFiltered,
 )
 from scrapy.settings import Settings
 from scrapy.utils.asyncio import call_later
@@ -297,6 +302,65 @@ 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):
+        """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 (
+            LogCapture() as log,
+            pytest.raises(_MediaRequestFiltered, match=re.escape(reason)),
+        ):
+            self.pipeline.media_failed(failure, request, self.pipeline.spiderinfo)
+
+        assert len(log.records) == 1
+        record = log.records[0]
+        assert record.levelname == "DEBUG"
+        assert record.exc_info is None
+        assert reason in record.getMessage()
+
+    def test_media_failed_download_error(self):
+        """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 LogCapture() as log, pytest.raises(FileException):
+            self.pipeline.media_failed(failure, request, self.pipeline.spiderinfo)
+
+        assert len(log.records) == 1
+        assert log.records[0].levelname == "WARNING"
+
+    @coroutine_test
+    async def test_process_item_filtered_request(self):
+        """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 (
+            LogCapture() as log,
+            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 log.records)
+        assert any(
+            "Filtered offsite request to 'example.com'" in r.getMessage()
+            for r in log.records
+        )
+
     @pytest.mark.parametrize(
         "bad_type",
         [

tests/test_pipeline_media.py

@@ -10,7 +10,7 @@ from scrapy import signals
 from scrapy.exceptions import ScrapyDeprecationWarning
 from scrapy.http import Request, Response
 from scrapy.http.request import NO_CALLBACK
-from scrapy.pipelines.files import FileException
+from scrapy.pipelines.files import FileException, _MediaRequestFiltered
 from scrapy.pipelines.media import MediaPipeline
 from scrapy.utils.defer import _defer_sleep_async
 from scrapy.utils.log import failure_to_exc_info
@@ -162,6 +162,19 @@ class TestBaseMediaPipeline:
         assert new_item is item
         assert len(log.records) == 0
 
+    def test_item_completed_filtered_request_not_logged(self):
+        """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 LogCapture() as log:
+            new_item = self.pipe.item_completed(results, item, self.info)
+
+        assert new_item is item
+        assert len(log.records) == 0
+
     @coroutine_test
     async def test_default_process_item(self):
         item = {"name": "name"}