exception email sent to admin on failed check

[tisdall]

I recently upgraded to Django 2.2.4 and using Python 3.6.7. The checks all work correctly when successful, but exceptions from failed ones sent an email. It took quite a while to figure out why (because it looked like the Exception was somehow getting out of the try-except block), but I think it's due to the logger.exception calls in the check decorator. I had to make changes in Django settings so the 'watchman' logging was sent to a null handler and then the emails stopped. I can't seem to find what the default setting for LOGGING is, but I suspect that exception logging messages may be emailed to admins (docs say that those messages are 'ERROR' level and that defaults to being emailed to admins with DEBUG=False).

I'm wondering if the logging statements should be changed to a lower level?

[mwarkentin]

@tisdall thanks for the issues - I'm a bit slammed today but I will try to review them soon. :)

[tisdall]

Looking a little more into this...

I made the following changes in settings:

LOGGING = {
    # ... [SNIP]
    'loggers': {
        # ... [SNIP]
        'watchman': {
            'handlers': ['console'],
            'propagate': False,
        },
    }
}

That allows errors to show when DEBUG = True but is ignored in production.

However, emails are still sent in production because django.request logger sends logging errors when a 500 response is sent (which the watchman endpoint sends on a failed test when hitting the endpoint). The default logging in Django is set to email admins on 500 errors. However, that's normally what you want and I just want to avoid sending an email when the 500 is on the watchman endpoint.

I was wondering why there was no issue in Django 1.11 and it suddenly started happening in 2.2. I found that a "fix" was added to 2.1 to make logging function the way the docs say they did. Prior to that, only uncaught exceptions actually got logged and not any 500 response. So, this issue is only present in Django 2.1 and newer.

So, I figured out how to "filter" out the logging caused by the watchman endpoint and ended up with the following:

def skip_watchman(record):
    if (record.name == 'django.request' and
            record.status_code == 500 and  # WATCHMAN_ERROR_CODE
            record.request.path == '/watchman/'):
        return False  # filter out this logging
    return True

LOGGING = {
    # ... [SNIP]
    'filters': {
        # ... [SNIP]
        'skip_watchman': {
            '()': 'django.utils.log.CallbackFilter',
            'callback': skip_watchman,
        }
    },
    'handlers': {
        # ... [SNIP]
        'mail_admins': {
            'level': 'ERROR',
            'filters': ['require_debug_false', 'skip_watchman'],
            'class': 'django.utils.log.AdminEmailHandler'
        },
    },
    'loggers': {
        # ... [SNIP]
    }
}

Additionally, the logging from 'watchman' wasn't actually sending the emails so that logger setting doesn't need to be set.

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.