15
votes

I'm struggling to make the 'django.request' logger work as advertised - 500 errors don't seem to propagate to handlers attached to it.

In the default logging configuration for every new project, the comment says the "logging performed by this configuration is to send an email to the site admins on every HTTP 500 error". Obviously the email is only sent if you've setup ADMINS correctly, but I'm not even seeing the handler get called when a view raises an exception.

I built a testcase starting with an empty project, and adding my own handler to the 'django.request' logger:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'mail_admins': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler'
        },
        'my_error_handler' : {
            'level': 'ERROR',
            'class': 'log.MyErrorHandler'
        }
    },
    'loggers': {
        'django.request': {
            'handlers': ['mail_admins', 'my_error_handler'],
            'level': 'ERROR',
            'propagate': True,
        },
    }
}

The handler itself:

import logging
class MyErrorHandler(logging.Handler):     
    def emit(self, record):
        print "handling error: %s" % record 

If I call .error() on the logger myself, everything works as it should. But when a 500 is generated by a view, neither of the handlers are called. My views.py:

import logging

def home(request):

    #this error will be processed by MyErrorHandler
    logging.getLogger('django.request').error("Custom error message")

    #this won't
    raise Exception('500 error message')

    return HttpResponse("Home")

Everything else is the project is default; DEBUG is True, the middleware config is unchanged. Is there some hidden config option I need to enable to have this work as it says in the docs?

Thanks, Matt.

2
Have you tried it with DEBUG set to False? When debugging don't the error handlers get overridden?Steve Mayne
Thank you Steve! Yes, django.core.handers.base.handle_uncaught_exception is the method which finally processes a view exception, and if settings.DEBUG it exits before calling logger.error. It seems like the logging docs should cover this - unless I've missed it somehow?Matt
I've added a proper answer so other people can find this information. I guessed this was the case because of the funky 'special' 500/404 pages Django displays when you're in debug mode - I don't think I ever read it in their (usually superb) docs.Steve Mayne

2 Answers

9
votes

Try it with DEBUG set to False. When debugging is enabled, the error handlers in your settings.py get overridden.

1
votes

Just for testing:

manage.py runserver --insecure