fix(acpx): make stalled ACP session establishment observable (PEN-1995)

[allyblockcast]

Refs PEN-1990, PEN-1995, PEN-2324.

Thinking Path

• Paperclip is the open source app people use to manage AI agents for work, and it invokes and observes every agent heartbeat
• The claude_local adapter runs these heartbeats through the ACP engine (packages/adapter-utils/src/acpx-engine/), which establishes an agent session before it ever sends a turn
• Built-in agents were producing "stillborn" runs — a 3-line, ~679-byte log, no model output, no terminal acpx.result — that sat for hours and were structurally indistinguishable from a dead process
• adapterConfig.timeoutSec was reported as inert, so the obvious remedy looked like "make the timeout enforced"
• Reading the code shows that is wrong: the timer is armed after session establishment, so it bounds the turn and never covers the handshake where all measured stall time actually lives
• Enforcing it would therefore convert a silent-latency bug into silent work loss — one stalled handshake was observed recovering at 43.20 h and then completing successfully
• This pull request instruments the unobserved handshake so a stall is visible while it is happening, and deliberately imposes no ceiling
• The benefit is that the stall becomes diagnosable now, and the recoverability distribution needed to choose a safe threshold can finally be collected

Linked Issues or Issue Description

• Refs PEN-1990 — stillborn claude_local heartbeat windows
• Refs PEN-1995 — containment and root cause (this PR is step 1)
• Refs PEN-2324 — Summarizer stale-run discriminator
• Related PR: fix: bound silent claude local processes #1279 (same issues, CLI branch rather than ACP branch — see "Relationship to fix: bound silent claude local processes #1279" below). No other similar PRs found.

Why

adapterConfig.timeoutSec was reported as inert on claude_local. It is not inert — it measures the wrong interval.

packages/adapter-utils/src/acpx-engine/execute.ts arms its AbortController/setTimeout at line ~2155, which is after acpx.session is emitted at ~2100. The timer therefore covers the turn. Session establishment — runtime.ensureSession → agent spawn + session/new|session/load — is awaited at ~1993/2008, before any timer exists.

The acpx side does not cover it either. In acpx@0.12.0/dist/runtime.js:823-862:

await client.start();                                              // 850  ← unbounded
const session = await createOrLoadRuntimeSession(client, …, cwd);  // 851  ← unbounded
const record = await this.createAndSaveRuntimeRecord({…});         // 852
  └─ applyRequestedModelIfAdvertised({ …, timeoutMs: this.options.timeoutMs })  // 885 ← only use

AcpRuntimeOptions.timeoutMs reaches the set-model RPC and nothing else.

That gap is where the stall time lives — 90.56 min, 16.5 h+, and 43.20 h have all been observed between the pre-exec log lines and acpx.session, with the log frozen at 3 lines throughout.

It also explains the runs that exited 0 past their bound (3.4× and 172.7×), which had looked like proof the ceiling was never wired: once the handshake finally returned, the turn completed in ~10 s — well inside 900 s — so the turn timer had nothing to fire on. No PID is recorded on this path either, because acpx spawns its own client and paperclip's onSpawn never runs, which is why the process-lost reaper had nothing to reap.

What Changed

Observability only — no behavioral change to when a run lives or dies.

• Wrap runtime.ensureSession in packages/adapter-utils/src/acpx-engine/execute.ts so the previously silent handshake emits acpx.session_establish events: started, periodic waiting, then established or failed.
• Each event carries stage, attempt number, resume flag, and elapsed time — enough to locate a stall at client.start() versus the session/new|session/load handshake.
• Periodic waiting ticks back off to a 5-minute ceiling, so a multi-hour stall costs a few hundred log lines rather than thousands.
• Add 6 tests to packages/adapter-utils/src/acpx-engine/execute.test.ts, including one that drives the real execute() path end-to-end so the wiring is verified rather than only the helper.

The operational point is that this keeps the run's last-output timestamp advancing. Today a stalled handshake leaves lastOutputSeq: 1 frozen for hours, which is exactly why these runs are indistinguishable from a dead process and why the process-lost reaper has nothing to act on.

What this deliberately does NOT change

It does not terminate a slow handshake. One was observed recovering at 43.20 h and then completing successfully. Any ceiling picked from today's evidence would destroy recoverable work — a 30-minute ceiling would have killed that run 86× early. Choosing a threshold is deliberately left until the data this collects exists. A test asserts a slow handshake still succeeds, so the no-kill property is enforced rather than merely intended.

No change to timeoutSec, no change to retry policy, no schema migration, no live agent configuration.

Relationship to #1279

#1279 (same issues, still open) instruments runChildProcess and the claude_local CLI branch. The affected agents take the ACP branch, which returns at claude-local/src/server/execute.ts:576 and calls neither. #1279's onLifecycle emits nothing on an ACP stillbirth, and its 6 h default is applied in buildClaudeRuntimeConfig, reached only after that early return. This PR targets the branch the stalls actually occur on. #1279 remains a valid CLI-path improvement and is not superseded by this PR.

Verification

• packages/adapter-utils/src/acpx-engine/execute.test.ts — 61/61 pass (55 pre-existing + 6 new), so no regression on the live ensureSession path.
• tsc --noEmit on packages/adapter-utils — clean.
• New coverage: normal bracketing; periodic ticks while genuinely stalled; slow handshake still succeeds (guards the no-kill constraint); failure path stops ticking and preserves the error; payload carries no sensitive keys; and an end-to-end test driving the real execute() path to confirm the wiring.

⚠️ Reviewer install note: pnpm install --frozen-lockfile aborts in a fresh worktree on an unrelated opencode-ai postinstall (Failed to install the right opencode CLI package). Test deps land fine but node_modules/.bin is left unlinked, so I ran vitest as node node_modules/vitest/vitest.mjs. Pre-existing and unrelated to this diff, but it will bite anyone reproducing.

Not verified: no live production repro of a stalled handshake, and Reflection Coach is untested (same code path, but unmeasured). This change explains why nothing bounds the hang — not what causes client.start() to hang, which remains open on PEN-1995.

Risks

• Low risk to run outcomes. The change is additive instrumentation around an existing await; it introduces no kill path, no ceiling, and no retry, so it cannot shorten or terminate a run that would otherwise have succeeded. A test pins the slow-handshake-still-succeeds property.
• Log volume on a stalled handshake. Periodic waiting ticks add events for as long as a handshake hangs. Mitigated by exponential back-off to a 5-minute ceiling — a 43 h stall produces a few hundred events, not thousands.
• Event-payload safety. These events are emitted on the credential-adjacent session path. Payload is restricted to stage/elapsed metadata, and a test asserts the key set contains no prompt, credential, environment, or model-output material.
• Incomplete fix, by design. This does not resolve PEN-1995. It removes the observability blocker so the remaining items (retry behavior, host-window correlation, threshold selection) can be worked from data instead of guesses. Merging this should not be read as closing the stall class.
• Rollback is a plain revert of this commit — no migration, no config change, no state to unwind.

For core feature work, check ROADMAP.md first and discuss it in #dev before opening the PR. Feature PRs that overlap with planned core work may need to be redirected — check the roadmap first. See CONTRIBUTING.md.

Model Used

• Claude Opus 5 (claude-opus-5), 1M-context variant ([1m]), running as Claude Code via the Claude Agent SDK.
• Extended thinking enabled; tool use, repository inspection, and local test execution (vitest, tsc) used to produce and verify this change.

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 in this diff
• I have updated relevant documentation to reflect my changes — no doc change made; the new events are internal run-event telemetry
• I have considered and documented any risks above
• All Paperclip CI gates are green — 20/20 checks pass on 0214a7c5 (Storybook visual regression skipped: no UI surface). The policy failure noted earlier was a GitHub-infra 429/503 downloading actions/upload-artifact, not this diff; it passed on re-run.
• Greptile is 5/5 with no open P2s, recommendations, or follow-ups — not yet reviewed
• I will address all Greptile and reviewer comments before requesting merge

🤖 Generated with Claude Code

[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: ## 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]

🔗 Paperclip issue: PEN-1990
🔗 Paperclip issue: PEN-2324
🔗 Paperclip issue: PEN-1995

[allyblockcast]

Reviewer note — new field evidence since this PR was opened (no diff change)

CI is now 20/20 green on 0214a7c5 (Storybook skipped, no UI surface); the earlier policy failure was a GitHub-infra 429/503 fetching actions/upload-artifact and passed on re-run. Checklist updated. The diff is unchanged.

Posting this because evidence gathered after opening sharpens why this instrumentation matters — the PR currently undersells it.

The unobserved handshake is very likely swallowing a provider signal we already have

A live built-in agent (claude_local, ACP path) currently reports:

status:          running                      ← 31 h stale heartbeat
errorReason:     429 · BYOS provider capacity for 'anthropic' temporarily
                 unavailable; capacity may reset at 2026-08-21T16:59:59.417Z;
                 retry in 431986s             ← 5.00 days

Its run spawned 203 ms after that error was recorded and has emitted nothing for 31 h — the exact 3-line stillborn shape this PR instruments.

Two timing facts support a capacity-window mechanism rather than a plain hang:

event	timestamp	distance to nearest :00/:30
a previous stall ending after 43.20 h of silence	2026-08-15T23:00:02.489Z	2.49 s
the advertised capacity reset above	2026-08-21T16:59:59.417Z	0.58 s
control: that stall starting	2026-08-14T03:48:17.387Z	702.61 s
control: this stall starting	2026-08-16T17:02:14.844Z	134.84 s

Stalls exit on a boundary; they don't enter on one. That asymmetry is what distinguishes waiting for a capacity window from random latency.

Why this argues for merging as-is

The same underlying 429 reaches a claude_k8s agent as "hit provider throttle/deadline before any token usage; scheduled for transient retry" — it fails visibly and reschedules. The ACP path takes the identical condition and hangs silently, because ensureSession is unobserved and unbounded.

So the signal exists and another adapter already acts on it; the ACP path just drops it on the floor. This PR is the minimum change that makes that droppage visible — and the session_establish stage/elapsed events are exactly what's needed to confirm or kill the capacity hypothesis from run logs instead of from an agent's mutable errorReason field.

Caveats, unchanged

This is correlational — read from agent records, not a repro and not serving-side logs, and I could not re-read the stalled run's log. A prior instance had capacity explicitly ruled out (it recovered while capacity was still unavailable), so this is not settled. A falsifiable check is scheduled for the 2026-08-21T16:59:59Z reset.

None of that changes the review: this PR adds no ceiling, no kill path, and no retry, and a test pins the slow-handshake-still-succeeds property. Whichever way the capacity question lands, the handshake needs to stop being invisible.