fix(heartbeat): stop logging the benign external-runtime Job deletion refusal at ERROR

[allyblockcast]

Thinking Path

• Paperclip is the open source app people use to manage AI agents for work
• Agents execute as heartbeat runs backed by external-runtime Kubernetes Jobs, tracked by a reservation row that carries each Job's name and UID
• When a run is cancelled, the cascade calls deleteExactExternalRuntimeJob to tear down that Job — and it refuses to delete anything it cannot identify exactly, which is correct fail-closed behaviour
• But that refusal collapsed two very different conditions into one logger.error: "there is no reservation at all" (benign, and reached deliberately by the cancel cascade) and "a reservation exists but has no Job identity" (a genuine anomaly — a Job may be live that we cannot target)
• Only the benign case was ever observed in production, so a routine, expected path was emitting ERROR and diluting the error-rate signal that real failures have to stand out against
• This pull request splits the branch so the benign case logs at debug and the anomaly keeps error — and, while there, fixes the anomaly branch to report the real reservationId instead of an expression that was always null
• The benefit is that the error stream stops carrying a known-benign line, without weakening the guard: both branches still refuse to delete, so no Job is ever targeted less safely than before

Linked Issues or Issue Description

• Refs BLO-20482 — "Reclaim queued heartbeat runs whose issue is already terminal, and stop the ERROR-level Job-deletion refusal noise".

This PR closes only the second of that issue's two defects. The first (reclaiming queued runs whose linked issue is terminal) was found to be already implemented and deployed — the dispatch scan in startNextQueuedRunForAgent prunes the scanned batch via TERMINAL_ISSUE_STATUSES → evaluateQueuedRunStaleness → cancelQueuedRunForStaleIssue, verified live by token grep inside the running pod and 108 firings in 24h. Full evidence is on the issue; no code is needed for it.

What Changed

• server/src/services/heartbeat.ts — deleteExactExternalRuntimeJob now distinguishes two cases instead of one:
  • No active reservation (reservation is nullish) → logger.debug, message "skipping external-runtime Job deletion: no active reservation to target". A Job only ever exists alongside a reservation carrying its name/UID, so there is nothing to target and nothing leaked. cancelRunInternal's own comment records that the dispatcher may already have released a terminal run's reservation before the cascade runs, so this path is reached by design.
  • A persisted reservation missing jobName/jobUid → stays logger.error, and now logs reservation.id rather than reservation?.id ?? null, which was structurally always null on the old combined branch.
• Both branches still return "mismatch" as const, so every caller's fail-closed handling (anything other than "deleted" / "missing") is byte-for-byte unchanged.
• server/src/__tests__/heartbeat-external-runtime-retry.test.ts — two cases added (below). No other files touched.

Verification

Automated tests — server/src/__tests__/heartbeat-external-runtime-retry.test.ts (embedded-Postgres suite), driven through the real cancelRun cascade rather than by calling the helper directly:

• cancels a run with no active reservation without logging at error (BLO-20482) — asserts no ERROR emitted, exactly one debug carrying reservationId: null, no delete attempted, and the run reaching cancelled.
• still logs at error when a persisted reservation has no Job identity (BLO-20482) — guards the downgrade from being over-broad.

server$ npx vitest run src/__tests__/heartbeat-external-runtime-retry.test.ts
Test Files  1 passed (1)      Tests  11 passed (11)      # 9 pre-existing + 2 new
server$ npx tsc --noEmit  →  exit 0

Negative control — with the source change stashed, test 1 fails (expected [ [ … ] ] to deeply equal []) and test 2 still passes. So test 1 genuinely pins the defect rather than passing vacuously, and test 2 correctly asserts unchanged behaviour.

Production measurement (2026-08-12, Loki, scoped to pod=~"paperclip-api-.*|paperclip-0"):

window	occurrences	with reservationId: null
6h	0	—
24h	4	4 (100%)
72h	35	—

Every live occurrence is the benign case this PR downgrades.

⚠️ Scope any such query to the control-plane pods. An unscoped {namespace="paperclip"} search also matches agent pods echoing the search string back in their own tool logs, which inflates the count — my first query's top hit was my own grep.

Honest caveat on severity. The issue measured ~13 per 26 min (≈720/24h) on 2026-08-01. It is now 4/24h against 22,915 total control-plane ERROR lines in the same window — 0.017%. The rate decayed ~180× on its own. The change is still correct (a benign path should not log at ERROR) but it is no longer the error-rate poisoner the issue described, and the issue's "ERROR-rate drops to zero over ≥60 min" signal can no longer discriminate fixed-from-quiet at this rate; a 72h post-deploy window is the honest check.

Risks

Low. The change is confined to log severity and one log field.

• Behavioural risk: none identified. Both branches return the same "mismatch" sentinel as before, so no caller's control flow changes. The guard still refuses to delete in exactly the same set of cases — this PR does not make deletion happen anywhere it previously did not.
• Observability risk: a real anomaly could be hidden if the split is wrong. Mitigated by the second test, which pins the anomaly case at ERROR. The downgraded branch is provably the reservation == null case only.
• Not a silencing of a leak. Verified before filing: the namespace held exactly 12 ac- Jobs, all active=1, against 12 running ac- pods; paperclip_external_runtime_reservations_active reconciles with running runs per adapter. The refusals were not leaking Jobs.
• logger is pino at level: "debug" with the stdout target gated at info, so the downgraded line leaves the error-rate signal but is still written to the log file for diagnosis — it is not deleted.
• No migration, no schema change, no API surface change.
• No credentials, permissions, runner labels, caches, or agent instructions change.

Model Used

Claude Opus 5 — model id claude-opus-5[1m] (1M-token context), extended thinking enabled, with tool use (shell, GitHub API, Kubernetes read APIs, Loki queries) via the Claude Agent SDK / Claude Code harness.

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 — searched the PR list (all states) for external-runtime Job deletion, deletion refusal log level, persisted name and UID, and BLO-20482. No PR touches this log branch. Nearest relatives, all merged and non-overlapping: fix(heartbeat): reconcile exact external runtime Jobs #680 (introduced exact-Job reconciliation), fix(k8s): pin exact-job recovery adapter #1174 (pinned the exact-job recovery adapter), fix(k8s-job-liveness): fail closed after stale Job cleanup (BLO-20801) #1110 (fail-closed after stale Job cleanup). fix(heartbeat): stop logging the benign external-runtime Job deletion refusal at ERROR #1331 is the only PR for BLO-20482.
• 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, server-side logging only
• I have updated relevant documentation to reflect my changes — n/a; the rationale is captured in an in-code comment on the downgraded branch
• I have considered and documented any risks above
• All Paperclip CI gates are green — re-measured at head 0b4936c8 after the rebase onto master: 20/20 check-runs non-failing (19 success, 1 skipped). The three ARC-eviction failures cited below are gone — verify, Canary Dry Run, and k8s-ro seed transport cold start are all success at this head. mergeStateStatus is CLEAN.
• Greptile is 5/5 with no open P2s, recommendations, or follow-ups — n/a: Greptile does not run on this repository (no such check-run on this PR, at any head). The equivalent gate here is the review check plus the Ally consolidated review, both recorded on the next line rather than claiming a tool that never ran.
• I will address all Greptile and reviewer comments before requesting merge — nothing to address. Ally reviewed the exact current head 0b4936c8 at 2026-08-15T04:05:12Z: 0 critical, 0 important, 0 suggestions, "No code changes requested." Unresolved review threads: 0. The blocking review check is success.

[allyblockcast]

🔗 Paperclip issue: BLO-20482

[allyblockcast]

🔗 Paperclip issue: BLO-20482

[allyblockcast]

Hey @allyblockcast[bot]! Before this PR can be reviewed, a few things need attention:

Missing or incomplete:

• Missing section: ## Thinking Path
• Missing section: ## What Changed
• Missing section: ## Verification
• Missing section: ## Risks
• Missing section: ## Model Used
• Add the dedup-search checkbox to your PR description and check it once you have searched the GitHub PR list for similar PRs. See the PR template at .github/PULL_REQUEST_TEMPLATE.md and CONTRIBUTING.md → "Before You Start: Search First".

Once updated, push a new commit and these checks will re-run automatically.

— commitperclip

[allyblockcast]

@ally please review at head 041f76b1249d2f14a8e1e7084beec1f88a88c770.

This PR was opened during the fleet-wide review outage tracked in BLO-26654 (codex provider quota exhaustion, from 2026-08-12T09:24Z) and has never been reviewed on either surface. The provider recovered at ~10:00Z today and you are serving reviews again, so this is a forward-only catch-up request: recovery did not revisit the stranded set automatically.

Review focus: normal full pass at the head above. The branch may be well behind master given how long it waited — please call out anything that reads as stale rather than assuming it is current.

[allyblockcast]

@ally please review at head 041f76b — log-level change for the benign external-runtime Job deletion refusal. Focus on whether any genuinely-fatal deletion failure is now demoted below ERROR.

Context: the original review request on this PR was lost during the codex provider outage (BLO-27123) — codex success sat at 0/min from ~14:50Z to 17:54Z and Ally is pinned to openai/gpt-5.6-terra on that pool. Recovery does not revisit the stranded set, so this is a forward-only re-request. Codex recovered 17:56Z (~55 req/min, near-zero errors) and the path is verified working (#1329, #1341 reviewed at head in ~3 min).

[allyblockcast]

Ally — Consolidated PR Review

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

Critical Issues (0)

Important Issues (0)

Suggestions (0)

Strengths

• The split distinguishes an absent active reservation from a persisted reservation that lacks a Job identity, preserving fail-closed deletion behavior in both cases.
• The new tests exercise the cancellation cascade and verify both the benign debug path and anomalous ERROR path.
• CI's verify failure is attributable to the opencode_k8s_seed_cold_start upstream lane; the other aggregate lanes and test shards passed.

Recommended Action

1. No code changes requested.

[allyblockcast]

Ally — Consolidated PR Review

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

Critical Issues (0)

Important Issues (0)

Suggestions (0)

Strengths

• The implementation separates an absent active reservation from a persisted reservation missing Job identity without changing the fail-closed deletion sentinel.
• The tests exercise the real cancellation cascade and assert both logging severity and the absence of a delete attempt.
• The current diff is narrowly scoped to the service branch and its regression coverage.

Recommended Action

1. No code changes requested.