LogFormatter.spider_error

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}
         )

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()

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 <GET http://www.example.com> (referer: http://example.org)"
+        )
+
     def test_scraped(self):
         item = CustomItem()
         item['name'] = u'\xa3'