Search code examples
pythondjangorediscelerycelerybeat

Celery worker goes into infinite startup and shutdown cycle


I've been using celery (the async task queue in python) in a Django project with Redis as a results backend and broker for a few years now - today I tried switching the backend / broker to AWS's ElastiCache Redis, but the celery worker goes into an infinite startup and shutdown cycle as seen below in the log file. I have also successfully connected to the Redis instance from the same machine running celery and done some basic SET and GET operations successfully.

My current setup is:

  • OS: Ubuntu 14.04
  • Python 2.7.6
  • Celery 3.1.17
  • Kombu 3.0.37
  • Billiard 3.3.0.23

command:

celery worker --concurrency=3 --queues=general --events --loglevel=DEBUG --beat --schedule=/tmp/celerybeat-schedule --pidfile=/tmp/celery.main.pid --config=celeryconfig

celerconfig.py:

import os

from django.conf import settings
from celery import Celery, Task, chain

os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'settings')


celery = Celery()
celery.config_from_object("celeryconfig")
celery.autodiscover_tasks(settings.INSTALLED_APPS, related_name='tasks')

BROKER_URL = "redis://staging-redis.abcde.clustercfg.use1.cache.amazonaws.com:6379/0"

CELERY_TIMEZONE = u'America/Los_Angeles'
CELERYD_HIJACK_ROOT_LOGGER = True
CELERY_IMPORTS = (
    "app.tasks"
)
CELERYD_TASK_TIME_LIMIT = 35  # seconds
CELERYD_TASK_SOFT_TIME_LIMIT = 25  # seconds

DJANGO_SETTINGS_MODULE = "settings"
CELERY_RESULT_BACKEND = BROKER_URL

CELERY_ROUTES = {
    'app.tasks.my_task': {'queue': 'general'}
}

celery.log:

 -------------- celery@ip-10-20-21-9 v3.1.24 (Cipater)
---- **** -----
--- * ***  * -- Linux-3.13.0-74-generic-x86_64-with-Ubuntu-14.04-trusty
-- * - **** ---
- ** ---------- [config]
- ** ---------- .> app:         default:0x7f7dc6d71650 (.default.Loader)
- ** ---------- .> transport:   redis://staging-redis.abcde.clustercfg.use1.cache.amazonaws.com:6379/0
- ** ---------- .> results:     redis://staging-redis.abcde.clustercfg.use1.cache.amazonaws.com:6379/0
- *** --- * --- .> concurrency: 3 (prefork)
-- ******* ----
--- ***** ----- [queues]
 -------------- .> general exchange=general(direct) key=general


[tasks]
  . app.tasks.my_task
  . celery.backend_cleanup
  . celery.chain
  . celery.chord
  . celery.chord_unlock
  . celery.chunks
  . celery.group
  . celery.map
  . celery.starmap

[2017-06-16 14:33:12,658: DEBUG/MainProcess] removing tasks from inqueue until task handler finished
[2017-06-16 14:33:15,110: DEBUG/MainProcess] | Worker: Preparing bootsteps.
[2017-06-16 14:33:15,112: DEBUG/MainProcess] | Worker: Building graph...
[2017-06-16 14:33:15,113: DEBUG/MainProcess] | Worker: New boot order: {Timer, Hub, Queues (intra), Pool, Autoscaler, StateDB, Autoreloader, Beat, Consumer}
[2017-06-16 14:33:15,118: DEBUG/MainProcess] | Consumer: Preparing bootsteps.
[2017-06-16 14:33:15,118: DEBUG/MainProcess] | Consumer: Building graph...
[2017-06-16 14:33:15,127: DEBUG/MainProcess] | Consumer: New boot order: {Connection, Events, Mingle, Tasks, Control, Heart, Agent, Gossip, event loop}
[2017-06-16 14:33:15,137: DEBUG/MainProcess] | Worker: Starting Hub
[2017-06-16 14:33:15,137: DEBUG/MainProcess] ^-- substep ok
[2017-06-16 14:33:15,137: DEBUG/MainProcess] | Worker: Starting Pool
[2017-06-16 14:33:15,287: DEBUG/MainProcess] ^-- substep ok
[2017-06-16 14:33:15,288: DEBUG/MainProcess] | Worker: Starting Consumer
[2017-06-16 14:33:15,288: DEBUG/MainProcess] | Consumer: Starting Connection
[2017-06-16 14:33:15,315: INFO/MainProcess] Connected to redis://staging-redis.abcde.clustercfg.use1.cache.amazonaws.com:6379/0
[2017-06-16 14:33:15,315: DEBUG/MainProcess] ^-- substep ok
[2017-06-16 14:33:15,316: DEBUG/MainProcess] | Consumer: Starting Events
[2017-06-16 14:33:15,328: DEBUG/MainProcess] | Worker: Closing Hub...
[2017-06-16 14:33:15,328: DEBUG/MainProcess] | Worker: Closing Pool...
[2017-06-16 14:33:15,328: DEBUG/MainProcess] | Worker: Closing Consumer...
[2017-06-16 14:33:15,329: DEBUG/MainProcess] | Worker: Stopping Consumer...
[2017-06-16 14:33:15,329: DEBUG/MainProcess] | Worker: Stopping Pool...
[2017-06-16 14:33:16,338: DEBUG/MainProcess] | Worker: Stopping Hub...
[2017-06-16 14:33:16,338: DEBUG/MainProcess] | Consumer: Shutdown Gossip...
[2017-06-16 14:33:16,338: DEBUG/MainProcess] | Consumer: Shutdown Heart...
[2017-06-16 14:33:16,339: DEBUG/MainProcess] | Consumer: Shutdown Control...
[2017-06-16 14:33:16,339: DEBUG/MainProcess] | Consumer: Shutdown Tasks...
[2017-06-16 14:33:16,339: DEBUG/MainProcess] | Consumer: Shutdown Events...
[2017-06-16 14:33:16,340: DEBUG/MainProcess] | Consumer: Shutdown Connection...

 -------------- celery@ip-10-20-21-9 v3.1.24 (Cipater)
---- **** -----
--- * ***  * -- Linux-3.13.0-74-generic-x86_64-with-Ubuntu-14.04-trusty
-- * - **** ---
- ** ---------- [config]
- ** ---------- .> app:         default:0x7fdc3b019650 (.default.Loader)
- ** ---------- .> transport:   redis://staging-redis.abcde.clustercfg.use1.cache.amazonaws.com:6379/0
- ** ---------- .> results:     redis://staging-redis.abcde.clustercfg.use1.cache.amazonaws.com:6379/0
- *** --- * --- .> concurrency: 3 (prefork)
-- ******* ----
--- ***** ----- [queues]
 -------------- .> general exchange=general(direct) key=general


[tasks]
  . app.tasks.my_task
  . celery.backend_cleanup
  . celery.chain
  . celery.chord
  . celery.chord_unlock
  . celery.chunks
  . celery.group
  . celery.map
  . celery.starmap

[2017-06-16 14:33:12,658: DEBUG/MainProcess] removing tasks from inqueue until task handler finished
[2017-06-16 14:33:15,110: DEBUG/MainProcess] | Worker: Preparing bootsteps.
[2017-06-16 14:33:15,112: DEBUG/MainProcess] | Worker: Building graph...
[2017-06-16 14:33:15,113: DEBUG/MainProcess] | Worker: New boot order: {Timer, Hub, Queues (intra), Pool, Autoscaler, StateDB, Autoreloader, Beat, Consumer}
[2017-06-16 14:33:15,118: DEBUG/MainProcess] | Consumer: Preparing bootsteps.
[2017-06-16 14:33:15,118: DEBUG/MainProcess] | Consumer: Building graph...
[2017-06-16 14:33:15,127: DEBUG/MainProcess] | Consumer: New boot order: {Connection, Events, Mingle, Tasks, Control, Heart, Agent, Gossip, event loop}
[2017-06-16 14:33:15,137: DEBUG/MainProcess] | Worker: Starting Hub
[2017-06-16 14:33:15,137: DEBUG/MainProcess] ^-- substep ok
[2017-06-16 14:33:15,137: DEBUG/MainProcess] | Worker: Starting Pool
[2017-06-16 14:33:15,287: DEBUG/MainProcess] ^-- substep ok
[2017-06-16 14:33:15,288: DEBUG/MainProcess] | Worker: Starting Consumer
[2017-06-16 14:33:15,288: DEBUG/MainProcess] | Consumer: Starting Connection
[2017-06-16 14:33:15,315: INFO/MainProcess] Connected to redis://staging-redis.abcde.clustercfg.use1.cache.amazonaws.com:6379/0
[2017-06-16 14:33:15,315: DEBUG/MainProcess] ^-- substep ok
[2017-06-16 14:33:15,316: DEBUG/MainProcess] | Consumer: Starting Events
[2017-06-16 14:33:15,328: DEBUG/MainProcess] | Worker: Closing Hub...
[2017-06-16 14:33:15,328: DEBUG/MainProcess] | Worker: Closing Pool...
[2017-06-16 14:33:15,328: DEBUG/MainProcess] | Worker: Closing Consumer...
[2017-06-16 14:33:15,329: DEBUG/MainProcess] | Worker: Stopping Consumer...
[2017-06-16 14:33:15,329: DEBUG/MainProcess] | Worker: Stopping Pool...
[2017-06-16 14:33:16,338: DEBUG/MainProcess] | Worker: Stopping Hub...
[2017-06-16 14:33:16,338: DEBUG/MainProcess] | Consumer: Shutdown Gossip...
[2017-06-16 14:33:16,338: DEBUG/MainProcess] | Consumer: Shutdown Heart...
[2017-06-16 14:33:16,339: DEBUG/MainProcess] | Consumer: Shutdown Control...
[2017-06-16 14:33:16,339: DEBUG/MainProcess] | Consumer: Shutdown Tasks...
[2017-06-16 14:33:16,339: DEBUG/MainProcess] | Consumer: Shutdown Events...
[2017-06-16 14:33:16,340: DEBUG/MainProcess] | Consumer: Shutdown Connection...

## And again...

Solution

  • Looks like the issue arose because I was trying to use a Redis Cluster as the broker and backend which isn't supported out of the box - in a more basic test setup, the SETNX command was failing on celery startup because it seems the command is not supported by Redis Clusters.

    I still need to do some research to see if it's possible to use a Redis Cluster as a Celery backend and broker.