Repository: scrapy/scrapy

Issue:
After adding request flags subclasses of logformatter that rely on 'flags' format string are broken
#2082 added flags to request but it also renamed formatting string key from flags to response_flags/request_flags
```
CRAWLEDMSG = u"Crawled (%(status)s) %(request)s (referer: %(referer)s)%(flags)s"
 +CRAWLEDMSG = u"Crawled (%(status)s) %(request)s%(request_flags)s (referer: %(referer)s)%(response_flags)s" 
```

Scrapy allows you to override logformatter and this is what I have in my project. I have logformatter looking rouhgly like this


```python
# dirbot/logf.py
from scrapy.logformatter import LogFormatter


class CustomLogFormatter(LogFormatter):
    def crawled(self, request, response, spider):
        kwargs = super(CustomLogFormatter, self).crawled(
            request, response, spider)
        kwargs['msg'] = (
            u"Crawled (%(status)s) %(request)s "
            u"(referer: %(referer)s, latency: %(latency).2f s)%(flags)s"
        )
        kwargs['args']['latency'] = response.meta.get('download_latency', 0)
        return kwargs
```

now if you enable it in settings `LOG_FORMATTER = 'dirbot.logf.CustomLogFormatter'
` and  try to run it with recent master you'll get KeyError

```
2017-03-13 14:15:26 [scrapy.extensions.telnet] DEBUG: Telnet console listening on 127.0.0.1:6023
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 851, in emit
    msg = self.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 724, in format
    return fmt.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 464, in format
    record.message = record.getMessage()
  File "/usr/lib/python2.7/logging/__init__.py", line 328, in getMessage
    msg = msg % self.args
KeyError: u'flags'
Logged from file engine.py, line 238
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 851, in emit
    msg = self.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 724, in format
    return fmt.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 464, in format
    record.message = record.getMessage()
  File "/usr/lib/python2.7/logging/__init__.py", line 328, in getMessage
    msg = msg % self.args
KeyError: u'flags'
Logged from file engine.py, line 238
2017-03-13 14:15:27 [scrapy.core.scraper] DEBUG: Scraped from <200 http://www.dmoz.org/Computers/Programming/Languages/Python/Resources/>
```

So this change that renamed `flags` to `response_flags/request_flags` seems backward incompatible. 

Discussion:

Patch:
diff --git a/scrapy/logformatter.py b/scrapy/logformatter.py
index e7bf7942e..075a6d862 100644
--- a/scrapy/logformatter.py
+++ b/scrapy/logformatter.py
@@ -43,6 +43,8 @@ class LogFormatter(object):
                 'request_flags' : request_flags,
                 'referer': referer_str(request),
                 'response_flags': response_flags,
+                # backward compatibility with Scrapy logformatter below 1.4 version
+                'flags': response_flags
             }
         }
 


Test patch:
diff --git a/tests/test_logformatter.py b/tests/test_logformatter.py
index 11fe7b653..94e6c9fde 100644
--- a/tests/test_logformatter.py
+++ b/tests/test_logformatter.py
@@ -64,5 +64,30 @@ class LoggingContribTest(unittest.TestCase):
         assert all(isinstance(x, six.text_type) for x in lines)
         self.assertEqual(lines, [u"Scraped from <200 http://www.example.com>", u'name: \xa3'])
 
+
+class LogFormatterSubclass(LogFormatter):
+    def crawled(self, request, response, spider):
+        kwargs = super(LogFormatterSubclass, self).crawled(
+        request, response, spider)
+        CRAWLEDMSG = (
+            u"Crawled (%(status)s) %(request)s (referer: "
+            u"%(referer)s)%(flags)s"
+        )
+        return {
+            'level': kwargs['level'],
+            'msg': CRAWLEDMSG,
+            'args': kwargs['args']
+        }
+
+
+class LogformatterSubclassTest(LoggingContribTest):
+    def setUp(self):
+        self.formatter = LogFormatterSubclass()
+        self.spider = Spider('default')
+
+    def test_flags_in_request(self):
+        pass
+
+
 if __name__ == "__main__":
     unittest.main()