`django.request` logger not logging 4xx and 5xx responses from views

Question

I am trying to log all 4xx and 5xx responses with the django.request logger but this is only working when an exception is raised or a URL is not matched in the urlconf.

My settings.py is as follows:

import logging.config

LOGGING_CONFIG = None

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
        },
        'logfile': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': "logfile",
            'maxBytes': 50000,
            'backupCount': 2,
        },
    },
    'loggers': {
        'django.request': {
            'handlers': ['logfile'],
            'level': 'WARNING',
            'propagate': True,
        }
    },
}
logging.config.dictConfig(LOGGING)

If I have a view which returns a 4xx or 5xx status like this:

def test500(request):
    return HttpResponse("error", status=500)

Then nothing is logged. However if my view raises an exception like this then an exception is correctly logged:

def testcrash(request):
    print 1/0 # server will respond with 500

Is this the expected behaviour of django.request logger? What is the best way to log 5xx and 4xx responses returned by my views?

Answer 1

I ran into this issue myself some time ago. Here is what happens:

• 500 errors are only logged if they are the result of an uncaught exception. If you set a 500 status manually then it will not be logged. Here's the relevant part of the code - as you can see that piece of logging happens inside a handle_uncaught_exception method.

• The behaviour for 404 responses is currently the same - only uncaught Http404 responses are logged. However, this has changed in Django 1.10. See my comment on this ticket:

  I just want to note that this change has altered the behaviour of Django's 404 logging somewhat.

  Previously, Django would only log a 404 if a Http404 exception bubbled up to the core handler (and not if a view/middleware caught the exception and returned a response, regardless of whether that response was still a 404).

  Now, it will log all 404 responses regardless of how they were generated. This seems better to me but there may be applications that were relying on the previous behaviour.

  So from Django 1.10 onwards all 404 responses will get logged. It seems a bit inconsistent to me.

• Other 4xx responses are only logged if the corresponding exception is raised. 400 exceptions are logged to django.security and not to django.request.

To answer your other question - what is the best way to consistently log this stuff? - the most reliable approach I have found is to write your own middleware which checks the status of all responses and does its own logging.

Edit: I've created a ticket that tries to address some of these inconsistencies in Django. The issue is fixed in Django 2.1.