django.request logger not working for get_object_or_404

Question

I have this code for UserDetailsView in Django Rest Framework. I am using django 1.9 and DRF 3.

class UserDetailsView(RetrieveUpdateAPIView):
    """
    API endpoint that allows a user to be viewed or edited.
    """
    serializer_class = UserDetailsSerializer
    permission_classes = (IsAuthenticated,)

    def get_object(self):
        pk = self.kwargs.get('pk', None)
        if not pk or (pk == str(self.request.user.pk)):
            return self.request.user
        else:
            try:
                return get_object_or_404(User, id=pk)
            except ValueError:
                return get_object_or_404(User, username=pk) 

I have have my django logger configured as per these settings.

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'simple': {
            'format': '[%(levelname)s]  %(message)s'
        },
    },
    'handlers': {
        'default': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': 'logs/backend_common.log',
            'maxBytes': 1024*1024*10,
            'backupCount': 10,
            'formatter': 'simple',
        },
        'request_handler': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': 'logs/backend_requests.log',
            'maxBytes': 1024*1024*10,
            'backupCount': 10,
            'formatter': 'simple',
        },
        'mail_admins': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler',
        }
    },
    'loggers': {
        '': {
            'handlers': ['default'],
            'propagate': True,
        },
        'django.request': {
            'handlers': ['request_handler', 'mail_admins'],
            'level': 'DEBUG',
            'propagate': False,
        }
    }
}

Now, all django 4xx, 5xx error status code should ideally be logged into backend_requests.log file and they are except 404 status resulting from get_object_or_404. I think 404 errors resulting from this view should also get logged. Any help is highly appreciated.

Answer 1

There are actually two issues here.

The first is a bug in Django, which was fixed just a few days ago. The bit of code that was logging 404s was running a little too early. The next release of Django will work and your 404s will be logged as you would expect.

For other exceptions however, the problem is as follows. Django will log errors if the exceptions that caused them are bubbled up to the core request handler. However if the view or some middleware catches the exception and handles it, then this portion of Django's code never gets called. This is what is happening with DRF:

REST framework's views handle various exceptions, and deal with returning appropriate error responses.

The handled exceptions are:

• Subclasses of APIException raised inside REST framework.
• Django's Http404 exception.
• Django's PermissionDenied exception.

In each case, REST framework will return a response with an appropriate status code and content-type. The body of the response will include any additional details regarding the nature of the error.

Because DRF catches the exception and returns a response object to Django, Django will just render the response and not log the error. This makes sense - it is possible for some middleware to take what was originally a 404 but return a different response instead (the flatpage middleware is a good example).

If you want to log exceptions handled by DRF you can specify your own EXCEPTION_HANDLER in the DRF config, or write your own middleware that logs the errors.

Note that 5xx exceptions are not handled by DRF and these should still propagate up to Django. These should be getting logged for you even now.