Fixed #19436 -- Don't log warnings in ensure_csrf_cookie.

AUTHORS

@@ -505,6 +505,7 @@ answer newbie questions, and generally made Django that much better:
     Bernd Schlapsi
     schwank@gmail.com
     scott@staplefish.com
+    Olivier Sels <olivier.sels@gmail.com>
     Ilya Semenov <semenov@inetss.com>
     Aleksandra Sendecka <asendecka@hauru.eu>
     serbaut@gmail.com

django/middleware/csrf.py

@@ -83,6 +83,13 @@ class CsrfViewMiddleware(object):
         return None
 
     def _reject(self, request, reason):
+        logger.warning('Forbidden (%s): %s',
+                       reason, request.path,
+            extra={
+                'status_code': 403,
+                'request': request,
+            }
+        )
         return _get_failure_view()(request, reason=reason)
 
     def process_view(self, request, callback, callback_args, callback_kwargs):
@@ -134,38 +141,18 @@ class CsrfViewMiddleware(object):
                 # we can use strict Referer checking.
                 referer = request.META.get('HTTP_REFERER')
                 if referer is None:
-                    logger.warning('Forbidden (%s): %s',
-                                   REASON_NO_REFERER, request.path,
-                        extra={
-                            'status_code': 403,
-                            'request': request,
-                        }
-                    )
                     return self._reject(request, REASON_NO_REFERER)
 
                 # Note that request.get_host() includes the port.
                 good_referer = 'https://%s/' % request.get_host()
                 if not same_origin(referer, good_referer):
                     reason = REASON_BAD_REFERER % (referer, good_referer)
-                    logger.warning('Forbidden (%s): %s', reason, request.path,
-                        extra={
-                            'status_code': 403,
-                            'request': request,
-                        }
-                    )
                     return self._reject(request, reason)
 
             if csrf_token is None:
                 # No CSRF cookie. For POST requests, we insist on a CSRF cookie,
                 # and in this way we can avoid all CSRF attacks, including login
                 # CSRF.
-                logger.warning('Forbidden (%s): %s',
-                               REASON_NO_CSRF_COOKIE, request.path,
-                    extra={
-                        'status_code': 403,
-                        'request': request,
-                    }
-                )
                 return self._reject(request, REASON_NO_CSRF_COOKIE)
 
             # Check non-cookie token for match.
@@ -179,13 +166,6 @@ class CsrfViewMiddleware(object):
                 request_csrf_token = request.META.get('HTTP_X_CSRFTOKEN', '')
 
             if not constant_time_compare(request_csrf_token, csrf_token):
-                logger.warning('Forbidden (%s): %s',
-                               REASON_BAD_TOKEN, request.path,
-                    extra={
-                        'status_code': 403,
-                        'request': request,
-                    }
-                )
                 return self._reject(request, REASON_BAD_TOKEN)
 
         return self._accept(request)

django/views/decorators/csrf.py

@@ -15,7 +15,7 @@ using the decorator multiple times, is harmless and efficient.
 
 class _EnsureCsrfToken(CsrfViewMiddleware):
     # We need this to behave just like the CsrfViewMiddleware, but not reject
-    # requests.
+    # requests or log warnings.
     def _reject(self, request, reason):
         return None
 

tests/csrf_tests/tests.py

 # -*- coding: utf-8 -*-
 from __future__ import unicode_literals
+import logging
 
 from django.conf import settings
 from django.core.context_processors import csrf
@@ -78,18 +79,18 @@ class CsrfViewMiddlewareTest(TestCase):
     def _check_token_present(self, response, csrf_id=None):
         self.assertContains(response, "name='csrfmiddlewaretoken' value='%s'" % (csrf_id or self._csrf_id))
 
-    def test_process_view_token_too_long(self): 
-        """ 
-        Check that if the token is longer than expected, it is ignored and 
-        a new token is created. 
-        """ 
-        req = self._get_GET_no_csrf_cookie_request() 
-        req.COOKIES[settings.CSRF_COOKIE_NAME] = 'x' * 10000000 
-        CsrfViewMiddleware().process_view(req, token_view, (), {}) 
-        resp = token_view(req) 
-        resp2 = CsrfViewMiddleware().process_response(req, resp) 
-        csrf_cookie = resp2.cookies.get(settings.CSRF_COOKIE_NAME, False) 
-        self.assertEqual(len(csrf_cookie.value), CSRF_KEY_LENGTH) 
+    def test_process_view_token_too_long(self):
+        """
+        Check that if the token is longer than expected, it is ignored and
+        a new token is created.
+        """
+        req = self._get_GET_no_csrf_cookie_request()
+        req.COOKIES[settings.CSRF_COOKIE_NAME] = 'x' * 10000000
+        CsrfViewMiddleware().process_view(req, token_view, (), {})
+        resp = token_view(req)
+        resp2 = CsrfViewMiddleware().process_response(req, resp)
+        csrf_cookie = resp2.cookies.get(settings.CSRF_COOKIE_NAME, False)
+        self.assertEqual(len(csrf_cookie.value), CSRF_KEY_LENGTH)
 
     def test_process_response_get_token_used(self):
         """
@@ -353,3 +354,29 @@ class CsrfViewMiddlewareTest(TestCase):
         resp2 = CsrfViewMiddleware().process_response(req, resp)
         self.assertTrue(resp2.cookies.get(settings.CSRF_COOKIE_NAME, False))
         self.assertTrue('Cookie' in resp2.get('Vary',''))
+
+    def test_ensures_csrf_cookie_no_logging(self):
+        """
+        Tests that ensure_csrf_cookie doesn't log warnings. See #19436.
+        """
+        @ensure_csrf_cookie
+        def view(request):
+            # Doesn't insert a token or anything
+            return HttpResponse(content="")
+
+        class TestHandler(logging.Handler):
+            def emit(self, record):
+                raise Exception("This shouldn't have happened!")
+
+        logger = logging.getLogger('django.request')
+        test_handler = TestHandler()
+        old_log_level = logger.level
+        try:
+            logger.addHandler(test_handler)
+            logger.setLevel(logging.WARNING)
+
+            req = self._get_GET_no_csrf_cookie_request()
+            resp = view(req)
+        finally:
+            logger.removeHandler(test_handler)
+            logger.setLevel(old_log_level)