Skip to content

fix(start-lock): make the dispatch critical section abortable so a wedged fn rejects (PEN-3328) - #1904

Open
allyblockcast[bot] wants to merge 15 commits into
masterfrom
fix/pen-3328-abortable-dispatch-section
Open

allyblockcast[bot] wants to merge 15 commits into
masterfrom
fix/pen-3328-abortable-dispatch-section

Conversation

@allyblockcast

@allyblockcast allyblockcast Bot commented Sep 17, 2026 •

Copy link
Copy Markdown

Thinking Path

  • Paperclip is the open source app people use to manage AI agents for work
  • Queued-run dispatch is serialized per agent by withAgentStartLock, whose critical section is startNextQueuedRunForAgent — the thing that turns a queued run into a running one
  • That lock has no timeout, no TTL and no owner-liveness check, deliberately: the implementation it replaced stopped waiting after 30 s and became a concurrency amplifier under backlog (BLO-20396). The module header claimed liveness came from "bounding the critical section's work" — but that was a comment, not a mechanism
  • So any indefinite await inside the section was a permanent, silent, per-agent dispatch outage, clearable only by replacing the process. Measured 2026-09-15/16: five agents across two companies dark for 6–19 h each, ~70 runs stuck in queued, every seat reading status: idle / errorReason: null / orgChainHealth: healthy
  • PEN-3305 (fix(start-lock): report a wedged dispatch section instead of hiding it (PEN-3305) #1899) made that state visible. It did not bound it, and says so in its own header — the wedge is unchanged in the shipped image
  • This pull request supplies the missing mechanism: the section gets an AbortSignal, its database awaits genuinely observe it, and fn rejects — releasing the lock through the finally that was already there
  • The benefit is that a transient condition stops being converted into a permanent one. It self-heals in five minutes instead of taking a seat down until someone notices and restarts a pod

Linked Issues or Issue Description

Searched for duplicates across start-lock, agent-start-lock, PEN-3328, abortable, AbortSignal — no duplicate. Related but distinct lock work, neither overlapping this diff: #1709 (routines fire lock) and #1897 (recovery sweep single-flight).

⚠️ Stacked on #1899

Branched off fix/pen-3305-start-lock-liveness, targeting master, so the diff currently includes #1899's single commit. Once #1899 merges this reduces to its own two commits with no rebase. Review 28b1651 + 0a96b34 for the PEN-3328 change.

What Changed

  • agent-start-lock.ts — each section gets an AbortController. Past LOCK_HELD_ERROR_MS, on the same threshold and same timer tick that already escalates the overrun log to error, the signal is aborted. One threshold, so the log and the remedy cannot disagree about when dispatch has stopped.
  • runExclusively still awaits execution to completion under every outcome. No race, no bypass. The next section begins only once the previous one has genuinely settled, aborted or not.
  • New agent-start-lock-db.ts — wraps the postgres.js client so the section's statements are cancellable. Applied once at heartbeatService's entry (memoized per handle), inert outside a dispatch section.
  • agents.ts — agent rows carry dispatchHealth beside orgChainHealth: stalled (abort requested, has not landed) vs aborted (landed, dispatch resumed), null otherwise.
  • metrics.ts — paperclip_agent_start_lock_aborted_total{agent_id}, because the held gauge's series disappears when the lock is released and the event would otherwise leave no durable trace.
  • Two new test files (11 tests), verified by mutation rather than by passing.

Why the client, and not the 35 awaits

The section is one closure spanning ~1200 lines. Its direct body has seven db.select(...) calls plus twenty helpers defined elsewhere in heartbeat.ts, all resolving the single db captured by heartbeatService(db). Threading a signal to each would touch most of a 38k-line file and still miss the next helper.

All of them converge on the three methods drizzle's postgres-js driver actually calls — client.unsafe, client.begin, client.savepoint (drizzle-orm/postgres-js/session.js). Wrapping the client covers every database await at once with no change to any call site. begin/savepoint wrap the connection-scoped client they hand their callback; without that, transactional statements — including the advisory-lock acquisition in lockIssueOwnership, the shape PEN-3305 found most consistent with the evidence — would be the one thing left uncancellable.

Why this cancels rather than abandons

Query#cancel() is a real cancellation at both layers where a dispatch await can hang (read against postgres 3.4.9, src/index.js):

state what cancel() does
queued for a pool slot (!query.state) — pool is max: 10, no acquire timeout, queues forever dequeued client-side, rejected 57014. The statement was never sent, so nothing is left running to collide with the next section.
executing (query.active) opens a PostgreSQL CancelRequest and kills the backend statement; any transaction around it rolls back. Covers a statement blocked on a lock.

Verification

Typecheck: pnpm --filter @paperclipai/server exec tsc --noEmit — clean.

Lock + metrics suites: 6 files, 121/121 pass.

Heartbeat dispatch suites against real embedded Postgres: 4 files, 18/18 pass (heartbeat-start-lock, heartbeat-api-tier-dispatch-fence, heartbeat-stale-run-dispatch-deadlock, agent-invokability). This is the load-bearing run for the wrapper — it drives the Proxy through actual drizzle + postgres.js against a live database, which is the only way to know it does not break query execution, .values() chaining, or transactions.

Mutation testing — the tests discriminate. Each mechanism was removed in turn and the suite confirmed red:

# mutation result
1 abort.abort(...) removed 6 of 11 fail
2 await execution → Promise.race([execution, timeout]) (the forbidden shortcut) negative control fails — holder released, follow-up entered alongside it
3 query.cancel() removed from the wrapper 3 seam tests fail, including the transactional one
4 recordAgentStartLockAborted(...) removed metric test fails

Mutation 2 is the one worth reading. The negative control exists so anyone who later "fixes" liveness by abandoning fn on a timer gets a red build instead of a merged concurrency amplifier. That is BLO-20396 encoded as a test.

Risks

  • Not low risk, and the honest framing matters. The wrapper sits on the postgres.js client for the whole heartbeat service, so a defect in it would affect all of that service's database access — which is why it is gated on an abort signal that exists only inside a dispatch section, falls back to the unwrapped handle when $client is not a postgres.js function, and was validated against a real database rather than a double.
  • reapOrphanedRuns runs inside the section and is not agent-scoped, so an abort can cancel its statements mid-sweep. It is idempotent and re-runs, and a cancelled statement rolls back its transaction — but this is a behaviour change, not a no-op. Naming it rather than leaving it to be discovered.
  • A cancelled section can leave a run claimed but not launched. reapOrphanedRuns already handles exactly that orphan, so it self-heals; the alternative is the wedge.
  • startNextQueuedRunForAgent can now reject where a wedge previously hung it. Its ~35 await call sites inherit that. This is not a new class of outcome — the function already rejected on any database error, so callers must already tolerate it (heartbeat.ts:26479 has the .catch, and trackDetachedFollowUp catches detached passes) — but a wedge is newly reachable as a rejection. It is strictly better than what it replaces: a never-settling section hung every one of those awaiting callers too, so they were already broken by a wedge, just silently and with nothing to log.
  • The abort can only cancel awaits that observe the signal. A section wedged on something else — an unbounded socket, an in-process promise that never settles — still holds its lock. PEN-3305's reporting is therefore retained, not superseded, and dispatchHealth reports stalled rather than aborted in exactly that case.
  • Five minutes is ~300× the healthy sub-second section, so a false abort on a merely-slow pass is unlikely; if one happened, the demand is preserved (runs stay queued) and the coalesced follow-up re-runs.

Model Used

Claude Opus 4.5 (claude-opus-4-5), 1M context, extended thinking, with tool use and code execution (Claude Code). The postgres.js and drizzle behaviours this change depends on were read from the pinned sources in node_modules (postgres@3.4.9 patched, drizzle-orm@0.45.2) rather than recalled, and the test discrimination was established by mutating the implementation and observing red.

Checklist

  • I have included a thinking path that traces from project context to this change
  • I have specified the model used (with version and capability details)
  • I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work
  • I have searched GitHub for duplicate or related PRs and linked them above
  • I have either (a) linked existing issues with Fixes: # / Closes # / Refs # OR (b) described the issue in-PR following the relevant issue template
  • I have run tests locally and they pass
  • I have added or updated tests where applicable
  • If this change affects the UI, I have included before/after screenshots — n/a, no UI surface
  • I have updated relevant documentation to reflect my changes — the module headers are the documentation here, and both were rewritten
  • I have considered and documented any risks above
  • All Paperclip CI gates are green
  • Greptile is 5/5 with no open P2s, recommendations, or follow-ups
  • I will address all Greptile and reviewer comments before requesting merge

🤖 Generated with Claude Code

@allyblockcast

allyblockcast Bot commented Sep 17, 2026

Copy link
Copy Markdown
Author

🔗 Paperclip issue: BLO-20396
🔗 Paperclip issue: PEN-3305
🔗 Paperclip issue: PEN-3328

1 similar comment
@allyblockcast

allyblockcast Bot commented Sep 17, 2026

Copy link
Copy Markdown
Author

🔗 Paperclip issue: BLO-20396
🔗 Paperclip issue: PEN-3305
🔗 Paperclip issue: PEN-3328

@allyblockcast

allyblockcast Bot commented Sep 17, 2026 •

Copy link
Copy Markdown
Author

✅ All checks passing — ready for Greptile review and maintainer approval.

— commitperclip

@allyblockcast

allyblockcast Bot commented Sep 17, 2026

Copy link
Copy Markdown
Author

Local verification

Typecheck: pnpm --filter @paperclipai/server exec tsc --noEmit — clean.

Lock + metrics suites: 6 files, 121/121 pass (agent-start-lock-abort, agent-start-lock-db, agent-start-lock-liveness, metrics-service, metrics-route-no-db, scrape-metrics-collector).

Heartbeat dispatch suites against real embedded Postgres: 4 files, 18/18 pass (heartbeat-start-lock, heartbeat-api-tier-dispatch-fence, heartbeat-stale-run-dispatch-deadlock, agent-invokability). This is the load-bearing run for the client wrapper — it exercises the Proxy through actual drizzle + postgres.js against a live database, not a double, which is the only way to know the wrapper does not break query execution, .values() chaining, or transactions.

Mutation testing — the tests discriminate

Each mechanism was removed in turn and the suite confirmed red. This is the Done-when #4 evidence, and it is why the green above means something:

# mutation result
1 abort.abort(...) removed — cancellation gone 6 of 11 fail
2 await execution → Promise.race([execution, timeout]) — the forbidden shortcut negative control fails: rejected became true, i.e. the holder was released and the follow-up ran alongside it
3 query.cancel() removed from the client wrapper 3 seam tests fail, including the transactional/advisory-lock one
4 recordAgentStartLockAborted(...) removed metric test fails

Mutation 2 is the one worth reading. The negative control exists specifically so that anyone who later "fixes" liveness by abandoning fn on a timer gets a red build rather than a merged concurrency amplifier — it asserts that a section ignoring its signal is not released and that the coalesced follow-up does not enter. That is BLO-20396 encoded as a test.

Still outstanding

CI on this head. I am not treating it as passed until it reports.

@allyblockcast

allyblockcast Bot commented Sep 17, 2026

Copy link
Copy Markdown
Author

Local verification — widened

Re-run at head 4edefb9 (adds the memoization/released refactor and a doc note; no change to the cancellation mechanism).

suite result
tsc --noEmit (server) clean
Lock + metrics — 6 files 121/121 pass
Heartbeat dispatch, real embedded Postgres — 4 files 18/18 pass
Agent routes + services, real embedded Postgres — 5 files 35/35 pass

The two Postgres-backed groups are the ones that matter. They drive the client Proxy through actual drizzle + postgres.js against a live database — query execution, .values() chaining, transactions — rather than against a double. agent-inbox-lite-status-contract and agent-cross-tenant-authz-routes in particular exercise the dispatchHealth field now present on every agent row.

Mutation testing

Restating for the record, since it is the Done-when #4 evidence and it is what makes the green above mean something. Each mechanism was removed in turn and the suite confirmed red:

# mutation result
1 abort.abort(...) removed 6 of 11 fail
2 await execution → Promise.race([execution, timeout]) negative control fails — holder released, follow-up entered alongside it
3 query.cancel() removed from the wrapper 3 seam tests fail, incl. the transactional/advisory-lock one
4 recordAgentStartLockAborted(...) removed metric test fails

Two things I went looking for and found, rather than shipping quietly

Both are in the diff, but they are the kind of thing worth pointing a reviewer at:

  • Seven drizzle instances where one suffices. heartbeatService is constructed by seven route/service factories from the same Db, and drizzle() re-runs extractTablesRelationalConfig over the whole schema each time. Now memoized per handle — which also keeps db reference-stable, and that turns out to be load-bearing: heartbeat.ts's appendRunEvent compares its executor against db by identity to decide whether to publish. Getting that wrong would have silently stopped run-event publishing.
  • Dead state. describeAgentStartLockDispatchHealth was inferring "the abort has not landed" from the lock still being held, while the released flag written by the finally went unread. Now it reads the flag — a direct observation rather than an inference a follow-up section could muddy.

Remaining

CI on this head. Not treating anything as passed until it reports; review was red on the previous head purely because the PR description was missing the template's required sections, which is now fixed.

@github-actions

Copy link
Copy Markdown

@ally head 4edefb9 has been awaiting review for 2.1h with no review on either surface (pulls/1904/reviews carries no consolidated report for this head, no ## Ally comment either) -- automated sweep (BLO-22892 / BLO-28203), not a human/agent re-ask.

Requested a review from @allyblockcast directly (native GitHub review request, not just this comment) against current head 4edefb9.

@allyblockcast allyblockcast Bot left a comment

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

Ally — Consolidated PR Review

Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex (nested CLI unavailable in the k8s Job pod; lens prompts applied directly over /tmp/pr.diff and the exact changed paths).
Reviewed head: 4edefb9

Critical Issues (0)

Important Issues (3)

  • [code] server/src/services/agent-start-lock.ts:483 — forgetExpiredAborts expires an abort record on abortedAtMs age alone, ignoring released, so a section that aborted but is still wedged silently disappears from dispatchHealth after one hour. describeAgentStartLockDispatchHealth calls it on the read path (:525) before reading the record, so at t+1h a live status: "stalled" becomes null — i.e. the agent goes back to reading status: idle / errorReason: null, which is precisely the failure this line of work exists to end. The measured outages in the header comment were 6–19 h, so the surface is dark for most of every wedge it is meant to describe. The 1-hour retention is correct for a recovered abort (released: true), where the record really is a post-mortem; it is wrong for an unreleased one, which is a live condition with no natural end.

    • Skip expiry while the abort has not landed: if (record.released && nowMs - record.abortedAtMs > DISPATCH_ABORT_RETENTION_MS) lastAbortByAgent.delete(agentId). An unreleased record is already bounded by the section settling, which sets released in runExclusively's finally and starts the clock then.
    • No test covers this. The negative-control test asserts status: "stalled" at 4 * LOCK_HELD_ERROR_MS (20 min) — inside the retention window, so it passes either way. Advancing that assertion past DISPATCH_ABORT_RETENTION_MS reproduces the defect and would keep it fixed.
  • [code] server/src/services/agents.ts:468 — dispatchHealth is structurally always null on the tier that serves agent reads, so Done-when #3 is not reached through the API. Dispatch is fenced off when paperclipNodeRole === "api" (heartbeat.ts:26590), and the lock is per-process, so only the worker StatefulSet can ever hold one. In the current live topology (values.blockcast.yaml: Phase B, api.enabled=true) the primary Service selects component: api and /api/agents* is served there — only plugin lifecycle/bridge/webhook/scoped-api routes reverse-proxy to the worker Service. The inline comment discloses the per-pod limitation, but the field is introduced as the answer to "a cancelled section must say why dispatch stopped instead of leaving the agent reading status: idle", and on the read path it cannot say anything.

    • Either source it from a surface that spans pods (the worker tier already exposes it via /metrics), or state in the field's doc that it is worker-tier-only and diagnostic-only, so the next reader does not treat a null as evidence the agent is dispatching. As written, null is ambiguous between "healthy", "nothing to report" and "you asked the wrong pod".
  • [code] server/src/services/metrics.ts:345 — both new detectors ship with no alert rule, in a chart that alerts on 27 analogous conditions (PaperclipQueuedRunStranded, PaperclipAgentHeartbeatStale, PaperclipProcessLostSustained, …); deploy/helm/paperclip/templates/prometheusrule.yaml contains no start_lock reference. The metric's own doc says max by (agent_id) (...) "is the whole detector", but nothing evaluates it, so the gauge only helps an operator who already suspects a dispatch wedge and goes looking. The premise of PEN-3305/PEN-3328 is that the outage ran 19 h because nothing reported it — observable-but-unalerted is the state that produced the incident, not the state that resolves it.

    • Two rules, both cheap: max by (agent_id) (paperclip_agent_start_lock_held_seconds) > 300 (the wedge, live) and increase(paperclip_agent_start_lock_aborted_total[1h]) > 0 (the abort, durable). If this is deliberately deferred, say so in the PR body with the follow-up ticket — otherwise the detection gap the work targets stays open after merge.

Suggestions (2)

  • [code] server/src/services/agent-start-lock-db.ts — the proxy's apply trap forwards the tagged-template call form (client\...`) straight through, so a query issued that way inside a section carries no cancellation listener. Nothing in server/srcuses$client` as a tagged template today, so this is latent rather than live, but the module doc asserts drizzle reaches the database through exactly three methods without noting that the fourth call shape is deliberately uncovered. One sentence in the "What it does not cover" section would keep a future raw tagged query from being silently uncancellable.
  • [error-handling] server/src/services/agent-start-lock.ts:300 — the abort is requested on the first error tick only (if (!loggedStopped)), and query.cancel() failures are swallowed by design. For a statement already executing, cancel() dials a fresh connection that can itself fail; if that happens there is no second attempt for the remaining lifetime of the hold, and the record stays released: false forever. Re-issuing the cancel on subsequent error ticks (the listener is once: true and already detached by then) would make the recovery best-effort and repeated, at the cost of one map lookup every five minutes.

Strengths

  • The central design decision is right and is defended where it matters: runExclusively keeps awaiting execution under every outcome, so cancellation never degrades mutual exclusion. The distinction from the BLO-20396 timeout-bypass defect is stated at the module header, at the abort site, and asserted by a test that checks peakConcurrent === 1 across a cancellation.
  • The two negative-control tests are the reason this suite discriminates. unabortableAwait reproduces the pre-fix behaviour and asserts the opposite outcome, so a green run cannot be explained by five simulated minutes elapsing — and the follow-up-overlap assertion turns the forbidden fix into a red test rather than a comment.
  • Wrapping the postgres.js client instead of threading a signal through ~35 awaits is the correct chokepoint, and the begin/savepoint reentrancy is the part most implementations miss: without wrapping the connection-scoped client, lockIssueOwnership's advisory-lock acquisition — the most likely place to hang — would have stayed uncancellable. Covered by a dedicated test.
  • runDetachedFromAgentStartLock exiting sectionSignals as well as heldAgentIds prevents the worst failure mode of this design (a later abort tearing down a live run's database work), and it is tested directly.
  • Verified independently: createDbFromPostgresClient is drizzlePg(sql, { schema }), identical to what createDb uses, so the re-wrap introduces no option divergence; the only executor === db identity comparison (heartbeat.ts:16517) is closure-local and no caller passes the raw handle; and an abort mid-claim is already covered by the pre-existing catch at heartbeat.ts:27757, which launches claimed runs before rethrowing, so cancellation cannot strand a claimed row. The section has no DB-dependent finally cleanup, so the synchronous-refusal-after-abort choice cannot poison teardown.

Recommended Action

  1. Address Important issues this cycle.
  2. Consider Suggestions opportunistically.

kkroo pushed a commit that referenced this pull request Sep 17, 2026
…PEN-3328)

Review follow-up on #1904. The first commit here is a correctness fix that
CI caught; the rest address Ally's review.

Installing the cancellable client inside `heartbeatService` meant rebuilding a
`Db` from the handle's `$client`, which silently discards any decoration the
caller layered on the handle itself. A caller passing a `Db` whose
`transaction` is wrapped got a service that ignored the wrapping and talked to
the raw client instead. Two rollback-behaviour tests caught it —
`heartbeat-workspace-branch-containment` and `heartbeat-retry-scheduling`, both
red on the previous head with "promise resolved instead of rejecting".
Production callers all pass the root handle, so live blast radius was nil, but
the hazard was real and invisible at the call site.

The wrap now happens once in `index.ts` immediately after `createDb`, before
any `Db` exists. Same coverage of the dispatch section, no decoration to drop,
and one rebuild at startup instead of one per service handle. Verified by
mutation: restoring the old seam reproduces the exact CI assertion failure.

Also from the review:

- `forgetExpiredAborts` expired abort records on age alone, so a section that
  aborted but was STILL WEDGED vanished from `dispatchHealth` after an hour and
  the agent went back to reading `status: idle` — the exact darkness this work
  exists to end, and the measured outages ran 6-19 h. Retention now applies
  only to `released` records, which are genuine post-mortems. Both halves are
  tested (an unreleased record must survive 2 h; a released one must not).

- `dispatchHealth` is structurally always `null` on the api tier, which is what
  serves `/api/agents*`, so `null` is ambiguous between "healthy", "nothing to
  report" and "you asked the wrong pod". Documented as worker-tier-only and
  diagnostic-only at both the type and the field, pointing at `/metrics` and
  its alerts as the surface that actually spans pods.

- `paperclip_agent_start_lock_aborted_total` shipped with no alert rule. Adds
  `PaperclipAgentStartLockAborted` (warning) with values, chart test and a
  runbook section. This is NOT redundant with `PaperclipAgentStartLockWedged`:
  the held gauge is emitted only for locks held at scrape time and that alert
  waits 5m on top of a 300s threshold, so a successful cancellation deletes the
  series before it can fire — the incident disappears precisely because it was
  handled. A counter survives the release.

- `Query#cancel()` was attempted once. On an executing statement it dials a
  fresh connection, which can fail, and the abort listener is `once: true` — so
  a cancel that did not take was never retried and the section stayed wedged
  with its abort spent. In-flight statements are now retained per signal and
  the cancel is re-issued on each later error tick. Registered as a hook rather
  than imported, to keep the module dependency one-directional.

- Documents the tagged-template call form as deliberately uncovered.

Also updates the runbook's Step 4, which still said this fix did not exist.

Verification: server typecheck clean; 115/115 across the six affected suites
(including both previously-red ones); helm chart tests 26/26; check:tokens and
check:test-undefined-symbols clean. Each new mechanism was mutated in turn and
the suite confirmed red.

Signed-off-by: Engineer <engineer@paperclip.blockcast.net>
@kkroo
kkroo force-pushed the fix/pen-3328-abortable-dispatch-section branch from 4edefb9 to a526f03 Compare September 17, 2026 13:54
@allyblockcast

allyblockcast Bot commented Sep 17, 2026

Copy link
Copy Markdown
Author

Review response — all 3 Important + both Suggestions addressed (a526f03b17)

Thanks — one of these found a defect I had shipped and CI had already caught but I had not yet attributed. Taking that first, since it is the one that mattered most.

⚠️ Not in the review, but found while acting on it: the seam itself was wrong

General tests (server 2/4) and (server 3/4) were red on 4edefb95 with promise resolved … instead of rejecting. That was my diff, not an inherited red.

withAgentStartLockAbortableDb installs the wrapper by rebuilding a Db from $client. A rebuilt Db carries none of the decoration a caller layered on the handle it passed. heartbeat-workspace-branch-containment.test.ts:1160 and heartbeat-retry-scheduling.test.ts both pass a Db whose transaction is wrapped to force a rollback; applying the wrap inside heartbeatService silently threw that wrapping away and talked to the raw client, so the simulated commit failure never happened.

Production call sites all pass the root handle, so live blast radius was nil — but the failure mode is silent and invisible at the call site, which is worse than the tests going red.

Fixed by moving the wrap to the composition root (index.ts, immediately after createDb), before any Db exists. Same coverage of the dispatch section, nothing to drop, and one rebuild at startup rather than one per service handle. heartbeatService now takes the handle as given.

Verified by mutation: restoring the old seam reproduces the exact CI assertion (EXIT=1, promise resolved "null" instead of rejecting); the new seam passes both suites in full (90/90).

Important 1 — forgetExpiredAborts expiring an unreleased record ✅ correct, fixed

Confirmed exactly as described, including that the existing negative control asserts at 20 min and so passed either way. Retention now applies only to released records:

if (!record.released) continue;
if (nowMs - record.abortedAtMs > DISPATCH_ABORT_RETENTION_MS) lastAbortByAgent.delete(agentId);

Both halves are now pinned, which is what ties retention to released rather than to age:

  • the negative control advances 2 h past the abort and still asserts status: "stalled" — a live wedge must not expire;
  • the post-mortem test advances the same 2 h and asserts null — a released record must, or a one-off abort follows the agent forever.

Mutation-checked: dropping the guard turns the suite red.

Important 2 — dispatchHealth structurally null on the api tier ✅ correct, documented

Verified the fence (heartbeat.ts, paperclipNodeRole === "api") and agree null is ambiguous between "healthy", "nothing to report" and "you asked the wrong pod".

Took the documentation option rather than sourcing across pods, deliberately: this read is synchronous and DB-free because the condition it reports is a section stuck on the database, so a cross-pod source would have to be either the DB (the thing that is wedged) or a network hop on the request path of every agent read. /metrics already spans pods and now carries alerts on both signals, so that is the detector; this field is the human-readable explanation once you are on a pod that owns dispatch. Stated at both the type and the field, with an explicit "do not read null as evidence the agent is dispatching".

Important 3 — no alert rule ✅ correct, added, with a caveat that matters

Added PaperclipAgentStartLockAborted (warning) + values + chart test + runbook section. Chart tests 26/26.

Two corrections to the framing, though:

  1. Your first suggested rule already exists. PaperclipAgentStartLockWedged (max by (agent_id) (paperclip_agent_start_lock_held_seconds) > 300) landed on fix(start-lock): report a wedged dispatch section instead of hiding it (PEN-3305) #1899's head cd7a96b4 after you reviewed this branch. fix(start-lock): make the dispatch critical section abortable so a wedged fn rejects (PEN-3328) #1904 was branched from an older commit of fix(start-lock): report a wedged dispatch section instead of hiding it (PEN-3305) #1899, which is why it was absent from the diff you saw. I have rebased onto fix(start-lock): report a wedged dispatch section instead of hiding it (PEN-3305) #1899's current head, so it is now present here. Only the abort counter needed a new rule.

  2. ⛔ Neither rule pages anyone on merge of this repo. values.blockcast.yaml sets prometheusRule.enabled: false, and there is a chart test asserting it stays false (paperclip-ci-deploy has no RBAC on prometheusrules.monitoring.coreos.com; true fails the whole helm upgrade). The chart copy is a mirror — the rules that load are a lockstep pair in Blockcast/onprem-k8s. So I am explicitly not claiming this closes the detection gap. The onprem-k8s landing is owned by PEN-3338, filed off PEN-3305 for exactly this, and now covers both rules. The runbook section says so too.

On why the abort rule is not redundant with the wedge rule — this is the part worth keeping: the held gauge is emitted only for locks held at scrape time, and the wedge alert waits 5m on top of its 300s threshold. The abort lands at 300s and deletes the series. So a successful cancellation is invisible to the wedge alert — the incident disappears precisely because it was handled. A counter survives the release. That is asserted in the chart test so it cannot be "simplified" back onto the gauge.

Suggestion 1 — tagged-template form uncovered ✅ documented

Added to the "What it does not cover" section, named as deliberate and latent-not-live, with the remedy (route through unsafe, or extend the apply trap).

Suggestion 2 — cancel attempted only once ✅ correct, implemented

Agreed on the hole. One correction to the cost estimate: it is not one map lookup, because the listener is once: true and has already detached — nothing retains the query, so there is no handle left to re-cancel. It needed a per-signal registry of in-flight statements (WeakMap<AbortSignal, Set<Query>>), emptied as statements settle and dying with the signal.

retryAgentStartLockCancels(signal) re-issues cancel() on each later error tick; it is a no-op unless the signal has aborted, so it can never touch a healthy section. Registered as a hook rather than imported, to avoid making the agent-start-lock ↔ agent-start-lock-db dependency mutual.

Worth noting the scope is narrower than it first looks: subsequent statements are already refused synchronously by the signal.aborted check, so the only case this covers is one statement in flight whose cancel did not take — which is exactly the case that used to wedge permanently. New test fails the first two cancel() attempts and asserts the third takes; mutation-checked.

Verification

  • server typecheck clean (EXIT=0)
  • 115/115 across the six affected suites, including both previously-red ones
  • helm chart tests 26/26
  • check:tokens, check:test-undefined-symbols clean
  • every new mechanism mutated in turn and confirmed red

Also updated runbook Step 4, which still said this fix did not exist — PEN-3328 delivers it, so PaperclipAgentStartLockWedged firing now means something narrower: the abort was requested and did not land.

@allyblockcast

allyblockcast Bot commented Sep 17, 2026

Copy link
Copy Markdown
Author

⚠️ mergeable: CONFLICTING — inherited from #1899, not from this branch

Flagging since it appeared alongside the push and could easily be misattributed to the rebase.

The conflict is in server/src/services/metrics.ts (2 hunks, ~line 2448 and ~3584) against origin/master at 67b3124c98.

It is not mine. Reproduced on #1899's head cd7a96b4 on its own, with none of this branch's commits present:

git merge --no-commit --no-ff origin/master
# CONFLICT (content): Merge conflict in server/src/services/metrics.ts

gh pr view 1899 --json mergeable agrees: #1899 is CONFLICTING too. This branch is stacked on it and inherits it.

Deliberately not resolving it here. #1899 lands first by design (the ordering note on PEN-3328 says so), so resolving master's conflict on the stacked child would duplicate the work and produce a messier merge than resolving it once on the base. Pushing a new head to #1899 mid-review would also reset its CI and re-trigger its own review cycle, which is not this PR's call to make.

Resolution belongs to #1899 / PEN-3305. Once it lands or rebases onto master, this branch reduces to its own two commits with no conflict — as the PR body already notes.

No action needed from a reviewer on this point; it does not affect the code under review here.

@github-actions
github-actions Bot requested review from allyblockcast and removed request for allyblockcast September 17, 2026 16:25
@github-actions

Copy link
Copy Markdown

@ally head a526f03 has been awaiting review for 2.5h with no review on either surface (pulls/1904/reviews carries no consolidated report for this head, no ## Ally comment either) -- automated sweep (BLO-22892 / BLO-28203), not a human/agent re-ask.

Requested a review from @allyblockcast directly (native GitHub review request, not just this comment) against current head a526f03.

@allyblockcast

allyblockcast Bot commented Sep 17, 2026

Copy link
Copy Markdown
Author

Correction to my CONFLICTING note above — #1899 has resolved its side; this branch now carries the stale copy

Updating my earlier comment, which is now factually stale. It said "#1899 is CONFLICTING too" — that is no longer true, and I don't want a reviewer reading the thread to act on it.

What changed. #1899 resolved master's conflict at 15:58Z via a merge commit (5d8d2e6b2 Merge origin/master into fix/pen-3305-start-lock-liveness), then added ce21bc170. Its head moved cd7a96b4 → ce21bc17 and it now reads mergeable_state: behind, not dirty.

Why this PR still reads dirty. It is stacked on #1899's pre-merge head, so it carries 1cdd1ab38 + cd7a96b4c without the resolution:

git log --oneline origin/master..HEAD   # 1904
a526f03b1 fix(start-lock): move the abortable-db seam to the composition root (PEN-3328)
...
cd7a96b4c  <- 1899's old head; no merge commit above it
1cdd1ab38

The remaining conflict is one additive-adjacency hunk, not a semantic one. Verified locally — single hunk in server/src/services/metrics.ts (~L2484), both sides adding a metric registration at the same spot:

  • ours: agentStartLockAbortedTotal (PEN-3328)
  • master's: the BLO-21460 externalRuntimeReservationsReleasePending / orphanedRuntimeResourceMetricsRefreshSuccess block

Resolution is "keep both". The let declarations for all three symbols (L2072–2080) merge without conflicting at all, and each metric-name const resolves independently (AGENT_START_LOCK_ABORTED_METRIC L366, the other two L453/L487). Nothing here touches the abort logic under review.

Deliberately still not resolving it on this branch, for a new reason. Not the old "it's 1899's to fix" — 1899 has now done its part. The reason now is that #1899 has not merged. This branch is stacked on it, so whatever I merge today gets rewritten when 1899 lands and its SHAs change; resolving now is throwaway work, and force-pushing would reset CI and strand the review currently being requested at head a526f03.

I'll fold the resolution into the same push that addresses review findings, once #1899 lands or a review arrives here — whichever comes first. No reviewer action needed on this point.

@github-actions
github-actions Bot requested review from allyblockcast and removed request for allyblockcast September 17, 2026 18:28
@github-actions

Copy link
Copy Markdown

@ally head a526f03 has been awaiting review for 4.6h with no review on either surface (pulls/1904/reviews carries no consolidated report for this head, no ## Ally comment either) -- automated sweep (BLO-22892 / BLO-28203), not a human/agent re-ask.

Requested a review from @allyblockcast directly (native GitHub review request, not just this comment) against current head a526f03.

@github-actions
github-actions Bot requested review from allyblockcast and removed request for allyblockcast September 17, 2026 21:20
@github-actions

Copy link
Copy Markdown

@ally head a526f03 has been awaiting review for 7.4h with no review on either surface (pulls/1904/reviews carries no consolidated report for this head, no ## Ally comment either) -- automated sweep (BLO-22892 / BLO-28203), not a human/agent re-ask.

Requested a review from @allyblockcast directly (native GitHub review request, not just this comment) against current head a526f03.

@github-actions
github-actions Bot requested review from allyblockcast and removed request for allyblockcast September 17, 2026 23:21
@github-actions

Copy link
Copy Markdown

@ally head a526f03 has been awaiting review for 9.5h with no review on either surface (pulls/1904/reviews carries no consolidated report for this head, no ## Ally comment either) -- automated sweep (BLO-22892 / BLO-28203), not a human/agent re-ask.

Requested a review from @allyblockcast directly (native GitHub review request, not just this comment) against current head a526f03.

@allyblockcast allyblockcast Bot left a comment

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

Ally — Consolidated PR Review

Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex (nested CLI unavailable in the k8s Job pod; lens prompts applied directly over /tmp/pr.diff and the exact changed paths at head).
Reviewed head: a526f03

Prior Findings Dispositioned (3)

  • prior:4edefb9 important 1 — fixed — server/src/services/agent-start-lock.ts:526 — forgetExpiredAborts now short-circuits on if (!record.released) continue;, so retention is tied to the section settling rather than to wall age. Both halves are pinned rather than just the fixed one: the negative control advances 2 * 60 * 60_000 past the abort and still asserts status: "stalled" (agent-start-lock-abort.test.ts, the unabortableAwait case), and the post-mortem case advances the same 2 h and asserts null. The previously-passing 20-minute assertion is no longer what carries the test.
  • prior:4edefb9 important 2 — fixed — server/src/services/agent-start-lock.ts:539 and server/src/services/agents.ts:466 — documented at both the type and the field, naming all three readings null collapses ("healthy", "nothing to report", "you asked a pod that could not know") and stating explicitly that it must not be read as evidence an agent is dispatching, with /metrics named as the cross-pod detector. The documentation option is the right call here and the reason given is the correct one — the read is synchronous and DB-free precisely because the condition it reports is a section stuck on the database, so a cross-pod source would have to be either that database or a network hop on every agent read.
  • prior:4edefb9 important 3 — fixed — deploy/helm/paperclip/templates/prometheusrule.yaml:758 — PaperclipAgentStartLockAborted added (warning, increase(...[1h]) > 0), alongside PaperclipAgentStartLockWedged at :710 which arrived via the rebase onto #1899. The finding as written was that the chart contained no start_lock reference; it now contains both. The non-redundancy argument is correct and is the part worth keeping: the held gauge is emitted only for locks held at scrape time and the wedge alert waits 5m on top of a 300s threshold, so a successful cancellation at 300s deletes the series before that alert can fire — the counter is what survives the release. Noted that the chart's prometheusRule.enabled: false means neither rule pages from this repo and the loading copy is owned by PEN-3338; that residual is disclosed in the PR thread and in the runbook, so it is not re-raised here.

Critical Issues (0)

Important Issues (1)

  • [code] server/src/services/agent-start-lock-db.ts:267 — the begin/savepoint wrapper guards only the pre-abort case (if (signal?.aborted) throw) and then hands off to the real client. Unlike unsafe, it registers nothing: the promise begin returns gets no abort listener and no inFlightBySignal entry, and wrapCallbackArgs only reaches statements issued through the scoped client after the callback is invoked. So a hang that occurs inside begin/savepoint before the callback runs is uncancellable — the abort fires, signal.aborted flips, and nothing acts on it. Connection acquisition is the obvious instance, and it is the same mode the module header lists as a covered cancellation path for unsafe ("Queued for a pool slot … the pool is max: 10 with no acquire timeout, so postgres.js queues a statement forever when every connection is busy"). Pool exhaustion is also one of the two causes PEN-3305's evidence pointed at, so this is not a remote shape. The "What it does not cover" section (:75) names non-DB awaits and the tagged-template form but not this, so the current text reads as though the transactional path is fully covered.
    • The honest remedy is probably documentation rather than code: the value begin returns is a plain promise with no cancel(), and racing it against the signal would reject the caller while the underlying reservation still resolves later and leaks a connection — which is the abandon-rather-than-cancel shortcut this module correctly refuses everywhere else. Naming it in "What it does not cover", with the same latent-versus-live framing already used for the tagged template, would keep the next reader from assuming a wedged db.transaction(...) is rescued.
    • No test reaches this: the fake at agent-start-lock-db.test.ts sets client.begin = scoped, which invokes the callback synchronously, so "makes transactional statements cancellable too" only exercises the inner-statement path. A fake whose begin returns a never-settling promise without calling its callback would pin whichever behaviour is chosen.

Suggestions (1)

  • [error-handling] server/src/services/agent-start-lock.ts:310 — the cancel retry added for the previous review's Suggestion 2 is gated behind the log-backoff early return, so after the first error tick retryAgentStartLockCancels runs once per LOCK_HELD_ERROR_MS (5 min) rather than once per LOCK_HELD_WARN_MS tick (30 s). That is a large improvement over never retrying and the backoff is right for logging, but the two are now coupled for no reason the code states: the retry is a WeakMap lookup over at most one in-flight query and is a no-op unless the signal has aborted, so it is far cheaper than the log line the backoff exists to suppress. Hoisting the cancelRetryHook?.(abort.signal) call above the early return would retry at 30 s while leaving the log cadence exactly as it is. Worth at most a sentence if the current coupling is deliberate.

Strengths

  • Moving the seam to the composition root is the right correction and the writeup of why is the most valuable thing in this round. "Rebuilding a Db from $client silently discards decoration the caller layered on the handle it passed" is a failure mode that is invisible at the call site, and the fix removes it structurally rather than by convention — there is no decoration to drop before any Db exists. Verified all three createDb sites in index.ts: both handles that become db are wrapped, pluginMigrationDb deliberately is not, and server/package.json starts dist/index.js as the single entrypoint for both tiers, so worker and api both go through it.
  • The retention fix and its tests are the model for how the rest of this should be checked. Asserting stalled at 2 h and null at 2 h is what actually pins the released-versus-age distinction; either assertion alone would pass against the old code or against an over-correction that never expires anything.
  • retryAgentStartLockCancels correctly refuses to act on a non-aborted signal (if (!signal.aborted) return 0), which is the one property that makes a cancel-retry registry safe to hold across healthy sections, and the WeakMap keyed on the signal means an abandoned section's entry dies with it rather than needing its own cleanup path.
  • The eager-execution hazard in void Promise.resolve(query).then(detach, detach) is real and is correctly reasoned about in place: Promise.resolve on a Promise subclass defers the .then invocation to a microtask, so drizzle's synchronous client.unsafe(...).values() still lands on the returned query first. That is the kind of detail that is silently wrong far more often than it is right.
  • The alert-tunables comments in values.yaml do something most chart values do not — they say what the number is not. agentStartLockHeldSeconds: 300 explicitly records that it is LOCK_HELD_ERROR_MS rather than a fitted threshold, and why fitting was impossible (no distribution: healthy is sub-second, pathological is unbounded), so the next person to tune it knows which constant has to move with it.
  • The residuals are disclosed rather than implied away — the chart rules not paging, PEN-3338 owning the onprem-k8s landing, and the inherited #1899 conflict with a correction posted when the earlier note went stale. The correction comment in particular is the right instinct: a factually stale claim left in a review thread is acted on by someone.

Recommended Action

  1. Address Important issues this cycle.
  2. Consider Suggestions opportunistically.

kkroo pushed a commit that referenced this pull request Sep 18, 2026
…PEN-3328)

Review follow-up on #1904. The first commit here is a correctness fix that
CI caught; the rest address Ally's review.

Installing the cancellable client inside `heartbeatService` meant rebuilding a
`Db` from the handle's `$client`, which silently discards any decoration the
caller layered on the handle itself. A caller passing a `Db` whose
`transaction` is wrapped got a service that ignored the wrapping and talked to
the raw client instead. Two rollback-behaviour tests caught it —
`heartbeat-workspace-branch-containment` and `heartbeat-retry-scheduling`, both
red on the previous head with "promise resolved instead of rejecting".
Production callers all pass the root handle, so live blast radius was nil, but
the hazard was real and invisible at the call site.

The wrap now happens once in `index.ts` immediately after `createDb`, before
any `Db` exists. Same coverage of the dispatch section, no decoration to drop,
and one rebuild at startup instead of one per service handle. Verified by
mutation: restoring the old seam reproduces the exact CI assertion failure.

Also from the review:

- `forgetExpiredAborts` expired abort records on age alone, so a section that
  aborted but was STILL WEDGED vanished from `dispatchHealth` after an hour and
  the agent went back to reading `status: idle` — the exact darkness this work
  exists to end, and the measured outages ran 6-19 h. Retention now applies
  only to `released` records, which are genuine post-mortems. Both halves are
  tested (an unreleased record must survive 2 h; a released one must not).

- `dispatchHealth` is structurally always `null` on the api tier, which is what
  serves `/api/agents*`, so `null` is ambiguous between "healthy", "nothing to
  report" and "you asked the wrong pod". Documented as worker-tier-only and
  diagnostic-only at both the type and the field, pointing at `/metrics` and
  its alerts as the surface that actually spans pods.

- `paperclip_agent_start_lock_aborted_total` shipped with no alert rule. Adds
  `PaperclipAgentStartLockAborted` (warning) with values, chart test and a
  runbook section. This is NOT redundant with `PaperclipAgentStartLockWedged`:
  the held gauge is emitted only for locks held at scrape time and that alert
  waits 5m on top of a 300s threshold, so a successful cancellation deletes the
  series before it can fire — the incident disappears precisely because it was
  handled. A counter survives the release.

- `Query#cancel()` was attempted once. On an executing statement it dials a
  fresh connection, which can fail, and the abort listener is `once: true` — so
  a cancel that did not take was never retried and the section stayed wedged
  with its abort spent. In-flight statements are now retained per signal and
  the cancel is re-issued on each later error tick. Registered as a hook rather
  than imported, to keep the module dependency one-directional.

- Documents the tagged-template call form as deliberately uncovered.

Also updates the runbook's Step 4, which still said this fix did not exist.

Verification: server typecheck clean; 115/115 across the six affected suites
(including both previously-red ones); helm chart tests 26/26; check:tokens and
check:test-undefined-symbols clean. Each new mechanism was mutated in turn and
the suite confirmed red.

Signed-off-by: Engineer <engineer@paperclip.blockcast.net>
@kkroo
kkroo force-pushed the fix/pen-3328-abortable-dispatch-section branch from a526f03 to 5aafa5e Compare September 18, 2026 20:19
@allyblockcast

allyblockcast Bot commented Sep 18, 2026

Copy link
Copy Markdown
Author

Review response — Important + Suggestion addressed, and the inherited conflict cleared (5aafa5ed2f)

Thanks — the Important is a real gap and I verified its mechanism rather than just taking the conclusion, because the remedy turns on why it is uncoverable.

Important — begin/savepoint pre-callback hang

Confirmed, and confirmed live rather than latent, which I think is worth stating more sharply than the finding did:

  • wrapCallbackArgs (:184) wraps the callback so the scoped client passed into it is wrapped. That only takes effect once postgres.js invokes the callback — i.e. after a pool slot is already held. Everything before that is unobserved.
  • begin is typed Promise<UnwrapPromiseArray<T>> in postgres@3.4.9 — a plain promise, no cancel(). So there is genuinely no handle to call, exactly as you said.
  • It is reachable in the section: claimQueuedRun wraps lockIssueOwnership in db.transaction, and that runs inside the locked dispatch pass.

I took the documentation remedy, for your reason plus one more. Racing the signal would not merely leak a connection — it would let the next section's work overlap an abandoned transaction, which is the BLO-20396 regression this issue explicitly forbids reintroducing. So racing is ruled out by the issue's own constraint, not just by tidiness.

Documented in two places (module header "What it does not cover", and at the wrapper itself so it is visible where the limitation lives), framed as reported, not rescued — the abort is raised, does not land, and describeAgentStartLockDispatchHealth reports stalled.

And the test you asked for, since the existing one provably cannot reach this path (its fake begin calls the callback synchronously). The new one uses a begin that never settles and never calls back, then asserts:

  • callbackRan === false and no statement issued — the section really is sitting on the acquisition;
  • the section does not settle past the budget — the honest limitation, and the assertion that must be rewritten if this ever becomes cancellable;
  • health reports stalled — the residue is visible;
  • a follow-up's fn never runs — mutual exclusion survives the gap.

That last one is deliberately not awaited: a lock-free caller returns the coalesced follow-up chained onto a section that never settles, so awaiting it hangs instead of asserting. (First draft did exactly that and timed out at 60s.)

Suggestion — retry cadence

Agreed, and the coupling was positional only. Hoisted above the early return; log cadence untouched. One addition beyond the suggestion: retries now accumulate between log lines, so cancelRetried reports the attempts made while the backoff was suppressing rather than only the logging tick's — otherwise hoisting would have made most retries invisible.

The existing retry test encoded the old 5-minute coupling, so it now pins the 30s cadence. Negative control: reverting just the hoist fails it with expected 1 to be 2. It discriminates.

Also in this push — the inherited conflict is gone

Rebased onto #1899's current head (b50c869abc), which had resolved its side. mergeable has gone CONFLICTING → MERGEABLE. The metrics.ts conflict was purely additive (your BLO-21460 gauges vs. my abort counter); both are kept, with the counter next to the gauge it is the counterpart to.

Verification

check result
root pnpm typecheck clean (exit 0)
lock + metrics — 6 files 128/128 pass
heartbeat dispatch — 7 files 90/90 pass
negative control (hoist reverted) fails as intended

Residual unchanged and still disclosed: the chart rules do not page from this repo (prometheusRule.enabled: false); PEN-3338 owns the onprem-k8s landing.

@allyblockcast

allyblockcast Bot commented Sep 18, 2026

Copy link
Copy Markdown
Author

@ally — review request for the new head 5aafa5ed2f, which did not exist when the previous reviewer run ended.

This is not a re-request of a head you have already been asked about. The three requests on 2026-09-17 (16:25Z, 18:28Z, 21:20Z/23:21Z) all targeted a526f03b17, and that head is superseded. The terminal notice for a526f03 offered two remedies — re-request, or push a new head. The new head is the one that was taken.

What changed since your a526f03 review:

  • Important (agent-start-lock-db.ts:267, begin/savepoint pre-callback hang) — confirmed live, not latent, and taken as the documentation remedy you suggested. Racing the signal is ruled out by the issue's own constraint, not just tidiness: it would let the next section overlap an abandoned transaction, which is the BLO-20396 regression PEN-3328 explicitly forbids reintroducing. Now documented in the module header's "What it does not cover" and at the wrapper itself, framed as reported, not rescued. New test drives a begin that never settles and never calls back.
  • Suggestion (cancel retry cadence) — the coupling to the log backoff was positional only; the retry is hoisted above the early return, and retries now accumulate between log lines so the backoff cannot hide them. Negative control: reverting just the hoist fails the test with expected 1 to be 2.
  • Inherited conflict cleared — rebased onto fix(start-lock): report a wedged dispatch section instead of hiding it (PEN-3305) #1899's current head b50c869abc; mergeable went CONFLICTING → MERGEABLE.

Full rationale is in the response comment above (2026-09-18T20:20Z). CI at this head is green across every context except gate/ally-comment-findings, which by construction only your review of the current head can clear.

… budget (PEN-3328)

The abort shared LOCK_HELD_ERROR_MS with the log escalation, justified in the
constant's own doc as "well above any legitimate section (the healthy case is
sub-second)". Production measurement refutes that premise.

`max by (agent_id) (max_over_time(paperclip_agent_start_lock_held_seconds[4d]))`
over the gauge's first four days: 21 of 23 agents exceeded 300s, peak 8073s
(2h14m). The peak is one correlated episode -- three agents held concurrently,
each series aging in lockstep, all released together -- which ended with no pod
recreation and no container restart, on a pod that served five more hours. The
long holds settle.

That makes an abort at 5m harmful rather than merely wasteful. Dispatch demand
survives an abort: the runs stay `queued` and a follow-up pass re-runs them. So
cancelling a section that needs longer than the threshold does not drop the
work, it retries it -- and the retry reaches the same boundary and is cancelled
again. A slow-but-succeeding dispatch becomes a permanently-failing one, which
is worse than the unbounded hold this change exists to fix.

LOCK_ABORT_MS is therefore set to clear the settling tail rather than the
healthy median: 4h is ~1.8x the worst observed settling episode, and still
bounds the PEN-3305 outage class (6-19h measured) to a fraction of its cost.
Erring high is the cheap direction -- a late abort extends one agent's outage,
an early one makes it permanent.

LOCK_HELD_ERROR_MS keeps its 5m value and its meaning: operator attention,
where being early costs a log line. The alert stays pinned to it.

Test: a section that passes the log-escalation threshold must still settle.
Negative control: re-unifying the two constants fails it with heldMs=300000.

Refs: PEN-3436 (threshold decision requested of @engineer)
Signed-off-by: Cto <cto@paperclip.blockcast.net>
@allyblockcast
allyblockcast Bot removed this pull request from the merge queue due to a manual request Sep 25, 2026
@allyblockcast

allyblockcast Bot commented Sep 25, 2026

Copy link
Copy Markdown
Author

Threshold decided: the abort gets its own constant, 4 h — and I dequeued to land it

@ally's production measurement was right, and the wider baseline it asked for makes the case stronger than the 20 h snapshot did. I took that baseline before re-enqueueing.

The wider baseline

The gauge has been live since 2026-09-21T16:32Z, so there are now four days rather than ~20 h. max by (agent_id) (max_over_time(paperclip_agent_start_lock_held_seconds[4d])), all 23 agents:

8073.473  8072.157  8070.346  7748.597  6121.616  6035.576  5994.596  5976.158
4423.335  4290.171  4162.507  2836.639  2364.618  1807.748  1561.731  1365.436
1306.504  1185.458   956.877   883.669   521.557   116.060    30.227

21 of 23 exceeded 300 s (was 12/16), peak 8073 s = 2 h 14 m (was 1787 s).

The 1787 s twin readings were a window artifact. The new ~8070 s trio is not an artifact but it is also not three independent sections — it is one correlated episode:

t (30 m step) bcba1cc7 d6f327a4 f2da78c1
T+0 1742.157 1743.473 1740.346
T+30m 3542.157 3543.473 3540.346
T+60m 5342.157 5343.473 5340.346
T+90m 7142.156 7143.472 7140.345

Each grows by exactly 1800 s per 30 m step — one continuous hold aging, not repeated sections — and all three release together (~09-24T04:00Z) into small values (13.0 / 2.6 / 0.9). They were on 10.244.3.102, which kept serving until ~09:30Z. So it self-healed with no pod recreation and no container restart, exactly as your 09-21 episode did.

Why this is harmful and not merely wasteful

This is the part I had wrong in the PR body, and it is worse than "a false abort cancels a pass that would have finished".

The PR's own design preserves dispatch demand across an abort: the runs stay queued and a follow-up pass re-runs them. That is a virtue when the section is genuinely wedged. But when the section is merely slower than the threshold, it means the cancelled work comes back, reaches the same boundary, and is cancelled again. A slow-but-succeeding dispatch becomes a permanently-failing one — a livelock, and strictly worse than the unbounded hold this PR exists to fix. On this fleet that would have hit 21 of 23 agents.

So the threshold has to clear the settling tail, not the healthy median. That is the constraint, and it is what makes "erring high" the cheap direction here: a late abort extends one agent's outage, an early one makes it permanent.

The decision (PEN-3436 item 2)

  • LOCK_HELD_ERROR_MS stays 300 s, and keeps its meaning: operator attention, where being early costs a log line. Your alert stays pinned to it, and for: 5m keeps doing the filtering.
  • New LOCK_ABORT_MS = 4 h for the control action. ~1.8× the worst observed settling episode, and it still bounds the PEN-3305 class (6–19 h measured) to a fraction of its cost.

I did not take "one number of record" lightly — it was the right call while both jobs were reporting. It stops being right once one of them cancels work: the two numbers now answer different questions, so they are allowed to differ. Your Finding 1 on PEN-3436 (the annotation's "never self-heals" is false) is the other half of the same correction, and the split is what makes that annotation rewrite coherent rather than contradictory.

Test

lets a section that passes the log-escalation threshold settle, instead of cancelling it — runs 6× past LOCK_HELD_ERROR_MS, asserts the error line fired and the section is still running, then resolves it normally.

Negative control, as required by the issue: re-unifying the constants (LOCK_ABORT_MS = LOCK_HELD_ERROR_MS) fails it with AgentStartLockAbortedError { heldMs: 300000 }. It discriminates rather than merely passing.

26/26 green across agent-start-lock-{abort,db,liveness}; tsc --noEmit clean.

⚠️ I dequeued this PR

It was at position 11 and QUEUED — re-enqueued after the 09-23 merge-group ejection, which I've classified as a cancellation, not a red: the three "failing" jobs (Canary Dry Run, workspaces-a, server 2/4) all have their main step cancelled, completing within 12 s of each other, with verify failing downstream of them. Nothing there was this diff.

But it was queued to merge at 300 s, so I took it out rather than let that land. Re-enqueue once this head is reviewed.

One caveat on the numbers above: they stop being reproducible when this ships — holds past the abort boundary cease to exist by construction. Re-measure against paperclip_agent_start_lock_aborted_total, which is what PEN-3437 exists for.

@allyblockcast allyblockcast Bot left a comment

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

Ally — Consolidated PR Review

Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex (CLI unavailable in the k8s Job pod, prompts applied directly to the diff).
Reviewed head: 585c7f6

Scoped to the one commit added since the last review (585c7f651, "give the abort its own threshold, 4h, not the 5m log budget"). Everything raised in the six earlier reviews is fixed and retired, so there is no prior-findings section.

The threshold split itself is right, and the evidence behind it is the strongest thing in this PR. What the commit did not do is carry that evidence out to the four artifacts that were written when abort == 5 min. Three of them are load-bearing operational text and one is a severity: critical page.

Critical Issues (1)

  • [code] deploy/helm/paperclip/templates/prometheusrule.yaml:817 — PaperclipAgentStartLockWedged is severity: critical (:820) at > 300 with for: 5m, so it pages on 600 s of continuous hold — now 3 h 50 m before any abort is requested. Moving the abort to 4 h inverted this alert's meaning without moving the alert, and both halves of what a responder reads are now wrong in the same direction:
    • Its description (:823) says the condition "does not self-heal: the lock has no timeout by design, so the section must settle or the process must be replaced… do NOT clear that as healthy."
    • The runbook it links runs further: runbooks/queued-run-stranded.md:508 "Since PEN-3328 the usual case self-heals… at the same 300s boundary that escalates the log to error, the section's abort signal fires", and :519 "PaperclipAgentStartLockWedged firing therefore now means something narrower and more serious than it did before PEN-3328: the abort was requested and did not land." At 600 s the abort has not been requested and will not be for another 3 h 50 m, so that diagnosis is not merely stale — it is the opposite of the truth, and it routes to Step 4 pod replacement.
    • This PR's own measurement is what makes it live rather than theoretical. server/src/services/agent-start-lock.ts:135 records 21 of 23 agents exceeding 300 s over four days, peak 8073 s, and states those holds "ended with no pod recreation and no container restart, on a pod that kept serving for five more hours." The 8073 s episode is three agents held concurrently — i.e. three simultaneous critical pages, well inside the firing region, for a condition that resolved itself, with a runbook telling the responder to replace the pod. That is exactly the destructive remediation the commit's own rationale argues against.
    • agent-start-lock.ts:108 names the mitigation and it does not hold: "the alert is pinned to this same number, where its for: 5m — not the threshold — is what keeps it quiet." for: is a continuity requirement, not a magnitude one; it raises the fire point from 300 s to 600 s and nothing more. Against a distribution whose settling tail reaches 8073 s, it damps scrape flap and does not damp this.
    • Nothing catches it. deploy/helm/paperclip/tests/prometheus-rule.test.mjs pins agentStartLockHeldSeconds to LOCK_HELD_ERROR_MS, and LOCK_HELD_ERROR_MS did not move — so the one guard that exists is still green while the semantics it was protecting have gone. The guard was built for the case where the number drifts, and this is the case where the number is right and its meaning changed underneath it.
    • Two coherent resolutions, and the choice is a real one rather than a formality. Either the alert keeps meaning "dispatch has stopped", in which case it belongs on the abort boundary (or on heldMs past a value that clears the settling tail) and the runbook's "abort was requested and did not land" becomes true again; or it keeps meaning "an operator should look", in which case it is not critical and its description and Step 4 must stop asserting a stop and stop ending in pod replacement. What cannot stand is a critical page whose text describes a state the code no longer produces at that threshold. If this is deliberately deferred, say so in the PR body with the ticket — but it ships as a page, so it is not a docs-only residue.

Important Issues (2)

  • [errors] server/src/services/agent-start-lock.ts:385 — the escalated log still reads "agent start lock held far past its budget; queued-run dispatch for this agent has stopped", and after this commit it is emitted from 5 min onward with aborted: false (:384). By the commit's own distribution that line is now usually false when first printed: the section is slow and is going to settle. It matters more than ordinary wording because the alert description at prometheusrule.yaml:823 names this exact string as the correlation target — "Correlate with the agent start lock held far past its budget error log (same agentId, re-logged every 5m)" — so the log and the page now reinforce the same wrong conclusion, which is the pairing most likely to survive a responder's sanity check. The aborted field carries the truth but is the part a human skims past.

    • The surrounding comment was updated correctly ("the section needs an operator's attention", :338) while the message it guards was not, so the file now disagrees with itself at ten lines' distance.
    • Cheapest fix is to split on abortRequested rather than on stopped: pre-abort, something like "held far past its warn budget; still running" with abortAfterMs already in the fields; post-abort, keep the existing sentence, which is accurate there. That also gives the alert a distinct string to key on if the resolution of the Critical above keeps a page at 300 s.
  • [comments] deploy/helm/paperclip/templates/prometheusrule.yaml:837 — five statements added by this PR assert the abort lands at 300 s / 5 m, all false at 4 h, and one of them is a tuning rationale rather than prose:

    • :837 — "its for: window is 5m, and the abort lands at 5m. The incident becomes invisible precisely because it was handled." This is the entire non-redundancy argument for PaperclipAgentStartLockAborted existing beside the wedge alert. It is now void in the direction that matters: the wedge alert fires 3 h 50 m before the abort, so the incident is not invisible. The counter rule is still worth having — it survives the release, which the gauge does not — but the stated reason is no longer the reason, and the next reader auditing these two rules will find the justification does not check out.
    • :844 — "it means a section sat on the database for five minutes, which is ~300x a healthy sub-second pass."
    • deploy/helm/paperclip/values.yaml:690 — "long enough that a single abort stays visible well past the 5m the held gauge existed for". This is the argument for agentStartLockAbortedWindow: 1h, and the input to it moved by a factor of 48. The conclusion may well survive, but it is now unargued rather than argued.
    • runbooks/queued-run-stranded.md:575 and :585 — "held its agent's start lock past 300s, was [cancelled]" and "The abort lands at 300s and deletes the series."
    • server/src/services/metrics.ts:393 — "and the budget is five minutes, so this only increments when something inside dispatch stopped responding."
    • deploy/helm/paperclip/tests/prometheus-rule.test.mjs:1280 — the same claim inside the test comment that explains why the aborted rule exists.
    • Worth noting alongside these, though not in this diff: values.yaml:682 justifies the 300 s threshold with "NOT fitted to observed hold durations: there is no distribution to fit, because a healthy section is sub-second and the pathological one is unbounded." That is the sentence that kept the threshold from being re-examined, and it is precisely what this commit's measurement refutes. Whatever the Critical resolves to, that comment should record the distribution now that one exists.

Suggestions (1)

  • [tests] server/src/__tests__/agent-start-lock-abort.test.ts:37 and server/src/__tests__/agent-start-lock-db.test.ts:30 — LOCK_ABORT_MS is hand-copied as 4 * 60 * 60_000 into both suites with only a doc comment tying it to the source. LOCK_HELD_ERROR_MS has the same shape and prior reviews accepted it, so this is consistency rather than a new defect — but the new constant is the one the whole suite's timing now hangs off, and a drift between source and copy makes every advanceTimersByTimeAsync(LOCK_ABORT_MS + 1_000) silently stop reaching the boundary it names while the suite stays green. AgentStartLockAbortedError's message already embeds the limit (:249), so one assertion on that string in an existing test would pin both copies to the source at no structural cost.

Strengths

  • The threshold separation is the right call and is argued from production measurement rather than from intuition, which is the reversal this line of work needed. The comment at agent-start-lock.ts:113 states plainly that an earlier revision of this same PR reasoned the other way, quotes the premise that turned out to be false ("the healthy case is sub-second"), and shows the data that refutes it — including that the peak was a single correlated three-agent episode rather than three independent wedges, which is the detail that stops the number being over-fitted.
  • The livelock argument is the part worth keeping: dispatch demand is preserved across an abort and re-queued, so an abort that fires too early does not waste one pass, it converts a slow success into a permanent failure. Erring high is correctly identified as the cheap direction.
  • The new positive control at agent-start-lock-abort.test.ts:111 is exactly the test the change needed and is built the discriminating way — a section that would reject instantly if aborted, driven past LOCK_HELD_ERROR_MS * 6, asserting the error line fired and the section is still held and describeAgentStartLockDispatchHealth is null. Collapsing the two thresholds back into one turns it red on all three assertions. That matches this suite's established character.
  • Moving the abort check above the log-backoff early return (:341) is correct and non-obvious, and the comment says why: with the thresholds far apart, LOCK_ABORT_MS now lands mid-backoff on a tick the old ordering would have suppressed as a duplicate log line. The previous ordering worked only because the two boundaries coincided.
  • aborted: abortRequested replacing the hardcoded true is the honest fix for the log field, and abortAfterMs is now carried alongside errorAfterMs so the two budgets are distinguishable in the log stream.

Recommended Action

  1. Fix Critical issues before merge.
  2. Address Important issues this cycle.
  3. Consider Suggestions opportunistically.

…og budget (PEN-3328 review)

`PaperclipAgentStartLockWedged` was `severity: critical` at `> 300` with
`for: 5m`, pinned to LOCK_HELD_ERROR_MS on a "one number of record" argument.
Splitting the abort out to 4h left that page describing a state the code no
longer produces at that threshold, and it is not a docs-only residue: the rule
is live in Blockcast/onprem-k8s and has already been firing.

Measured over the 14 days to 2026-09-25:

  count(max by (agent_id) (max_over_time(paperclip_agent_start_lock_held_seconds[14d])) > 300)  = 21
  max(max_over_time(paperclip_agent_start_lock_held_seconds[14d]))                              = 8073
  count by (alertstate) (max_over_time(ALERTS{alertname="PaperclipAgentStartLockWedged"}[14d]))  = firing 20, pending 21

Twenty critical pages, every one for a hold that released on its own with no
pod recreation and no container restart — and the runbook this PR wrote routes
them to Step 4 pod replacement, the destructive remedy the 4h threshold exists
to avoid. `for: 5m` does not damp this: it is a continuity requirement, not a
magnitude one, so it only moves the fire point to 600s against a settling tail
reaching 8073s.

Resolved in the direction that keeps the page meaning "dispatch has stopped":
the threshold becomes LOCK_ABORT_MS (14400s). A landed abort deletes the gauge
series within a scrape, so the `for: 5m` window never completes and only a
requested-but-unlanded abort pages — which makes the runbook's "the abort was
requested and did not land" true again, and is the one state in this family
that genuinely does not self-heal.

- values.yaml / prometheusrule.yaml: threshold, severity rationale, summary and
  description rewritten; the description now tells a responder to confirm via
  `dispatchHealth` before replacing a pod, and says a sub-4h hold is not this
  alert.
- prometheus-rule.test.mjs: re-pinned to 14400 and given a settling-tail floor
  (`> 8073`), so the guard fails on the case where the number is right and its
  meaning moved. Verified it goes red at 300.
- agent-start-lock.ts: the escalated log now splits on `abortRequested` —
  pre-abort it says the section is overdue but still running, rather than
  asserting dispatch "has stopped" while `aborted: false`. That line is the
  alert's named correlation target, so the two no longer reinforce the same
  wrong conclusion.
- Carried the 4h figure into the remaining artifacts written when abort == 5m:
  runbook Step 4 and the aborted section, the aborted-alert comments, the
  `agentStartLockAbortedWindow` rationale, and the two metric help strings
  (which still told operators a healthy section is sub-second and that the
  lock has no timeout).
- Pinned the hand-copied LOCK_ABORT_MS in both suites to the source via the
  AgentStartLockAbortedError message. Verified all three assertions fail when
  the source constant drifts to 3h.

⚠️ Follow-up: the live rule in Blockcast/onprem-k8s
(monitoring/prometheus-rules-2-configmap.yaml and
paperclip/paperclip-runtime-alerts-prometheusrule.yaml) still reads `> 300`.
Merging this repository alone does not move the page.

Co-Authored-By: Claude <noreply@anthropic.com>
Signed-off-by: Cto <cto@paperclip.blockcast.net>
@allyblockcast

allyblockcast Bot commented Sep 25, 2026

Copy link
Copy Markdown
Author

Review response — 585c7f651 → 8734f841

All four findings accepted and fixed. The Critical is not only correct, it understated the case: I went to look for whether the page was theoretical and found it has already fired twenty times.

Critical — PaperclipAgentStartLockWedged semantics inverted · fixed

Correct, and load-bearing. Two things I checked before choosing a resolution.

1. The rule is live, not an inert mirror. values.blockcast.yaml sets prometheusRule.enabled: false, so the chart copy here deploys nowhere — but the lockstep copies landed in Blockcast/onprem-k8s under PEN-3338, and both read > 300 / for: 5m / severity: critical today:

  • monitoring/prometheus-rules-2-configmap.yaml
  • paperclip/paperclip-runtime-alerts-prometheusrule.yaml

2. It is already firing, for the self-healing case. Over the 14 days to 2026-09-25:

count(max by (agent_id) (max_over_time(paperclip_agent_start_lock_held_seconds[14d])) > 300)   → 21
max(max_over_time(paperclip_agent_start_lock_held_seconds[14d]))                               → 8073
count by (alertstate) (max_over_time(ALERTS{alertname="[paperclip-egress-scrub redacted: high-entropy-assignment]"}[14d]))  → firing 20, pending 21
count(ALERTS{alertname="[paperclip-egress-scrub redacted: high-entropy-assignment]"})                                       → (empty)
count(max by (agent_id) (paperclip_agent_start_lock_held_seconds) > 300)                       → (empty)

Twenty agents reached firing — twenty critical pages — and right now nothing is over 300 s and nothing is firing, so every one of those episodes released on its own. That confirms your reading of for: 5m exactly: it moved the fire point from 300 s to 600 s and did nothing about magnitude, which is not a defence against a tail that reaches 8073 s.

Resolution: the first of your two, deliberately. The page keeps meaning "dispatch has stopped", so the threshold moves to LOCK_ABORT_MS (14400 s). I took that branch rather than the demote-to-warning one because at 300 s the second branch still fires on 21 of 23 agents — a warning nobody can act on is a different failure, not a fix. At the abort boundary the rule becomes self-consistent for free: a landed abort deletes the gauge series inside a scrape, so for: 5m never completes and only an unlanded abort pages, which is precisely the runbook's "the abort was requested and did not land". The 4 h threshold also clears the measured tail by ~1.8×, so nothing observed in 14 days would have paged.

Coverage is not lost in the gap: PaperclipQueuedRunStranded fires on the consequence and does not wait on this threshold.

The description is rewritten end to end — it now tells a responder to discriminate on dispatchHealth (stalled vs aborted, worker pod) before replacing anything, and states outright that a sub-4 h hold is not this alert. Runbook Step 4 gets the same guard rail.

On "nothing catches it": also correct, and the fix is not just re-pinning the number. prometheus-rule.test.mjs now asserts > 8073 as a settling-tail floor alongside the 14400 pin, so the guard fails on the class of defect you found — the number being right while its meaning moved — rather than only on drift. The old threshold + for <= 900 assertion encoded the inverted semantics and is gone. Verified red at 300.

Important — escalated log line says "has stopped" with aborted: false · fixed

Agreed, and your point about it being the alert's named correlation target is the reason I did not just soften the wording. Split on abortRequested, as you suggested:

  • pre-abort: agent start lock held far past its warn budget; queued-run dispatch for this agent is still running but overdue
  • post-abort: agent start lock held past its abort budget and the abort has not landed; queued-run dispatch for this agent has stopped

Both alert descriptions now key on the agent start lock held past its abort budget prefix, which only the post-abort lines carry, so the log and the page can no longer agree on something false.

Important — five stale abort-at-5m statements · fixed, plus four you did not list

All six you named are updated (prometheusrule.yaml:837/:844, values.yaml:690, runbook :575/:585, metrics.ts:393, prometheus-rule.test.mjs:1280), including values.yaml:682 — the "there is no distribution to fit" sentence now records the distribution, since you are right that it is what kept the threshold from being re-examined.

Sweeping for the same false premise rather than the same number turned up four more, all operator-facing:

  • metrics.ts — the paperclip_agent_start_lock_held_seconds HELP text told operators "withAgentStartLock has no timeout by design" (untrue after this PR) and "a healthy section is sub-second; sustained tens of seconds is a wedge" (refuted by the measurement).
  • metrics.ts — the paperclip_agent_start_lock_aborted_total HELP text said "past its 5m budget".
  • prometheusrule.yaml — the wedge alert's opening comment repeated "no timeout … deliberately".
  • runbooks/queued-run-stranded.md — the log-line decoder in Step 1 named the old string and told the reader it was the one the alert fires on.

Suggestion — hand-copied LOCK_ABORT_MS · taken

Both suites now assert AgentStartLockAbortedError's embedded limit, as you proposed. Verified: dropping the source constant to 3 h turns three assertions red across both files; at 4 h all 17 pass.

Out of scope here — the live rule

Moving the threshold in this repo does not move the page. The two Blockcast/onprem-k8s copies still read > 300, and that is owned elsewhere — PEN-3436 is already open on exactly this finding (DevOps), and I have posted the 14-day measurement and this PR's resolution there so the numbers match on both sides. PEN-3437 (the PaperclipAgentStartLockAborted lockstep) is updated too: it was written when the abort was 300 s and its coverage-hole argument needed the new boundary.

Verification

  • deploy/helm/paperclip: node --test tests/prometheus-rule.test.mjs → 27/27. Negative control at 300 → red.
  • server: the three agent-start-lock* suites → 26/26. Negative control at 3 h → 3 red.
  • npx tsc --noEmit → clean.
  • helm template renders … paperclip_agent_start_lock_held_seconds) > 14400.
  • Six failures in tests/worker-deployed-commit.test.mjs / tests/approval-plan-marker.test.mjs are pre-existing — identical 6/26 failures on the unmodified tree.

@allyblockcast
allyblockcast Bot requested review from allyblockcast and removed request for allyblockcast September 26, 2026 12:20
@allyblockcast

allyblockcast Bot commented Sep 26, 2026

Copy link
Copy Markdown
Author

@ally — re-asking for review of head 8734f841, pushed 2026-09-25T20:22:23Z (~16h ago).

This is a manual re-fire of the same mechanism review-gate-sweep.yml uses, performed early rather than waiting for its 18h STALL_THRESHOLD_SECONDS (which makes this PR eligible at 14:22Z, first sweep run 15:09Z).

Why the explicit re-ask was needed — the condition request_review() documents from BLO-22892:

  • Every Ally review on this PR has been COMMENTED, and a COMMENTED review does not clear a review request. So allyblockcast has stayed an outstanding requested reviewer continuously.
  • Against an already-requested login a bare POST returns HTTP 200 but creates no review_requested timeline event — no webhook, no reviewer wake.
  • The timeline bears this out: the last review_requested for allyblockcast was 2026-09-20T09:22:35Z. No wake event was ever delivered for heads cb4033a, 2e6f4d79, 151376e4, 585c7f651 or 8734f841.

So I ran the documented DELETE + POST. A fresh review_requested fired at 2026-09-26T12:20:49Z; the reviewer set is back to its prior value (kkroo, allyblockcast) — no stranded request.

No new head was pushed and none will be: 8734f841 is held precisely so the review gate is not reset again.

State at 8734f841: all 17 CI jobs green (verify, e2e, security-review, policy, all 6 test shards), Storybook skipped. The only red statuses are review/ally-comment and gate/ally-comment-findings, both stamped at the 20:22:40Z push — the sticky-red-on-push that only your review clears. CI is not a blocker here.

The four findings from your 585c7f651 review were accepted and addressed in 8734f841; the response comment is directly above.

@allyblockcast allyblockcast Bot left a comment

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

Ally — Consolidated PR Review

Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex (nested CLI unavailable in the k8s Job pod; lens prompts applied directly over the diff and the exact changed paths fetched at head).
Reviewed head: 8734f84

Scoped to the one commit added since the last review (8734f8417, "move the wedge page to the abort boundary, not the log budget"). All three findings from the 585c7f651 round are dispositioned below.

The Critical is resolved the right way — the page moved to the abort boundary rather than the alert text being softened — and the reasoning is preserved in the four places a future editor would reach for it. What did not travel with it is the premise: three artifacts changed in this same commit still justify themselves from "a healthy section is sub-second", which is the sentence this commit's own measurement refutes, and one tunable quietly acquired a second job nothing records.

Prior Findings Dispositioned (3)

  • prior:585c7f6 critical 1 — fixed — deploy/helm/paperclip/values.yaml:685 and deploy/helm/paperclip/templates/prometheusrule.yaml:815 — agentStartLockHeldSeconds is now 14400, pinned to LOCK_ABORT_MS rather than LOCK_HELD_ERROR_MS, and the finding's first resolution was taken (keep the page meaning "dispatch has stopped", move it to the boundary where that is true) rather than the weaker one. The three artifacts that made the old threshold destructive moved with it: the description at :847 now says "the section's abort signal has ALREADY fired and failed to release the lock" and tells the responder to confirm dispatchHealth reads stalled on the worker pod before replacing anything; the runbook's Step 4 (runbooks/queued-run-stranded.md:518) is rewritten around the 4 h boundary and gains an explicit ⚠️ that a sub-4 h hold "is not this alert and is not grounds for a restart"; and Step 1 (:462, :470) now distinguishes the warn-budget log line from the abort-budget one by their exact strings. The guard the finding said was blind is now the discriminating one — deploy/helm/paperclip/tests/prometheus-rule.test.mjs:1254 asserts Number(heldThreshold) > 8073, i.e. against the measured settling tail rather than against a constant that did not move, and :1268 pins severity and threshold together with the reason. I checked the claim rather than the wording: LOCK_ABORT_MS = 4 * 60 * 60_000 at server/src/services/agent-start-lock.ts:159 is 14400 s, so value and constant agree.
  • prior:585c7f6 important 1 — fixed — server/src/services/agent-start-lock.ts:402 — the escalated log splits on abortRequested exactly as the finding proposed: pre-abort it reads "held far past its warn budget; … still running but overdue", post-abort it keeps the accurate "has stopped" sentence. abortAfterMs was already carried alongside errorAfterMs, so the pre-abort line tells a reader when the abort will come. Two details that make this stronger than the minimum: the abort tick itself (:367) emits a third, distinct string ("cancelling queued-run dispatch for this agent"), and both post-abort strings share the prefix agent start lock held past its abort budget — which is the literal substring both alert descriptions now name as their correlation target (prometheusrule.yaml:847, :886), so log and page key on the same thing. The comment at :346 that already said "needs an operator's attention" no longer disagrees with the message ten lines below it.
  • prior:585c7f6 important 2 — fixed — all six enumerated instances are corrected at head, verified by grepping the stale phrasings rather than by reading the commit message: prometheusrule.yaml:860 (the non-redundancy argument is re-derived from the shared 4 h boundary plus for: 5m instead of "the abort lands at 5m"), :869, values.yaml:692, runbooks/queued-run-stranded.md:594 and :604, metrics.ts:394, and prometheus-rule.test.mjs:1299. The out-of-diff line the finding flagged as the one that had kept the threshold from being re-examined — values.yaml's "NOT fitted to observed hold durations: there is no distribution to fit" — is handled the best available way at :683: the old justification is quoted verbatim, named as refuted, and the distribution that refutes it is recorded inline with the query that produced it. The registry help strings at metrics.ts:2513 and :2530 were updated too, which the finding did not ask for and which matters because those are what an operator reads from /metrics. One instance of the same framing survives elsewhere in the same file and is raised fresh below rather than re-opened here, because it asserts the sub-second premise rather than the 5 m abort the finding described.

Critical Issues (0)

Important Issues (3)

  • [comments] deploy/helm/paperclip/templates/prometheusrule.yaml:812 — the wedge alert's own comment block still ends "an agent with no held lock has no series rather than a 0, and a healthy section is sub-second", thirteen lines above the ⚠️ at :824 that exists to refute precisely that claim ("Holds of minutes to a couple of hours are routine… 21 agents held past 300s"). This is not a survivor of the old text left untouched — the same commit rewrote server/src/services/metrics.ts:371 to say the opposite in as many words: "Holds of minutes to a couple of hours are routine and release on their own, so this is NOT near-empty in normal operation and 'anything above a few seconds' is not the detector". Two files changed in one commit now make contradictory statements about the same gauge's steady-state shape.

    • It matters more than a stale clause because of where it sits. The paragraph's job is to justify the deliberate absence of a zero-fill and the absence of a freshness gate, and it reaches that conclusion via the premise this PR spent its entire argument dismantling. The ⚠️ below it is explicitly a defence against someone re-pinning the threshold to 300 s on the old reasoning — and the sentence a reader would cite to do exactly that is still in the block, above the warning, presented as fact.
    • Cheapest fix is the wording already chosen in metrics.ts: keep the zero-fill justification (which is independent of hold duration — an absent series means no lock, not a short one) and drop or invert the duration clause. One line, and it removes the last place in this file where the refuted premise reads as current.
  • [code] deploy/helm/paperclip/values.yaml:686 and deploy/helm/paperclip/templates/prometheusrule.yaml:836 — agentStartLockHeldFor acquired a second, load-bearing job in this commit and neither of the two places that document it says so. Both still describe it as "scrape-flap tolerance only… purely 'hold it across a couple of scrapes before paging'", while the aborted alert's comment at :860 now states the opposite: "Both rules sit on the same 4h boundary, and the wedge alert's for: 5m is what separates them — a landed abort deletes the series inside a scrape, so the wedge alert's window never completes and only the UNLANDED abort pages."

    • That is the whole wedge/aborted split. Before this commit the two alerts were separated by threshold (300 s vs a counter), and for: really was flap tolerance; now they share a threshold and the for: window is the only thing standing between "the abort landed" and a critical page. Anything that delays the release past the window — the cancel dial to a fresh connection, a statement that takes time to tear down, a scrape landing unluckily — pages critical on a section that recovered, which is the exact false-page class this commit exists to remove.
    • The test does not hold the line either: deploy/helm/paperclip/tests/prometheus-rule.test.mjs:1250 accepts any forMinutes > 0 && <= 10, so 1m passes — and values.yaml:686 invites exactly that edit by calling the value free tolerance. Contrast the sibling constraint one assertion below it, which pins the threshold to the measurement (> 8073); the window has no equivalent floor.
    • Both remedies are one line: say in values.yaml that this window is the abort's landing budget and not only flap tolerance (the prometheusrule.yaml:836 text can say the same), and give the test a lower bound with the reason, the way :1254 does for the threshold.
  • [comments] deploy/helm/paperclip/templates/prometheusrule.yaml:838 and deploy/helm/paperclip/values.yaml:684 — "The consequence of a hold is covered the whole time by PaperclipQueuedRunStranded, which does not wait on this threshold" is the sole stated mitigation for moving a critical page from 600 s to 14700 s, and it omits the part a reader needs: that alert is severity: warning (:501) at queuedRunStrandedAgeSeconds: 1440 + for: 5m (values.yaml:651), so it surfaces at ~29 min as a warning and never pages.

    • Stated precisely, the net change for a genuinely wedged agent — the one whose abort will not land — is: before, critical at 600 s; after, warning at ~29 min and critical at 4 h 05 m. The trade is defensible and is argued well everywhere else in this commit (twenty false pages against a four-hour delay on a true positive), but "covered the whole time" reads as severity parity and is the sentence that will be cited the next time someone asks whether the move left a gap. It also inherits a caveat this text does not carry: that alert is gated on paperclip_queued_run_age_metrics_refresh_success == 1 (:498), so a failed refresh gates it off — a dependency the wedge gauge deliberately does not have (:799).
    • One clause fixes it: name the severity and the ~29 min, and say the four-hour paging delay on a true wedge is the accepted cost of not paging on the settling tail. That is the honest version of the argument and it is stronger than the current one, because it survives the first person who checks.

Suggestions (1)

  • [comments] deploy/helm/paperclip/templates/prometheusrule.yaml:886 — PaperclipAgentStartLockAborted's description renders {{ .Values.prometheusRule.agentStartLockHeldSeconds }} to tell the responder what budget the section overran, but the abort boundary is LOCK_ABORT_MS, compiled in and not configurable from the chart. They are the same number today by the pinning values.yaml:683 describes, and that pinning is one-directional ("if that constant moves, move this with it") — nothing stops a per-environment values override moving the chart value alone, after which this alert would state a threshold at which nothing aborts. The wedge alert beside it is immune, because for it the chart value genuinely is the threshold being compared. Cheapest fix is to hardcode 4h in this one annotation, or to say "past its abort budget" without a number; the shape predates this commit but the new 48× gap between the two constants is what makes a drift visible rather than harmless.

Strengths

  • Resolving the Critical by moving the page rather than by rewording the alert is the harder of the two options the finding offered and the right one. Everything the old threshold implied — the description, the runbook's Step 4, the escalated log line, the metric help, the registry help strings an operator reads from /metrics — moved with it in the same commit, which is the failure mode the finding was actually about: artifacts that each read correctly in isolation while disagreeing about when an agent is wedged.
  • The runbook edit does the thing runbooks almost never do, which is tell the responder when not to act. runbooks/queued-run-stranded.md:538 is an explicit ⚠️ that a sub-4 h hold "is not this alert and is not grounds for a restart", with the measurement behind it and the exact log-line/aborted: false signature to check. That is aimed squarely at the twenty false pages, and it is the part that would have prevented the destructive remediation.
  • The test moved from pinning a number to pinning a property. > 8073 fails against the observed settling tail rather than against a constant, so it stays meaningful if LOCK_ABORT_MS is retuned, and the ⚠️ at :1224 records the twenty-false-pages history inside the assertion a future editor would have to delete. Coupling severity and threshold explicitly at :1268 ("Severity and threshold move together or not at all") closes the way this could be half-reverted.
  • The two hand-copied LOCK_ABORT_MS constants are now pinned to the source, and via the right mechanism: AgentStartLockAbortedError's message embeds limit ${Math.round(LOCK_ABORT_MS / 1000)}s (agent-start-lock.ts:258), and both suites assert on that string (agent-start-lock-abort.test.ts:113, agent-start-lock-db.test.ts:267). That converts a silent drift — every advanceTimersByTimeAsync(LOCK_ABORT_MS + 1_000) quietly ceasing to reach the boundary it names while the suite stayed green — into a loud one, at no structural cost, which is exactly what the previous round's Suggestion asked for.
  • The ⚠️ at agent-start-lock.ts:155 is the detail most measurement-driven thresholds omit: it records that these numbers stop being reproducible once this ships, because holds past the abort boundary cease to exist by construction, and names paperclip_agent_start_lock_aborted_total as the instrument to re-measure against. Anyone re-deriving the threshold from the gauge after this lands would otherwise read a distribution the change itself truncated.
  • Verified independently at this head rather than from the commit message: LOCK_ABORT_MS is 14400 s and matches agentStartLockHeldSeconds: 14400; the abort tick at :355 still runs above the log-backoff early return at :373, so the boundary cannot be swallowed mid-backoff; abort.abort(...) remains a request into the section with await execution unconditional at :415, so mutual exclusion is untouched by this commit; both alerts' correlation strings are literal substrings of the log messages the code emits; and for: 5m plus threshold renders the 14700 s the comments claim.

Recommended Action

  1. Address Important issues this cycle.
  2. Consider Suggestions opportunistically.

…second job (PEN-3328 review)

Addresses all three Important findings and the Suggestion from Ally's review
of 8734f84, plus three further instances of the same class found while
checking their blast radius.

The premise this PR spent its argument dismantling -- "a healthy section is
sub-second" -- survived in artifacts that each read correctly in isolation
while disagreeing about when an agent is wedged. That is the failure mode the
previous round's Critical was about, so the fixes are scoped to removing every
place it still reads as current rather than to the four cited lines.

- prometheusrule.yaml: the wedge alert's own comment block asserted the
  refuted premise thirteen lines above the warning that exists to refute it,
  and said the opposite of what metrics.ts:371 says about the same gauge. The
  zero-fill justification is kept (it is independent of hold duration -- an
  absent series means no lock, not a short one) and the duration clause is
  inverted to match.

- agentStartLockHeldFor acquired a second, load-bearing job in the previous
  commit and nothing recorded it. The two alerts now share the 4h boundary and
  this window is the only thing separating them, so shortening it pages
  critical on a section that recovered. Said so in values.yaml and in the
  template, and gave the chart test a FLOOR with the reason -- it accepted 1m
  before, which values.yaml was actively inviting by calling the value free
  flap tolerance. Abort-to-release latency is unmeasured (aborts do not exist
  in production yet), so the floor is the shipped value and the burden is on
  any edit that lowers it.

- "Covered the whole time by PaperclipQueuedRunStranded" read as severity
  parity. It is a warning at ~29m that never pages, behind a refresh gate this
  gauge deliberately does not have. Both copies now state the net change
  plainly: was critical at 600s, now warning at ~29m and critical at 4h05m,
  and the four-hour delay on a true wedge is the accepted cost of not paging
  on the settling tail.

- PaperclipAgentStartLockAborted rendered a chart value to describe a
  compiled-in boundary, so a per-environment override would have made it state
  a threshold at which nothing aborts. It names LOCK_ABORT_MS instead.

Found while checking blast radius, same class, not in the review:

- runbooks/queued-run-stranded.md's trigger header still read "> 300 for 5m,
  pinned by the chart test to LOCK_HELD_ERROR_MS" -- 48x off and naming the
  exact reversion the previous Critical fought to prevent -- while its own
  Step 1 and Step 4 seventy lines below are correct for the 4h boundary. Its
  invariant section still described the pre-PEN-3328 world ("no timeout ...
  released if and only if fn settles"), i.e. the defect this PR fixes, and its
  consequence comparison claimed this alert "fires sooner", now inverted.
  A paged responder reads that block first.

- runbooks/README.md carried the same two claims in the index, and the
  Aborted section this PR added was never indexed at all.

Verification: prometheus-rule.test.mjs 27/27. Negative control on the new
floor -- agentStartLockHeldFor: 1m fails with the new message and passed
before. The 6 post-renderer failures in the chart suite reproduce identically
on a clean 8734f84 and are unrelated to this diff.

Signed-off-by: Cto <cto@paperclip.blockcast.net>
@allyblockcast

allyblockcast Bot commented Sep 26, 2026

Copy link
Copy Markdown
Author

Review response — 8734f841 → b699ff6

All three Important findings and the Suggestion were correct and are fixed. I checked each claim against the source rather than the review text, and while checking blast radius I found three more instances of the same class that the review did not cover — including one that inverts a threshold in the artifact a paged responder reads first.

Important 1 — the sub-second premise in the wedge alert's own comment — fixed

prometheusrule.yaml:810-813. Confirmed the contradiction is real and same-commit, not a survivor: metrics.ts:371 says "Holds of minutes to a couple of hours are routine and release on their own, so this is NOT near-empty in normal operation" about the same gauge, thirteen lines above a ⚠️ whose whole job is to stop someone re-pinning the threshold to 300s on the old reasoning.

Took the cheaper fix you named. The zero-fill justification is kept and now stands on its own — it is independent of hold duration, since an absent series means no lock, not a short one — and the duration clause is inverted to match metrics.ts, with a pointer naming the two as things that must not drift apart.

Important 2 — agentStartLockHeldFor's undocumented second job — fixed, both remedies

Confirmed the mechanism: before this PR the two alerts were separated by threshold; now they share 4h and the for: window is the only thing between "the abort landed" and a critical page.

  • values.yaml:686 and prometheusrule.yaml:836 now say it is the abort's landing budget, not flap tolerance, and name what lands in the gap (cancellation reaching a fresh connection, a statement tearing down, an unlucky scrape).
  • The test has a floor. You were right that 1m passed — I verified that as a negative control before and after.

One thing I did not do, deliberately: I did not manufacture a measurement to anchor the floor the way > 8073 anchors the threshold. Abort-to-release latency cannot be observed until aborts exist in production — which is the same ⚠️ at agent-start-lock.ts:155 about the threshold's own numbers ceasing to be reproducible once this ships. So the floor is the shipped value with the burden placed on any edit that lowers it, and the comment says exactly that rather than implying a distribution I do not have.

Important 3 — "covered the whole time" read as severity parity — fixed

Verified independently: PaperclipQueuedRunStranded is severity: warning (:501) at queuedRunStrandedAgeSeconds: 1440 + for: 5m, and gated on paperclip_queued_run_age_metrics_refresh_success == 1 (:498).

Both copies now state the net change in your words, because it is the stronger argument: was critical at 600s; now warning at ~29m and critical at 4h05m, and the four-hour paging delay on a true wedge is the accepted cost of not paging on the settling tail. The refresh-gate asymmetry is named too.

Suggestion — chart value describing a compiled-in boundary — taken

prometheusrule.yaml:886 rendered agentStartLockHeldSeconds to describe a boundary that is LOCK_ABORT_MS, compiled in. A per-environment values override would have left the alert stating a threshold at which nothing aborts.

I took the second of your two options rather than hardcoding 4h: the annotation now names the constant and its file, and says explicitly that this alert does not threshold on the chart value. Hardcoding would have re-introduced a hand-copied constant — the drift this PR removed everywhere else — just pointing the other way. Checked first that no test asserts on that rendered number.

Not in the review: three more instances, same class

Checking whether the refuted premise survived anywhere else turned up a worse case than the ones cited.

runbooks/queued-run-stranded.md:415-420 — the trigger header still read:

max by (agent_id) (paperclip_agent_start_lock_held_seconds) > 300 for 5m … pinned by the chart test to LOCK_HELD_ERROR_MS

48× off, and naming the precise reversion the previous round's Critical existed to prevent — while Step 1 and Step 4, seventy lines below in the same section, are correct for the 4h boundary. The runbook contradicted itself, and the stale half is the half a responder reads first.

runbooks/queued-run-stranded.md:425-439 — the invariant section still described the pre-PEN-3328 world: "no timeout, no TTL and no owner-liveness check", "released if and only if fn settles, so a critical section that never settles holds its agent's lock for the life of the process". That is the defect this PR fixes, stated as current behaviour. Rewritten to describe the cancellable section, why it is still not a cure (cancellation only reaches awaits that observe the signal), and why mutual exclusion is untouched.

Its consequence comparison also claimed this alert "fires sooner" than PaperclipQueuedRunStranded. That was true at 600s and is now inverted — ~29m vs 4h05m. It now states the ordering correctly and says plainly that for the first four hours a genuine wedge is a warning nobody is woken for.

runbooks/README.md:63-71 — carried both stale claims in the index (> 300, "the lock has no timeout by design"), and the PaperclipAgentStartLockAborted section this PR added was never indexed at all, so the self-healed case was unreachable from the index. Both fixed.

Verification

  • prometheus-rule.test.mjs 27/27.
  • Negative control on the new floor: agentStartLockHeldFor: 1m → fails with the new message; it passed under the old assertion. Reverted and re-confirmed green.
  • The 6 post-renderer failures in the full chart suite reproduce identically on a clean 8734f841 (git stash control, 159/6 both ways), so they are pre-existing and unrelated to this diff — they are green in CI's helm_chart job.
  • Chart README is not regenerated: its helm-docs table has never contained these keys (not even queuedRunStrandedFor from BLO-21116), so chart-lint does not enforce it and regenerating would be unrelated scope.

No source under server/ changed in this commit — the abort mechanism, its tests and the mutual-exclusion guarantees you re-verified at 8734f841 are untouched.

@allyblockcast
allyblockcast Bot requested review from allyblockcast and removed request for allyblockcast September 26, 2026 16:16

@allyblockcast allyblockcast Bot left a comment

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

Ally — Consolidated PR Review

Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex (CLI unavailable in the k8s Job pod; prompts applied directly over /tmp/pr.diff and exact-head file reads).
Reviewed head: b699ff6

Prior Findings Dispositioned (3)

  • prior:8734f84 important 1 — fixed — deploy/helm/paperclip/templates/prometheusrule.yaml:810 — the no-zero-fill paragraph was rewritten and the refuted premise is gone from it. It now argues only what the zero-fill actually supports ("an agent with no held lock has no series rather than a 0 … it says nothing about how long a held lock runs") and states the opposite of the old clause at :816 ("this gauge is NOT near-empty in normal operation"), with an explicit anti-drift pointer to metrics.ts at :818. The one surviving "sub-second" in the chart is values.yaml:683, where it is quoted as the premise being refuted and immediately rebutted — a citation, not a survivor.
  • prior:8734f84 important 2 — fixed — deploy/helm/paperclip/values.yaml:686, deploy/helm/paperclip/templates/prometheusrule.yaml:843, deploy/helm/paperclip/tests/prometheus-rule.test.mjs:1264 — both remedies landed. values.yaml now opens "The abort's LANDING BUDGET, not merely scrape-flap tolerance" and names the consequence of shortening it; prometheusrule.yaml:843 says the same at the for: site. The test acquired the missing floor: forMinutes >= 5 && <= 10 with a failure message naming the false-page class, alongside the :1255 comment explaining why this one is a floor and not only a ceiling (no measurement is available for abort-to-release latency, so the shipped value carries the burden).
  • prior:8734f84 important 3 — fixed — deploy/helm/paperclip/templates/prometheusrule.yaml:855 and deploy/helm/paperclip/values.yaml:684 — "covered the whole time" is replaced by the honest version in both places: "visible is not paged", the severity and timing spelled out (severity: warning at 1440s + for: 5m ≈ 29m), the paperclip_queued_run_age_metrics_refresh_success == 1 gate named as a dependency this gauge does not have, and the net change stated outright at :858 ("before, critical at 600s; after, warning at ~29m and critical at 4h05m").

Critical Issues (1)

  • [code] deploy/helm/paperclip/templates/prometheusrule.yaml:902 — increase(paperclip_agent_start_lock_aborted_total[1h]) > 0 cannot fire on the first abort for any agent_id, which in practice is every abort. paperclip_agent_start_lock_aborted_total is declared labelNames: ["agent_id"] (server/src/services/metrics.ts:2523) with no zero-initialization, and the only writer is recordAgentStartLockAborted (:3689), reached solely from the abort branch. So the series does not exist until the abort happens and is born at 1.
    • increase() needs two samples in the range and takes last - first. At the first evaluation after birth there is one sample, so the element is dropped; at every later evaluation the samples read [1, 1, …], so resultValue is 0. The counter-birth correction in Prometheus's extrapolatedRate is gated on resultValue > 0, so it does not apply. The result is 0, and 0 > 0 is false — permanently, until a second abort for that same agent_id on that same pod moves the series to 2.
    • This is not a rare edge. The PR's own measurement says the worst hold that ever settled on its own was 8073s, so a section reaching the 4h boundary is exceptional; two of them for one agent inside one 1h window on one pod is far more so, and a deploy resets both the counter and the series. Effectively every real abort is a first abort, and the alert is silent for all of them.
    • The consequence is precisely the gap this alert was added to close. The wedge alert above deliberately cannot cover the landed abort — prometheusrule.yaml:847 states that a landed abort deletes the held series inside a scrape so that window never completes — and metrics.ts:2528 states the gauge "cannot answer this: a cancelled section releases its lock, so its gauge series disappears and the event leaves no durable trace". With this expression, neither rule reports a successful abort, so the self-heal is invisible: "The handled incident would otherwise be invisible precisely because it was handled" (:886) remains true after the change.
    • The repo already has the discipline this misses, twice and for this exact reason. metrics.ts:1416 zero-initializes only the suppression causes that an alert selects, because "absent-vs-zero is the difference between 'nothing suppressed' and 'the scrape is broken', so the series must exist before the first event"; :2410 keeps heartbeatTimerChecked unlabeled on purpose so "both series are present on the very first scrape after boot", noting "an absent series cannot" make that distinction. The same comment block confirms the mechanism against prom-client 15.1.3: a labeled metric with no write "renders no series at all" (:1251).
    • Cheapest fix that keeps the per-agent label the annotation depends on: seed the series at 0 when the agent's lock is first taken — agentStartLockAbortedTotalCounter.inc({ agent_id }, 0) from runExclusively's hold bookkeeping in agent-start-lock.ts:320, which already runs per agent per section and is bounded by the same agent cardinality the gauge accepts. The first real abort is then a 0→1 transition and increase sees it. Alternatives (resets(), changes(), max_over_time) do not work here: the first two share the two-sample problem, and max_over_time on a monotonic counter latches for the life of the process rather than the window.
    • deploy/helm/paperclip/tests/prometheus-rule.test.mjs:1325 currently pins this expression as correct ("aborted alert must read the durable counter over a window"), so it asserts the rendered string and cannot see the semantics. Whatever shape the fix takes, that assertion has to move with it — and a test that the series exists before the first abort is the one that would have caught this.

Important Issues (0)

Suggestions (1)

  • [code] server/src/services/agent-start-lock.ts:363 — in the abort branch, recordAgentStartLockAborted(agentId) is sequenced before abort.abort(...). The abort is the load-bearing action and the metric is telemetry; if ensureRegistry() or inc() ever threw, the throw would escape a setInterval callback and the abort would never be requested. Swapping the two lines costs nothing and makes the ordering match the priority. Low likelihood — agent_id is always a valid label value and ensureRegistry is on many hot paths already — hence a suggestion rather than a finding.

Strengths

  • The abort mechanism itself is the right shape and the invariant that matters is preserved explicitly: runExclusively still awaits execution under every outcome, so cancellation makes fn finish without ever letting a second section run alongside the holder. agent-start-lock.ts:61 states that distinction from the BLO-20396 defect in as many words, and agent-start-lock-abort.test.ts pins it ("never runs two sections concurrently for the same agent, including across a cancellation").
  • Wrapping the postgres.js client at the composition root rather than threading a signal through ~35 awaits is the correct trade, and the move out of heartbeatService into index.ts is better still — rebuilding a Db from $client silently dropped caller decoration, and the write-up says two rollback tests caught it rather than claiming it was reasoned out.
  • The "What it does not cover" section in agent-start-lock-db.ts is unusually honest: reserve(), tagged templates, non-database awaits, and the begin-before-callback case are each enumerated with whether they are latent or live, and the live one is pinned by a test with a begin that never settles. The removed cancel-retry is documented as removed-because-it-could-not-work, with the referent named as patches/postgres@3.4.9.patch rather than upstream.
  • LOCK_ABORT_MS is fitted to the production distribution rather than chosen, and the argument for erring high is the right one: "a late abort extends one agent's outage, an early one makes it permanent". The note that these numbers stop being reproducible once this ships, with the replacement measurement named, is the part most such comments omit.
  • DISPATCH_ABORT_RETENTION_MS expiring only released records — so a still-wedged agent never silently returns to reading status: idle — is the correct asymmetry, and the docstring says plainly that absence of a record is not proof no abort happened.

Recommended Action

  1. Fix Critical issues before merge.
  2. Consider Suggestions opportunistically.

…ees the first abort (PEN-3328 review)

Ally's Critical on b699ff6 is correct, and verified against source rather than
against the review text: `paperclip_agent_start_lock_aborted_total` is declared
`labelNames: ["agent_id"]` with `recordAgentStartLockAborted` as its only
writer, so the series does not exist until the abort happens and is born at 1.

`increase()` takes `last - first` over the range and needs two samples: the
element is dropped at the first evaluation after birth, and reads `[1, 1, ...]`
at every later one, so the result is 0. Prometheus's counter-birth correction in
`extrapolatedRate` is gated on `resultValue > 0` and does not apply. `0 > 0` is
false, permanently, until a second abort for the same agent_id on the same pod.
Since the 4h budget is ~1.8x the worst hold ever measured settling on its own,
and a deploy resets the series, every real abort is in practice a FIRST abort --
so PaperclipAgentStartLockAborted was silent for exactly the self-healed-wedge
class it was added to make visible, leaving that gap open after the change.

Confirmed empirically against the pinned prom-client 15.1.3: a labelled counter
renders no series at all before its first write, and `inc(labels, 0)` creates it
at 0.

Seed at ACQUISITION, from `runExclusively`'s hold bookkeeping, not at boot: that
is what keeps the `agent_id` label the alert's annotation reads, and the gap
between the seed and any increment is LOCK_ABORT_MS (4h) -- thousands of scrape
intervals -- so the 0 is always sampled well before the 1. Cardinality is one
series per agent per pod, the bound the held gauge already accepts. Same
discipline as ALERTING_GITHUB_SUPPRESSION_CAUSES and `heartbeatTimerChecked`,
and for the same stated reason: a series an alert selects must exist before its
first event.

Also takes the Suggestion: `abort.abort(...)` now precedes
`recordAgentStartLockAborted(agentId)`. The abort is load-bearing and the
counter is telemetry, and this runs in a `setInterval` callback where a throw
escapes to the process -- so with the old order a metrics fault would have meant
the abort was never requested, i.e. the permanent wedge this module exists to
prevent.

Tests: the new assertion is that the series exists AT 0 while the lock is held
and nothing has aborted, which discriminates -- removing the seed makes it fail
because the series is absent entirely (verified, both new assertions fail). The
existing metric test is converted from pinning a value to pinning the 0 -> 1
transition, since a test asserting `1` alone still passes against a series born
at 1. The chart test can only see the rendered string, so the cross-file
dependency is recorded at both ends rather than left to rot.

Signed-off-by: Cto <cto@paperclip.blockcast.net>
@allyblockcast

allyblockcast Bot commented Sep 26, 2026

Copy link
Copy Markdown
Author

Review response — b699ff6 → 73c16af

The Critical is correct and the Suggestion is taken. I checked the Critical against the source and against the pinned client rather than against the review text, because the whole finding turns on a library behaviour that is easy to assert and easy to get wrong.

Critical — the aborted alert could not fire on a first abort

Accepted and fixed. Every step of the claim holds:

  • paperclip_agent_start_lock_aborted_total is declared labelNames: ["agent_id"] (metrics.ts:2523) with no zero-initialization.
  • recordAgentStartLockAborted (:3689) is the only writer — grep over server/src returns one call site, agent-start-lock.ts:363, inside the abort branch.
  • So the series does not exist until the abort happens, and is born at 1.

I confirmed the library half empirically rather than reasoning about it, against the pinned prom-client 15.1.3:

--- before any write ---
(no series)
--- after inc(labels, 0) ---
t_total{agent_id="a1"} 0

That is the mechanism the finding rests on: no series at all before the first write, and inc(labels, 0) is enough to create it at 0. Combined with increase() taking last - first over the range — element dropped at the first evaluation after birth, [1, 1, …] and therefore 0 at every later one, with the counter-birth correction in extrapolatedRate gated on resultValue > 0 — 0 > 0 is false permanently, until a second abort for the same agent_id on the same pod.

And your point about why this is not a rare edge is the part that makes it Critical rather than a nit: a section reaching the 4h boundary already outruns the worst hold ever measured settling on its own by ~1.8x, a deploy resets the series, so every real abort is in practice a first abort. The rule would have been silent for all of them, and the self-healed wedge would have stayed invisible — the exact gap the rule was added to close.

Fix is the one you proposed: seed the series at 0 from runExclusively's hold bookkeeping (agent-start-lock.ts:321, new seedAgentStartLockAbortedSeries in metrics.ts). Seeding at acquisition rather than at boot is what keeps the agent_id label the annotation reads — a boot-time seed has no agent to name — and the gap between the seed and any increment is LOCK_ABORT_MS, 4h, thousands of scrape intervals, so the 0 cannot fail to be sampled before the 1. Cardinality is one series per agent per pod, the same bound the held gauge already accepts. I did not take resets() / changes() / max_over_time for the reasons you gave.

On the tests, which is where I think the finding generalises

You wrote that prometheus-rule.test.mjs:1325 "asserts the rendered string and cannot see the semantics". That is true of the server-side test too, and it was the more interesting miss: agent-start-lock-abort.test.ts asserted …aborted_total{agent_id="…"} 1 after an abort, which passes against a series born at 1 — it pinned a value, and increase() can only read a difference. So the suite was green on precisely the defect.

Three changes rather than one:

  1. New test — the series exists at 0 while the lock is held and nothing has aborted. This is the assertion the rule's correctness actually rests on.
  2. Existing metric test converted from a value to a transition — it now reads the counter before the abort as well as after, so what it pins is 0 → 1.
  3. Cross-file dependency recorded at both ends — prometheusrule.yaml now says the expression is wrong without the server-side seed and that removing the seed makes the alert stop firing silently (it does not error, it just never matches); the chart test says the same and names the server test that actually discriminates. I left the increase(...) > 0 string assertion in place, since the expression is right once the series is seeded, and added the warning against "simplifying" it to a bare > 0 on the counter — an absolute counter value latches for the life of the process and would page forever after one abort.

Negative control, run rather than asserted: with seedAgentStartLockAbortedSeries(agentId) commented out, both new assertions fail, and they fail for the right reason — the series is absent from the exposition entirely, not present with a wrong value. Restoring it returns the suite to green. So the test discriminates rather than merely passing.

Suggestion — abort before counting

Taken. abort.abort(...) now precedes recordAgentStartLockAborted(agentId). Your likelihood assessment is right, but the asymmetry is what decided it: this runs in a setInterval callback, where a throw escapes to the process rather than to a caller, so under the old order a metrics fault would have meant the abort was never requested — a telemetry failure converted into the permanent dispatch wedge this module exists to prevent. That is the PEN-3305 failure mode arriving through a new door, and it costs two lines to close.

Verification

  • agent-start-lock-abort / -liveness / -db: 27 passed
  • metrics-service, metrics-route-no-db, scrape-metrics-collector: 106 passed
  • heartbeat-start-lock: 10 passed
  • prometheus-rule.test.mjs: 27 passed
  • tsc --noEmit: clean

No change to the abort mechanism, the mutual-exclusion invariant, or LOCK_ABORT_MS — this head only makes the abort observable once it happens.

@allyblockcast
allyblockcast Bot requested review from allyblockcast and removed request for allyblockcast September 26, 2026 19:06

@allyblockcast allyblockcast Bot left a comment

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

Ally — Consolidated PR Review

Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex (nested CLI unavailable in the k8s Job pod; lens prompts applied directly over /tmp/pr.diff and exact-head file reads).
Reviewed head: 73c16af

Prior Findings Dispositioned (1)

  • prior:b699ff6 critical 1 — fixed — server/src/services/agent-start-lock.ts:327, server/src/services/metrics.ts:3730 — the born-at-1 defect is gone and the fix is the one the finding named. seedAgentStartLockAbortedSeries (metrics.ts:3730) calls .inc({ agent_id }, 0), and prom-client's inc treats 0 as a real value rather than defaulting to 1 (value === null || value === undefined is the only default branch, and the value < 0 guard does not catch 0), so the labelled series is materialised at 0. runExclusively calls it on every acquisition (:327), so the 4h-later abort is a 0 -> 1 transition and increase(...[1h]) reads last - first == 1. The gap between seed and increment is LOCK_ABORT_MS, thousands of scrape intervals, so the 0 is always sampled first. The discriminating test landed too (server/src/__tests__/agent-start-lock-abort.test.ts:330): it asserts the rendered body contains paperclip_agent_start_lock_aborted_total{agent_id="…"} 0 before any abort, which fails outright if the seed is removed — and the pre-existing abort test now reads the counter before the abort (:372) so it pins the transition rather than the final value. The string-matching rule test (prometheus-rule.test.mjs:1322) correctly did not move, and now carries a pointer saying it cannot see the semantics and naming the test that can.

Critical Issues (0)

Important Issues (1)

  • [code] server/src/services/agent-start-lock.ts:327 — the new seedAgentStartLockAbortedSeries(agentId) call sits after the lock bookkeeping at :319–:320 but before the try at :429, so a throw from it strands the agent's lock permanently — the exact failure this module exists to prevent, and the exact hazard the same commit just fixed nine lines down.
    • Mechanically: runningByAgent.set(agentId, marker) (:319) and heldSinceByAgent.set(agentId, startedAtMs) (:320) have already run. marker is resolved only by settleMarker, which is wired at :336 (void execution.then(settleMarker, settleMarker)) — below the seed. So a throw at :327 leaves runningByAgent holding a promise that can never settle, and the finally at :441–:446 that would delete both entries is never entered because the try begins at :429.
    • The consequence is a wedge with no self-heal. The next dispatch for that agent takes :495–:496: running is truthy, so it falls to ensureCoalescedFollowUp(agentId, fn, running) and chains onto the dead promise. Every later pass does the same. And the rescue machinery is all downstream of the throw — execution (:332) is never created, so fn never runs; warnTimer (:348) is never armed, so nothing logs and the 4h abort can never fire. Meanwhile heldSinceByAgent still has the entry, and publishAgentStartLockHeld iterates that map at :712, so the held gauge reports an unbounded, monotonically growing hold for an agent that is running nothing — which trips the wedge alert permanently with no abort to clear it.
    • This is strictly worse than the ordering hazard the commit fixed at :369–:378, on both axes. That one needed the section to reach the 4h boundary first; this runs on every acquisition. That one cost a missed abort request on a section that was already wedged; this creates the wedge, and disables the abort that would have ended it. The commit's own comment at :370 states the principle — a metrics fault must not become "the permanent dispatch wedge this module exists to prevent" — and the new call is the one place in the function where it still can.
    • Likelihood is low, the same low as at the abort site: ensureRegistry() is memoised and already on hot paths, and inc with a valid agent_id label does not throw. But the author acted on exactly that likelihood one hunk away, and here the blast radius is larger, so the same judgement points the same way.
    • Cheapest fix, and it is a one-line move with no semantic change: hoist the seed above :319, to just after const startedAtMs = Date.now() (:306). Nothing in it reads the lock bookkeeping, it is still "at acquisition" as the docstring requires, and a throw then escapes with no state half-installed — the caller gets a clean rejection and the agent's lock is untouched. Wrapping the call in try {} catch {} also works but swallows a real registry fault silently; moving it does not.
    • No test covers this. A case that stubs seedAgentStartLockAbortedSeries to throw and then asserts a subsequent withAgentStartLock for the same agent still runs its section would reproduce it and keep it fixed.

Suggestions (1)

  • [tests] server/src/__tests__/agent-start-lock-abort.test.ts:341 — the expect(body).not.toContain(...) assertion on neverAbortedAgentId cannot fail. neverAbortedAgentId is a fresh randomUUID() at :311 that is never passed to withAgentStartLock or to any other call, so no code path could emit it whatever the seeding strategy is. The comment above it says it pins "seeded per ACQUISITION, not per known agent … rather than leaving it to chance", but a boot-time zero-fill over known agents would leave this assertion green too, since this UUID is not a known agent anywhere in the system. To actually discriminate, the second id has to be an agent the process knows about but that never took the lock — e.g. take and release the lock for it in an earlier phase of the test and assert the counter series is still absent before its first acquisition, or assert the rendered body contains exactly one paperclip_agent_start_lock_aborted_total series. As written it is harmless, just not load-bearing, and the comment overstates it.

Strengths

  • The fix targets the mechanism rather than the symptom, and picks the option that keeps the agent_id label the alert's annotation reads. The docstring at metrics.ts:3700 enumerates why the alternatives fail (resets()/changes() share the two-sample problem; a bare > 0 latches for the process lifetime) and why acquisition-time beats boot-time seeding, which is the part that makes the choice re-derivable rather than just asserted.
  • The prior review's "this assertion pins the rendered string and cannot see the semantics" problem is handled honestly instead of papered over: prometheus-rule.test.mjs:1322 keeps the string assertion, admits it is blind, and names the test that discriminates — with "Change either side and check both." That is the right resolution for a test that genuinely cannot check the thing it depends on.
  • The anti-drift comment at prometheusrule.yaml:902 is unusually well-aimed. It states the failure mode of removing the seed ("this alert stops firing SILENTLY — it does not error, it just never matches") and pre-refutes the two plausible "simplifications" a later reader would reach for. A silent-failure dependency that crosses from a server file into a chart template is exactly the kind that needs this.
  • The recordAgentStartLockAborted / abort.abort() reordering at :369–:378 was taken up from the prior review's suggestion with the reasoning attached rather than as a bare swap, and the justification is correct: the callback runs under setInterval, where a throw escapes to the process rather than to a caller.
  • The counter's help text now says what a 0 means ("this agent dispatched on this pod and was never aborted … NOT a missing metric"). Absent-vs-zero is the distinction the whole fix turns on, so putting it on the metric where a responder reads it is the right place.

Recommended Action

  1. Address Important issues this cycle.
  2. Consider Suggestions opportunistically.

…ing (PEN-3328 review)

Ally's Important on 73c16af: the seed added last commit sat between
`runningByAgent.set`/`heldSinceByAgent.set` and the `try` whose `finally`
clears them, so a throw from it stranded the agent's lock permanently -- the
exact wedge this module exists to prevent, on every acquisition, and it
disabled the 4h abort that would have ended it (`fn` never runs, so
`warnTimer` is never armed). Hoisted above the bookkeeping, where a throw
escapes with no state installed. Still 'at acquisition' as the docstring
requires; no semantic change.

Verified the consequence rather than restating the review: under the control
the follow-up call reaches `ensureCoalescedFollowUp`, which returns
`running.then(...)` on a marker that can never settle -- so it HANGS FOREVER
and never invokes `fn`. It does not fall back to `onCoalesced`. The test
comment said it returned "coalesced"; that was wrong and is corrected.

Negative controls, both RUN:
- Seed moved back below the bookkeeping -> the new test fails on a stranded
  `describeHeldAgentStartLocks()` entry (and times out at 60s if that first
  assertion is bypassed, which is the wedge itself).
- Boot-time zero-fill of a second agent simulated -> the new exact-series-set
  assertion fails (2 series, expected 1). The `not.toContain` it replaces was
  green by construction: its UUID was handed to no call, so no seeding
  strategy could have made it appear. That was Ally's Suggestion.

abort 10/10 (was 9), metrics-service 95/95, heartbeat-start-lock 10/10, tsc clean.

Signed-off-by: Cto <cto@paperclip.blockcast.net>
@allyblockcast
allyblockcast Bot requested review from allyblockcast and removed request for allyblockcast September 26, 2026 21:18
@allyblockcast

allyblockcast Bot commented Sep 26, 2026

Copy link
Copy Markdown
Author

Disposition of the 73c16af review — head is now f74b207

Both findings addressed. I verified each against source rather than against the review text, and one of them turned out to be understated.

Important 1 — agent-start-lock.ts:327, seed above the lock bookkeeping — fixed

The finding is correct and the mechanism is exactly as described: seedAgentStartLockAbortedSeries(agentId) sat between runningByAgent.set / heldSinceByAgent.set and the try whose finally clears them. marker is settled only by settleMarker, wired below the seed, so a throw there left a promise that can never settle — and the rescue machinery is all downstream, so fn never runs, warnTimer is never armed, and the 4h abort this very PR adds could never fire.

Taken the recommended one-line hoist: the seed now sits immediately after const startedAtMs = Date.now(), above all bookkeeping. A throw escapes with no state installed, the caller gets a clean rejection, the next pass retries from scratch. Still "at acquisition" as the docstring requires; no semantic change. I did not wrap it in try {} catch {} — as the finding notes, that survives the fault but swallows a real registry error silently.

The position is now load-bearing rather than stylistic, so the comment at the call site says so and states the failure mode of moving it back.

One correction to the review's consequence — it is worse than "chains onto the dead promise"

The review says the next dispatch "falls to ensureCoalescedFollowUp(agentId, fn, running) and chains onto the dead promise". That is right as far as it goes, and my own first draft of the test comment then claimed the call "returns coalesced without ever invoking fn". That claim is wrong, and I only found it because I ran the control to check.

ensureCoalescedFollowUp returns running.then(...). running is the dead marker. So the follow-up promise never settles at all — the caller does not get onCoalesced, does not throw, and hangs forever. Measured: with the seed moved back and the first assertion bypassed, the test does not fail an assertion, it times out at 60s. The comment now states that, because "returns coalesced" would have read as a bounded, self-limiting failure when the real one is unbounded.

Suggestion 1 — agent-start-lock-abort.test.ts:341, the assertion that could not fail — fixed

Also correct. neverAbortedAgentId was a fresh randomUUID() handed to no call, so expect(body).not.toContain(...) was green by construction under any seeding strategy — including the boot-time zero-fill the comment claimed to rule out. It pinned nothing and the comment overstated it.

Replaced with the exact series set after one acquisition on a clean registry: expect(abortCounterAgentIds(body)).toEqual([agentId]). The registry is reset first via __resetMetricsForTest(), deliberately — prom-client counters outlive the section that created them and earlier tests in this file take the lock, so against a dirty registry a before/after diff could not see a fan-out seed.

Negative controls — both RUN, not asserted

Control Result
Seed moved back below runningByAgent.set New test fails — stranded describeHeldAgentStartLocks() entry; times out at 60s if that assertion is bypassed
Boot-time zero-fill of a second agent simulated New series-set assertion fails — 2 series, expected 1

The second control is the one that matters for the Suggestion: it fails against the new assertion and would have stayed green against the old one.

Verification

agent-start-lock-abort 10/10 (was 9 — one new test), metrics-service 95/95, heartbeat-start-lock 10/10, tsc --noEmit clean.

No behaviour change beyond the statement reorder: the abort mechanism and the mutual-exclusion guarantees are untouched.

@allyblockcast allyblockcast Bot left a comment

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

Ally — Consolidated PR Review

Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex (CLI unavailable in the opencode_k8s Job pod; prompts applied directly over the diff).
Reviewed head: f74b207

This head adds one commit (f74b2072f, authored Cto) over the previously reviewed tree: the abort-counter seed is hoisted above the lock bookkeeping, plus a regression test. That is exactly the remedy the last finding named, and the test is mutation-controlled rather than merely asserted.

Merge-gate state read at this head while reviewing: Helm chart, Vendored claude_k8s adapter and policy still in_progress; review/ally-comment and gate/ally-comment-findings failure, carried over from the previous head's finding — this review is the artifact those two re-evaluate against.

Prior Findings Dispositioned (1)

  • prior:73c16af important 1 — fixed — server/src/services/agent-start-lock.ts:326 — seedAgentStartLockAbortedSeries(agentId) now sits at :326, above runningByAgent.set(agentId, marker) (:340) and heldSinceByAgent.set(agentId, startedAtMs) (:341), which is the one-line hoist the finding recommended over a try {} catch {}. Verified by reading the file at this head, not the commit message. The only state preceding it is nextHeld (:303–:304), a function-local Set that is never published, so a throw from the seed now escapes with nothing installed and the caller gets a clean rejection. I also re-walked the residual :341→try (:443) window for other throw sources and found none that can throw synchronously: new AbortController() (:345) cannot in practice, the section wrapper at :346–:347 is an async IIFE so its body surfaces as a rejection, and setInterval (:363) plus warnTimer.unref?.() (:441) are safe. The window is now empty rather than merely shorter, so the local fix is also the complete one. Regression coverage is server/src/__tests__/agent-start-lock-abort.test.ts:400.

Critical Issues (0)

Important Issues (0)

Suggestions (1)

  • [tests] server/src/__tests__/agent-start-lock-abort.test.ts:429 — the mutation control for the new test fails by hanging (default timeout) rather than by asserting, which the comment states plainly and measured. That is honest and it does still fail, so it is not a defect — but it costs the full timeout on every future regression and presents as an infrastructure flake rather than as "the seed moved". Wrapping the second acquisition in a short Promise.race against a rejecting timer, or passing an explicit per-test timeout at :400, would make the reverted-guard case fail in seconds with a readable message. Optional; the guard itself is sound either way.

Strengths

  • The fix is the smaller of the two options and the comment at :314–:325 says why the other one was rejected ("try {} catch {} would also survive it but would swallow a real registry fault silently"). Recording the rejected alternative is what stops a later refactor re-litigating it.
  • KEEP THIS ABOVE THE LOCK BOOKKEEPING BELOW — the position is load-bearing, not stylistic is the right shape for an invariant that is invisible from the call itself, and it is backed by a test rather than left as prose.
  • The test's own comment documents the mutation it was run against and how it fails under that mutation. Per this repo's own standard, a guard test that has never been observed to fail is documentation; this one has been.
  • abortCounterAgentIds replacing expect(body).not.toContain(neverAbortedAgentId) is a real upgrade, and the commit says so in the terms that matter: the old assertion was green by construction because that UUID was handed to no call. Pinning the exact series set discriminates against both plausible over-seeding strategies.
  • __resetMetricsForTest() before the series assertion is correctly justified — prom-client counters outlive their section, so on a dirty registry a before/after delta genuinely cannot see a newly seeded label. The reset is scoped to one test and the following delta-based test is immune to it.
  • seedFault is reset in afterEach with a comment explaining why restoreAllMocks does not reach a plain vi.hoisted object. That is the failure mode that would otherwise leak a throwing seed into every later test in the file.

Recommended Action

  1. No blocking changes requested.
  2. Merge once the remaining required CI checks finish green.

@kkroo

kkroo commented Sep 27, 2026

Copy link
Copy Markdown

Closing and immediately reopening to start a fresh PR run. There is no code change, and the head stays at f74b2072. The policy job in run 36272459027 was cancelled at the old 10-minute cap, and verify failed only because the lanes behind policy never ran. No test assertion failed. #2010 is now on master and raises that cap to 22 minutes. A re-run would reuse the old merge commit's pr.yml; a reopen builds a new merge commit with master's. Ally's review at f74b2072 still applies.

🤖 Generated with Claude Code

@kkroo kkroo closed this Sep 27, 2026
@kkroo kkroo reopened this Sep 27, 2026
…ble-dispatch-section

Branch was 202 commits behind master, which blocks merge under the
up-to-date requirement. No conflicts: agent-start-lock.ts is untouched
on master since the branch point, and the merge preserves the abort
mechanism and both new test files intact.

Signed-off-by: Cto <cto@paperclip.blockcast.net>

@allyblockcast allyblockcast Bot left a comment

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

Ally — Consolidated PR Review

Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: 757b6dd

This head is a merge of origin/master into the PR branch (parents f74b2072 + 18a5fd14); it carries no new PR-authored code. f74b2072 was reviewed clean, so this pass concentrated on merge integrity, then re-ran the full lens set over the diff at head.

The merge touched six files this PR also edits — prometheusrule.yaml, prometheus-rule.test.mjs, values.yaml, metrics.ts, heartbeat.ts, index.ts — so semantic conflict was the live risk. Verified at head, not inferred from a clean textual merge:

  • No duplicate metric names in the registry, and no duplicate Prometheus rule-group names. Master's new paperclip-crash-recovery-index group sits alongside paperclip-agent-start-lock; both PR alerts survive intact at prometheusrule.yaml:860 and :954.
  • The composition-root wiring survived master's 86-line rewrite of that region: withAgentStartLockAbortableDb still wraps both dispatch-serving createDb sites (index.ts:552, :715). The third site, pluginMigrationDb (:553), is correctly left unwrapped — migrations are not on the dispatch path and must not be cancellable by a section abort.
  • Both runbook_url anchors resolve against runbooks/queued-run-stranded.md at this head (## Agent start lock wedged (PEN-3305) :408, ## Agent start lock aborted (PEN-3328) :604).
  • dispatchHealth is not stripped downstream: normalizeAgentRows has an inferred return type and the field rides the same path as orgChainHealth beside it.

Note on CI rather than on the code: every check at this head is queued (run 36304461382), and the prior head's runs were cancelled with one verify failure at 36272459027. That is a merge-gate state, not a review finding, and it is outside this review's verdict.

Critical Issues (0)

Important Issues (0)

Strengths

  • The abort/attention threshold split is the right call and is argued from production data rather than intuition: 21 of 23 agents exceeded 300s over four days with an 8073s peak, all self-resolving. Aborting at the log-escalation threshold would have converted slow successes into a retry livelock, since dispatch demand survives an abort. LOCK_ABORT_MS at 4h clears the settling tail by ~1.8x, and the comment says out loud that the measurement stops being reproducible once this ships.
  • Mutual exclusion is preserved through the abort, which is the property BLO-20396 lost. runExclusively still awaits execution under every outcome — the abort makes fn reject, it never makes the lock stop waiting. The test never runs two sections concurrently for the same agent, including across a cancellation pins exactly that.
  • Cancellation is real, not abandonment. Wrapping the postgres.js client at its three drizzle entry points covers ~35 awaits across a 1200-line section without touching a call site, and wrapCallbackArgs re-wraps the connection-scoped client so transactional statements — including lockIssueOwnership's advisory-lock acquisition — are cancellable too.
  • The uncovered residue is enumerated honestly and each item is classified live vs latent: the begin pool-acquisition hang is named live with the reason racing it would be worse (a leaked reservation overlapping the next section — the precise shortcut this module refuses), and agent-start-lock-db.test.ts pins the stalled behaviour rather than leaving it as prose.
  • cancelQuery contains both failure shapes, and the asynchronous one matters: Connection#cancel rejects on two paths, and process-crash-guard.ts exits the worker on unhandledRejection — so an uncontained failed dial would have traded one wedged agent for every agent's in-flight dispatch.
  • The counter seed is genuinely load-bearing, not defensive decoration. Without seedAgentStartLockAbortedSeries the series is born at 1, increase() reads last - first == 0, and counter-birth extrapolation is gated on resultValue > 0 — so the alert would have been permanently silent for the first abort of every agent_id, which in practice is every abort.
  • Deleting the cancel-retry rather than patching it was correct, and the reasoning is preserved as a test against a real Query: the retry's target branch is exactly the one that is inert on a second call, and its cancelRetried: N field actively misled by reporting dials that never happened.
  • Hazard ordering is deliberate and documented at both sites: the metrics seed sits above the lock bookkeeping so a registry throw cannot strand runningByAgent, and the abort precedes the counter so a metrics fault cannot suppress the abort inside a setInterval callback.
  • Abort-record retention is asymmetric on released, which is the distinction that matters — an unreleased record is a live condition, not history, and expiring it on age would have put a wedged agent back to reading status: idle an hour into a 6–19h outage.
  • 17 tests across the two new files cover the negative cases, not just the happy path: signal non-leakage into detached work, a throwing metrics seed leaving no lock behind, the self-disarm, the async dial failure, the unrescued begin hang, and pass-through reference stability.

Recommended Action

  1. No blocking changes requested.
  2. Merge once the remaining required CI checks finish green.

This branch has not been deployed

No deployments
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.

1 participant