Skip to content

Commit 36b17c4

Browse files
mihowclaude
andcommitted
fix(jobs): reaper checks Redis directly via all_tasks_processed
Job 2521 ended REVOKED despite NATS+Redis both confirming all 4510 tasks processed. Root cause: `_update_job_progress` writes the entire `Job.progress` JSONB blob without a row lock since #1261 dropped `select_for_update`. Concurrent workers raced; a slower committer clobbered the faster committer's SUCCESS write, leaving progress at `processed=4509 remaining=1 STARTED`. The reaper read the clobbered `progress.is_complete()` -> False -> REVOKE. Add `AsyncJobStateManager.all_tasks_processed() -> bool | None` (tri-state) backed directly by Redis SCARD across both pending sets, and inline it at the reaper guard in `check_stale_jobs`. Sync_api jobs unchanged (dispatch_mode gate). When Redis state is absent (cleanup, expiry, never initialized, or transient RedisError), fall back to `progress.is_complete()` and emit a WARNING so monitoring can flag the fallback path. Other 5 `progress.is_complete()` callers stay as-is — only the reaper guard is bitten by the clobber. Atomic-write follow-up tracked separately. Co-Authored-By: Claude <noreply@anthropic.com>
1 parent c828d9e commit 36b17c4

4 files changed

Lines changed: 300 additions & 7 deletions

File tree

ami/jobs/tasks.py

Lines changed: 21 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -909,9 +909,10 @@ def check_stale_jobs(minutes: int | None = None, dry_run: bool = False) -> list[
909909
910910
For each stale job, checks Celery for a terminal task status. REVOKED is
911911
always trusted. For async_api jobs, SUCCESS and FAILURE are only accepted
912-
when job.progress.is_complete() — NATS workers may still be delivering
913-
results after the Celery task finishes. All other cases result in revocation.
914-
Async resources (NATS/Redis) are cleaned up in both branches.
912+
when AsyncJobStateManager.all_tasks_processed() reports True (i.e. the
913+
Redis pending sets are drained). When Redis state is absent, falls back to
914+
job.progress.is_complete(). All other cases result in revocation. Async
915+
resources (NATS/Redis) are cleaned up in both branches.
915916
916917
Returns a list of dicts describing what was done to each job.
917918
"""
@@ -961,12 +962,25 @@ def check_stale_jobs(minutes: int | None = None, dry_run: bool = False) -> list[
961962
# Treat as unknown state — job will be revoked below.
962963

963964
# Only trust terminal Celery states. For async_api jobs, SUCCESS and
964-
# FAILURE are only accepted when progress is complete — NATS workers may
965-
# still be delivering results after the Celery task finishes.
965+
# FAILURE are only accepted when all NATS tasks are processed — workers
966+
# may still be delivering results after the Celery task finishes.
967+
# Consult Redis (source of truth for SREM completeness) directly rather
968+
# than Job.progress.is_complete(), which mirrors a JSONB blob racy under
969+
# concurrent _update_job_progress writes since #1261.
966970
is_terminal = celery_state in states.READY_STATES
967971
is_async_api = job.dispatch_mode == JobDispatchMode.ASYNC_API
968-
if is_async_api and celery_state in {states.SUCCESS, states.FAILURE} and not job.progress.is_complete():
969-
is_terminal = False
972+
if is_async_api and celery_state in {states.SUCCESS, states.FAILURE}:
973+
processed = AsyncJobStateManager(job.pk).all_tasks_processed()
974+
if processed is False:
975+
is_terminal = False
976+
elif processed is None:
977+
logger.warning(
978+
"Reaper for job %s: Redis state absent, falling back to " "progress.is_complete()",
979+
job.pk,
980+
)
981+
if not job.progress.is_complete():
982+
is_terminal = False
983+
# processed is True -> trust Celery's terminal state
970984

971985
previous_status = job.status
972986
if is_terminal:

ami/jobs/tests/test_tasks.py

Lines changed: 195 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1229,3 +1229,198 @@ def test_jobs_health_check_runs_lost_images_before_stale_jobs(self, mock_manager
12291229

12301230
job.refresh_from_db()
12311231
self.assertEqual(job.status, JobState.SUCCESS.value)
1232+
1233+
1234+
class TestCheckStaleJobsReaperGuard(TransactionTestCase):
1235+
"""Reaper guard for async_api jobs: SUCCESS/FAILURE Celery state is only
1236+
accepted when AsyncJobStateManager.all_tasks_processed() reports True. The
1237+
earlier guard read Job.progress.is_complete() — racy under concurrent
1238+
_update_job_progress writes since #1261 dropped select_for_update. Job 2521
1239+
landed REVOKED with NATS+Redis fully drained because a slower committer
1240+
clobbered the SUCCESS write. This class verifies the new Redis-direct path,
1241+
the absent-state fallback to progress.is_complete() with a WARNING, and
1242+
that sync_api jobs are unaffected.
1243+
"""
1244+
1245+
def setUp(self):
1246+
cache.clear()
1247+
self.project = Project.objects.create(name="Reaper Guard Project")
1248+
self.pipeline = Pipeline.objects.create(name="Reaper Pipeline", slug="reaper-pipeline")
1249+
self.pipeline.projects.add(self.project)
1250+
self.collection = SourceImageCollection.objects.create(name="Reaper Coll", project=self.project)
1251+
1252+
def tearDown(self):
1253+
cache.clear()
1254+
1255+
def _stale_async_job(self, *, task_id: str = "reaper-task") -> Job:
1256+
job = Job.objects.create(
1257+
job_type_key=MLJob.key,
1258+
project=self.project,
1259+
name="reaper async job",
1260+
pipeline=self.pipeline,
1261+
source_image_collection=self.collection,
1262+
dispatch_mode=JobDispatchMode.ASYNC_API,
1263+
)
1264+
job.task_id = task_id
1265+
job.update_status(JobState.STARTED, save=True)
1266+
return job
1267+
1268+
def _mark_stale(self, job: Job) -> None:
1269+
"""Push updated_at back past STALLED_JOBS_MAX_MINUTES via raw update so
1270+
Job.save() side-effects (auto_now) don't undo it. Call AFTER any helper
1271+
that touches the job model."""
1272+
Job.objects.filter(pk=job.pk).update(
1273+
updated_at=datetime.datetime.now() - datetime.timedelta(minutes=Job.STALLED_JOBS_MAX_MINUTES + 1)
1274+
)
1275+
job.refresh_from_db()
1276+
1277+
def _set_progress_clobbered(self, job: Job, total: int, processed: int) -> None:
1278+
"""Mimic the 2521 Job.progress shape: process stage at processed/total
1279+
with status STARTED, even though Redis was actually fully drained."""
1280+
progress = job.progress
1281+
collect = progress.get_stage("collect")
1282+
collect.progress = 1.0
1283+
collect.status = JobState.SUCCESS
1284+
progress.update_stage(
1285+
"process",
1286+
progress=processed / total,
1287+
status=JobState.STARTED,
1288+
processed=processed,
1289+
remaining=total - processed,
1290+
failed=0,
1291+
)
1292+
progress.update_stage(
1293+
"results",
1294+
progress=processed / total,
1295+
status=JobState.STARTED,
1296+
captures=processed,
1297+
)
1298+
job.save()
1299+
1300+
def _set_progress_complete(self, job: Job) -> None:
1301+
progress = job.progress
1302+
for key in ("collect", "process", "results"):
1303+
stage = progress.get_stage(key)
1304+
stage.progress = 1.0
1305+
stage.status = JobState.SUCCESS
1306+
job.save()
1307+
1308+
@patch("celery.result.AsyncResult")
1309+
def test_async_celery_success_redis_empty_progress_clobbered_lands_success(self, mock_async_result):
1310+
"""The 2521 case. Pre-fix, this came back REVOKED because the reaper
1311+
consulted progress.is_complete() (False, due to clobber). Post-fix,
1312+
Redis says all_tasks_processed() → True, so SUCCESS is honored."""
1313+
from ami.jobs.tasks import check_stale_jobs
1314+
1315+
job = self._stale_async_job()
1316+
ids = [str(i) for i in range(10)]
1317+
manager = AsyncJobStateManager(job.pk)
1318+
manager.initialize_job(ids)
1319+
manager.update_state(set(ids), stage="process")
1320+
manager.update_state(set(ids), stage="results")
1321+
# Clobber: progress shows mid-flight even though Redis is drained.
1322+
self._set_progress_clobbered(job, total=10, processed=9)
1323+
self._mark_stale(job)
1324+
1325+
from celery import states as celery_states
1326+
1327+
mock_async_result.return_value.state = celery_states.SUCCESS
1328+
1329+
check_stale_jobs()
1330+
1331+
job.refresh_from_db()
1332+
self.assertEqual(
1333+
job.status,
1334+
JobState.SUCCESS.value,
1335+
f"clobbered progress should not block SUCCESS when Redis says drained; got {job.status}",
1336+
)
1337+
1338+
@patch("celery.result.AsyncResult")
1339+
def test_async_celery_success_redis_pending_lands_revoked(self, mock_async_result):
1340+
"""Redis still has pending ids → genuine in-flight; reaper revokes."""
1341+
from ami.jobs.tasks import check_stale_jobs
1342+
1343+
job = self._stale_async_job()
1344+
ids = [str(i) for i in range(10)]
1345+
AsyncJobStateManager(job.pk).initialize_job(ids)
1346+
# No SREMs — pending sets still full.
1347+
self._mark_stale(job)
1348+
1349+
from celery import states as celery_states
1350+
1351+
mock_async_result.return_value.state = celery_states.SUCCESS
1352+
1353+
check_stale_jobs()
1354+
1355+
job.refresh_from_db()
1356+
self.assertEqual(job.status, JobState.REVOKED.value)
1357+
1358+
@patch("celery.result.AsyncResult")
1359+
def test_async_celery_success_redis_absent_progress_complete_lands_success(self, mock_async_result):
1360+
"""Redis state is gone (cleaned up / never initialized). Reaper falls
1361+
back to progress.is_complete(). Complete progress → SUCCESS + WARNING."""
1362+
from ami.jobs.tasks import check_stale_jobs
1363+
1364+
job = self._stale_async_job()
1365+
# Don't initialize Redis state.
1366+
self._set_progress_complete(job)
1367+
self._mark_stale(job)
1368+
1369+
from celery import states as celery_states
1370+
1371+
mock_async_result.return_value.state = celery_states.SUCCESS
1372+
1373+
with self.assertLogs("ami.jobs.tasks", level="WARNING") as cm:
1374+
check_stale_jobs()
1375+
1376+
job.refresh_from_db()
1377+
self.assertEqual(job.status, JobState.SUCCESS.value)
1378+
self.assertTrue(any("Redis state absent" in m for m in cm.output))
1379+
1380+
@patch("celery.result.AsyncResult")
1381+
def test_async_celery_success_redis_absent_progress_incomplete_lands_revoked(self, mock_async_result):
1382+
"""Redis absent + progress incomplete → REVOKED via fallback + WARNING."""
1383+
from ami.jobs.tasks import check_stale_jobs
1384+
1385+
job = self._stale_async_job()
1386+
# Don't initialize Redis. Default progress is fresh (not complete).
1387+
self._mark_stale(job)
1388+
1389+
from celery import states as celery_states
1390+
1391+
mock_async_result.return_value.state = celery_states.SUCCESS
1392+
1393+
with self.assertLogs("ami.jobs.tasks", level="WARNING") as cm:
1394+
check_stale_jobs()
1395+
1396+
job.refresh_from_db()
1397+
self.assertEqual(job.status, JobState.REVOKED.value)
1398+
self.assertTrue(any("Redis state absent" in m for m in cm.output))
1399+
1400+
@patch("celery.result.AsyncResult")
1401+
def test_sync_api_celery_success_lands_success_without_redis_check(self, mock_async_result):
1402+
"""sync_api jobs skip the Redis guard entirely — Celery's terminal
1403+
state is authoritative. No Redis state initialized; if the new path
1404+
leaked into sync_api this would REVOKE."""
1405+
from ami.jobs.tasks import check_stale_jobs
1406+
1407+
job = Job.objects.create(
1408+
job_type_key=MLJob.key,
1409+
project=self.project,
1410+
name="reaper sync job",
1411+
pipeline=self.pipeline,
1412+
source_image_collection=self.collection,
1413+
dispatch_mode=JobDispatchMode.SYNC_API,
1414+
)
1415+
job.task_id = "reaper-sync-task"
1416+
job.update_status(JobState.STARTED, save=True)
1417+
self._mark_stale(job)
1418+
1419+
from celery import states as celery_states
1420+
1421+
mock_async_result.return_value.state = celery_states.SUCCESS
1422+
1423+
check_stale_jobs()
1424+
1425+
job.refresh_from_db()
1426+
self.assertEqual(job.status, JobState.SUCCESS.value)

ami/ml/orchestration/async_job_state.py

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -228,6 +228,36 @@ def get_pending_image_ids(self) -> set[str]:
228228
return set()
229229
return {m.decode() if isinstance(m, (bytes, bytearray)) else str(m) for m in members}
230230

231+
def all_tasks_processed(self) -> bool | None:
232+
"""Tri-state truth signal for NATS-task SREM completeness across both
233+
process and results pending sets.
234+
235+
True — both pending sets empty AND total > 0 (or total == 0)
236+
False — at least one pending set has members
237+
None — Redis state absent (cleaned up, expired, never initialized,
238+
or transient RedisError)
239+
240+
Scope: tracks NATS task lifecycle only; does not know about `collect`
241+
or any future post-results stages.
242+
"""
243+
try:
244+
redis = self._get_redis()
245+
with redis.pipeline() as pipe:
246+
for stage in self.STAGES:
247+
pipe.scard(self._get_pending_key(stage))
248+
pipe.get(self._total_key)
249+
results = pipe.execute()
250+
except RedisError as e:
251+
logger.warning(f"Redis error reading all_tasks_processed for job {self.job_id}: {e}")
252+
return None
253+
254+
*pending_counts, total_raw = results
255+
if total_raw is None:
256+
return None
257+
if int(total_raw) == 0:
258+
return True
259+
return all(count == 0 for count in pending_counts)
260+
231261
def cleanup(self) -> None:
232262
"""
233263
Delete all Redis keys associated with this job.

ami/ml/tests.py

Lines changed: 54 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1407,6 +1407,60 @@ def test_update_state_returns_none_when_state_genuinely_missing(self):
14071407
progress = self.manager.update_state({"img1", "img2"}, "process")
14081408
self.assertIsNone(progress)
14091409

1410+
def test_all_tasks_processed_fresh_init_returns_false(self):
1411+
"""Just-initialized job has all images pending in both stages."""
1412+
self._init_and_verify(self.image_ids)
1413+
self.assertFalse(self.manager.all_tasks_processed())
1414+
1415+
def test_all_tasks_processed_after_drain_returns_true(self):
1416+
"""SREM-ing every id from both stages → True."""
1417+
self._init_and_verify(self.image_ids)
1418+
self.manager.update_state(set(self.image_ids), "process")
1419+
self.manager.update_state(set(self.image_ids), "results")
1420+
self.assertTrue(self.manager.all_tasks_processed())
1421+
1422+
def test_all_tasks_processed_partial_stage_returns_false(self):
1423+
"""Process drained but results still pending → False."""
1424+
self._init_and_verify(self.image_ids)
1425+
self.manager.update_state(set(self.image_ids), "process")
1426+
# results stage untouched
1427+
self.assertFalse(self.manager.all_tasks_processed())
1428+
1429+
def test_all_tasks_processed_zero_total_returns_true(self):
1430+
"""A zero-images job is trivially complete."""
1431+
self.manager.initialize_job([])
1432+
self.assertTrue(self.manager.all_tasks_processed())
1433+
1434+
def test_all_tasks_processed_never_initialized_returns_none(self):
1435+
"""No init → total key absent → None (caller falls back)."""
1436+
# Do NOT call initialize_job
1437+
self.assertIsNone(self.manager.all_tasks_processed())
1438+
1439+
def test_all_tasks_processed_after_cleanup_returns_none(self):
1440+
"""After cleanup() the total key is gone → None."""
1441+
self._init_and_verify(self.image_ids)
1442+
self.manager.cleanup()
1443+
self.assertIsNone(self.manager.all_tasks_processed())
1444+
1445+
def test_all_tasks_processed_returns_none_on_redis_error(self):
1446+
"""Transient RedisError → WARNING + None (caller falls back)."""
1447+
from unittest.mock import MagicMock, patch
1448+
1449+
from redis.exceptions import RedisError
1450+
1451+
self._init_and_verify(self.image_ids)
1452+
1453+
pipe = MagicMock()
1454+
pipe.execute.side_effect = RedisError("Connection reset by peer")
1455+
fake_redis = MagicMock()
1456+
fake_redis.pipeline.return_value.__enter__.return_value = pipe
1457+
1458+
with patch.object(self.manager, "_get_redis", return_value=fake_redis):
1459+
with self.assertLogs("ami.ml.orchestration.async_job_state", level="WARNING") as cm:
1460+
result = self.manager.all_tasks_processed()
1461+
self.assertIsNone(result)
1462+
self.assertTrue(any("Redis error reading all_tasks_processed" in m for m in cm.output))
1463+
14101464

14111465
class TestSaveResultsRefreshesDeploymentCounts(TestCase):
14121466
"""save_results must refresh Deployment cached counts, not just Event counts.

0 commit comments

Comments
 (0)