From ad18d4a70ea7f5ab48c306d4a4850c3de9459f46 Mon Sep 17 00:00:00 2001
From: Pablo Hoffman <pablo@pablohoffman.com>
Date: Thu, 26 Aug 2010 23:19:35 -0300
Subject: [PATCH] Added pluggable log formatter

---
 scrapy/conf/default_settings.py |  2 +-
 scrapy/contrib/logformatter.py  |  7 -------
 scrapy/core/engine.py           |  3 +--
 scrapy/core/scraper.py          |  9 +++++----
 scrapy/log.py                   |  3 +++
 scrapy/logformatter.py          | 21 +++++++++++++++++++++
 6 files changed, 31 insertions(+), 14 deletions(-)
 delete mode 100644 scrapy/contrib/logformatter.py
 create mode 100644 scrapy/logformatter.py

diff --git a/scrapy/conf/default_settings.py b/scrapy/conf/default_settings.py
index 143f29632..eed71eda9 100644
--- a/scrapy/conf/default_settings.py
+++ b/scrapy/conf/default_settings.py
@@ -152,7 +152,7 @@ ITEM_PIPELINES = []
 
 LOG_ENABLED = True
 LOG_ENCODING = 'utf-8'
-LOG_FORMATTER_CRAWLED = 'scrapy.contrib.logformatter.crawled_logline'
+LOG_FORMATTER = 'scrapy.logformatter.LogFormatter'
 LOG_STDOUT = False
 LOG_LEVEL = 'DEBUG'
 LOG_FILE = None
diff --git a/scrapy/contrib/logformatter.py b/scrapy/contrib/logformatter.py
deleted file mode 100644
index 55995f6e8..000000000
--- a/scrapy/contrib/logformatter.py
+++ /dev/null
@@ -1,7 +0,0 @@
-"""Functions for logging diferent actions"""
-
-def crawled_logline(request, response):
-    referer = request.headers.get('Referer')
-    flags = ' %s' % str(response.flags) if response.flags else ''
-    return "Crawled (%d) %s (referer: %s)%s" % (response.status, \
-        request, referer, flags)
diff --git a/scrapy/core/engine.py b/scrapy/core/engine.py
index 48f5dc0e9..3370b2c30 100644
--- a/scrapy/core/engine.py
+++ b/scrapy/core/engine.py
@@ -28,7 +28,6 @@ class ExecutionEngine(object):
         self.running = False
         self.paused = False
         self._next_request_calls = {}
-        self._crawled_logline = load_object(settings['LOG_FORMATTER_CRAWLED'])
         self.scheduler = load_object(settings['SCHEDULER'])()
         self.downloader = Downloader()
         self.scraper = Scraper(self, self.settings)
@@ -156,7 +155,7 @@ class ExecutionEngine(object):
             assert isinstance(response, (Response, Request))
             if isinstance(response, Response):
                 response.request = request # tie request to response received
-                log.msg(self._crawled_logline(request, response), \
+                log.msg(log.formatter.crawled(request, response, spider), \
                     level=log.DEBUG, spider=spider)
                 return response
             elif isinstance(response, Request):
diff --git a/scrapy/core/scraper.py b/scrapy/core/scraper.py
index 50be2ed5c..6ce5d7582 100644
--- a/scrapy/core/scraper.py
+++ b/scrapy/core/scraper.py
@@ -168,8 +168,8 @@ class Scraper(object):
                 spider=spider)
             self.engine.crawl(request=output, spider=spider)
         elif isinstance(output, BaseItem):
-            log.msg("Scraped %s in <%s>" % (output, request.url), level=log.DEBUG, \
-                spider=spider)
+            log.msg(log.formatter.scraped(output, request, response, spider), \
+                level=log.DEBUG, spider=spider)
             self.sites[spider].itemproc_size += 1
             dfd = send_catch_log_deferred(signal=signals.item_scraped, \
                 item=output, spider=spider, response=response)
@@ -204,13 +204,14 @@ class Scraper(object):
         if isinstance(output, Failure):
             ex = output.value
             if isinstance(ex, DropItem):
-                log.msg("Dropped %s - %s" % (item, str(ex)), level=log.WARNING, spider=spider)
+                log.msg(log.formatter.dropped(item, ex, spider), \
+                    level=log.WARNING, spider=spider)
                 return send_catch_log_deferred(signal=signals.item_dropped, \
                     item=item, spider=spider, exception=output.value)
             else:
                 log.err(output, 'Error processing %s' % item, spider=spider)
         else:
-            log.msg("Passed %s" % item, log.INFO, spider=spider)
+            log.msg(log.formatter.passed(item, spider), log.INFO, spider=spider)
             return send_catch_log_deferred(signal=signals.item_passed, \
                 item=item, spider=spider, output=output)
 
diff --git a/scrapy/log.py b/scrapy/log.py
index 55a391b49..4ba20bd67 100644
--- a/scrapy/log.py
+++ b/scrapy/log.py
@@ -10,6 +10,7 @@ from twisted.python import log
 
 from scrapy.conf import settings
 from scrapy.utils.python import unicode_to_str
+from scrapy.utils.misc import load_object
  
 # Logging levels
 DEBUG = logging.DEBUG
@@ -117,3 +118,5 @@ def err(_stuff=None, _why=None, **kw):
     kw.setdefault('system', 'scrapy')
     kw['logLevel'] = kw.pop('level', ERROR)
     log.err(_stuff, _why, **kw)
+
+formatter = load_object(settings['LOG_FORMATTER'])()
diff --git a/scrapy/logformatter.py b/scrapy/logformatter.py
new file mode 100644
index 000000000..f6612602f
--- /dev/null
+++ b/scrapy/logformatter.py
@@ -0,0 +1,21 @@
+
+class LogFormatter(object):
+    """Class for generating log messages for different actions. All methods
+    must return a plain string which doesn't include the log level or the
+    timestamp
+    """
+
+    def crawled(self, request, response, spider):
+        referer = request.headers.get('Referer')
+        flags = ' %s' % str(response.flags) if response.flags else ''
+        return "Crawled (%d) %s (referer: %s)%s" % (response.status, \
+            request, referer, flags)
+
+    def scraped(self, item, request, response, spider):
+        return "Scraped %s in <%s>" % (item, request.url)
+
+    def dropped(self, item, exception, spider):
+        return "Dropped %s - %s" % (item, str(exception))
+
+    def passed(self, item, spider):
+        return "Passed %s" % item