diff --git a/scrapy/commands/shell.py b/scrapy/commands/shell.py index 0b130529b..cf99865c4 100644 --- a/scrapy/commands/shell.py +++ b/scrapy/commands/shell.py @@ -53,7 +53,6 @@ class Command(ScrapyCommand): # The crawler is created this way since the Shell manually handles the # crawling engine, so the set up in the crawl method won't work crawler = self.crawler_process._create_crawler(spidercls) - self.crawler_process._setup_crawler_logging(crawler) # The Shell class needs a persistent engine in the crawler crawler.engine = crawler._create_engine() crawler.engine.start() diff --git a/scrapy/crawler.py b/scrapy/crawler.py index f96086605..4eba6f83a 100644 --- a/scrapy/crawler.py +++ b/scrapy/crawler.py @@ -15,7 +15,7 @@ from scrapy.signalmanager import SignalManager from scrapy.exceptions import ScrapyDeprecationWarning from scrapy.utils.ossignal import install_shutdown_handlers, signal_names from scrapy.utils.misc import load_object -from scrapy.utils.log import configure_logging, log_scrapy_info +from scrapy.utils.log import LogCounterHandler, configure_logging, log_scrapy_info from scrapy import signals logger = logging.getLogger('scrapy') @@ -32,6 +32,12 @@ class Crawler(object): self.signals = SignalManager(self) self.stats = load_object(self.settings['STATS_CLASS'])(self) + + handler = LogCounterHandler(self, level=settings.get('LOG_LEVEL')) + logging.root.addHandler(handler) + self.signals.connect(lambda: logging.root.removeHandler(handler), + signals.engine_stopped) + lf_cls = load_object(self.settings['LOG_FORMATTER']) self.logformatter = lf_cls.from_crawler(self) self.extensions = ExtensionManager.from_crawler(self) @@ -103,7 +109,6 @@ class CrawlerRunner(object): crawler = crawler_or_spidercls if not isinstance(crawler_or_spidercls, Crawler): crawler = self._create_crawler(crawler_or_spidercls) - self._setup_crawler_logging(crawler) self.crawlers.add(crawler) d = crawler.crawl(*args, **kwargs) @@ -121,11 +126,6 @@ class CrawlerRunner(object): spidercls = self.spider_loader.load(spidercls) return Crawler(spidercls, self.settings) - def _setup_crawler_logging(self, crawler): - log_observer = log.start_from_crawler(crawler) - if log_observer: - crawler.signals.connect(log_observer.stop, signals.engine_stopped) - def stop(self): return defer.DeferredList([c.stop() for c in list(self.crawlers)]) diff --git a/scrapy/utils/log.py b/scrapy/utils/log.py index 4fd0f3afb..b3e76887d 100644 --- a/scrapy/utils/log.py +++ b/scrapy/utils/log.py @@ -72,3 +72,15 @@ def log_scrapy_info(settings): d = dict(overridden_settings(settings)) logger.info("Overridden settings: %(settings)r", {'settings': d}) + + +class LogCounterHandler(logging.Handler): + """Record log levels count into a crawler stats""" + + def __init__(self, crawler, *args, **kwargs): + super(LogCounterHandler, self).__init__(*args, **kwargs) + self.crawler = crawler + + def emit(self, record): + sname = 'log_count/{}'.format(record.levelname) + self.crawler.stats.inc_value(sname) diff --git a/tests/py3-ignores.txt b/tests/py3-ignores.txt index 7a150b281..0fc90eddb 100644 --- a/tests/py3-ignores.txt +++ b/tests/py3-ignores.txt @@ -59,6 +59,7 @@ tests/test_stats.py tests/test_utils_defer.py tests/test_utils_iterators.py tests/test_utils_jsonrpc.py +tests/test_utils_log.py tests/test_utils_python.py tests/test_utils_reqser.py tests/test_utils_request.py diff --git a/tests/test_utils_log.py b/tests/test_utils_log.py index f843d9797..d98dbb574 100644 --- a/tests/test_utils_log.py +++ b/tests/test_utils_log.py @@ -6,7 +6,8 @@ import unittest from testfixtures import LogCapture from twisted.python.failure import Failure -from scrapy.utils.log import FailureFormatter +from scrapy.utils.log import FailureFormatter, LogCounterHandler +from scrapy.utils.test import get_crawler class FailureFormatterTest(unittest.TestCase): @@ -44,3 +45,33 @@ class FailureFormatterTest(unittest.TestCase): self.assertEqual(len(l.records), 1) self.assertMultiLineEqual(l.records[0].getMessage(), 'test log msg' + os.linesep + '3') + + +class LogCounterHandlerTest(unittest.TestCase): + + def setUp(self): + self.logger = logging.getLogger('test') + self.logger.setLevel(logging.NOTSET) + self.logger.propagate = False + self.crawler = get_crawler(settings_dict={'LOG_LEVEL': 'WARNING'}) + self.handler = LogCounterHandler(self.crawler) + self.logger.addHandler(self.handler) + + def tearDown(self): + self.logger.propagate = True + self.logger.removeHandler(self.handler) + + def test_init(self): + self.assertIsNone(self.crawler.stats.get_value('log_count/DEBUG')) + self.assertIsNone(self.crawler.stats.get_value('log_count/INFO')) + self.assertIsNone(self.crawler.stats.get_value('log_count/WARNING')) + self.assertIsNone(self.crawler.stats.get_value('log_count/ERROR')) + self.assertIsNone(self.crawler.stats.get_value('log_count/CRITICAL')) + + def test_accepted_level(self): + self.logger.error('test log msg') + self.assertEqual(self.crawler.stats.get_value('log_count/ERROR'), 1) + + def test_filtered_out_level(self): + self.logger.debug('test log msg') + self.assertIsNone(self.crawler.stats.get_value('log_count/INFO'))