Worker / celery stops working

[buffcode]

After upgrading to 20.8.0.dev 069e8ccd events stop showing up in the frontend sporadically.

The UI shows Background workers haven't checked in recently. It seems that you have a backlog of 71 tasks. Either your workers aren't running or you need more capacity.

The worker log shows:

11:42:28 [INFO] sentry.deletions.async: object.delete.executed (object_id=26394L model=u'Group' transaction_id=u'2109ad23955d4c59                               91283be5016442b7')
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/site-packages/celery/worker/consumer/consumer.py", line 316, in start
    blueprint.start(self)
  File "/usr/local/lib/python2.7/site-packages/celery/bootsteps.py", line 119, in start
    step.start(parent)
  File "/usr/local/lib/python2.7/site-packages/celery/worker/consumer/consumer.py", line 592, in start
    c.loop(*c.loop_args())
  File "/usr/local/lib/python2.7/site-packages/celery/worker/loops.py", line 91, in asynloop
    next(loop)
  File "/usr/local/lib/python2.7/site-packages/kombu/asynchronous/hub.py", line 354, in create_loop
    cb(*cbargs)
  File "/usr/local/lib/python2.7/site-packages/kombu/transport/redis.py", line 1047, in on_readable
    self.cycle.on_readable(fileno)
  File "/usr/local/lib/python2.7/site-packages/kombu/transport/redis.py", line 344, in on_readable
    chan.handlers[type]()
  File "/usr/local/lib/python2.7/site-packages/kombu/transport/redis.py", line 721, in _brpop_read
    **options)
  File "/usr/local/lib/python2.7/site-packages/redis/client.py", line 680, in parse_response
    response = connection.read_response()
  File "/usr/local/lib/python2.7/site-packages/redis/connection.py", line 624, in read_response
    response = self._parser.read_response()
  File "/usr/local/lib/python2.7/site-packages/redis/connection.py", line 403, in read_response
    (e.args,))
ConnectionError: Error while reading from socket: ('Connection closed by server.',)
11:43:29 [WARNING] celery.worker.consumer.consumer: consumer: Connection to broker lost. Trying to re-establish the connection...
Restoring 13 unacknowledged message(s)

Restarting the worker reprocesses the events and works for a short time. The connection won't be re-established as printed.

Besides fixing a potential bug while re-establishing the connection the worker should exit in order for docker restart policy to kick in as a last resort.

[buffcode]

Cross refs:

• https://forum.sentry.io/t/sentry-stops-processing-events-after-upgrade-10-0-20-8-0-dev0ba2aa70/10702/19
• Sentry stopped receiving events suddenly with no trace #400

[marbon87]

Same problem here.

btw: Health-Checks in the compose-file would be good to restart the worker automatically on such errors

[marbon87]

Maybe updating celery will help regarding to celery/celery#3932

[maximal]

I’m having the same problem in the last few weeks.

Restarting docker-compose down && docker-compose up -d helps but not for a long time.

[BYK]

Hey all,

We suspect this to be due to a recent Celery upgrade. We have submitted a revert over at getsentry/sentry#20531. If you can test this out by running: SENTRY_IMAGE=us.gcr.io/sentryio/sentry:8e03c697cd50ceba9e73ae5801729f86624c6989 ./install.sh and report back here, it would really help us determine how to proceed with @wedamija.

Thanks a lot for your cooperation and apologies for the inconvenience!

[maximal]

Did:

git pull
SENTRY_IMAGE=us.gcr.io/sentryio/sentry:8e03c697cd50ceba9e73ae5801729f86624c6989
./install.sh
docker-compose up -d

Seems like it’s working fine now. At least, docker-compose logs -f isn’t yielding much about failed jobs and /manage/queue/ page isn’t showing huge amount of jobs in Global Throughput graph.

[wedamija]

@maximal Are things still running well after a day? If so, I'll look into bumping to latest Celery and see whether it helps.

[maximal]

@wedamija, I cannot definitely say it’s completely fine, but the system behaves in much more stable way.

Once during the day it yielded a standard queue overflow message (and then stopped receiving jobs):

Background workers haven't checked in recently. It seems that you have a backlog of 2382 tasks. Either your workers aren't running or you need more capacity.

I restarted Sentry’s docker containers, and it went okay. At least I don’t have to restart those twice an hour.

[e2-robert]

This is what I see regularly on the worker, after restart it continues to run for 20-40 minutes:

worker_1                       | 11:27:04 [WARNING] celery.worker.consumer.consumer: consumer: Connection to broker lost. Trying to re-establish the connection...
worker_1                       | Restoring 31 unacknowledged message(s)
worker_1                       | Traceback (most recent call last):
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/celery/worker/consumer/consumer.py", line 316, in start
worker_1                       |     blueprint.start(self)
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/celery/bootsteps.py", line 119, in start
worker_1                       |     step.start(parent)
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/celery/worker/consumer/consumer.py", line 592, in start
worker_1                       |     c.loop(*c.loop_args())
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/celery/worker/loops.py", line 91, in asynloop
worker_1                       |     next(loop)
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/kombu/asynchronous/hub.py", line 276, in create_loop
worker_1                       |     tick_callback()
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/kombu/transport/redis.py", line 1040, in on_poll_start
worker_1                       |     cycle_poll_start()
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/kombu/transport/redis.py", line 322, in on_poll_start
worker_1                       |     self._register_BRPOP(channel)
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/kombu/transport/redis.py", line 308, in _register_BRPOP
worker_1                       |     channel._brpop_start()
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/kombu/transport/redis.py", line 714, in _brpop_start
worker_1                       |     self.client.connection.send_command('BRPOP', *keys)
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/redis/connection.py", line 610, in send_command
worker_1                       |     self.send_packed_command(self.pack_command(*args))
worker_1                       |   File "/usr/local/lib/python2.7/site-packages/redis/connection.py", line 603, in send_packed_command
worker_1                       |     (errno, errmsg))
worker_1                       | ConnectionError: Error 32 while writing to socket. Broken pipe.
worker_1                       | 11:27:13 [WARNING] celery.worker.consumer.consumer: consumer: Connection to broker lost. Trying to re-establish the connection...
worker_1                       | Restoring 31 unacknowledged message(s)

Another thing that happened to me with 8e03c697cd50ceba9e73ae5801729f86624c6989, redis server consumes ton of memory. I've restricted it now to 4G - it was eating all RAM up to 11G before.

[tomasz-grzesik]

Some solution?