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

#6672

Possible Duplicates

None

Environment & Settings

Celery version: 5.1.2

celery report Output:

software -> celery:5.1.2 (sun-harmonics) kombu:5.1.0 py:3.6.8
billiard:3.6.4.0 py-amqp:5.0.6
platform -> system:Darwin arch:64bit
kernel version:20.5.0 imp:CPython
loader -> celery.loaders.app.AppLoader
settings -> transport:amqp results:django-db

accept_content: ['pickle']
result_serializer: 'pickle'
task_serializer: 'pickle'

Steps to Reproduce

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

Prerequirements are to have the Django project and setup described in official celery docs.

@app.task
def sleep_task(user_object):
import time
time.sleep(100000)

# in Django shell
sleep_task.delay(User.objects.first())

Expected Behavior

We should have standard inspect active output with deserialized Django object like in 4.x.

-> celery@xyz: OK
* {'id': '81f641db-8ba9-45c8-8d1e-e8cd52c50de1', 'name': 'proj.tasks.sleep_task', 'args': (<User: XYZ>,), 'kwargs': {}, 'type': 'proj.tasks.sleep_task'', 'hostname': 'celery@xyz', 'time_start': 1633008451.4256349, 'acknowledged': True, 'delivery_info': {'exchange': '', 'routing_key': 'celery', 'priority': 0, 'redelivered': False}, 'worker_pid': 36039}

1 node online.

Actual Behavior

Instead of receiving the active task data, celery -A proj inspect active raises DecodeError

Traceback (most recent call last):
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/serialization.py", line 42, in _reraise_errors
yield
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/serialization.py", line 255, in loads
return decode(data)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/serialization.py", line 327, in unpickle
return pickle_loads(str_to_bytes(s))
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/serialization.py", line 51, in pickle_loads
return load(BytesIO(s))
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/django/db/models/base.py", line 1828, in model_unpickle
model = apps.get_model(*model_id)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/django/apps/registry.py", line 198, in get_model
self.check_models_ready()
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/django/apps/registry.py", line 140, in check_models_ready
raise AppRegistryNotReady("Models aren't loaded yet.")
django.core.exceptions.AppRegistryNotReady: Models aren't loaded yet.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/Users/xyz/.virtualenvs/proj/bin/celery", line 8, in <module>
sys.exit(main())
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/celery/__main__.py", line 15, in main
sys.exit(_main())
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/celery/bin/celery.py", line 213, in main
return celery(auto_envvar_prefix="CELERY")
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/click/core.py", line 829, in __call__
return self.main(*args, **kwargs)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/click/core.py", line 782, in main
rv = self.invoke(ctx)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/click/core.py", line 1259, in invoke
return _process_result(sub_ctx.command.invoke(sub_ctx))
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/click/core.py", line 1066, in invoke
return ctx.invoke(self.callback, **ctx.params)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/click/core.py", line 610, in invoke
return callback(*args, **kwargs)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/click/decorators.py", line 21, in new_func
return f(get_current_context(), *args, **kwargs)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/celery/bin/base.py", line 133, in caller
return f(ctx, *args, **kwargs)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/celery/bin/control.py", line 137, in inspect
**arguments)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/celery/app/control.py", line 114, in _request
pattern=self.pattern, matcher=self.matcher,
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/celery/app/control.py", line 743, in broadcast
limit, callback, channel=channel,
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/pidbox.py", line 350, in _broadcast
channel=chan)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/pidbox.py", line 389, in _collect
self.connection.drain_events(timeout=timeout)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/connection.py", line 318, in drain_events
return self.transport.drain_events(self.connection, **kwargs)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/transport/pyamqp.py", line 135, in drain_events
return connection.drain_events(**kwargs)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/amqp/connection.py", line 523, in drain_events
while not self.blocking_read(timeout):
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/amqp/connection.py", line 529, in blocking_read
return self.on_inbound_frame(frame)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/amqp/method_framing.py", line 77, in on_frame
callback(channel, msg.frame_method, msg.frame_args, msg)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/amqp/connection.py", line 536, in on_inbound_method
method_sig, payload, content,
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/amqp/abstract_channel.py", line 143, in dispatch_method
listener(*args)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/amqp/channel.py", line 1613, in _on_basic_deliver
fun(msg)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/messaging.py", line 620, in _receive_callback
decoded = None if on_m else message.decode()
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/message.py", line 190, in decode
self._decoded_cache = self._decode()
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/message.py", line 195, in _decode
self.content_encoding, accept=self.accept)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/serialization.py", line 255, in loads
return decode(data)
File "/Users/xyz/.pyenv/versions/3.6.8/lib/python3.6/contextlib.py", line 99, in __exit__
self.gen.throw(type, value, traceback)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/serialization.py", line 46, in _reraise_errors
reraise(wrapper, wrapper(exc), sys.exc_info()[2])
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/exceptions.py", line 21, in reraise
raise value.with_traceback(tb)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/serialization.py", line 42, in _reraise_errors
yield
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/serialization.py", line 255, in loads
return decode(data)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/serialization.py", line 327, in unpickle
return pickle_loads(str_to_bytes(s))
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/kombu/serialization.py", line 51, in pickle_loads
return load(BytesIO(s))
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/django/db/models/base.py", line 1828, in model_unpickle
model = apps.get_model(*model_id)
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/django/apps/registry.py", line 198, in get_model
self.check_models_ready()
File "/Users/xyz/.virtualenvs/proj/lib/python3.6/site-packages/django/apps/registry.py", line 140, in check_models_ready
raise AppRegistryNotReady("Models aren't loaded yet.")
kombu.exceptions.DecodeError: Models aren't loaded yet.

Issue 2:
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 report Output:

software -> celery:4.2.1 (windowlicker) kombu:4.6.7 py:3.6.5
billiard:3.5.0.5 sqs:N/A
platform -> system:Darwin arch:64bit imp:CPython
loader -> celery.loaders.app.AppLoader
settings -> transport:sqs results:disabled

BROKER_TRANSPORT_OPTIONS: {
'polling_interval': 1,
'queue_name_prefix': 'celery_dev-',
'region': 'eu-west-1',
'sqs-creation-attributes': {'KmsMasterKeyId': '********'},
'visibility_timeout': 3600,
'wait_time_seconds': 10}
BROKER_URL: 'sqs://localhost//'
CELERYBEAT_SCHEDULE: {***}
CELERYD_LOG_FORMAT: ('%(asctime)s %(name)s '
'%(process)d-0@local '
'[%(levelname)s] %(pathname)s:%(lineno)d '
'%(funcName)s(): %(module)s: %(message)s')
CELERY_ACKS_LATE: True
CELERY_ENABLE_REMOTE_CONTROL: False
CELERY_ENABLE_UTC: True
CELERY_SEND_EVENTS: False
CELERY_TIMEZONE: 'Asia/Kolkata'
DEBUG: True
DEFAULT_VISIBILITY_TIMEOUT: 3600
REGION_NAME: 'eu-west-1'
USE_API_AUTH: '********'
crontab: <class 'celery.schedules.crontab'>
env: 'dev'
gethostname: <built-in function gethostname>
CELERY_INCLUDE: ['tasks.generic_tasks']

Steps to Reproduce

Required Dependencies

Minimal Python Version: Python 3.6.5

Minimal Celery Version: 4.2.1

Minimal Kombu Version: 4.6.7

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:

amqp==2.5.2
aws-requests-auth==0.4.2
awscli==1.16.53
billiard==3.5.0.5
boto3==1.9.161
botocore==1.12.182
celery==4.2.1
certifi==2019.11.28
chardet==3.0.4
circus==0.15.0
click==6.7
colorama==0.3.9
docutils==0.14
elasticsearch==6.2.0
elasticsearch-curator==5.8.0
flasgger==0.9.2
Flask==1.0.2
gunicorn==19.9.0
idna==2.7
importlib-metadata==1.3.0
itsdangerous==1.1.0
Jinja2==2.10
jmespath==0.9.3
jsonpickle==1.0
jsonschema==2.6.0
kombu==4.6.7
MarkupSafe==1.0
mistune==0.8.4
more-itertools==8.0.2
mysqlclient==1.3.13
psutil==5.4.8
pyasn1==0.4.4
pycurl==7.43.0.1
python-dateutil==2.7.5
pytz==2018.7
PyYAML==3.13
pyzmq==16.0.4
redis==2.10.6
requests==2.19.1
requests-aws4auth==0.9
rsa==3.4.2
s3transfer==0.2.1
six==1.11.0
SQLAlchemy==1.2.14
tornado==4.5.3
urllib3==1.22
vine==1.3.0
voluptuous==0.11.7
Werkzeug==0.14.1
zipp==0.6.0

Other Dependencies

N/A

Minimally Reproducible Test Case

Obtained this issue once in production

Expected Behavior

Task should be processed by other available consumers

Actual Behavior

Context

We have 3 machines in prod for celery workers and have a one-by-one deployment strategy. Hence, at any time, we have 2 workers available to pick up tasks

As mentioned above, the visibility timeout is kept 1 hr

We have one task which is triggered by 2 crons. One cron @ 5th, 35th and 50th minute of every hour. Another @ 20th minute. (The difference is in parameters passed to the task)

Issue

Around 9:20 PM, we had a deployment for the celery worker machines. The beat machine was deployed later.

A task, T1, was scheduled successfully. Verified by the "Sending due task" logs from beat machine

Ideally within a few seconds, the task is picked up by the worker machines, but no logs are found. I checked the logs of "Received task"

Around 10:20 PM, beat schedules another task (T2). Verified by the "Sending due task" logs from beat machine

This time, we see the "Received task" logs twice.

Verified that they are not the same task "instance" by comparing the task ids. This also rules out the possibility that SQS gave double delivery (at least once effort)

Hypothesis

The task, T1, was received by the master process in one machine. This triggered the visibility timer at SQS. The task was not yet passed to the worker threads. During sigterm, the task was not restored to SQS and thus, after the visibility timeout = 1 hr, the task got picked up and executed

Callouts

This issue has occurred once as per our knowledge (I discovered this while root causing another issue). Thus, unsure if this is happening already multiple times but not getting caught.

Unable to reproduce this on local / beta machines

Expectation from the community

Does the hypothesis imply the issue?

Any ideas on how to reproduce such a condition successfully?

What logs would be better to switch on at celery side so that we can catch this issue next time it happens. (We can't possibly move to debug level because the sheer volume is too high)