Issue 1:
Checklist

I have verified that the issue exists against the master branch of Celery.

This has already been asked to the discussion group first.

I have read the relevant section in the

contribution guide

on reporting bugs.

I have checked the issues list

for similar or identical bug reports.

I have checked the pull requests list

for existing proposed fixes.

I have checked the commit log

to find out if the bug was already fixed in the master branch.

I have included all related issues and possible duplicate issues

in this issue (If there are none, check this box anyway).

Mandatory Debugging Information

I have included the output of celery -A proj report in the issue.

(if you are not able to do this, then at least specify the Celery

version affected).

I have verified that the issue exists against the master branch of Celery.

I have included the contents of pip freeze in the issue.

I have included all the versions of all the external dependencies required

to reproduce this bug.

Optional Debugging Information

I have tried reproducing the issue on more than one Python version

and/or implementation.

I have tried reproducing the issue on more than one message broker and/or

result backend.

I have tried reproducing the issue on more than one version of the message

broker and/or result backend.

I have tried reproducing the issue on more than one operating system.

I have tried reproducing the issue on more than one workers pool.

I have tried reproducing the issue with autoscaling, retries,

ETA/Countdown & rate limits disabled.

I have tried reproducing the issue after downgrading

and/or upgrading Celery and its dependencies.

Related Issues and Possible Duplicates

Related Issues

None

Possible Duplicates

None

Environment & Settings

Celery version: celery==4.4.2

celery report Output:

[2020-05-31 23:28:34,434: INFO/MainProcess] Connected to amqp://remote_worker:**@127.0.0.1:5672//
[2020-05-31 23:28:34,453: INFO/MainProcess] mingle: searching for neighbors
[2020-05-31 23:28:35,487: INFO/MainProcess] mingle: all alone
[2020-05-31 23:28:35,528: WARNING/MainProcess] /home/ubuntu/.local/lib/python3.7/site-packages/celery/fixups/django.py:203: UserWarning: Using settings.DEBUG leads to a memory
leak, never use this setting in production environments!
leak, never use this setting in production environments!''')
[2020-05-31 23:28:35,529: INFO/MainProcess] celery@testroom ready.
[2020-05-31 23:28:47,351: INFO/MainProcess] Received task: api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906]
[2020-05-31 23:28:47,689: WARNING/ForkPoolWorker-1] started
[2020-05-31 23:28:47,690: WARNING/ForkPoolWorker-1] HELLOOOOO
[2020-05-31 23:28:47,690: WARNING/ForkPoolWorker-1] retry
[2020-05-31 23:28:47,721: INFO/MainProcess] Received task: api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] ETA:[2020-05-31 23:28:57.692348+00:00]
[2020-05-31 23:28:47,722: INFO/MainProcess] Received task: api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] ETA:[2020-05-31 23:28:57.716321+00:00]
[2020-05-31 23:28:47,777: INFO/ForkPoolWorker-1] Task api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] retry: Retry in 10s: Retry(Retry(...), Exception('i have filled now'), 10)
[2020-05-31 23:28:57,999: WARNING/ForkPoolWorker-1] started
[2020-05-31 23:28:57,999: WARNING/ForkPoolWorker-1] HELLOOOOO
[2020-05-31 23:28:58,000: WARNING/ForkPoolWorker-1] ended
[2020-05-31 23:28:58,000: WARNING/ForkPoolWorker-1] BYEEEEE
[2020-05-31 23:28:58,062: INFO/ForkPoolWorker-1] Task api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] succeeded in 0.34440315900428686s: None
[2020-05-31 23:28:58,301: WARNING/ForkPoolWorker-1] started
[2020-05-31 23:28:58,302: WARNING/ForkPoolWorker-1] HELLOOOOO
[2020-05-31 23:28:58,302: WARNING/ForkPoolWorker-1] retry
[2020-05-31 23:28:58,304: INFO/MainProcess] Received task: api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] ETA:[2020-05-31 23:29:08.303091+00:00]
[2020-05-31 23:28:58,307: INFO/MainProcess] Received task: api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] ETA:[2020-05-31 23:29:08.306141+00:00]
[2020-05-31 23:28:58,368: INFO/ForkPoolWorker-1] Task api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] retry: Retry in 10s: Retry(Retry(...), Exception('i have filled now'), 10)
[2020-05-31 23:29:08,572: WARNING/ForkPoolWorker-1] started
[2020-05-31 23:29:08,572: WARNING/ForkPoolWorker-1] HELLOOOOO
[2020-05-31 23:29:08,573: WARNING/ForkPoolWorker-1] ended
[2020-05-31 23:29:08,573: WARNING/ForkPoolWorker-1] BYEEEEE
[2020-05-31 23:29:08,633: INFO/ForkPoolWorker-1] Task api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] succeeded in 0.3256059319974156s: None
[2020-05-31 23:29:08,872: WARNING/ForkPoolWorker-1] started
[2020-05-31 23:29:08,872: WARNING/ForkPoolWorker-1] HELLOOOOO
[2020-05-31 23:29:08,873: WARNING/ForkPoolWorker-1] retry
[2020-05-31 23:29:08,875: INFO/MainProcess] Received task: api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] ETA:[2020-05-31 23:29:18.873799+00:00]
[2020-05-31 23:29:08,878: WARNING/ForkPoolWorker-1] BYEEEEE
[2020-05-31 23:29:08,880: INFO/MainProcess] Received task: api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] ETA:[2020-05-31 23:29:18.877550+00:00]
[2020-05-31 23:29:08,940: INFO/ForkPoolWorker-1] Task api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] retry: Retry in 10s: Retry(Retry(...), Exception('i have filled now'), 10)
[2020-05-31 23:29:19,144: WARNING/ForkPoolWorker-1] started
[2020-05-31 23:29:19,144: WARNING/ForkPoolWorker-1] HELLOOOOO
[2020-05-31 23:29:19,145: WARNING/ForkPoolWorker-1] ended
[2020-05-31 23:29:19,145: WARNING/ForkPoolWorker-1] BYEEEEE
[2020-05-31 23:29:19,205: INFO/ForkPoolWorker-1] Task api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] succeeded in 0.326258520995907s: None
[2020-05-31 23:29:19,444: WARNING/ForkPoolWorker-1] started
[2020-05-31 23:29:19,444: WARNING/ForkPoolWorker-1] HELLOOOOO
[2020-05-31 23:29:19,445: WARNING/ForkPoolWorker-1] retry
[2020-05-31 23:29:19,505: ERROR/ForkPoolWorker-1] Task api_v3.tests.execute[e97d93b5-b0e5-4b87-96ab-1aab66119906] raised unexpected: Exception('i have filled now')
Traceback (most recent call last):
File "/home/ubuntu/.local/lib/python3.7/site-packages/celery/app/trace.py", line 385, in trace_task
R = retval = fun(*args, **kwargs)
File "/home/ubuntu/.local/lib/python3.7/site-packages/celery/app/trace.py", line 650, in __protected_call__
return self.run(*args, **kwargs)
File "/home/ubuntu/.local/lib/python3.7/site-packages/celery/app/base.py", line 500, in run
raise task.retry(exc=exc, **retry_kwargs)
File "/home/ubuntu/.local/lib/python3.7/site-packages/celery/app/task.py", line 704, in retry
raise_with_context(exc)
File "/home/ubuntu/.local/lib/python3.7/site-packages/celery/app/base.py", line 487, in run
return task._orig_run(*args, **kwargs)
File "/var/www/django_projects/earthalytics-api/api_v3/tests.py", line 26, in execute
self.retry(exc=Exception("i have filled now"), args=[param_a, param_b], kwargs=kwargs)
File "/home/ubuntu/.local/lib/python3.7/site-packages/celery/app/task.py", line 704, in retry
raise_with_context(exc)
File "/home/ubuntu/.local/lib/python3.7/site-packages/celery/utils/serialization.py", line 288, in raise_with_context
_raise_with_context(exc, exc_info[1])
File "<string>", line 1, in _raise_with_context
Exception: i have filled now

Steps to Reproduce

Make a class with a destructor.

Make a celery task.

Instantiate the class in the celery task.

Make the celery task raise an Exception.

See how destructor dosn't get called.(Gets called if task ends in success)

Required Dependencies

Minimal Python Version: N/A or Unknown

Minimal Celery Version: N/A or Unknown

Minimal Kombu Version: N/A or Unknown

Minimal Broker Version: N/A or Unknown

Minimal Result Backend Version: N/A or Unknown

Minimal OS and/or Kernel Version: N/A or Unknown

Minimal Broker Client Version: N/A or Unknown

Minimal Result Backend Client Version: N/A or Unknown

Python Packages

pip freeze Output:

Other Dependencies

N/A

Minimally Reproducible Test Case

class WelcomeClass():
def __init__(self):
print("HELLOOOOO")

def __del__(self):
print("BYEEEEE")

@app_cluster.task(bind=True, autoretry_for=(Exception,), max_retries=3,
default_retry_delay=10)
def execute(self, param_a, param_b=None, **kwargs):
print("started")
jb = WelcomeClass()
if param_b is None:
param_b = "filled"
print("retry")
self.retry(exc=Exception("i have filled now"), args=[param_a, param_b], kwargs=kwargs)
print("ended")

def test_celery(self):
sig = execute.si("something")
t = sig.delay()
t = 0

Expected Behavior

I expect the destructor of a class begin called everytime a celery task succeed/fail/raise exception etc

Actual Behavior

Destrucutor gets called only when task succeed.

Issue 2:
Summary

In a Celery/RabbitMQ/Heroku setup with many tasks using countdown/eta and retry, I'm experiencing workers suddenly not processing tasks anymore. They don't raise an exception and the main Celery process does not terminate.

I will outline in some detail what I'm seeing and present a single case with a log section showing a worker process that is processing tasks, then it gets restarted (24h Heroku dyno cycling), then it processes one more task which ends in a retry, and then it seemingly 'falls asleep' (it ignores all the tasks piling up in the task queue, and even when the currently fetched task is up for retry, it doesn't process it).

What possible reasons could you think of, which destabilize a Celery worker that has to process a lot of countdown/eta/retry? Anything with prefetch_count maybe? Is there anything that could clog up the local pool in a worker to the point that it no longer fetches new tasks or processes local ones?

Environment

Python: 2.7.12

Versions: celery 3.1.24, kombu 3.0.37, billiard 3.3.0.23, amqp 1.4.9

Broker: RabbitMQ (professionally hosted with CloudAMQP, standard configuration)

Platform: Heroku (Linux)

Configuration

CELERYD_PREFETCH_MULTIPLIER = 1

# broker configuration as advised by https://www.cloudamqp.com/docs/celery.html
BROKER_URL = os.environ.get('CLOUDAMQP_URL')
BROKER_USE_SSL = True
BROKER_POOL_LIMIT = 1 # important for small AMQP plans! see https://devcenter.heroku.com/articles/cloudamqp#celery
BROKER_HEARTBEAT = None # we're using TCP keep-alive instead
BROKER_CONNECTION_TIMEOUT = 30 # may require a long timeout due to Linux DNS timeouts etc
CELERY_EVENT_QUEUE_EXPIRES = 60 # expire temporary event queues after 60 seconds
CELERY_TRACK_STARTED = True # The task will report its status as "started" when the task is executed by a worker. Can be useful for when there are long running tasks and there is a need to report which task is currently running. - http://docs.celeryproject.org/en/latest/configuration.html#celery-track-started

A single worker dyno is launched with the following command line:

worker: celery worker --app=myapp --queues=priority,default --concurrency=3 --loglevel=DEBUG -Ofair --without-heartbeat --without-gossip --without-mingle

There's a second dyno type, with a similar configuration, but which is only working the priority queue and also has --beat set. It was not affected in the case shown here and kept processing the tasks from the priority queue when the worker type had frozen. (Tasks on the priority queue never have a countdown set and only rarely use retry.)

Issue

The worker is running with the preforked pool and a concurrency of 3. It's receiving a lot of tasks with an ETA of 15mins. Quite often these tasks need to be retried (always with a 30min delay).

Every once in a while, at seemingly arbitrary times of the day, the worker will process one last task and then stop. The last task often ends in a retry, but not always (maybe 80% of the time).

This occurs sometimes multiple times a day and sometimes it doesn't for days. Sometimes it occurs hours later and sometimes right after the worker has started. (Heroku restarts them every 24h by force, so I never have a worker running longer than that.)

When it does occur, the worker stops processing any tasks. It doesn't receive any new tasks from the broker, nor does it proceed with tasks in the local pool that have been pushed back by way of retry.

Example

The following log shows one case of this. Here's the order of events to be seen:

14:21:58: The worker is working fine. The prefetch_count is 65 (so it's my understanding that 62 tasks are waiting to be retried).

14:21:59: Task a2a5bc98 is fetched from RabbitMQ, processed and completed (no retry).

14:21:59: Heroku decides that after 24h, it wants to restart (cycle) the dyno, so it performs a shutdown of Celery (note that this still affected by #2839, so active tasks are not being shut down cleanly, however no task seems to have been in process in this case).

14:22:11: Celery starts up again in a new dyno with a new process.

14:22:11: After the restart, the prefetch_count goes back to 3 (the configured concurrency).

14:22:11: The worker receives a single task (why not at least three?), 09ffc23f, which has an ETA, and increases the prefetch_count to 4.

Nothing happens for two minutes! (I didn't cut anything from the log of this dyno here.)

14:24:25: Then the prefetch_count is set back to 3, and the task is accepted. It is executed to the end, and ends in a retry.

From here on, the worker doesn't do anything anymore. Not even at 14:54:26, when it should have retried task 09ffc23f from the local pool.

It's not possible to inspect the dyno on Heroku, but I know the main worker process hasn't crashed (I don't know about the preforked subprocesses) for two reasons:

a) If the main process terminates, Heroku detects that and restarts the dyno. But it doesn't.

b) When I eventually restart the dyno manually, Heroku sends a signal to the process, and I see the log lines on celery.bootsteps around Closing Hub, Closing consumer channel and so on.

Logs

And finally, here's the log to the case described above:

Jan 20 14:21:58 myapp app/worker.1: DEBUG [-/-/-/kombu.common] basic.qos: prefetch_count->65
Jan 20 14:21:59 myapp app/worker.1: INFO [-/-/-/celery.worker.strategy] Received task: myapp.retrieve[a2a5bc98-906a-4c6a-ab30-762a7c738143]
Jan 20 14:21:59 myapp app/worker.1: DEBUG [-/-/-/celery.pool] TaskPool: Apply <function _fast_trace_task at 0x7f74d12b5398> (args:(u'myapp.retrieve', 'a2a5bc98-906a-4c6a-ab30-762a7c738143', [], {u'account_id': 5466}, {'retries': 0, 'id': 'a2a5bc98-906a-4c6a-ab30-762a7c738143', u'reply_to': u'9e8056dd-a933-3398-98bf-e6af7669487d', 'utc': True, 'expires': None, u'correlation_id': u'a2a5bc98-906a-4c6a-ab30-762a7c738143', u'headers': {}, 'taskset': None, u'group': None, u'hostname': 'celery@1b7e0939-0c49-46c4-b9cd-33adc9f30fcd', u'delivery_info': {u'exchange': u'default', u'routing_key': u'priority', u'priority': None, u'redelivered': False}, 'kwargs': {u'account_id': 5466}, 'task': u'myapp.retrieve', u'is_eager': False, 'errbacks': None, 'eta': None, 'args': [], 'callbacks': None, 'chord': None, 'timelimit': (None, None)}) kwargs:{})
Jan 20 14:21:59 myapp app/worker.1: DEBUG [-/-/-/celery.worker.job] Task accepted: myapp.retrieve[a2a5bc98-906a-4c6a-ab30-762a7c738143] pid:11
Jan 20 14:21:59 myapp heroku/worker.1: Cycling
Jan 20 14:21:59 myapp heroku/worker.1: State changed from up to starting
Jan 20 14:21:59 myapp app/worker.1: INFO [myapp.retrieve/a2a5bc98/acc5466/myapp.tasks] Complete
Jan 20 14:22:00 myapp app/worker.1: INFO [-/-/-/celery.worker.job] Task myapp.retrieve[a2a5bc98-906a-4c6a-ab30-762a7c738143] succeeded in 0.820070138987s: None
Jan 20 14:22:00 myapp heroku/worker.1: Stopping all processes with SIGTERM
Jan 20 14:22:00 myapp app/worker.1: worker: Warm shutdown (MainProcess)
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Closing Hub...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Closing Pool...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Closing Consumer...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Stopping Consumer...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Closing Connection...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Closing Events...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Closing Tasks...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Closing Control...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Closing event loop...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Stopping event loop...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Stopping Control...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/amqp] Closed channel #2
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Stopping Tasks...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.worker.consumer] Canceling task consumer...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Stopping Events...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Stopping Connection...
Jan 20 14:22:00 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Stopping Pool...
Jan 20 14:22:01 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Stopping Hub...
Jan 20 14:22:01 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Shutdown Control...
Jan 20 14:22:01 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Shutdown Tasks...
Jan 20 14:22:01 myapp app/worker.1: DEBUG [-/-/-/celery.worker.consumer] Canceling task consumer...
Jan 20 14:22:01 myapp app/worker.1: DEBUG [-/-/-/celery.worker.consumer] Closing consumer channel...
Jan 20 14:22:01 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Shutdown Events...
Jan 20 14:22:01 myapp app/worker.1: DEBUG [-/-/-/amqp] Closed channel #1
Jan 20 14:22:01 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Shutdown Connection...
Jan 20 14:22:01 myapp app/worker.1: DEBUG [-/-/-/amqp] Closed channel #1
Jan 20 14:22:01 myapp app/worker.1: DEBUG [-/-/-/celery.concurrency.asynpool] removing tasks from inqueue until task handler finished
Jan 20 14:22:02 myapp heroku/worker.1: Process exited with status 0
Jan 20 14:22:08 myapp heroku/worker.1: Starting process with command `celery worker --app=myapp --queues=priority,default --concurrency=3 --loglevel=DEBUG -Ofair --without-heartbeat --without-gossip --without-mingle`
Jan 20 14:22:08 myapp heroku/worker.1: State changed from starting to up
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Preparing bootsteps.
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Building graph...
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: New boot order: {StateDB, Timer, Hub, Queues (intra), Pool, Autoreloader, Beat, Autoscaler, Consumer}
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Preparing bootsteps.
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Building graph...
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: New boot order: {Connection, Events, Mingle, Tasks, Control, Heart, Agent, Gossip, event loop}
Jan 20 14:22:11 myapp app/worker.1: -------------- celery@49b5f034-8438-4b82-8fd8-1cc7c8180f03 v3.1.24 (Cipater)
Jan 20 14:22:11 myapp app/worker.1: ---- **** -----
Jan 20 14:22:11 myapp app/worker.1: --- * *** * -- Linux-3.13.0-105-generic-x86_64-with-debian-jessie-sid
Jan 20 14:22:11 myapp app/worker.1: -- * - **** ---
Jan 20 14:22:11 myapp app/worker.1: - ** ---------- [config]
Jan 20 14:22:11 myapp app/worker.1: - ** ---------- .> app: myapp:0x7f20a3c28d10
Jan 20 14:22:11 myapp app/worker.1: - ** ---------- .> transport: amqp://myapp:**@moose.rmq.cloudamqp.com:5671/myapp
Jan 20 14:22:11 myapp app/worker.1: - ** ---------- .> results:
Jan 20 14:22:11 myapp app/worker.1: - *** --- * --- .> concurrency: 3 (prefork)
Jan 20 14:22:11 myapp app/worker.1: -- ******* ----
Jan 20 14:22:11 myapp app/worker.1: --- ***** ----- [queues]
Jan 20 14:22:11 myapp app/worker.1: -------------- .> default exchange=default(direct) key=default
Jan 20 14:22:11 myapp app/worker.1: .> priority exchange=default(direct) key=priority
Jan 20 14:22:11 myapp app/worker.1: [tasks]
Jan 20 14:22:11 myapp app/worker.1: . celery.backend_cleanup
Jan 20 14:22:11 myapp app/worker.1: . celery.chain
Jan 20 14:22:11 myapp app/worker.1: . celery.chord
Jan 20 14:22:11 myapp app/worker.1: . celery.chord_unlock
Jan 20 14:22:11 myapp app/worker.1: . celery.chunks
Jan 20 14:22:11 myapp app/worker.1: . celery.group
Jan 20 14:22:11 myapp app/worker.1: . celery.map
Jan 20 14:22:11 myapp app/worker.1: . celery.starmap
[...]
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Starting Hub
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] ^-- substep ok
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Starting Pool
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] ^-- substep ok
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Starting Consumer
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Starting Connection
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/amqp] Start from server, version: 0.9, properties: {u'version': u'3.5.6', u'information': u'Licensed under the MPL. See http://www.rabbitmq.com/', u'platform': u'Erlang/OTP', u'copyright': u'Copyright (C) 2007-2015 Pivotal Software, Inc.', u'product': u'RabbitMQ', u'cluster_name': u'moose', u'capabilities': {u'authentication_failure_close': True, u'exchange_exchange_bindings': True, u'consumer_cancel_notify': True, u'consumer_priorities': True, u'per_consumer_qos': True, u'connection.blocked': True, u'basic.nack': True, u'publisher_confirms': True}}, mechanisms: [u'PLAIN', u'AMQPLAIN'], locales: [u'en_US']
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/amqp] Open OK!
Jan 20 14:22:11 myapp app/worker.1: INFO [-/-/-/celery.worker.consumer] Connected to amqp://myapp:**@moose.rmq.cloudamqp.com:5671/myapp
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] ^-- substep ok
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Starting Events
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/amqp] Start from server, version: 0.9, properties: {u'version': u'3.5.6', u'information': u'Licensed under the MPL. See http://www.rabbitmq.com/', u'platform': u'Erlang/OTP', u'copyright': u'Copyright (C) 2007-2015 Pivotal Software, Inc.', u'product': u'RabbitMQ', u'cluster_name': u'moose', u'capabilities': {u'authentication_failure_close': True, u'exchange_exchange_bindings': True, u'consumer_cancel_notify': True, u'consumer_priorities': True, u'per_consumer_qos': True, u'connection.blocked': True, u'basic.nack': True, u'publisher_confirms': True}}, mechanisms: [u'PLAIN', u'AMQPLAIN'], locales: [u'en_US']
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/amqp] Open OK!
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/amqp] using channel_id: 1
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/amqp] Channel open
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] ^-- substep ok
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Starting Tasks
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/amqp] using channel_id: 1
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/amqp] Channel open
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] ^-- substep ok
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Starting Control
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/amqp] using channel_id: 2
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/amqp] Channel open
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] ^-- substep ok
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Consumer: Starting event loop
Jan 20 14:22:11 myapp app/worker.1: INFO [-/-/-/celery.redirected] celery@49b5f034-8438-4b82-8fd8-1cc7c8180f03 ready.
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/celery.bootsteps] | Worker: Hub.register Pool...
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/kombu.common] basic.qos: prefetch_count->3
Jan 20 14:22:11 myapp app/worker.1: INFO [-/-/-/celery.worker.strategy] Received task: myapp.finalize[09ffc23f-759a-4147-ab3a-ef5ad669afe1] eta:[2017-01-20 14:24:25.142725+00:00]
Jan 20 14:22:11 myapp app/worker.1: DEBUG [-/-/-/kombu.common] basic.qos: prefetch_count->4
Jan 20 14:24:25 myapp app/worker.1: DEBUG [-/-/-/celery.pool] TaskPool: Apply <function _fast_trace_task at 0x7f20a0707398> (args:(u'myapp.finalize', '09ffc23f-759a-4147-ab3a-ef5ad669afe1', [], {u'account_id': 4426, u'reaction_id': 1494970}, {'taskset': None, 'retries': 22, 'task': u'myapp.finalize', 'timelimit': (None, None), 'utc': True, u'hostname': 'celery@49b5f034-8438-4b82-8fd8-1cc7c8180f03', 'id': '09ffc23f-759a-4147-ab3a-ef5ad669afe1', 'args': [], u'reply_to': u'dd5e604d-f8d3-3b4e-9a24-6011f659934a', 'kwargs': {u'account_id': 4426, u'reaction_id': 1494970}, u'group': None, 'eta': '2017-01-20T14:24:25.142725+00:00', 'callbacks': None, 'errbacks': None, 'chord': None, u'headers': {}, 'expires': None, u'delivery_info': {u'exchange': u'default', u'routing_key': u'default', u'redelivered': True, u'priority': 0}, u'is_eager': False, u'correlation_id': u'09ffc23f-759a-4147-ab3a-ef5ad669afe1'}) kwargs:{})
Jan 20 14:24:26 myapp app/worker.1: DEBUG [-/-/-/kombu.common] basic.qos: prefetch_count->3
Jan 20 14:24:26 myapp app/worker.1: DEBUG [-/-/-/celery.worker.job] Task accepted: myapp.finalize[09ffc23f-759a-4147-ab3a-ef5ad669afe1] pid:11
Jan 20 14:24:26 myapp app/worker.1: DEBUG [myapp.finalize/09ffc23f/-/integration.operational.sentry_client.CustomSentryClient] Configuring Raven for host: <raven.conf.remote.RemoteConfig object at 0x7f20998a5090>
Jan 20 14:24:26 myapp app/worker.1: INFO [myapp.finalize/09ffc23f/acc4426/myapp.tasks] Rescheduling task
Jan 20 14:24:26 myapp app/worker.1: DEBUG [myapp.finalize/09ffc23f/acc4426/amqp] Start from server, version: 0.9, properties: {u'version': u'3.5.6', u'information': u'Licensed under the MPL. See http://www.rabbitmq.com/', u'platform': u'Erlang/OTP', u'copyright': u'Copyright (C) 2007-2015 Pivotal Software, Inc.', u'product': u'RabbitMQ', u'cluster_name': u'moose', u'capabilities': {u'authentication_failure_close': True, u'exchange_exchange_bindings': True, u'consumer_cancel_notify': True, u'consumer_priorities': True, u'per_consumer_qos': True, u'connection.blocked': True, u'basic.nack': True, u'publisher_confirms': True}}, mechanisms: [u'PLAIN', u'AMQPLAIN'], locales: [u'en_US']
Jan 20 14:24:26 myapp app/worker.1: DEBUG [myapp.finalize/09ffc23f/acc0541/amqp] Open OK!
Jan 20 14:24:26 myapp app/worker.1: DEBUG [myapp.finalize/09ffc23f/acc0541/amqp] using channel_id: 1
Jan 20 14:24:26 myapp app/worker.1: DEBUG [myapp.finalize/09ffc23f/acc0541/amqp] Channel open
Jan 20 14:24:26 myapp app/worker.1: INFO [-/-/-/celery.worker.job] Task myapp.finalize[09ffc23f-759a-4147-ab3a-ef5ad669afe1] retry: Retry in 1800s

After this, there was silence in this worker's logs for the next 60 minutes. Then I restarted it and it started processing tasks just fine for the next hour or two, until the same issue occured. Rinse and repeat.

Second case

Here's another case, this time with RabbitMQ management graph:

Worker was started at 19:13:23. It processed a couple of tasks (about one every 20s, which is unexpectedly few), the last one at 19:21:55, then went silent.