diff --git a/scrapy/core/scraper.py b/scrapy/core/scraper.py index c5bb48ea6..21820e988 100644 --- a/scrapy/core/scraper.py +++ b/scrapy/core/scraper.py @@ -16,7 +16,7 @@ from scrapy import signals from scrapy.http import Request, Response from scrapy.item import BaseItem from scrapy.core.spidermw import SpiderMiddlewareManager -from scrapy.utils.request import referer_str + logger = logging.getLogger(__name__) @@ -152,9 +152,9 @@ class Scraper(object): if isinstance(exc, CloseSpider): self.crawler.engine.close_spider(spider, exc.reason or 'cancelled') return - logger.error( - "Spider error processing %(request)s (referer: %(referer)s)", - {'request': request, 'referer': referer_str(request)}, + logkws = self.logformatter.spider_error(_failure, request, response, spider) + logger.log( + *logformatter_adapter(logkws), exc_info=failure_to_exc_info(_failure), extra={'spider': spider} ) diff --git a/scrapy/logformatter.py b/scrapy/logformatter.py index 9e038160f..d87f685d5 100644 --- a/scrapy/logformatter.py +++ b/scrapy/logformatter.py @@ -9,6 +9,7 @@ SCRAPEDMSG = "Scraped from %(src)s" + os.linesep + "%(item)s" DROPPEDMSG = "Dropped: %(exception)s" + os.linesep + "%(item)s" CRAWLEDMSG = "Crawled (%(status)s) %(request)s%(request_flags)s (referer: %(referer)s)%(response_flags)s" ITEMERRORMSG = "Error processing %(item)s" +SPIDERERRORMSG = "Spider error processing %(request)s (referer: %(referer)s)" class LogFormatter(object): @@ -103,6 +104,17 @@ class LogFormatter(object): } } + def spider_error(self, failure, request, response, spider): + """Logs an error message from a spider.""" + return { + 'level': logging.ERROR, + 'msg': SPIDERERRORMSG, + 'args': { + 'request': request, + 'referer': referer_str(request), + } + } + @classmethod def from_crawler(cls, crawler): return cls() diff --git a/tests/test_logformatter.py b/tests/test_logformatter.py index 990927f71..47d2747c2 100644 --- a/tests/test_logformatter.py +++ b/tests/test_logformatter.py @@ -2,6 +2,7 @@ import unittest from testfixtures import LogCapture from twisted.internet import defer +from twisted.python.failure import Failure from twisted.trial.unittest import TestCase as TwistedTestCase import six @@ -73,6 +74,19 @@ class LogFormatterTestCase(unittest.TestCase): logline = logkws['msg'] % logkws['args'] self.assertEqual(logline, u"Error processing {'key': 'value'}") + def test_spider_error(self): + # In practice, the complete traceback is shown by passing the + # 'exc_info' argument to the logging function + failure = Failure(Exception()) + request = Request("http://www.example.com", headers={'Referer': 'http://example.org'}) + response = Response("http://www.example.com", request=request) + logkws = self.formatter.spider_error(failure, request, response, self.spider) + logline = logkws['msg'] % logkws['args'] + self.assertEqual( + logline, + "Spider error processing (referer: http://example.org)" + ) + def test_scraped(self): item = CustomItem() item['name'] = u'\xa3'