Skip to content

fix(cron): separate fire-fence contention from fire-claim ownership loss - #109003

Closed
apedance wants to merge 1 commit into
NousResearch:mainfrom
apedance:fix/cron-fire-fence-contention
Closed

apedance wants to merge 1 commit into
NousResearch:mainfrom
apedance:fix/cron-fire-fence-contention

Conversation

@apedance

Copy link
Copy Markdown

Fixes #100401 (canonical; also reported as #108341, #108862, #106737, #105861).

Problem

A cron job whose delivery leg holds its per-job fire fence past _JOBS_LOCK_TIMEOUT_SECONDS (30s) gets
its own fire-claim heartbeat timed out into heartbeat_fire_claim() -> False, which the heartbeat loop
reads as ownership lost. A run that delivered is then booked failed.

Real incident on a self-hosted gateway (2026-09-12) — a no_agent script job delivering to Telegram:

03:30:56,856 INFO    cron.scheduler: Cron job 'e7d0e5ec5197' handed to restart-safe worker execution=33fd39d1cd0f4b4965345dab08825
03:32:26,832 ERROR   cron.jobs: Timed out waiting for local fire fence <cron_dir>::e7d0e5ec5197; failing closed
03:32:26,832 WARNING __main__: Job 'e7d0e5ec5197': fire claim ownership lost; interrupting stale run
03:32:29,410 INFO    cron.scheduler: Job 'e7d0e5ec5197': delivered to telegram:515754425 message_id=43288

The same worker delivered the notification 2.6s after the "ownership lost" line — nothing had shut down.
jobs.json still recorded last_status=error, last_error="Interrupted by shutdown before terminal completion.", and the executions ledger recorded the same. That write only happens on the branch that
first re-verifies the claim still belongs to us, i.e. the claim was never taken by anyone else.

Root cause

_fire_job_lock() (cron/jobs.py) serializes a job's owner mutations and its external side effects:
the run thread holds the fence across save_job_output() and _deliver_result(). The heartbeat runs on
a different thread, so the fence's thread-local reentrancy does not apply and the RLock is genuinely
contended for as long as delivery takes. On timeout the fence yields False, and
heartbeat_fire_claim() (cron/jobs.py:2601) collapsed that into the same False it returns when the
CAS proves another owner holds the claim, so the heartbeat loop (cron/scheduler.py:2380) could not tell
"could not determine ownership" from "definitely lost it".

That conflation reaches four consumers, not one:

consumer on fence timeout today should be
_run_with_fire_claim_heartbeat sets lost_ownership, interrupts the run unverified: renew later, bounded by the existing grace
pre-run validation "ownership lost before execution started" unverified: fail closed without claiming loss
_FireOwnership.lost() skips a legitimate delivery unverified: do not skip on contention
fire_claim_fence() → _save_compose_deliver raises claim-lost, stamps "Interrupted by shutdown..." skip the side effect, record fence contention as the cause

Approach

The fence is a serialization primitive, not an ownership signal, so both primitives now report the two
states separately — None = fence not acquired, ownership unverified; False = verified loss (claim
gone or a replacement owner holds it):

  • heartbeat_fire_claim() and fire_claim_fence() return/yield None when the fence is unavailable.
  • The heartbeat loop renews on True, still fails closed immediately on False, and lets None be
    renewed inside the existing _FIRE_CLAIM_HEARTBEAT_GRACE_SECONDS window instead of interrupting on the
    first contended tick.
  • Pre-run validation treats None as "not confirmed" and fails closed before any side effect.
  • A side effect that cannot acquire its fence is still skipped — never act on an unverified claim —
    but the run records "Fire fence busy: save/delivery skipped without performing side effects (fire claim ownership could not be verified)." instead of the ownership-lost/shutdown stamp.
  • _record_fire_ownership_lost() writes the interrupted stamp only for a verified still-owned claim.

Tests

tests/cron/test_fire_fence_contention.py — both tests fail on main:

  • test_fence_contention_during_slow_delivery_is_not_ownership_loss: a delivery that outlives the
    (compressed) fence wait while the real heartbeat timer ticks. On main: Timed out waiting for local fire fence → fire claim ownership lost; interrupting stale run, and the run body is handed a
    set lost-ownership event. After the fix: the delivery runs and the run is recorded successful.
  • test_fence_held_elsewhere_skips_side_effects_without_ownership_lost_stamp: a second thread holds the
    real fence. On main: side effects skipped, ledger closed with "Fire claim ownership lost; stale result was discarded." After the fix: nothing is written or sent, and the ledger carries the
    fence-contention cause.

scripts/run_tests.sh tests/cron/ → 105 files, 1248 passed, 0 failed, 1 skipped (windows_only lane).

Overlap with existing PRs — please read before triaging

This issue has ~12 open fix PRs. The heartbeat half of this patch overlaps #100418 / #100965 / #107844
and should lose to whichever of those the maintainers prefer — I am happy to be closed in favour of one
of them, or to rebase this down to only the parts below.

What none of the existing PRs cover (I checked every open fix's diff: none touches
_FireClaimLostDuringSideEffect or the fire_claim_fence() fence-busy path): the side-effect path.
Applying the converged heartbeat shape (heartbeat refreshes its CAS under _jobs_lock() only, no fire
fence) on top of this branch and running the new tests gives 1 passed, 1 failed — the second test still
fails with 'Interrupted by shutdown before terminal completion.'. So a heartbeat-only fix still books a
run whose fence is held elsewhere as an ownership loss / shutdown. That half is in this PR with its test,
and it is the follow-up the reporters on #100401 asked for ("_OWNERSHIP_LOST_INTERRUPTED ... is written
from _record_fire_ownership_lost ... the current message is not [honest]").

Risk

  • heartbeat_fire_claim()'s return type widens to Optional[bool]; all call sites are in-tree (3 in
    cron/scheduler.py, plus tests) and are updated here. A caller treating None as falsy reads
    unverified as lost — the pre-existing behaviour — so nothing gets weaker by omission.
  • Fail-closed policy is unchanged for verified loss and for side effects: an unverified fence never
    performs a side effect. What changes is the bookkeeping, plus not interrupting on the first contended
    heartbeat tick.
  • Residual bound, not addressed here: a single side effect holding the fence past
    _FIRE_CLAIM_HEARTBEAT_GRACE_SECONDS (180s) still ends in an uncertain-loss interrupt, and the claim's
    own 300s TTL can still expire during a very long delivery (Cron fire-claim TTL (300s) expires mid-run, allowing a second concurrent execution of a long job #88507 tracks that separately).

Verified in production on the reporting host: this commit is applied to the live checkout and the
regression tests pass there against the running cron store.

A job's fire fence is held across its external side effects, so a delivery that
outlives _JOBS_LOCK_TIMEOUT_SECONDS (30s) makes the fire-claim heartbeat's own
fence acquire time out. heartbeat_fire_claim() collapsed that timeout into the
same False it returns for a verified lost claim, and the heartbeat loop read it
as ownership loss: it interrupted a run that had delivered and stamped it
"Interrupted by shutdown before terminal completion." in jobs.json and in the
executions ledger (observed: a 33s Telegram send landing 33s after its output
save, 2026-09-12 03:31).

The fence is a serialization primitive, not an ownership signal, so the two
outcomes are now reported separately -- None = fence busy/unverified, False =
verified loss:

- heartbeat_fire_claim() and fire_claim_fence() report an unacquirable fence as
  None; the heartbeat loop renews on True, fails closed on False, and bounds
  None by the existing _FIRE_CLAIM_HEARTBEAT_GRACE_SECONDS window.
- Pre-run validation and _record_fire_ownership_lost() accept a claim only when
  it is verified.
- A side effect that cannot acquire its fence is still skipped (fail closed),
  but recorded as fence contention instead of an ownership loss.

tests/cron/test_fire_fence_contention.py covers both paths; both tests fail on
main.

@ehz0ah ehz0ah left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I found two blocking correctness issues in the new contention handling. Both reproduce at this exact head and can still misclassify a busy fire fence as successful delivery or verified ownership loss. GitHub does not permit this account to submit a request-changes review, so I am posting the blockers as review comments.

Comment thread cron/scheduler.py
)
try:
with fence.side_effect_fence() as owns_delivery:
if owns_delivery is None:

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[Bug] (blocking) This exception is swallowed by the broad delivery-error handler below. If output saving succeeds but another holder keeps the fence busy before delivery, this raise is caught by except Exception as de because only _FireClaimLostDuringSideEffect is re-raised. Since this exception has no message, d.delivery_error becomes empty while d.success remains true, so the skipped delivery can be recorded as successful and classified as delivered. Please preserve this control-flow exception through the generic delivery-error handler and cover contention on the second fence.

Comment thread cron/scheduler.py
execution_token=execution_token)
except _FireClaimLostDuringSideEffect:
d.side_effect_ownership_lost = True
except _FireFenceBusyDuringSideEffect:

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[Bug] (blocking) This handler still cannot preserve the fence-contention result when the same holder remains active through finalization. It proceeds directly to mark_job_run, whose boolean return collapses a fire-fence timeout and an owner mismatch. _finish_completed_run then reports every false result as Fire claim ownership lost before terminal completion. The regression test masks this path by mocking mark_job_run(return_value=True) while its fence holder remains active. With the real store path, sustained contention therefore reproduces the false ownership-loss bookkeeping this PR is meant to remove. Finalization needs to distinguish fence unavailability from verified ownership loss, and the test should exercise the real final write.

@kshitijk4poor

Copy link
Copy Markdown

The fix for this bug landed on main via #109310 (merge 9a60a7f): heartbeat_fire_claim now refreshes under _jobs_lock only and no longer waits on the per-thread fire fence its own run holds, so a delivery/agent turn longer than the 30s fence timeout is no longer misread as ownership loss. _refresh_claim still CASes on claim["by"], so a real takeover keeps returning False (pinned by test).

Thanks @apedance. Re @ehz0ah's two blocking findings (a busy fence misclassified as delivered/verified loss): the landed fix sidesteps the classification entirely — the heartbeat no longer takes the fence, so there is no contention result to classify. Closing with credit.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[Bug]: cron — fire-claim heartbeat deadlocks on its own run's fence, killing every job that runs >60s as "Interrupted by shutdown"

3 participants