chord of chains with groups: body duplication and invalid task execution order #5947
Description
Checklist
- I have verified that the issue exists against the
masterbranch 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 reportin 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
masterbranch of Celery. - I have included the contents of
pip freezein 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
- None
Possible Duplicates
- None
Environment & Settings
Celery version: 4.4.0
celery report Output:
software -> celery:4.4.0 (cliffs) kombu:4.6.7 py:3.7.3
billiard:3.6.1.0 py-amqp:2.5.2
platform -> system:Linux arch:64bit, ELF
kernel version:5.0.0-37-generic imp:CPython
loader -> celery.loaders.app.AppLoader
settings -> transport:amqp results:redis://redis/
CELERY_BROKER_URL: 'amqp://guest:********@rabbit:5672//'
CELERY_RESULT_BACKEND: 'redis://redis/'
CELERY_TASK_SERIALIZER: 'json'
is_overridden: <bound method Settings.is_overridden of <Settings "app.settings">>
beat_schedule: {}
task_routes: {
'app.tasks.*': {'queue': 'main'}}
Steps to Reproduce
- Start celery worker with
--concurrency 8and-O fairusing code from test case below - Call a broken task via
celery -A app.celery_app call app.tasks.bug.task - Call a correct task via
celery -A app.celery_app call app.tasks.bug.task_correct
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:
aiohttp==3.6.2
amqp==2.5.2
asgiref==3.2.3
async-timeout==3.0.1
attrs==19.3.0
billiard==3.6.1.0
celery==4.4.0
certifi==2019.9.11
chardet==3.0.4
curlify==2.2.1
decorator==4.4.1
defusedxml==0.6.0
Django==3.0.2
django-braces==1.13.0
django-cors-headers==3.1.1
django-filter==2.2.0
django-oauth-toolkit==1.2.0
django-rest-framework-social-oauth2==1.1.0
django-templated-mail==1.1.1
djangorestframework==3.11.0
djoser==2.0.3
drf-nested-routers==0.91
facebook-business==5.0.0
ffmpeg-python==0.2.0
future==0.18.1
idna==2.8
ImageHash==4.0
imageio==2.6.1
imageio-ffmpeg==0.3.0
importlib-metadata==1.3.0
kombu==4.6.7
more-itertools==8.0.2
moviepy==1.0.1
multidict==4.5.2
numpy==1.17.4
oauthlib==3.1.0
Pillow==6.2.0
proglog==0.1.9
psycopg2-binary==2.8.3
PyJWT==1.7.1
pymongo==3.9.0
pyslack==0.5.0
python3-openid==3.1.0
pytz==2019.2
PyWavelets==1.1.1
redis==3.3.8
requests==2.22.0
requests-oauthlib==1.2.0
rest-social-auth==3.0.0
scipy==1.3.2
sentry-sdk==0.13.5
six==1.12.0
slackclient==2.3.0
social-auth-app-django==3.1.0
social-auth-core==3.2.0
sqlparse==0.3.0
tqdm==4.39.0
urllib3==1.25.6
vine==1.3.0
yarl==1.3.0
zipp==0.6.0
Other Dependencies
Details
N/A
Minimally Reproducible Test Case
Details
from time import sleep
from celery import chord, group
from app.celery_app import app
@app.task
def task():
chord([
a.s(1) | group([b.si(), b.si()]),
a.s(3) | group([b.si(), b.si()]),
])(c.si())
@app.task
def task_correct():
chord([
a.s(1) | group([b.si(), b.si()]) | dummy.si(),
a.s(3) | group([b.si(), b.si()]) | dummy.si(),
])(c.si())
@app.task
def dummy():
pass
@app.task
def a(delay):
sleep(delay)
@app.task
def b():
pass
@app.task
def c():
passExpected Behavior
I expect the tasks to complete in the following order:
A B B A B B C
Actual Behavior
Task C gets duplicated:
[2020-01-31 13:48:40,765: INFO/MainProcess] Received task: app.tasks.bug.task[9d35ec5f-a268-4db9-9068-1e27fe64cef9]
[2020-01-31 13:48:40,817: INFO/MainProcess] Received task: app.tasks.bug.a[b2833570-bca5-4875-ab6d-e3ec339f36d1]
[2020-01-31 13:48:40,824: INFO/MainProcess] Received task: app.tasks.bug.a[3d49f0d7-6b1a-4937-ac1c-29bac230e533]
[2020-01-31 13:48:40,828: INFO/ForkPoolWorker-8] Task app.tasks.bug.task[9d35ec5f-a268-4db9-9068-1e27fe64cef9] succeeded in 0.06039188499562442s: None
[2020-01-31 13:48:41,864: INFO/MainProcess] Received task: app.tasks.bug.b[796bcd9f-f548-4282-9f6d-16ddb3ddc29b]
[2020-01-31 13:48:41,867: INFO/ForkPoolWorker-8] Task app.tasks.bug.b[796bcd9f-f548-4282-9f6d-16ddb3ddc29b] succeeded in 0.001961939036846161s: None
[2020-01-31 13:48:41,869: INFO/MainProcess] Received task: app.tasks.bug.b[eacaa3ce-cc71-4daf-8e62-8d24f9322c7b]
[2020-01-31 13:48:41,871: INFO/ForkPoolWorker-9] Task app.tasks.bug.a[b2833570-bca5-4875-ab6d-e3ec339f36d1] succeeded in 1.0521306470036507s: None
[2020-01-31 13:48:41,884: INFO/ForkPoolWorker-8] Task app.tasks.bug.b[eacaa3ce-cc71-4daf-8e62-8d24f9322c7b] succeeded in 0.013368424959480762s: None
[2020-01-31 13:48:41,884: INFO/MainProcess] Received task: app.tasks.bug.c[8e50636b-a440-454e-a6fe-57bb7595b82f]
[2020-01-31 13:48:41,886: INFO/ForkPoolWorker-8] Task app.tasks.bug.c[8e50636b-a440-454e-a6fe-57bb7595b82f] succeeded in 0.0010153759503737092s: None
[2020-01-31 13:48:43,880: INFO/MainProcess] Received task: app.tasks.bug.b[07eb9c18-1303-4517-b95b-d555de1d6315]
[2020-01-31 13:48:43,884: INFO/ForkPoolWorker-8] Task app.tasks.bug.b[07eb9c18-1303-4517-b95b-d555de1d6315] succeeded in 0.0018030810169875622s: None
[2020-01-31 13:48:43,887: INFO/MainProcess] Received task: app.tasks.bug.b[7ebaf58a-28f5-4170-86fb-61c3b5ee1909]
[2020-01-31 13:48:43,887: INFO/ForkPoolWorker-2] Task app.tasks.bug.a[3d49f0d7-6b1a-4937-ac1c-29bac230e533] succeeded in 3.0580567660508677s: None
[2020-01-31 13:48:43,892: INFO/ForkPoolWorker-8] Task app.tasks.bug.b[7ebaf58a-28f5-4170-86fb-61c3b5ee1909] succeeded in 0.004260396934114397s: None
[2020-01-31 13:48:43,893: INFO/MainProcess] Received task: app.tasks.bug.c[8e50636b-a440-454e-a6fe-57bb7595b82f]
[2020-01-31 13:48:43,896: INFO/ForkPoolWorker-8] Task app.tasks.bug.c[8e50636b-a440-454e-a6fe-57bb7595b82f] succeeded in 0.000999139971099794s: None
Actual execution order is weird, and task C is executed twice.
But when you add a dummy task to the end of each chain, execution order becomes correct (as seen in task_correct task):
[2020-01-31 15:13:00,867: INFO/MainProcess] Received task: app.tasks.bug.task_correct[d9dd4fb3-8df9-4c39-8b3d-e8892f9d6fef]
[2020-01-31 15:13:00,928: INFO/MainProcess] Received task: app.tasks.bug.a[e7eb341f-3c10-4bb0-9dee-2cfa38354005]
[2020-01-31 15:13:00,939: INFO/MainProcess] Received task: app.tasks.bug.a[c13967b3-b53a-4005-9249-dffa4b6122af]
[2020-01-31 15:13:00,941: INFO/ForkPoolWorker-8] Task app.tasks.bug.task_correct[d9dd4fb3-8df9-4c39-8b3d-e8892f9d6fef] succeeded in 0.07147384795825928s: None
[2020-01-31 15:13:01,974: INFO/MainProcess] Received task: app.tasks.bug.b[88ceb430-5056-40a1-ae82-cfd95d27845e]
[2020-01-31 15:13:01,977: INFO/MainProcess] Received task: app.tasks.bug.b[3a354338-edb7-447b-9d40-855e9e386531]
[2020-01-31 15:13:01,977: INFO/ForkPoolWorker-9] Task app.tasks.bug.a[e7eb341f-3c10-4bb0-9dee-2cfa38354005] succeeded in 1.0470000900095329s: None
[2020-01-31 15:13:01,978: INFO/ForkPoolWorker-8] Task app.tasks.bug.b[88ceb430-5056-40a1-ae82-cfd95d27845e] succeeded in 0.0024882910074666142s: None
[2020-01-31 15:13:02,008: INFO/MainProcess] Received task: app.tasks.bug.dummy[2b9094d8-fe73-43b3-9a2a-c5ad756b3e22]
[2020-01-31 15:13:02,009: INFO/ForkPoolWorker-3] Task app.tasks.bug.b[3a354338-edb7-447b-9d40-855e9e386531] succeeded in 0.02914690098259598s: None
[2020-01-31 15:13:02,013: INFO/ForkPoolWorker-8] Task app.tasks.bug.dummy[2b9094d8-fe73-43b3-9a2a-c5ad756b3e22] succeeded in 0.002397596021182835s: None
[2020-01-31 15:13:03,989: INFO/MainProcess] Received task: app.tasks.bug.b[fafd28c6-55d0-41c5-a035-1d4da0d6067b]
[2020-01-31 15:13:03,992: INFO/MainProcess] Received task: app.tasks.bug.b[ea8c9c21-f860-4268-b44c-6faa8ba66dc2]
[2020-01-31 15:13:03,993: INFO/ForkPoolWorker-8] Task app.tasks.bug.b[fafd28c6-55d0-41c5-a035-1d4da0d6067b] succeeded in 0.0024769710144028068s: None
[2020-01-31 15:13:03,994: INFO/ForkPoolWorker-2] Task app.tasks.bug.a[c13967b3-b53a-4005-9249-dffa4b6122af] succeeded in 3.050520417978987s: None
[2020-01-31 15:13:04,001: INFO/ForkPoolWorker-9] Task app.tasks.bug.b[ea8c9c21-f860-4268-b44c-6faa8ba66dc2] succeeded in 0.006369335926137865s: None
[2020-01-31 15:13:04,001: INFO/MainProcess] Received task: app.tasks.bug.dummy[998aa572-9010-4991-856a-191cf1741680]
[2020-01-31 15:13:04,021: INFO/MainProcess] Received task: app.tasks.bug.c[976f5323-1505-41c6-ad01-e0e720c4b5c7]
[2020-01-31 15:13:04,021: INFO/ForkPoolWorker-8] Task app.tasks.bug.dummy[998aa572-9010-4991-856a-191cf1741680] succeeded in 0.018995660939253867s: None
[2020-01-31 15:13:04,023: INFO/ForkPoolWorker-9] Task app.tasks.bug.c[976f5323-1505-41c6-ad01-e0e720c4b5c7] succeeded in 0.0012671550503000617s: None