Sentry handler in LOGGING config doesn't respect filters

[natethelen]

I have a clean install of Django 1.4.5 and raven 3.3.2 (happened in version prior to this) in Python 2.7.3. I have a filter which strips out SuspiciousOperation exceptions like those that happen when using ALLOWED_HOSTS (can see it here: http://www.tiwoc.de/blog/2013/03/django-prevent-email-notification-on-suspiciousoperation/). They successfully are stripped from console, but they still show up in Sentry. One thing that is curious is that the module is always 'root' that the error comes from. Also, during testing, I removed the whole 'root' section from the LOGGING config so that nothing should be going to Sentry at all (as that was the only place sentry was listed as a handler), but I still get entries in Sentry for errors that are happening. This would suggest that something is happening outside of the standard LOGGING config and hence why the filter isn't being respected.

Here is the relevant stuff from my settings file:

from django.core.exceptions import SuspiciousOperation

def skip_suspicious_operations(record):
  if record.exc_info:
    exc_value = record.exc_info[1]
    if isinstance(exc_value, SuspiciousOperation):
      return False
  return True

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'filters': {
        'skip_suspicious_operations': {
            '()': 'django.utils.log.CallbackFilter',
            'callback': skip_suspicious_operations,
        },
    },
    'root': {
        'level': 'DEBUG',
        'handlers': ['console', 'sentry'],
    },
    'formatters': {
        'verbose': {
            'format': '%(levelname)s %(asctime)s %(module)s %(process)d %(thread)d %(message)s'
        },
    },
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'filters': ['skip_suspicious_operations'],
            'formatter': 'verbose'
        },
        'sentry': {
            'level': 'ERROR',
            'class': 'raven.contrib.django.raven_compat.handlers.SentryHandler',
            'filters': ['skip_suspicious_operations'],
        },
    },
    'loggers': {
        'raven': {
            'level': 'DEBUG',
            'handlers': ['console'],
            'propagate': False,
        },
        'sentry.errors': {
            'level': 'DEBUG',
            'handlers': ['console'],
            'propagate': False,
        },
    }
}

[dcramer]

By default Sentry does not rely on logging. Whats likely happening is that Django bubbles up these SuspiciousOperation errors, and Sentry hooks into the core Django handler so that it still captures these.

I would simply recommend doing a try/except on them (possibly in a middleware?) if you don't want to capture them.

On Friday, April 5, 2013 at 2:28 PM, Nate Thelen wrote:

I have a clean install of Django 1.4.5 and raven 3.3.2 (happened in version prior to this) in Python 2.7.3. I have a filter which strips out SuspiciousOperation exceptions like those that happen when using ALLOWED_HOSTS (can see it here: http://www.tiwoc.de/blog/2013/03/django-prevent-email-notification-on-suspiciousoperation/). They successfully are stripped from console, but they still show up in Sentry. One thing that is curious is that the module is always 'root' that the error comes from. Also, during testing, I removed the whole 'root' section from the LOGGING config so that nothing should be going to Sentry at all (as that was the only place sentry was listed as a handler), but I still get entries in Sentry for errors that are happening. This would suggest that something is happening outside of the standard LOGGING config and hence why the filter isn't being respected.
Here is the relevant stuff from my settings file:
from django.core.exceptions import SuspiciousOperation def skip_suspicious_operations(record): if record.exc_info: exc_value = record.exc_info[1] if isinstance(exc_value, SuspiciousOperation): return False return True LOGGING = { 'version': 1, 'disable_existing_loggers': True, 'filters': { 'skip_suspicious_operations': { '()': 'django.utils.log.CallbackFilter', 'callback': skip_suspicious_operations, }, }, 'root': { 'level': 'DEBUG', 'handlers': ['console', 'sentry'], }, 'formatters': { 'verbose': { 'format': '%(levelname)s %(asctime)s %(module)s %(process)d %(thread)d %(message)s' }, }, 'handlers': { 'console': { 'level': 'DEBUG', 'class': 'logging.StreamHandler', 'filters': ['skip_suspicious_operations'], 'formatter': 'verbose' }, 'sentry': { 'level': 'ERROR', 'class': 'raven.contrib.django.raven_compat.handlers.SentryHandler', 'filters': ['skip_suspicious_operations'], }, }, 'loggers': { 'raven': { 'level': 'DEBUG', 'handlers': ['console'], 'propagate': False, }, 'sentry.errors': { 'level': 'DEBUG', 'handlers': ['console'], 'propagate': False, }, } }

—
Reply to this email directly or view it on GitHub (#289).

[natethelen]

So is it recommended to remove the sentry handler from LOGGING completely?

[dcramer]

@natethelen Most people use it, you just can't log some messages to Sentry (and others you dont want to go there).

I use a config like the following:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
        'simple': {
            'format': '%(name)s %(levelname)s %(asctime)s %(message)s',
        },
    },
    'handlers': {
        'console': {
            'level': 'INFO',
            'class': 'logging.StreamHandler',
            'formatter': 'simple',
        },
        'sentry': {
            'level': 'WARNING',
            'class': 'raven.contrib.django.handlers.SentryHandler',
        }
    },
    'loggers': {
        '()': {
            'handlers': ['console', 'sentry'],
            'propagate': True,
        },
        'django.request': {
            'level': 'ERROR',
            'handlers': ['console'],
            'propagate': False,
        },
    }
}

[natethelen]

OK, Thanks!

[natethelen]

The only way I was able to make this work was to do this:

RAVEN_CONFIG = {
    'dsn': 'https://{mykeys}@app.getsentry.com/{myid}',
    'IGNORE_EXCEPTIONS': [
        'SuspiciousOperation',
    ],
}

[qn7o]

Hello,

This is a big issue for me. When my database goes down, Sentry instantly gets over flooded by psycopg2's OperationalError: could not connect to server: Connection refused. Since OperationalError can be thrown in other cases than unreachable databases, I can't just blindly ignore it using the config provided here above.
And I cannot filter it using Django's logging filters, because it just doesn't work. It properly intercepts the exception, but still bubbles it up somewhow.

My question is: did someone fix it in the meantime ? How can I prevent Raven from shooting certain types of exceptions at Sentry ?

FYI, the filter's code:

def skip_unreachable_database(record):
    """Avoid flooding Sentry when the database is down"""
    if record.exc_info:
        print '>>>', record.exc_info
        exc_type, exc_value = record.exc_info[:2]
        if isinstance(exc_value, OperationalError) and exc_value.message.lower().startswith('could not connect to server: connection refused'):
            return False
    return True

[eliasdorneles]

Note that this problem doesn't happen if you implement the filter extending logging.Filter, like in this example which filters out log messages that don't contain exception info:

class FilterOutErrorsWithoutExceptions(logging.Filter):
    def filter(self, record):
        return bool(record.exc_info)

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'loggers': {
        '': {
            'level': 'DEBUG',
            'handlers': ['sentry'],
        },
        # ...
    },
    'handlers': {
        'sentry': {
            'level': 'ERROR',
            'class': 'raven.contrib.django.raven_compat.handlers.SentryHandler',
            'filters': ['onlyexceptions'],
        },
        # ...
    },
    'filters': {
        'onlyexceptions': {
            '()': FilterOutErrorsWithoutExceptions,
        },
    },
    # ...
}