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

Merge pull request #4188 from elacuesta/logformatter-error-formatting 

LogFormatter error formatting
This commit is contained in:
Andrey Rahmatullin 2020-02-19 19:05:08 +05:00 committed by GitHub
parent 528b894f28 03af8885ff
commit f558df2558
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 86 additions and 21 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

29
scrapy/core/scraper.py
View File

@ -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__)
@ -158,9 +158,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}
)
@ -208,16 +208,21 @@ class Scraper(object):
"""
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
@ -236,7 +241,7 @@ class Scraper(object):
signal=signals.item_dropped, item=item, response=response,
spider=spider, exception=output.value)
else:
logkws = self.logformatter.error(item, ex, response, spider)
logkws = self.logformatter.item_error(item, ex, response, spider)
logger.log(*logformatter_adapter(logkws), extra={'spider': spider},
exc_info=failure_to_exc_info(output))
return self.signals.send_catch_log_deferred(

40
scrapy/logformatter.py
View File

@ -5,10 +5,13 @@ from twisted.python.failure import Failure
from scrapy.utils.request import referer_str
SCRAPEDMSG = u"Scraped from %(src)s" + os.linesep + "%(item)s"
DROPPEDMSG = u"Dropped: %(exception)s" + os.linesep + "%(item)s"
CRAWLEDMSG = u"Crawled (%(status)s) %(request)s%(request_flags)s (referer: %(referer)s)%(response_flags)s"
ERRORMSG = u"'Error processing %(item)s'"
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)"
DOWNLOADERRORMSG_SHORT = "Error downloading %(request)s"
DOWNLOADERRORMSG_LONG = "Error downloading %(request)s: %(errmsg)s"
class LogFormatter(object):
@ -93,16 +96,41 @@ class LogFormatter(object):
}
}
def error(self, item, exception, response, spider):
def item_error(self, item, exception, response, spider):
"""Logs a message when an item causes an error while it is passing through the item pipeline."""
return {
'level': logging.ERROR,
'msg': ERRORMSG,
'msg': ITEMERRORMSG,
'args': {
'item': item,
}
}
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),
}
}
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()

38
tests/test_logformatter.py
View File

@ -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
from scrapy.crawler import CrawlerRunner
@ -62,15 +63,46 @@ class LogFormatterTestCase(unittest.TestCase):
assert all(isinstance(x, str) for x in lines)
self.assertEqual(lines, [u"Dropped: \u2018", '{}'])
def test_error(self):
def test_item_error(self):
# In practice, the complete traceback is shown by passing the
# 'exc_info' argument to the logging function
item = {'key': 'value'}
exception = Exception()
response = Response("http://www.example.com")
logkws = self.formatter.error(item, exception, response, self.spider)
logkws = self.formatter.item_error(item, exception, response, self.spider)
logline = logkws['msg'] % logkws['args']
self.assertEqual(logline, u"'Error processing {'key': 'value'}'")
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_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()