Skip to content

Commit a2f4d03

Browse files
SEP-1894: Reconcile a sync run abandoned with no items left active (#1454)
## Summary - A worker killed between its last `SyncItem` write and `BaseSyncer.__aexit__` leaves a `SyncInstance` stuck at `RUNNING` with zero `PENDING`/`RUNNING` items, and nothing reconciles it: the stale-run reclaim only ran once `create()` had already detected an item conflict, and its candidate query was keyed on non-terminal items — so an all-terminal run was invisible to both halves. The inventory sync-status endpoint kept reporting that run as running until ten later runs aged it out of the window. - `reclaim_stale_runs()` gains a second candidate class: a `RUNNING` run whose items have all gone terminal. It is still grouped over `SyncItem` rows, so a run that wrote no item at all — which carries no activity to measure — stays out of scope, and `NOT IN` against the existing in-progress subquery keeps the two candidate sets disjoint. `create()` now calls the reclaim whether or not an item conflict exists, and reads the conflicting items once, after the reclaim — reclaim → check on both paths. - The fence `UPDATE` re-asserts item staleness alongside the instance status. The candidate query commits separately from the fence, so a worker that resumed and either touched an existing item or opened a new one is progressing after all and must not be failed retroactively. `snapshot_complete` is deliberately left `NULL` on a reclaim, so a partially applied run is never counted as a complete generation. ### Review round (`81582d60b`) - **The pre-reclaim conflict read was dead on the reclaim path.** It was assigned before the reclaim and then unconditionally overwritten whenever `stale_after` was set, and `reclaim_stale_runs` consumes none of it, so on the primary path that `SELECT` fed no later statement. The read now happens once, below the reclaim block, which leaves both paths behaving identically and drops a round trip per run start. `test_create_refuses_a_run_that_resumed_during_the_reclaim` still fails if the read moves back above the reclaim. - **The fence's staleness re-assertion reused the candidate subquery bare**, so it compiled to a `GROUP BY` over the whole `syncitem` table with no syncer or candidate predicate. It now repeats the `in_(stale_instance_ids)` narrowing, which lands as a `WHERE` before the `GROUP BY` and makes the subquery index-seekable. The semantics are unchanged because every group is one instance's items, so removing other instances' rows cannot move a surviving group's `max()` — and the two spare-conditions (`test_reclaim_spares_a_run_whose_worker_touched_an_item`, `test_reclaim_spares_an_idle_run_that_started_a_new_item`) still fail when the predicate is dropped altogether. ### Risks - **A live long-running run can now be fenced.** A run that writes its top-level item terminal early and then keeps working has no heartbeat at all, so once its last item write is older than `stale_after` this path will reclaim it. Bounded by the documented contract on `stale_run_after` ("must exceed the longest expected runtime of a sync", shipped as 3600s), and it fails safe: `is_still_owned()` gates every retirement and `finalize_run()` is guarded on `status == RUNNING`, so a wrongly-fenced run stops retiring and leaves `snapshot_complete` `NULL` rather than advancing the missing-grace counter. Heartbeating `SyncInstance.updated_at` during a run would remove the exposure and is out of scope here. - **No new blocking mode.** The reclaim only ever moves a row from `PENDING`/`RUNNING` to `FAILED` and releases items, and `create()` still gates refusal on items, so it cannot start refusing runs it accepts today. This is also why the follow-up advisory-lock ticket must not replace the item-based check with a `SyncInstance.status` constraint — and why the `create()` sequence is worth a look in review, since that ticket will wrap it in a lock. - **Clock sources differ**, pre-existing and inherited unchanged: `updated_at` is written by `onupdate=func.now()` (server clock) while the `having` compares against Python `utc_now()`. Not introduced here and deliberately not fixed here. The existing candidate query has to stay item-keyed rather than instance-status-keyed: a reclaim interrupted between its fence and its item release leaves an already-`FAILED` instance whose items are still held, and only an item-keyed set still finds it to finish the release. ## Tested - [ ] Plant the drift row against the dev DB: a `SyncInstance` for the PMM syncer with `status='running'` plus one `SyncItem` with `status='success'` and `updated_at` backdated beyond `STALE_RUN_AFTER`. - [ ] `GET /api/inventory/sync-status` reports that run as `running` in `last_runs`. - [ ] Trigger an inventory sync, then re-read `GET /api/inventory/sync-status`: the planted run now reads `failed` with `snapshot_complete` null, and the new run is present and healthy. - [ ] Add a second, recent `SyncItem` to the planted run and confirm a sync leaves it `running` (progress is respected). Automated: `tests/app/sep/test_crud.py` 67 passed; blast radius (`test_crud` + `sync/` + `apps/inventory/`) 680 passed, 2 skipped; `app/sep/crud.py` at 96% with no missing branches. Each new guard was mutation-checked — dropping the fence's staleness predicate or widening the new candidate class back to `PENDING` fails exactly the tests written for it. CI's `python / test` job has failed once on this branch, at `645a45d98`: `tests/app/sep/test_config.py::TestDiagnosticsDeliveryInputs::test_defaults_to_not_configured`, raising `APPS.15.MODULE_NAME Value error, No module named app.sep.apps._scaffold_ci_scriptforward` — a scaffolding app name reaching the settings the test builds, so workspace-dependent and unrelated to these files. The later full runs on this branch are green. Locally, `tests/app/sep/test_import_boundary.py` fails a varying subset under xdist (3 tests one run, 2 the next) while passing 62/62 in isolation, on a clean `main` too — the same environment-dependent class, also unrelated. ## Checklist - [x] New/modified functions have type hints and rST docstrings - [x] New tests added for new features or bug fixes - [ ] All tests pass locally (`make test`) - [x] Pre-commit hooks pass (`make run-pre-commit`) - [ ] Database migrations generated if models changed (`make makemigrations`) - [ ] User-facing changes documented (README, inline help, UI text) - [ ] Configuration changes documented with examples - [x] Changelog fragment added under `changelog.d/` if the change is user-facing (`make changelog-add`), or confirmed N/A (internal-only change, or a same-release-cycle fix for an unreleased sibling ticket)
1 parent c16578d commit a2f4d03

3 files changed

Lines changed: 445 additions & 38 deletions

File tree

app/sep/crud.py

Lines changed: 48 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -228,10 +228,11 @@ async def create(
228228
it raises a `SyncInstanceAlreadyInProgressError`. Otherwise, it creates and
229229
saves the new `SyncInstance`.
230230
231-
When ``stale_after`` is supplied, an in-progress conflict is first re-examined
232-
for abandoned runs: items left behind by a killed worker would otherwise
233-
block the syncer permanently, because the hanging-item sweep runs only when
234-
the run exits through its context manager.
231+
When ``stale_after`` is supplied, abandoned runs are reclaimed before that
232+
check runs and without waiting for an item conflict to justify it, because a
233+
worker killed after its last item write leaves a stale run that no item
234+
conflict would ever surface. Whatever the reclaim spared is what the conflict
235+
check then sees.
235236
236237
:param session: The SQLAlchemy asynchronous session to use for database
237238
operations.
@@ -243,15 +244,14 @@ async def create(
243244
:raises SyncInstanceAlreadyInProgressError: If a SyncInstance with the same
244245
``syncer`` is already in progress and could not be reclaimed as stale.
245246
"""
247+
if stale_after is not None:
248+
await cls.reclaim_stale_runs(session, instance_create.syncer, stale_after)
249+
# Read after the reclaim, never before it: the reclaim commits separately, so
250+
# a run it spared for resuming mid-reclaim can hold an item an earlier read
251+
# never saw, and refusing on a stale empty list would start a second run.
246252
syncs_in_progress = await cls._items_in_progress(
247253
session, instance_create.syncer
248254
)
249-
if syncs_in_progress and stale_after is not None:
250-
await cls.reclaim_stale_runs(session, instance_create.syncer, stale_after)
251-
syncs_in_progress = await cls._items_in_progress(
252-
session,
253-
instance_create.syncer,
254-
)
255255
if syncs_in_progress:
256256
raise SyncInstanceAlreadyInProgressError(syncs_in_progress)
257257
return await super().create(session, instance_create, **extra_fields)
@@ -291,12 +291,13 @@ async def reclaim_stale_runs(
291291
"""Fail the runs of a syncer whose items stopped progressing long ago.
292292
293293
A run is stale when the newest activity across **all** of its items predates
294-
``stale_after``, so a run still making progress is never reclaimed. The item
295-
flip is a single conditional statement, so a second reclaimer arriving
296-
concurrently matches no rows rather than reclaiming twice. It covers every
297-
stale run already fenced as ``FAILED``, not only the ones this call fenced,
298-
so a reclaim interrupted between its two statements resumes on the next
299-
attempt instead of leaving the syncer blocked.
294+
``stale_after``, so a run still making progress is never reclaimed. Two
295+
classes qualify: a run still holding ``PENDING``/``RUNNING`` items, and a
296+
``RUNNING`` run whose items have all gone terminal. A run that wrote no item
297+
carries no activity to measure and is left alone.
298+
299+
Both the fence and the item flip are single conditional statements, so a
300+
concurrent reclaimer matches no rows rather than reclaiming twice.
300301
301302
``snapshot_complete`` is deliberately left untouched: a partially applied run
302303
must never be counted as a complete generation.
@@ -323,36 +324,56 @@ async def reclaim_stale_runs(
323324
last_activity = func.max(
324325
func.coalesce(col(SyncItem.updated_at), col(SyncItem.created_at)),
325326
)
326-
query = (
327+
cutoff = utc_now() - stale_after
328+
stale_activity = (
327329
select(col(SyncItem.sync_instance_id))
328-
.where(col(SyncItem.sync_instance_id).in_(in_progress))
329330
.group_by(col(SyncItem.sync_instance_id))
330-
.having(last_activity < utc_now() - stale_after)
331+
.having(last_activity < cutoff)
331332
)
332-
result = await cls._exec(session, query)
333-
stale_instance_ids = list(result.all())
333+
blocked = stale_activity.where(col(SyncItem.sync_instance_id).in_(in_progress))
334+
# Kept as a second query rather than folded into the one above: that one must
335+
# stay item-keyed so a reclaim interrupted after fencing still finds its run
336+
# and releases the items. Excluding those runs makes the two sets disjoint,
337+
# and grouping over items is what leaves a run that wrote none out of both.
338+
idle = stale_activity.join(SyncInstance).where(
339+
col(SyncInstance.syncer) == syncer,
340+
col(SyncInstance.status) == SyncStatusEnum.RUNNING,
341+
col(SyncItem.sync_instance_id).not_in(in_progress),
342+
)
343+
blocked_result = await cls._exec(session, blocked)
344+
idle_result = await cls._exec(session, idle)
345+
stale_instance_ids = [*blocked_result.all(), *idle_result.all()]
334346
if not stale_instance_ids:
335347
return []
336348
# The instance is fenced first, and only then are its items released.
337349
# Each statement commits on its own, so flipping the items first would
338350
# leave a window in which a reclaimed-but-live worker still reads
339-
# ``RUNNING`` and walks into its retire phase. The status predicate keeps
340-
# a run that finished between the query above and this update: it has
341-
# already written its own verdict, and is no longer anyone's to reclaim.
351+
# ``RUNNING`` and walks into its retire phase. Both predicates re-assert
352+
# what the query above selected on, because it committed separately: a run
353+
# that finished meanwhile has written its own verdict, and one whose worker
354+
# resumed and touched an item is progressing after all. The re-assertion
355+
# repeats the candidate narrowing so its grouping is index-seekable rather
356+
# than spanning every item row; restricting the rows cannot change a
357+
# surviving group's ``max()``, since every group is one instance's items.
342358
reclaimed_ids = await cls.update_where(
343359
session,
344360
{"status": SyncStatusEnum.FAILED},
345361
col(SyncInstance.id).in_(stale_instance_ids),
362+
col(SyncInstance.id).in_(
363+
stale_activity.where(
364+
col(SyncItem.sync_instance_id).in_(stale_instance_ids),
365+
),
366+
),
346367
col(SyncInstance.status).in_(
347368
[SyncStatusEnum.PENDING, SyncStatusEnum.RUNNING],
348369
),
349370
returning=["id"],
350371
)
351372
# Items are released for every stale instance already fenced, not only the
352-
# ones this call fenced. A crash between the two statements leaves a FAILED
373+
# ones this call fenced: a crash between the two statements leaves a FAILED
353374
# instance whose items were never released, and the update above then matches
354-
# nothing on every later attempt -- so without this the syncer would stay
355-
# blocked by exactly the abandoned run the reclaim exists to clear.
375+
# nothing on every later attempt, blocking the syncer with exactly the
376+
# abandoned run the reclaim exists to clear.
356377
fenced = await cls._exec(
357378
session,
358379
select(col(SyncInstance.id)).where(

changelog.d/SEP-1894.fixed.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
1+
Reconcile a sync run abandoned by a killed worker even when it left no unfinished items behind.

0 commit comments

Comments
 (0)