RomanNum3ral
/
scrapy
mirror of https://github.com/scrapy/scrapy.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Scope unscoped log counting to crawler context 

Signed-off-by: Mridankan Mandal <xerontitan90@gmail.com>
This commit is contained in:
Mridankan Mandal 2026-06-28 03:01:03 +05:30
parent b3cd077b59
commit 9f97dcab05
No known key found for this signature in database
GPG Key ID: C24AD565E950FF59
6 changed files with 273 additions and 76 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

5
scrapy/core/engine.py
View File

@ -41,7 +41,7 @@ from scrapy.utils.defer import (
maybe_deferred_to_future,
)
from scrapy.utils.deprecate import argument_is_required
from scrapy.utils.log import failure_to_exc_info, logformatter_adapter
from scrapy.utils.log import failure_to_exc_info, log_crawler, logformatter_adapter
from scrapy.utils.misc import build_from_crawler, load_object
from scrapy.utils.python import global_object_name
from scrapy.utils.reactor import CallLaterOnce
@ -274,7 +274,8 @@ class ExecutionEngine:
"""
assert self._start is not None
try:
item_or_request = await anext(self._start)
with log_crawler(self.crawler):
item_or_request = await anext(self._start)
except StopAsyncIteration:
self._start = None
except Exception as exception:

84
scrapy/core/scraper.py
View File

@ -35,7 +35,7 @@ from scrapy.utils.defer import (
parallel_async,
)
from scrapy.utils.deprecate import method_is_overridden
from scrapy.utils.log import failure_to_exc_info, logformatter_adapter
from scrapy.utils.log import failure_to_exc_info, log_crawler, logformatter_adapter
from scrapy.utils.misc import load_object, warn_on_generator_with_return_value
from scrapy.utils.python import global_object_name
from scrapy.utils.spider import iterate_spider_output
@ -310,40 +310,43 @@ class Scraper:
.. versionadded:: 2.13
"""
await _defer_sleep_async()
assert self.crawler.spider
if isinstance(result, Response):
if getattr(result, "request", None) is None:
result.request = request
assert result.request
callback = result.request.callback or self.crawler.spider._parse
warn_on_generator_with_return_value(self.crawler.spider, callback)
output = callback(result, **result.request.cb_kwargs)
if isinstance(output, Deferred):
warnings.warn(
f"{callback} returned a Deferred."
f" Returning Deferreds from spider callbacks is deprecated.",
ScrapyDeprecationWarning,
stacklevel=2,
with log_crawler(self.crawler):
assert self.crawler.spider
if isinstance(result, Response):
if getattr(result, "request", None) is None:
result.request = request
assert result.request
callback = result.request.callback or self.crawler.spider._parse
warn_on_generator_with_return_value(self.crawler.spider, callback)
output = callback(result, **result.request.cb_kwargs)
if isinstance(output, Deferred):
warnings.warn(
f"{callback} returned a Deferred."
f" Returning Deferreds from spider callbacks is deprecated.",
ScrapyDeprecationWarning,
stacklevel=2,
)
else: # result is a Failure
# TODO: properly type adding this attribute to a Failure
result.request = request # type: ignore[attr-defined]
if not request.errback:
result.raiseException()
warn_on_generator_with_return_value(
self.crawler.spider, request.errback
)
else: # result is a Failure
# TODO: properly type adding this attribute to a Failure
result.request = request # type: ignore[attr-defined]
if not request.errback:
result.raiseException()
warn_on_generator_with_return_value(self.crawler.spider, request.errback)
output = request.errback(result)
if isinstance(output, Failure):
output.raiseException()
# else the errback returned actual output (like a callback),
# which needs to be passed to iterate_spider_output()
if isinstance(output, Deferred):
warnings.warn(
f"{request.errback} returned a Deferred."
f" Returning Deferreds from spider errbacks is deprecated.",
ScrapyDeprecationWarning,
stacklevel=2,
)
return await ensure_awaitable(iterate_spider_output(output))
output = request.errback(result)
if isinstance(output, Failure):
output.raiseException()
# else the errback returned actual output (like a callback),
# which needs to be passed to iterate_spider_output()
if isinstance(output, Deferred):
warnings.warn(
f"{request.errback} returned a Deferred."
f" Returning Deferreds from spider errbacks is deprecated.",
ScrapyDeprecationWarning,
stacklevel=2,
)
return await ensure_awaitable(iterate_spider_output(output))
def handle_spider_error(
self,
@ -491,12 +494,13 @@ class Scraper:
assert self.crawler.spider is not None # typing
self.slot.itemproc_size += 1
try:
if self._itemproc_has_async["process_item"]:
output = await self.itemproc.process_item_async(item)
else:
output = await maybe_deferred_to_future(
self.itemproc.process_item(item, self.crawler.spider)
)
with log_crawler(self.crawler):
if self._itemproc_has_async["process_item"]:
output = await self.itemproc.process_item_async(item)
else:
output = await maybe_deferred_to_future(
self.itemproc.process_item(item, self.crawler.spider)
)
except DropItem as ex:
logkws = self.logformatter.dropped(item, ex, response, self.crawler.spider)
if logkws is not None:

62
scrapy/crawler.py
View File

@ -25,6 +25,7 @@ from scrapy.utils.log import (
configure_logging,
get_scrapy_root_handler,
install_scrapy_root_handler,
log_crawler,
log_reactor_info,
log_scrapy_info,
)
@ -184,18 +185,19 @@ class Crawler:
)
self.crawling = self._started = True
try:
self.spider = self._create_spider(*args, **kwargs)
self._apply_settings()
self._update_root_log_handler()
self.engine = self._create_engine()
yield deferred_from_coro(self.engine.open_spider_async())
yield deferred_from_coro(self.engine.start_async())
except Exception:
self.crawling = False
if self.engine is not None:
yield deferred_from_coro(self.engine.close_async())
raise
with log_crawler(self):
try:
self.spider = self._create_spider(*args, **kwargs)
self._apply_settings()
self._update_root_log_handler()
self.engine = self._create_engine()
yield deferred_from_coro(self.engine.open_spider_async())
yield deferred_from_coro(self.engine.start_async())
except Exception:
self.crawling = False
if self.engine is not None:
yield deferred_from_coro(self.engine.close_async())
raise
async def crawl_async(self, *args: Any, **kwargs: Any) -> None:
"""Start the crawler by instantiating its spider class with the given
@ -214,18 +216,19 @@ class Crawler:
)
self.crawling = self._started = True
try:
self.spider = self._create_spider(*args, **kwargs)
self._apply_settings()
self._update_root_log_handler()
self.engine = self._create_engine()
await self.engine.open_spider_async()
await self.engine.start_async()
except Exception:
self.crawling = False
if self.engine is not None:
await self.engine.close_async()
raise
with log_crawler(self):
try:
self.spider = self._create_spider(*args, **kwargs)
self._apply_settings()
self._update_root_log_handler()
self.engine = self._create_engine()
await self.engine.open_spider_async()
await self.engine.start_async()
except Exception:
self.crawling = False
if self.engine is not None:
await self.engine.close_async()
raise
def _create_spider(self, *args: Any, **kwargs: Any) -> Spider:
return self.spidercls.from_crawler(self, *args, **kwargs)
@ -248,11 +251,12 @@ class Crawler:
.. versionadded:: 2.14
"""
if self.crawling:
self.crawling = False
assert self.engine
if self.engine.running:
await self.engine.stop_async()
with log_crawler(self):
if self.crawling:
self.crawling = False
assert self.engine
if self.engine.running:
await self.engine.stop_async()
@staticmethod
def _get_component(

36
scrapy/utils/log.py
View File

@ -3,7 +3,9 @@ from __future__ import annotations
import logging
import pprint
import sys
from collections.abc import MutableMapping
from collections.abc import Iterator, MutableMapping
from contextlib import contextmanager
from contextvars import ContextVar
from logging.config import dictConfig
from typing import TYPE_CHECKING, Any, cast
@ -23,6 +25,20 @@ if TYPE_CHECKING:
logger = logging.getLogger(__name__)
_log_crawler: ContextVar[Crawler | None] = ContextVar("log_crawler", default=None)
@contextmanager
def log_crawler(crawler: Crawler) -> Iterator[None]:
token = _log_crawler.set(crawler)
try:
yield
finally:
_log_crawler.reset(token)
def get_log_crawler() -> Crawler | None:
return _log_crawler.get()
def failure_to_exc_info(
@ -239,14 +255,24 @@ class LogCounterHandler(logging.Handler):
def emit(self, record: logging.LogRecord) -> None:
record_crawler = getattr(record, "crawler", None)
record_spider = getattr(record, "spider", None)
if record_crawler is None:
record_crawler = getattr(record_spider, "crawler", None)
if record_crawler is None:
record_crawler = get_log_crawler()
if record_crawler is not None and record_crawler is not self.crawler:
return
record_spider = getattr(record, "spider", None)
record_spider_crawler = getattr(record_spider, "crawler", None)
if (
record_spider_crawler is not None
and record_spider_crawler is not self.crawler
record_crawler is None
and sum(
isinstance(handler, LogCounterHandler)
for handler in logging.root.handlers
)
> 1
):
return

121
tests/test_crawler.py
View File

@ -7,6 +7,7 @@ from pathlib import Path
from typing import Any, ClassVar
import pytest
from twisted.internet.defer import Deferred
from zope.interface.exceptions import MultipleInvalid
import scrapy
@ -555,6 +556,126 @@ class TestCrawlerLogging:
assert info_count == 1
assert crawler.stats.get_value("log_count/DEBUG", 0) == 0
@coroutine_test
async def test_log_counter_scope_isolated_between_crawlers(self) -> None:
barrier: Deferred[None] = Deferred()
counts: dict[str, int] = {}
opened = 0
root_level = logging.root.level
class BaseSpider(scrapy.Spider):
custom_settings = {
"LOG_LEVEL": "INFO",
"EXTENSIONS": {
"scrapy.extensions.logstats.LogStats": None,
"scrapy.extensions.telnet.TelnetConsole": None,
},
}
start_urls = ["data:,test"]
@classmethod
def from_crawler(cls, crawler, *args, **kwargs):
spider = super().from_crawler(crawler, *args, **kwargs)
crawler.signals.connect(
spider.spider_opened, signal=scrapy.signals.spider_opened
)
return spider
def spider_opened(self, spider) -> None:
nonlocal opened
opened += 1
if opened == 2 and not barrier.called:
barrier.callback(None)
async def parse(self, response):
await maybe_deferred_to_future(barrier)
logging.info("info message") # noqa: LOG015
assert self.crawler.stats
counts[self.name] = self.crawler.stats.get_value("log_count/INFO")
return []
class Spider1(BaseSpider):
name = "spider1"
class Spider2(BaseSpider):
name = "spider2"
try:
logging.root.setLevel(logging.INFO)
runner = CrawlerRunner()
crawler1 = runner.create_crawler(Spider1)
crawler2 = runner.create_crawler(Spider2)
d1 = runner.crawl(crawler1)
d2 = runner.crawl(crawler2)
await maybe_deferred_to_future(d1)
await maybe_deferred_to_future(d2)
finally:
logging.root.setLevel(root_level)
assert counts == {"spider1": 1, "spider2": 1}
@coroutine_test
async def test_log_counter_scope_isolated_between_crawlers_in_start(
self,
) -> None:
barrier: Deferred[None] = Deferred()
counts: dict[str, int] = {}
opened = 0
root_level = logging.root.level
class BaseSpider(scrapy.Spider):
custom_settings = {
"LOG_LEVEL": "INFO",
"EXTENSIONS": {
"scrapy.extensions.logstats.LogStats": None,
"scrapy.extensions.telnet.TelnetConsole": None,
},
}
@classmethod
def from_crawler(cls, crawler, *args, **kwargs):
spider = super().from_crawler(crawler, *args, **kwargs)
crawler.signals.connect(
spider.spider_opened, signal=scrapy.signals.spider_opened
)
return spider
def spider_opened(self, spider) -> None:
nonlocal opened
opened += 1
if opened == 2 and not barrier.called:
barrier.callback(None)
async def start(self):
await maybe_deferred_to_future(barrier)
logging.info("info message") # noqa: LOG015
yield scrapy.Request("data:,test", dont_filter=True)
async def parse(self, response):
assert self.crawler.stats
counts[self.name] = self.crawler.stats.get_value("log_count/INFO")
return []
class Spider1(BaseSpider):
name = "spider1"
class Spider2(BaseSpider):
name = "spider2"
try:
logging.root.setLevel(logging.INFO)
runner = CrawlerRunner()
crawler1 = runner.create_crawler(Spider1)
crawler2 = runner.create_crawler(Spider2)
d1 = runner.crawl(crawler1)
d2 = runner.crawl(crawler2)
await maybe_deferred_to_future(d1)
await maybe_deferred_to_future(d2)
finally:
logging.root.setLevel(root_level)
assert counts == {"spider1": 1, "spider2": 1}
def test_spider_custom_settings_log_append(self, tmp_path: Path) -> None:
log_file = Path(tmp_path, "log.txt")
log_file.write_text("previous message\n", encoding="utf-8")

41
tests/test_utils_log.py
View File

@ -17,6 +17,7 @@ from scrapy.utils.log import (
StreamLogger,
TopLevelFormatter,
failure_to_exc_info,
log_crawler,
)
from scrapy.utils.test import get_crawler
from tests.spiders import LogSpider
@ -113,6 +114,46 @@ class TestLogCounterHandler:
assert crawler.stats
assert crawler.stats.get_value("log_count/ERROR") is None
def test_log_crawler_context(self, crawler: Crawler) -> None:
other_crawler = get_crawler(settings_dict={"LOG_LEVEL": "WARNING"})
logger = logging.getLogger("test")
logger.setLevel(logging.DEBUG)
handler = LogCounterHandler(crawler, level=crawler.settings.get("LOG_LEVEL"))
other_handler = LogCounterHandler(
other_crawler, level=other_crawler.settings.get("LOG_LEVEL")
)
logging.root.addHandler(handler)
logging.root.addHandler(other_handler)
try:
with log_crawler(crawler):
logger.error("test log msg")
finally:
logging.root.removeHandler(handler)
logging.root.removeHandler(other_handler)
assert crawler.stats
assert crawler.stats.get_value("log_count/ERROR") == 1
assert other_crawler.stats
assert other_crawler.stats.get_value("log_count/ERROR") is None
def test_ambiguous_record(self, crawler: Crawler) -> None:
other_crawler = get_crawler(settings_dict={"LOG_LEVEL": "WARNING"})
logger = logging.getLogger("test")
handler = LogCounterHandler(crawler, level=crawler.settings.get("LOG_LEVEL"))
other_handler = LogCounterHandler(
other_crawler, level=other_crawler.settings.get("LOG_LEVEL")
)
logging.root.addHandler(handler)
logging.root.addHandler(other_handler)
try:
logger.error("test log msg")
finally:
logging.root.removeHandler(handler)
logging.root.removeHandler(other_handler)
assert crawler.stats
assert crawler.stats.get_value("log_count/ERROR") is None
assert other_crawler.stats
assert other_crawler.stats.get_value("log_count/ERROR") is None
def test_filtered_out_level(self, crawler: Crawler, logger: logging.Logger) -> None:
logger.debug("test log msg")
assert crawler.stats