Repository navigation
A pool child lost after a task's link is published, before its result is stored, fires the error callback beside the link #10952
Replies: 3 comments 1 reply
Reproduced with a real
|
| Pool child killed at | Setting | State | Messages sent | Callbacks |
|---|---|---|---|---|
mark_as_done (link already published) |
default | FAILURE | 1 | failed: WorkerLostError and sent |
mark_as_done |
task_reject_on_worker_lost=True |
SUCCESS | 2 | sent twice |
task_postrun (SUCCESS stored) |
default | SUCCESS | 1 | sent: #10752 holds |
task_postrun |
task_reject_on_worker_lost=True |
SUCCESS | 1 | sent: #10752 holds |
Celery main (e3cc7cc), Python 3.13, Redis 7.4.11. Run: python probe_sigkill.py mark_as_done (REJECT=1 for the second row, task_postrun for the last two).
probe_sigkill.py
"""
Probe 1: a real external SIGKILL of the pool child, at mark_as_done (#10949) or task_postrun (#10724).
The pool child pauses at the stage (first time only) and writes its pid; the driver kills it with
SIGKILL from outside, as the OOM killer would. Usage: python probe_sigkill.py mark_as_done|task_postrun
REJECT=1 sets task_reject_on_worker_lost=True. REDIS defaults to redis://localhost:6379.
"""
import os
import signal
import subprocess
import sys
import time
import redis
from celery import Celery, signals
from celery.result import AsyncResult
REDIS = os.environ.get('REDIS', 'redis://localhost:6379')
RECORDS = redis.Redis.from_url(f'{REDIS}/12', decode_responses=True)
PIDFILE = '/tmp/celery-probe-child.pid'
app = Celery('probe', broker=f'{REDIS}/10', backend=f'{REDIS}/11')
app.conf.update(
task_acks_late=True,
worker_prefetch_multiplier=1,
task_reject_on_worker_lost=os.environ.get('REJECT') == '1',
)
@app.task
def send_message(message):
RECORDS.rpush('sent', message)
return message
@app.task
def announce(result):
RECORDS.rpush('announced', f'sent {result!r}')
@app.task
def report_failure(request, exc, traceback):
RECORDS.rpush('announced', f'failed: {type(exc).__name__}: {exc}')
def pause_here():
if RECORDS.set('paused', 1, nx=True):
with open(PIDFILE, 'w') as f:
f.write(str(os.getpid()))
time.sleep(30) # the driver kills us long before this ends
def install(stage):
if stage == 'mark_as_done':
backend = type(app.backend)
store = backend.mark_as_done
def mark_as_done(self, task_id, result, request=None, *args, **kwargs):
if getattr(request, 'task', None) == send_message.name:
pause_here() # the link was already published, just above mark_as_done in trace.py
return store(self, task_id, result, request, *args, **kwargs)
backend.mark_as_done = mark_as_done
elif stage == 'task_postrun':
def postrun(sender=None, **_):
if getattr(sender, 'name', None) == send_message.name:
pause_here() # SUCCESS is stored
signals.task_postrun.connect(postrun, weak=False)
else:
raise SystemExit(f'unknown stage {stage}')
def worker(stage=None):
args = [sys.executable, __file__, 'worker'] + ([stage] if stage else [])
return subprocess.Popen(args)
def wait(task_id, timeout=40):
deadline = time.monotonic() + timeout
while not AsyncResult(task_id, app=app).ready() and time.monotonic() < deadline:
time.sleep(0.2)
time.sleep(2)
def stop(process):
process.terminate()
process.wait(30)
if __name__ == '__main__' and sys.argv[1] == 'worker':
if len(sys.argv) > 2:
install(sys.argv[2])
app.worker_main(['worker', '--pool=prefork', '--concurrency=1', '--loglevel=WARNING',
'--without-mingle', '--without-gossip', '--without-heartbeat'])
elif __name__ == '__main__':
stage = sys.argv[1]
for db in (10, 11):
redis.Redis.from_url(f'{REDIS}/{db}').flushdb()
RECORDS.flushdb()
if os.path.exists(PIDFILE):
os.remove(PIDFILE)
first = worker(stage)
task_id = send_message.apply_async(
('your order has shipped',), link=announce.s(), link_error=report_failure.s()
).id
deadline = time.monotonic() + 40
while not os.path.exists(PIDFILE) and time.monotonic() < deadline:
time.sleep(0.1)
time.sleep(0.3)
pid = int(open(PIDFILE).read())
print(f'state before kill: {AsyncResult(task_id, app=app).state}; killing pool child {pid} with SIGKILL')
os.kill(pid, signal.SIGKILL)
wait(task_id)
stop(first)
second = worker() # recovery: the worker starts again
time.sleep(5)
wait(task_id)
stop(second)
meta = AsyncResult(task_id, app=app)
print('state: ', meta.state, '| result:', repr(meta.result)[:120])
print('sent: ', RECORDS.lrange('sent', 0, -1))
print('announced:', sorted(RECORDS.lrange('announced', 0, -1)))Written with Claude Code, directed by Aviad Rozenhek (author of pytest-obligation); every result above came from running the scripts.
|
This is a fully AI generated code based project with not enough star and external user. so this need to be mature and community vetted first. |
|
The bugs stand without the tool. Each report below now has a reproduction that needs only Celery and Redis:
Each was also checked against the real failure, not only an injected one: an outside To demo the pytest-obligation integration, Its contract now runs on gigaverse-app/celery against this fork and, nightly, against Celery's current |
Uh oh!
There was an error while loading. Please reload this page.
Uh oh!
There was an error while loading. Please reload this page.
Note
How this was found, and an offer. This issue came from pytest-obligation, an open-source pytest plugin (Apache-2.0) for background work that must not be lost, run twice or recorded wrongly. You describe one task and how to see what it did. The plugin then generates the failure cases: on a real
celery workerit kills the pool child at each of Celery's stages, makes a hook raise, refuses a publish, restarts the worker, and compares every outcome with a normal run.In Celery it has produced #10724 (fixed by #10752 and #10759), #10725 and #10949. Each finding stays in the suite as a pinned outcome and a strict xfail, so a fix shows up as a change, and so does a regression. That already happened once: after
mainmerged the two #10724 fixes, the unchanged contract flagged exactly those two cases as changed. The harness also grows. Since the first version of #10726 it has added a chord history and two more guarantee families. Each new release runs the same contract against more ways to fail.We'd like Celery to adopt it. #10726 does that fully: the contract in
t/due_work, plus a CI job (Linux, one Redis service, about 3.5 minutes with install, and a test-only dependency). If you want it, a follow-up PR can add pytest-obligation's PR report, a single comment on each PR summarizing what the contract proved.Disclosure: the harness is written by Aviad Rozenhek (CTO, tapin.io), who directed this work. This report, the reproduction and the PR were written with Claude Code, and every result in them was produced by running the code.
Checklist
mainbranch of Celery.contribution guide
on reporting bugs.
for similar or identical bug reports.
for existing proposed fixes.
to find out if the bug was already fixed in the main branch.
in this issue (If there are none, check this box anyway).
Mandatory Debugging Information
celery -A proj reportin the issue.mainbranch of Celery.pip freezein the issue (the packages that matter; the environment also hasrequirements/test.txt).to reproduce this bug.
Optional Debugging Information
and/or implementation.
result backend.
broker and/or result backend.
ETA/Countdown & rate limits disabled.
and/or upgrading Celery and its dependencies.
Related Issues and Possible Duplicates
Related Issues
collectwithgroup#1936: why links are published before the result is stored (soresult.childrenis populated).Possible Duplicates
Environment & Settings
Celery version: 5.7.0rc1,
mainat e3cc7cccelery reportOutput:Steps to Reproduce
Required Dependencies
main, e3cc7cc)Python Packages
pip freezeOutput:Other Dependencies
Details
Redis 7.4.11 as broker and result backend.
Minimally Reproducible Test Case
One task,
send_message, with a link (announce) and an error callback (report_failure),task_acks_late=True,celery worker --pool=prefork --concurrency=1. The pool child exits withos._exit(1)when the tracer callsmark_as_done, which is after the link is published. Then the worker is started again. Needs Redis onlocalhost:6379; runpython repro.py, orREJECT=1 python repro.pyfortask_reject_on_worker_lost=True.repro.pyExpected Behavior
One execution reports one outcome. Either the link runs or the error callback runs, not both. The recorded state agrees with whichever callback ran. In a chord, a header whose body ran is not counted as a failure while its link went out as a success.
Actual Behavior
trace.pypublishes the task's links and chain, then stores the result. The order is deliberate (#1936). If the pool child is lost between the two, there is nothing stored. On an OOM kill, a SIGKILL, or a crash inmark_as_doneitself (serialising a large result, for example), the parent getsWorkerLostError.Request.on_failurefinds no stored SUCCESS, so #10752's check does not apply, and it records FAILURE.task_reject_on_worker_lost=True: the message is requeued and the task runs again. That much is the documented at-least-once trade. The rerun publishes the link again, so the link runs twice: once for the lost execution and once for the rerun.send_messageheaders, the first header's child lost at the same point): both messages are sent, the header is recorded FAILURE, and the chord fails withChordError. The body never runs.What it costs:
task_reject_on_worker_lost, the follow-up step runs twice, though only one execution's result is recorded.This came out of pytest-obligation (formerly due-work-harness), the harness in #10726. Its Celery worker integration fails one task at each of Celery's stages on a real worker, restarts the worker, and compares each outcome with a normal run. On today's
mainthe run showed #10752 and #10759 working, and this stage still diverging, for a single task and for a chord. #10726 pins it inFINDINGSandCHORD_FINDINGSas thedied at mark_as_donerow.All reactions