CODEWITHSUNDEEP
pythondjangologgingnginxmandrill
hyperknot
hyperknot

Reputation: 13976

Django not logging all errors

I have the following logging config set up in Django 1.8:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'file': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'filename': normpath(join(DJANGO_ROOT, '../../logs', 'django.log')),
        },
    },
    'loggers': {
        '': {
            'handlers': ['file'],
            'propagate': True,
            'level': 'DEBUG',
        },
    },
}

Moreover, I'm also logging the stdout and stderr of gunicorn into two separate files via supervisord.

My problem is that not all errors are showing up in Django logs. For example, there is a case when I had a simple .get() query in a model's save function, which raised a DoesNotExist exception in the admin page. This exception did not show up at all in any Django log, all I could see was the 500 in the nginx log for a POST request.

When I tried with debug mode in local machine, it produced the detailed error page, but what if I couldn't reproduce a bug in a local machine?

Why are 500 errors silently disappearing in Django and how can I fix it?

// I know that Sentry is able to report such exception errors, I'm looking for a way which doesn't involve using an external service.

Upvotes: 3

Views: 4859

Answers (2)

hyperknot
hyperknot

Reputation: 13976

I debugged the case, it was a combination of two things:

  1. Without specifying SERVER_EMAIL, Django sends admin emails from root@localhost. The SMTP provider I'm using (Mandrill) silently blocks all emails from such address, thus I never got the emails, nor any log at Mandrill.

Solution was to specify SERVER_EMAIL to a real address and test admin email sending using mail_admins().

  1. django.security and django.request loggers are set not to propagate by default, thus my root logger '' did not catch them.

Solution was to re-specify them and set propagate to True. This way they both send emails and are visible in the log files as well.

My working logger configuration is the following:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'file': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'filename': normpath(join(DJANGO_ROOT, '../../logs', 'django.log')),
            'formatter': 'verbose',
        },
        'mail_admins': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler'
        }
    },
    'formatters': {
        'verbose': {
            'format': '%(asctime)s %(levelname)-8s [%(name)s:%(lineno)s] %(message)s',
        },
    },
    'loggers': {
        '': {
            'handlers': ['file'],
            'level': 'DEBUG',
        },
        'django.request': {
            'handlers': ['mail_admins'],
            'level': 'ERROR',
            'propagate': True,
        },
        'django.security': {
            'handlers': ['mail_admins'],
            'level': 'ERROR',
            'propagate': True,
        },
    },
}

Upvotes: 4

Sylvain Biehler
Sylvain Biehler

Reputation: 1433

Reading this code from django.core.handlers.base.BaseHandler,

def handle_uncaught_exception(self, request, resolver, exc_info):
    """
    Processing for any otherwise uncaught exceptions (those that will
    generate HTTP 500 responses). Can be overridden by subclasses who want
    customised 500 handling.
    Be *very* careful when overriding this because the error could be
    caused by anything, so assuming something like the database is always
    available would be an error.
    """
    if settings.DEBUG_PROPAGATE_EXCEPTIONS:
        raise

    logger.error('Internal Server Error: %s', request.path,
        exc_info=exc_info,
        extra={
            'status_code': 500,
            'request': request
        }
    )

    if settings.DEBUG:
        return debug.technical_500_response(request, *exc_info)

    # If Http500 handler is not installed, re-raise last exception
    if resolver.urlconf_module is None:
        six.reraise(*exc_info)
    # Return an HttpResponse that displays a friendly error message.
    callback, param_dict = resolver.resolve_error_handler(500)
    return callback(request, **param_dict)

I see 2 possibilities :

  1. settings.DEBUG_PROPAGATE_EXCEPTIONS is True
  2. your defintion of the loggers with 'loggers': { '': { ... doesn't work for the errors catched at django level

Upvotes: 0

Related Questions