test_mwp9_running_job_dedup.py
python
sha256:de4600779cefea10176aeb9f4590ed488b3a0b40300d5389b311d226fde67ca8
fix: terminally fail stale jobs that already exhausted thei…
Sonnet 5
patch
14 hours ago
| 1 | """MWP-9 — fetch.mpack.prebuild dedup must cover 'running', not just 'pending'. |
| 2 | |
| 3 | Root cause (found live, while running a bulk commit-signature repair against |
| 4 | staging.musehub.ai, during the muse#108 wire-protocol investigation): |
| 5 | ``fetch.mpack.prebuild`` is explicitly self-coalescing by design -- |
| 6 | ``process_fetch_mpack_prebuild_job`` re-reads live branch tips at run time |
| 7 | rather than trusting its enqueue-time payload (see its own docstring). But |
| 8 | every enqueue site (the regular post-push path in ``enqueue_push_intel``, |
| 9 | and the repair path in ``wire_repair_commit`` -> ``_enqueue_repair_prebuild``) |
| 10 | only dedups against jobs with ``status == "pending"``. |
| 11 | |
| 12 | For a repo whose full rebuild takes longer than the gap between two triggers |
| 13 | (confirmed live: ~1624 commits / 162MB took 30-100+s to rebuild under load), |
| 14 | the first job transitions pending -> running, and every subsequent trigger |
| 15 | (another push, another repair-commit call) sees no "pending" row and happily |
| 16 | enqueues a brand new one -- even though the currently-running job will, |
| 17 | by its own self-coalescing design, already produce a mpack covering |
| 18 | whatever triggered the new enqueue. Each of those redundant jobs is a full, |
| 19 | independent rebuild. Under rapid repeated triggers (a bulk repair script |
| 20 | issuing 180+ calls in a few minutes, or just several pushes in quick |
| 21 | succession) this floods the single-worker queue and starves ordinary |
| 22 | clone/fetch requests past their 120s retry budget -- confirmed live: 3 of 5 |
| 23 | consecutive clone attempts hit 4x 503 retries and failed outright during a |
| 24 | repair batch run. |
| 25 | |
| 26 | Fix: for this specific, explicitly self-coalescing job type, dedup against |
| 27 | both 'pending' and 'running' at both enqueue sites. |
| 28 | """ |
| 29 | from __future__ import annotations |
| 30 | |
| 31 | import hashlib |
| 32 | from datetime import datetime, timedelta, timezone |
| 33 | |
| 34 | import pytest |
| 35 | from sqlalchemy import select |
| 36 | from sqlalchemy.ext.asyncio import AsyncSession |
| 37 | |
| 38 | from musehub.core.genesis import compute_job_id |
| 39 | from musehub.db.musehub_jobs_models import MusehubBackgroundJob |
| 40 | from musehub.services.musehub_jobs import ( |
| 41 | _MAX_ATTEMPTS, |
| 42 | enqueue_push_intel, |
| 43 | reclaim_stale_jobs, |
| 44 | ) |
| 45 | from musehub.services.musehub_wire_push import _enqueue_repair_prebuild |
| 46 | from tests.factories import create_branch, create_repo |
| 47 | |
| 48 | |
| 49 | def _fake_commit_id(seed: str) -> str: |
| 50 | return "sha256:" + hashlib.sha256(seed.encode()).hexdigest() |
| 51 | |
| 52 | |
| 53 | def _now() -> datetime: |
| 54 | return datetime.now(tz=timezone.utc) |
| 55 | |
| 56 | |
| 57 | async def _insert_prebuild_job(session: AsyncSession, repo_id: str, status: str) -> str: |
| 58 | now = _now() |
| 59 | job_id = compute_job_id(repo_id, "fetch.mpack.prebuild", now.isoformat() + status) |
| 60 | session.add(MusehubBackgroundJob( |
| 61 | job_id=job_id, |
| 62 | repo_id=repo_id, |
| 63 | job_type="fetch.mpack.prebuild", |
| 64 | payload={"tip_commit_ids": [_fake_commit_id("a")]}, |
| 65 | status=status, |
| 66 | created_at=now, |
| 67 | attempt=0, |
| 68 | )) |
| 69 | await session.commit() |
| 70 | return job_id |
| 71 | |
| 72 | |
| 73 | async def _count_prebuild_jobs(session: AsyncSession, repo_id: str) -> int: |
| 74 | rows = (await session.execute( |
| 75 | select(MusehubBackgroundJob.job_id).where( |
| 76 | MusehubBackgroundJob.repo_id == repo_id, |
| 77 | MusehubBackgroundJob.job_type == "fetch.mpack.prebuild", |
| 78 | ) |
| 79 | )).scalars().all() |
| 80 | return len(rows) |
| 81 | |
| 82 | |
| 83 | @pytest.mark.asyncio |
| 84 | async def test_mwp9_01_pending_prebuild_still_deduped_on_repair(db_session: AsyncSession) -> None: |
| 85 | """GREEN guard: existing 'pending' dedup must keep working unchanged.""" |
| 86 | repo = await create_repo(db_session) |
| 87 | await create_branch(db_session, repo.repo_id, name="main", head_commit_id=_fake_commit_id("tip")) |
| 88 | await _insert_prebuild_job(db_session, repo.repo_id, status="pending") |
| 89 | |
| 90 | await _enqueue_repair_prebuild(db_session, repo.repo_id) |
| 91 | await db_session.commit() |
| 92 | |
| 93 | assert await _count_prebuild_jobs(db_session, repo.repo_id) == 1 |
| 94 | |
| 95 | |
| 96 | @pytest.mark.asyncio |
| 97 | async def test_mwp9_02_running_prebuild_deduped_on_repair(db_session: AsyncSession) -> None: |
| 98 | """RED before the fix: a 'running' prebuild job is not covered by the |
| 99 | current dedup, so repair-commit enqueues a redundant second job.""" |
| 100 | repo = await create_repo(db_session) |
| 101 | await create_branch(db_session, repo.repo_id, name="main", head_commit_id=_fake_commit_id("tip")) |
| 102 | await _insert_prebuild_job(db_session, repo.repo_id, status="running") |
| 103 | |
| 104 | await _enqueue_repair_prebuild(db_session, repo.repo_id) |
| 105 | await db_session.commit() |
| 106 | |
| 107 | assert await _count_prebuild_jobs(db_session, repo.repo_id) == 1, ( |
| 108 | "repair-commit enqueued a redundant fetch.mpack.prebuild job while one " |
| 109 | "was already running — the exact flooding mechanism that caused live " |
| 110 | "clone failures during a bulk repair run" |
| 111 | ) |
| 112 | |
| 113 | |
| 114 | @pytest.mark.asyncio |
| 115 | async def test_mwp9_03_running_prebuild_deduped_on_regular_push(db_session: AsyncSession) -> None: |
| 116 | """RED before the fix: the regular post-push path has the identical gap -- |
| 117 | confirms this isn't a repair-script-only issue, it's the baseline |
| 118 | push-time behavior under any rapid repeated push load.""" |
| 119 | repo = await create_repo(db_session) |
| 120 | await create_branch(db_session, repo.repo_id, name="main", head_commit_id=_fake_commit_id("tip")) |
| 121 | await _insert_prebuild_job(db_session, repo.repo_id, status="running") |
| 122 | |
| 123 | await enqueue_push_intel( |
| 124 | db_session, repo.repo_id, head=_fake_commit_id("tip"), |
| 125 | domain_id="code", branch="main", |
| 126 | ) |
| 127 | await db_session.commit() |
| 128 | |
| 129 | assert await _count_prebuild_jobs(db_session, repo.repo_id) == 1, ( |
| 130 | "a regular push enqueued a redundant fetch.mpack.prebuild job while " |
| 131 | "one was already running" |
| 132 | ) |
| 133 | |
| 134 | |
| 135 | @pytest.mark.asyncio |
| 136 | async def test_mwp9_04_other_coarse_job_types_unaffected(db_session: AsyncSession) -> None: |
| 137 | """Scope guard: the fix must be narrow to fetch.mpack.prebuild. A |
| 138 | 'running' gc job (not self-coalescing by any documented design) must |
| 139 | still allow a fresh 'pending' gc job to be enqueued, exactly as before.""" |
| 140 | repo = await create_repo(db_session) |
| 141 | await create_branch(db_session, repo.repo_id, name="main", head_commit_id=_fake_commit_id("tip")) |
| 142 | now = _now() |
| 143 | db_session.add(MusehubBackgroundJob( |
| 144 | job_id=compute_job_id(repo.repo_id, "gc", now.isoformat()), |
| 145 | repo_id=repo.repo_id, job_type="gc", payload={}, |
| 146 | status="running", created_at=now, attempt=0, |
| 147 | )) |
| 148 | await db_session.commit() |
| 149 | |
| 150 | await enqueue_push_intel( |
| 151 | db_session, repo.repo_id, head=_fake_commit_id("tip"), |
| 152 | domain_id="code", branch="main", |
| 153 | ) |
| 154 | await db_session.commit() |
| 155 | |
| 156 | gc_rows = (await db_session.execute( |
| 157 | select(MusehubBackgroundJob.job_id).where( |
| 158 | MusehubBackgroundJob.repo_id == repo.repo_id, |
| 159 | MusehubBackgroundJob.job_type == "gc", |
| 160 | ) |
| 161 | )).scalars().all() |
| 162 | assert len(gc_rows) == 2, ( |
| 163 | "gc's dedup window must remain pending-only -- broadening it to " |
| 164 | "'running' for every coarse job type was explicitly out of scope" |
| 165 | ) |
| 166 | |
| 167 | |
| 168 | @pytest.mark.asyncio |
| 169 | async def test_mwp9_05_exhausted_stale_running_job_marked_failed_not_left_running( |
| 170 | db_session: AsyncSession, |
| 171 | ) -> None: |
| 172 | """RED before the fix (found live on staging, 2026-10-21): two |
| 173 | fetch.mpack.prebuild rows have sat at status='running', attempt=3 |
| 174 | (== _MAX_ATTEMPTS) since July and September -- a worker crash/restart |
| 175 | mid-job never called fail_job, and reclaim_stale_jobs explicitly |
| 176 | excludes attempt >= _MAX_ATTEMPTS from its reset-to-pending query, so |
| 177 | these rows are permanently stuck in 'running'. |
| 178 | |
| 179 | This was invisible before MWP9_02/03 because the old dedup only ever |
| 180 | looked at 'pending'. Once dedup also treats 'running' as coverage (the |
| 181 | whole point of this file), an exhausted zombie 'running' row permanently |
| 182 | blocks every future trigger for that job type on that repo -- staging's |
| 183 | clone has been wedged on exactly this since this fix went live. |
| 184 | |
| 185 | reclaim_stale_jobs must terminally fail exhausted stale jobs (not just |
| 186 | silently skip them) so they stop blocking dedup forever, while jobs |
| 187 | still under budget keep retrying via the existing reset-to-pending path. |
| 188 | """ |
| 189 | repo = await create_repo(db_session) |
| 190 | await create_branch(db_session, repo.repo_id, name="main", head_commit_id=_fake_commit_id("tip")) |
| 191 | |
| 192 | stale_claimed_at = _now() - timedelta(minutes=30) |
| 193 | job_id = compute_job_id(repo.repo_id, "fetch.mpack.prebuild", "zombie") |
| 194 | db_session.add(MusehubBackgroundJob( |
| 195 | job_id=job_id, |
| 196 | repo_id=repo.repo_id, |
| 197 | job_type="fetch.mpack.prebuild", |
| 198 | payload={"tip_commit_ids": [_fake_commit_id("a")]}, |
| 199 | status="running", |
| 200 | created_at=stale_claimed_at, |
| 201 | claimed_at=stale_claimed_at, |
| 202 | attempt=_MAX_ATTEMPTS, |
| 203 | )) |
| 204 | await db_session.commit() |
| 205 | |
| 206 | await reclaim_stale_jobs(db_session) |
| 207 | await db_session.commit() |
| 208 | |
| 209 | row = (await db_session.execute( |
| 210 | select(MusehubBackgroundJob).where(MusehubBackgroundJob.job_id == job_id) |
| 211 | )).scalar_one() |
| 212 | assert row.status == "failed", ( |
| 213 | "an exhausted stale job must be terminally failed, not left in " |
| 214 | "'running' forever -- a permanent zombie that blocks dedup for this " |
| 215 | "job type/repo indefinitely" |
| 216 | ) |
| 217 | |
| 218 | |
| 219 | @pytest.mark.asyncio |
| 220 | async def test_mwp9_06_stale_running_job_under_budget_still_resets_to_pending( |
| 221 | db_session: AsyncSession, |
| 222 | ) -> None: |
| 223 | """GREEN guard: the existing retry behavior for stale jobs that still |
| 224 | have attempts remaining must be unchanged by the exhausted-attempt fix.""" |
| 225 | repo = await create_repo(db_session) |
| 226 | await create_branch(db_session, repo.repo_id, name="main", head_commit_id=_fake_commit_id("tip")) |
| 227 | |
| 228 | stale_claimed_at = _now() - timedelta(minutes=30) |
| 229 | job_id = compute_job_id(repo.repo_id, "fetch.mpack.prebuild", "retryable") |
| 230 | db_session.add(MusehubBackgroundJob( |
| 231 | job_id=job_id, |
| 232 | repo_id=repo.repo_id, |
| 233 | job_type="fetch.mpack.prebuild", |
| 234 | payload={"tip_commit_ids": [_fake_commit_id("a")]}, |
| 235 | status="running", |
| 236 | created_at=stale_claimed_at, |
| 237 | claimed_at=stale_claimed_at, |
| 238 | attempt=_MAX_ATTEMPTS - 1, |
| 239 | )) |
| 240 | await db_session.commit() |
| 241 | |
| 242 | await reclaim_stale_jobs(db_session) |
| 243 | await db_session.commit() |
| 244 | |
| 245 | row = (await db_session.execute( |
| 246 | select(MusehubBackgroundJob).where(MusehubBackgroundJob.job_id == job_id) |
| 247 | )).scalar_one() |
| 248 | assert row.status == "pending" |
File History
1 commit
sha256:de4600779cefea10176aeb9f4590ed488b3a0b40300d5389b311d226fde67ca8
fix: terminally fail stale jobs that already exhausted thei…
Sonnet 5
patch
14 hours ago