fix(canary): make E-01 lease-aware so a healthy pull turn stops paging critical (#1990) - #2046
Conversation
…g critical (#1990) E-01 ("no running row older than execution_timeout_seconds + 300s") was the last invariant reading the running-row set with no lease-awareness, after S-01 shipped with the pull phases and E-05 got it in #1982. A #1081 Phase-3 pull-CLAIMED row (lease_expires_at IS NOT NULL) is status='running' but owned exclusively by the lease-reaper, which re-queues it (redelivery_count++, started_at reset) or poison-parks it terminal at MAX_REDELIVERY. Its age is not evidence of the stuck-execution class E-01 detects: the deadline governing a leased row is its lease, and a different component owns the recovery. The overlap is exact, not merely awkward. claim_next_queued stamps lease_expires_at = started_at + (execution_timeout_seconds + SLOT_TTL_BUFFER) (pull_coordination_service.py) -- the same threshold E-01 builds. So age > threshold became true at the precise instant the lease expired, which is the instant the reaper's recovery window OPENS. The 300s buffer exists so E-01 fires only after the owning component has had its window; against a leased row that head-room was zero, and E-01 paged critical for the whole gap between lease expiry and the reaper's next sweep -- on every re-delivery, per execution, while the machinery worked as designed. The db layer already encoded this ownership split, including on the very sweep whose failure E-01 exists to detect: mark_stale_executions_failed carries lease_expires_at IS NULL, as do get_running_executions, get_running_executions_with_agent_info, fail_stale_slot_execution and mark_no_session_executions_failed. The canary was the layer that hadn't caught up. This blocks the #1766 soak, whose AC is "canary green throughout" and whose abort criterion is a critical canary violation on the pilot -- so a healthy soak would abort itself, or worse, train the operator to ignore the one invariant that matters most during it. The exclusion is keyed on the lease, not a blanket silencing: a NULL-lease (push) row of identical age still fires, the threshold boundary is unchanged, and an absent snapshot key fails OPEN (an older image that never populated the column keeps being checked). Closes T3.7 in docs/testing/PULL_MIGRATION_TESTING.md section 3. E-02 assessed and deliberately NOT excluded ------------------------------------------- E-01, E-05, S-01 and E-02 are the four readers of running_exec_ids; E-02 is the one that must keep seeing leased rows. It asks a different question -- was this id terminal in a previous cycle and is it non-terminal now -- whose answer does not depend on who owns the row. The reaper cannot produce that transition (requeue_expired_lease / park_expired_lease both CAS on status='running' with a past lease, so a terminal row is unreachable to them), and re-delivery preserves the execution_id by construction (#1084/#525 are execution_id-scoped), so a terminal id reappearing as running/queued is exactly the corruption E-02 exists to catch. Pull is MORE exposed to it than push -- a late worker result and a reaper pass race for the same row -- so copying this exclusion into E-02 "for consistency" would blind it on the very path #1081 introduces. Recorded in the E-01 docstring, snapshot.py, the catalog and architecture.md, and guarded executably by a test. Testing ------- tests/unit/test_1990_e01_lease_awareness.py -- 13 tests. Under tests/unit/ because CI runs `cd tests && pytest unit/` only; the pre-existing E-01 tests sit in tests/test_canary_invariants.py, which no workflow executes (trinity#2037), so a guard placed beside them would never go red. Verified red without the fix: 5 failed, 8 passed -- the 8 being the NULL-lease controls, which must pass either way. Load-bearing: a NULL-lease control row of identical age still fires, asserted both alone and alongside a leased row in one snapshot. Every other test in the module would still pass if someone "fixed" E-01 by deleting it. Boundary asserted exactly (threshold silent / threshold+1 fires) off integer offsets from one literal T0, per the #1909 clock discipline. The E-02 verdict is a test, not a comment. Two mirrored cases added to the in-place suite for locality beside the rest of E-01's coverage, with a pointer to the enforcing module. Full unit suite: 7814 passed, 18 skipped (7801 baseline + 13). Also: the E-01 Slack runbook now states a firing row is always NULL-lease, so on-call is not sent after the lease-reaper for a push-path stall. Closes #1990
dolho
left a comment
There was a problem hiding this comment.
Reviewed the diff, the E-01/S-01/E-05 exclusion trio, lease_reaper_service.py, requeue_expired_lease/park_expired_lease, and the new test module. CI is green across all 6 pytest shards.
The diagnosis is right and well-evidenced: claim_next_queued stamps lease_expires_at = started_at + (execution_timeout_seconds + SLOT_TTL_BUFFER), which is byte-for-byte the threshold E-01 builds, so a leased row crossed E-01's line at the exact instant the reaper became eligible — zero head-room, critical severity, once per re-delivery. Excluding leased rows matches the lease_expires_at IS NULL clause that mark_stale_executions_failed (the very sweep E-01 watches) already carries, so the invariant was genuinely the layer that hadn't caught up. The E-02 non-exclusion analysis is correct and test_e02_deliberately_counts_leased_running_rows is the right way to record it.
One substantive concern before merge.
1. The unconditional skip removes the only automated detector for a stuck or dead lease-reaper
requeue_expired_lease sets started_at=now and clears lease_expires_at in the same atomic UPDATE, and the reaper runs on cleanup_service's 5-minute cycle. So with a healthy reaper, a leased row's age cannot exceed threshold + ~one cleanup interval — the false-positive window this PR targets is small and bounded.
continue-ing on any non-NULL lease is therefore much wider than the bug requires, and it locks in permanent silence for the failure case. test_leased_row_far_past_threshold_is_still_silent makes that explicit: a row at 10× threshold whose lease expired an hour ago is asserted silent forever. That row is not a re-delivery transient — PULL_MIGRATION_TESTING.md §9 M4 calls exactly that state "a running row past its lease_expires_at that the reaper has not touched is a reaper failure", and a non-empty M4 is a #1766 abort criterion.
After this PR, who catches it?
- In-platform: nobody. E-01, E-05 and S-01 all exclude leased rows; E-02 only catches terminal→non-terminal reversals; there is no lease-overdue invariant in
canary/invariants/. - Externally:
/deep-probev1.3 (trinity-ops-agent#297) runs M1/M3/M5 — not M4. - The reaper itself lives in
cleanup_service, i.e. the same loop whose death E-01 exists to detect for push rows. For pull rows that detection is now gone.
Net effect: the soak's headline AC ("no lost/phantom executions") is checked only by a human pasting SQL. The PR's own framing — "a different component owns the recovery" — is true, but that component's failure now has no owner.
Concrete options, roughly in order of preference:
(a) Grace window instead of a blanket skip. Keep the exclusion keyed on the lease but bound it in time:
lease = agent.running_lease_expires_at.get(eid)
if lease is not None and not _overdue_by(lease, snapshot.snapshot_time, GRACE_SECONDS):
continueWith GRACE_SECONDS ≈ 2× the cleanup interval (~600s), a working reaper never produces a firing row (it re-queues and resets started_at within one cycle), and a reaper that has stopped fires — which is exactly E-01's stated job. This costs one constant and keeps every test in the module passing except the deliberately-forever-silent one, which would become a bounded-silence assertion.
(b) A dedicated lease-overdue invariant (the S-01/E-05/E-01 trio all excluded leased rows, so this is now the missing third).
(c) At minimum: file the follow-up, add M4 to /deep-probe, and change the docstring's "a different component owns the recovery" to say plainly that that component's own failure is currently unmonitored, with the issue number. Leaving it implied is how the next reader concludes it's covered.
Happy to be told this is deliberate and tracked — but it should be tracked, not inferred from the exclusion.
2. Smaller notes
- The skip is placed before the
started_atlookup, so a leased row also bypasses the missing-timestamp branch. Correct as written, but it means a leased row is fully unobserved by this invariant, not merely un-aged — reinforces point 1. is not Nonetreats an empty string as a live lease. In practice writes go throughto_utc_iso, so NULL-or-ISO holds; not worth code, but if you ever collect from a source that coerces NULL to""the exclusion silently widens.canary_alerts.py: "A firing row is always NULL-lease" is accurate under the current skip and useful for on-call. If (a) lands, that line needs to change with it.
3. What's good
- Fail-open on an absent snapshot key is the right default and is documented at the field, not just at the call site — an older image keeps being checked rather than silently retiring the invariant.
- Boundary asserted exactly off one literal
T0(thresholdsilent /threshold + 1fires), no real clock on either side — matches the #1909 discipline. - The NULL-lease control asserted both alone and alongside a leased row in one snapshot is the load-bearing test, and the module says so.
- Test placement under
tests/unit/with the #2037 rationale spelled out is right; the mirrored cases in the uncollected suite are locality-only and labelled as such.
… forever Review finding (dolho, #2046): the unconditional `continue` on any non-NULL lease is wider than the bug requires, and it locks in permanent silence for a real failure — a stuck or dead lease-reaper. `requeue_expired_lease` sets `started_at=now` and clears `lease_expires_at` in one atomic UPDATE, and the reaper runs on `cleanup_service`'s cycle, so under a healthy reaper a leased row's observable overdue-ness is bounded by one interval. The false-positive window this PR targets is small and bounded; the blanket skip was not. Nothing else covered the failure case. E-01, E-05 and S-01 all exclude leased rows; E-02 only catches terminal→non-terminal reversals; there is no lease-overdue invariant; and /deep-probe v1.3 (trinity-ops-agent#297) ships M1/M3/M5, not M4. Meanwhile PULL_MIGRATION_TESTING.md §9 M4 — "a running row past its lease_expires_at that the reaper has not touched is a reaper failure" — is a #1766 soak ABORT criterion. It would have had no automated owner. So the skip is now bounded by LEASE_REAPER_GRACE_SECONDS (600s = 2 x cleanup_service.CLEANUP_INTERVAL_SECONDS): one reaper cycle of worst case plus a full spare cycle. A healthy reaper never fires; one that has merely missed a cycle never fires; one that has STOPPED fires within grace + one canary cadence. The constant carries its derivation and is asserted against the live interval so the coupling cannot drift silently. A firing leased row is a DIFFERENT diagnosis — the lease-reaper failed, not cleanup_service's stale watchdog — so `lease_expires_at`, `lease_overdue_seconds` and the grace ride in observed_state, the signal_query names it, and the runbook hint now branches on `lease_expires_at` instead of asserting "a firing row is always NULL-lease". Two states that now fire deliberately, both on-call-actionable and documented: the #1085 re-delivery governor hold (opt-in, 300s pause TTL, absorbed by the spare cycle unless sustained) and reaper saturation (`find_expired_leases` takes limit=500/pass). Also from the review: `_parse_lease` collapses None/""/unparseable to "no lease", so a future collector coercing NULL to "" widens nothing — a bare `is not None` would have read that as a live lease and silenced the row.
|
Taken — option (a), the grace window, in You're right that the blanket The grace is derived, not picked. Two states now fire deliberately, both found while checking the grace was actually safe, both on-call-actionable and documented: the #1085 re-delivery governor hold (opt-in, 300s pause TTL, absorbed by the spare cycle unless the storm is sustained — and a sustained one should fire, since re-delivery genuinely isn't happening and nothing else says so), and reaper saturation ( Your smaller notes:
Docs updated to match in all four places ( Left untouched deliberately, per your "what's good" list: the exact-boundary discipline off one literal Suite: |
vybe
left a comment
There was a problem hiding this comment.
The threshold-identity argument is the crux and it checks out: claim_next_queued stamps lease_expires_at = started_at + (execution_timeout_seconds + SLOT_TTL_BUFFER), which is the same expression E-01 builds — so age > threshold became true at the exact instant the lease expired, i.e. the instant the reaper's window opens. The 300s buffer exists precisely so E-01 fires only after the owning component has had its chance, and against a leased row that head-room was zero. That makes this a false positive by construction, not a tuning problem.
Reading the code, it is more careful than the description suggests, and in the direction that matters: this is not a blanket continue on any non-NULL lease. A leased row is skipped only while overdue by at most LEASE_REAPER_GRACE_SECONDS, and past that it still fires — carrying lease_expires_at/lease_overdue_seconds so on-call gets the different diagnosis (the lease-reaper failed, not cleanup_service's watchdog). Given that E-01, E-05 and S-01 all exclude leased rows and there is no lease-overdue invariant, a blanket skip would have been permanent silence on M4. Good instinct to bound the exclusion rather than take it.
Not excluding E-02 is the right call and the reasoning is correct — it asks "was this id terminal before and is it non-terminal now?", whose answer is owner-independent, and pull is more exposed to that race than push, so copying the exclusion "for consistency" would blind it on exactly the path #1081 introduces. Making that verdict executable as a tripwire test rather than leaving it as prose is what stops the next person doing it.
Two test choices worth noting: fail-open on an absent snapshot key, so an older collector keeps being checked instead of silently retiring the invariant; and placing the guard under tests/unit/ because CI runs cd tests && pytest unit/ only — a guard next to the existing E-01 tests in tests/test_canary_invariants.py would never have gone red (#2037 is a real gap and worth closing separately). Verified-red at 5 failed / 8 passed, with the 8 being the NULL-lease controls that must pass either way, is the right shape.
Unblocks the #1766 soak, whose abort criterion would otherwise have tripped on day one while the machinery worked as designed.
E-01 ("no
runningrow older thanexecution_timeout_seconds + 300s") was the last invariant reading the running-row set with no lease-awareness — S-01 shipped with the pull phases, E-05 got it in #1982.The overlap is exact, not merely awkward
A #1081 Phase-3 pull-CLAIMED row (
lease_expires_at IS NOT NULL) isstatus='running'but owned exclusively by the lease-reaper, which re-queues it (redelivery_count++,started_atreset) or poison-parks it terminal atMAX_REDELIVERY. Its age is not evidence of the stuck-execution class E-01 detects: the deadline governing a leased row is its lease, and a different component owns the recovery.And the two windows are the same window.
claim_next_queuedstampslease_expires_at = started_at + (execution_timeout_seconds + SLOT_TTL_BUFFER)(pull_coordination_service.py:164) — the identical threshold E-01 builds. Soage > thresholdbecame true at the precise instant the lease expired, which is the instant the reaper's recovery window opens. The 300s buffer exists so E-01 fires only after the owning component has had its window to act; against a leased row that head-room was zero, and E-01 paged critical for the entire gap between lease expiry and the reaper's next sweep — on every re-delivery, per execution, while the machinery worked exactly as designed.The db layer already encoded this ownership split, including on the very sweep whose failure E-01 exists to detect:
mark_stale_executions_failedcarrieslease_expires_at IS NULL, as doget_running_executions,get_running_executions_with_agent_info,fail_stale_slot_executionandmark_no_session_executions_failed. The canary was the layer that hadn't caught up.Why now
This blocks the #1766 soak being set up on
eu2. Its AC is "canary green throughout" and its abort criterion is a critical canary violation on the pilot — so a healthy soak aborts itself on day one, or worse, trains the operator to ignore the one invariant they most need during precisely that window.Keyed on the lease, not a blanket silencing
A NULL-lease (push) row of identical age still fires, the threshold boundary is unchanged, and an absent snapshot key fails OPEN — a collector that never populated the column (older image, pre-#1081) keeps being checked, rather than silently retiring E-01.
Closes T3.7 in
docs/testing/PULL_MIGRATION_TESTING.md§3. Canary lease-awareness is now complete.E-02 assessed, and deliberately NOT excluded
E-01, E-05, S-01 and E-02 are the four readers of
running_exec_ids; E-02 is the one that must keep seeing leased rows.It asks a different question — "was this id terminal in a previous cycle and is it non-terminal now?" — whose answer does not depend on who owns the row. The reaper cannot produce that transition (
requeue_expired_lease/park_expired_leaseboth CAS onstatus='running'with a past lease, so a terminal row is unreachable to them), and re-delivery preserves theexecution_idby construction (#1084/#525 are execution_id-scoped) — so a terminal id reappearing as running/queued is exactly the corruption E-02 exists to catch. Pull is more exposed to it than push (a late worker result and a reaper pass race for the same row), so copying this exclusion into E-02 "for consistency" would blind it on the very path #1081 introduces.Recorded in the E-01 docstring,
snapshot.py, the catalog,architecture.mdandPULL_MIGRATION_STATUS.md— and guarded by a test rather than left as prose.Testing
tests/unit/test_1990_e01_lease_awareness.py— 13 tests. Undertests/unit/because CI runscd tests && pytest unit/only; the pre-existing E-01 tests sit intests/test_canary_invariants.py, which no workflow executes (#2037), so a guard placed beside them would never go red.thresholdsilent /threshold + 1fires) off integer offsets from one literalT0— neither side samples a real clock, per the bug: test_a13_exact_cutoff_row_is_not_expired is wall-clock flaky (~3.3%), reddens regression diff on unrelated PRs #1909 discipline.test_e02_deliberately_counts_leased_running_rowsmakes the AC-5 verdict executable — a tripwire on someone copying the exclusion into E-02.Two mirrored cases added to the in-place suite for locality beside the rest of E-01's coverage, with a pointer to the enforcing module.
Full unit suite: 7814 passed, 18 skipped (7801 baseline + 13).
Also
The E-01 Slack runbook now states that a firing row is always NULL-lease, so on-call is not sent after the lease-reaper for a push-path stall.
Docs
docs/memory/architecture.md(canary invariant table),docs/testing/orchestration-invariant-catalog.md(E-01 signal + the E-02 non-exclusion),docs/testing/PULL_MIGRATION_TESTING.md(T3.7 closed, §8 remaining set),docs/planning/PULL_MIGRATION_STATUS.md.Closes #1990
🤖 Generated with Claude Code