dcramer/raven — Issue #73: IntegrityError on message_id/event_id when using log handler
Author: f4nt
Created: 2012-02-29 21:52:59+00:00
State: open

I've been trying to use raven in conjunction with sentry to log any errors that celery would produce. In doing so, I've ran into an IntergrityError issue where I can only ever post 1 error to Sentry before having to restart celery. It would appear in the raven Client base class, that event_id which I believe should be a uuid hex generated on capture, is instead the same value every time. Here's an excerpt from my celery log:

[2012-02-29 14:04:12,969: INFO/MainProcess] Got task from broker: shared.tasks.authorization.create_cadr_auth[08cf77bb-f7ea-4752-a683-59447c9e0266]
[2012-02-29 14:04:13,093: WARNING/PoolWorker-1] CURRENT EVENT ID: 8dfb3bc8722e4483bad09382b5f87ee4
[2012-02-29 14:04:13,201: INFO/MainProcess] Task shared.tasks.authorization.create_cadr_auth[08cf77bb-f7ea-4752-a683-59447c9e0266] succeeded in 0.202355861664s: False
[2012-02-29 14:04:15,295: INFO/MainProcess] Got task from broker: shared.tasks.authorization.create_cadr_auth[a8844b1b-b04e-4d84-a437-c7cc72983970]
[2012-02-29 14:04:15,415: WARNING/PoolWorker-3] CURRENT EVENT ID: 8dfb3bc8722e4483bad09382b5f87ee4

If I restart celery, I'll get a new event id, but not until then. I believe this is what's causing the IntegrityError that we're seeing over and over.

We're running 1.3.1, with Celery 2.4.6. We're using the logging dictionary setup that Django 1.3 introduced, and we're using it in a fairly normal/sane manner. The only difference being is that we check to make sure raven is installed, and append handlers as necessary like so:

# General purpose Sentry handler
conf['handlers']['sentry'] = {
'level': 'DEBUG',
'class': 'raven.contrib.django.handlers.SentryHandler',
'formatter': 'verbose'
}

# ERROR level handler used by celery for sentry
conf['handlers']['sentry_celery'] = {
'level': 'ERROR',
'class': 'raven.contrib.django.handlers.SentryHandler',
'formatter': 'verbose'
}

conf['loggers']['celery.task.default']['handlers'] += ['sentry_celery']

We're using Raven 1.4.3, with sentry 2.7.0. Any ideas? We're seeing this in other areas with our log usage as well, it's just much, much easier to track/see/catch with celery.