LogFormatter.download_error

scrapy/core/scraper.py

@@ -200,19 +200,23 @@ class Scraper(object):
         """Log and silence errors that come from the engine (typically download
         errors that got propagated thru here)
         """
-        if (isinstance(download_failure, Failure) and
-                not download_failure.check(IgnoreRequest)):
+        if isinstance(download_failure, Failure) and not download_failure.check(IgnoreRequest):
             if download_failure.frames:
-                logger.error('Error downloading %(request)s',
-                             {'request': request},
-                             exc_info=failure_to_exc_info(download_failure),
-                             extra={'spider': spider})
+                logkws = self.logformatter.download_error(download_failure, request, spider)
+                logger.log(
+                    *logformatter_adapter(logkws),
+                    extra={'spider': spider},
+                    exc_info=failure_to_exc_info(download_failure),
+                )
             else:
                 errmsg = download_failure.getErrorMessage()
                 if errmsg:
-                    logger.error('Error downloading %(request)s: %(errmsg)s',
-                                 {'request': request, 'errmsg': errmsg},
-                                 extra={'spider': spider})
+                    logkws = self.logformatter.download_error(
+                        download_failure, request, spider, errmsg)
+                    logger.log(
+                        *logformatter_adapter(logkws),
+                        extra={'spider': spider},
+                    )
 
         if spider_failure is not download_failure:
             return spider_failure

scrapy/logformatter.py

@@ -10,6 +10,8 @@ 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)"
+DOWNLOADERRORMSG_SHORT = "Error downloading %(request)s"
+DOWNLOADERRORMSG_LONG = "Error downloading %(request)s: %(errmsg)s"
 
 
 class LogFormatter(object):
@@ -115,6 +117,20 @@ class LogFormatter(object):
             }
         }
 
+    def download_error(self, failure, request, spider, errmsg=None):
+        """Logs a download error message from a spider (typically coming from the engine)."""
+        args = {'request': request}
+        if errmsg:
+            msg = DOWNLOADERRORMSG_LONG
+            args['errmsg'] = errmsg
+        else:
+            msg = DOWNLOADERRORMSG_SHORT
+        return {
+            'level': logging.ERROR,
+            'msg': msg,
+            'args': args,
+        }
+
     @classmethod
     def from_crawler(cls, crawler):
         return cls()

tests/test_logformatter.py

@@ -87,6 +87,24 @@ class LogFormatterTestCase(unittest.TestCase):
             "Spider error processing <GET http://www.example.com> (referer: http://example.org)"
         )
 
+    def test_download_error_short(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")
+        logkws = self.formatter.download_error(failure, request, self.spider)
+        logline = logkws['msg'] % logkws['args']
+        self.assertEqual(logline, "Error downloading <GET http://www.example.com>")
+
+    def test_download_error_long(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")
+        logkws = self.formatter.download_error(failure, request, self.spider, "Some message")
+        logline = logkws['msg'] % logkws['args']
+        self.assertEqual(logline, "Error downloading <GET http://www.example.com>: Some message")
+
     def test_scraped(self):
         item = CustomItem()
         item['name'] = u'\xa3'