Django 1.3 logging: 500 errors are not logged

Question

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.

Ozonide

Have you tried it with DEBUG set to False? When debugging don't the error handlers get overridden? – Concepcionconcept

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? – Ozonide

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. – Concepcionconcept

Answer 1

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

Concepcionconcept

The problem with setting DEBUG to False is that the static files will not work (I am using Django to server static files in development). Is there any other workarounds to get the logging for 500 error to work while having DEBUG=True? Thanks. – Deciduous

Answer 2

Just for testing:

manage.py runserver --insecure

Perpetuity

To elaborate, this will force static files to be served even when DEBUG = False – Botti