Fixed #19866 -- Added security logger and return 400 for SuspiciousOperation.

SuspiciousOperations have been differentiated into subclasses, and
are now logged to a 'django.security.*' logger. SuspiciousOperations
that reach django.core.handlers.base.BaseHandler will now return a 400
instead of a 500.

Thanks to tiwoc for the report, and Carl Meyer and Donald Stufft
for review.

12 files changed, 87 insertions, 25 deletions

diff --git a/tests/admin_views/tests.py b/tests/admin_views/tests.py
index c0f6533cb2..3485ea353b 100644
--- a/tests/admin_views/tests.py
+++ b/tests/admin_views/tests.py
@@ -11,7 +11,6 @@ except ImportError:  # Python 2
 
 from django.conf import settings, global_settings
 from django.core import mail
-from django.core.exceptions import SuspiciousOperation
 from django.core.files import temp as tempfile
 from django.core.urlresolvers import reverse
 # Register auth models with the admin.
@@ -30,6 +29,7 @@ from django.db import connection
 from django.forms.util import ErrorList
 from django.template.response import TemplateResponse
 from django.test import TestCase
+from django.test.utils import patch_logger
 from django.utils import formats, translation, unittest
 from django.utils.cache import get_max_age
 from django.utils.encoding import iri_to_uri, force_bytes
@@ -543,20 +543,21 @@ class AdminViewBasicTest(TestCase):
                 self.assertContains(response, '%Y-%m-%d %H:%M:%S')
 
     def test_disallowed_filtering(self):
-        self.assertRaises(SuspiciousOperation,
-            self.client.get, "/test_admin/admin/admin_views/album/?owner__email__startswith=fuzzy"
-        )
+        with patch_logger('django.security.DisallowedModelAdminLookup', 'error') as calls:
+            response = self.client.get("/test_admin/admin/admin_views/album/?owner__email__startswith=fuzzy")
+            self.assertEqual(response.status_code, 400)
+            self.assertEqual(len(calls), 1)
 
-        try:
-            self.client.get("/test_admin/admin/admin_views/thing/?color__value__startswith=red")
-            self.client.get("/test_admin/admin/admin_views/thing/?color__value=red")
-        except SuspiciousOperation:
-            self.fail("Filters are allowed if explicitly included in list_filter")
+        # Filters are allowed if explicitly included in list_filter
+        response = self.client.get("/test_admin/admin/admin_views/thing/?color__value__startswith=red")
+        self.assertEqual(response.status_code, 200)
+        response = self.client.get("/test_admin/admin/admin_views/thing/?color__value=red")
+        self.assertEqual(response.status_code, 200)
 
-        try:
-            self.client.get("/test_admin/admin/admin_views/person/?age__gt=30")
-        except SuspiciousOperation:
-            self.fail("Filters should be allowed if they involve a local field without the need to whitelist them in list_filter or date_hierarchy.")
+        # Filters should be allowed if they involve a local field without the
+        # need to whitelist them in list_filter or date_hierarchy.
+        response = self.client.get("/test_admin/admin/admin_views/person/?age__gt=30")
+        self.assertEqual(response.status_code, 200)
 
         e1 = Employee.objects.create(name='Anonymous', gender=1, age=22, alive=True, code='123')
         e2 = Employee.objects.create(name='Visitor', gender=2, age=19, alive=True, code='124')
@@ -574,10 +575,9 @@ class AdminViewBasicTest(TestCase):
         ForeignKey 'limit_choices_to' should be allowed, otherwise raw_id_fields
         can break.
         """
-        try:
-            self.client.get("/test_admin/admin/admin_views/inquisition/?leader__name=Palin&leader__age=27")
-        except SuspiciousOperation:
-            self.fail("Filters should be allowed if they are defined on a ForeignKey pointing to this model")
+        # Filters should be allowed if they are defined on a ForeignKey pointing to this model
+        response = self.client.get("/test_admin/admin/admin_views/inquisition/?leader__name=Palin&leader__age=27")
+        self.assertEqual(response.status_code, 200)
 
     def test_hide_change_password(self):
         """
diff --git a/tests/handlers/tests.py b/tests/handlers/tests.py
index 3680eecdd2..397b63647a 100644
--- a/tests/handlers/tests.py
+++ b/tests/handlers/tests.py
@@ -61,6 +61,7 @@ class TransactionsPerRequestTests(TransactionTestCase):
             connection.settings_dict['ATOMIC_REQUESTS'] = old_atomic_requests
         self.assertContains(response, 'False')
 
+
 class SignalsTests(TestCase):
     urls = 'handlers.urls'
 
@@ -89,3 +90,11 @@ class SignalsTests(TestCase):
         self.assertEqual(self.signals, ['started'])
         self.assertEqual(b''.join(response.streaming_content), b"streaming content")
         self.assertEqual(self.signals, ['started', 'finished'])
+
+
+class HandlerSuspiciousOpsTest(TestCase):
+    urls = 'handlers.urls'
+
+    def test_suspiciousop_in_view_returns_400(self):
+        response = self.client.get('/suspicious/')
+        self.assertEqual(response.status_code, 400)
diff --git a/tests/handlers/urls.py b/tests/handlers/urls.py
index 29858055ab..eaf764b00b 100644
--- a/tests/handlers/urls.py
+++ b/tests/handlers/urls.py
@@ -9,4 +9,5 @@ urlpatterns = patterns('',
     url(r'^streaming/$', views.streaming),
     url(r'^in_transaction/$', views.in_transaction),
     url(r'^not_in_transaction/$', views.not_in_transaction),
+    url(r'^suspicious/$', views.suspicious),
 )
diff --git a/tests/handlers/views.py b/tests/handlers/views.py
index 9cc86ae6f3..1b75b27043 100644
--- a/tests/handlers/views.py
+++ b/tests/handlers/views.py
@@ -1,5 +1,6 @@
 from __future__ import unicode_literals
 
+from django.core.exceptions import SuspiciousOperation
 from django.db import connection, transaction
 from django.http import HttpResponse, StreamingHttpResponse
 
@@ -15,3 +16,6 @@ def in_transaction(request):
 @transaction.non_atomic_requests
 def not_in_transaction(request):
     return HttpResponse(str(connection.in_atomic_block))
+
+def suspicious(request):
+    raise SuspiciousOperation('dubious')
diff --git a/tests/logging_tests/tests.py b/tests/logging_tests/tests.py
index 8e5445cd42..0c2d269464 100644
--- a/tests/logging_tests/tests.py
+++ b/tests/logging_tests/tests.py
@@ -8,9 +8,10 @@ import warnings
 from django.conf import LazySettings
 from django.core import mail
 from django.test import TestCase, RequestFactory
-from django.test.utils import override_settings
+from django.test.utils import override_settings, patch_logger
 from django.utils.encoding import force_text
-from django.utils.log import CallbackFilter, RequireDebugFalse, RequireDebugTrue
+from django.utils.log import (CallbackFilter, RequireDebugFalse,
+    RequireDebugTrue)
 from django.utils.six import StringIO
 from django.utils.unittest import skipUnless
 
@@ -354,3 +355,22 @@ class SettingsConfigureLogging(TestCase):
         settings.configure(
             LOGGING_CONFIG='logging_tests.tests.dictConfig')
         self.assertTrue(dictConfig.called)
+
+
+class SecurityLoggerTest(TestCase):
+
+    urls = 'logging_tests.urls'
+
+    def test_suspicious_operation_creates_log_message(self):
+        with self.settings(DEBUG=True):
+            with patch_logger('django.security.SuspiciousOperation', 'error') as calls:
+                response = self.client.get('/suspicious/')
+                self.assertEqual(len(calls), 1)
+                self.assertEqual(calls[0], 'dubious')
+
+    def test_suspicious_operation_uses_sublogger(self):
+        with self.settings(DEBUG=True):
+            with patch_logger('django.security.DisallowedHost', 'error') as calls:
+                response = self.client.get('/suspicious_spec/')
+                self.assertEqual(len(calls), 1)
+                self.assertEqual(calls[0], 'dubious')
diff --git a/tests/logging_tests/urls.py b/tests/logging_tests/urls.py
new file mode 100644
index 0000000000..c738bd565c
--- /dev/null
+++ b/tests/logging_tests/urls.py
@@ -0,0 +1,10 @@
+from __future__ import unicode_literals
+
+from django.conf.urls import patterns, url
+
+from . import views
+
+urlpatterns = patterns('',
+    url(r'^suspicious/$', views.suspicious),
+    url(r'^suspicious_spec/$', views.suspicious_spec),
+)
diff --git a/tests/logging_tests/views.py b/tests/logging_tests/views.py
new file mode 100644
index 0000000000..c685bcc005
--- /dev/null
+++ b/tests/logging_tests/views.py
@@ -0,0 +1,11 @@
+from __future__ import unicode_literals
+
+from django.core.exceptions import SuspiciousOperation, DisallowedHost
+
+
+def suspicious(request):
+    raise SuspiciousOperation('dubious')
+
+
+def suspicious_spec(request):
+    raise DisallowedHost('dubious')
diff --git a/tests/test_client_regress/tests.py b/tests/test_client_regress/tests.py
index 2582b210c4..6a58ef6344 100644
--- a/tests/test_client_regress/tests.py
+++ b/tests/test_client_regress/tests.py
@@ -7,7 +7,6 @@ from __future__ import unicode_literals
 import os
 
 from django.conf import settings
-from django.core.exceptions import SuspiciousOperation
 from django.core.urlresolvers import reverse
 from django.template import (TemplateDoesNotExist, TemplateSyntaxError,
     Context, Template, loader)
@@ -20,6 +19,7 @@ from django.utils._os import upath
 from django.utils.translation import ugettext_lazy
 from django.http import HttpResponse
 
+from .views import CustomTestException
 
 @override_settings(
     TEMPLATE_DIRS=(os.path.join(os.path.dirname(upath(__file__)), 'templates'),)
@@ -619,7 +619,7 @@ class ExceptionTests(TestCase):
         try:
             response = self.client.get("/test_client_regress/staff_only/")
             self.fail("General users should not be able to visit this page")
-        except SuspiciousOperation:
+        except CustomTestException:
             pass
 
         # At this point, an exception has been raised, and should be cleared.
@@ -629,7 +629,7 @@ class ExceptionTests(TestCase):
         self.assertTrue(login, 'Could not log in')
         try:
             self.client.get("/test_client_regress/staff_only/")
-        except SuspiciousOperation:
+        except CustomTestException:
             self.fail("Staff should be able to visit this page")
 
 
diff --git a/tests/test_client_regress/views.py b/tests/test_client_regress/views.py
index 7e86ffd8ca..71e5b526e5 100644
--- a/tests/test_client_regress/views.py
+++ b/tests/test_client_regress/views.py
@@ -3,12 +3,15 @@ import json
 from django.conf import settings
 from django.contrib.auth.decorators import login_required
 from django.http import HttpResponse, HttpResponseRedirect
-from django.core.exceptions import SuspiciousOperation
 from django.shortcuts import render_to_response
 from django.core.serializers.json import DjangoJSONEncoder
 from django.test.client import CONTENT_TYPE_RE
 from django.template import RequestContext
 
+
+class CustomTestException(Exception):
+    pass
+
 def no_template_view(request):
     "A simple view that expects a GET request, and returns a rendered template"
     return HttpResponse("No template used. Sample content: twice once twice. Content ends.")
@@ -18,7 +21,7 @@ def staff_only_view(request):
     if request.user.is_staff:
         return HttpResponse('')
     else:
-        raise SuspiciousOperation()
+        raise CustomTestException()
 
 def get_view(request):
     "A simple login protected view"
diff --git a/tests/urlpatterns_reverse/tests.py b/tests/urlpatterns_reverse/tests.py
index d5d9b3a709..f54c796d30 100644
--- a/tests/urlpatterns_reverse/tests.py
+++ b/tests/urlpatterns_reverse/tests.py
@@ -516,7 +516,7 @@ class RequestURLconfTests(TestCase):
             b''.join(self.client.get('/second_test/'))
 
 class ErrorHandlerResolutionTests(TestCase):
-    """Tests for handler404 and handler500"""
+    """Tests for handler400, handler404 and handler500"""
 
     def setUp(self):
         from django.core.urlresolvers import RegexURLResolver
@@ -528,12 +528,14 @@ class ErrorHandlerResolutionTests(TestCase):
     def test_named_handlers(self):
         from .views import empty_view
         handler = (empty_view, {})
+        self.assertEqual(self.resolver.resolve400(), handler)
         self.assertEqual(self.resolver.resolve404(), handler)
         self.assertEqual(self.resolver.resolve500(), handler)
 
     def test_callable_handers(self):
         from .views import empty_view
         handler = (empty_view, {})
+        self.assertEqual(self.callable_resolver.resolve400(), handler)
         self.assertEqual(self.callable_resolver.resolve404(), handler)
         self.assertEqual(self.callable_resolver.resolve500(), handler)
 
diff --git a/tests/urlpatterns_reverse/urls_error_handlers.py b/tests/urlpatterns_reverse/urls_error_handlers.py
index be4f42afbc..7146fdf43c 100644
--- a/tests/urlpatterns_reverse/urls_error_handlers.py
+++ b/tests/urlpatterns_reverse/urls_error_handlers.py
@@ -4,5 +4,6 @@ from django.conf.urls import patterns
 
 urlpatterns = patterns('')
 
+handler400 = 'urlpatterns_reverse.views.empty_view'
 handler404 = 'urlpatterns_reverse.views.empty_view'
 handler500 = 'urlpatterns_reverse.views.empty_view'
diff --git a/tests/urlpatterns_reverse/urls_error_handlers_callables.py b/tests/urlpatterns_reverse/urls_error_handlers_callables.py
index fe2d3137e9..befeccaf45 100644
--- a/tests/urlpatterns_reverse/urls_error_handlers_callables.py
+++ b/tests/urlpatterns_reverse/urls_error_handlers_callables.py
@@ -9,5 +9,6 @@ from .views import empty_view
 
 urlpatterns = patterns('')
 
+handler400 = empty_view
 handler404 = empty_view
 handler500 = empty_view