From 523e04dfebf622b922579c3daf139368c4e16031 Mon Sep 17 00:00:00 2001
From: Claude Paroz <claude@2xlibre.net>
Date: Sun, 29 Apr 2018 11:02:51 +0200
Subject: [PATCH] Captured logging in tests with self.assertLogs().

---
 tests/servers/test_basehttp.py       | 51 +++++++++++---------------
 tests/template_tests/test_logging.py | 53 ++++++++++------------------
 tests/view_tests/tests/test_debug.py | 46 ++++++++++++++----------
 3 files changed, 66 insertions(+), 84 deletions(-)

diff --git a/tests/servers/test_basehttp.py b/tests/servers/test_basehttp.py
index a231a437f2..3e694c3750 100644
--- a/tests/servers/test_basehttp.py
+++ b/tests/servers/test_basehttp.py
@@ -1,4 +1,3 @@
-import logging
 from io import BytesIO
 
 from django.core.handlers.wsgi import WSGIRequest
@@ -18,36 +17,26 @@ class Stub:
 class WSGIRequestHandlerTestCase(SimpleTestCase):
 
     def test_log_message(self):
-        # Silence the django.server logger by replacing its StreamHandler with
-        # NullHandler.
-        logger = logging.getLogger('django.server')
-        original_handlers = logger.handlers
-        logger.handlers = [logging.NullHandler()]
-        try:
-            request = WSGIRequest(RequestFactory().get('/').environ)
-            request.makefile = lambda *args, **kwargs: BytesIO()
-            handler = WSGIRequestHandler(request, '192.168.0.2', None)
-            level_status_codes = {
-                'info': [200, 301, 304],
-                'warning': [400, 403, 404],
-                'error': [500, 503],
-            }
-
-            for level, status_codes in level_status_codes.items():
-                for status_code in status_codes:
-                    # The correct level gets the message.
-                    with self.assertLogs('django.server', level.upper()) as cm:
-                        handler.log_message('GET %s %s', 'A', str(status_code))
-                    self.assertIn('GET A %d' % status_code, cm.output[0])
-
-                    # Incorrect levels shouldn't have any messages.
-                    for wrong_level in level_status_codes:
-                        if wrong_level != level:
-                            with self.assertRaisesMessage(AssertionError, 'no logs'):
-                                with self.assertLogs('django.template', level.upper()):
-                                    handler.log_message('GET %s %s', 'A', str(status_code))
-        finally:
-            logger.handlers = original_handlers
+        request = WSGIRequest(RequestFactory().get('/').environ)
+        request.makefile = lambda *args, **kwargs: BytesIO()
+        handler = WSGIRequestHandler(request, '192.168.0.2', None)
+        level_status_codes = {
+            'info': [200, 301, 304],
+            'warning': [400, 403, 404],
+            'error': [500, 503],
+        }
+        for level, status_codes in level_status_codes.items():
+            for status_code in status_codes:
+                # The correct level gets the message.
+                with self.assertLogs('django.server', level.upper()) as cm:
+                    handler.log_message('GET %s %s', 'A', str(status_code))
+                self.assertIn('GET A %d' % status_code, cm.output[0])
+                # Incorrect levels don't have any messages.
+                for wrong_level in level_status_codes:
+                    if wrong_level != level:
+                        with self.assertLogs('django.server', 'INFO') as cm:
+                            handler.log_message('GET %s %s', 'A', str(status_code))
+                        self.assertNotEqual(cm.records[0].levelname, wrong_level.upper())
 
     def test_https(self):
         request = WSGIRequest(RequestFactory().get('/').environ)
diff --git a/tests/template_tests/test_logging.py b/tests/template_tests/test_logging.py
index db4c9454be..568f5a5f1e 100644
--- a/tests/template_tests/test_logging.py
+++ b/tests/template_tests/test_logging.py
@@ -4,29 +4,7 @@ from django.template import Engine, Variable, VariableDoesNotExist
 from django.test import SimpleTestCase
 
 
-class TestHandler(logging.Handler):
-    def __init__(self):
-        super().__init__()
-        self.log_record = None
-
-    def emit(self, record):
-        self.log_record = record
-
-
-class BaseTemplateLoggingTestCase(SimpleTestCase):
-    def setUp(self):
-        self.test_handler = TestHandler()
-        self.logger = logging.getLogger('django.template')
-        self.original_level = self.logger.level
-        self.logger.addHandler(self.test_handler)
-        self.logger.setLevel(self.loglevel)
-
-    def tearDown(self):
-        self.logger.removeHandler(self.test_handler)
-        self.logger.level = self.original_level
-
-
-class VariableResolveLoggingTests(BaseTemplateLoggingTestCase):
+class VariableResolveLoggingTests(SimpleTestCase):
     loglevel = logging.DEBUG
 
     def test_log_on_variable_does_not_exist_silent(self):
@@ -52,31 +30,38 @@ class VariableResolveLoggingTests(BaseTemplateLoggingTestCase):
             def __getitem__(self, item):
                 return self.__dict__[item]
 
-        Variable('article').resolve(TestObject())
+        with self.assertLogs('django.template', self.loglevel) as cm:
+            Variable('article').resolve(TestObject())
 
+        self.assertEqual(len(cm.records), 1)
+        log_record = cm.records[0]
         self.assertEqual(
-            self.test_handler.log_record.getMessage(),
+            log_record.getMessage(),
             "Exception while resolving variable 'article' in template 'template_name'."
         )
-        self.assertIsNotNone(self.test_handler.log_record.exc_info)
-        raised_exception = self.test_handler.log_record.exc_info[1]
+        self.assertIsNotNone(log_record.exc_info)
+        raised_exception = log_record.exc_info[1]
         self.assertEqual(str(raised_exception), 'Attribute does not exist.')
 
     def test_log_on_variable_does_not_exist_not_silent(self):
-        with self.assertRaises(VariableDoesNotExist):
-            Variable('article.author').resolve({'article': {'section': 'News'}})
+        with self.assertLogs('django.template', self.loglevel) as cm:
+            with self.assertRaises(VariableDoesNotExist):
+                Variable('article.author').resolve({'article': {'section': 'News'}})
 
+        self.assertEqual(len(cm.records), 1)
+        log_record = cm.records[0]
         self.assertEqual(
-            self.test_handler.log_record.getMessage(),
+            log_record.getMessage(),
             "Exception while resolving variable 'author' in template 'unknown'."
         )
-        self.assertIsNotNone(self.test_handler.log_record.exc_info)
-        raised_exception = self.test_handler.log_record.exc_info[1]
+        self.assertIsNotNone(log_record.exc_info)
+        raised_exception = log_record.exc_info[1]
         self.assertEqual(
             str(raised_exception),
             "Failed lookup for key [author] in {'section': 'News'}"
         )
 
     def test_no_log_when_variable_exists(self):
-        Variable('article.section').resolve({'article': {'section': 'News'}})
-        self.assertIsNone(self.test_handler.log_record)
+        with self.assertRaisesMessage(AssertionError, 'no logs'):
+            with self.assertLogs('django.template', self.loglevel):
+                Variable('article.section').resolve({'article': {'section': 'News'}})
diff --git a/tests/view_tests/tests/test_debug.py b/tests/view_tests/tests/test_debug.py
index 8aae115bb0..b411387eac 100644
--- a/tests/view_tests/tests/test_debug.py
+++ b/tests/view_tests/tests/test_debug.py
@@ -57,22 +57,25 @@ class CallableSettingWrapperTests(SimpleTestCase):
 
 
 @override_settings(DEBUG=True, ROOT_URLCONF='view_tests.urls')
-class DebugViewTests(LoggingCaptureMixin, SimpleTestCase):
+class DebugViewTests(SimpleTestCase):
 
     def test_files(self):
-        response = self.client.get('/raises/')
+        with self.assertLogs('django.request', 'ERROR'):
+            response = self.client.get('/raises/')
         self.assertEqual(response.status_code, 500)
 
         data = {
             'file_data.txt': SimpleUploadedFile('file_data.txt', b'haha'),
         }
-        response = self.client.post('/raises/', data)
+        with self.assertLogs('django.request', 'ERROR'):
+            response = self.client.post('/raises/', data)
         self.assertContains(response, 'file_data.txt', status_code=500)
         self.assertNotContains(response, 'haha', status_code=500)
 
     def test_400(self):
         # When DEBUG=True, technical_500_template() is called.
-        response = self.client.get('/raises400/')
+        with self.assertLogs('django.security', 'WARNING'):
+            response = self.client.get('/raises400/')
         self.assertContains(response, '<div class="context" id="', status_code=400)
 
     # Ensure no 403.html template exists to test the default case.
@@ -139,7 +142,8 @@ class DebugViewTests(LoggingCaptureMixin, SimpleTestCase):
         Numeric IDs and fancy traceback context blocks line numbers shouldn't be localized.
         """
         with self.settings(DEBUG=True, USE_L10N=True):
-            response = self.client.get('/raises500/')
+            with self.assertLogs('django.request', 'ERROR'):
+                response = self.client.get('/raises500/')
             # We look for a HTML fragment of the form
             # '<div class="context" id="c38123208">', not '<div class="context" id="c38,123,208"'
             self.assertContains(response, '<div class="context" id="', status_code=500)
@@ -152,15 +156,16 @@ class DebugViewTests(LoggingCaptureMixin, SimpleTestCase):
             )
 
     def test_template_exceptions(self):
-        try:
-            self.client.get(reverse('template_exception'))
-        except Exception:
-            raising_loc = inspect.trace()[-1][-2][0].strip()
-            self.assertNotEqual(
-                raising_loc.find("raise Exception('boom')"), -1,
-                "Failed to find 'raise Exception' in last frame of "
-                "traceback, instead found: %s" % raising_loc
-            )
+        with self.assertLogs('django.request', 'ERROR'):
+            try:
+                self.client.get(reverse('template_exception'))
+            except Exception:
+                raising_loc = inspect.trace()[-1][-2][0].strip()
+                self.assertNotEqual(
+                    raising_loc.find("raise Exception('boom')"), -1,
+                    "Failed to find 'raise Exception' in last frame of "
+                    "traceback, instead found: %s" % raising_loc
+                )
 
     def test_template_loader_postmortem(self):
         """Tests for not existing file"""
@@ -171,7 +176,7 @@ class DebugViewTests(LoggingCaptureMixin, SimpleTestCase):
             with override_settings(TEMPLATES=[{
                 'BACKEND': 'django.template.backends.django.DjangoTemplates',
                 'DIRS': [tempdir],
-            }]):
+            }]), self.assertLogs('django.request', 'ERROR'):
                 response = self.client.get(reverse('raises_template_does_not_exist', kwargs={"path": template_name}))
             self.assertContains(response, "%s (Source does not exist)" % template_path, status_code=500, count=2)
             # Assert as HTML.
@@ -187,8 +192,9 @@ class DebugViewTests(LoggingCaptureMixin, SimpleTestCase):
         """
         Make sure if you don't specify a template, the debug view doesn't blow up.
         """
-        with self.assertRaises(TemplateDoesNotExist):
-            self.client.get('/render_no_template/')
+        with self.assertLogs('django.request', 'ERROR'):
+            with self.assertRaises(TemplateDoesNotExist):
+                self.client.get('/render_no_template/')
 
     @override_settings(ROOT_URLCONF='view_tests.default_urls')
     def test_default_urlconf_template(self):
@@ -253,7 +259,8 @@ class NonDjangoTemplatesDebugViewTests(SimpleTestCase):
 
     def test_400(self):
         # When DEBUG=True, technical_500_template() is called.
-        response = self.client.get('/raises400/')
+        with self.assertLogs('django.security', 'WARNING'):
+            response = self.client.get('/raises400/')
         self.assertContains(response, '<div class="context" id="', status_code=400)
 
     def test_403(self):
@@ -267,7 +274,8 @@ class NonDjangoTemplatesDebugViewTests(SimpleTestCase):
     def test_template_not_found_error(self):
         # Raises a TemplateDoesNotExist exception and shows the debug view.
         url = reverse('raises_template_does_not_exist', kwargs={"path": "notfound.html"})
-        response = self.client.get(url)
+        with self.assertLogs('django.request', 'ERROR'):
+            response = self.client.get(url)
         self.assertContains(response, '<div class="context" id="', status_code=500)