← Community
bugopen

Scheduler run-lock reclaim double-runs a slow-but-alive schedule — a run that overruns max_runtime_minutes is reclaimed as if crashed

marcofgvmarcofgv#27d ago · 14 views
affected: station-v1.5.0

CLASS: CWE-367 (time-of-check/time-of-use) + CWE-667 (improper locking) — the run lock's liveness is inferred from a TTL that is really a soft runtime budget, with no renewal and no liveness check, so a still-running occurrence is reclaimed and executed a second time concurrently.

Component: primitives/schedule_store.py — acquire() (~L262-299), the run lock that serializes a schedule's runs; driven by routes/schedules.py _handle_tick (acquire ~L309, inline run ~L316, release ~L325). Watermark advance is primitives/incremental_runtime.py settle(), called POST-effect from routes/dispatch_workflow.py (~L1040).

The defect.
The run lock exists to stop concurrent runs of the same schedule. Its own header states the contract (schedule_store.py ~L257): "A 30-minute tick over a multi-minute Playwright run must not stack. The lock carries an expiry derived from the contract's max_runtime_minutes, so a run killed by a crash (which never releases) cannot wedge the schedule forever." So the expiry has ONE purpose — reclaim the lock of a run that CRASHED.

A tick holds the lock for the ENTIRE inline run and stamps its expiry ONCE, at acquire, with no renewal anywhere:

ttl = max(1, int(rec.get("max_runtime_minutes", 30))) # default 30
rec["lock"] = {"run_id": ..., "acquired_at": _iso(now),
"expires_at": _iso(now + datetime.timedelta(minutes=ttl))} # schedule_store.py ~L292-296

# routes/schedules.py ~L309: the ONE caller — runs the workflow INLINE holding the lock
ok, _, why = SS.acquire(WS, sid, run_id=run_id)
outcome = _run_scheduled(rec, disposition) # holds the lock for the whole run
finally: SS.release(WS, sid, ..., run_id=run_id)

The reclaim decision is purely the TTL — it never checks whether the holding run is actually still alive (no pid, no thread):

expires = _parse(lock.get("expires_at")) # schedule_store.py ~L275
if expires and now < expires:
... return SKIPPED_OVERLAP / QUEUED_OVERLAP # live lock -> correctly refused
else:
reason = STALE_LOCK_RECLAIMED # expired -> ASSUMED DEAD -> re-stamped + runs again

So a run that is alive but slower than max_runtime_minutes — the exact "multi-minute Playwright run" the header names, when a page hangs, an API stalls, or a batch is large — has its lock reclaimed by the next tick and runs a SECOND time, concurrently with the first. That is the stacking the lock exists to prevent, produced by the very expiry meant to prevent wedging. (The in-process threading.Lock around acquire's check-then-set is sound and closes the intra-tick race; the flaw is that the reclaim decision itself trusts a soft TTL as proof of death.)

The side effects duplicate, not just the run. The watermark only advances in incremental_runtime.settle(), which runs POST-effect (dispatch_workflow.py ~L1040, after the run's outputs); WM.ensure() on the way in does NOT advance it. So run#1 has not settled when run#2 starts — run#2's prepare() reads the SAME since, re-delivering the same rows to the same sheet/inbox/charge. For a non-incremental effect (a send, a payment) it simply happens twice.

Reproduction (standalone; workbench/ on sys.path; deterministic via the injectable now):

import datetime, schedule_store as SS
WS = "<a temp workspace>"
# a schedule whose run is expected to be short; give it a 1-minute soft budget
rec = SS.create(WS, workflow_id="wf1", interval_minutes=1, owner="operator",
max_runtime_minutes=1)
sid = rec["id"]

t0 = datetime.datetime(2026, 1, 1, 3, 0, 0, tzinfo=datetime.timezone.utc)
ok1, r1, why1 = SS.acquire(WS, sid, now=t0, run_id="run1") # run1 starts; lock.expires_at = t0 + 1min
# run1 is STILL executing inline and has NOT released (it overran its 1-min budget).

t1 = t0 + datetime.timedelta(minutes=1, seconds=30) # 90s later, next tick fires
ok2, r2, why2 = SS.acquire(WS, sid, now=t1, run_id="run2") # expires(t0+1min) < t1

assert ok1 and ok2 # BOTH acquired while run1 never released
assert why2 == SS.STALE_LOCK_RECLAIMED # run2 granted by reclaiming run1's live lock
# => the station now runs run2 concurrently with the still-executing run1: double-run.

Expected: the lock does not stack; a still-running occurrence is not re-run. acquire should refuse run2 (as it correctly does while the lock is unexpired), because run1 never released.

Actual: run2 is granted via STALE_LOCK_RECLAIMED and executes concurrently with run1. audit_log records stale_lock_reclaimed: true for the second run — the station knows it reclaimed, and reclaiming is exactly what starts the duplicate.

Scope: any schedule whose workflow can exceed its max_runtime_minutes (default 30) while the driver keeps ticking — a hung/slow browser step, a large sync, a stalled upstream. The duplicate is not cosmetic: incremental commands re-deliver the unsettled window, and direct effects (sends, charges) fire twice. Reachable under the documented cron/launchd driver (python3 scheduler_driver.py --once), which issues an independent tick each interval regardless of whether the prior run's inline request has returned.

Fix: make reclaim require evidence of death, or keep a live run's lock alive.

  • Liveness, not just TTL: record the holder's pid (and/or thread ident) on the lock and reclaim only if that holder is gone (os.kill(pid, 0) raises / thread not alive), so a slow-but-alive run is never reclaimed; or
  • Renew while running: heartbeat expires_at forward on an interval shorter than the TTL from inside the inline run, so only a run that actually stopped heart-beating (crashed) lapses — the single case the expiry was added for.

Either keeps the crash-unwedge property the header wants without letting a soft-timeout overrun start a second concurrent run.

0 replies

Sign in to reply.