Fixed #26688 -- Fixed HTTP request logging inconsistencies.

* Added logging of 500 responses for instantiated responses.
* Added logging of all 4xx and 5xx responses.

2 files changed, 42 insertions, 9 deletions

diff --git a/django/utils/cache.py b/django/utils/cache.py
index 7117d40526..0e0428fc11 100644
--- a/django/utils/cache.py
+++ b/django/utils/cache.py
@@ -17,7 +17,6 @@ An example: i18n middleware would need to distinguish caches by the
 "Accept-language" header.
 """
 import hashlib
-import logging
 import re
 import time
 
@@ -28,13 +27,12 @@ from django.utils.encoding import force_bytes, iri_to_uri
 from django.utils.http import (
     http_date, parse_etags, parse_http_date_safe, quote_etag,
 )
+from django.utils.log import log_response
 from django.utils.timezone import get_current_timezone_name
 from django.utils.translation import get_language
 
 cc_delim_re = re.compile(r'\s*,\s*')
 
-logger = logging.getLogger('django.request')
-
 
 def patch_cache_control(response, **kwargs):
     """
@@ -106,14 +104,13 @@ def set_response_etag(response):
 
 
 def _precondition_failed(request):
-    logger.warning(
+    response = HttpResponse(status=412)
+    log_response(
         'Precondition Failed: %s', request.path,
-        extra={
-            'status_code': 412,
-            'request': request,
-        },
+        response=response,
+        request=request,
     )
-    return HttpResponse(status=412)
+    return response
 
 
 def _not_modified(request, response=None):
diff --git a/django/utils/log.py b/django/utils/log.py
index 2c3d4ed5e3..2de6dbbb59 100644
--- a/django/utils/log.py
+++ b/django/utils/log.py
@@ -9,6 +9,8 @@ from django.core.management.color import color_style
 from django.utils.module_loading import import_string
 from django.views.debug import ExceptionReporter
 
+request_logger = logging.getLogger('django.request')
+
 # Default logging for Django. This sends an email to the site admins on every
 # HTTP 500 error. Depending on DEBUG, all other log records are either sent to
 # the console (DEBUG=True) or discarded (DEBUG=False) by means of the
@@ -192,3 +194,37 @@ class ServerFormatter(logging.Formatter):
 
     def uses_server_time(self):
         return self._fmt.find('{server_time}') >= 0
+
+
+def log_response(message, *args, response=None, request=None, logger=request_logger, level=None, exc_info=None):
+    """
+    Log errors based on HttpResponse status.
+
+    Log 5xx responses as errors and 4xx responses as warnings (unless a level
+    is given as a keyword argument). The HttpResponse status_code and the
+    request are passed to the logger's extra parameter.
+    """
+    # Check if the response has already been logged. Multiple requests to log
+    # the same response can be received in some cases, e.g., when the
+    # response is the result of an exception and is logged at the time the
+    # exception is caught so that the exc_info can be recorded.
+    if getattr(response, '_has_been_logged', False):
+        return
+
+    if level is None:
+        if response.status_code >= 500:
+            level = 'error'
+        elif response.status_code >= 400:
+            level = 'warning'
+        else:
+            level = 'info'
+
+    getattr(logger, level)(
+        message, *args,
+        extra={
+            'status_code': response.status_code,
+            'request': request,
+        },
+        exc_info=exc_info,
+    )
+    response._has_been_logged = True