From 70a6655c9a85f025cd147f087a17bfc4de19ad17 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 01:27:21 +0800 Subject: [PATCH 01/27] docs: design rescue progress lifecycle --- ...-08-08-rescue-progress-lifecycle-design.md | 155 ++++++++++++++++++ 1 file changed, 155 insertions(+) create mode 100644 docs/superpowers/specs/2026-08-08-rescue-progress-lifecycle-design.md diff --git a/docs/superpowers/specs/2026-08-08-rescue-progress-lifecycle-design.md b/docs/superpowers/specs/2026-08-08-rescue-progress-lifecycle-design.md new file mode 100644 index 00000000..c8ed84f1 --- /dev/null +++ b/docs/superpowers/specs/2026-08-08-rescue-progress-lifecycle-design.md @@ -0,0 +1,155 @@ +# Rescue Progress and Foreground Lifecycle Design + +## Problem + +Foreground `$zcode:rescue` currently sends one ZCode turn and then waits only for +its terminal `state.updated` notification. A healthy delegated task can therefore +produce no visible output for minutes even while ZCode is actively running tools. +If the foreground companion is interrupted, its durable job may also remain +`running` until a later same-owner reconciliation. + +The observed failure mode was not a CPU deadlock: the nested Codex task continued +editing and running commands while the outer companion stayed silent. The user +could not distinguish that state from a dead process. + +## Goals + +- Surface bounded, user-safe ZCode activity during foreground review, adversarial + review, and Rescue runs. +- Persist the latest activity so `$zcode:status` explains what an active job is + doing without requiring private log inspection. +- Emit a periodic foreground heartbeat when ZCode has not produced a new activity + event. +- Turn foreground `SIGINT` and `SIGTERM` into an acknowledged ZCode session stop + and a durable cancelled job whenever the remote stop succeeds. +- Preserve the existing result, ownership, permission, recovery, and background + execution contracts. + +## Non-goals + +- Do not expose model reasoning, message text, tool inputs, command arguments, or + arbitrary `state.updated.patch` contents. +- Do not infer or kill process identifiers belonging to plugins or tools nested + inside ZCode. `session/stop` is the supported cancellation boundary. +- Do not add a polling loop around `session/read`; progress must use notifications + already delivered on the active protocol connection. +- Do not change the one-hour completion timeout or make inactivity itself a + failure. A quiet but healthy task remains valid. +- Do not change `--background` semantics. Background work survives the launching + Codex turn and is stopped through `$zcode:cancel` or session lifecycle cleanup. + +## Approach + +Use the existing ZCode protocol subscription as the common event boundary. A new +progress module converts only same-session `state.updated` notifications into a +small public event: + +```js +{ + phase: 'starting' | 'running' | 'waiting' | 'finalizing', + message: 'ZCode activity: tool call started', + observedAt: '2026-08-08T00:00:00.000Z' +} +``` + +The normalizer accepts a bounded, control-free `reason` and maps known reason +families to stable phases. Unknown safe reasons are humanized without inspecting +their patch. Terminal reasons become `finalizing`. Invalid, oversized, cross- +session, or non-`state.updated` notifications are ignored. + +The reporter has two sinks: + +1. Foreground stderr receives `[zcode] ` immediately. +2. The durable job stores `phase`, `lastActivityAt`, and the four most recent + progress messages. Messages are bounded and schema-validated by the state + store. Repeated identical activity is deduplicated. + +Progress persistence is serialized behind a small internal promise chain. It may +not overturn terminal state: if cancellation or completion wins first, a late +progress update observes the terminal job and becomes a no-op. Before publishing +the final result, the executor drains the progress chain. + +## Heartbeat + +Foreground commands start a 20-second unref'd heartbeat after the remote turn is +accepted. If no new activity has arrived, stderr receives a line such as: + +```text +[zcode] Still waiting for ZCode; last activity 42s ago. +``` + +The heartbeat is observational only. It does not update `lastActivityAt`, does +not enter the durable progress preview, and never extends a timeout. Background +workers do not emit heartbeats because their stdio is intentionally detached. + +## Status Rendering + +`$zcode:status ` renders: + +- job ID, command, status, and phase; +- start/finish timestamps and elapsed/duration; +- last ZCode activity timestamp; +- up to four recent progress messages; +- the existing model-policy summary. + +`$zcode:status --all` keeps one compact line per job and adds phase plus the most +recent progress message. JSON output includes the same public fields through the +existing redaction boundary. `$zcode:result` remains unchanged. + +## Foreground Interruption + +The executable entry point installs temporary `SIGINT` and `SIGTERM` handlers for +foreground invocations only and passes an `AbortSignal` through the companion to +the active executor. Once a ZCode turn has been accepted: + +1. Abort rejects the completion wait with a stable interruption error. +2. The executor requests `session/stop` on its existing authenticated client. +3. After stop acknowledgement, it transitions `running -> cancelling -> + cancelled`, records `finishedAt`, and closes the client. +4. The process exits with 130 for `SIGINT` or 143 for `SIGTERM` and emits a concise + stderr explanation rather than a misleading protocol error envelope. + +If ZCode does not acknowledge the stop, the job remains `running` with a bounded +`lastCancelError`. That conservative state allows existing recovery to inspect +the remote session later instead of falsely claiming cancellation. + +Signals received before a remote turn is accepted abort local setup and allow the +existing failure path to settle the reservation. Background workers retain their +current signal behavior so explicit cancellation remains the single owner of +their terminal transition. + +## State and Security Invariants + +- `phase` is from a fixed public vocabulary. +- `progressPreview` contains at most four control-free strings, each at most 256 + UTF-8 bytes. +- `lastActivityAt` is an ISO timestamp not earlier than `startedAt` and not later + than the job's updated timestamp. +- Notification content never reaches output unless it passes the bounded + normalizer. +- Progress updates do not change ownership, permission snapshots, worker leases, + accepted-turn boundaries, result artifacts, or terminal status. +- Existing redaction still removes capabilities, tokens, and permission state + from JSON output. + +## Testing + +Tests follow red-green-refactor and cover: + +- safe same-session normalization, known/unknown reasons, terminal mapping, + cross-session rejection, control characters, and byte limits; +- foreground stderr delivery, deduplication, heartbeat timing, and cleanup; +- durable progress schema validation, terminal no-op behavior, and retention of + only four messages; +- status text/JSON rendering for active and terminal jobs; +- interruption after accepted send, acknowledged stop, stop failure, correct exit + codes, and absence of signal handling in background workers; +- integration with the fake ZCode peer emitting intermediate notifications; +- the complete existing `npm run check` suite. + +## Release Notes + +The patch updates both READMEs and `CHANGELOG.md` to describe live foreground +activity, status previews, heartbeat behavior, and the foreground cancellation +boundary. The package version remains unchanged until the release step selected +by the maintainer. From 2c52cc5c7826b0b38724463b06af989fce68d058 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 01:28:05 +0800 Subject: [PATCH 02/27] docs: harden progress event rendering --- .../specs/2026-08-08-rescue-progress-lifecycle-design.md | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/docs/superpowers/specs/2026-08-08-rescue-progress-lifecycle-design.md b/docs/superpowers/specs/2026-08-08-rescue-progress-lifecycle-design.md index c8ed84f1..f03192ba 100644 --- a/docs/superpowers/specs/2026-08-08-rescue-progress-lifecycle-design.md +++ b/docs/superpowers/specs/2026-08-08-rescue-progress-lifecycle-design.md @@ -53,9 +53,10 @@ small public event: ``` The normalizer accepts a bounded, control-free `reason` and maps known reason -families to stable phases. Unknown safe reasons are humanized without inspecting -their patch. Terminal reasons become `finalizing`. Invalid, oversized, cross- -session, or non-`state.updated` notifications are ignored. +families to stable phases and fixed public messages. Unknown safe reasons produce +the generic message `ZCode reported activity`; their raw value and patch are not +rendered. Terminal reasons become `finalizing`. Invalid, oversized, cross-session, +or non-`state.updated` notifications are ignored. The reporter has two sinks: From 82182b36acba200bdc35002b441a0ca610dd2859 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 01:30:28 +0800 Subject: [PATCH 03/27] docs: plan rescue progress lifecycle --- .../2026-08-08-rescue-progress-lifecycle.md | 311 ++++++++++++++++++ 1 file changed, 311 insertions(+) create mode 100644 docs/superpowers/plans/2026-08-08-rescue-progress-lifecycle.md diff --git a/docs/superpowers/plans/2026-08-08-rescue-progress-lifecycle.md b/docs/superpowers/plans/2026-08-08-rescue-progress-lifecycle.md new file mode 100644 index 00000000..ac6e29c6 --- /dev/null +++ b/docs/superpowers/plans/2026-08-08-rescue-progress-lifecycle.md @@ -0,0 +1,311 @@ +# Rescue Progress and Foreground Lifecycle Implementation Plan + +> **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking. + +**Goal:** Make delegated ZCode work visibly alive, inspectable through `$zcode:status`, and durably cancelled when a foreground invocation is interrupted. + +**Architecture:** Normalize the existing same-session `state.updated` notification stream into bounded public progress events, then feed a reporter with foreground stderr and durable-state sinks. Add an abort path at the executable boundary which stops the owned ZCode session and settles the existing job state machine without changing background semantics. + +**Tech Stack:** Node.js 22.13+ ESM, `node:test`, ZCode 0.16.1 JSON-lines app-server protocol, existing private state store and advisory locks. + +--- + +## File Map + +- Create `scripts/lib/progress.mjs`: notification normalization, deduplicated reporting, heartbeat lifecycle, and abort-aware completion helper. +- Modify `scripts/lib/state.mjs`: schema-validated `updateJobProgress` operation and persisted progress fields. +- Modify `scripts/lib/review.mjs`: subscribe an active job to progress, drain it before finalization, and settle interruption through the cancellation lock. +- Modify `scripts/zcode-companion.mjs`: pass foreground progress/abort dependencies and map process signals to conventional exit codes. +- Modify `scripts/lib/render.mjs`: detailed status rendering and compact list summaries. +- Modify `tests/fixtures/fake-zcode-cli.mjs`: optionally emit safe intermediate notifications. +- Create `tests/progress.test.mjs`: progress normalizer, reporter, heartbeat, and abort helper unit tests. +- Modify `tests/state.test.mjs`: durable progress schema and terminal-race tests. +- Modify `tests/job-control.test.mjs`: executor subscription and interruption tests. +- Modify `tests/integration/companion.test.mjs`: real CLI progress and status integration tests. +- Modify `README.md`, `README.zh-CN.md`, and `CHANGELOG.md`: user-visible behavior and cancellation boundary. + +### Task 1: Safe Progress Event Boundary + +**Files:** +- Create: `scripts/lib/progress.mjs` +- Create: `tests/progress.test.mjs` + +- [ ] **Step 1: Write failing notification-normalization tests** + +Cover a same-session known reason, terminal reason, unknown reason, cross-session event, non-session scope, control character, oversized reason, and arbitrary secret-bearing patch. Assert that no patch content or unknown raw reason is returned. + +```js +test('normalizes only bounded same-session activity without exposing patch data', () => { + const known = normalizeZCodeProgress(notification('tool_call_started'), 'session-a', now); + assert.deepEqual(known, { + phase: 'running', + message: 'ZCode started a tool call.', + observedAt: now, + }); + assert.equal( + normalizeZCodeProgress(notification('future_secret_reason', { apiKey: 'never' }), 'session-a', now).message, + 'ZCode reported activity.', + ); + assert.equal(normalizeZCodeProgress(notification('tool_call_started'), 'session-b', now), null); +}); +``` + +- [ ] **Step 2: Run the focused test and verify RED** + +Run: `node --test tests/progress.test.mjs` + +Expected: FAIL because `scripts/lib/progress.mjs` does not exist. + +- [ ] **Step 3: Implement the bounded normalizer** + +Export `PROGRESS_PHASES`, `normalizeZCodeProgress`, and constants for four preview entries, 256 message bytes, and a 20-second heartbeat. Use fixed mappings for known reasons and a generic fixed message for unknown safe reasons. Reject non-object frames, wrong method/scope/session, empty/oversized reason, C0/C1 controls, and invalid timestamps. + +```js +const KNOWN = new Map([ + ['prompt_started', ['starting', 'ZCode started the delegated turn.']], + ['model_streaming', ['running', 'ZCode is generating a response.']], + ['tool_call_started', ['running', 'ZCode started a tool call.']], + ['tool_call_progress', ['running', 'ZCode tool work is still running.']], + ['tool_call_result', ['running', 'ZCode completed a tool call.']], + ['api_retry', ['waiting', 'ZCode is retrying the model request.']], + ['prompt_completed', ['finalizing', 'ZCode completed the delegated turn.']], + ['prompt_failed', ['finalizing', 'ZCode reported a failed delegated turn.']], +]); +``` + +- [ ] **Step 4: Add reporter and heartbeat tests, then verify RED** + +Use injected `write`, `persist`, `setInterval`, `clearInterval`, and `now` functions. Assert immediate `[zcode]` lines, duplicate suppression, serialized persistence, 20-second heartbeat text, no heartbeat persistence, and idempotent `close()`. + +Run: `node --test tests/progress.test.mjs` + +Expected: normalization tests PASS; reporter tests FAIL because `createProgressReporter` is missing. + +- [ ] **Step 5: Implement the reporter minimally** + +Export `createProgressReporter({ sessionId, write, persist, now, setInterval, clearInterval })` returning `{ observe, flush, close }`. `observe(message)` normalizes, deduplicates consecutive `(phase,message)` pairs, writes synchronously when a writer exists, and appends persistence work to one promise chain. `close()` clears its unref-capable heartbeat and `flush()` awaits the persistence chain. + +- [ ] **Step 6: Verify GREEN and commit** + +Run: `node --test tests/progress.test.mjs` + +Expected: all progress tests PASS with no warnings. + +Commit: `feat: add safe zcode progress reporting` + +### Task 2: Durable Progress and Status Rendering + +**Files:** +- Modify: `scripts/lib/state.mjs` +- Modify: `scripts/lib/render.mjs` +- Modify: `tests/state.test.mjs` +- Create: `tests/render-progress.test.mjs` + +- [ ] **Step 1: Write failing durable-state tests** + +Add tests proving that `updateJobProgress(workspace, jobId, event)`: + +- updates only running/cancelling jobs; +- keeps the newest four messages; +- updates `phase`, `lastActivityAt`, and monotonic `updatedAt`; +- deduplicates an identical final preview entry; +- returns a terminal job unchanged when completion wins; +- rejects unknown phases, invalid timestamps, more than 256 UTF-8 bytes, controls, arrays, and extra fields. + +```js +const progressed = await store.updateJobProgress(workspace, running.id, { + phase: 'running', + message: 'ZCode started a tool call.', + observedAt: new Date().toISOString(), +}); +assert.equal(progressed.phase, 'running'); +assert.deepEqual(progressed.progressPreview, ['ZCode started a tool call.']); +``` + +- [ ] **Step 2: Run state tests and verify RED** + +Run: `node --test tests/state.test.mjs` + +Expected: FAIL because `updateJobProgress` is undefined. + +- [ ] **Step 3: Implement progress persistence and schema validation** + +Add `phase`, `lastActivityAt`, and `progressPreview` to the strict job schema. Implement `updateJobProgress` under the existing workspace state lock. Read and validate the current job, no-op for terminal/queued jobs, cap the preview at four, atomically rewrite the job, and never modify lifecycle identity fields. + +- [ ] **Step 4: Verify state tests GREEN** + +Run: `node --test tests/state.test.mjs` + +Expected: all state tests PASS. + +- [ ] **Step 5: Write failing status-rendering tests** + +Test a detailed active job and an `--all` list. Require status, phase, timestamps, elapsed/duration, last activity, and each preview line. Require the compact list to contain only the latest preview. Ensure Markdown/control injection is escaped or rejected at state ingress. + +- [ ] **Step 6: Implement status rendering** + +Keep result rendering unchanged. Replace the one-line `value.job` branch with a bounded human-readable report and enrich the `value.jobs` branch with phase/latest activity. Compute elapsed/duration at render time from persisted ISO timestamps. Preserve `renderOutput(..., { json: true })` and redaction behavior. + +- [ ] **Step 7: Verify GREEN and commit** + +Run: `node --test tests/state.test.mjs tests/render-progress.test.mjs` + +Expected: all focused tests PASS. + +Commit: `feat: persist and render zcode job progress` + +### Task 3: Wire ZCode Notifications Into Active Jobs + +**Files:** +- Modify: `scripts/lib/review.mjs` +- Modify: `scripts/zcode-companion.mjs` +- Modify: `tests/fixtures/fake-zcode-cli.mjs` +- Modify: `tests/job-control.test.mjs` +- Modify: `tests/integration/companion.test.mjs` + +- [ ] **Step 1: Write failing executor tests** + +Provide a client stub whose `subscribe` captures a handler. During `waitForCompletion`, deliver intermediate same-session and sibling-session notifications. Assert that only the same-session event reaches the injected writer and `store.updateJobProgress`, that reporter persistence drains before the succeeded transition, and that unsubscribe/heartbeat cleanup occurs on success and failure. + +- [ ] **Step 2: Run focused tests and verify RED** + +Run: `node --test tests/job-control.test.mjs` + +Expected: FAIL because `executeJob` does not subscribe or accept progress dependencies. + +- [ ] **Step 3: Integrate the reporter at the accepted-turn boundary** + +Extend `executeJob` with optional `progressWriter`, `progressDependencies`, and `signal`. After the running job is persisted and before `client.send`, create a reporter bound to the returned ZCode session, subscribe it to protocol notifications, and emit a fixed starting event. In `finally`, unsubscribe, close, flush, and then close the client. Pass the writer only from foreground `main`; direct module calls and background workers stay quiet. + +- [ ] **Step 4: Add fake-peer intermediate events and integration RED test** + +When `FAKE_ZCODE_PROGRESS=1`, emit `model_streaming`, `tool_call_started`, and `tool_call_result` notifications with increasing revisions before the terminal notification. Spawn the real companion foreground path, assert `[zcode]` lines on stderr and final result on stdout, then query status JSON and assert the persisted phase/activity/preview. + +- [ ] **Step 5: Pass foreground writer dependencies and verify GREEN** + +Thread `progressWriter` and the reporter's injected timer/clock dependencies from +`main` through `runDirectInvocation`, `runCompanion`, `executeWithWorkerLease`, +and `executeJob`. Do not derive foreground/background state inside the progress +module; the executable boundary supplies a writer only for a foreground process. + +Run: `node --test tests/progress.test.mjs tests/state.test.mjs tests/job-control.test.mjs tests/integration/companion.test.mjs` + +Expected: all focused tests PASS with no unhandled rejections. + +- [ ] **Step 6: Commit** + +Commit: `feat: surface live zcode task activity` + +### Task 4: Foreground Signal Cancellation + +**Files:** +- Create: `scripts/lib/signals.mjs` +- Modify: `scripts/lib/progress.mjs` +- Modify: `scripts/lib/review.mjs` +- Modify: `scripts/zcode-companion.mjs` +- Create: `tests/signals.test.mjs` +- Modify: `tests/job-control.test.mjs` +- Modify: `tests/integration/companion.test.mjs` + +- [ ] **Step 1: Write failing signal-controller tests** + +With an injected EventEmitter-like process, assert that foreground installation registers one `SIGINT` and one `SIGTERM` listener, the first signal aborts with a `JOB_INTERRUPTED` `PluginError` carrying exit code 130 or 143, repeated signals do not duplicate work, cleanup removes listeners, and background mode installs none. + +- [ ] **Step 2: Run signal tests and verify RED** + +Run: `node --test tests/signals.test.mjs` + +Expected: FAIL because `scripts/lib/signals.mjs` does not exist. + +- [ ] **Step 3: Implement temporary signal handling and abort-aware wait** + +Export `createForegroundSignalController` and `waitForCompletionOrAbort`. The controller owns an `AbortController`, records the first conventional exit code, and removes handlers in `finally`. The wait helper races the existing completion promise with the abort signal while keeping rejection handlers attached. + +Call `signal.throwIfAborted()` at safe setup boundaries before discovery, before +session creation/resume, and before send. An already-running bounded RPC retains +its existing request timeout; the next boundary observes the interruption. + +- [ ] **Step 4: Write failing interruption lifecycle tests** + +Abort after accepted send and assert one `stopSession`, durable `running -> cancelling -> cancelled`, `finishedAt`, and no result artifact. Add a stop-failure case asserting the job returns to `running` with `lastCancelError`. Add a completion-wins race asserting success is not overwritten. + +- [ ] **Step 5: Implement cancellation under the existing cancellation lock** + +In `executeJob`, distinguish interruption from ordinary failure. Under `withJobCancellationLock`, stop the exact `zcodeSessionId`; after acknowledgement transition to cancelled. On stop failure, restore running with a bounded error and rethrow the interruption. Do not run the ordinary failure terminalization for this branch. + +In `main`, install handlers only when not setup and not `ZCODE_BACKGROUND_WORKER=1`, pass the signal through, emit a concise stderr interruption message, suppress the normal JSON error envelope for `JOB_INTERRUPTED`, and set `process.exitCode` to the captured 130/143. + +- [ ] **Step 6: Verify signal integration GREEN** + +Run: `node --test tests/signals.test.mjs tests/job-control.test.mjs tests/integration/companion.test.mjs` + +Expected: all focused tests PASS; spawned foreground interruption exits 130, acknowledges stop, and leaves no running job. + +- [ ] **Step 7: Commit** + +Commit: `fix: cancel foreground zcode jobs on interrupt` + +### Task 5: Documentation and Full Qualification + +**Files:** +- Modify: `README.md` +- Modify: `README.zh-CN.md` +- Modify: `CHANGELOG.md` +- Modify: relevant contract tests if documentation wording is asserted + +- [ ] **Step 1: Write or update failing documentation contract tests** + +Require both READMEs to document foreground activity, 20-second heartbeat, status previews, explicit background cancellation, and the `session/stop` boundary. Require the changelog to mention the behavior change without changing the package version. + +- [ ] **Step 2: Run contract tests and verify RED** + +Run: `node --test tests/release-contracts.test.mjs tests/plugin-contracts.test.mjs` + +Expected: FAIL on missing documentation text. + +- [ ] **Step 3: Update English/Chinese documentation and changelog** + +Document visible examples without claiming that this plugin can kill arbitrary detached grandchildren created by nested tools. Keep all command syntax and ownership rules unchanged. + +- [ ] **Step 4: Run focused tests GREEN** + +Run: `node --test tests/release-contracts.test.mjs tests/plugin-contracts.test.mjs` + +Expected: all focused tests PASS. + +- [ ] **Step 5: Run complete verification** + +Run: `npm run lint` + +Expected: exit 0, no lint errors. + +Run: `npm run typecheck` + +Expected: exit 0, no TypeScript diagnostics. + +Run: `npm test` + +Expected: exit 0, no failed tests; authenticated real E2E tests may remain explicitly skipped unless their opt-in environment variables are present. + +Run: `npm run test:qualified` + +Expected: exit 0; qualification tests either pass or report only their documented opt-in skips. + +Run: `git diff --check` + +Expected: no output and exit 0. + +- [ ] **Step 6: Commit** + +Commit: `docs: explain zcode progress and interruption behavior` + +## Final Review + +After all five tasks: + +1. Dispatch a spec-compliance reviewer against + `docs/superpowers/specs/2026-08-08-rescue-progress-lifecycle-design.md`. +2. Resolve every missing or extra behavior and request re-review. +3. Dispatch an independent code-quality reviewer over the full branch diff. +4. Resolve every Critical or Important issue and request re-review. +5. Re-run `npm run check` and `git diff --check` immediately before reporting completion. From d6a542b7d0680dff28e42b1a5a8b4c167f5aee6b Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 01:37:02 +0800 Subject: [PATCH 04/27] feat: add safe zcode progress reporting --- scripts/lib/progress.mjs | 88 ++++++++++++++++++++ tests/progress.test.mjs | 168 +++++++++++++++++++++++++++++++++++++++ 2 files changed, 256 insertions(+) create mode 100644 scripts/lib/progress.mjs create mode 100644 tests/progress.test.mjs diff --git a/scripts/lib/progress.mjs b/scripts/lib/progress.mjs new file mode 100644 index 00000000..c16f2989 --- /dev/null +++ b/scripts/lib/progress.mjs @@ -0,0 +1,88 @@ +export const PROGRESS_PHASES = Object.freeze(['starting', 'running', 'waiting', 'finalizing']); +export const MAX_PROGRESS_PREVIEW_ENTRIES = 4; +export const MAX_PROGRESS_MESSAGE_BYTES = 256; +export const PROGRESS_HEARTBEAT_MS = 20_000; + +const KNOWN_PROGRESS = new Map([ + ['prompt_started', ['starting', 'ZCode started the delegated turn.']], + ['model_streaming', ['running', 'ZCode is generating a response.']], + ['tool_call_started', ['running', 'ZCode started a tool call.']], + ['tool_call_progress', ['running', 'ZCode tool work is still running.']], + ['tool_call_result', ['running', 'ZCode completed a tool call.']], + ['api_retry', ['waiting', 'ZCode is retrying the model request.']], + ['prompt_completed', ['finalizing', 'ZCode completed the delegated turn.']], + ['prompt_failed', ['finalizing', 'ZCode reported a failed delegated turn.']], +]); + +/** @param {unknown} notification @param {string} sessionId @param {unknown} observedAt */ +export function normalizeZCodeProgress(notification, sessionId, observedAt) { + if (!plainObject(notification) || notification.method !== 'state.updated' || !plainObject(notification.params)) return null; + const { params } = notification; + if (params.scope !== 'session' || params.sessionId !== sessionId || !safeReason(params.reason) || !validTimestamp(observedAt)) return null; + const [phase, message] = KNOWN_PROGRESS.get(params.reason) ?? ['running', 'ZCode reported activity.']; + return { phase, message, observedAt }; +} + +/** + * @param {{sessionId:string,write?:(line:string)=>void,persist?:(event:{phase:string,message:string,observedAt:string})=>Promise|void,now?:()=>string,setInterval?:(callback:()=>void,milliseconds:number)=>any,clearInterval?:(timer:any)=>void}} options + */ +export function createProgressReporter({ + sessionId, + write, + persist, + now = () => new Date().toISOString(), + setInterval: setIntervalFn = globalThis.setInterval, + clearInterval: clearIntervalFn = globalThis.clearInterval, +}) { + let lastActivityAt = now(); + /** @type {string|null} */ + let previousKey = null; + let persistence = Promise.resolve(); + let timer = setIntervalFn(() => { + const currentTime = now(); + if (typeof write !== 'function' || !validTimestamp(currentTime) || !validTimestamp(lastActivityAt)) return; + const elapsedMs = Date.parse(currentTime) - Date.parse(lastActivityAt); + if (elapsedMs < PROGRESS_HEARTBEAT_MS) return; + const seconds = Math.floor(elapsedMs / 1_000); + write(`[zcode] Still waiting for ZCode; last activity ${seconds}s ago.\n`); + }, PROGRESS_HEARTBEAT_MS); + timer?.unref?.(); + + return { + /** @param {unknown} notification */ + observe(notification) { + const event = normalizeZCodeProgress(notification, sessionId, now()); + if (event === null) return null; + const key = `${event.phase}\u0000${event.message}`; + if (key === previousKey) return null; + previousKey = key; + lastActivityAt = event.observedAt; + if (typeof write === 'function') write(`[zcode] ${event.message}\n`); + if (typeof persist === 'function') persistence = persistence.then(() => persist(event)); + return event; + }, + flush() { return persistence; }, + close() { + if (timer === null) return; + clearIntervalFn(timer); + timer = null; + }, + }; +} + +/** @param {unknown} value */ +function safeReason(value) { + return typeof value === 'string' && value.length > 0 && Buffer.byteLength(value) <= MAX_PROGRESS_MESSAGE_BYTES && !hasControl(value); +} + +/** @param {string} value */ +function hasControl(value) { return [...value].some((character) => { const codePoint = character.charCodeAt(0); return codePoint <= 31 || codePoint >= 127 && codePoint <= 159; }); } + +/** @param {unknown} value @returns {value is string} */ +function validTimestamp(value) { + if (typeof value !== 'string' || value.length === 0) return false; + try { return new Date(value).toISOString() === value; } catch { return false; } +} + +/** @param {unknown} value @returns {value is Record} */ +function plainObject(value) { return value !== null && typeof value === 'object' && !Array.isArray(value); } diff --git a/tests/progress.test.mjs b/tests/progress.test.mjs new file mode 100644 index 00000000..d9a5a3b8 --- /dev/null +++ b/tests/progress.test.mjs @@ -0,0 +1,168 @@ +// @ts-nocheck +import assert from 'node:assert/strict'; +import test from 'node:test'; + +import * as progressModule from '../scripts/lib/progress.mjs'; +import { + MAX_PROGRESS_MESSAGE_BYTES, + MAX_PROGRESS_PREVIEW_ENTRIES, + PROGRESS_HEARTBEAT_MS, + PROGRESS_PHASES, + normalizeZCodeProgress, +} from '../scripts/lib/progress.mjs'; + +const observedAt = '2026-08-08T00:00:00.000Z'; + +function notification(reason, patch = {}, overrides = {}) { + return { + method: 'state.updated', + params: { + type: 'state.updated', + scope: 'session', + sessionId: 'session-a', + revision: 2, + reason, + patch, + ...overrides, + }, + }; +} + +test('exports fixed progress bounds and phases', () => { + assert.deepEqual(PROGRESS_PHASES, ['starting', 'running', 'waiting', 'finalizing']); + assert.equal(MAX_PROGRESS_PREVIEW_ENTRIES, 4); + assert.equal(MAX_PROGRESS_MESSAGE_BYTES, 256); + assert.equal(PROGRESS_HEARTBEAT_MS, 20_000); +}); + +test('normalizes known same-session activity to fixed public messages', () => { + const cases = [ + ['prompt_started', 'starting', 'ZCode started the delegated turn.'], + ['model_streaming', 'running', 'ZCode is generating a response.'], + ['tool_call_started', 'running', 'ZCode started a tool call.'], + ['tool_call_progress', 'running', 'ZCode tool work is still running.'], + ['tool_call_result', 'running', 'ZCode completed a tool call.'], + ['api_retry', 'waiting', 'ZCode is retrying the model request.'], + ['prompt_completed', 'finalizing', 'ZCode completed the delegated turn.'], + ['prompt_failed', 'finalizing', 'ZCode reported a failed delegated turn.'], + ]; + for (const [reason, phase, message] of cases) { + assert.deepEqual(normalizeZCodeProgress(notification(reason), 'session-a', observedAt), { phase, message, observedAt }); + } +}); + +test('uses a generic message for bounded unknown reasons without exposing patches', () => { + const event = normalizeZCodeProgress(notification('future_secret_reason', { + apiKey: 'never-render-this', + command: 'curl -H Authorization:secret', + reasoning: 'private chain of thought', + }), 'session-a', observedAt); + assert.deepEqual(event, { phase: 'running', message: 'ZCode reported activity.', observedAt }); + assert.doesNotMatch(JSON.stringify(event), /future_secret_reason|never-render-this|Authorization|chain of thought/); +}); + +test('rejects notifications outside the safe same-session boundary', () => { + const cases = [ + null, + [], + 'frame', + {}, + { method: 'session.updated', params: notification('tool_call_started').params }, + notification('tool_call_started', {}, { scope: 'workspace' }), + notification('tool_call_started', {}, { sessionId: 'session-b' }), + notification(''), + notification('tool\u0007call'), + notification('tool\u0085call'), + notification('x'.repeat(257)), + ]; + for (const frame of cases) assert.equal(normalizeZCodeProgress(frame, 'session-a', observedAt), null); +}); + +test('rejects invalid observation timestamps', () => { + for (const timestamp of [undefined, null, '', 'not-a-date', 0, '2026-02-30T00:00:00.000Z']) { + assert.equal(normalizeZCodeProgress(notification('tool_call_started'), 'session-a', timestamp), null); + } +}); + +test('reports immediately, suppresses consecutive duplicates, and serializes persistence', async () => { + const lines = []; + const persistenceStarted = []; + const persisted = []; + const releases = []; + let signalSecondStarted; + const secondStarted = new Promise((resolve) => { signalSecondStarted = resolve; }); + let currentTime = observedAt; + const reporter = progressModule.createProgressReporter({ + sessionId: 'session-a', + write: (line) => lines.push(line), + persist: async (event) => { + persistenceStarted.push(event.message); + if (persistenceStarted.length === 2) signalSecondStarted(); + await new Promise((resolve) => releases.push(resolve)); + persisted.push(event); + }, + now: () => currentTime, + setInterval: () => ({ unref() {} }), + clearInterval: () => {}, + }); + + reporter.observe(notification('tool_call_started')); + reporter.observe(notification('tool_call_started', { secret: 'duplicate must stay private' })); + currentTime = '2026-08-08T00:00:01.000Z'; + reporter.observe(notification('api_retry')); + + assert.deepEqual(lines, [ + '[zcode] ZCode started a tool call.\n', + '[zcode] ZCode is retrying the model request.\n', + ]); + await Promise.resolve(); + assert.deepEqual(persistenceStarted, ['ZCode started a tool call.']); + releases.shift()(); + await secondStarted; + assert.deepEqual(persistenceStarted, ['ZCode started a tool call.', 'ZCode is retrying the model request.']); + releases.shift()(); + await reporter.flush(); + assert.deepEqual(persisted, [ + { phase: 'running', message: 'ZCode started a tool call.', observedAt }, + { phase: 'waiting', message: 'ZCode is retrying the model request.', observedAt: currentTime }, + ]); +}); + +test('emits an unpersisted 20-second heartbeat and closes idempotently', async () => { + const lines = []; + const persisted = []; + const cleared = []; + let intervalCallback; + let intervalMs; + let unrefCount = 0; + let currentTime = observedAt; + const timer = { unref: () => { unrefCount += 1; } }; + const reporter = progressModule.createProgressReporter({ + sessionId: 'session-a', + write: (line) => lines.push(line), + persist: async (event) => persisted.push(event), + now: () => currentTime, + setInterval: (callback, milliseconds) => { intervalCallback = callback; intervalMs = milliseconds; return timer; }, + clearInterval: (value) => cleared.push(value), + }); + + reporter.observe(notification('model_streaming')); + await reporter.flush(); + currentTime = '2026-08-08T00:00:10.000Z'; + intervalCallback(); + assert.deepEqual(lines, ['[zcode] ZCode is generating a response.\n']); + currentTime = '2026-08-08T00:00:42.000Z'; + intervalCallback(); + + assert.equal(intervalMs, PROGRESS_HEARTBEAT_MS); + assert.equal(unrefCount, 1); + assert.deepEqual(lines, [ + '[zcode] ZCode is generating a response.\n', + '[zcode] Still waiting for ZCode; last activity 42s ago.\n', + ]); + assert.deepEqual(persisted, [{ phase: 'running', message: 'ZCode is generating a response.', observedAt }]); + + reporter.close(); + reporter.close(); + assert.deepEqual(cleared, [timer]); +}); From 24ab317f8c80129a0cf1a05f7170f60a360ed805 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 01:47:09 +0800 Subject: [PATCH 05/27] fix: harden zcode progress reporter lifecycle --- scripts/lib/progress.mjs | 32 ++++++++++------ tests/progress.test.mjs | 81 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 102 insertions(+), 11 deletions(-) diff --git a/scripts/lib/progress.mjs b/scripts/lib/progress.mjs index c16f2989..b8726450 100644 --- a/scripts/lib/progress.mjs +++ b/scripts/lib/progress.mjs @@ -38,14 +38,21 @@ export function createProgressReporter({ /** @type {string|null} */ let previousKey = null; let persistence = Promise.resolve(); - let timer = setIntervalFn(() => { - const currentTime = now(); - if (typeof write !== 'function' || !validTimestamp(currentTime) || !validTimestamp(lastActivityAt)) return; - const elapsedMs = Date.parse(currentTime) - Date.parse(lastActivityAt); - if (elapsedMs < PROGRESS_HEARTBEAT_MS) return; - const seconds = Math.floor(elapsedMs / 1_000); - write(`[zcode] Still waiting for ZCode; last activity ${seconds}s ago.\n`); - }, PROGRESS_HEARTBEAT_MS); + let hasPersistenceError = false; + /** @type {unknown} */ + let persistenceError; + /** @type {any} */ + let timer = null; + if (typeof write === 'function') { + timer = setIntervalFn(() => { + const currentTime = now(); + if (!validTimestamp(currentTime) || !validTimestamp(lastActivityAt)) return; + const elapsedMs = Date.parse(currentTime) - Date.parse(lastActivityAt); + if (elapsedMs < PROGRESS_HEARTBEAT_MS) return; + const seconds = Math.floor(elapsedMs / 1_000); + write(`[zcode] Still waiting for ZCode; last activity ${seconds}s ago.\n`); + }, PROGRESS_HEARTBEAT_MS); + } timer?.unref?.(); return { @@ -53,15 +60,18 @@ export function createProgressReporter({ observe(notification) { const event = normalizeZCodeProgress(notification, sessionId, now()); if (event === null) return null; + lastActivityAt = event.observedAt; const key = `${event.phase}\u0000${event.message}`; if (key === previousKey) return null; previousKey = key; - lastActivityAt = event.observedAt; if (typeof write === 'function') write(`[zcode] ${event.message}\n`); - if (typeof persist === 'function') persistence = persistence.then(() => persist(event)); + if (typeof persist === 'function') persistence = persistence.then(async () => { + try { await persist(event); } + catch (error) { if (!hasPersistenceError) { hasPersistenceError = true; persistenceError = error; } } + }); return event; }, - flush() { return persistence; }, + async flush() { await persistence; if (hasPersistenceError) throw persistenceError; }, close() { if (timer === null) return; clearIntervalFn(timer); diff --git a/tests/progress.test.mjs b/tests/progress.test.mjs index d9a5a3b8..840afdc1 100644 --- a/tests/progress.test.mjs +++ b/tests/progress.test.mjs @@ -78,6 +78,19 @@ test('rejects notifications outside the safe same-session boundary', () => { for (const frame of cases) assert.equal(normalizeZCodeProgress(frame, 'session-a', observedAt), null); }); +test('enforces the reason limit in UTF-8 bytes at a multibyte boundary', () => { + const reason256 = `${'é'.repeat(127)}ab`; + const reason257 = `${'é'.repeat(127)}abc`; + assert.equal(Buffer.byteLength(reason256), 256); + assert.equal(Buffer.byteLength(reason257), 257); + assert.deepEqual(normalizeZCodeProgress(notification(reason256), 'session-a', observedAt), { + phase: 'running', + message: 'ZCode reported activity.', + observedAt, + }); + assert.equal(normalizeZCodeProgress(notification(reason257), 'session-a', observedAt), null); +}); + test('rejects invalid observation timestamps', () => { for (const timestamp of [undefined, null, '', 'not-a-date', 0, '2026-02-30T00:00:00.000Z']) { assert.equal(normalizeZCodeProgress(notification('tool_call_started'), 'session-a', timestamp), null); @@ -166,3 +179,71 @@ test('emits an unpersisted 20-second heartbeat and closes idempotently', async ( reporter.close(); assert.deepEqual(cleared, [timer]); }); + +test('duplicate activity refreshes the heartbeat clock without repeating output or persistence', async () => { + const lines = []; + const persisted = []; + let intervalCallback; + let currentTime = observedAt; + const reporter = progressModule.createProgressReporter({ + sessionId: 'session-a', + write: (line) => lines.push(line), + persist: async (event) => persisted.push(event), + now: () => currentTime, + setInterval: (callback) => { intervalCallback = callback; return { unref() {} }; }, + clearInterval: () => {}, + }); + + reporter.observe(notification('tool_call_progress')); + currentTime = '2026-08-08T00:00:19.000Z'; + reporter.observe(notification('tool_call_progress')); + currentTime = '2026-08-08T00:00:21.000Z'; + intervalCallback(); + await reporter.flush(); + + assert.deepEqual(lines, ['[zcode] ZCode tool work is still running.\n']); + assert.deepEqual(persisted, [{ phase: 'running', message: 'ZCode tool work is still running.', observedAt }]); + reporter.close(); +}); + +test('persistence failures stay handled, do not poison later work, and surface from flush', async () => { + const firstError = new Error('first persistence failed'); + const attempts = []; + const unhandled = []; + const onUnhandled = (error) => unhandled.push(error); + process.on('unhandledRejection', onUnhandled); + const reporter = progressModule.createProgressReporter({ + sessionId: 'session-a', + persist: async (event) => { + attempts.push(event.message); + if (attempts.length === 1) throw firstError; + }, + now: () => observedAt, + setInterval: () => ({ unref() {} }), + clearInterval: () => {}, + }); + + try { + reporter.observe(notification('tool_call_started')); + await new Promise((resolve) => setImmediate(resolve)); + assert.deepEqual(unhandled, []); + reporter.observe(notification('api_retry')); + await assert.rejects(reporter.flush(), (error) => error === firstError); + assert.deepEqual(attempts, ['ZCode started a tool call.', 'ZCode is retrying the model request.']); + } finally { + process.off('unhandledRejection', onUnhandled); + reporter.close(); + } +}); + +test('does not create a heartbeat interval without a writer', () => { + let intervalCalls = 0; + const reporter = progressModule.createProgressReporter({ + sessionId: 'session-a', + now: () => observedAt, + setInterval: () => { intervalCalls += 1; return { unref() {} }; }, + clearInterval: () => {}, + }); + assert.equal(intervalCalls, 0); + reporter.close(); +}); From ad5659569349d9af51af586766fb520191688a81 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 01:56:19 +0800 Subject: [PATCH 06/27] feat: persist and render zcode job progress --- scripts/lib/render.mjs | 96 +++++++++++++++++++++++++++- scripts/lib/state.mjs | 101 +++++++++++++++++++++++++++++- tests/render-progress.test.mjs | 99 +++++++++++++++++++++++++++++ tests/state.test.mjs | 111 +++++++++++++++++++++++++++++++++ 4 files changed, 403 insertions(+), 4 deletions(-) create mode 100644 tests/render-progress.test.mjs diff --git a/scripts/lib/render.mjs b/scripts/lib/render.mjs index 25643fa1..a5b7d5ec 100644 --- a/scripts/lib/render.mjs +++ b/scripts/lib/render.mjs @@ -11,12 +11,104 @@ export function renderOutput(value, options = {}) { if (options.json) return `${JSON.stringify(redact(value))}\n`; if (value?.type === 'transfer' && typeof value.result === 'string') return value.result.endsWith('\n') ? value.result : `${value.result}\n`; if (value?.type === 'background') return `Reserved background job ${value.job.id}.\n`; - if (value?.jobs) return `${value.jobs.map((/** @type {any} */ job) => `${job.id} ${job.status} ${job.command} ${job.owner}`).join('\n')}\n${renderModelPolicy(value.modelPolicy)}`; + if (value?.jobs) return `${value.jobs.map(renderCompactJob).join('\n')}\n${renderModelPolicy(value.modelPolicy)}`; if (value?.result !== undefined) return `${value.result}\n`; - if (value?.job) return `${value.job.id} ${value.job.status}\n${renderModelPolicy(value.modelPolicy)}`; + if (value?.job) return `${renderJob(value.job)}${renderModelPolicy(value.modelPolicy)}`; return `${JSON.stringify(redact(value))}\n`; } +/** @param {any} job */ +function renderCompactJob(job) { + const fields = [job.id, job.status, job.command, job.owner].map((value) => safeInline(value)); + if (typeof job.phase === 'string') fields.push(`phase=${safeInline(job.phase)}`); + if (typeof job.lastActivityAt === 'string') { + fields.push(`activity=${safeInline(job.lastActivityAt)}`); + } + const latest = Array.isArray(job.progressPreview) ? job.progressPreview.at(-1) : undefined; + if (typeof latest === 'string') fields.push(`latest=${safeProgress(latest)}`); + return fields.join(' '); +} + +/** @param {any} job */ +function renderJob(job) { + const terminal = ['succeeded', 'failed', 'cancelled'].includes(job.status); + const startedAt = validTimestamp(job.startedAt) ? job.startedAt + : validTimestamp(job.createdAt) ? job.createdAt : undefined; + const finishedAt = validTimestamp(job.finishedAt) ? job.finishedAt : undefined; + const end = terminal ? finishedAt : new Date(Date.now()).toISOString(); + const timingLabel = terminal ? 'Duration' : 'Elapsed'; + const timing = startedAt && end ? formatDuration(Date.parse(end) - Date.parse(startedAt)) : '—'; + const previews = Array.isArray(job.progressPreview) + ? job.progressPreview.filter((/** @type {unknown} */ message) => typeof message === 'string').slice(-4) + : []; + const lines = [ + `Job: ${safeInline(job.id)}`, + `Command: ${safeInline(job.command)}`, + `Status: ${safeInline(job.status)}`, + `Phase: ${safeInline(job.phase)}`, + `Created: ${safeInline(job.createdAt)}`, + `Started: ${safeInline(job.startedAt)}`, + `Finished: ${safeInline(job.finishedAt)}`, + `${timingLabel}: ${timing}`, + `Last activity: ${safeInline(job.lastActivityAt)}`, + 'Progress:', + ...(previews.length > 0 + ? previews.map((/** @type {string} */ message) => ` - ${safeProgress(message)}`) + : [' - none']), + ]; + return `${lines.join('\n')}\n`; +} + +/** @param {unknown} value */ +function safeInline(value) { + if (typeof value !== 'string' || value.length === 0) return '—'; + const controlFree = [...value].map((character) => { + const code = /** @type {number} */ (character.codePointAt(0)); + return code <= 31 || code >= 127 && code <= 159 ? ' ' : character; + }).join(''); + return escapeMarkdown(controlFree.replace(/\s+/g, ' ').trim()); +} + +/** @param {string} message */ +function safeProgress(message) { + const bounded = boundUtf8(message, 256); + return safeInline(bounded); +} + +/** @param {string} value */ +function escapeMarkdown(value) { + return value.replace(/([\\`*_{}[\]<>#!|])/g, '\\$1').replace(/^([-+])/, '\\$1'); +} + +/** @param {string} value @param {number} maxBytes */ +function boundUtf8(value, maxBytes) { + if (Buffer.byteLength(value) <= maxBytes) return value; + let result = ''; + for (const character of value) { + if (Buffer.byteLength(result) + Buffer.byteLength(character) > maxBytes - 3) break; + result += character; + } + return `${result}...`; +} + +/** @param {number} milliseconds */ +function formatDuration(milliseconds) { + let seconds = Math.max(0, Math.floor(milliseconds / 1_000)); + const days = Math.floor(seconds / 86_400); seconds %= 86_400; + const hours = Math.floor(seconds / 3_600); seconds %= 3_600; + const minutes = Math.floor(seconds / 60); seconds %= 60; + if (days > 0) return `${days}d ${hours}h`; + if (hours > 0) return `${hours}h ${minutes}m`; + if (minutes > 0) return `${minutes}m ${seconds}s`; + return `${seconds}s`; +} + +/** @param {unknown} value */ +function validTimestamp(value) { + if (typeof value !== 'string') return false; + try { return new Date(value).toISOString() === value; } catch { return false; } +} + /** @param {any} policy */ function renderModelPolicy(policy) { return policy ? `Model policy: default=${policy.defaultModel ?? 'ZCode default'}; aliases=${policy.aliases.length ? policy.aliases.join(',') : 'none'}\n` : ''; } diff --git a/scripts/lib/state.mjs b/scripts/lib/state.mjs index 928fb94e..0b9b50f9 100644 --- a/scripts/lib/state.mjs +++ b/scripts/lib/state.mjs @@ -5,6 +5,11 @@ import { join } from 'node:path'; import { PluginError } from './errors.mjs'; import { atomicWriteJson, ensurePrivateDirectory, readJsonFile, withFileLock } from './fs.mjs'; import { isSafeIdentifier } from './identifier.mjs'; +import { + MAX_PROGRESS_MESSAGE_BYTES, + MAX_PROGRESS_PREVIEW_ENTRIES, + PROGRESS_PHASES, +} from './progress.mjs'; import { resolveWorkspaceStorage } from './workspace.mjs'; export const JOB_STATUSES = Object.freeze([ @@ -176,6 +181,42 @@ export function createStateStore(options) { }); }, + /** + * @param {string} workspace + * @param {string} jobId + * @param {{phase:string,message:string,observedAt:string}} event + */ + async updateJobProgress(workspace, jobId, event) { + validateProgressInput(workspace, jobId, event); + const storage = await jobStorage(dataRoot, workspace); + return withFileLock(storage.lockPath, async () => { + const path = jobPath(storage.jobsDirectory, jobId); + const job = await readJobRecord(path, jobId, storage.workspacePath); + if (job.status === 'queued' || TERMINAL_STATUSES.has(job.status)) return job; + const observedAtMs = Date.parse(event.observedAt); + const activityFloor = Date.parse(job.lastActivityAt ?? job.startedAt ?? job.createdAt); + if (observedAtMs < activityFloor) throw invalidProgressInput(['observedAt']); + const progressPreview = job.progressPreview ?? []; + const messages = progressPreview.at(-1) === event.message + ? progressPreview + : [...progressPreview, event.message].slice(-MAX_PROGRESS_PREVIEW_ENTRIES); + const updated = { + ...job, + phase: event.phase, + lastActivityAt: event.observedAt, + progressPreview: messages, + updatedAt: new Date(Math.max( + Date.now(), + Date.parse(job.updatedAt), + observedAtMs, + )).toISOString(), + }; + validateJobRecord(updated, jobId, storage.workspacePath); + await atomicWriteJson(path, updated); + return updated; + }); + }, + /** @param {string} workspace @param {string} jobId */ async readJob(workspace, jobId) { const storage = await jobStorage(dataRoot, workspace); @@ -286,6 +327,32 @@ function validateTransitionInput(workspace, jobId, expectedStatuses, nextStatus, } } +/** @param {unknown} workspace @param {unknown} jobId @param {unknown} event */ +function validateProgressInput(workspace, jobId, event) { + const invalidFields = []; + if (!isNonEmptyString(workspace)) invalidFields.push('workspace'); + if (!isDigest(jobId)) invalidFields.push('jobId'); + if (!isPlainJsonObject(event)) invalidFields.push('event'); + else { + const fields = Object.keys(event); + const extraFields = fields.filter((field) => !['message', 'observedAt', 'phase'].includes(field)); + if (extraFields.length > 0) invalidFields.push(...extraFields); + if (!PROGRESS_PHASES.includes(event.phase)) invalidFields.push('phase'); + if (!isSafeProgressMessage(event.message)) invalidFields.push('message'); + if (!isIsoTimestamp(event.observedAt)) invalidFields.push('observedAt'); + } + if (invalidFields.length > 0) throw invalidProgressInput(invalidFields); +} + +/** @param {string[]} invalidFields */ +function invalidProgressInput(invalidFields) { + return new PluginError('JOB_PROGRESS_INPUT_INVALID', 'Job progress input is invalid.', { + category: 'state', + remedy: 'Provide one fixed phase, bounded control-free message, and ISO observation timestamp.', + details: { invalidFields }, + }); +} + /** @param {any} job @param {string} expectedJobId @param {string} expectedWorkspacePath @returns {any} */ function validateJobRecord(job, expectedJobId, expectedWorkspacePath) { const validShape = isPlainJsonObject(job) @@ -311,7 +378,10 @@ function validateJobRecord(job, expectedJobId, expectedWorkspacePath) { && (!('promptArtifact' in job) || isSafeArtifact(job.promptArtifact)) && (!('resultArtifact' in job) || isSafeArtifact(job.resultArtifact)) && (!('error' in job) || isTrackedError(job.error)) - && (!('lastCancelError' in job) || isCancellationError(job.lastCancelError)); + && (!('lastCancelError' in job) || isCancellationError(job.lastCancelError)) + && (!('phase' in job) || PROGRESS_PHASES.includes(job.phase)) + && (!('lastActivityAt' in job) || isIsoTimestamp(job.lastActivityAt)) + && (!('progressPreview' in job) || validProgressPreview(job.progressPreview)); const boundaryFields = ['inputId', 'startRevision', 'beforeMessageIds']; const hasBoundary = boundaryFields.some((field) => field in job); const validBoundary = !hasBoundary || boundaryFields.every((field) => field in job) @@ -334,13 +404,22 @@ function validateJobRecord(job, expectedJobId, expectedWorkspacePath) { const createdAt = validShape ? Date.parse(job.createdAt) : Number.NaN; const startedAt = validShape && 'startedAt' in job ? Date.parse(job.startedAt) : undefined; const finishedAt = validShape && 'finishedAt' in job ? Date.parse(job.finishedAt) : undefined; + const lastActivityAt = validShape && 'lastActivityAt' in job + ? Date.parse(job.lastActivityAt) : undefined; + const progressFields = ['phase', 'lastActivityAt', 'progressPreview']; + const hasProgress = progressFields.some((field) => field in job); + const validProgress = !hasProgress || progressFields.every((field) => field in job) + && job.status !== 'queued' + && lastActivityAt !== undefined + && lastActivityAt >= (startedAt ?? createdAt) + && Date.parse(job.updatedAt) >= lastActivityAt; const validTimeline = validShape && Date.parse(job.updatedAt) >= createdAt && (startedAt === undefined || Date.parse(job.updatedAt) >= startedAt) && (finishedAt === undefined || Date.parse(job.updatedAt) >= finishedAt) && (startedAt === undefined || startedAt >= createdAt) && (finishedAt === undefined || finishedAt >= (startedAt ?? createdAt)); - if (!validLifecycle || !validTimeline) { + if (!validLifecycle || !validProgress || !validTimeline) { throw new PluginError('JOB_RECORD_INVALID', 'Persisted job record failed schema validation.', { category: 'state', remedy: 'Restore or remove the corrupted job record.', @@ -464,6 +543,24 @@ function validBeforeMessageIds(value) { return true; } +/** @param {unknown} value */ +function validProgressPreview(value) { + return Array.isArray(value) + && value.length > 0 + && value.length <= MAX_PROGRESS_PREVIEW_ENTRIES + && value.every(isSafeProgressMessage); +} + +/** @param {unknown} value */ +function isSafeProgressMessage(value) { + return isNonEmptyString(value) + && Buffer.byteLength(value) <= MAX_PROGRESS_MESSAGE_BYTES + && ![...value].some((character) => { + const code = /** @type {number} */ (character.codePointAt(0)); + return code <= 31 || code >= 127 && code <= 159; + }); +} + /** @param {unknown} value */ function isIsoTimestamp(value) { return typeof value === 'string' && Number.isFinite(Date.parse(value)) diff --git a/tests/render-progress.test.mjs b/tests/render-progress.test.mjs new file mode 100644 index 00000000..5b7f364f --- /dev/null +++ b/tests/render-progress.test.mjs @@ -0,0 +1,99 @@ +import assert from 'node:assert/strict'; +import test from 'node:test'; + +import { renderOutput } from '../scripts/lib/render.mjs'; + +const id = 'a'.repeat(64); + +test('renders a bounded detailed active-job progress report with elapsed time', () => { + const originalNow = Date.now; + Date.now = () => Date.parse('2026-08-08T00:05:00.000Z'); + try { + const output = renderOutput({ + job: { + id, + command: 'rescue', + status: 'running', + phase: 'waiting', + createdAt: '2026-08-07T23:59:00.000Z', + startedAt: '2026-08-08T00:00:00.000Z', + updatedAt: '2026-08-08T00:04:30.000Z', + lastActivityAt: '2026-08-08T00:04:00.000Z', + progressPreview: [ + 'ZCode started the delegated turn.', + 'ZCode started a tool call.', + 'ZCode is retrying the model request.', + '**ZCode completed a tool call.**', + ], + }, + modelPolicy: { defaultModel: 'quick', aliases: ['quick'] }, + }); + + assert.match(output, new RegExp(`Job: ${id}`)); + assert.match(output, /Command: rescue/); + assert.match(output, /Status: running/); + assert.match(output, /Phase: waiting/); + assert.match(output, /Created: 2026-08-07T23:59:00\.000Z/); + assert.match(output, /Started: 2026-08-08T00:00:00\.000Z/); + assert.match(output, /Finished: —/); + assert.match(output, /Elapsed: 5m 0s/); + assert.match(output, /Last activity: 2026-08-08T00:04:00\.000Z/); + assert.match(output, /Progress:\n {2}- ZCode started the delegated turn\.\n {2}- ZCode started a tool call\.\n {2}- ZCode is retrying the model request\.\n {2}- \\\*\\\*ZCode completed a tool call\.\\\*\\\*/); + assert.match(output, /Model policy: default=quick; aliases=quick/); + assert.doesNotMatch(output, / {2}- \*\*ZCode/); + } finally { + Date.now = originalNow; + } +}); + +test('renders terminal duration and keeps result rendering unchanged', () => { + const job = { + id, + command: 'review', + status: 'succeeded', + phase: 'finalizing', + createdAt: '2026-08-08T00:00:00.000Z', + startedAt: '2026-08-08T00:00:01.000Z', + finishedAt: '2026-08-08T00:01:03.000Z', + updatedAt: '2026-08-08T00:01:03.000Z', + lastActivityAt: '2026-08-08T00:01:02.000Z', + progressPreview: ['ZCode completed the delegated turn.'], + }; + const output = renderOutput({ job }); + assert.match(output, /Finished: 2026-08-08T00:01:03\.000Z/); + assert.match(output, /Duration: 1m 2s/); + assert.doesNotMatch(output, /Elapsed:/); + assert.equal(renderOutput({ job, result: 'unchanged result' }), 'unchanged result\n'); +}); + +test('compact job lists include phase and only the latest safe preview', () => { + const output = renderOutput({ + jobs: [{ + id, + status: 'running', + command: 'rescue', + owner: 'same-owner', + phase: 'running', + lastActivityAt: '2026-08-08T00:04:00.000Z', + progressPreview: ['old preview', 'latest `preview`\nforged line'], + }], + }); + + assert.doesNotMatch(output, /old preview/); + assert.match(output, /phase=running/); + assert.match(output, /activity=2026-08-08T00:04:00\.000Z/); + assert.match(output, /latest=latest \\`preview\\` forged line/); + assert.equal(output.trim().split('\n').length, 1); +}); + +test('JSON output remains structurally unchanged and redacted', () => { + const value = { + job: { id, status: 'running', phase: 'running', progressPreview: ['safe'] }, + permissionSnapshot: { mode: 'workspace-write' }, + nested: { executionCapability: 'secret', visible: true }, + }; + assert.deepEqual(JSON.parse(renderOutput(value, { json: true })), { + job: { id, status: 'running', phase: 'running', progressPreview: ['safe'] }, + nested: { visible: true }, + }); +}); diff --git a/tests/state.test.mjs b/tests/state.test.mjs index a4ce626c..c24d881d 100644 --- a/tests/state.test.mjs +++ b/tests/state.test.mjs @@ -589,6 +589,117 @@ test('tracked job fields persist through their legal lifecycle phases', async () assert.deepEqual(await store.readJob(workspace, cancelledJob.id), cancelled); }); +test('running and cancelling jobs persist bounded monotonic progress', async () => { + const { dataRoot, workspace } = await fixture(); + const store = createStateStore({ dataRoot }); + const queued = await store.reserveJob({ workspace, ...jobInput }); + const startedAt = new Date(Date.parse(queued.createdAt) + 1_000).toISOString(); + let job = await store.transitionJob(workspace, queued.id, ['queued'], 'running', { startedAt }); + const identity = { + id: job.id, + workspace: job.workspace, + ownerSessionId: job.ownerSessionId, + ownerTurnId: job.ownerTurnId, + command: job.command, + readOnly: job.readOnly, + permissionSnapshot: job.permissionSnapshot, + createdAt: job.createdAt, + startedAt: job.startedAt, + }; + + for (let index = 1; index <= 5; index += 1) { + const observedAt = new Date(Date.parse(startedAt) + index * 1_000).toISOString(); + const previousUpdatedAt = job.updatedAt; + job = await store.updateJobProgress(workspace, job.id, { + phase: index === 5 ? 'waiting' : 'running', + message: `Progress ${index}`, + observedAt, + }); + assert.ok(Date.parse(job.updatedAt) >= Date.parse(previousUpdatedAt)); + assert.ok(Date.parse(job.updatedAt) >= Date.parse(observedAt)); + } + + assert.equal(job.phase, 'waiting'); + assert.equal(job.lastActivityAt, new Date(Date.parse(startedAt) + 5_000).toISOString()); + assert.deepEqual(job.progressPreview, ['Progress 2', 'Progress 3', 'Progress 4', 'Progress 5']); + assert.deepEqual({ + id: job.id, + workspace: job.workspace, + ownerSessionId: job.ownerSessionId, + ownerTurnId: job.ownerTurnId, + command: job.command, + readOnly: job.readOnly, + permissionSnapshot: job.permissionSnapshot, + createdAt: job.createdAt, + startedAt: job.startedAt, + }, identity); + + const duplicate = await store.updateJobProgress(workspace, job.id, { + phase: 'running', + message: 'Progress 5', + observedAt: new Date(Date.parse(startedAt) + 6_000).toISOString(), + }); + assert.equal(duplicate.phase, 'running'); + assert.deepEqual(duplicate.progressPreview, job.progressPreview); + + const cancelling = await store.transitionJob(workspace, job.id, ['running'], 'cancelling'); + const cancellingProgress = await store.updateJobProgress(workspace, job.id, { + phase: 'finalizing', + message: 'Stopping ZCode.', + observedAt: new Date(Date.parse(startedAt) + 7_000).toISOString(), + }); + assert.equal(cancellingProgress.status, 'cancelling'); + assert.equal(cancellingProgress.phase, 'finalizing'); + assert.ok(Date.parse(cancellingProgress.updatedAt) >= Date.parse(cancelling.updatedAt)); +}); + +test('progress is a no-op once queued or terminal lifecycle state wins', async () => { + const { dataRoot, workspace } = await fixture(); + const store = createStateStore({ dataRoot }); + const queued = await store.reserveJob({ workspace, ...jobInput }); + const event = { + phase: 'starting', + message: 'ZCode started the delegated turn.', + observedAt: queued.updatedAt, + }; + assert.deepEqual(await store.updateJobProgress(workspace, queued.id, event), queued); + + const running = await store.transitionJob(workspace, queued.id, ['queued'], 'running'); + const succeeded = await store.transitionJob(workspace, running.id, ['running'], 'succeeded'); + assert.deepEqual(await store.updateJobProgress(workspace, succeeded.id, event), succeeded); + assert.deepEqual(await store.readJob(workspace, succeeded.id), succeeded); +}); + +test('progress rejects malformed, unsafe, and out-of-timeline events', async () => { + const { dataRoot, workspace } = await fixture(); + const store = createStateStore({ dataRoot }); + const queued = await store.reserveJob({ workspace, ...jobInput }); + const startedAt = new Date(Date.parse(queued.createdAt) + 1_000).toISOString(); + const running = await store.transitionJob(workspace, queued.id, ['queued'], 'running', { startedAt }); + const observedAt = new Date(Date.parse(startedAt) + 1_000).toISOString(); + const valid = { phase: 'running', message: 'Safe progress.', observedAt }; + const invalidEvents = /** @type {any[]} */ ([ + null, + [], + { ...valid, phase: 'unknown' }, + { ...valid, observedAt: 'tomorrow' }, + { ...valid, observedAt: new Date(Date.parse(startedAt) - 1).toISOString() }, + { ...valid, message: 'x'.repeat(257) }, + { ...valid, message: `${'é'.repeat(127)}abc` }, + { ...valid, message: 'line one\nline two' }, + { ...valid, message: '\u001b[31mspoof' }, + { ...valid, extra: true }, + ]); + + for (const event of invalidEvents) { + await assert.rejects( + store.updateJobProgress(workspace, running.id, event), + (error) => error instanceof PluginError && error.code === 'JOB_PROGRESS_INPUT_INVALID', + ); + } + assert.deepEqual(await store.readJob(workspace, running.id), running); +}); + test('accepted send boundaries persist for durable worker recovery', async () => { const { dataRoot, workspace } = await fixture(); const store = createStateStore({ dataRoot }); const queued = await store.reserveJob({ workspace, ...jobInput }); From 995b4dbe4150b92bbfb2044943d93c0156e20772 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 02:02:06 +0800 Subject: [PATCH 07/27] fix: show progress placeholders for legacy jobs --- scripts/lib/render.mjs | 6 ++---- tests/integration/companion.test.mjs | 2 +- tests/render-progress.test.mjs | 6 ++++++ 3 files changed, 9 insertions(+), 5 deletions(-) diff --git a/scripts/lib/render.mjs b/scripts/lib/render.mjs index a5b7d5ec..9db9b78a 100644 --- a/scripts/lib/render.mjs +++ b/scripts/lib/render.mjs @@ -20,10 +20,8 @@ export function renderOutput(value, options = {}) { /** @param {any} job */ function renderCompactJob(job) { const fields = [job.id, job.status, job.command, job.owner].map((value) => safeInline(value)); - if (typeof job.phase === 'string') fields.push(`phase=${safeInline(job.phase)}`); - if (typeof job.lastActivityAt === 'string') { - fields.push(`activity=${safeInline(job.lastActivityAt)}`); - } + fields.push(`phase=${safeInline(job.phase)}`); + fields.push(`activity=${safeInline(job.lastActivityAt)}`); const latest = Array.isArray(job.progressPreview) ? job.progressPreview.at(-1) : undefined; if (typeof latest === 'string') fields.push(`latest=${safeProgress(latest)}`); return fields.join(' '); diff --git a/tests/integration/companion.test.mjs b/tests/integration/companion.test.mjs index cf9f2208..38e243b5 100644 --- a/tests/integration/companion.test.mjs +++ b/tests/integration/companion.test.mjs @@ -355,7 +355,7 @@ test('status --all reports every workspace job with nonsecret ownership markers' assert.ok(listed.json.jobs.every((/** @type {any} */ job) => !('ownerSessionId' in job) && !('ownerTurnId' in job) && !('permissionSnapshot' in job))); const lines = listed.stdout.trim().split('\n'); assert.equal(lines.pop(), 'Model policy: default=ZCode default; aliases=none'); - assert.deepEqual(lines, listed.json.jobs.map((/** @type {any} */ job) => `${job.id} ${job.status} ${job.command} ${job.owner}`)); + assert.deepEqual(lines, listed.json.jobs.map((/** @type {any} */ job) => `${job.id} ${job.status} ${job.command} ${job.owner} phase=— activity=—`)); assert.doesNotMatch(listed.stdout, /codex-session|other-session/); }); diff --git a/tests/render-progress.test.mjs b/tests/render-progress.test.mjs index 5b7f364f..53a50934 100644 --- a/tests/render-progress.test.mjs +++ b/tests/render-progress.test.mjs @@ -86,6 +86,12 @@ test('compact job lists include phase and only the latest safe preview', () => { assert.equal(output.trim().split('\n').length, 1); }); +test('compact legacy and queued jobs show explicit missing progress placeholders', () => { + assert.equal(renderOutput({ + jobs: [{ id, status: 'queued', command: 'review', owner: 'same-owner' }], + }), `${id} queued review same-owner phase=— activity=—\n`); +}); + test('JSON output remains structurally unchanged and redacted', () => { const value = { job: { id, status: 'running', phase: 'running', progressPreview: ['safe'] }, From 52a93a0ffd4816bab3b544417a02f10fb7c2676a Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 02:12:02 +0800 Subject: [PATCH 08/27] fix: harden zcode progress timestamps and rendering --- scripts/lib/render.mjs | 9 +++- scripts/lib/state.mjs | 20 ++++++-- tests/render-progress.test.mjs | 5 +- tests/state.test.mjs | 85 ++++++++++++++++++++++++++++++---- 4 files changed, 104 insertions(+), 15 deletions(-) diff --git a/scripts/lib/render.mjs b/scripts/lib/render.mjs index 9db9b78a..1de380a8 100644 --- a/scripts/lib/render.mjs +++ b/scripts/lib/render.mjs @@ -62,6 +62,7 @@ function safeInline(value) { if (typeof value !== 'string' || value.length === 0) return '—'; const controlFree = [...value].map((character) => { const code = /** @type {number} */ (character.codePointAt(0)); + if (isBidiControl(code)) return ''; return code <= 31 || code >= 127 && code <= 159 ? ' ' : character; }).join(''); return escapeMarkdown(controlFree.replace(/\s+/g, ' ').trim()); @@ -75,7 +76,13 @@ function safeProgress(message) { /** @param {string} value */ function escapeMarkdown(value) { - return value.replace(/([\\`*_{}[\]<>#!|])/g, '\\$1').replace(/^([-+])/, '\\$1'); + return value.replace(/([\\`*_{}[\]<>#!|~])/g, '\\$1').replace(/^([-+])/, '\\$1'); +} + +/** @param {number} code */ +function isBidiControl(code) { + return code === 0x061c || code === 0x200e || code === 0x200f + || code >= 0x202a && code <= 0x202e || code >= 0x2066 && code <= 0x2069; } /** @param {string} value @param {number} maxBytes */ diff --git a/scripts/lib/state.mjs b/scripts/lib/state.mjs index 0b9b50f9..5f8426c0 100644 --- a/scripts/lib/state.mjs +++ b/scripts/lib/state.mjs @@ -194,8 +194,11 @@ export function createStateStore(options) { const job = await readJobRecord(path, jobId, storage.workspacePath); if (job.status === 'queued' || TERMINAL_STATUSES.has(job.status)) return job; const observedAtMs = Date.parse(event.observedAt); + const currentTime = Date.now(); const activityFloor = Date.parse(job.lastActivityAt ?? job.startedAt ?? job.createdAt); - if (observedAtMs < activityFloor) throw invalidProgressInput(['observedAt']); + if (observedAtMs < activityFloor || observedAtMs > currentTime) { + throw invalidProgressInput(['observedAt']); + } const progressPreview = job.progressPreview ?? []; const messages = progressPreview.at(-1) === event.message ? progressPreview @@ -206,7 +209,7 @@ export function createStateStore(options) { lastActivityAt: event.observedAt, progressPreview: messages, updatedAt: new Date(Math.max( - Date.now(), + currentTime, Date.parse(job.updatedAt), observedAtMs, )).toISOString(), @@ -412,7 +415,8 @@ function validateJobRecord(job, expectedJobId, expectedWorkspacePath) { && job.status !== 'queued' && lastActivityAt !== undefined && lastActivityAt >= (startedAt ?? createdAt) - && Date.parse(job.updatedAt) >= lastActivityAt; + && Date.parse(job.updatedAt) >= lastActivityAt + && (!terminal || finishedAt !== undefined && finishedAt >= lastActivityAt); const validTimeline = validShape && Date.parse(job.updatedAt) >= createdAt && (startedAt === undefined || Date.parse(job.updatedAt) >= startedAt) @@ -461,6 +465,8 @@ function validateJobPatch(job, nextStatus, patch, jobId) { if ('finishedAt' in patch && (!isIsoTimestamp(patch.finishedAt) || Date.parse(/** @type {string} */ (patch.finishedAt)) < Date.parse(job.startedAt ?? job.createdAt) + || typeof job.lastActivityAt === 'string' + && Date.parse(/** @type {string} */ (patch.finishedAt)) < Date.parse(job.lastActivityAt) || !TERMINAL_STATUSES.has(nextStatus))) invalidFields.push('finishedAt'); if ('promptArtifact' in patch && (!isSafeArtifact(patch.promptArtifact) || !writesRunningMetadata)) { @@ -557,10 +563,16 @@ function isSafeProgressMessage(value) { && Buffer.byteLength(value) <= MAX_PROGRESS_MESSAGE_BYTES && ![...value].some((character) => { const code = /** @type {number} */ (character.codePointAt(0)); - return code <= 31 || code >= 127 && code <= 159; + return code <= 31 || code >= 127 && code <= 159 || isBidiControl(code); }); } +/** @param {number} code */ +function isBidiControl(code) { + return code === 0x061c || code === 0x200e || code === 0x200f + || code >= 0x202a && code <= 0x202e || code >= 0x2066 && code <= 0x2069; +} + /** @param {unknown} value */ function isIsoTimestamp(value) { return typeof value === 'string' && Number.isFinite(Date.parse(value)) diff --git a/tests/render-progress.test.mjs b/tests/render-progress.test.mjs index 53a50934..7dc17010 100644 --- a/tests/render-progress.test.mjs +++ b/tests/render-progress.test.mjs @@ -75,14 +75,15 @@ test('compact job lists include phase and only the latest safe preview', () => { owner: 'same-owner', phase: 'running', lastActivityAt: '2026-08-08T00:04:00.000Z', - progressPreview: ['old preview', 'latest `preview`\nforged line'], + progressPreview: ['old preview', 'latest `preview`\nforged \u202Eline ~~strike~~'], }], }); assert.doesNotMatch(output, /old preview/); assert.match(output, /phase=running/); assert.match(output, /activity=2026-08-08T00:04:00\.000Z/); - assert.match(output, /latest=latest \\`preview\\` forged line/); + assert.match(output, /latest=latest \\`preview\\` forged line \\~\\~strike\\~\\~/); + assert.doesNotMatch(output, /\u202E/); assert.equal(output.trim().split('\n').length, 1); }); diff --git a/tests/state.test.mjs b/tests/state.test.mjs index c24d881d..c16b3ea0 100644 --- a/tests/state.test.mjs +++ b/tests/state.test.mjs @@ -593,7 +593,7 @@ test('running and cancelling jobs persist bounded monotonic progress', async () const { dataRoot, workspace } = await fixture(); const store = createStateStore({ dataRoot }); const queued = await store.reserveJob({ workspace, ...jobInput }); - const startedAt = new Date(Date.parse(queued.createdAt) + 1_000).toISOString(); + const startedAt = queued.createdAt; let job = await store.transitionJob(workspace, queued.id, ['queued'], 'running', { startedAt }); const identity = { id: job.id, @@ -608,7 +608,7 @@ test('running and cancelling jobs persist bounded monotonic progress', async () }; for (let index = 1; index <= 5; index += 1) { - const observedAt = new Date(Date.parse(startedAt) + index * 1_000).toISOString(); + const observedAt = startedAt; const previousUpdatedAt = job.updatedAt; job = await store.updateJobProgress(workspace, job.id, { phase: index === 5 ? 'waiting' : 'running', @@ -620,7 +620,7 @@ test('running and cancelling jobs persist bounded monotonic progress', async () } assert.equal(job.phase, 'waiting'); - assert.equal(job.lastActivityAt, new Date(Date.parse(startedAt) + 5_000).toISOString()); + assert.equal(job.lastActivityAt, startedAt); assert.deepEqual(job.progressPreview, ['Progress 2', 'Progress 3', 'Progress 4', 'Progress 5']); assert.deepEqual({ id: job.id, @@ -637,7 +637,7 @@ test('running and cancelling jobs persist bounded monotonic progress', async () const duplicate = await store.updateJobProgress(workspace, job.id, { phase: 'running', message: 'Progress 5', - observedAt: new Date(Date.parse(startedAt) + 6_000).toISOString(), + observedAt: startedAt, }); assert.equal(duplicate.phase, 'running'); assert.deepEqual(duplicate.progressPreview, job.progressPreview); @@ -646,7 +646,7 @@ test('running and cancelling jobs persist bounded monotonic progress', async () const cancellingProgress = await store.updateJobProgress(workspace, job.id, { phase: 'finalizing', message: 'Stopping ZCode.', - observedAt: new Date(Date.parse(startedAt) + 7_000).toISOString(), + observedAt: startedAt, }); assert.equal(cancellingProgress.status, 'cancelling'); assert.equal(cancellingProgress.phase, 'finalizing'); @@ -665,18 +665,86 @@ test('progress is a no-op once queued or terminal lifecycle state wins', async ( assert.deepEqual(await store.updateJobProgress(workspace, queued.id, event), queued); const running = await store.transitionJob(workspace, queued.id, ['queued'], 'running'); - const succeeded = await store.transitionJob(workspace, running.id, ['running'], 'succeeded'); + const succeeded = await store.transitionJob(workspace, running.id, ['running'], 'succeeded', { + finishedAt: running.updatedAt, + }); assert.deepEqual(await store.updateJobProgress(workspace, succeeded.id, event), succeeded); assert.deepEqual(await store.readJob(workspace, succeeded.id), succeeded); }); +test('future progress is rejected without poisoning a subsequent current update', async () => { + const { dataRoot, workspace } = await fixture(); + const store = createStateStore({ dataRoot }); + const queued = await store.reserveJob({ workspace, ...jobInput }); + const running = await store.transitionJob(workspace, queued.id, ['queued'], 'running', { + startedAt: queued.createdAt, + }); + const future = new Date(Date.now() + 60_000).toISOString(); + await assert.rejects( + store.updateJobProgress(workspace, running.id, { + phase: 'running', message: 'Future activity.', observedAt: future, + }), + (error) => error instanceof PluginError && error.code === 'JOB_PROGRESS_INPUT_INVALID', + ); + assert.deepEqual(await store.readJob(workspace, running.id), running); + + const observedAt = new Date().toISOString(); + const progressed = await store.updateJobProgress(workspace, running.id, { + phase: 'running', message: 'Current activity.', observedAt, + }); + assert.equal(progressed.lastActivityAt, observedAt); + assert.deepEqual(progressed.progressPreview, ['Current activity.']); +}); + +test('progress winning the lock prevents an earlier completion but permits a later one', async () => { + const { dataRoot, workspace } = await fixture(); + const store = createStateStore({ dataRoot }); + const queued = await store.reserveJob({ workspace, ...jobInput }); + const running = await store.transitionJob(workspace, queued.id, ['queued'], 'running'); + const storage = await resolveWorkspaceStorage({ dataRoot, workspace }); + const path = join(storage.directory, 'jobs', `${running.id}.json`); + const startedAt = '2020-01-01T00:00:00.000Z'; + const historical = { + ...running, + createdAt: startedAt, + startedAt, + updatedAt: '2020-01-01T00:00:01.000Z', + }; + await atomicWriteJson(path, historical); + const progressed = await store.updateJobProgress(workspace, running.id, { + phase: 'finalizing', + message: 'ZCode completed the delegated turn.', + observedAt: '2020-01-01T00:00:02.000Z', + }); + + await atomicWriteJson(path, { + ...progressed, + status: 'succeeded', + finishedAt: '2020-01-01T00:00:01.000Z', + }); + await assert.rejects(store.readJob(workspace, running.id), { code: 'JOB_RECORD_INVALID' }); + await atomicWriteJson(path, progressed); + + await assert.rejects( + store.transitionJob(workspace, running.id, ['running'], 'succeeded', { + finishedAt: '2020-01-01T00:00:01.000Z', + }), + { code: 'JOB_PATCH_INVALID' }, + ); + const succeeded = await store.transitionJob(workspace, running.id, ['running'], 'succeeded', { + finishedAt: '2020-01-01T00:00:03.000Z', + }); + assert.equal(succeeded.status, 'succeeded'); + assert.equal(succeeded.lastActivityAt, progressed.lastActivityAt); +}); + test('progress rejects malformed, unsafe, and out-of-timeline events', async () => { const { dataRoot, workspace } = await fixture(); const store = createStateStore({ dataRoot }); const queued = await store.reserveJob({ workspace, ...jobInput }); - const startedAt = new Date(Date.parse(queued.createdAt) + 1_000).toISOString(); + const startedAt = queued.createdAt; const running = await store.transitionJob(workspace, queued.id, ['queued'], 'running', { startedAt }); - const observedAt = new Date(Date.parse(startedAt) + 1_000).toISOString(); + const observedAt = startedAt; const valid = { phase: 'running', message: 'Safe progress.', observedAt }; const invalidEvents = /** @type {any[]} */ ([ null, @@ -688,6 +756,7 @@ test('progress rejects malformed, unsafe, and out-of-timeline events', async () { ...valid, message: `${'é'.repeat(127)}abc` }, { ...valid, message: 'line one\nline two' }, { ...valid, message: '\u001b[31mspoof' }, + { ...valid, message: 'safe\u202Etxt' }, { ...valid, extra: true }, ]); From f3b1714bbead8ea7630eb01e3163bb55b7b42cb2 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 02:25:45 +0800 Subject: [PATCH 09/27] feat: surface live zcode task activity --- scripts/lib/review.mjs | 43 ++++++++++++-- scripts/zcode-companion.mjs | 16 ++++-- tests/fixtures/fake-zcode-cli.mjs | 9 ++- tests/integration/companion.test.mjs | 20 +++++++ tests/job-control.test.mjs | 85 ++++++++++++++++++++++++++-- 5 files changed, 155 insertions(+), 18 deletions(-) diff --git a/scripts/lib/review.mjs b/scripts/lib/review.mjs index a5359b75..7e5938ef 100644 --- a/scripts/lib/review.mjs +++ b/scripts/lib/review.mjs @@ -7,6 +7,7 @@ import { PluginError } from './errors.mjs'; import { resolveModel } from './args.mjs'; import { ensurePrivateDirectory, withFileLock } from './fs.mjs'; import { collectGitFacts } from './git.mjs'; +import { createProgressReporter } from './progress.mjs'; import { buildPrompt } from './prompts.mjs'; import { loadReviewOutputSchema, validateJsonSchema } from './review-schema.mjs'; import { resolveWorkspaceStorage } from './workspace.mjs'; @@ -30,11 +31,17 @@ export function decidePermission(request, permissionSnapshot, command) { } /** - * @param {{job:any,workspace:string,dataRoot:string,store:any,client:any,scope?:string,base?:string,focus?:string,task?:string,model?:any,modelRequest?:string,modelAliases?:Record,effort?:string,resumeSessionId?:string,onBeforeResume?:(job:any)=>Promise,childPid?:number,workerLeaseId?:string,onBoundaryPersisted?:(job:any)=>Promise,syncDirectory?:(path:string)=>Promise}} input + * @param {{job:any,workspace:string,dataRoot:string,store:any,client:any,scope?:string,base?:string,focus?:string,task?:string,model?:any,modelRequest?:string,modelAliases?:Record,effort?:string,resumeSessionId?:string,onBeforeResume?:(job:any)=>Promise,childPid?:number,workerLeaseId?:string,onBoundaryPersisted?:(job:any)=>Promise,syncDirectory?:(path:string)=>Promise,progressWriter?:(line:string)=>void,progressDependencies?:{now?:()=>string,setInterval?:(callback:()=>void,milliseconds:number)=>any,clearInterval?:(timer:any)=>void},signal?:AbortSignal}} input */ export async function executeJob(input) { const { job, client, workspace, dataRoot } = input; let running = job; let sessionId; let sendAttempted = false; let remoteTerminalProven = false; + let reporter; + let unsubscribe = () => {}; + /** @type {unknown} */ + let primaryError; + /** @type {any} */ + let output; try { let prompt; if (job.command === 'review' || job.command === 'adversarial-review') { @@ -48,6 +55,13 @@ export async function executeJob(input) { snapshot = await client.resumeSession(input.resumeSessionId); } else snapshot = await client.createSession({ workspace, ...(input.model ? { model: input.model } : {}) }); sessionId = snapshot.session.sessionId; + reporter = createProgressReporter({ + sessionId, + ...(input.progressWriter ? { write: input.progressWriter } : {}), + persist: (event) => input.store.updateJobProgress(workspace, job.id, event), + ...input.progressDependencies, + }); + unsubscribe = client.subscribe(reporter.observe); const selectedModel = input.modelRequest ? resolveModel(input.modelRequest, input.modelAliases, snapshot.settings.model.available) : input.model; if (selectedModel && !sameModel(snapshot.settings.model.current, selectedModel)) snapshot = await client.setModel(sessionId, selectedModel); if (input.effort) snapshot = await client.setThoughtLevel(sessionId, input.effort); @@ -59,6 +73,7 @@ export async function executeJob(input) { ...(input.workerLeaseId ? { workerLeaseId: input.workerLeaseId } : {}), ...(selectedModel ? { model: selectedModel } : {}), ...(input.effort ? { effort: input.effort } : {}), }); + reporter.observe({ method: 'state.updated', params: { scope: 'session', sessionId, reason: 'prompt_started' } }); const beforeMessageIds = [...snapshotMessageIds(snapshot)]; sendAttempted = true; const sent = await client.send(sessionId, prompt); running = await input.store.transitionJob(workspace, job.id, ['running'], 'running', { inputId: sent.inputId, startRevision: sent.stateRevision, beforeMessageIds }); await input.onBoundaryPersisted?.(running); @@ -68,22 +83,38 @@ export async function executeJob(input) { remoteTerminalProven = true; const result = extractFinalResult(finalSnapshot, job.command, turnBoundary); const resultArtifact = await writeArtifact({ dataRoot, workspace, directory: 'results', jobId: job.id, contents: result }, { syncDirectory: input.syncDirectory }); + await reporter.flush(); const succeeded = await input.store.transitionJob(workspace, job.id, ['running'], 'succeeded', { resultArtifact, finishedAt: new Date().toISOString(), exitCode: 0 }); - return { job: succeeded, result }; + output = { job: succeeded, result }; } catch (error) { + primaryError = error; const current = await input.store.readJob(workspace, job.id).catch(() => running); if (current && !['failed', 'succeeded', 'cancelled', 'cancelling'].includes(current.status)) { + let canFail = true; if (current.status === 'running' && sendAttempted && sessionId && !remoteTerminalProven) { try { await client.stopSession(sessionId); } catch (stopError) { await input.store.transitionJob(workspace, job.id, ['running'], 'running', { lastCancelError: safeError(stopError).message }).catch(() => {}); - throw error; + canFail = false; } } - await input.store.transitionJob(workspace, job.id, [current.status], 'failed', { error: safeError(error), finishedAt: new Date().toISOString(), exitCode: 1 }).catch(() => {}); + if (canFail) await input.store.transitionJob(workspace, job.id, [current.status], 'failed', { error: safeError(error), finishedAt: new Date().toISOString(), exitCode: 1 }).catch(() => {}); } - throw error; - } finally { await client.close().catch(() => {}); } + } + // Cleanup order is part of the progress lifecycle contract. + const cleanupErrors = []; + try { unsubscribe(); } catch (error) { cleanupErrors.push(error); } + try { reporter?.close(); } catch (error) { cleanupErrors.push(error); } + try { await reporter?.flush(); } catch (error) { cleanupErrors.push(error); } + try { await client.close(); } catch (error) { cleanupErrors.push(error); } + const distinctCleanupErrors = cleanupErrors.filter((error) => error !== primaryError); + if (primaryError) { + if (distinctCleanupErrors.length) throw new AggregateError([primaryError, ...distinctCleanupErrors], 'ZCode execution and progress cleanup failed.'); + throw primaryError; + } + if (cleanupErrors.length === 1) throw cleanupErrors[0]; + if (cleanupErrors.length > 1) throw new AggregateError(cleanupErrors, 'ZCode progress cleanup failed.'); + return output; } /** @param {{dataRoot:string,workspace:string,artifact:string}} input */ diff --git a/scripts/zcode-companion.mjs b/scripts/zcode-companion.mjs index ba335b19..052ebf74 100644 --- a/scripts/zcode-companion.mjs +++ b/scripts/zcode-companion.mjs @@ -30,7 +30,7 @@ import { reconcileBrokerOwnership } from './zcode-broker.mjs'; const backgroundBindings = new WeakMap(); const activePluginRoot = realpathSync(fileURLToPath(new URL('../', import.meta.url))); -/** @param {string[]} argv @param {{cwd?:string,env?:NodeJS.ProcessEnv,authorization?:Record,dependencies?:any,caller?:any,startupAck?:()=>Promise,originalPrompt?:string,autoLaunchBackground?:boolean}} [runtime] */ +/** @param {string[]} argv @param {{cwd?:string,env?:NodeJS.ProcessEnv,authorization?:Record,dependencies?:any,caller?:any,startupAck?:()=>Promise,originalPrompt?:string,autoLaunchBackground?:boolean,progressWriter?:(line:string)=>void,progressDependencies?:any,signal?:AbortSignal}} [runtime] */ export async function runCompanion(argv, runtime = {}) { const cwd = runtime.cwd ?? process.cwd(); const env = runtime.env ?? process.env; const parsed = parseArgs(argv); const dataRoot = resolvePluginDataRoot({ env, pluginRoot: activePluginRoot }); @@ -65,10 +65,10 @@ export async function runCompanion(argv, runtime = {}) { try { return { job: await cancelling.cancel(cwd, selected.id, caller.sessionId) }; } finally { await client.close().catch(() => {}); } } - return startPublic({ parsed, caller, cwd, env, dataRoot, identity, store, controller, dependencies: runtime.dependencies, originalPrompt: runtime.originalPrompt, autoLaunchBackground: runtime.autoLaunchBackground }); + return startPublic({ parsed, caller, cwd, env, dataRoot, identity, store, controller, dependencies: runtime.dependencies, originalPrompt: runtime.originalPrompt, autoLaunchBackground: runtime.autoLaunchBackground, progressWriter: runtime.progressWriter, progressDependencies: runtime.progressDependencies, signal: runtime.signal }); } -/** Resolve a hook-recorded active turn and invoke through ordinary stdio without caller-supplied authorization. @param {string[]} argv @param {{cwd?:string,env?:NodeJS.ProcessEnv,dependencies?:any}} [runtime] */ +/** Resolve a hook-recorded active turn and invoke through ordinary stdio without caller-supplied authorization. @param {string[]} argv @param {{cwd?:string,env?:NodeJS.ProcessEnv,dependencies?:any,progressWriter?:(line:string)=>void,progressDependencies?:any,signal?:AbortSignal}} [runtime] */ export async function runDirectInvocation(argv, runtime = {}) { const cwd = runtime.cwd ?? process.cwd(); const env = runtime.env ?? process.env; const dataRoot = resolvePluginDataRoot({ env, pluginRoot: activePluginRoot }); const sessionId = env.CODEX_THREAD_ID; if (typeof sessionId !== 'string' || !sessionId) throw new PluginError('THREAD_ID_REQUIRED', 'The active Codex thread identity is unavailable.', { category: 'authorization', remedy: 'Invoke this installed skill from an active Codex turn.' }); @@ -84,7 +84,7 @@ export async function runDirectInvocation(argv, runtime = {}) { return { type: 'needs-choice', choices: ['wait', 'background'] }; } } - const output = await runCompanion(invocation.argv, { cwd, env, caller: executionCaller, originalPrompt: invocation.implicitText, autoLaunchBackground: true, dependencies: runtime.dependencies }); + const output = await runCompanion(invocation.argv, { cwd, env, caller: executionCaller, originalPrompt: invocation.implicitText, autoLaunchBackground: true, dependencies: runtime.dependencies, progressWriter: runtime.progressWriter, progressDependencies: runtime.progressDependencies, signal: runtime.signal }); if (output?.type === 'needs-choice') await invocations.savePending({ sessionId, turnId: executionCaller.turnId, workspace: cwd, permissionMode: executionCaller.permissionMode, command, spec: { argv: invocation.argv } }); return output; } @@ -176,7 +176,7 @@ async function executeReserved(context) { client = await createManagedZCodeClient({ dataRoot, workspace: cwd, launch, ownerId, env }); const modelConfig = await readWorkspaceModelConfig({ dataRoot, workspace: cwd }); const modelRequest = spec.model ?? modelConfig.defaultModel; const preResolvedModel = modelRequest && (modelRequest.includes('/') || Object.hasOwn(modelConfig.models, modelRequest)) ? resolveModel(modelRequest, modelConfig.models, []) : undefined; - return await executeJob({ job, workspace: cwd, dataRoot, store, client, scope: spec.scope, base: spec.base, focus: spec.focus, task: spec.task, model: preResolvedModel, modelRequest: preResolvedModel ? undefined : modelRequest, modelAliases: modelConfig.models, effort: spec.effort, resumeSessionId: spec.resumeSessionId, childPid: context.childPid, workerLeaseId: context.workerLeaseId, onBoundaryPersisted: context.onBoundaryPersisted, onBeforeResume: async () => { await validateResumeCandidate(store, cwd, job.ownerSessionId, spec); await reconcileBrokerOwnership({ dataRoot, workspace: cwd, ownerId, ownedSessionIds: [spec.resumeSessionId] }); } }); + return await executeJob({ job, workspace: cwd, dataRoot, store, client, scope: spec.scope, base: spec.base, focus: spec.focus, task: spec.task, model: preResolvedModel, modelRequest: preResolvedModel ? undefined : modelRequest, modelAliases: modelConfig.models, effort: spec.effort, resumeSessionId: spec.resumeSessionId, childPid: context.childPid, workerLeaseId: context.workerLeaseId, onBoundaryPersisted: context.onBoundaryPersisted, progressWriter: context.progressWriter, progressDependencies: context.progressDependencies, signal: context.signal, onBeforeResume: async () => { await validateResumeCandidate(store, cwd, job.ownerSessionId, spec); await reconcileBrokerOwnership({ dataRoot, workspace: cwd, ownerId, ownedSessionIds: [spec.resumeSessionId] }); } }); } catch (error) { await client?.close().catch(() => {}); const current = await store.readJob(cwd, job.id).catch(() => null); @@ -324,7 +324,11 @@ async function main() { let output; try { const entry = process.argv[2]; const setup = entry === 'setup'; const direct = entry === 'invoke' || entry === 'invoke-choice'; const worker = process.env.ZCODE_BACKGROUND_WORKER === '1'; const authorization = setup || direct ? undefined : await readInternalEnvelope(); - output = direct ? await runDirectInvocation(process.argv.slice(2)) : await runCompanion(process.argv.slice(2), { authorization, ...(worker ? { startupAck: acknowledgeBackgroundStartup } : {}) }); + const foregroundProgress = worker ? {} : { + progressWriter: (/** @type {string} */ line) => process.stderr.write(line), + progressDependencies: { now: () => new Date().toISOString(), setInterval: globalThis.setInterval, clearInterval: globalThis.clearInterval }, + }; + output = direct ? await runDirectInvocation(process.argv.slice(2), foregroundProgress) : await runCompanion(process.argv.slice(2), { authorization, ...foregroundProgress, ...(worker ? { startupAck: acknowledgeBackgroundStartup } : {}) }); if (!setup && !direct && !worker) await writeInternalResponse(output); if (!worker) process.stdout.write(renderOutput(output)); if (output?.type === 'needs-choice') process.exitCode = 3; } catch (error) { if (output?.type === 'background') await failBackgroundDelivery(output, error); const envelope = errorEnvelope(error); const entry = process.argv[2]; const protectedOutput = entry !== 'setup' && entry !== 'invoke' && entry !== 'invoke-choice' && process.env.ZCODE_BACKGROUND_WORKER !== '1'; if (protectedOutput) try { await writeInternalResponse(envelope); } catch { /* no trusted response channel */ } if (process.env.ZCODE_BACKGROUND_WORKER !== '1') process.stdout.write(renderOutput(envelope, { json: true })); if (process.env.ZCODE_DEBUG === '1') process.stderr.write(`${error instanceof Error ? error.stack : String(error)}\n`); process.exitCode = error instanceof PluginError && error.category === 'validation' ? 2 : 1; } diff --git a/tests/fixtures/fake-zcode-cli.mjs b/tests/fixtures/fake-zcode-cli.mjs index 3562aa21..e622053c 100644 --- a/tests/fixtures/fake-zcode-cli.mjs +++ b/tests/fixtures/fake-zcode-cli.mjs @@ -171,7 +171,14 @@ input.on('line', async (line) => { if (process.env.FAKE_ZCODE_PERMISSION_REPLAY === '1') send({ id: permissionId++, method: 'interaction/requestPermission', params }); } const notificationSession = process.env.FAKE_ZCODE_CROSS_SESSION ?? p.sessionId; - const completion = { method: 'state.updated', params: { type: 'state.updated', scope: 'session', sessionId: notificationSession, revision: stateRevision + 1, reason: 'prompt_completed', patch: { status: 'idle' } } }; + let notificationRevision = stateRevision; + if (process.env.FAKE_ZCODE_PROGRESS === '1') { + for (const reason of ['model_streaming', 'tool_call_started', 'tool_call_result']) { + notificationRevision += 1; + send({ method: 'state.updated', params: { type: 'state.updated', scope: 'session', sessionId: notificationSession, revision: notificationRevision, reason, patch: {} } }); + } + } + const completion = { method: 'state.updated', params: { type: 'state.updated', scope: 'session', sessionId: notificationSession, revision: notificationRevision + 1, reason: 'prompt_completed', patch: { status: 'idle' } } }; if (process.env.FAKE_ZCODE_SYNC_BATCH === 'stale-valid') sendBatch([response, { method: 'state.updated', params: { ...completion.params, revision: stateRevision } }, completion]); else if (process.env.FAKE_ZCODE_SYNC_COMPLETE === '1') send(completion); else if (!(process.env.FAKE_ZCODE_SUPPRESS_FIRST_COMPLETION === '1' && sendCount === 1) diff --git a/tests/integration/companion.test.mjs b/tests/integration/companion.test.mjs index 38e243b5..9fd5b97d 100644 --- a/tests/integration/companion.test.mjs +++ b/tests/integration/companion.test.mjs @@ -92,6 +92,26 @@ test('rescue task semantics reach the fake peer as the authorized objective', as assert.match(sent.params.content, /UNTRUSTED GIT DATA/); }); +test('foreground rescue streams safe progress to stderr and durably exposes it through status', async () => { + const context = await fixture(); + const result = await companion(context, ['rescue', '--fresh', 'surface progress'], { FAKE_ZCODE_PROGRESS: '1' }); + assert.equal(result.code, 0, `${result.stderr}${result.stdout}`); assert.equal(result.stdout, 'done\n'); + assert.match(result.stderr, /\[zcode\] ZCode started the delegated turn\./); + assert.match(result.stderr, /\[zcode\] ZCode is generating a response\./); + assert.match(result.stderr, /\[zcode\] ZCode started a tool call\./); + assert.match(result.stderr, /\[zcode\] ZCode completed a tool call\./); + const status = await companion(context, ['status', result.json.job.id]); + assert.equal(status.code, 0, `${status.stderr}${status.stdout}`); + assert.equal(status.json.job.phase, 'finalizing'); + assert.ok(Date.parse(status.json.job.lastActivityAt)); + assert.deepEqual(status.json.job.progressPreview, [ + 'ZCode is generating a response.', + 'ZCode started a tool call.', + 'ZCode completed a tool call.', + 'ZCode completed the delegated turn.', + ]); +}); + test('background reservation exposes one private invocation, which is single-use', async () => { const context = await fixture(); const reserved = await companion(context, ['review', '--background']); diff --git a/tests/job-control.test.mjs b/tests/job-control.test.mjs index c818bcae..00976429 100644 --- a/tests/job-control.test.mjs +++ b/tests/job-control.test.mjs @@ -19,6 +19,7 @@ async function setup() { } const reservation = { ownerSessionId: 'session-a', ownerTurnId: 'turn-a', command: 'rescue', readOnly: false, permissionSnapshot: { permissionMode: 'workspace-write' } }; +const silentSubscribe = () => () => {}; /** @param {string} root @param {string} workspace @param {string} jobId */ async function attemptFixture(root, workspace, jobId) { @@ -236,7 +237,7 @@ test('executor failure cannot steal cancellation terminal ownership', async () = const completion = new Promise((resolve, reject) => { rejectCompletion = () => reject(new Error('stopped')); }); const client = { createSession: async () => ({ session: { sessionId: 'zs' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), - setPermissionHandler: () => {}, send: async () => ({ inputId: 'input-cancel-race', stateRevision: 1 }), waitForCompletion: () => { signalWaitStarted(); return completion; }, + setPermissionHandler: () => {}, subscribe: silentSubscribe, send: async () => ({ inputId: 'input-cancel-race', stateRevision: 1 }), waitForCompletion: () => { signalWaitStarted(); return completion; }, readSession: async () => ({}), close: async () => {}, }; const execution = executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task' }); @@ -256,7 +257,7 @@ test('executor persists the accepted turn boundary and worker identity before st let acknowledged = null; const client = { createSession: async () => ({ session: { sessionId: 'zs-boundary' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [{ info: { messageId: 'before-1' } }] }), - setPermissionHandler: () => {}, send: async () => ({ inputId: 'input-boundary', stateRevision: 19 }), + setPermissionHandler: () => {}, subscribe: silentSubscribe, send: async () => ({ inputId: 'input-boundary', stateRevision: 19 }), waitForCompletion: async () => { throw new Error('simulated worker crash after acknowledgement'); }, stopSession: async () => {}, close: async () => {}, }; const workerLeaseId = 'a'.repeat(64); @@ -266,12 +267,86 @@ test('executor persists the accepted turn boundary and worker identity before st const persisted = await store.readJob(workspace, job.id); assert.equal(persisted.status, 'failed'); assert.equal(persisted.inputId, 'input-boundary'); assert.equal(persisted.childPid, 4321); assert.equal(persisted.workerLeaseId, workerLeaseId); }); +test('executor reports only same-session progress and drains persistence before success', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + /** @type {string[]} */ + const lines = []; + /** @type {any[]} */ + const persisted = []; + /** @type {string[]} */ + const order = []; + /** @type {null|((message:any)=>void)} */ let handler = null; let unsubscribes = 0; let closes = 0; /** @type {null|(()=>void)} */ let intervalCallback = null; let cleared = 0; + const wrapped = { + ...store, + updateJobProgress: async (/** @type {string} */ workspaceArg, /** @type {string} */ jobId, /** @type {any} */ event) => { + order.push(`persist:${event.phase}`); persisted.push(event); + await new Promise((resolve) => setImmediate(resolve)); + return store.updateJobProgress(workspaceArg, jobId, event); + }, + transitionJob: async (/** @type {string} */ workspaceArg, /** @type {string} */ jobId, /** @type {string[]} */ expected, /** @type {string} */ next, /** @type {Record} */ patch = {}) => { + if (next === 'succeeded') order.push('transition:succeeded'); + return store.transitionJob(workspaceArg, jobId, expected, next, patch); + }, + }; + const notification = (/** @type {string} */ sessionId, /** @type {string} */ reason, /** @type {number} */ revision) => ({ method: 'state.updated', params: { type: 'state.updated', scope: 'session', sessionId, revision, reason, patch: {} } }); + const emit = (/** @type {any} */ message) => { if (!handler) throw new Error('progress handler missing'); handler(message); }; + const client = { + createSession: async () => ({ session: { sessionId: 'zs-progress' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [] }), + setPermissionHandler: () => {}, + subscribe: (/** @type {(message:any)=>void} */ subscriber) => { handler = subscriber; return () => { unsubscribes += 1; handler = null; }; }, + send: async () => ({ inputId: 'input-progress', stateRevision: 1 }), + waitForCompletion: async () => { + emit(notification('zs-sibling', 'tool_call_started', 2)); + emit(notification('zs-progress', 'model_streaming', 2)); + emit(notification('zs-progress', 'tool_call_started', 3)); + emit(notification('zs-progress', 'prompt_completed', 4)); + }, + readSession: async () => ({ messages: [{ info: { role: 'assistant', messageId: 'assistant-progress', parentMessageId: 'input-progress' }, parts: [{ type: 'text', text: 'done' }] }] }), + close: async () => { closes += 1; }, + }; + const result = await executeJob({ + job, workspace, dataRoot: join(root, 'data'), store: wrapped, client, task: 'task', + progressWriter: (line) => lines.push(line), + progressDependencies: { + now: () => new Date().toISOString(), + setInterval: (callback) => { intervalCallback = callback; return { unref() {} }; }, + clearInterval: () => { cleared += 1; }, + }, + }); + assert.equal(result.job.status, 'succeeded'); assert.equal(typeof intervalCallback, 'function'); + assert.deepEqual(lines, [ + '[zcode] ZCode started the delegated turn.\n', + '[zcode] ZCode is generating a response.\n', + '[zcode] ZCode started a tool call.\n', + '[zcode] ZCode completed the delegated turn.\n', + ]); + assert.deepEqual(persisted.map((event) => event.message), lines.map((line) => line.slice(8, -1))); + assert.ok(order.lastIndexOf('persist:finalizing') < order.indexOf('transition:succeeded')); + assert.equal(unsubscribes, 1); assert.equal(cleared, 1); assert.equal(closes, 1); assert.equal(handler, null); +}); + +test('executor failure still unsubscribes, stops heartbeat, and closes the client', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + let handler = null; let unsubscribes = 0; let cleared = 0; let closes = 0; + const client = { + createSession: async () => ({ session: { sessionId: 'zs-progress-failure' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), + setPermissionHandler: () => {}, subscribe: (/** @type {(message:any)=>void} */ subscriber) => { handler = subscriber; return () => { unsubscribes += 1; handler = null; }; }, + send: async () => ({ inputId: 'input-progress-failure', stateRevision: 1 }), + waitForCompletion: async () => { throw new Error('progress wait failed'); }, stopSession: async () => {}, close: async () => { closes += 1; }, + }; + await assert.rejects(executeJob({ + job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', progressWriter: () => {}, + progressDependencies: { now: () => new Date().toISOString(), setInterval: () => ({ unref() {} }), clearInterval: () => { cleared += 1; } }, + }), /progress wait failed/); + assert.equal(unsubscribes, 1); assert.equal(cleared, 1); assert.equal(closes, 1); assert.equal(handler, null); +}); + test('accepted send with boundary persistence failure requires remote stop proof before releasing the guard', async () => { for (const stopSucceeds of [true, false]) { const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); let stops = 0; const boundaryError = new Error('boundary fsync refused'); const wrapped = /** @type {typeof store} */ ({ ...store, transitionJob: async (workspaceArg, jobId, expectedStatuses, nextStatus, patch = {}) => { if (patch.inputId) throw boundaryError; return store.transitionJob(workspaceArg, jobId, expectedStatuses, nextStatus, patch); } }); - const client = { createSession: async () => ({ session: { sessionId: 'zs-boundary-failure' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), setPermissionHandler: () => {}, send: async () => ({ inputId: 'accepted-not-durable', stateRevision: 2 }), stopSession: async () => { stops += 1; if (!stopSucceeds) throw new Error('stop not acknowledged'); }, close: async () => {} }; + const client = { createSession: async () => ({ session: { sessionId: 'zs-boundary-failure' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), setPermissionHandler: () => {}, subscribe: silentSubscribe, send: async () => ({ inputId: 'accepted-not-durable', stateRevision: 2 }), stopSession: async () => { stops += 1; if (!stopSucceeds) throw new Error('stop not acknowledged'); }, close: async () => {} }; await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store: wrapped, client, task: 'task' }), boundaryError); const persisted = await store.readJob(workspace, job.id); assert.equal(stops, 1); assert.equal(persisted.status, stopSucceeds ? 'failed' : 'running'); if (!stopSucceeds) { assert.match(persisted.lastCancelError, /stop not acknowledged/); await assert.rejects(store.reserveJob({ workspace, ...reservation, ownerTurnId: 'later' }), { code: 'WRITABLE_JOB_EXISTS' }); } @@ -281,7 +356,7 @@ test('accepted send with boundary persistence failure requires remote stop proof test('wait and read ambiguity retain the running guard when remote stop is unacknowledged', async () => { for (const stage of ['wait', 'read']) { const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); let stops = 0; - const client = { createSession: async () => ({ session: { sessionId: `zs-${stage}-failure` }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), setPermissionHandler: () => {}, send: async () => ({ inputId: `input-${stage}`, stateRevision: 3 }), waitForCompletion: async () => { if (stage === 'wait') throw new Error('wait protocol ambiguous'); }, readSession: async () => { throw new Error('read protocol ambiguous'); }, stopSession: async () => { stops += 1; throw new Error(`${stage} stop refused`); }, close: async () => {} }; + const client = { createSession: async () => ({ session: { sessionId: `zs-${stage}-failure` }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), setPermissionHandler: () => {}, subscribe: silentSubscribe, send: async () => ({ inputId: `input-${stage}`, stateRevision: 3 }), waitForCompletion: async () => { if (stage === 'wait') throw new Error('wait protocol ambiguous'); }, readSession: async () => { throw new Error('read protocol ambiguous'); }, stopSession: async () => { stops += 1; throw new Error(`${stage} stop refused`); }, close: async () => {} }; await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task' }), new RegExp(`${stage} protocol ambiguous`)); const persisted = await store.readJob(workspace, job.id); assert.equal(stops, 1, stage); assert.equal(persisted.status, 'running', stage); assert.match(persisted.lastCancelError, new RegExp(`${stage} stop refused`)); } @@ -289,7 +364,7 @@ test('wait and read ambiguity retain the running guard when remote stop is unack test('artifact directory fsync failure fails the job before success', async () => { const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); - const client = { createSession: async () => ({ session: { sessionId: 'zs' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), setPermissionHandler: () => {}, send: async () => ({ inputId: 'input-artifact-failure', stateRevision: 1 }), waitForCompletion: async () => ({}), readSession: async () => ({ messages: [{ info: { role: 'assistant', messageId: 'assistant-artifact', parentMessageId: 'input-artifact-failure' }, parts: [{ type: 'text', text: 'done' }] }] }), close: async () => {} }; + const client = { createSession: async () => ({ session: { sessionId: 'zs' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), setPermissionHandler: () => {}, subscribe: silentSubscribe, send: async () => ({ inputId: 'input-artifact-failure', stateRevision: 1 }), waitForCompletion: async () => ({}), readSession: async () => ({ messages: [{ info: { role: 'assistant', messageId: 'assistant-artifact', parentMessageId: 'input-artifact-failure' }, parts: [{ type: 'text', text: 'done' }] }] }), close: async () => {} }; const error = Object.assign(new Error('disk sync failed'), { code: 'EIO' }); await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', syncDirectory: async () => { throw error; } }), { code: 'ARTIFACT_WRITE_FAILED' }); assert.equal((await store.readJob(workspace, job.id)).status, 'failed'); From e718b48d3a5fbc0930d69b42dd1e10c8bf9b1cd3 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 02:31:23 +0800 Subject: [PATCH 10/27] fix: drain progress before terminal transition --- scripts/lib/review.mjs | 20 +++++++++++++++----- tests/job-control.test.mjs | 6 +++++- 2 files changed, 20 insertions(+), 6 deletions(-) diff --git a/scripts/lib/review.mjs b/scripts/lib/review.mjs index 7e5938ef..647a52ca 100644 --- a/scripts/lib/review.mjs +++ b/scripts/lib/review.mjs @@ -36,12 +36,23 @@ export function decidePermission(request, permissionSnapshot, command) { export async function executeJob(input) { const { job, client, workspace, dataRoot } = input; let running = job; let sessionId; let sendAttempted = false; let remoteTerminalProven = false; + /** @type {any} */ let reporter; let unsubscribe = () => {}; /** @type {unknown} */ let primaryError; /** @type {any} */ let output; + let progressCleaned = false; + const cleanupProgress = async () => { + if (progressCleaned) return []; + progressCleaned = true; + const errors = []; + try { unsubscribe(); } catch (error) { errors.push(error); } + try { reporter?.close(); } catch (error) { errors.push(error); } + try { await reporter?.flush(); } catch (error) { errors.push(error); } + return errors; + }; try { let prompt; if (job.command === 'review' || job.command === 'adversarial-review') { @@ -83,7 +94,9 @@ export async function executeJob(input) { remoteTerminalProven = true; const result = extractFinalResult(finalSnapshot, job.command, turnBoundary); const resultArtifact = await writeArtifact({ dataRoot, workspace, directory: 'results', jobId: job.id, contents: result }, { syncDirectory: input.syncDirectory }); - await reporter.flush(); + const terminalCleanupErrors = await cleanupProgress(); + if (terminalCleanupErrors.length === 1) throw terminalCleanupErrors[0]; + if (terminalCleanupErrors.length > 1) throw new AggregateError(terminalCleanupErrors, 'ZCode progress cleanup failed.'); const succeeded = await input.store.transitionJob(workspace, job.id, ['running'], 'succeeded', { resultArtifact, finishedAt: new Date().toISOString(), exitCode: 0 }); output = { job: succeeded, result }; } catch (error) { @@ -102,10 +115,7 @@ export async function executeJob(input) { } } // Cleanup order is part of the progress lifecycle contract. - const cleanupErrors = []; - try { unsubscribe(); } catch (error) { cleanupErrors.push(error); } - try { reporter?.close(); } catch (error) { cleanupErrors.push(error); } - try { await reporter?.flush(); } catch (error) { cleanupErrors.push(error); } + const cleanupErrors = await cleanupProgress(); try { await client.close(); } catch (error) { cleanupErrors.push(error); } const distinctCleanupErrors = cleanupErrors.filter((error) => error !== primaryError); if (primaryError) { diff --git a/tests/job-control.test.mjs b/tests/job-control.test.mjs index 00976429..9aae4b0f 100644 --- a/tests/job-control.test.mjs +++ b/tests/job-control.test.mjs @@ -284,7 +284,10 @@ test('executor reports only same-session progress and drains persistence before return store.updateJobProgress(workspaceArg, jobId, event); }, transitionJob: async (/** @type {string} */ workspaceArg, /** @type {string} */ jobId, /** @type {string[]} */ expected, /** @type {string} */ next, /** @type {Record} */ patch = {}) => { - if (next === 'succeeded') order.push('transition:succeeded'); + if (next === 'succeeded') { + order.push('transition:succeeded'); + if (handler) handler(notification('zs-progress', 'api_retry', 5)); + } return store.transitionJob(workspaceArg, jobId, expected, next, patch); }, }; @@ -322,6 +325,7 @@ test('executor reports only same-session progress and drains persistence before ]); assert.deepEqual(persisted.map((event) => event.message), lines.map((line) => line.slice(8, -1))); assert.ok(order.lastIndexOf('persist:finalizing') < order.indexOf('transition:succeeded')); + assert.equal(order.includes('persist:waiting'), false); assert.equal(unsubscribes, 1); assert.equal(cleared, 1); assert.equal(closes, 1); assert.equal(handler, null); }); From 698966488c97e1ce022c910db40254f6c2bdd88c Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 02:42:44 +0800 Subject: [PATCH 11/27] fix: preserve progress lifecycle error semantics --- scripts/lib/progress.mjs | 17 +++++++++++------ scripts/lib/review.mjs | 25 +++++++++++++++++++------ scripts/zcode-companion.mjs | 3 ++- tests/job-control.test.mjs | 36 ++++++++++++++++++++++++++++++++++-- tests/progress.test.mjs | 26 ++++++++++++++++++++++++++ 5 files changed, 92 insertions(+), 15 deletions(-) diff --git a/scripts/lib/progress.mjs b/scripts/lib/progress.mjs index b8726450..41fa2275 100644 --- a/scripts/lib/progress.mjs +++ b/scripts/lib/progress.mjs @@ -38,9 +38,10 @@ export function createProgressReporter({ /** @type {string|null} */ let previousKey = null; let persistence = Promise.resolve(); - let hasPersistenceError = false; + let hasReporterError = false; /** @type {unknown} */ - let persistenceError; + let reporterError; + const recordError = (/** @type {unknown} */ error) => { if (!hasReporterError) { hasReporterError = true; reporterError = error; } }; /** @type {any} */ let timer = null; if (typeof write === 'function') { @@ -50,7 +51,8 @@ export function createProgressReporter({ const elapsedMs = Date.parse(currentTime) - Date.parse(lastActivityAt); if (elapsedMs < PROGRESS_HEARTBEAT_MS) return; const seconds = Math.floor(elapsedMs / 1_000); - write(`[zcode] Still waiting for ZCode; last activity ${seconds}s ago.\n`); + try { write(`[zcode] Still waiting for ZCode; last activity ${seconds}s ago.\n`); } + catch (error) { recordError(error); } }, PROGRESS_HEARTBEAT_MS); } timer?.unref?.(); @@ -64,14 +66,17 @@ export function createProgressReporter({ const key = `${event.phase}\u0000${event.message}`; if (key === previousKey) return null; previousKey = key; - if (typeof write === 'function') write(`[zcode] ${event.message}\n`); + if (typeof write === 'function') { + try { write(`[zcode] ${event.message}\n`); } + catch (error) { recordError(error); } + } if (typeof persist === 'function') persistence = persistence.then(async () => { try { await persist(event); } - catch (error) { if (!hasPersistenceError) { hasPersistenceError = true; persistenceError = error; } } + catch (error) { recordError(error); } }); return event; }, - async flush() { await persistence; if (hasPersistenceError) throw persistenceError; }, + async flush() { await persistence; if (hasReporterError) throw reporterError; }, close() { if (timer === null) return; clearIntervalFn(timer); diff --git a/scripts/lib/review.mjs b/scripts/lib/review.mjs index 647a52ca..56fa3420 100644 --- a/scripts/lib/review.mjs +++ b/scripts/lib/review.mjs @@ -95,8 +95,7 @@ export async function executeJob(input) { const result = extractFinalResult(finalSnapshot, job.command, turnBoundary); const resultArtifact = await writeArtifact({ dataRoot, workspace, directory: 'results', jobId: job.id, contents: result }, { syncDirectory: input.syncDirectory }); const terminalCleanupErrors = await cleanupProgress(); - if (terminalCleanupErrors.length === 1) throw terminalCleanupErrors[0]; - if (terminalCleanupErrors.length > 1) throw new AggregateError(terminalCleanupErrors, 'ZCode progress cleanup failed.'); + if (terminalCleanupErrors.length) throw progressFailure(terminalCleanupErrors); const succeeded = await input.store.transitionJob(workspace, job.id, ['running'], 'succeeded', { resultArtifact, finishedAt: new Date().toISOString(), exitCode: 0 }); output = { job: succeeded, result }; } catch (error) { @@ -116,14 +115,13 @@ export async function executeJob(input) { } // Cleanup order is part of the progress lifecycle contract. const cleanupErrors = await cleanupProgress(); - try { await client.close(); } catch (error) { cleanupErrors.push(error); } + await client.close().catch(() => {}); const distinctCleanupErrors = cleanupErrors.filter((error) => error !== primaryError); if (primaryError) { - if (distinctCleanupErrors.length) throw new AggregateError([primaryError, ...distinctCleanupErrors], 'ZCode execution and progress cleanup failed.'); + attachCleanupFailure(primaryError, distinctCleanupErrors); throw primaryError; } - if (cleanupErrors.length === 1) throw cleanupErrors[0]; - if (cleanupErrors.length > 1) throw new AggregateError(cleanupErrors, 'ZCode progress cleanup failed.'); + if (cleanupErrors.length) throw progressFailure(cleanupErrors); return output; } @@ -243,6 +241,21 @@ function invalidReviewResult(cause) { return new PluginError('REVIEW_RESULT_INVA function validResponse(response) { return response && typeof response === 'object' && ['allow', 'deny'].includes(response.decision); } /** @param {unknown} error */ function safeError(error) { return { message: error instanceof Error ? error.message.slice(0, 2048) : 'Unknown execution failure' }; } +/** @param {unknown[]} errors */ +function progressFailure(errors) { + const first = errors[0]; + if (first instanceof PluginError) { attachCleanupFailure(first, errors.slice(1)); return first; } + return new PluginError('ZCODE_PROGRESS_FAILED', 'ZCode progress reporting failed.', { category: 'runtime', remedy: 'Retry the delegated task and inspect the progress output channel.', cause: first, details: { additionalFailureCount: Math.max(0, errors.length - 1) } }); +} +/** @param {unknown} primary @param {unknown[]} cleanupErrors */ +function attachCleanupFailure(primary, cleanupErrors) { + if (!cleanupErrors.length || !(primary instanceof Error)) return; + const failure = progressFailure(cleanupErrors); + try { + if (!('cause' in primary)) Object.defineProperty(primary, 'cause', { value: failure, configurable: true }); + else if (primary instanceof PluginError) primary.details = { ...primary.details, cleanupFailure: safeError(failure) }; + } catch { /* Cleanup diagnostics must never replace the primary failure. */ } +} /** @param {unknown} error */ function errorCode(error) { return error && typeof error === 'object' && 'code' in error && typeof error.code === 'string' ? error.code : undefined; } /** @param {any} left @param {any} right */ diff --git a/scripts/zcode-companion.mjs b/scripts/zcode-companion.mjs index 052ebf74..a9bbb293 100644 --- a/scripts/zcode-companion.mjs +++ b/scripts/zcode-companion.mjs @@ -176,7 +176,8 @@ async function executeReserved(context) { client = await createManagedZCodeClient({ dataRoot, workspace: cwd, launch, ownerId, env }); const modelConfig = await readWorkspaceModelConfig({ dataRoot, workspace: cwd }); const modelRequest = spec.model ?? modelConfig.defaultModel; const preResolvedModel = modelRequest && (modelRequest.includes('/') || Object.hasOwn(modelConfig.models, modelRequest)) ? resolveModel(modelRequest, modelConfig.models, []) : undefined; - return await executeJob({ job, workspace: cwd, dataRoot, store, client, scope: spec.scope, base: spec.base, focus: spec.focus, task: spec.task, model: preResolvedModel, modelRequest: preResolvedModel ? undefined : modelRequest, modelAliases: modelConfig.models, effort: spec.effort, resumeSessionId: spec.resumeSessionId, childPid: context.childPid, workerLeaseId: context.workerLeaseId, onBoundaryPersisted: context.onBoundaryPersisted, progressWriter: context.progressWriter, progressDependencies: context.progressDependencies, signal: context.signal, onBeforeResume: async () => { await validateResumeCandidate(store, cwd, job.ownerSessionId, spec); await reconcileBrokerOwnership({ dataRoot, workspace: cwd, ownerId, ownedSessionIds: [spec.resumeSessionId] }); } }); + const executionClient = client; client = undefined; + return await executeJob({ job, workspace: cwd, dataRoot, store, client: executionClient, scope: spec.scope, base: spec.base, focus: spec.focus, task: spec.task, model: preResolvedModel, modelRequest: preResolvedModel ? undefined : modelRequest, modelAliases: modelConfig.models, effort: spec.effort, resumeSessionId: spec.resumeSessionId, childPid: context.childPid, workerLeaseId: context.workerLeaseId, onBoundaryPersisted: context.onBoundaryPersisted, progressWriter: context.progressWriter, progressDependencies: context.progressDependencies, signal: context.signal, onBeforeResume: async () => { await validateResumeCandidate(store, cwd, job.ownerSessionId, spec); await reconcileBrokerOwnership({ dataRoot, workspace: cwd, ownerId, ownedSessionIds: [spec.resumeSessionId] }); } }); } catch (error) { await client?.close().catch(() => {}); const current = await store.readJob(cwd, job.id).catch(() => null); diff --git a/tests/job-control.test.mjs b/tests/job-control.test.mjs index 9aae4b0f..9b8aa035 100644 --- a/tests/job-control.test.mjs +++ b/tests/job-control.test.mjs @@ -297,7 +297,7 @@ test('executor reports only same-session progress and drains persistence before createSession: async () => ({ session: { sessionId: 'zs-progress' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [] }), setPermissionHandler: () => {}, subscribe: (/** @type {(message:any)=>void} */ subscriber) => { handler = subscriber; return () => { unsubscribes += 1; handler = null; }; }, - send: async () => ({ inputId: 'input-progress', stateRevision: 1 }), + send: async () => { emit(notification('zs-progress', 'tool_call_result', 1)); return { inputId: 'input-progress', stateRevision: 1 }; }, waitForCompletion: async () => { emit(notification('zs-sibling', 'tool_call_started', 2)); emit(notification('zs-progress', 'model_streaming', 2)); @@ -305,7 +305,7 @@ test('executor reports only same-session progress and drains persistence before emit(notification('zs-progress', 'prompt_completed', 4)); }, readSession: async () => ({ messages: [{ info: { role: 'assistant', messageId: 'assistant-progress', parentMessageId: 'input-progress' }, parts: [{ type: 'text', text: 'done' }] }] }), - close: async () => { closes += 1; }, + close: async () => { closes += 1; throw new Error('close refused after success'); }, }; const result = await executeJob({ job, workspace, dataRoot: join(root, 'data'), store: wrapped, client, task: 'task', @@ -319,6 +319,7 @@ test('executor reports only same-session progress and drains persistence before assert.equal(result.job.status, 'succeeded'); assert.equal(typeof intervalCallback, 'function'); assert.deepEqual(lines, [ '[zcode] ZCode started the delegated turn.\n', + '[zcode] ZCode completed a tool call.\n', '[zcode] ZCode is generating a response.\n', '[zcode] ZCode started a tool call.\n', '[zcode] ZCode completed the delegated turn.\n', @@ -326,9 +327,40 @@ test('executor reports only same-session progress and drains persistence before assert.deepEqual(persisted.map((event) => event.message), lines.map((line) => line.slice(8, -1))); assert.ok(order.lastIndexOf('persist:finalizing') < order.indexOf('transition:succeeded')); assert.equal(order.includes('persist:waiting'), false); + assert.equal((await store.readJob(workspace, job.id)).status, 'succeeded'); assert.equal(unsubscribes, 1); assert.equal(cleared, 1); assert.equal(closes, 1); assert.equal(handler, null); }); +test('writer failure still persists progress and fails with a stable progress error', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + /** @type {any[]} */ + const persisted = []; + const wrapped = { ...store, updateJobProgress: async (/** @type {string} */ workspaceArg, /** @type {string} */ jobId, /** @type {any} */ event) => { persisted.push(event); return store.updateJobProgress(workspaceArg, jobId, event); } }; + const client = { + createSession: async () => ({ session: { sessionId: 'zs-writer-failure' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), + setPermissionHandler: () => {}, subscribe: silentSubscribe, + send: async () => ({ inputId: 'input-writer-failure', stateRevision: 1 }), waitForCompletion: async () => {}, + readSession: async () => ({ messages: [{ info: { role: 'assistant', messageId: 'assistant-writer-failure', parentMessageId: 'input-writer-failure' }, parts: [{ type: 'text', text: 'done' }] }] }), close: async () => {}, + }; + await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store: wrapped, client, task: 'task', progressWriter: () => { throw new Error('stderr closed'); } }), (error) => error instanceof PluginError && error.code === 'ZCODE_PROGRESS_FAILED'); + assert.ok(persisted.some((event) => event.message === 'ZCode started the delegated turn.')); + assert.equal((await store.readJob(workspace, job.id)).status, 'failed'); +}); + +test('cleanup failures preserve the primary PluginError envelope and close once', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + const primary = new PluginError('PRIMARY_STABLE', 'primary failure', { category: 'protocol', remedy: 'keep this remedy' }); let closes = 0; + const client = { + createSession: async () => ({ session: { sessionId: 'zs-primary-failure' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), + setPermissionHandler: () => {}, subscribe: silentSubscribe, send: async () => ({ inputId: 'input-primary-failure', stateRevision: 1 }), + waitForCompletion: async () => { throw primary; }, stopSession: async () => {}, close: async () => { closes += 1; throw new Error('close is advisory'); }, + }; + const caught = await executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', progressWriter: () => { throw new Error('writer cleanup failed'); } }).catch((error) => error); + assert.equal(caught, primary); + assert.deepEqual((await import('../scripts/lib/render.mjs')).errorEnvelope(caught), { error: { code: 'PRIMARY_STABLE', category: 'protocol', message: 'primary failure', remedy: 'keep this remedy', details: {} } }); + assert.equal(closes, 1); +}); + test('executor failure still unsubscribes, stops heartbeat, and closes the client', async () => { const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); let handler = null; let unsubscribes = 0; let cleared = 0; let closes = 0; diff --git a/tests/progress.test.mjs b/tests/progress.test.mjs index 840afdc1..1ec357d3 100644 --- a/tests/progress.test.mjs +++ b/tests/progress.test.mjs @@ -236,6 +236,32 @@ test('persistence failures stay handled, do not poison later work, and surface f } }); +test('writer failures do not interrupt observation or persistence and surface after drain', async () => { + const writerError = new Error('writer failed'); + const persisted = []; + const unhandled = []; + const onUnhandled = (error) => unhandled.push(error); + process.on('unhandledRejection', onUnhandled); + const reporter = progressModule.createProgressReporter({ + sessionId: 'session-a', + write: () => { throw writerError; }, + persist: async (event) => persisted.push(event), + now: () => observedAt, + setInterval: () => ({ unref() {} }), + clearInterval: () => {}, + }); + try { + assert.doesNotThrow(() => reporter.observe(notification('tool_call_started'))); + await assert.rejects(reporter.flush(), (error) => error === writerError); + assert.deepEqual(persisted, [{ phase: 'running', message: 'ZCode started a tool call.', observedAt }]); + await new Promise((resolve) => setImmediate(resolve)); + assert.deepEqual(unhandled, []); + } finally { + process.off('unhandledRejection', onUnhandled); + reporter.close(); + } +}); + test('does not create a heartbeat interval without a writer', () => { let intervalCalls = 0; const reporter = progressModule.createProgressReporter({ From 78d73f7f98310e207e01d24eff7f5687bd5f7700 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 02:59:21 +0800 Subject: [PATCH 12/27] fix: cancel foreground zcode jobs on interrupt --- scripts/lib/job-control.mjs | 12 +++- scripts/lib/progress.mjs | 20 +++++++ scripts/lib/review.mjs | 15 ++++- scripts/lib/signals.mjs | 32 +++++++++++ scripts/zcode-companion.mjs | 47 ++++++++++++---- tests/integration/companion.test.mjs | 60 ++++++++++++++++++++ tests/job-control.test.mjs | 82 ++++++++++++++++++++++++++++ tests/signals.test.mjs | 59 ++++++++++++++++++++ 8 files changed, 313 insertions(+), 14 deletions(-) create mode 100644 scripts/lib/signals.mjs create mode 100644 tests/signals.test.mjs diff --git a/scripts/lib/job-control.mjs b/scripts/lib/job-control.mjs index fdc809f9..f64d579b 100644 --- a/scripts/lib/job-control.mjs +++ b/scripts/lib/job-control.mjs @@ -123,7 +123,7 @@ async function performCancellation(input, attempts, election) { if (!cancelling.zcodeSessionId || !input.options.stopSession) throw new Error('No live ZCode session stop handler is available.'); await input.options.stopSession(cancelling.zcodeSessionId); } catch (error) { - const message = error instanceof Error ? error.message : 'ZCode stop failed'; + const message = boundedCancelMessage(error instanceof Error ? error.message : 'ZCode stop failed'); await input.options.store.transitionJob(input.workspace, job.id, ['cancelling'], 'running', { lastCancelError: message }); await attempts.update(job.id, input.ownerSessionId, attempt.attemptId, 'failed-pending-release', message); await input.options.afterRollbackBeforeSettle?.(); @@ -167,3 +167,13 @@ function eligibleImplicit(job, eligibility) { function finalizeError(jobId, cause) { return new PluginError('JOB_CANCEL_FINALIZE_FAILED', `ZCode stopped, but job ${jobId} could not be finalized as cancelled.`, { category: 'storage', remedy: 'Retry cancellation to reconcile and finalize the cancelling job.', cause }); } /** @param {string} jobId @param {string} message @param {unknown} [cause] */ function cancelError(jobId, message, cause) { return new PluginError('JOB_CANCEL_FAILED', `Could not cancel job ${jobId}: ${message}`, { category: 'runtime', remedy: 'The job remains running; retry cancellation or inspect the ZCode session.', ...(cause ? { cause } : {}) }); } +/** @param {string} message */ +function boundedCancelMessage(message) { + let result = ''; let bytes = 0; + for (const character of message) { + const characterBytes = Buffer.byteLength(character); + if (bytes + characterBytes > 2_048) break; + result += character; bytes += characterBytes; + } + return result || 'ZCode stop failed'; +} diff --git a/scripts/lib/progress.mjs b/scripts/lib/progress.mjs index 41fa2275..71f3e881 100644 --- a/scripts/lib/progress.mjs +++ b/scripts/lib/progress.mjs @@ -3,6 +3,26 @@ export const MAX_PROGRESS_PREVIEW_ENTRIES = 4; export const MAX_PROGRESS_MESSAGE_BYTES = 256; export const PROGRESS_HEARTBEAT_MS = 20_000; +/** @template T @param {Promise} completion @param {AbortSignal|undefined} signal @returns {Promise} */ +export async function waitForCompletionOrAbort(completion, signal) { + const completionPromise = Promise.resolve(completion); + // The completion RPC remains in flight after interruption. Keep its later + // rejection observed even after the abort side wins the race. + completionPromise.catch(() => {}); + if (!signal) return completionPromise; + signal.throwIfAborted(); + /** @type {()=>void} */ + let removeAbortListener = () => {}; + const interrupted = new Promise((resolve, reject) => { + const onAbort = () => reject(signal.reason); + signal.addEventListener('abort', onAbort, { once: true }); + removeAbortListener = () => signal.removeEventListener('abort', onAbort); + }); + interrupted.catch(() => {}); + try { return await Promise.race([completionPromise, interrupted]); } + finally { removeAbortListener(); } +} + const KNOWN_PROGRESS = new Map([ ['prompt_started', ['starting', 'ZCode started the delegated turn.']], ['model_streaming', ['running', 'ZCode is generating a response.']], diff --git a/scripts/lib/review.mjs b/scripts/lib/review.mjs index 56fa3420..3bc45ae0 100644 --- a/scripts/lib/review.mjs +++ b/scripts/lib/review.mjs @@ -7,7 +7,8 @@ import { PluginError } from './errors.mjs'; import { resolveModel } from './args.mjs'; import { ensurePrivateDirectory, withFileLock } from './fs.mjs'; import { collectGitFacts } from './git.mjs'; -import { createProgressReporter } from './progress.mjs'; +import { createJobController } from './job-control.mjs'; +import { createProgressReporter, waitForCompletionOrAbort } from './progress.mjs'; import { buildPrompt } from './prompts.mjs'; import { loadReviewOutputSchema, validateJsonSchema } from './review-schema.mjs'; import { resolveWorkspaceStorage } from './workspace.mjs'; @@ -61,8 +62,10 @@ export async function executeJob(input) { } else prompt = await buildPrompt({ command: 'rescue', task: input.task }); const promptArtifact = await writeArtifact({ dataRoot, workspace, directory: 'prompts', jobId: job.id, contents: prompt }, { syncDirectory: input.syncDirectory }); let snapshot; + input.signal?.throwIfAborted(); if (input.resumeSessionId) { await input.onBeforeResume?.(job); + input.signal?.throwIfAborted(); snapshot = await client.resumeSession(input.resumeSessionId); } else snapshot = await client.createSession({ workspace, ...(input.model ? { model: input.model } : {}) }); sessionId = snapshot.session.sessionId; @@ -85,11 +88,12 @@ export async function executeJob(input) { ...(selectedModel ? { model: selectedModel } : {}), ...(input.effort ? { effort: input.effort } : {}), }); reporter.observe({ method: 'state.updated', params: { scope: 'session', sessionId, reason: 'prompt_started' } }); + input.signal?.throwIfAborted(); const beforeMessageIds = [...snapshotMessageIds(snapshot)]; sendAttempted = true; const sent = await client.send(sessionId, prompt); running = await input.store.transitionJob(workspace, job.id, ['running'], 'running', { inputId: sent.inputId, startRevision: sent.stateRevision, beforeMessageIds }); await input.onBoundaryPersisted?.(running); const turnBoundary = { beforeMessageIds: new Set(beforeMessageIds), ...sent }; - await client.waitForCompletion(sessionId); + await waitForCompletionOrAbort(client.waitForCompletion(sessionId), input.signal); const finalSnapshot = await client.readSession(sessionId); remoteTerminalProven = true; const result = extractFinalResult(finalSnapshot, job.command, turnBoundary); @@ -101,7 +105,10 @@ export async function executeJob(input) { } catch (error) { primaryError = error; const current = await input.store.readJob(workspace, job.id).catch(() => running); - if (current && !['failed', 'succeeded', 'cancelled', 'cancelling'].includes(current.status)) { + if (isInterruption(error) && current && !['failed', 'succeeded', 'cancelled'].includes(current.status)) { + const cancellation = createJobController({ store: input.store, dataRoot, stopSession: (id) => client.stopSession(id) }); + await cancellation.cancel(workspace, job.id, job.ownerSessionId).catch(() => {}); + } else if (current && !['failed', 'succeeded', 'cancelled', 'cancelling'].includes(current.status)) { let canFail = true; if (current.status === 'running' && sendAttempted && sessionId && !remoteTerminalProven) { try { await client.stopSession(sessionId); } @@ -241,6 +248,8 @@ function invalidReviewResult(cause) { return new PluginError('REVIEW_RESULT_INVA function validResponse(response) { return response && typeof response === 'object' && ['allow', 'deny'].includes(response.decision); } /** @param {unknown} error */ function safeError(error) { return { message: error instanceof Error ? error.message.slice(0, 2048) : 'Unknown execution failure' }; } +/** @param {unknown} error */ +function isInterruption(error) { return error instanceof PluginError && error.code === 'JOB_INTERRUPTED'; } /** @param {unknown[]} errors */ function progressFailure(errors) { const first = errors[0]; diff --git a/scripts/lib/signals.mjs b/scripts/lib/signals.mjs new file mode 100644 index 00000000..c2528b57 --- /dev/null +++ b/scripts/lib/signals.mjs @@ -0,0 +1,32 @@ +import process from 'node:process'; + +import { PluginError } from './errors.mjs'; + +const SIGNAL_EXIT_CODES = Object.freeze({ SIGINT: 130, SIGTERM: 143 }); + +/** + * @param {{process?:{on:(event:string,listener:()=>void)=>unknown,removeListener:(event:string,listener:()=>void)=>unknown,exitCode?:string|number|null},foreground?:boolean}} [options] + */ +export function createForegroundSignalController(options = {}) { + const processLike = options.process ?? process; + const controller = new AbortController(); + let cleaned = false; + const handlers = Object.fromEntries(Object.entries(SIGNAL_EXIT_CODES).map(([signal, exitCode]) => [signal, () => { + if (controller.signal.aborted) return; + processLike.exitCode = exitCode; + controller.abort(new PluginError('JOB_INTERRUPTED', `Foreground ZCode job interrupted by ${signal}.`, { + category: 'interruption', + remedy: 'Retry the command when you are ready.', + details: { signal, exitCode }, + })); + }])); + if (options.foreground !== false) for (const [signal, handler] of Object.entries(handlers)) processLike.on(signal, handler); + return { + signal: controller.signal, + cleanup() { + if (cleaned) return; + cleaned = true; + if (options.foreground !== false) for (const [signal, handler] of Object.entries(handlers)) processLike.removeListener(signal, handler); + }, + }; +} diff --git a/scripts/zcode-companion.mjs b/scripts/zcode-companion.mjs index a9bbb293..8972b60c 100644 --- a/scripts/zcode-companion.mjs +++ b/scripts/zcode-companion.mjs @@ -12,7 +12,7 @@ import { runSetup } from './lib/codex-config.mjs'; import { PluginError } from './lib/errors.mjs'; import { atomicWriteJson, readJsonFile } from './lib/fs.mjs'; import { createIdentityStore } from './lib/identity.mjs'; -import { createJobController, ownerIdForSession } from './lib/job-control.mjs'; +import { createJobController, ownerIdForSession, withJobCancellationLock } from './lib/job-control.mjs'; import { resolvePluginDataRoot } from './lib/plugin-data.mjs'; import { discoverZCode } from './lib/zcode-discovery.mjs'; import { createManagedZCodeClient } from './lib/zcode-client.mjs'; @@ -21,6 +21,7 @@ import { createInvocationStore, parseRecordedInvocation, requiresExecutionChoice import { executeJob, readResultArtifact } from './lib/review.mjs'; import { reconcileOwnedJobs, withWorkerLease } from './lib/recovery.mjs'; import { errorEnvelope, renderOutput } from './lib/render.mjs'; +import { createForegroundSignalController } from './lib/signals.mjs'; import { createStateStore } from './lib/state.mjs'; import { resolveWorkspaceStorage } from './lib/workspace.mjs'; import { readWorkspaceModelConfig, summarizeWorkspaceModelConfig } from './lib/workspace-config.mjs'; @@ -36,9 +37,10 @@ export async function runCompanion(argv, runtime = {}) { const parsed = parseArgs(argv); const dataRoot = resolvePluginDataRoot({ env, pluginRoot: activePluginRoot }); if (parsed.command === 'setup') return runSetup({ pluginRoot: activePluginRoot, dataRoot, cwd, reviewGate: parsed.options.reviewGate, env, codex: codexAppServerOptions(env, cwd), dependencies: runtime.dependencies }); const identity = createIdentityStore({ dataRoot }); const store = createStateStore({ dataRoot }); - if (parsed.command === 'run-reserved-job') return runReserved({ parsed, cwd, env, dataRoot, identity, store, authorization: requireAuthorization(runtime.authorization, ['executionCapability', 'jobId']), startupAck: runtime.startupAck, dependencies: runtime.dependencies }); + if (parsed.command === 'run-reserved-job') return runReserved({ parsed, cwd, env, dataRoot, identity, store, authorization: requireAuthorization(runtime.authorization, ['executionCapability', 'jobId']), startupAck: runtime.startupAck, dependencies: runtime.dependencies, signal: runtime.signal }); const caller = runtime.caller ?? await identity.consumeCallerContext(requireAuthorization(runtime.authorization, ['callerContext']).callerContext, { workspace: cwd }); const reconcile = () => reconcileOwnedJobs({ store, dataRoot, workspace: cwd, ownerSessionId: caller.sessionId, createClient: async (job, ownerId) => { + runtime.signal?.throwIfAborted(); const launch = await discoverLaunch(env); return (runtime.dependencies?.createManagedZCodeClient ?? createManagedZCodeClient)({ dataRoot, workspace: cwd, launch, ownerId, env, ...managedWireOptionsForJob(job) }); } }); @@ -59,7 +61,7 @@ export async function runCompanion(argv, runtime = {}) { if (parsed.command === 'cancel') { const selected = await controller.selectOwned(cwd, caller.sessionId, parsed.positionals[0], 'cancel'); if (!['running', 'cancelling'].includes(selected.status)) return { job: await controller.cancel(cwd, selected.id, caller.sessionId) }; - const launch = await discoverLaunch(env); + runtime.signal?.throwIfAborted(); const launch = await discoverLaunch(env); const client = await createManagedZCodeClient({ dataRoot, workspace: cwd, launch, ownerId: ownerIdForSession(caller.sessionId), env, ...managedWireOptionsForJob(selected) }); const cancelling = createJobController({ store, dataRoot, stopSession: (sessionId) => client.stopSession(sessionId) }); try { return { job: await cancelling.cancel(cwd, selected.id, caller.sessionId) }; } @@ -102,7 +104,7 @@ async function startPublic(context) { const transferSource = parsed.command === 'transfer' ? resolveTransferSource(parsed.options, caller) : undefined; const job = await store.reserveJob({ workspace: cwd, ownerSessionId: caller.sessionId, ownerTurnId: caller.turnId, command: parsed.command, readOnly: parsed.command !== 'rescue', permissionSnapshot, ...(transferSource ? { codexThreadId: transferSource } : {}) }); if (parsed.command === 'transfer') { - return executeTransfer({ job, workspace: job.workspace, dataRoot, store, sourceThreadId: /** @type {string} */ (transferSource), resolveLaunch: () => discoverLaunch(context.env), + return executeTransfer({ job, workspace: job.workspace, dataRoot, store, sourceThreadId: /** @type {string} */ (transferSource), resolveLaunch: () => { context.signal?.throwIfAborted(); return discoverLaunch(context.env); }, readThread: () => (context.dependencies?.readCodexThread ?? readCodexThread)(transferSource, codexAppServerOptions(context.env, job.workspace)), createClient: (launch) => (context.dependencies?.createManagedZCodeClient ?? createManagedZCodeClient)({ dataRoot, workspace: job.workspace, launch, ownerId: ownerIdForSession(caller.sessionId), env: context.env, ...managedWireOptionsForJob(job) }), }); @@ -145,7 +147,7 @@ function codexAppServerOptions(env, cwd) { } /** @param {any} input */ -async function runReserved({ parsed, cwd, env, dataRoot, identity, store, authorization, startupAck, dependencies }) { +async function runReserved({ parsed, cwd, env, dataRoot, identity, store, authorization, startupAck, dependencies, signal }) { const jobId = parsed.positionals[0]; const job = await store.readJob(cwd, jobId); if (authorization.jobId !== jobId) throw authorizationInputError(); const record = await readJobSpec(dataRoot, cwd, jobId); @@ -155,7 +157,7 @@ async function runReserved({ parsed, cwd, env, dataRoot, identity, store, author const consumed = await identity.consumeExecutionCapability(authorization.executionCapability, { jobId, ownerSessionId: job.ownerSessionId, workspace: cwd, operation: 'run-reserved-job', specDigest: recomputed }); if (!sameJson(consumed.permissionSnapshot, job.permissionSnapshot)) throw new PluginError('EXECUTION_SNAPSHOT_MISMATCH', 'Execution capability permission snapshot does not match the reserved job.', { category: 'authorization', remedy: 'Issue a new capability from the exact reserved job.' }); if (job.status !== 'queued') throw new PluginError('RESERVED_JOB_NOT_QUEUED', `Reserved job ${jobId} is ${job.status}.`, { category: 'state', remedy: 'Generate a new execution capability only for a queued job.' }); - return executeWithWorkerLease({ parsed, cwd, env, dataRoot, identity, store, job, spec, caller: { sessionId: job.ownerSessionId }, dependencies, ...(startupAck ? { onBoundaryPersisted: async () => startupAck() } : {}) }); + return executeWithWorkerLease({ parsed, cwd, env, dataRoot, identity, store, job, spec, caller: { sessionId: job.ownerSessionId }, dependencies, signal, ...(startupAck ? { onBoundaryPersisted: async () => startupAck() } : {}) }); } /** @param {any} context */ @@ -172,6 +174,7 @@ async function executeReserved(context) { const { cwd, env, dataRoot, store, job, spec } = context; let client; try { + context.signal?.throwIfAborted(); const launch = await discoverLaunch(env, context.dependencies); const ownerId = ownerIdForSession(job.ownerSessionId); client = await createManagedZCodeClient({ dataRoot, workspace: cwd, launch, ownerId, env }); const modelConfig = await readWorkspaceModelConfig({ dataRoot, workspace: cwd }); const modelRequest = spec.model ?? modelConfig.defaultModel; @@ -181,7 +184,10 @@ async function executeReserved(context) { } catch (error) { await client?.close().catch(() => {}); const current = await store.readJob(cwd, job.id).catch(() => null); - if (current?.status === 'queued') { + if (isInterruption(error) && current?.status === 'queued') { + if (current.workerLeaseId === context.workerLeaseId) await cancelClaimedQueuedInterruption(context).catch(() => {}); + else await createJobController({ store, dataRoot }).cancel(cwd, job.id, job.ownerSessionId).catch(() => {}); + } else if (!isInterruption(error) && current?.status === 'queued') { await store.transitionJob(cwd, job.id, ['queued'], 'failed', { error: { message: error instanceof Error ? error.message.slice(0, 2048) : 'Execution failed' }, finishedAt: new Date().toISOString(), exitCode: 1 }).catch(() => {}); } throw error; @@ -207,6 +213,16 @@ async function readJobSpec(dataRoot, workspace, jobId) { } /** @param {unknown} left @param {unknown} right */ function sameJson(left, right) { return JSON.stringify(left) === JSON.stringify(right); } +/** @param {unknown} error */ +function isInterruption(error) { return error instanceof PluginError && error.code === 'JOB_INTERRUPTED'; } +/** @param {any} context */ +async function cancelClaimedQueuedInterruption(context) { + return withJobCancellationLock({ dataRoot: context.dataRoot, workspace: context.cwd, jobId: context.job.id }, async () => { + const current = await context.store.readJob(context.cwd, context.job.id); + if (current.status !== 'queued' || current.workerLeaseId !== context.workerLeaseId) return current; + return context.store.transitionJob(context.cwd, current.id, ['queued'], 'cancelled', { finishedAt: new Date().toISOString(), exitCode: null }); + }); +} /** @param {unknown} value @param {string[]} keys @returns {any} */ function requireAuthorization(value, keys) { @@ -322,17 +338,28 @@ async function failQueuedJob(store, workspace, jobId, error) { } async function main() { - let output; + let output; const entry = process.argv[2]; const setup = entry === 'setup'; const direct = entry === 'invoke' || entry === 'invoke-choice'; const worker = process.env.ZCODE_BACKGROUND_WORKER === '1'; + const signalController = !setup && !worker ? createForegroundSignalController({ process }) : null; try { - const entry = process.argv[2]; const setup = entry === 'setup'; const direct = entry === 'invoke' || entry === 'invoke-choice'; const worker = process.env.ZCODE_BACKGROUND_WORKER === '1'; const authorization = setup || direct ? undefined : await readInternalEnvelope(); + const authorization = setup || direct ? undefined : await readInternalEnvelope(); const foregroundProgress = worker ? {} : { progressWriter: (/** @type {string} */ line) => process.stderr.write(line), progressDependencies: { now: () => new Date().toISOString(), setInterval: globalThis.setInterval, clearInterval: globalThis.clearInterval }, + ...(signalController ? { signal: signalController.signal } : {}), }; output = direct ? await runDirectInvocation(process.argv.slice(2), foregroundProgress) : await runCompanion(process.argv.slice(2), { authorization, ...foregroundProgress, ...(worker ? { startupAck: acknowledgeBackgroundStartup } : {}) }); if (!setup && !direct && !worker) await writeInternalResponse(output); if (!worker) process.stdout.write(renderOutput(output)); if (output?.type === 'needs-choice') process.exitCode = 3; } - catch (error) { if (output?.type === 'background') await failBackgroundDelivery(output, error); const envelope = errorEnvelope(error); const entry = process.argv[2]; const protectedOutput = entry !== 'setup' && entry !== 'invoke' && entry !== 'invoke-choice' && process.env.ZCODE_BACKGROUND_WORKER !== '1'; if (protectedOutput) try { await writeInternalResponse(envelope); } catch { /* no trusted response channel */ } if (process.env.ZCODE_BACKGROUND_WORKER !== '1') process.stdout.write(renderOutput(envelope, { json: true })); if (process.env.ZCODE_DEBUG === '1') process.stderr.write(`${error instanceof Error ? error.stack : String(error)}\n`); process.exitCode = error instanceof PluginError && error.category === 'validation' ? 2 : 1; } + catch (error) { + if (error instanceof PluginError && error.code === 'JOB_INTERRUPTED') { + const signal = typeof error.details.signal === 'string' ? error.details.signal : 'signal'; + process.stderr.write(`Interrupted by ${signal}.\n`); + if (typeof error.details.exitCode === 'number') process.exitCode = error.details.exitCode; + return; + } + if (output?.type === 'background') await failBackgroundDelivery(output, error); const envelope = errorEnvelope(error); const protectedOutput = entry !== 'setup' && entry !== 'invoke' && entry !== 'invoke-choice' && process.env.ZCODE_BACKGROUND_WORKER !== '1'; if (protectedOutput) try { await writeInternalResponse(envelope); } catch { /* no trusted response channel */ } if (process.env.ZCODE_BACKGROUND_WORKER !== '1') process.stdout.write(renderOutput(envelope, { json: true })); if (process.env.ZCODE_DEBUG === '1') process.stderr.write(`${error instanceof Error ? error.stack : String(error)}\n`); process.exitCode = error instanceof PluginError && error.category === 'validation' ? 2 : 1; + } + finally { signalController?.cleanup(); } } if (process.argv[1] && sameEntryPath(fileURLToPath(import.meta.url), resolve(process.argv[1]))) await main(); diff --git a/tests/integration/companion.test.mjs b/tests/integration/companion.test.mjs index 9fd5b97d..115f3b73 100644 --- a/tests/integration/companion.test.mjs +++ b/tests/integration/companion.test.mjs @@ -7,6 +7,7 @@ import { fileURLToPath } from 'node:url'; import test from 'node:test'; import { createIdentityStore } from '../../scripts/lib/identity.mjs'; +import { PluginError } from '../../scripts/lib/errors.mjs'; import { atomicWriteJson } from '../../scripts/lib/fs.mjs'; import { ownerIdForSession } from '../../scripts/lib/job-control.mjs'; import { createStateStore } from '../../scripts/lib/state.mjs'; @@ -14,6 +15,7 @@ import { TRANSFER_WIRE_LIMITS } from '../../scripts/lib/transfer.mjs'; import { createManagedZCodeClient } from '../../scripts/lib/zcode-client.mjs'; import { resolveWorkspaceStorage } from '../../scripts/lib/workspace.mjs'; import { renderOutput } from '../../scripts/lib/render.mjs'; +import { runCompanion } from '../../scripts/zcode-companion.mjs'; const root = fileURLToPath(new URL('../..', import.meta.url)); const cli = join(root, 'scripts', 'zcode-companion.mjs'); @@ -55,11 +57,29 @@ async function companion(context, args, extraEnv = {}, authorization = { callerC return { ...result, json: result.internal ? JSON.parse(result.internal) : null }; } +/** @param {()=>Promise} predicate @param {string} message */ +async function waitFor(predicate, message) { + const deadline = Date.now() + 5_000; + while (Date.now() < deadline) { + if (await predicate()) return; + await new Promise((resolve) => setTimeout(resolve, 10)); + } + throw new Error(message); +} + test('module import has no CLI side effects', async () => { const result = await run(process.execPath, ['--input-type=module', '--eval', `await import(${JSON.stringify(new URL('../../scripts/zcode-companion.mjs', import.meta.url).href)}); process.stdout.write('imported')`]); assert.deepEqual({ code: result.code, stdout: result.stdout, stderr: result.stderr }, { code: 0, stdout: 'imported', stderr: '' }); }); +test('an already-aborted foreground invocation cancels its reservation before launcher discovery', async () => { + const context = await fixture(); const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'before discovery'); controller.abort(interruption); let discoveries = 0; + await assert.rejects(runCompanion(['rescue', '--fresh', 'task'], { cwd: context.workspace, env: context.env, caller: { sessionId: 'codex-session', turnId: 'turn-1', permissionMode: 'workspace-write' }, signal: controller.signal, dependencies: { discoverLaunch: async () => { discoveries += 1; throw new Error('must not discover'); } } }), (error) => error === interruption); + assert.equal(discoveries, 0); + const jobs = await createStateStore({ dataRoot: context.dataRoot }).listJobs(context.workspace); + assert.equal(jobs.length, 1); assert.equal(jobs[0].status, 'cancelled'); +}); + test('real CLI runs foreground review/adversarial/rescue and persists private artifacts', async () => { const context = await fixture(); for (const args of [ @@ -112,6 +132,32 @@ test('foreground rescue streams safe progress to stderr and durably exposes it t ]); }); +test('foreground SIGINT stops the accepted ZCode session, exits 130, and leaves no running job', async (t) => { + const context = await fixture(); const record = join(context.directory, 'interrupt.jsonl'); await writeFile(record, ''); + const child = spawn(process.execPath, [cli, 'rescue', '--fresh', 'interrupt me'], { + cwd: context.workspace, + env: { ...context.env, FAKE_ZCODE_RECORD: record, FAKE_ZCODE_SUPPRESS_FIRST_COMPLETION: '1' }, + stdio: ['ignore', 'pipe', 'pipe', 'pipe', 'pipe'], + shell: false, + }); + let stdout = ''; let stderr = ''; let internal = ''; let exited = false; + child.stdout?.on('data', (chunk) => { stdout += chunk; }); child.stderr?.on('data', (chunk) => { stderr += chunk; }); child.stdio[4]?.on('data', (chunk) => { internal += chunk; }); + child.stdio[3]?.on('error', consumePipeError); child.stdio[4]?.on('error', consumePipeError); + /** @type {import('node:stream').Writable} */ (child.stdio[3]).end(`${JSON.stringify({ callerContext: context.caller })}\n`); + t.after(() => { if (!exited) child.kill('SIGKILL'); }); + + const recorded = async () => (await readFile(record, 'utf8')).trim().split('\n').filter(Boolean).map((line) => JSON.parse(line)); + await waitFor(async () => (await recorded()).some((frame) => frame.method === 'session/send'), 'foreground send was not accepted'); + child.kill('SIGINT'); + const exit = await new Promise((resolve, reject) => { child.once('error', reject); child.once('exit', (code, signal) => { exited = true; resolve({ code, signal }); }); }); + assert.deepEqual(exit, { code: 130, signal: null }); + const calls = await recorded(); const sentSession = calls.find((frame) => frame.method === 'session/send').params.sessionId; + assert.equal(calls.filter((frame) => frame.method === 'session/stop' && frame.params.sessionId === sentSession).length, 1); + const jobs = await createStateStore({ dataRoot: context.dataRoot }).listJobs(context.workspace); + assert.equal(jobs.length, 1); assert.equal(jobs[0].status, 'cancelled'); assert.ok(jobs[0].finishedAt); assert.equal(jobs[0].resultArtifact, undefined); + assert.equal(stdout, ''); assert.equal(internal, ''); assert.match(stderr, /Interrupted by SIGINT\./); assert.doesNotMatch(stderr, /JOB_INTERRUPTED|"error"/); +}); + test('background reservation exposes one private invocation, which is single-use', async () => { const context = await fixture(); const reserved = await companion(context, ['review', '--background']); @@ -127,6 +173,20 @@ test('background reservation exposes one private invocation, which is single-use assert.notEqual(replay.code, 0); assert.equal(replay.json.error.code, 'EXECUTION_CAPABILITY_CONSUMED'); }); +test('a non-worker reserved-job invocation receives the foreground abort signal', async () => { + const context = await fixture(); const reserved = await companion(context, ['review', '--background']); + const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'reserved foreground'); controller.abort(interruption); let discoveries = 0; + await assert.rejects(runCompanion(reserved.json.privateInvocation, { + cwd: context.workspace, + env: context.env, + authorization: { executionCapability: reserved.json.executionCapability, jobId: reserved.json.job.id }, + signal: controller.signal, + dependencies: { discoverLaunch: async () => { discoveries += 1; throw new Error('must not discover'); } }, + }), (error) => error === interruption); + assert.equal(discoveries, 0); + assert.equal((await createStateStore({ dataRoot: context.dataRoot }).readJob(context.workspace, reserved.json.job.id)).status, 'cancelled'); +}); + test('status/list/result and queued cancellation enforce owned job semantics', async () => { const context = await fixture(); const reserved = await companion(context, ['rescue', '--background', '--fresh', 'task']); diff --git a/tests/job-control.test.mjs b/tests/job-control.test.mjs index 9b8aa035..8576d863 100644 --- a/tests/job-control.test.mjs +++ b/tests/job-control.test.mjs @@ -251,6 +251,88 @@ test('executor failure cannot steal cancellation terminal ownership', async () = assert.equal((await store.readJob(workspace, job.id)).status, 'cancelled'); }); +test('foreground interruption after an accepted send stops exactly once and durably cancels without a result', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + const controller = new AbortController(); let stops = 0; let waitStarted = () => {}; + const waiting = new Promise((resolve) => { waitStarted = () => resolve(undefined); }); + const completion = new Promise(() => {}); + const interruption = new PluginError('JOB_INTERRUPTED', 'interrupted', { category: 'interruption', remedy: 'retry' }); + const client = { + createSession: async () => ({ session: { sessionId: 'zs-interrupted' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [] }), + setPermissionHandler: () => {}, subscribe: silentSubscribe, + send: async () => ({ inputId: 'input-interrupted', stateRevision: 4 }), + waitForCompletion: () => { waitStarted(); return completion; }, + stopSession: async (/** @type {string} */ sessionId) => { assert.equal(sessionId, 'zs-interrupted'); stops += 1; }, close: async () => {}, + }; + const execution = executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', signal: controller.signal }); + await waiting; controller.abort(interruption); + await assert.rejects(execution, (error) => error === interruption); + const persisted = await store.readJob(workspace, job.id); + assert.equal(stops, 1); assert.equal(persisted.status, 'cancelled'); assert.ok(persisted.finishedAt); + assert.equal(persisted.resultArtifact, undefined); +}); + +test('foreground interruption keeps running on stop failure, bounds the error, and rethrows the interruption', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + const controller = new AbortController(); let waitStarted = () => {}; + const waiting = new Promise((resolve) => { waitStarted = () => resolve(undefined); }); + const interruption = new PluginError('JOB_INTERRUPTED', 'interrupted', { category: 'interruption', remedy: 'retry' }); + const client = { + createSession: async () => ({ session: { sessionId: 'zs-stop-refused' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [] }), + setPermissionHandler: () => {}, subscribe: silentSubscribe, + send: async () => ({ inputId: 'input-stop-refused', stateRevision: 5 }), waitForCompletion: () => { waitStarted(); return new Promise(() => {}); }, + stopSession: async () => { throw new Error(`refused-${'x'.repeat(4_000)}`); }, close: async () => {}, + }; + const execution = executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', signal: controller.signal }); + await waiting; controller.abort(interruption); + await assert.rejects(execution, (error) => error === interruption); + const persisted = await store.readJob(workspace, job.id); + assert.equal(persisted.status, 'running'); assert.match(persisted.lastCancelError, /^refused-/); + assert.ok(Buffer.byteLength(persisted.lastCancelError) <= 2_048); assert.equal(persisted.finishedAt, undefined); +}); + +test('completion that wins the signal race remains successful', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + const controller = new AbortController(); let stops = 0; + const client = { + createSession: async () => ({ session: { sessionId: 'zs-completion-wins' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [] }), + setPermissionHandler: () => {}, subscribe: silentSubscribe, + send: async () => ({ inputId: 'input-completion-wins', stateRevision: 6 }), waitForCompletion: async () => {}, + readSession: async () => { controller.abort(new PluginError('JOB_INTERRUPTED', 'late')); return { messages: [{ info: { role: 'assistant', messageId: 'assistant-completion-wins', parentMessageId: 'input-completion-wins' }, parts: [{ type: 'text', text: 'done' }] }] }; }, + stopSession: async () => { stops += 1; }, close: async () => {}, + }; + const result = await executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', signal: controller.signal }); + assert.equal(result.job.status, 'succeeded'); assert.equal(stops, 0); + assert.equal((await store.readJob(workspace, job.id)).status, 'succeeded'); +}); + +test('an interruption before session creation is observed at the safe boundary and cancels the queued job', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'early'); controller.abort(interruption); let creates = 0; + const client = { createSession: async () => { creates += 1; }, close: async () => {} }; + await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', signal: controller.signal }), (error) => error === interruption); + assert.equal(creates, 0); assert.equal((await store.readJob(workspace, job.id)).status, 'cancelled'); +}); + +test('interruptions are observed immediately before resume and send RPC boundaries', async () => { + { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'before resume'); let resumes = 0; + const client = { resumeSession: async () => { resumes += 1; }, close: async () => {} }; + await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', resumeSessionId: 'zs-resume', signal: controller.signal, onBeforeResume: async () => controller.abort(interruption) }), (error) => error === interruption); + assert.equal(resumes, 0); assert.equal((await store.readJob(workspace, job.id)).status, 'cancelled'); + } + { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'before send'); let sends = 0; let stops = 0; + const wrapped = { ...store, transitionJob: async (/** @type {string} */ workspaceArg, /** @type {string} */ jobId, /** @type {string[]} */ expected, /** @type {string} */ next, /** @type {Record} */ patch = {}) => { const result = await store.transitionJob(workspaceArg, jobId, expected, next, patch); if (next === 'running' && patch.zcodeSessionId) controller.abort(interruption); return result; } }; + const client = { + createSession: async () => ({ session: { sessionId: 'zs-before-send' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [] }), + setPermissionHandler: () => {}, subscribe: silentSubscribe, send: async () => { sends += 1; }, stopSession: async (/** @type {string} */ sessionId) => { assert.equal(sessionId, 'zs-before-send'); stops += 1; }, close: async () => {}, + }; + await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store: wrapped, client, task: 'task', signal: controller.signal }), (error) => error === interruption); + assert.equal(sends, 0); assert.equal(stops, 1); assert.equal((await store.readJob(workspace, job.id)).status, 'cancelled'); + } +}); + test('executor persists the accepted turn boundary and worker identity before startup acknowledgement', async () => { const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); /** @type {any} */ diff --git a/tests/signals.test.mjs b/tests/signals.test.mjs new file mode 100644 index 00000000..51013846 --- /dev/null +++ b/tests/signals.test.mjs @@ -0,0 +1,59 @@ +import assert from 'node:assert/strict'; +import { EventEmitter } from 'node:events'; +import test from 'node:test'; + +import { PluginError } from '../scripts/lib/errors.mjs'; +import { waitForCompletionOrAbort } from '../scripts/lib/progress.mjs'; +import { createForegroundSignalController } from '../scripts/lib/signals.mjs'; + +test('foreground signal controller aborts once with signal-specific interruption exit codes and cleans up', () => { + /** @type {Array<[string,number]>} */ + const cases = [['SIGINT', 130], ['SIGTERM', 143]]; + for (const [name, exitCode] of cases) { + const processLike = /** @type {EventEmitter & {exitCode?:number}} */ (new EventEmitter()); + const controller = createForegroundSignalController({ process: processLike }); + assert.equal(processLike.listenerCount('SIGINT'), 1); + assert.equal(processLike.listenerCount('SIGTERM'), 1); + + processLike.emit(name); + const reason = controller.signal.reason; + assert.ok(reason instanceof PluginError); + assert.equal(reason.code, 'JOB_INTERRUPTED'); + assert.equal(reason.details.signal, name); + assert.equal(reason.details.exitCode, exitCode); + assert.equal(processLike.exitCode, exitCode); + + processLike.emit(name === 'SIGINT' ? 'SIGTERM' : 'SIGINT'); + assert.equal(controller.signal.reason, reason); + assert.equal(processLike.exitCode, exitCode); + controller.cleanup(); + controller.cleanup(); + assert.equal(processLike.listenerCount('SIGINT'), 0); + assert.equal(processLike.listenerCount('SIGTERM'), 0); + } +}); + +test('background signal controller installs no process handlers', () => { + const processLike = /** @type {EventEmitter & {exitCode?:number}} */ (new EventEmitter()); + const controller = createForegroundSignalController({ process: processLike, foreground: false }); + assert.equal(processLike.listenerCount('SIGINT'), 0); + assert.equal(processLike.listenerCount('SIGTERM'), 0); + assert.equal(controller.signal.aborted, false); + controller.cleanup(); +}); + +test('completion or abort returns the winner and handles a later losing rejection', async () => { + const completed = new AbortController(); + assert.equal(await waitForCompletionOrAbort(Promise.resolve('done'), completed.signal), 'done'); + completed.abort(new PluginError('JOB_INTERRUPTED', 'late')); + + const interrupted = new AbortController(); + let rejectCompletion = (/** @type {unknown} */ error) => { void error; }; + const completion = new Promise((resolve, reject) => { rejectCompletion = reject; }); + const raced = waitForCompletionOrAbort(completion, interrupted.signal); + const reason = new PluginError('JOB_INTERRUPTED', 'interrupted'); + interrupted.abort(reason); + await assert.rejects(raced, (error) => error === reason); + rejectCompletion(new Error('late completion failure')); + await new Promise((resolve) => setImmediate(resolve)); +}); From 48434e74432b4276da254a5f1fc20ebb87180d71 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 03:08:50 +0800 Subject: [PATCH 13/27] fix: preserve interrupt during authorization read --- scripts/zcode-companion.mjs | 3 ++- tests/fixtures/signal-handler-probe.cjs | 25 ++++++++++++++++++++++++ tests/integration/companion.test.mjs | 26 +++++++++++++++++++++++++ 3 files changed, 53 insertions(+), 1 deletion(-) create mode 100644 tests/fixtures/signal-handler-probe.cjs diff --git a/scripts/zcode-companion.mjs b/scripts/zcode-companion.mjs index 8972b60c..49c03870 100644 --- a/scripts/zcode-companion.mjs +++ b/scripts/zcode-companion.mjs @@ -18,6 +18,7 @@ import { discoverZCode } from './lib/zcode-discovery.mjs'; import { createManagedZCodeClient } from './lib/zcode-client.mjs'; import { acknowledgeBackgroundStartup, startBackgroundWorker } from './lib/background-worker.mjs'; import { createInvocationStore, parseRecordedInvocation, requiresExecutionChoice } from './lib/invocation.mjs'; +import { waitForCompletionOrAbort } from './lib/progress.mjs'; import { executeJob, readResultArtifact } from './lib/review.mjs'; import { reconcileOwnedJobs, withWorkerLease } from './lib/recovery.mjs'; import { errorEnvelope, renderOutput } from './lib/render.mjs'; @@ -341,7 +342,7 @@ async function main() { let output; const entry = process.argv[2]; const setup = entry === 'setup'; const direct = entry === 'invoke' || entry === 'invoke-choice'; const worker = process.env.ZCODE_BACKGROUND_WORKER === '1'; const signalController = !setup && !worker ? createForegroundSignalController({ process }) : null; try { - const authorization = setup || direct ? undefined : await readInternalEnvelope(); + const authorization = setup || direct ? undefined : await waitForCompletionOrAbort(readInternalEnvelope(), signalController?.signal); const foregroundProgress = worker ? {} : { progressWriter: (/** @type {string} */ line) => process.stderr.write(line), progressDependencies: { now: () => new Date().toISOString(), setInterval: globalThis.setInterval, clearInterval: globalThis.clearInterval }, diff --git a/tests/fixtures/signal-handler-probe.cjs b/tests/fixtures/signal-handler-probe.cjs new file mode 100644 index 00000000..af994b58 --- /dev/null +++ b/tests/fixtures/signal-handler-probe.cjs @@ -0,0 +1,25 @@ +'use strict'; + +const { writeFileSync } = require('node:fs'); +const process = require('node:process'); + +const marker = process.env.ZCODE_SIGNAL_HANDLER_PROBE; +if (marker) { + const originalOn = process.on; + const originalRemoveListener = process.removeListener; + const wrappers = new WeakMap(); + process.on = function on(event, listener) { + if (event !== 'SIGINT') return originalOn.call(this, event, listener); + const wrapped = function wrapped(...args) { + writeFileSync(marker, 'handled'); + return Reflect.apply(listener, this, args); + }; + wrappers.set(listener, wrapped); + const result = originalOn.call(this, event, wrapped); + writeFileSync(marker, 'ready'); + return result; + }; + process.removeListener = function removeListener(event, listener) { + return originalRemoveListener.call(this, event, wrappers.get(listener) ?? listener); + }; +} diff --git a/tests/integration/companion.test.mjs b/tests/integration/companion.test.mjs index 115f3b73..04ab5c9d 100644 --- a/tests/integration/companion.test.mjs +++ b/tests/integration/companion.test.mjs @@ -21,6 +21,7 @@ const root = fileURLToPath(new URL('../..', import.meta.url)); const cli = join(root, 'scripts', 'zcode-companion.mjs'); const fake = join(root, 'tests', 'fixtures', 'fake-zcode-cli.mjs'); const fakeCodex = join(root, 'tests', 'fixtures', 'fake-codex-app-server.mjs'); +const signalHandlerProbe = join(root, 'tests', 'fixtures', 'signal-handler-probe.cjs'); async function fixture() { const directory = await mkdtemp(join(tmpdir(), 'zcode-companion-')); @@ -158,6 +159,31 @@ test('foreground SIGINT stops the accepted ZCode session, exits 130, and leaves assert.equal(stdout, ''); assert.equal(internal, ''); assert.match(stderr, /Interrupted by SIGINT\./); assert.doesNotMatch(stderr, /JOB_INTERRUPTED|"error"/); }); +test('foreground SIGINT wins while the protected authorization envelope is incomplete', async (t) => { + const context = await fixture(); const marker = join(context.directory, 'signal-handler.txt'); + const child = spawn(process.execPath, ['--require', signalHandlerProbe, cli, 'rescue', '--fresh', 'interrupt authorization'], { + cwd: context.workspace, + env: { ...context.env, ZCODE_SIGNAL_HANDLER_PROBE: marker }, + stdio: ['ignore', 'pipe', 'pipe', 'pipe', 'pipe'], + shell: false, + }); + let stdout = ''; let stderr = ''; let internal = ''; let exited = false; + child.stdout?.on('data', (chunk) => { stdout += chunk; }); child.stderr?.on('data', (chunk) => { stderr += chunk; }); child.stdio[4]?.on('data', (chunk) => { internal += chunk; }); + child.stdio[3]?.on('error', consumePipeError); child.stdio[4]?.on('error', consumePipeError); + t.after(() => { if (!exited) child.kill('SIGKILL'); }); + + await waitFor(async () => await readFile(marker, 'utf8').catch(() => '') === 'ready', 'foreground signal handler was not installed'); + /** @type {import('node:stream').Writable} */ (child.stdio[3]).write('{'); + child.kill('SIGINT'); + await waitFor(async () => await readFile(marker, 'utf8').catch(() => '') === 'handled', 'SIGINT did not enter the installed handler'); + /** @type {import('node:stream').Writable} */ (child.stdio[3]).end(); + const exit = await new Promise((resolve, reject) => { child.once('error', reject); child.once('exit', (code, signal) => { exited = true; resolve({ code, signal }); }); }); + + assert.deepEqual(exit, { code: 130, signal: null }); + assert.equal(stdout, ''); assert.equal(internal, ''); + assert.match(stderr, /Interrupted by SIGINT\./); assert.doesNotMatch(stderr, /INTERNAL_AUTHORIZATION_INVALID|"error"/); +}); + test('background reservation exposes one private invocation, which is single-use', async () => { const context = await fixture(); const reserved = await companion(context, ['review', '--background']); From c100645178bf68bd3b39f89587bbea1bdaf35a0b Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 03:14:33 +0800 Subject: [PATCH 14/27] fix: close authorization input on interrupt --- scripts/zcode-companion.mjs | 17 ++++++++++++----- tests/integration/companion.test.mjs | 6 ++++-- 2 files changed, 16 insertions(+), 7 deletions(-) diff --git a/scripts/zcode-companion.mjs b/scripts/zcode-companion.mjs index 49c03870..c41e76af 100644 --- a/scripts/zcode-companion.mjs +++ b/scripts/zcode-companion.mjs @@ -18,7 +18,6 @@ import { discoverZCode } from './lib/zcode-discovery.mjs'; import { createManagedZCodeClient } from './lib/zcode-client.mjs'; import { acknowledgeBackgroundStartup, startBackgroundWorker } from './lib/background-worker.mjs'; import { createInvocationStore, parseRecordedInvocation, requiresExecutionChoice } from './lib/invocation.mjs'; -import { waitForCompletionOrAbort } from './lib/progress.mjs'; import { executeJob, readResultArtifact } from './lib/review.mjs'; import { reconcileOwnedJobs, withWorkerLease } from './lib/recovery.mjs'; import { errorEnvelope, renderOutput } from './lib/render.mjs'; @@ -252,18 +251,26 @@ async function validateResumeCandidate(store, workspace, ownerSessionId, spec) { if (candidate.ownerSessionId !== ownerSessionId || candidate.command !== 'rescue' || candidate.zcodeSessionId !== spec.resumeSessionId || !['running', 'succeeded', 'failed'].includes(candidate.status)) throw new PluginError('RESUME_CANDIDATE_INVALID', 'The bound rescue candidate is no longer eligible.', { category: 'authorization', remedy: 'Reserve a fresh rescue job.' }); } -/** @param {number} [fd] @param {{maxBytes?:number,timeoutMs?:number}} [options] */ +/** @param {number} [fd] @param {{maxBytes?:number,timeoutMs?:number,signal?:AbortSignal}} [options] */ export function readInternalEnvelope(fd = 3, options = {}) { const maxBytes = options.maxBytes ?? 64 * 1024; const timeoutMs = options.timeoutMs ?? 5_000; if (!Number.isSafeInteger(fd) || fd < 3 || !Number.isSafeInteger(maxBytes) || maxBytes <= 0 || !Number.isSafeInteger(timeoutMs) || timeoutMs <= 0) throw authorizationInputError(); + options.signal?.throwIfAborted(); return new Promise((resolvePromise, reject) => { const stream = createReadStream('', { fd, autoClose: false }); let data = ''; let bytes = 0; let settled = false; - /** @param {()=>void} callback */ - const finish = (callback) => { if (settled) return; settled = true; clearTimeout(timer); stream.destroy(); callback(); }; + let removeAbortListener = () => {}; + /** @param {()=>void} callback @param {boolean} [closeDescriptor] */ + const finish = (callback, closeDescriptor = false) => { if (settled) return; settled = true; clearTimeout(timer); removeAbortListener(); stream.destroy(); if (closeDescriptor) try { closeFdSync(fd); } catch { /* abort cleanup must not replace the signal reason */ } callback(); }; const timer = setTimeout(() => finish(() => reject(authorizationInputError())), timeoutMs); stream.on('data', (chunk) => { bytes += chunk.length; if (bytes > maxBytes) finish(() => reject(authorizationInputError())); else data += chunk.toString('utf8'); }); stream.once('error', () => finish(() => reject(authorizationInputError()))); stream.once('end', () => finish(() => { try { resolvePromise(JSON.parse(data)); } catch { reject(authorizationInputError()); } })); + if (options.signal) { + const onAbort = () => finish(() => reject(options.signal?.reason), true); + options.signal.addEventListener('abort', onAbort, { once: true }); + removeAbortListener = () => options.signal?.removeEventListener('abort', onAbort); + if (options.signal.aborted) onAbort(); + } }); } /** @param {unknown} value @param {number} [fd] @param {{maxBytes?:number,timeoutMs?:number,write?:(fd:number,buffer:Buffer,offset:number,length:number,position:null,callback:(error:NodeJS.ErrnoException|null,bytesWritten:number)=>void)=>void|{cancel?:()=>void},close?:(fd:number,callback:(error?:NodeJS.ErrnoException|null)=>void)=>void}} [options] */ @@ -342,7 +349,7 @@ async function main() { let output; const entry = process.argv[2]; const setup = entry === 'setup'; const direct = entry === 'invoke' || entry === 'invoke-choice'; const worker = process.env.ZCODE_BACKGROUND_WORKER === '1'; const signalController = !setup && !worker ? createForegroundSignalController({ process }) : null; try { - const authorization = setup || direct ? undefined : await waitForCompletionOrAbort(readInternalEnvelope(), signalController?.signal); + const authorization = setup || direct ? undefined : await readInternalEnvelope(3, { signal: signalController?.signal }); const foregroundProgress = worker ? {} : { progressWriter: (/** @type {string} */ line) => process.stderr.write(line), progressDependencies: { now: () => new Date().toISOString(), setInterval: globalThis.setInterval, clearInterval: globalThis.clearInterval }, diff --git a/tests/integration/companion.test.mjs b/tests/integration/companion.test.mjs index 04ab5c9d..061f32b0 100644 --- a/tests/integration/companion.test.mjs +++ b/tests/integration/companion.test.mjs @@ -171,13 +171,15 @@ test('foreground SIGINT wins while the protected authorization envelope is incom child.stdout?.on('data', (chunk) => { stdout += chunk; }); child.stderr?.on('data', (chunk) => { stderr += chunk; }); child.stdio[4]?.on('data', (chunk) => { internal += chunk; }); child.stdio[3]?.on('error', consumePipeError); child.stdio[4]?.on('error', consumePipeError); t.after(() => { if (!exited) child.kill('SIGKILL'); }); + const exitPromise = new Promise((resolve, reject) => { child.once('error', reject); child.once('exit', (code, signal) => { exited = true; resolve({ code, signal }); }); }); await waitFor(async () => await readFile(marker, 'utf8').catch(() => '') === 'ready', 'foreground signal handler was not installed'); /** @type {import('node:stream').Writable} */ (child.stdio[3]).write('{'); child.kill('SIGINT'); await waitFor(async () => await readFile(marker, 'utf8').catch(() => '') === 'handled', 'SIGINT did not enter the installed handler'); - /** @type {import('node:stream').Writable} */ (child.stdio[3]).end(); - const exit = await new Promise((resolve, reject) => { child.once('error', reject); child.once('exit', (code, signal) => { exited = true; resolve({ code, signal }); }); }); + /** @type {NodeJS.Timeout|undefined} */ + let exitTimer; + const exit = await Promise.race([exitPromise, new Promise((resolve, reject) => { void resolve; exitTimer = setTimeout(() => { if (!exited) child.kill('SIGKILL'); reject(new Error('foreground process retained incomplete fd3 after SIGINT')); }, 1_000); })]).finally(() => clearTimeout(exitTimer)); assert.deepEqual(exit, { code: 130, signal: null }); assert.equal(stdout, ''); assert.equal(internal, ''); From 2853a24cad37ce9c1e8127ab6175c2f2da85d5c4 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 03:29:44 +0800 Subject: [PATCH 15/27] fix: cancel foreground transfers on interrupt --- scripts/lib/transfer.mjs | 89 ++++++++++++++++++++++------ scripts/zcode-companion.mjs | 2 +- tests/integration/companion.test.mjs | 22 +++++++ tests/transfer.test.mjs | 48 ++++++++++++++- 4 files changed, 141 insertions(+), 20 deletions(-) diff --git a/scripts/lib/transfer.mjs b/scripts/lib/transfer.mjs index a35537a0..63d47c9a 100644 --- a/scripts/lib/transfer.mjs +++ b/scripts/lib/transfer.mjs @@ -2,7 +2,7 @@ import { randomBytes } from 'node:crypto'; import { PluginError } from './errors.mjs'; import { hasControl, isSafeIdentifier } from './identifier.mjs'; -import { withJobCancellationLock } from './job-control.mjs'; +import { createJobController, withJobCancellationLock } from './job-control.mjs'; import { removeResultArtifact, writeResultArtifact } from './review.mjs'; import { withWorkerLease } from './recovery.mjs'; import { IMPORTED_HISTORY_SOURCE } from './zcode-client.mjs'; @@ -61,7 +61,7 @@ export function extractImportedHistory(thread, expectedThreadId) { } /** - * @param {{job:any,workspace:string,dataRoot:string,store:any,sourceThreadId:string,launch?:{command:string,args:string[]},resolveLaunch?:()=>Promise<{command:string,args:string[]}>,readThread:()=>Promise,createClient:(launch:{command:string,args:string[]})=>Promise,writeResult?:(input:any)=>Promise,removeResult?:(input:any)=>Promise}} input + * @param {{job:any,workspace:string,dataRoot:string,store:any,sourceThreadId:string,launch?:{command:string,args:string[]},resolveLaunch?:()=>Promise<{command:string,args:string[]}>,readThread:()=>Promise,createClient:(launch:{command:string,args:string[]})=>Promise,writeResult?:(input:any)=>Promise,removeResult?:(input:any)=>Promise,signal?:AbortSignal}} input */ export async function executeTransfer(input) { validateExecution(input); @@ -76,40 +76,93 @@ export async function executeTransfer(input) { async function executeClaimedTransfer(input) { const { job, workspace, dataRoot, store, sourceThreadId } = input; let client; let running = job; + /** @type {string|undefined} */ let sessionId; + /** @type {string|undefined} */ let resultArtifact; + /** @type {string|undefined} */ let result; + /** @type {string|undefined} */ let resumeCommand; try { validateExecution(input); running = await store.transitionJob(workspace, job.id, ['queued'], 'running', { startedAt: new Date().toISOString() }); - const importedHistory = extractImportedHistory(await input.readThread(), sourceThreadId); - const launch = input.launch ?? await /** @type {()=>Promise<{command:string,args:string[]}>} */ (input.resolveLaunch)(); + input.signal?.throwIfAborted(); + const importedHistory = extractImportedHistory(await boundedStep(input.readThread, input.signal), sourceThreadId); + input.signal?.throwIfAborted(); + const launch = input.launch ?? await boundedStep(/** @type {()=>Promise<{command:string,args:string[]}>} */ (input.resolveLaunch), input.signal); validateLaunch(launch); - client = await input.createClient(launch); - const snapshot = await client.createSession({ workspace, importedHistory }); - const sessionId = snapshot?.session?.sessionId; + client = await boundedStep(() => input.createClient(launch), input.signal); + input.signal?.throwIfAborted(); + let snapshot; + try { snapshot = await client.createSession({ workspace, importedHistory }); } + catch (error) { input.signal?.throwIfAborted(); throw error; } + sessionId = snapshot?.session?.sessionId; if (!isSafeIdentifier(sessionId)) throw new PluginError('ZCODE_OUTPUT_INVALID', 'ZCode returned an invalid imported session.', { category: 'protocol', remedy: 'Upgrade or restart ZCode and retry.' }); running = await store.transitionJob(workspace, job.id, ['running'], 'running', { zcodeSessionId: sessionId }); - const resumeCommand = buildResumeCommand(launch, sessionId); - const result = `Imported from Codex\nZCode session ID: ${sessionId}\nResume in ZCode: ${resumeCommand}\n`; - const resultArtifact = await (input.writeResult ?? writeResultArtifact)({ dataRoot, workspace, jobId: job.id, contents: result }); - const succeeded = await withJobCancellationLock({ dataRoot, workspace, jobId: job.id }, async () => { + input.signal?.throwIfAborted(); + resumeCommand = buildResumeCommand(launch, /** @type {string} */ (sessionId)); + result = `Imported from Codex\nZCode session ID: ${sessionId}\nResume in ZCode: ${resumeCommand}\n`; + input.signal?.throwIfAborted(); + try { resultArtifact = await (input.writeResult ?? writeResultArtifact)({ dataRoot, workspace, jobId: job.id, contents: result }); } + catch (error) { input.signal?.throwIfAborted(); throw error; } + input.signal?.throwIfAborted(); + const finalized = await withJobCancellationLock({ dataRoot, workspace, jobId: job.id }, async () => { const current = await store.readJob(workspace, job.id); - if (current.status === 'cancelled') return current; + if (current.status === 'succeeded') return { job: current }; + if (input.signal?.aborted) return { interrupted: true }; + if (current.status === 'cancelled') return { job: current }; if (current.status !== 'running') throw new PluginError('TRANSFER_FINALIZE_CONFLICT', `Transfer job ${job.id} cannot finalize from ${current.status}.`, { category: 'state', remedy: 'Inspect the job status and retry with a new Transfer.' }); - return store.transitionJob(workspace, job.id, ['running'], 'succeeded', { resultArtifact, finishedAt: new Date().toISOString(), exitCode: 0 }); + return { job: await store.transitionJob(workspace, job.id, ['running'], 'succeeded', { resultArtifact, finishedAt: new Date().toISOString(), exitCode: 0 }) }; }); + if (finalized.interrupted) throw input.signal?.reason; + const succeeded = finalized.job; if (succeeded.status === 'cancelled') { await (input.removeResult ?? removeResultArtifact)({ dataRoot, workspace, jobId: job.id, artifact: resultArtifact }); throw new PluginError('TRANSFER_CANCELLED', `Transfer job ${job.id} was cancelled.`, { category: 'state', remedy: 'Run Transfer again if the imported session is still needed.' }); } return { type: 'transfer', job: succeeded, result, zcodeSessionId: sessionId, resumeCommand }; - } catch (error) { - await withJobCancellationLock({ dataRoot, workspace, jobId: job.id }, async () => { - const current = await store?.readJob(workspace, job?.id).catch(() => running); - if (['queued', 'running'].includes(current?.status)) await store.transitionJob(workspace, job.id, [current.status], 'failed', { error: { message: error instanceof Error ? error.message.slice(0, 2048) : 'Transfer failed' }, finishedAt: new Date().toISOString(), exitCode: 1 }); - }).catch(() => {}); + } catch (caught) { + const error = input.signal?.aborted ? input.signal.reason : caught; + const current = await store?.readJob(workspace, job?.id).catch(() => running); + if (isInterruption(error)) { + if (current?.status === 'succeeded' && sessionId && resultArtifact && result && resumeCommand) return { type: 'transfer', job: current, result, zcodeSessionId: sessionId, resumeCommand }; + if (resultArtifact) await (input.removeResult ?? removeResultArtifact)({ dataRoot, workspace, jobId: job.id, artifact: resultArtifact }).catch(() => {}); + await cancelInterruptedTransfer({ ...input, job, client }).catch(() => {}); + } else { + await withJobCancellationLock({ dataRoot, workspace, jobId: job.id }, async () => { + const latest = await store?.readJob(workspace, job?.id).catch(() => running); + if (['queued', 'running'].includes(latest?.status)) await store.transitionJob(workspace, job.id, [latest.status], 'failed', { error: { message: error instanceof Error ? error.message.slice(0, 2048) : 'Transfer failed' }, finishedAt: new Date().toISOString(), exitCode: 1 }); + }).catch(() => {}); + } throw error; } finally { await client?.close().catch(() => {}); } } +/** @template T @param {()=>Promise} operation @param {AbortSignal|undefined} signal */ +async function boundedStep(operation, signal) { + signal?.throwIfAborted(); + try { const value = await operation(); signal?.throwIfAborted(); return value; } + catch (error) { signal?.throwIfAborted(); throw error; } +} + +/** @param {any} input */ +async function cancelInterruptedTransfer(input) { + const current = await input.store.readJob(input.workspace, input.job.id); + if (['succeeded', 'failed', 'cancelled'].includes(current.status)) return current; + if (current.zcodeSessionId && input.client) { + const controller = createJobController({ store: input.store, dataRoot: input.dataRoot, stopSession: (sessionId) => input.client.stopSession(sessionId) }); + return controller.cancel(input.workspace, current.id, current.ownerSessionId); + } + return withJobCancellationLock({ dataRoot: input.dataRoot, workspace: input.workspace, jobId: current.id }, async () => { + let latest = await input.store.readJob(input.workspace, current.id); + if (['succeeded', 'failed', 'cancelled'].includes(latest.status)) return latest; + if (latest.status === 'queued') return input.store.transitionJob(input.workspace, latest.id, ['queued'], 'cancelled', { finishedAt: new Date().toISOString(), exitCode: null }); + if (latest.status === 'running') latest = await input.store.transitionJob(input.workspace, latest.id, ['running'], 'cancelling', latest.lastCancelError ? { lastCancelError: null } : {}); + if (latest.status === 'cancelling') return input.store.transitionJob(input.workspace, latest.id, ['cancelling'], 'cancelled', { finishedAt: new Date().toISOString(), exitCode: null }); + return latest; + }); +} + +/** @param {unknown} error */ +function isInterruption(error) { return error instanceof PluginError && error.code === 'JOB_INTERRUPTED'; } + /** @param {{command:string,args:string[]}} launch @param {string} sessionId */ export function buildResumeCommand(launch, sessionId) { return [launch.command, ...launch.args, '--resume', sessionId].map(shellQuote).join(' '); } diff --git a/scripts/zcode-companion.mjs b/scripts/zcode-companion.mjs index c41e76af..59589a8a 100644 --- a/scripts/zcode-companion.mjs +++ b/scripts/zcode-companion.mjs @@ -104,7 +104,7 @@ async function startPublic(context) { const transferSource = parsed.command === 'transfer' ? resolveTransferSource(parsed.options, caller) : undefined; const job = await store.reserveJob({ workspace: cwd, ownerSessionId: caller.sessionId, ownerTurnId: caller.turnId, command: parsed.command, readOnly: parsed.command !== 'rescue', permissionSnapshot, ...(transferSource ? { codexThreadId: transferSource } : {}) }); if (parsed.command === 'transfer') { - return executeTransfer({ job, workspace: job.workspace, dataRoot, store, sourceThreadId: /** @type {string} */ (transferSource), resolveLaunch: () => { context.signal?.throwIfAborted(); return discoverLaunch(context.env); }, + return executeTransfer({ job, workspace: job.workspace, dataRoot, store, sourceThreadId: /** @type {string} */ (transferSource), signal: context.signal, resolveLaunch: () => discoverLaunch(context.env), readThread: () => (context.dependencies?.readCodexThread ?? readCodexThread)(transferSource, codexAppServerOptions(context.env, job.workspace)), createClient: (launch) => (context.dependencies?.createManagedZCodeClient ?? createManagedZCodeClient)({ dataRoot, workspace: job.workspace, launch, ownerId: ownerIdForSession(caller.sessionId), env: context.env, ...managedWireOptionsForJob(job) }), }); diff --git a/tests/integration/companion.test.mjs b/tests/integration/companion.test.mjs index 061f32b0..95001b9c 100644 --- a/tests/integration/companion.test.mjs +++ b/tests/integration/companion.test.mjs @@ -474,6 +474,28 @@ test('real CLI status wait stays alive until its timeout', async () => { assert.equal(waited.code, 1); assert.equal(waited.json.error.code, 'JOB_WAIT_TIMEOUT'); }); +test('foreground Transfer observes SIGTERM after its bounded create RPC and exits 143', async (t) => { + const context = await fixture(); const zcodeRecord = join(context.directory, 'transfer-interrupt.jsonl'); await writeFile(zcodeRecord, ''); + const sourceThread = { id: 'codex-session', ephemeral: false, turns: [{ startedAt: 1_725_000_000, items: [{ type: 'agentMessage', text: 'visible response' }] }] }; + const child = spawn(process.execPath, [cli, 'transfer'], { + cwd: context.workspace, + env: { ...context.env, CODEX_APP_SERVER_PATH: process.execPath, CODEX_APP_SERVER_ARGS_JSON: JSON.stringify([fakeCodex]), FAKE_CODEX_THREAD_JSON: JSON.stringify(sourceThread), FAKE_ZCODE_RECORD: zcodeRecord, FAKE_ZCODE_DELAY_MS: '200' }, + stdio: ['ignore', 'pipe', 'pipe', 'pipe', 'pipe'], shell: false, + }); + let stdout = ''; let stderr = ''; let internal = ''; let exited = false; + child.stdout?.on('data', (chunk) => { stdout += chunk; }); child.stderr?.on('data', (chunk) => { stderr += chunk; }); child.stdio[4]?.on('data', (chunk) => { internal += chunk; }); + child.stdio[3]?.on('error', consumePipeError); child.stdio[4]?.on('error', consumePipeError); /** @type {import('node:stream').Writable} */ (child.stdio[3]).end(`${JSON.stringify({ callerContext: context.caller })}\n`); + t.after(() => { if (!exited) child.kill('SIGKILL'); }); + const exitPromise = new Promise((resolve, reject) => { child.once('error', reject); child.once('exit', (code, signal) => { exited = true; resolve({ code, signal }); }); }); + const recorded = async () => (await readFile(zcodeRecord, 'utf8')).trim().split('\n').filter(Boolean).map((line) => JSON.parse(line)); + await waitFor(async () => (await recorded()).some((frame) => frame.method === 'session/create'), 'Transfer create RPC did not start'); child.kill('SIGTERM'); + const exit = await exitPromise; assert.deepEqual(exit, { code: 143, signal: null }); + const calls = await recorded(); const sessionId = calls.find((frame) => frame.method === 'session/stop')?.params?.sessionId; + assert.equal(typeof sessionId, 'string'); assert.equal(calls.filter((frame) => frame.method === 'session/stop' && frame.params.sessionId === sessionId).length, 1); + const jobs = await createStateStore({ dataRoot: context.dataRoot }).listJobs(context.workspace); assert.equal(jobs.length, 1); assert.equal(jobs[0].status, 'cancelled'); assert.equal(jobs[0].zcodeSessionId, sessionId); assert.equal(jobs[0].resultArtifact, undefined); + assert.equal(stdout, ''); assert.equal(internal, ''); assert.match(stderr, /Interrupted by SIGTERM\./); assert.doesNotMatch(stderr, /JOB_INTERRUPTED|"error"/); +}); + test('real Transfer imports current Codex history into a resumable ZCode session without leaking caller authorization', async () => { const context = await fixture(); const codexRecord = join(context.directory, 'codex.jsonl'); const zcodeRecord = join(context.directory, 'zcode.jsonl'); await writeFile(codexRecord, ''); await writeFile(zcodeRecord, ''); diff --git a/tests/transfer.test.mjs b/tests/transfer.test.mjs index 9b15d4b3..8b450fb1 100644 --- a/tests/transfer.test.mjs +++ b/tests/transfer.test.mjs @@ -4,6 +4,7 @@ import { tmpdir } from 'node:os'; import { join } from 'node:path'; import test from 'node:test'; +import { PluginError } from '../scripts/lib/errors.mjs'; import { createStateStore } from '../scripts/lib/state.mjs'; import { createJobController } from '../scripts/lib/job-control.mjs'; import { writeResultArtifact } from '../scripts/lib/review.mjs'; @@ -68,7 +69,10 @@ async function executionFixture(readThread = async () => thread()) { const directory = await mkdtemp(join(tmpdir(), 'zcode-transfer-')); const workspace = join(directory, 'repo'); const dataRoot = join(directory, 'data'); await mkdir(workspace); const store = createStateStore({ dataRoot }); const job = await store.reserveJob({ workspace, ownerSessionId: 'codex-owner', ownerTurnId: 'turn-owner', command: 'transfer', codexThreadId: source, readOnly: true, permissionSnapshot: { permissionMode: 'workspace-write' } }); - /** @type {any[]} */ const calls = []; const client = { createSession: async (/** @type {any} */ payload) => { calls.push(payload); return { session: { sessionId: 'zcode-session-1' } }; }, close: async () => { calls.push('close'); } }; + /** @type {any[]} */ + const calls = []; + /** @type {any} */ + const client = { createSession: async (/** @type {any} */ payload) => { calls.push(payload); return { session: { sessionId: 'zcode-session-1' } }; }, close: async () => { calls.push('close'); } }; return { calls, client, dataRoot, directory, job, readThread, store, workspace }; } @@ -150,3 +154,45 @@ test('artifact failure terminalization joins successful and failed cancellation assert.match((await transfer).error?.message ?? '', /disk refused/); const final = await context.store.readJob(context.workspace, context.job.id); assert.equal(final.status, stopSucceeds ? 'cancelled' : 'failed'); assert.equal(final.resultArtifact, undefined); } }); + +test('Transfer interruption during Codex read cancels without creating a remote session', async () => { + const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'read interrupted'); const context = await executionFixture(); let creates = 0; + await assert.rejects(executeTransfer({ ...context, sourceThreadId: source, launch: { command: 'zcode', args: [] }, signal: controller.signal, readThread: async () => { controller.abort(interruption); throw new Error('bounded read failed after interruption'); }, createClient: async () => { creates += 1; return context.client; } }), (error) => error === interruption); + const persisted = await context.store.readJob(context.workspace, context.job.id); + assert.equal(creates, 0); assert.equal(persisted.status, 'cancelled'); assert.ok(persisted.finishedAt); assert.equal(persisted.zcodeSessionId, undefined); assert.equal(persisted.resultArtifact, undefined); +}); + +test('Transfer interruption after create persists and stops the exact remote session once', async () => { + const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'create interrupted'); const context = await executionFixture(); let stops = 0; let closes = 0; + context.client.createSession = async () => { controller.abort(interruption); return { session: { sessionId: 'zcode-interrupted-create' } }; }; + context.client.stopSession = async (/** @type {string} */ sessionId) => { assert.equal(sessionId, 'zcode-interrupted-create'); stops += 1; }; + context.client.close = async () => { closes += 1; }; + await assert.rejects(executeTransfer({ ...context, sourceThreadId: source, launch: { command: 'zcode', args: [] }, signal: controller.signal, createClient: async () => context.client }), (error) => error === interruption); + const persisted = await context.store.readJob(context.workspace, context.job.id); + assert.equal(stops, 1); assert.equal(closes, 1); assert.equal(persisted.zcodeSessionId, 'zcode-interrupted-create'); assert.equal(persisted.status, 'cancelled'); assert.equal(persisted.resultArtifact, undefined); +}); + +test('Transfer interruption preserves running and the original interruption when remote stop fails', async () => { + const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'stop interrupted'); const context = await executionFixture(); let stops = 0; + context.client.createSession = async () => { controller.abort(interruption); return { session: { sessionId: 'zcode-stop-refused' } }; }; + context.client.stopSession = async () => { stops += 1; throw new Error(`stop-refused-${'x'.repeat(4_000)}`); }; + await assert.rejects(executeTransfer({ ...context, sourceThreadId: source, launch: { command: 'zcode', args: [] }, signal: controller.signal, createClient: async () => context.client }), (error) => error === interruption); + const persisted = await context.store.readJob(context.workspace, context.job.id); + assert.equal(stops, 1); assert.equal(persisted.status, 'running'); assert.equal(persisted.zcodeSessionId, 'zcode-stop-refused'); assert.match(persisted.lastCancelError, /^stop-refused-/); assert.ok(Buffer.byteLength(persisted.lastCancelError) <= 2_048); +}); + +test('Transfer interruption removes a written result while a completed finalization still wins', async () => { + { + const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'artifact interrupted'); const context = await executionFixture(); let artifact = ''; + context.client.stopSession = async () => {}; + await assert.rejects(executeTransfer({ ...context, sourceThreadId: source, launch: { command: 'zcode', args: [] }, signal: controller.signal, createClient: async () => context.client, writeResult: async (input) => { artifact = await writeResultArtifact(input); controller.abort(interruption); return artifact; } }), (error) => error === interruption); + const persisted = await context.store.readJob(context.workspace, context.job.id); assert.equal(persisted.status, 'cancelled'); assert.equal(persisted.resultArtifact, undefined); + const storage = await resolveWorkspaceStorage(context); await assert.rejects(readFile(join(storage.directory, artifact), 'utf8'), { code: 'ENOENT' }); + } + { + const controller = new AbortController(); const context = await executionFixture(); + const wrapped = { ...context.store, transitionJob: async (/** @type {string} */ workspace, /** @type {string} */ jobId, /** @type {string[]} */ expected, /** @type {string} */ next, /** @type {Record} */ patch = {}) => { const result = await context.store.transitionJob(workspace, jobId, expected, next, patch); if (next === 'succeeded') controller.abort(new PluginError('JOB_INTERRUPTED', 'late')); return result; } }; + const output = await executeTransfer({ ...context, store: wrapped, sourceThreadId: source, launch: { command: 'zcode', args: [] }, signal: controller.signal, createClient: async () => context.client }); + assert.equal(output.job.status, 'succeeded'); assert.ok(output.job.resultArtifact); assert.equal((await context.store.readJob(context.workspace, context.job.id)).status, 'succeeded'); + } +}); From 9366b3fd7022f34945f7cdb824459cf7f5e106a7 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 03:34:11 +0800 Subject: [PATCH 16/27] fix: retain transfer client ownership on interrupt --- scripts/lib/transfer.mjs | 4 +++- tests/transfer.test.mjs | 8 ++++++++ 2 files changed, 11 insertions(+), 1 deletion(-) diff --git a/scripts/lib/transfer.mjs b/scripts/lib/transfer.mjs index 63d47c9a..058e9dec 100644 --- a/scripts/lib/transfer.mjs +++ b/scripts/lib/transfer.mjs @@ -88,7 +88,9 @@ async function executeClaimedTransfer(input) { input.signal?.throwIfAborted(); const launch = input.launch ?? await boundedStep(/** @type {()=>Promise<{command:string,args:string[]}>} */ (input.resolveLaunch), input.signal); validateLaunch(launch); - client = await boundedStep(() => input.createClient(launch), input.signal); + input.signal?.throwIfAborted(); + try { client = await input.createClient(launch); } + catch (error) { input.signal?.throwIfAborted(); throw error; } input.signal?.throwIfAborted(); let snapshot; try { snapshot = await client.createSession({ workspace, importedHistory }); } diff --git a/tests/transfer.test.mjs b/tests/transfer.test.mjs index 8b450fb1..e3d5781c 100644 --- a/tests/transfer.test.mjs +++ b/tests/transfer.test.mjs @@ -162,6 +162,14 @@ test('Transfer interruption during Codex read cancels without creating a remote assert.equal(creates, 0); assert.equal(persisted.status, 'cancelled'); assert.ok(persisted.finishedAt); assert.equal(persisted.zcodeSessionId, undefined); assert.equal(persisted.resultArtifact, undefined); }); +test('Transfer owns and closes a client returned after createClient observes interruption', async () => { + const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'client interrupted'); const context = await executionFixture(); let closes = 0; let sessions = 0; + context.client.close = async () => { closes += 1; }; context.client.createSession = async () => { sessions += 1; return { session: { sessionId: 'must-not-create' } }; }; + await assert.rejects(executeTransfer({ ...context, sourceThreadId: source, launch: { command: 'zcode', args: [] }, signal: controller.signal, createClient: async () => { controller.abort(interruption); return context.client; } }), (error) => error === interruption); + const persisted = await context.store.readJob(context.workspace, context.job.id); + assert.equal(closes, 1); assert.equal(sessions, 0); assert.equal(persisted.status, 'cancelled'); assert.equal(persisted.zcodeSessionId, undefined); assert.equal(persisted.resultArtifact, undefined); +}); + test('Transfer interruption after create persists and stops the exact remote session once', async () => { const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'create interrupted'); const context = await executionFixture(); let stops = 0; let closes = 0; context.client.createSession = async () => { controller.abort(interruption); return { session: { sessionId: 'zcode-interrupted-create' } }; }; From 7e559b9034b5a842ef94fa3be8e9a1dd8e28dade Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 03:41:41 +0800 Subject: [PATCH 17/27] docs: explain zcode progress and interruption behavior --- CHANGELOG.md | 3 +++ README.md | 18 ++++++++++++++++ README.zh-CN.md | 18 ++++++++++++++++ tests/release-contracts.test.mjs | 35 ++++++++++++++++++++++++++++++++ 4 files changed, 74 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 20172d81..515ba228 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,9 @@ All notable changes follow Semantic Versioning. - Added marketplace-qualified plugin-data discovery and a restart-safe `$zcode:setup` bootstrap that configures the data directory as a writable root before persisting state. - Added ZCode CLI 0.16.1 compatibility for runtime-preference server requests with string IDs. - Improved `$zcode:setup` guidance when the ZCode CLI has no model provider configured, including the distinction between Desktop and CLI settings and API-key providers that do not require OAuth. +- Added foreground activity output, a 20-second heartbeat, and durable status previews for long-running ZCode work. +- Added bounded foreground `SIGINT` and `SIGTERM` handling: the plugin cancels before session creation or sends `session/stop` only to the exact persisted ZCode session, while background jobs continue until completion or explicit cancellation with `$zcode:cancel`. +- Kept the package version at `0.1.0` for these Unreleased behavior changes. ## 0.1.0 - 2026-08-06 diff --git a/README.md b/README.md index b4797926..25292f78 100644 --- a/README.md +++ b/README.md @@ -63,6 +63,24 @@ To verify configuration, rerun `$zcode:setup`, then run `$zcode:rescue --fresh - Every run is reserved as a durable, owner-scoped job. Installed plugin state lives beneath `$CODEX_HOME/plugins/data/zcode-/workspaces//` with private permissions; prompts, results, session IDs, and logs are never written into the repository or plugin cache. `$zcode:status`, `$zcode:result`, and `$zcode:cancel` work across later turns in the same Codex session, while sibling sessions cannot adopt a job. +Foreground runs stream ZCode activity to the current terminal. If no new activity arrives, they emit a 20-second heartbeat so a long model or tool call remains visibly alive. The same safe activity is stored on the job; `$zcode:status ` shows its phase, last activity time, and recent progress previews. For example: + +```text +$zcode:rescue --wait repair the failing tests +[zcode] ZCode started a tool call. +[zcode] Still waiting for ZCode; last activity 20s ago. + +$zcode:status +Status: running +Phase: running +Progress: + - ZCode started a tool call. +``` + +Background jobs have a separate lifecycle: ending the launching foreground command or Codex turn does not automatically cancel them. Use `$zcode:status ` to inspect one and `$zcode:cancel ` for explicit cancellation; ownership remains limited to the Codex session that reserved the job. + +On supported foreground paths, `SIGINT` and `SIGTERM` are observed at safe protocol boundaries. Before a ZCode session exists, interruption cancels the queued reservation. Once the exact persisted ZCode session ID exists, the plugin sends `session/stop` only for that session. A confirmed stop durably marks the job cancelled; if `session/stop` fails or times out, the job remains running with the cancellation error available through status so cancellation can be retried. This is intentionally a session-level boundary: the plugin does not claim to stop or kill arbitrary detached grandchildren created by ZCode or nested tools. + Transfer reads a persisted Codex thread through `codex app-server` and imports only ordered visible user/assistant text. It does not transfer hidden reasoning, tools, permissions, or ZCode job ownership. The optional Stop review gate runs a bounded foreground read-only review only after a changed, user-driven parent turn. Enable or disable it with `$zcode:setup`; a Codex restart may be required. Missing, outdated, or unauthenticated ZCode fails open with setup guidance. Once a review session starts, malformed, failed, or timed-out review output blocks conservatively. diff --git a/README.zh-CN.md b/README.zh-CN.md index 43c9e0b6..00c6f4cd 100644 --- a/README.zh-CN.md +++ b/README.zh-CN.md @@ -63,6 +63,24 @@ Setup 会把以下 schema 写入 `$CODEX_HOME/plugins/data/zcode-/w 每次运行都会先建立持久、带 owner 的 job。已安装插件的状态保存在 `$CODEX_HOME/plugins/data/zcode-/workspaces//`，使用私有权限；prompt、result、session ID 和日志都不会写进仓库或插件缓存。后续 turn 仍可使用 `$zcode:status`、`$zcode:result`、`$zcode:cancel`，但 sibling Codex session 无法接管任务。 +前台运行会把 ZCode 活动流式显示在当前终端。如果没有新活动，则每 20 秒输出一次心跳，让耗时较长的模型请求或工具调用仍然可见。同一份安全活动也会持久化到 job；`$zcode:status ` 会显示阶段、最后活动时间和近期进度预览。例如： + +```text +$zcode:rescue --wait 修复失败的测试 +[zcode] ZCode started a tool call. +[zcode] Still waiting for ZCode; last activity 20s ago. + +$zcode:status +Status: running +Phase: running +Progress: + - ZCode started a tool call. +``` + +后台任务有独立生命周期：启动它的前台命令或 Codex turn 结束时，后台任务不会自动取消。用 `$zcode:status ` 查看，用 `$zcode:cancel ` 显式取消；ownership 仍只属于预留该 job 的 Codex session。 + +在支持的前台路径上，插件会在安全协议边界处理 `SIGINT` 和 `SIGTERM`。ZCode session 尚未建立时，中断会取消排队中的预留；精确持久化的 ZCode session ID 一旦存在，插件只会对该 session 发送 `session/stop`。停止得到确认后，job 会持久标记为 cancelled；如果 `session/stop` 失败或超时，job 会保持 running，并通过 status 暴露取消错误，以便重试取消。这是刻意限定的 session 级边界：插件不声称停止或杀死 ZCode 或嵌套工具创建的任意 detached grandchildren。 + Transfer 通过 `codex app-server` 读取持久 Codex thread，只导入按顺序排列、用户可见的 user/assistant 文本；不转移隐藏推理、工具状态、permission 或 job ownership。 可选 Stop review gate 只会在用户驱动的父 turn 确实改变工作区后执行有界、前台、只读审查。用 `$zcode:setup` 开关，可能需要重启 Codex。ZCode 缺失、过旧或未认证时会附 setup 指引并 fail open；一旦审查会话已启动，畸形、失败或超时输出会保守阻止结束。 diff --git a/tests/release-contracts.test.mjs b/tests/release-contracts.test.mjs index 25549b6f..f41a7d94 100644 --- a/tests/release-contracts.test.mjs +++ b/tests/release-contracts.test.mjs @@ -31,6 +31,41 @@ test('English and Chinese release docs cover installation, operation, and qualif } }); +test('release docs explain progress reporting and supported interruption boundaries', () => { + const english = read('README.md'); + assert.match(english, /foreground runs? stream(?:s)? ZCode activity/i); + assert.match(english, /20-second heartbeat/i); + assert.match(english, /status.{0,100}progress previews/i); + assert.match(english, /background jobs?.{0,160}(?:do not|does not|won't) automatically cancel/i); + assert.match(english, /\$zcode:cancel/); + assert.match(english, /SIGINT.*SIGTERM/i); + assert.match(english, /session\/stop/); + assert.match(english, /exact persisted ZCode session/i); + assert.match(english, /does not claim to (?:stop|kill).{0,100}detached grandchildren/i); + + const chinese = read('README.zh-CN.md'); + assert.match(chinese, /前台运行.{0,80}ZCode 活动/); + assert.match(chinese, /20 秒.{0,20}心跳/); + assert.match(chinese, /status.{0,100}进度预览/i); + assert.match(chinese, /后台任务.{0,160}不会自动取消/); + assert.match(chinese, /\$zcode:cancel/); + assert.match(chinese, /SIGINT.*SIGTERM/i); + assert.match(chinese, /session\/stop/); + assert.match(chinese, /精确持久化的 ZCode session/); + assert.match(chinese, /不(?:声称|保证)(?:停止|终止|杀死).{0,100}detached grandchildren/i); +}); + +test('Unreleased changelog records progress and interruption behavior without a version bump', () => { + const changelog = read('CHANGELOG.md'); + assert.match(changelog, /foreground activity/i); + assert.match(changelog, /20-second heartbeat/i); + assert.match(changelog, /status previews/i); + assert.match(changelog, /background.{0,120}explicit cancellation/i); + assert.match(changelog, /SIGINT.*SIGTERM/i); + assert.match(changelog, /session\/stop/); + assert.equal(JSON.parse(read('package.json')).version, '0.1.0'); +}); + test('marketplace catalog and publisher describe an installable vitry snapshot', () => { const catalog = JSON.parse(read('marketplace/.agents/plugins/marketplace.json')); assert.equal(catalog.name, 'vitry'); From 8fc7b6679b348b0a48de9cc72164b01b1d90109f Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 03:52:08 +0800 Subject: [PATCH 18/27] fix: defer progress until send acceptance --- scripts/lib/progress.mjs | 64 ++++++++++++++++++++++++++++---------- scripts/lib/review.mjs | 3 +- tests/job-control.test.mjs | 39 +++++++++++++++++++++++ tests/progress.test.mjs | 33 ++++++++++++++++++++ 4 files changed, 122 insertions(+), 17 deletions(-) diff --git a/scripts/lib/progress.mjs b/scripts/lib/progress.mjs index 71f3e881..752ac6d6 100644 --- a/scripts/lib/progress.mjs +++ b/scripts/lib/progress.mjs @@ -44,19 +44,25 @@ export function normalizeZCodeProgress(notification, sessionId, observedAt) { } /** - * @param {{sessionId:string,write?:(line:string)=>void,persist?:(event:{phase:string,message:string,observedAt:string})=>Promise|void,now?:()=>string,setInterval?:(callback:()=>void,milliseconds:number)=>any,clearInterval?:(timer:any)=>void}} options + * @param {{sessionId:string,deferred?:boolean,write?:(line:string)=>void,persist?:(event:{phase:string,message:string,observedAt:string})=>Promise|void,now?:()=>string,setInterval?:(callback:()=>void,milliseconds:number)=>any,clearInterval?:(timer:any)=>void}} options */ export function createProgressReporter({ sessionId, + deferred = false, write, persist, now = () => new Date().toISOString(), setInterval: setIntervalFn = globalThis.setInterval, clearInterval: clearIntervalFn = globalThis.clearInterval, }) { - let lastActivityAt = now(); + let active = !deferred; + let closed = false; + let lastActivityAt = active ? now() : null; /** @type {string|null} */ let previousKey = null; + /** @type {Array<{phase:string,message:string,observedAt:string}>} */ + const buffered = []; + const bufferedKeys = new Set(); let persistence = Promise.resolve(); let hasReporterError = false; /** @type {unknown} */ @@ -64,7 +70,8 @@ export function createProgressReporter({ const recordError = (/** @type {unknown} */ error) => { if (!hasReporterError) { hasReporterError = true; reporterError = error; } }; /** @type {any} */ let timer = null; - if (typeof write === 'function') { + const startTimer = () => { + if (timer !== null || typeof write !== 'function') return; timer = setIntervalFn(() => { const currentTime = now(); if (!validTimestamp(currentTime) || !validTimestamp(lastActivityAt)) return; @@ -74,30 +81,55 @@ export function createProgressReporter({ try { write(`[zcode] Still waiting for ZCode; last activity ${seconds}s ago.\n`); } catch (error) { recordError(error); } }, PROGRESS_HEARTBEAT_MS); - } - timer?.unref?.(); + timer?.unref?.(); + }; + /** @param {{phase:string,message:string,observedAt:string}} event */ + const dispatch = (event) => { + lastActivityAt = event.observedAt; + const key = `${event.phase}\u0000${event.message}`; + if (key === previousKey) return null; + previousKey = key; + if (typeof write === 'function') { + try { write(`[zcode] ${event.message}\n`); } + catch (error) { recordError(error); } + } + if (typeof persist === 'function') persistence = persistence.then(async () => { + try { await persist(event); } + catch (error) { recordError(error); } + }); + return event; + }; + if (active) startTimer(); return { /** @param {unknown} notification */ observe(notification) { + if (closed) return null; const event = normalizeZCodeProgress(notification, sessionId, now()); if (event === null) return null; - lastActivityAt = event.observedAt; const key = `${event.phase}\u0000${event.message}`; - if (key === previousKey) return null; - previousKey = key; - if (typeof write === 'function') { - try { write(`[zcode] ${event.message}\n`); } - catch (error) { recordError(error); } + if (!active) { + if (bufferedKeys.has(key)) return null; + if (buffered.length === MAX_PROGRESS_PREVIEW_ENTRIES) { + const removed = buffered.shift(); + if (removed) bufferedKeys.delete(`${removed.phase}\u0000${removed.message}`); + } + buffered.push(event); bufferedKeys.add(key); return event; } - if (typeof persist === 'function') persistence = persistence.then(async () => { - try { await persist(event); } - catch (error) { recordError(error); } - }); - return event; + return dispatch(event); + }, + /** @param {unknown} initialNotification */ + activate(initialNotification) { + if (active || closed) return false; + const activatedAt = now(); active = true; lastActivityAt = activatedAt; startTimer(); + const initial = normalizeZCodeProgress(initialNotification, sessionId, activatedAt); + if (initial) dispatch(initial); + for (const event of buffered) dispatch({ ...event, observedAt: activatedAt }); + buffered.length = 0; bufferedKeys.clear(); return true; }, async flush() { await persistence; if (hasReporterError) throw reporterError; }, close() { + closed = true; buffered.length = 0; bufferedKeys.clear(); if (timer === null) return; clearIntervalFn(timer); timer = null; diff --git a/scripts/lib/review.mjs b/scripts/lib/review.mjs index 3bc45ae0..c96f9f68 100644 --- a/scripts/lib/review.mjs +++ b/scripts/lib/review.mjs @@ -71,6 +71,7 @@ export async function executeJob(input) { sessionId = snapshot.session.sessionId; reporter = createProgressReporter({ sessionId, + deferred: true, ...(input.progressWriter ? { write: input.progressWriter } : {}), persist: (event) => input.store.updateJobProgress(workspace, job.id, event), ...input.progressDependencies, @@ -87,9 +88,9 @@ export async function executeJob(input) { ...(input.workerLeaseId ? { workerLeaseId: input.workerLeaseId } : {}), ...(selectedModel ? { model: selectedModel } : {}), ...(input.effort ? { effort: input.effort } : {}), }); - reporter.observe({ method: 'state.updated', params: { scope: 'session', sessionId, reason: 'prompt_started' } }); input.signal?.throwIfAborted(); const beforeMessageIds = [...snapshotMessageIds(snapshot)]; sendAttempted = true; const sent = await client.send(sessionId, prompt); + reporter.activate({ method: 'state.updated', params: { scope: 'session', sessionId, reason: 'prompt_started' } }); running = await input.store.transitionJob(workspace, job.id, ['running'], 'running', { inputId: sent.inputId, startRevision: sent.stateRevision, beforeMessageIds }); await input.onBoundaryPersisted?.(running); const turnBoundary = { beforeMessageIds: new Set(beforeMessageIds), ...sent }; diff --git a/tests/job-control.test.mjs b/tests/job-control.test.mjs index 8576d863..5fc7775a 100644 --- a/tests/job-control.test.mjs +++ b/tests/job-control.test.mjs @@ -413,6 +413,45 @@ test('executor reports only same-session progress and drains persistence before assert.equal(unsubscribes, 1); assert.equal(cleared, 1); assert.equal(closes, 1); assert.equal(handler, null); }); +test('slow send has no progress side effects until accepted', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + /** @type {string[]} */ + const lines = []; + let intervalCalls = 0; let fireInterval = () => {}; + /** @type {(value:any)=>void} */ let resolveSend = () => {}; + /** @type {()=>void} */ let signalSendStarted = () => {}; + const sendStarted = new Promise((resolve) => { signalSendStarted = () => resolve(undefined); }); + const sendCompletion = new Promise((resolve) => { resolveSend = resolve; }); + let currentTime = new Date().toISOString(); + const client = { + createSession: async () => ({ session: { sessionId: 'zs-slow-send' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [] }), + setPermissionHandler: () => {}, subscribe: silentSubscribe, + send: async () => { signalSendStarted(); return sendCompletion; }, waitForCompletion: async () => {}, + readSession: async () => ({ messages: [{ info: { role: 'assistant', messageId: 'assistant-slow-send', parentMessageId: 'input-slow-send' }, parts: [{ type: 'text', text: 'done' }] }] }), close: async () => {}, + }; + const execution = executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', progressWriter: (line) => lines.push(line), progressDependencies: { now: () => currentTime, setInterval: (callback) => { intervalCalls += 1; fireInterval = callback; return { unref() {} }; }, clearInterval: () => {} } }); + await sendStarted; + currentTime = new Date(Date.parse(currentTime) + 21_000).toISOString(); fireInterval(); + assert.equal(intervalCalls, 0); assert.deepEqual(lines, []); + const beforeAccepted = await store.readJob(workspace, job.id); assert.equal(beforeAccepted.phase, undefined); assert.equal(beforeAccepted.progressPreview, undefined); + currentTime = new Date().toISOString(); resolveSend({ inputId: 'input-slow-send', stateRevision: 1 }); + assert.equal((await execution).job.status, 'succeeded'); assert.match(lines[0], /started the delegated turn/); +}); + +test('rejected send never activates progress or heartbeat', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + /** @type {string[]} */ + const lines = []; + let intervalCalls = 0; + const client = { + createSession: async () => ({ session: { sessionId: 'zs-rejected-send' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } } }), + setPermissionHandler: () => {}, subscribe: silentSubscribe, send: async () => { throw new Error('send rejected'); }, stopSession: async () => {}, close: async () => {}, + }; + await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', progressWriter: (line) => lines.push(line), progressDependencies: { now: () => new Date().toISOString(), setInterval: () => { intervalCalls += 1; return { unref() {} }; }, clearInterval: () => {} } }), /send rejected/); + const failed = await store.readJob(workspace, job.id); + assert.equal(intervalCalls, 0); assert.deepEqual(lines, []); assert.equal(failed.status, 'failed'); assert.equal(failed.phase, undefined); assert.equal(failed.progressPreview, undefined); +}); + test('writer failure still persists progress and fails with a stable progress error', async () => { const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); /** @type {any[]} */ diff --git a/tests/progress.test.mjs b/tests/progress.test.mjs index 1ec357d3..416a1b5e 100644 --- a/tests/progress.test.mjs +++ b/tests/progress.test.mjs @@ -262,6 +262,39 @@ test('writer failures do not interrupt observation or persistence and surface af } }); +test('deferred reporter buffers only bounded normalized events and activates starting-first', async () => { + const lines = []; const persisted = []; let intervalCalls = 0; let currentTime = observedAt; + const reporter = progressModule.createProgressReporter({ + sessionId: 'session-a', deferred: true, + write: (line) => lines.push(line), persist: async (event) => persisted.push(event), now: () => currentTime, + setInterval: () => { intervalCalls += 1; return { unref() {} }; }, clearInterval: () => {}, + }); + for (const reason of ['model_streaming', 'model_streaming', 'tool_call_started', 'api_retry', 'tool_call_result', 'prompt_completed']) { + reporter.observe(notification(reason, { secret: `raw-${reason}` })); + } + assert.equal(intervalCalls, 0); assert.deepEqual(lines, []); assert.deepEqual(persisted, []); + currentTime = '2026-08-08T00:00:10.000Z'; + reporter.activate(notification('prompt_started')); + await reporter.flush(); + assert.equal(intervalCalls, 1); + assert.deepEqual(lines, [ + '[zcode] ZCode started the delegated turn.\n', + '[zcode] ZCode started a tool call.\n', + '[zcode] ZCode is retrying the model request.\n', + '[zcode] ZCode completed a tool call.\n', + '[zcode] ZCode completed the delegated turn.\n', + ]); + assert.deepEqual(persisted.map(({ phase, message, observedAt: at }) => ({ phase, message, observedAt: at })), [ + { phase: 'starting', message: 'ZCode started the delegated turn.', observedAt: currentTime }, + { phase: 'running', message: 'ZCode started a tool call.', observedAt: currentTime }, + { phase: 'waiting', message: 'ZCode is retrying the model request.', observedAt: currentTime }, + { phase: 'running', message: 'ZCode completed a tool call.', observedAt: currentTime }, + { phase: 'finalizing', message: 'ZCode completed the delegated turn.', observedAt: currentTime }, + ]); + assert.doesNotMatch(JSON.stringify(persisted), /raw-|secret/); + reporter.close(); +}); + test('does not create a heartbeat interval without a writer', () => { let intervalCalls = 0; const reporter = progressModule.createProgressReporter({ From 1438b9e4a7c6a8b45b5058e9f90b657d8d830893 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 04:02:43 +0800 Subject: [PATCH 19/27] fix status wait signal interruption --- scripts/lib/job-control.mjs | 45 +++++++++++++++++----- scripts/zcode-companion.mjs | 2 +- tests/fixtures/status-wait-probe.cjs | 13 +++++++ tests/integration/companion.test.mjs | 29 ++++++++++++++ tests/job-control.test.mjs | 57 ++++++++++++++++++++++++++++ 5 files changed, 136 insertions(+), 10 deletions(-) create mode 100644 tests/fixtures/status-wait-probe.cjs diff --git a/scripts/lib/job-control.mjs b/scripts/lib/job-control.mjs index f64d579b..5c5cec93 100644 --- a/scripts/lib/job-control.mjs +++ b/scripts/lib/job-control.mjs @@ -5,6 +5,7 @@ import { join, resolve } from 'node:path'; import { createCancelAttemptStore } from './cancel-attempt.mjs'; import { PluginError } from './errors.mjs'; import { withFileLock } from './fs.mjs'; +import { waitForCompletionOrAbort } from './progress.mjs'; import { resolveWorkspaceStorage } from './workspace.mjs'; const TERMINAL = new Set(['succeeded', 'failed', 'cancelled']); @@ -25,12 +26,13 @@ export function ownerIdForSession(sessionId) { return createHash('sha256').update(JSON.stringify(['zcode-owner-v1', sessionId])).digest('hex'); } -/** @param {{store:any,dataRoot?:string,stopSession?:(sessionId:string)=>Promise,pollIntervalMs?:number,clock?:()=>number,delay?:(ms:number)=>Promise,beforeWaitPoll?:()=>Promise,afterRollbackBeforeSettle?:()=>Promise,afterFollowerSelected?:()=>Promise,afterObservationBeforeLock?:()=>Promise}} options */ +/** @param {{store:any,dataRoot?:string,stopSession?:(sessionId:string)=>Promise,pollIntervalMs?:number,clock?:()=>number,delay?:(ms:number)=>Promise,setTimeout?:(callback:()=>void,ms:number)=>any,clearTimeout?:(timer:any)=>void,beforeWaitPoll?:()=>Promise,afterRollbackBeforeSettle?:()=>Promise,afterFollowerSelected?:()=>Promise,afterObservationBeforeLock?:()=>Promise}} options */ export function createJobController(options) { if (!options?.store) throw new PluginError('JOB_CONTROLLER_INPUT_INVALID', 'A state store is required.', { category: 'validation', remedy: 'Provide the Task 2 state store.' }); const pollIntervalMs = options.pollIntervalMs ?? 50; const clock = options.clock ?? Date.now; - const delay = options.delay ?? pollDelay; + const scheduleTimeout = options.setTimeout ?? globalThis.setTimeout; + const cancelTimeout = options.clearTimeout ?? globalThis.clearTimeout; /** @type {Map>} */ const inFlight = new Map(); return { @@ -45,15 +47,19 @@ export function createJobController(options) { if (!selected) throw new PluginError('OWNED_JOB_NOT_FOUND', 'No matching owned job was found.', { category: 'authorization', remedy: 'Check the job ID and invoke the command from its owning Codex session.' }); return selected; }, - /** @param {string} workspace @param {string} jobId @param {number} timeoutMs */ - async wait(workspace, jobId, timeoutMs) { + /** @param {string} workspace @param {string} jobId @param {number} timeoutMs @param {AbortSignal} [signal] */ + async wait(workspace, jobId, timeoutMs, signal) { const started = clock(); while (true) { - await options.beforeWaitPoll?.(); - const job = await options.store.readJob(workspace, jobId); + signal?.throwIfAborted(); + await abortable(() => options.beforeWaitPoll?.(), signal); + const job = await abortable(() => options.store.readJob(workspace, jobId), signal); if (TERMINAL.has(job.status)) return job; if (clock() - started >= timeoutMs) throw new PluginError('JOB_WAIT_TIMEOUT', `Timed out waiting for job ${jobId}.`, { category: 'timeout', remedy: `Retry $zcode:status ${jobId} --wait.`, details: { jobId, status: job.status, timeoutMs } }); - await delay(Math.min(pollIntervalMs, Math.max(0, timeoutMs - (clock() - started)))); + const waitMs = Math.min(pollIntervalMs, Math.max(0, timeoutMs - (clock() - started))); + const customDelay = options.delay; + if (customDelay) await abortable(() => customDelay(waitMs), signal); + else await pollDelay(waitMs, signal, scheduleTimeout, cancelTimeout); } }, /** @param {string} workspace @param {string} jobId @param {string} ownerSessionId */ @@ -155,8 +161,29 @@ function completedDuringAcquisition(observed, current) { && ['failed', 'succeeded', 'finalize-pending'].includes(current.status); } -/** @param {number} milliseconds */ -function pollDelay(milliseconds) { return new Promise((resolve) => setTimeout(resolve, milliseconds)); } +/** @param {number} milliseconds @param {AbortSignal} [signal] @param {(callback:()=>void,ms:number)=>any} [schedule] @param {(timer:any)=>void} [cancel] */ +function pollDelay(milliseconds, signal, schedule = globalThis.setTimeout, cancel = globalThis.clearTimeout) { + signal?.throwIfAborted(); + return new Promise((resolve, reject) => { + let settled = false; + let timer = /** @type {any} */ (undefined); + const cleanup = () => signal?.removeEventListener('abort', onAbort); + const onAbort = () => { if (settled) return; settled = true; if (timer !== undefined) cancel(timer); cleanup(); reject(signal?.reason); }; + const onTimer = () => { if (settled) return; settled = true; cleanup(); resolve(undefined); }; + signal?.addEventListener('abort', onAbort, { once: true }); + if (signal?.aborted) onAbort(); + if (!settled) { + timer = schedule(onTimer, milliseconds); + if (settled) cancel(timer); + } + }); +} +/** @template T @param {()=>T|Promise} operation @param {AbortSignal} [signal] */ +function abortable(operation, signal) { + signal?.throwIfAborted(); + const completion = Promise.resolve().then(() => { signal?.throwIfAborted(); return operation(); }); + return waitForCompletionOrAbort(completion, signal); +} /** @param {any} job @param {'status'|'result'|'cancel'} eligibility */ function eligibleImplicit(job, eligibility) { if (eligibility === 'cancel') return ['queued', 'running', 'cancelling'].includes(job.status); diff --git a/scripts/zcode-companion.mjs b/scripts/zcode-companion.mjs index 59589a8a..2b5e0086 100644 --- a/scripts/zcode-companion.mjs +++ b/scripts/zcode-companion.mjs @@ -50,7 +50,7 @@ export async function runCompanion(argv, runtime = {}) { const modelPolicy = summarizeWorkspaceModelConfig(await readWorkspaceModelConfig({ dataRoot, workspace: cwd })); if (parsed.options.all) return { jobs: (await store.listJobs(cwd)).map((job) => publicJob(job, caller.sessionId)), modelPolicy }; let job = await controller.selectOwned(cwd, caller.sessionId, parsed.positionals[0]); - if (parsed.options.wait) job = await controller.wait(cwd, job.id, parsed.options.timeoutMs); + if (parsed.options.wait) job = await controller.wait(cwd, job.id, parsed.options.timeoutMs, runtime.signal); return { job, modelPolicy }; } if (parsed.command === 'result') { diff --git a/tests/fixtures/status-wait-probe.cjs b/tests/fixtures/status-wait-probe.cjs new file mode 100644 index 00000000..4b00f7f1 --- /dev/null +++ b/tests/fixtures/status-wait-probe.cjs @@ -0,0 +1,13 @@ +'use strict'; + +const { writeFileSync } = require('node:fs'); +const process = require('node:process'); + +const marker = process.env.ZCODE_STATUS_WAIT_PROBE; +if (marker) { + const originalSetTimeout = globalThis.setTimeout; + globalThis.setTimeout = function setTimeout(callback, milliseconds, ...args) { + if (milliseconds === 50 && new Error().stack.includes('job-control.mjs')) writeFileSync(marker, 'waiting'); + return Reflect.apply(originalSetTimeout, this, [callback, milliseconds, ...args]); + }; +} diff --git a/tests/integration/companion.test.mjs b/tests/integration/companion.test.mjs index 95001b9c..78bec513 100644 --- a/tests/integration/companion.test.mjs +++ b/tests/integration/companion.test.mjs @@ -22,6 +22,7 @@ const cli = join(root, 'scripts', 'zcode-companion.mjs'); const fake = join(root, 'tests', 'fixtures', 'fake-zcode-cli.mjs'); const fakeCodex = join(root, 'tests', 'fixtures', 'fake-codex-app-server.mjs'); const signalHandlerProbe = join(root, 'tests', 'fixtures', 'signal-handler-probe.cjs'); +const statusWaitProbe = join(root, 'tests', 'fixtures', 'status-wait-probe.cjs'); async function fixture() { const directory = await mkdtemp(join(tmpdir(), 'zcode-companion-')); @@ -474,6 +475,34 @@ test('real CLI status wait stays alive until its timeout', async () => { assert.equal(waited.code, 1); assert.equal(waited.json.error.code, 'JOB_WAIT_TIMEOUT'); }); +test('real CLI status wait exits immediately without protocol output on SIGINT', async (t) => { + const context = await fixture(); const marker = join(context.directory, 'status-wait.txt'); + const store = createStateStore({ dataRoot: context.dataRoot }); + const queued = await store.reserveJob({ workspace: context.workspace, ownerSessionId: 'codex-session', ownerTurnId: 'turn-1', command: 'rescue', readOnly: false, permissionSnapshot: { permissionMode: 'workspace-write' } }); + await store.transitionJob(context.workspace, queued.id, ['queued'], 'running', { childPid: process.pid, zcodeSessionId: 'status-wait-session' }); + const child = spawn(process.execPath, ['--require', statusWaitProbe, cli, 'status', queued.id, '--wait', '--timeout-ms', '10000'], { + cwd: context.workspace, + env: { ...context.env, ZCODE_STATUS_WAIT_PROBE: marker }, + stdio: ['ignore', 'pipe', 'pipe', 'pipe', 'pipe'], shell: false, + }); + let stdout = ''; let stderr = ''; let internal = ''; let exited = false; + child.stdout?.on('data', (chunk) => { stdout += chunk; }); child.stderr?.on('data', (chunk) => { stderr += chunk; }); child.stdio[4]?.on('data', (chunk) => { internal += chunk; }); + child.stdio[3]?.on('error', consumePipeError); child.stdio[4]?.on('error', consumePipeError); + /** @type {import('node:stream').Writable} */ (child.stdio[3]).end(`${JSON.stringify({ callerContext: context.caller })}\n`); + t.after(() => { if (!exited) child.kill('SIGKILL'); }); + const exitPromise = new Promise((resolve, reject) => { child.once('error', reject); child.once('exit', (code, signal) => { exited = true; resolve({ code, signal }); }); }); + + await waitFor(async () => await readFile(marker, 'utf8').catch(() => '') === 'waiting', 'status command did not enter its polling wait'); + child.kill('SIGINT'); + /** @type {NodeJS.Timeout|undefined} */ let deadline; + const exit = await Promise.race([exitPromise, new Promise((resolve, reject) => { void resolve; deadline = setTimeout(() => { if (!exited) child.kill('SIGKILL'); reject(new Error('status wait did not exit promptly after SIGINT')); }, 1_000); })]).finally(() => clearTimeout(deadline)); + + assert.deepEqual(exit, { code: 130, signal: null }); + assert.equal(stdout, ''); assert.equal(internal, ''); + assert.match(stderr, /Interrupted by SIGINT\./); assert.doesNotMatch(stderr, /JOB_INTERRUPTED|JOB_WAIT_TIMEOUT|"error"/); + assert.equal((await store.readJob(context.workspace, queued.id)).status, 'running'); +}); + test('foreground Transfer observes SIGTERM after its bounded create RPC and exits 143', async (t) => { const context = await fixture(); const zcodeRecord = join(context.directory, 'transfer-interrupt.jsonl'); await writeFile(zcodeRecord, ''); const sourceThread = { id: 'codex-session', ephemeral: false, turns: [{ startedAt: 1_725_000_000, items: [{ type: 'agentMessage', text: 'visible response' }] }] }; diff --git a/tests/job-control.test.mjs b/tests/job-control.test.mjs index 5fc7775a..cdc89275 100644 --- a/tests/job-control.test.mjs +++ b/tests/job-control.test.mjs @@ -1,4 +1,5 @@ import assert from 'node:assert/strict'; +import { getEventListeners } from 'node:events'; import { mkdir, mkdtemp, readFile, stat } from 'node:fs/promises'; import { tmpdir } from 'node:os'; import { join } from 'node:path'; @@ -68,6 +69,62 @@ test('wait reaches terminal state or returns a stable timeout error', async () = await assert.rejects(controller.wait(workspace, active.id, 0), { code: 'JOB_WAIT_TIMEOUT' }); }); +test('wait rejects an already-aborted signal before polling', async () => { + const { workspace, store } = await setup(); + const job = await store.reserveJob({ workspace, ...reservation }); + const interruption = new PluginError('JOB_INTERRUPTED', 'Interrupted by SIGINT.'); + const abort = new AbortController(); abort.abort(interruption); + let polls = 0; + const controller = createJobController({ store, beforeWaitPoll: async () => { polls += 1; } }); + await assert.rejects(controller.wait(workspace, job.id, 100, abort.signal), (error) => error === interruption); + assert.equal(polls, 0); +}); + +test('wait interrupts a pending poll and handles its later rejection', async () => { + const { workspace, store } = await setup(); + const job = await store.reserveJob({ workspace, ...reservation }); + /** @type {()=>void} */ let startPoll = () => {}; + /** @type {Promise} */ const pollStarted = new Promise((resolve) => { startPoll = resolve; }); + /** @type {(error:Error)=>void} */ let rejectPoll = () => {}; + const controller = createJobController({ store, beforeWaitPoll: () => new Promise((resolve, reject) => { void resolve; rejectPoll = reject; startPoll(); }) }); + const abort = new AbortController(); + const interruption = new PluginError('JOB_INTERRUPTED', 'Interrupted by SIGTERM.'); + const waiting = controller.wait(workspace, job.id, 10_000, abort.signal); + await pollStarted; abort.abort(interruption); + const outcome = await Promise.race([ + waiting.catch((error) => error), + new Promise((resolve) => setTimeout(() => resolve('deadline'), 25)), + ]); + assert.equal(outcome, interruption); + rejectPoll(new Error('late reconciliation failure')); + await new Promise((resolve) => setImmediate(resolve)); +}); + +test('wait clears its polling timer and abort listener when interrupted', async () => { + const { workspace, store } = await setup(); + const job = await store.reserveJob({ workspace, ...reservation }); + const timerToken = { timer: true }; + /** @type {()=>void} */ let announceTimer = () => {}; + /** @type {Promise} */ const timerStarted = new Promise((resolve) => { announceTimer = resolve; }); + let cleared; + const controller = createJobController({ + store, + pollIntervalMs: 1_000, + setTimeout: () => { announceTimer(); return timerToken; }, + clearTimeout: (token) => { cleared = token; }, + }); + const abort = new AbortController(); + const interruption = new PluginError('JOB_INTERRUPTED', 'Interrupted by SIGINT.'); + const waiting = controller.wait(workspace, job.id, 10_000, abort.signal); + const enteredDelay = await Promise.race([timerStarted.then(() => true), new Promise((resolve) => setTimeout(() => resolve(false), 25))]); + assert.equal(getEventListeners(abort.signal, 'abort').length, 1); + abort.abort(interruption); + await assert.rejects(waiting, (error) => error === interruption); + assert.equal(enteredDelay, true); + assert.equal(cleared, timerToken); + assert.equal(getEventListeners(abort.signal, 'abort').length, 0); +}); + test('queued cancellation is safe and terminal cancellation is idempotent', async () => { const { workspace, store, controller } = await setup(); const queued = await store.reserveJob({ workspace, ...reservation }); From 56a81258732cda35cded5d5a877cf410bb6431f5 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 04:07:07 +0800 Subject: [PATCH 20/27] fix: show cancellation errors in job status --- scripts/lib/render.mjs | 12 ++++++++++++ tests/render-progress.test.mjs | 22 ++++++++++++++++++++++ 2 files changed, 34 insertions(+) diff --git a/scripts/lib/render.mjs b/scripts/lib/render.mjs index 1de380a8..5d87f9fa 100644 --- a/scripts/lib/render.mjs +++ b/scripts/lib/render.mjs @@ -39,6 +39,7 @@ function renderJob(job) { const previews = Array.isArray(job.progressPreview) ? job.progressPreview.filter((/** @type {unknown} */ message) => typeof message === 'string').slice(-4) : []; + const lastCancellationError = renderCancellationError(job.lastCancelError); const lines = [ `Job: ${safeInline(job.id)}`, `Command: ${safeInline(job.command)}`, @@ -49,6 +50,8 @@ function renderJob(job) { `Finished: ${safeInline(job.finishedAt)}`, `${timingLabel}: ${timing}`, `Last activity: ${safeInline(job.lastActivityAt)}`, + ...(lastCancellationError === null + ? [] : [`Last cancellation error: ${lastCancellationError}`]), 'Progress:', ...(previews.length > 0 ? previews.map((/** @type {string} */ message) => ` - ${safeProgress(message)}`) @@ -57,6 +60,15 @@ function renderJob(job) { return `${lines.join('\n')}\n`; } +/** @param {unknown} value */ +function renderCancellationError(value) { + const message = typeof value === 'string' ? value + : value && typeof value === 'object' && 'message' in value + && typeof value.message === 'string' ? value.message : null; + if (message === null || message.trim().length === 0) return null; + return boundUtf8(safeInline(message), 2_048); +} + /** @param {unknown} value */ function safeInline(value) { if (typeof value !== 'string' || value.length === 0) return '—'; diff --git a/tests/render-progress.test.mjs b/tests/render-progress.test.mjs index 7dc17010..1e78a9b2 100644 --- a/tests/render-progress.test.mjs +++ b/tests/render-progress.test.mjs @@ -41,11 +41,33 @@ test('renders a bounded detailed active-job progress report with elapsed time', assert.match(output, /Progress:\n {2}- ZCode started the delegated turn\.\n {2}- ZCode started a tool call\.\n {2}- ZCode is retrying the model request\.\n {2}- \\\*\\\*ZCode completed a tool call\.\\\*\\\*/); assert.match(output, /Model policy: default=quick; aliases=quick/); assert.doesNotMatch(output, / {2}- \*\*ZCode/); + assert.doesNotMatch(output, /Last cancellation error:/); } finally { Date.now = originalNow; } }); +test('detailed status safely renders a bounded last cancellation error', () => { + const job = { + id, + command: 'rescue', + status: 'running', + createdAt: '2026-08-08T00:00:00.000Z', + updatedAt: '2026-08-08T00:00:01.000Z', + lastCancelError: 'stop **refused**\nretry \u202Esoon ~~later~~', + }; + const output = renderOutput({ job }); + assert.match(output, /Last cancellation error: stop \\\*\\\*refused\\\*\\\* retry soon \\~\\~later\\~\\~/); + assert.doesNotMatch(output, /\u202E|\nretry/); + + const raw = renderOutput({ job: { ...job, lastCancelError: 'x'.repeat(3_000) } }); + const line = raw.split('\n').find((/** @type {string} */ entry) => entry.startsWith('Last cancellation error: ')); + assert.ok(line); + const renderedError = line.slice('Last cancellation error: '.length); + assert.ok(Buffer.byteLength(renderedError) <= 2_048); + assert.match(renderedError, /\.\.\.$/); +}); + test('renders terminal duration and keeps result rendering unchanged', () => { const job = { id, From 4fd14410be29cfc54c0f0aa63b2308ea188bf27e Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 04:27:59 +0800 Subject: [PATCH 21/27] fix foreground signal race semantics --- scripts/lib/review.mjs | 50 +++++++++++----- scripts/lib/signals.mjs | 3 +- tests/fixtures/completion-signal-probe.cjs | 15 +++++ tests/integration/companion.test.mjs | 28 +++++++++ tests/job-control.test.mjs | 68 ++++++++++++++++++++++ tests/signals.test.mjs | 6 +- 6 files changed, 151 insertions(+), 19 deletions(-) create mode 100644 tests/fixtures/completion-signal-probe.cjs diff --git a/scripts/lib/review.mjs b/scripts/lib/review.mjs index c96f9f68..2314d82d 100644 --- a/scripts/lib/review.mjs +++ b/scripts/lib/review.mjs @@ -36,7 +36,10 @@ export function decidePermission(request, permissionSnapshot, command) { */ export async function executeJob(input) { const { job, client, workspace, dataRoot } = input; - let running = job; let sessionId; let sendAttempted = false; let remoteTerminalProven = false; + let running = job; + /** @type {string|undefined} */ + let sessionId; + let sendAttempted = false; let remoteTerminalProven = false; /** @type {any} */ let reporter; let unsubscribe = () => {}; @@ -66,11 +69,17 @@ export async function executeJob(input) { if (input.resumeSessionId) { await input.onBeforeResume?.(job); input.signal?.throwIfAborted(); - snapshot = await client.resumeSession(input.resumeSessionId); - } else snapshot = await client.createSession({ workspace, ...(input.model ? { model: input.model } : {}) }); - sessionId = snapshot.session.sessionId; + sessionId = input.resumeSessionId; + snapshot = await boundedStep(() => client.resumeSession(input.resumeSessionId), input.signal); + } else snapshot = await boundedStep(async () => { + const created = await client.createSession({ workspace, ...(input.model ? { model: input.model } : {}) }); + sessionId = created?.session?.sessionId; + return created; + }, input.signal); + const activeSessionId = /** @type {string} */ (sessionId ?? snapshot.session.sessionId); + sessionId = activeSessionId; reporter = createProgressReporter({ - sessionId, + sessionId: activeSessionId, deferred: true, ...(input.progressWriter ? { write: input.progressWriter } : {}), persist: (event) => input.store.updateJobProgress(workspace, job.id, event), @@ -78,24 +87,24 @@ export async function executeJob(input) { }); unsubscribe = client.subscribe(reporter.observe); const selectedModel = input.modelRequest ? resolveModel(input.modelRequest, input.modelAliases, snapshot.settings.model.available) : input.model; - if (selectedModel && !sameModel(snapshot.settings.model.current, selectedModel)) snapshot = await client.setModel(sessionId, selectedModel); - if (input.effort) snapshot = await client.setThoughtLevel(sessionId, input.effort); + if (selectedModel && !sameModel(snapshot.settings.model.current, selectedModel)) snapshot = await boundedStep(() => client.setModel(activeSessionId, selectedModel), input.signal); + if (input.effort) snapshot = await boundedStep(() => client.setThoughtLevel(activeSessionId, input.effort), input.signal); client.setPermissionHandler((/** @type {any} */ request) => decidePermission(request, job.permissionSnapshot, job.command)); const now = new Date().toISOString(); running = await input.store.transitionJob(workspace, job.id, ['queued'], 'running', { - startedAt: now, zcodeSessionId: sessionId, promptArtifact, + startedAt: now, zcodeSessionId: activeSessionId, promptArtifact, ...(input.childPid ? { childPid: input.childPid } : {}), ...(input.workerLeaseId ? { workerLeaseId: input.workerLeaseId } : {}), ...(selectedModel ? { model: selectedModel } : {}), ...(input.effort ? { effort: input.effort } : {}), }); input.signal?.throwIfAborted(); - const beforeMessageIds = [...snapshotMessageIds(snapshot)]; sendAttempted = true; const sent = await client.send(sessionId, prompt); - reporter.activate({ method: 'state.updated', params: { scope: 'session', sessionId, reason: 'prompt_started' } }); + const beforeMessageIds = [...snapshotMessageIds(snapshot)]; sendAttempted = true; const sent = await boundedStep(() => client.send(activeSessionId, prompt), input.signal); + reporter.activate({ method: 'state.updated', params: { scope: 'session', sessionId: activeSessionId, reason: 'prompt_started' } }); running = await input.store.transitionJob(workspace, job.id, ['running'], 'running', { inputId: sent.inputId, startRevision: sent.stateRevision, beforeMessageIds }); await input.onBoundaryPersisted?.(running); const turnBoundary = { beforeMessageIds: new Set(beforeMessageIds), ...sent }; - await waitForCompletionOrAbort(client.waitForCompletion(sessionId), input.signal); - const finalSnapshot = await client.readSession(sessionId); + await waitForCompletionOrAbort(client.waitForCompletion(activeSessionId), input.signal); + const finalSnapshot = await client.readSession(activeSessionId); remoteTerminalProven = true; const result = extractFinalResult(finalSnapshot, job.command, turnBoundary); const resultArtifact = await writeArtifact({ dataRoot, workspace, directory: 'results', jobId: job.id, contents: result }, { syncDirectory: input.syncDirectory }); @@ -107,8 +116,14 @@ export async function executeJob(input) { primaryError = error; const current = await input.store.readJob(workspace, job.id).catch(() => running); if (isInterruption(error) && current && !['failed', 'succeeded', 'cancelled'].includes(current.status)) { - const cancellation = createJobController({ store: input.store, dataRoot, stopSession: (id) => client.stopSession(id) }); - await cancellation.cancel(workspace, job.id, job.ownerSessionId).catch(() => {}); + if (current.status === 'queued' && sessionId) { + let stopped = false; + try { await client.stopSession(sessionId); stopped = true; } catch { /* retain the writable guard when remote stop is unacknowledged */ } + if (stopped) await input.store.transitionJob(workspace, job.id, ['queued'], 'cancelled', { finishedAt: new Date().toISOString(), exitCode: null }).catch(() => {}); + } else { + const cancellation = createJobController({ store: input.store, dataRoot, stopSession: (id) => client.stopSession(id) }); + await cancellation.cancel(workspace, job.id, job.ownerSessionId).catch(() => {}); + } } else if (current && !['failed', 'succeeded', 'cancelled', 'cancelling'].includes(current.status)) { let canFail = true; if (current.status === 'running' && sendAttempted && sessionId && !remoteTerminalProven) { @@ -133,6 +148,13 @@ export async function executeJob(input) { return output; } +/** @template T @param {()=>Promise} operation @param {AbortSignal|undefined} signal */ +async function boundedStep(operation, signal) { + signal?.throwIfAborted(); + try { const value = await operation(); signal?.throwIfAborted(); return value; } + catch (error) { signal?.throwIfAborted(); throw error; } +} + /** @param {{dataRoot:string,workspace:string,artifact:string}} input */ export async function readResultArtifact({ dataRoot, workspace, artifact }) { const storage = await resolveWorkspaceStorage({ dataRoot, workspace }); diff --git a/scripts/lib/signals.mjs b/scripts/lib/signals.mjs index c2528b57..4cccafc6 100644 --- a/scripts/lib/signals.mjs +++ b/scripts/lib/signals.mjs @@ -5,7 +5,7 @@ import { PluginError } from './errors.mjs'; const SIGNAL_EXIT_CODES = Object.freeze({ SIGINT: 130, SIGTERM: 143 }); /** - * @param {{process?:{on:(event:string,listener:()=>void)=>unknown,removeListener:(event:string,listener:()=>void)=>unknown,exitCode?:string|number|null},foreground?:boolean}} [options] + * @param {{process?:{on:(event:string,listener:()=>void)=>unknown,removeListener:(event:string,listener:()=>void)=>unknown},foreground?:boolean}} [options] */ export function createForegroundSignalController(options = {}) { const processLike = options.process ?? process; @@ -13,7 +13,6 @@ export function createForegroundSignalController(options = {}) { let cleaned = false; const handlers = Object.fromEntries(Object.entries(SIGNAL_EXIT_CODES).map(([signal, exitCode]) => [signal, () => { if (controller.signal.aborted) return; - processLike.exitCode = exitCode; controller.abort(new PluginError('JOB_INTERRUPTED', `Foreground ZCode job interrupted by ${signal}.`, { category: 'interruption', remedy: 'Retry the command when you are ready.', diff --git a/tests/fixtures/completion-signal-probe.cjs b/tests/fixtures/completion-signal-probe.cjs new file mode 100644 index 00000000..da996ae9 --- /dev/null +++ b/tests/fixtures/completion-signal-probe.cjs @@ -0,0 +1,15 @@ +'use strict'; + +const process = require('node:process'); + +if (process.env.ZCODE_COMPLETION_SIGNAL_PROBE === '1') { + const write = process.stdout.write; + let emitted = false; + process.stdout.write = function completionSignalWrite(chunk, ...args) { + if (!emitted && String(chunk).length > 0) { + emitted = true; + process.emit('SIGINT'); + } + return Reflect.apply(write, this, [chunk, ...args]); + }; +} diff --git a/tests/integration/companion.test.mjs b/tests/integration/companion.test.mjs index 78bec513..d7f50639 100644 --- a/tests/integration/companion.test.mjs +++ b/tests/integration/companion.test.mjs @@ -21,6 +21,7 @@ const root = fileURLToPath(new URL('../..', import.meta.url)); const cli = join(root, 'scripts', 'zcode-companion.mjs'); const fake = join(root, 'tests', 'fixtures', 'fake-zcode-cli.mjs'); const fakeCodex = join(root, 'tests', 'fixtures', 'fake-codex-app-server.mjs'); +const completionSignalProbe = join(root, 'tests', 'fixtures', 'completion-signal-probe.cjs'); const signalHandlerProbe = join(root, 'tests', 'fixtures', 'signal-handler-probe.cjs'); const statusWaitProbe = join(root, 'tests', 'fixtures', 'status-wait-probe.cjs'); @@ -160,6 +161,33 @@ test('foreground SIGINT stops the accepted ZCode session, exits 130, and leaves assert.equal(stdout, ''); assert.equal(internal, ''); assert.match(stderr, /Interrupted by SIGINT\./); assert.doesNotMatch(stderr, /JOB_INTERRUPTED|"error"/); }); +test('real CLI completion that wins before SIGINT remains succeeded with exit zero', async () => { + const context = await fixture(); + const result = await run(process.execPath, ['--require', completionSignalProbe, cli, 'rescue', '--fresh', 'completion wins'], { + cwd: context.workspace, + env: { ...context.env, ZCODE_COMPLETION_SIGNAL_PROBE: '1' }, + input: { callerContext: context.caller }, + }); + assert.equal(result.code, 0, `${result.stderr}${result.stdout}`); + assert.equal(result.stdout, 'done\n'); assert.doesNotMatch(result.stderr, /Interrupted by SIGINT|JOB_INTERRUPTED/); + assert.equal(JSON.parse(result.internal).job.status, 'succeeded'); + const jobs = await createStateStore({ dataRoot: context.dataRoot }).listJobs(context.workspace); + assert.equal(jobs.length, 1); assert.equal(jobs[0].status, 'succeeded'); assert.equal(jobs[0].exitCode, 0); +}); + +test('real CLI successful status is not flipped by SIGINT during output', async () => { + const context = await fixture(); const completed = await companion(context, ['review']); + assert.equal(completed.code, 0, `${completed.stderr}${completed.stdout}`); + const result = await run(process.execPath, ['--require', completionSignalProbe, cli, 'status', completed.json.job.id], { + cwd: context.workspace, + env: { ...context.env, ZCODE_COMPLETION_SIGNAL_PROBE: '1' }, + input: { callerContext: context.caller }, + }); + assert.equal(result.code, 0, `${result.stderr}${result.stdout}`); + assert.match(result.stdout, /^Job: /); assert.doesNotMatch(result.stderr, /Interrupted by SIGINT|JOB_INTERRUPTED/); + assert.equal(JSON.parse(result.internal).job.status, 'succeeded'); +}); + test('foreground SIGINT wins while the protected authorization envelope is incomplete', async (t) => { const context = await fixture(); const marker = join(context.directory, 'signal-handler.txt'); const child = spawn(process.execPath, ['--require', signalHandlerProbe, cli, 'rescue', '--fresh', 'interrupt authorization'], { diff --git a/tests/job-control.test.mjs b/tests/job-control.test.mjs index cdc89275..30a15d12 100644 --- a/tests/job-control.test.mjs +++ b/tests/job-control.test.mjs @@ -329,6 +329,21 @@ test('foreground interruption after an accepted send stops exactly once and dura assert.equal(persisted.resultArtifact, undefined); }); +test('send transport rejection after abort preserves the interruption and stops exactly once', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + const controller = new AbortController(); let stops = 0; + const interruption = new PluginError('JOB_INTERRUPTED', 'send interrupted', { category: 'interruption', remedy: 'retry' }); + const client = { + createSession: async () => ({ session: { sessionId: 'zs-send-reject' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [] }), + setPermissionHandler: () => {}, subscribe: silentSubscribe, + send: async () => { controller.abort(interruption); throw new Error('transport closed after abort'); }, + stopSession: async (/** @type {string} */ sessionId) => { assert.equal(sessionId, 'zs-send-reject'); stops += 1; }, close: async () => {}, + }; + await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', signal: controller.signal }), (error) => error === interruption); + const persisted = await store.readJob(workspace, job.id); + assert.equal(stops, 1); assert.equal(persisted.status, 'cancelled'); assert.equal(persisted.resultArtifact, undefined); +}); + test('foreground interruption keeps running on stop failure, bounds the error, and rethrows the interruption', async () => { const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); const controller = new AbortController(); let waitStarted = () => {}; @@ -371,6 +386,59 @@ test('an interruption before session creation is observed at the safe boundary a assert.equal(creates, 0); assert.equal((await store.readJob(workspace, job.id)).status, 'cancelled'); }); +test('session creation completion observes abort before configuration and stops the known session once', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + const controller = new AbortController(); let permissions = 0; let stops = 0; + const interruption = new PluginError('JOB_INTERRUPTED', 'create interrupted', { category: 'interruption', remedy: 'retry' }); + const client = { + createSession: async () => { controller.abort(interruption); return { session: { sessionId: 'zs-create-abort' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [] }; }, + setPermissionHandler: () => { permissions += 1; }, subscribe: silentSubscribe, + stopSession: async (/** @type {string} */ sessionId) => { assert.equal(sessionId, 'zs-create-abort'); stops += 1; }, close: async () => {}, + }; + await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', signal: controller.signal }), (error) => error === interruption); + assert.equal(permissions, 0); assert.equal(stops, 1); + assert.equal((await store.readJob(workspace, job.id)).status, 'cancelled'); +}); + +test('resume transport rejection after abort preserves the interruption and stops the known session once', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + const controller = new AbortController(); let stops = 0; + const interruption = new PluginError('JOB_INTERRUPTED', 'resume interrupted', { category: 'interruption', remedy: 'retry' }); + const client = { + resumeSession: async () => { controller.abort(interruption); throw new Error('resume transport closed'); }, + stopSession: async (/** @type {string} */ sessionId) => { assert.equal(sessionId, 'zs-resume-abort'); stops += 1; }, close: async () => {}, + }; + await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', resumeSessionId: 'zs-resume-abort', signal: controller.signal }), (error) => error === interruption); + assert.equal(stops, 1); assert.equal((await store.readJob(workspace, job.id)).status, 'cancelled'); +}); + +test('model RPC rejection after abort preserves the interruption and stops the known session once', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + const controller = new AbortController(); let stops = 0; + const interruption = new PluginError('JOB_INTERRUPTED', 'model interrupted', { category: 'interruption', remedy: 'retry' }); + const selectedModel = { providerId: 'p', modelId: 'new' }; + const client = { + createSession: async () => ({ session: { sessionId: 'zs-model-abort' }, settings: { model: { current: { providerId: 'p', modelId: 'old' }, available: [] } }, messages: [] }), + subscribe: silentSubscribe, setModel: async () => { controller.abort(interruption); throw new Error('model transport closed'); }, + stopSession: async (/** @type {string} */ sessionId) => { assert.equal(sessionId, 'zs-model-abort'); stops += 1; }, close: async () => {}, + }; + await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', model: selectedModel, signal: controller.signal }), (error) => error === interruption); + assert.equal(stops, 1); assert.equal((await store.readJob(workspace, job.id)).status, 'cancelled'); +}); + +test('thought RPC rejection after abort preserves the interruption and stops the known session once', async () => { + const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); + const controller = new AbortController(); let stops = 0; + const interruption = new PluginError('JOB_INTERRUPTED', 'thought interrupted', { category: 'interruption', remedy: 'retry' }); + const client = { + createSession: async () => ({ session: { sessionId: 'zs-thought-abort' }, settings: { model: { current: { providerId: 'p', modelId: 'm' }, available: [] } }, messages: [] }), + subscribe: silentSubscribe, setThoughtLevel: async () => { controller.abort(interruption); throw new Error('thought transport closed'); }, + stopSession: async (/** @type {string} */ sessionId) => { assert.equal(sessionId, 'zs-thought-abort'); stops += 1; }, close: async () => {}, + }; + await assert.rejects(executeJob({ job, workspace, dataRoot: join(root, 'data'), store, client, task: 'task', effort: 'high', signal: controller.signal }), (error) => error === interruption); + assert.equal(stops, 1); assert.equal((await store.readJob(workspace, job.id)).status, 'cancelled'); +}); + test('interruptions are observed immediately before resume and send RPC boundaries', async () => { { const { root, workspace, store } = await setup(); const job = await store.reserveJob({ workspace, ...reservation }); const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'before resume'); let resumes = 0; diff --git a/tests/signals.test.mjs b/tests/signals.test.mjs index 51013846..8d3429f0 100644 --- a/tests/signals.test.mjs +++ b/tests/signals.test.mjs @@ -6,7 +6,7 @@ import { PluginError } from '../scripts/lib/errors.mjs'; import { waitForCompletionOrAbort } from '../scripts/lib/progress.mjs'; import { createForegroundSignalController } from '../scripts/lib/signals.mjs'; -test('foreground signal controller aborts once with signal-specific interruption exit codes and cleans up', () => { +test('foreground signal controller aborts once without setting the process exit code and cleans up', () => { /** @type {Array<[string,number]>} */ const cases = [['SIGINT', 130], ['SIGTERM', 143]]; for (const [name, exitCode] of cases) { @@ -21,11 +21,11 @@ test('foreground signal controller aborts once with signal-specific interruption assert.equal(reason.code, 'JOB_INTERRUPTED'); assert.equal(reason.details.signal, name); assert.equal(reason.details.exitCode, exitCode); - assert.equal(processLike.exitCode, exitCode); + assert.equal(processLike.exitCode, undefined); processLike.emit(name === 'SIGINT' ? 'SIGTERM' : 'SIGINT'); assert.equal(controller.signal.reason, reason); - assert.equal(processLike.exitCode, exitCode); + assert.equal(processLike.exitCode, undefined); controller.cleanup(); controller.cleanup(); assert.equal(processLike.listenerCount('SIGINT'), 0); From 16e8f716ecd2b825deab3615de4e4d49c54254d4 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 04:32:00 +0800 Subject: [PATCH 22/27] fix: bound progress persistence backlog --- scripts/lib/progress.mjs | 39 ++++++++++++++++++++++++++++++++------- tests/progress.test.mjs | 24 ++++++++++++++++++++++++ 2 files changed, 56 insertions(+), 7 deletions(-) diff --git a/scripts/lib/progress.mjs b/scripts/lib/progress.mjs index 752ac6d6..d62ee25b 100644 --- a/scripts/lib/progress.mjs +++ b/scripts/lib/progress.mjs @@ -1,5 +1,6 @@ export const PROGRESS_PHASES = Object.freeze(['starting', 'running', 'waiting', 'finalizing']); export const MAX_PROGRESS_PREVIEW_ENTRIES = 4; +export const MAX_PROGRESS_PENDING_EVENTS = 4; export const MAX_PROGRESS_MESSAGE_BYTES = 256; export const PROGRESS_HEARTBEAT_MS = 20_000; @@ -63,7 +64,10 @@ export function createProgressReporter({ /** @type {Array<{phase:string,message:string,observedAt:string}>} */ const buffered = []; const bufferedKeys = new Set(); - let persistence = Promise.resolve(); + /** @type {Array<{phase:string,message:string,observedAt:string}>} */ + const pending = []; + /** @type {Promise|null} */ + let inFlight = null; let hasReporterError = false; /** @type {unknown} */ let reporterError; @@ -84,19 +88,37 @@ export function createProgressReporter({ timer?.unref?.(); }; /** @param {{phase:string,message:string,observedAt:string}} event */ + const startPersist = (event) => { + if (typeof persist !== 'function') return; + let operation; + try { operation = Promise.resolve(persist(event)); } + catch (error) { recordError(error); operation = Promise.resolve(); } + const tracked = operation.catch((error) => { recordError(error); }).then(() => { + inFlight = null; + const next = pending.shift(); + if (next) startPersist(next); + }); + inFlight = tracked; + }; + /** @param {{phase:string,message:string,observedAt:string}} event */ + const enqueue = (event) => { + if (typeof persist !== 'function') return true; + if (inFlight === null) { startPersist(event); return true; } + if (pending.length < MAX_PROGRESS_PENDING_EVENTS) { pending.push(event); return true; } + pending[pending.length - 1] = event; + return false; + }; + /** @param {{phase:string,message:string,observedAt:string}} event */ const dispatch = (event) => { lastActivityAt = event.observedAt; const key = `${event.phase}\u0000${event.message}`; if (key === previousKey) return null; previousKey = key; - if (typeof write === 'function') { + const admitted = enqueue(event); + if (admitted && typeof write === 'function') { try { write(`[zcode] ${event.message}\n`); } catch (error) { recordError(error); } } - if (typeof persist === 'function') persistence = persistence.then(async () => { - try { await persist(event); } - catch (error) { recordError(error); } - }); return event; }; if (active) startTimer(); @@ -127,7 +149,10 @@ export function createProgressReporter({ for (const event of buffered) dispatch({ ...event, observedAt: activatedAt }); buffered.length = 0; bufferedKeys.clear(); return true; }, - async flush() { await persistence; if (hasReporterError) throw reporterError; }, + async flush() { + while (inFlight !== null) await inFlight; + if (hasReporterError) throw reporterError; + }, close() { closed = true; buffered.length = 0; bufferedKeys.clear(); if (timer === null) return; diff --git a/tests/progress.test.mjs b/tests/progress.test.mjs index 416a1b5e..8112b746 100644 --- a/tests/progress.test.mjs +++ b/tests/progress.test.mjs @@ -31,6 +31,7 @@ function notification(reason, patch = {}, overrides = {}) { test('exports fixed progress bounds and phases', () => { assert.deepEqual(PROGRESS_PHASES, ['starting', 'running', 'waiting', 'finalizing']); assert.equal(MAX_PROGRESS_PREVIEW_ENTRIES, 4); + assert.equal(progressModule.MAX_PROGRESS_PENDING_EVENTS, 4); assert.equal(MAX_PROGRESS_MESSAGE_BYTES, 256); assert.equal(PROGRESS_HEARTBEAT_MS, 20_000); }); @@ -141,6 +142,29 @@ test('reports immediately, suppresses consecutive duplicates, and serializes per ]); }); +test('bounds pending persistence and output while retaining the latest event under flood', async () => { + const calls = []; const persisted = []; const lines = []; + let releaseFirst = () => {}; + const firstBlocked = new Promise((resolve) => { releaseFirst = () => resolve(undefined); }); + const reporter = progressModule.createProgressReporter({ + sessionId: 'session-a', write: (line) => lines.push(line), + persist: async (event) => { calls.push(event); if (calls.length === 1) await firstBlocked; persisted.push(event); }, + now: () => observedAt, setInterval: () => ({ unref() {} }), clearInterval: () => {}, + }); + for (let index = 0; index < 100_000; index += 1) reporter.observe(notification(index % 2 === 0 ? 'tool_call_started' : 'api_retry')); + reporter.observe(notification('prompt_completed')); + await Promise.resolve(); + const callsWhileBlocked = calls.length; const linesWhileBlocked = lines.length; + releaseFirst(); await reporter.flush(); + assert.equal(callsWhileBlocked, 1); + assert.ok(calls.length <= 1 + progressModule.MAX_PROGRESS_PENDING_EVENTS, calls.length); + assert.ok(linesWhileBlocked <= 1 + progressModule.MAX_PROGRESS_PENDING_EVENTS, linesWhileBlocked); + assert.equal(calls.at(-1).phase, 'finalizing'); + assert.equal(calls.at(-1).message, 'ZCode completed the delegated turn.'); + assert.equal(persisted.at(-1).phase, 'finalizing'); + reporter.close(); +}); + test('emits an unpersisted 20-second heartbeat and closes idempotently', async () => { const lines = []; const persisted = []; From 2f84fd8d34e3851bcb9b6f98ac6e8c6663bdcd34 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 04:38:39 +0800 Subject: [PATCH 23/27] fix: emit coalesced progress when persisted --- scripts/lib/progress.mjs | 20 +++++++++++--------- tests/progress.test.mjs | 14 +++++++++----- 2 files changed, 20 insertions(+), 14 deletions(-) diff --git a/scripts/lib/progress.mjs b/scripts/lib/progress.mjs index d62ee25b..eeebc4c6 100644 --- a/scripts/lib/progress.mjs +++ b/scripts/lib/progress.mjs @@ -72,6 +72,12 @@ export function createProgressReporter({ /** @type {unknown} */ let reporterError; const recordError = (/** @type {unknown} */ error) => { if (!hasReporterError) { hasReporterError = true; reporterError = error; } }; + /** @param {{phase:string,message:string,observedAt:string}} event */ + const writeEvent = (event) => { + if (typeof write !== 'function') return; + try { write(`[zcode] ${event.message}\n`); } + catch (error) { recordError(error); } + }; /** @type {any} */ let timer = null; const startTimer = () => { @@ -90,6 +96,7 @@ export function createProgressReporter({ /** @param {{phase:string,message:string,observedAt:string}} event */ const startPersist = (event) => { if (typeof persist !== 'function') return; + writeEvent(event); let operation; try { operation = Promise.resolve(persist(event)); } catch (error) { recordError(error); operation = Promise.resolve(); } @@ -102,11 +109,10 @@ export function createProgressReporter({ }; /** @param {{phase:string,message:string,observedAt:string}} event */ const enqueue = (event) => { - if (typeof persist !== 'function') return true; - if (inFlight === null) { startPersist(event); return true; } - if (pending.length < MAX_PROGRESS_PENDING_EVENTS) { pending.push(event); return true; } + if (typeof persist !== 'function') { writeEvent(event); return; } + if (inFlight === null) { startPersist(event); return; } + if (pending.length < MAX_PROGRESS_PENDING_EVENTS) { pending.push(event); return; } pending[pending.length - 1] = event; - return false; }; /** @param {{phase:string,message:string,observedAt:string}} event */ const dispatch = (event) => { @@ -114,11 +120,7 @@ export function createProgressReporter({ const key = `${event.phase}\u0000${event.message}`; if (key === previousKey) return null; previousKey = key; - const admitted = enqueue(event); - if (admitted && typeof write === 'function') { - try { write(`[zcode] ${event.message}\n`); } - catch (error) { recordError(error); } - } + enqueue(event); return event; }; if (active) startTimer(); diff --git a/tests/progress.test.mjs b/tests/progress.test.mjs index 8112b746..585f643a 100644 --- a/tests/progress.test.mjs +++ b/tests/progress.test.mjs @@ -98,7 +98,7 @@ test('rejects invalid observation timestamps', () => { } }); -test('reports immediately, suppresses consecutive duplicates, and serializes persistence', async () => { +test('reports the in-flight event immediately, suppresses duplicates, and serializes pending output with persistence', async () => { const lines = []; const persistenceStarted = []; const persisted = []; @@ -125,15 +125,16 @@ test('reports immediately, suppresses consecutive duplicates, and serializes per currentTime = '2026-08-08T00:00:01.000Z'; reporter.observe(notification('api_retry')); - assert.deepEqual(lines, [ - '[zcode] ZCode started a tool call.\n', - '[zcode] ZCode is retrying the model request.\n', - ]); + assert.deepEqual(lines, ['[zcode] ZCode started a tool call.\n']); await Promise.resolve(); assert.deepEqual(persistenceStarted, ['ZCode started a tool call.']); releases.shift()(); await secondStarted; assert.deepEqual(persistenceStarted, ['ZCode started a tool call.', 'ZCode is retrying the model request.']); + assert.deepEqual(lines, [ + '[zcode] ZCode started a tool call.\n', + '[zcode] ZCode is retrying the model request.\n', + ]); releases.shift()(); await reporter.flush(); assert.deepEqual(persisted, [ @@ -162,6 +163,9 @@ test('bounds pending persistence and output while retaining the latest event und assert.equal(calls.at(-1).phase, 'finalizing'); assert.equal(calls.at(-1).message, 'ZCode completed the delegated turn.'); assert.equal(persisted.at(-1).phase, 'finalizing'); + assert.equal(lines.length, calls.length); + assert.ok(lines.length <= 1 + progressModule.MAX_PROGRESS_PENDING_EVENTS, lines.length); + assert.equal(lines.at(-1), '[zcode] ZCode completed the delegated turn.\n'); reporter.close(); }); From 0b9441a12291cb9707a6af8e3ec35c1b1df397f9 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 04:50:28 +0800 Subject: [PATCH 24/27] test: stabilize incomplete authorization interrupt --- tests/fixtures/signal-handler-probe.cjs | 4 ++-- tests/integration/companion.test.mjs | 26 ++++++++++++++++++++++++- 2 files changed, 27 insertions(+), 3 deletions(-) diff --git a/tests/fixtures/signal-handler-probe.cjs b/tests/fixtures/signal-handler-probe.cjs index af994b58..b795b19e 100644 --- a/tests/fixtures/signal-handler-probe.cjs +++ b/tests/fixtures/signal-handler-probe.cjs @@ -11,8 +11,8 @@ if (marker) { process.on = function on(event, listener) { if (event !== 'SIGINT') return originalOn.call(this, event, listener); const wrapped = function wrapped(...args) { - writeFileSync(marker, 'handled'); - return Reflect.apply(listener, this, args); + try { return Reflect.apply(listener, this, args); } + finally { writeFileSync(marker, 'handled'); } }; wrappers.set(listener, wrapped); const result = originalOn.call(this, event, wrapped); diff --git a/tests/integration/companion.test.mjs b/tests/integration/companion.test.mjs index d7f50639..1ca2a29f 100644 --- a/tests/integration/companion.test.mjs +++ b/tests/integration/companion.test.mjs @@ -188,6 +188,30 @@ test('real CLI successful status is not flipped by SIGINT during output', async assert.equal(JSON.parse(result.internal).job.status, 'succeeded'); }); +test('signal probe marks handled only after the wrapped handler returns', async (t) => { + const directory = await mkdtemp(join(tmpdir(), 'zcode-signal-probe-')); const marker = join(directory, 'marker.txt'); + const script = ` + const { readFileSync } = require('node:fs'); + const keepAlive = setInterval(() => {}, 1000); + process.on('SIGINT', () => { + process.stdout.write(readFileSync(process.env.ZCODE_SIGNAL_HANDLER_PROBE, 'utf8')); + clearInterval(keepAlive); + setImmediate(() => process.exit(0)); + }); + `; + const child = spawn(process.execPath, ['--require', signalHandlerProbe, '--eval', script], { + env: { ...process.env, ZCODE_SIGNAL_HANDLER_PROBE: marker }, stdio: ['ignore', 'pipe', 'pipe'], shell: false, + }); + let stdout = ''; let exited = false; child.stdout?.on('data', (chunk) => { stdout += chunk; }); + t.after(() => { if (!exited) child.kill('SIGKILL'); }); + const exitPromise = new Promise((resolve, reject) => { child.once('error', reject); child.once('exit', (code, signal) => { exited = true; resolve({ code, signal }); }); }); + await waitFor(async () => await readFile(marker, 'utf8').catch(() => '') === 'ready', 'probe handler was not installed'); + child.kill('SIGINT'); + assert.deepEqual(await exitPromise, { code: 0, signal: null }); + assert.equal(stdout, 'ready'); + assert.equal(await readFile(marker, 'utf8'), 'handled'); +}); + test('foreground SIGINT wins while the protected authorization envelope is incomplete', async (t) => { const context = await fixture(); const marker = join(context.directory, 'signal-handler.txt'); const child = spawn(process.execPath, ['--require', signalHandlerProbe, cli, 'rescue', '--fresh', 'interrupt authorization'], { @@ -208,7 +232,7 @@ test('foreground SIGINT wins while the protected authorization envelope is incom await waitFor(async () => await readFile(marker, 'utf8').catch(() => '') === 'handled', 'SIGINT did not enter the installed handler'); /** @type {NodeJS.Timeout|undefined} */ let exitTimer; - const exit = await Promise.race([exitPromise, new Promise((resolve, reject) => { void resolve; exitTimer = setTimeout(() => { if (!exited) child.kill('SIGKILL'); reject(new Error('foreground process retained incomplete fd3 after SIGINT')); }, 1_000); })]).finally(() => clearTimeout(exitTimer)); + const exit = await Promise.race([exitPromise, new Promise((resolve, reject) => { void resolve; exitTimer = setTimeout(() => reject(new Error('foreground process retained incomplete fd3 after SIGINT')), 5_000); })]).finally(() => clearTimeout(exitTimer)); assert.deepEqual(exit, { code: 130, signal: null }); assert.equal(stdout, ''); assert.equal(internal, ''); From f3384dec4c7351a87b2860b3e645316edb8ff01d Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 04:58:45 +0800 Subject: [PATCH 25/27] test: skip unsupported Windows signal delivery --- tests/integration/companion.test.mjs | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/tests/integration/companion.test.mjs b/tests/integration/companion.test.mjs index 1ca2a29f..5b4e7c20 100644 --- a/tests/integration/companion.test.mjs +++ b/tests/integration/companion.test.mjs @@ -24,6 +24,7 @@ const fakeCodex = join(root, 'tests', 'fixtures', 'fake-codex-app-server.mjs'); const completionSignalProbe = join(root, 'tests', 'fixtures', 'completion-signal-probe.cjs'); const signalHandlerProbe = join(root, 'tests', 'fixtures', 'signal-handler-probe.cjs'); const statusWaitProbe = join(root, 'tests', 'fixtures', 'status-wait-probe.cjs'); +const windowsRealSignalSkip = process.platform === 'win32' ? 'Node child.kill cannot emulate Windows console control events' : false; async function fixture() { const directory = await mkdtemp(join(tmpdir(), 'zcode-companion-')); @@ -135,7 +136,7 @@ test('foreground rescue streams safe progress to stderr and durably exposes it t ]); }); -test('foreground SIGINT stops the accepted ZCode session, exits 130, and leaves no running job', async (t) => { +test('foreground SIGINT stops the accepted ZCode session, exits 130, and leaves no running job', { skip: windowsRealSignalSkip }, async (t) => { const context = await fixture(); const record = join(context.directory, 'interrupt.jsonl'); await writeFile(record, ''); const child = spawn(process.execPath, [cli, 'rescue', '--fresh', 'interrupt me'], { cwd: context.workspace, @@ -198,6 +199,7 @@ test('signal probe marks handled only after the wrapped handler returns', async clearInterval(keepAlive); setImmediate(() => process.exit(0)); }); + setImmediate(() => process.emit('SIGINT')); `; const child = spawn(process.execPath, ['--require', signalHandlerProbe, '--eval', script], { env: { ...process.env, ZCODE_SIGNAL_HANDLER_PROBE: marker }, stdio: ['ignore', 'pipe', 'pipe'], shell: false, @@ -205,14 +207,12 @@ test('signal probe marks handled only after the wrapped handler returns', async let stdout = ''; let exited = false; child.stdout?.on('data', (chunk) => { stdout += chunk; }); t.after(() => { if (!exited) child.kill('SIGKILL'); }); const exitPromise = new Promise((resolve, reject) => { child.once('error', reject); child.once('exit', (code, signal) => { exited = true; resolve({ code, signal }); }); }); - await waitFor(async () => await readFile(marker, 'utf8').catch(() => '') === 'ready', 'probe handler was not installed'); - child.kill('SIGINT'); assert.deepEqual(await exitPromise, { code: 0, signal: null }); assert.equal(stdout, 'ready'); assert.equal(await readFile(marker, 'utf8'), 'handled'); }); -test('foreground SIGINT wins while the protected authorization envelope is incomplete', async (t) => { +test('foreground SIGINT wins while the protected authorization envelope is incomplete', { skip: windowsRealSignalSkip }, async (t) => { const context = await fixture(); const marker = join(context.directory, 'signal-handler.txt'); const child = spawn(process.execPath, ['--require', signalHandlerProbe, cli, 'rescue', '--fresh', 'interrupt authorization'], { cwd: context.workspace, @@ -527,7 +527,7 @@ test('real CLI status wait stays alive until its timeout', async () => { assert.equal(waited.code, 1); assert.equal(waited.json.error.code, 'JOB_WAIT_TIMEOUT'); }); -test('real CLI status wait exits immediately without protocol output on SIGINT', async (t) => { +test('real CLI status wait exits immediately without protocol output on SIGINT', { skip: windowsRealSignalSkip }, async (t) => { const context = await fixture(); const marker = join(context.directory, 'status-wait.txt'); const store = createStateStore({ dataRoot: context.dataRoot }); const queued = await store.reserveJob({ workspace: context.workspace, ownerSessionId: 'codex-session', ownerTurnId: 'turn-1', command: 'rescue', readOnly: false, permissionSnapshot: { permissionMode: 'workspace-write' } }); @@ -555,7 +555,7 @@ test('real CLI status wait exits immediately without protocol output on SIGINT', assert.equal((await store.readJob(context.workspace, queued.id)).status, 'running'); }); -test('foreground Transfer observes SIGTERM after its bounded create RPC and exits 143', async (t) => { +test('foreground Transfer observes SIGTERM after its bounded create RPC and exits 143', { skip: windowsRealSignalSkip }, async (t) => { const context = await fixture(); const zcodeRecord = join(context.directory, 'transfer-interrupt.jsonl'); await writeFile(zcodeRecord, ''); const sourceThread = { id: 'codex-session', ephemeral: false, turns: [{ startedAt: 1_725_000_000, items: [{ type: 'agentMessage', text: 'visible response' }] }] }; const child = spawn(process.execPath, [cli, 'transfer'], { From 9101e03c35899c4b948c50e07e9ef7a4e8d1f240 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 07:55:09 +0800 Subject: [PATCH 26/27] fix: close interrupted authorization pipes --- scripts/zcode-companion.mjs | 37 ++++++++++----- .../fixtures/internal-reader-abort-child.mjs | 16 +++++++ tests/recovery.test.mjs | 45 ++++++++++++++++++- 3 files changed, 87 insertions(+), 11 deletions(-) create mode 100644 tests/fixtures/internal-reader-abort-child.mjs diff --git a/scripts/zcode-companion.mjs b/scripts/zcode-companion.mjs index 2b5e0086..64ddfa07 100644 --- a/scripts/zcode-companion.mjs +++ b/scripts/zcode-companion.mjs @@ -1,7 +1,7 @@ #!/usr/bin/env node import process from 'node:process'; import { createHash, randomBytes } from 'node:crypto'; -import { closeSync as closeFdSync, createReadStream, realpathSync } from 'node:fs'; +import { closeSync as closeFdSync, realpathSync } from 'node:fs'; import { Socket } from 'node:net'; import { fileURLToPath } from 'node:url'; import { join, resolve, sep } from 'node:path'; @@ -251,22 +251,39 @@ async function validateResumeCandidate(store, workspace, ownerSessionId, spec) { if (candidate.ownerSessionId !== ownerSessionId || candidate.command !== 'rescue' || candidate.zcodeSessionId !== spec.resumeSessionId || !['running', 'succeeded', 'failed'].includes(candidate.status)) throw new PluginError('RESUME_CANDIDATE_INVALID', 'The bound rescue candidate is no longer eligible.', { category: 'authorization', remedy: 'Reserve a fresh rescue job.' }); } -/** @param {number} [fd] @param {{maxBytes?:number,timeoutMs?:number,signal?:AbortSignal}} [options] */ +/** @param {number} [fd] @param {{maxBytes?:number,timeoutMs?:number,signal?:AbortSignal,createStream?:(fd:number)=>any}} [options] */ export function readInternalEnvelope(fd = 3, options = {}) { const maxBytes = options.maxBytes ?? 64 * 1024; const timeoutMs = options.timeoutMs ?? 5_000; if (!Number.isSafeInteger(fd) || fd < 3 || !Number.isSafeInteger(maxBytes) || maxBytes <= 0 || !Number.isSafeInteger(timeoutMs) || timeoutMs <= 0) throw authorizationInputError(); options.signal?.throwIfAborted(); return new Promise((resolvePromise, reject) => { - const stream = createReadStream('', { fd, autoClose: false }); let data = ''; let bytes = 0; let settled = false; + const stream = options.createStream?.(fd) ?? new Socket({ fd, readable: true, writable: false }); + let data = ''; let bytes = 0; let settled = false; let closed = false; let cleaned = false; + /** @type {{resolve:true,value:any}|{resolve:false,value:unknown}|null} */ + let outcome = null; + /** @type {NodeJS.Timeout|undefined} */ let timer; let removeAbortListener = () => {}; - /** @param {()=>void} callback @param {boolean} [closeDescriptor] */ - const finish = (callback, closeDescriptor = false) => { if (settled) return; settled = true; clearTimeout(timer); removeAbortListener(); stream.destroy(); if (closeDescriptor) try { closeFdSync(fd); } catch { /* abort cleanup must not replace the signal reason */ } callback(); }; - const timer = setTimeout(() => finish(() => reject(authorizationInputError())), timeoutMs); - stream.on('data', (chunk) => { bytes += chunk.length; if (bytes > maxBytes) finish(() => reject(authorizationInputError())); else data += chunk.toString('utf8'); }); - stream.once('error', () => finish(() => reject(authorizationInputError()))); - stream.once('end', () => finish(() => { try { resolvePromise(JSON.parse(data)); } catch { reject(authorizationInputError()); } })); + const cleanup = () => { if (cleaned) return; cleaned = true; if (timer) clearTimeout(timer); removeAbortListener(); }; + const settleAfterClose = () => { + if (settled || !closed || !outcome) return; + settled = true; cleanup(); + if (outcome.resolve) resolvePromise(outcome.value); else reject(outcome.value); + }; + /** @param {boolean} resolve @param {unknown} value */ + const finish = (resolve, value) => { + if (outcome) return; + outcome = resolve ? { resolve: true, value } : { resolve: false, value }; + cleanup(); + if (!stream.destroyed) stream.destroy(); + settleAfterClose(); + }; + stream.once('close', () => { closed = true; if (!outcome) outcome = { resolve: false, value: authorizationInputError() }; settleAfterClose(); }); + stream.on('data', (/** @type {Buffer} */ chunk) => { if (outcome) return; bytes += chunk.length; if (bytes > maxBytes) finish(false, authorizationInputError()); else data += chunk.toString('utf8'); }); + stream.once('error', () => finish(false, authorizationInputError())); + stream.once('end', () => { try { finish(true, JSON.parse(data)); } catch { finish(false, authorizationInputError()); } }); + timer = setTimeout(() => finish(false, authorizationInputError()), timeoutMs); if (options.signal) { - const onAbort = () => finish(() => reject(options.signal?.reason), true); + const onAbort = () => finish(false, options.signal?.reason); options.signal.addEventListener('abort', onAbort, { once: true }); removeAbortListener = () => options.signal?.removeEventListener('abort', onAbort); if (options.signal.aborted) onAbort(); diff --git a/tests/fixtures/internal-reader-abort-child.mjs b/tests/fixtures/internal-reader-abort-child.mjs new file mode 100644 index 00000000..49476e77 --- /dev/null +++ b/tests/fixtures/internal-reader-abort-child.mjs @@ -0,0 +1,16 @@ +import process from 'node:process'; + +import { PluginError } from '../../scripts/lib/errors.mjs'; +import { readInternalEnvelope } from '../../scripts/zcode-companion.mjs'; + +const controller = new AbortController(); +const interruption = new PluginError('JOB_INTERRUPTED', 'reader interrupted'); +const reading = readInternalEnvelope(3, { signal: controller.signal }); +setImmediate(() => controller.abort(interruption)); +try { + await reading; + throw new Error('read unexpectedly completed'); +} catch (error) { + if (error !== interruption) throw error; + process.stdout.write('rejected-original\n'); +} diff --git a/tests/recovery.test.mjs b/tests/recovery.test.mjs index 8e2a0632..8ad93f9b 100644 --- a/tests/recovery.test.mjs +++ b/tests/recovery.test.mjs @@ -1,6 +1,7 @@ // @ts-nocheck import assert from 'node:assert/strict'; import { execFile, spawn } from 'node:child_process'; +import { EventEmitter } from 'node:events'; import { closeSync, constants, openSync } from 'node:fs'; import { mkdir, mkdtemp, readFile, readdir, rm, writeFile } from 'node:fs/promises'; import { Socket } from 'node:net'; @@ -11,6 +12,7 @@ import { promisify } from 'node:util'; import { fileURLToPath } from 'node:url'; import { createIdentityStore } from '../scripts/lib/identity.mjs'; +import { PluginError } from '../scripts/lib/errors.mjs'; import { atomicWriteJson } from '../scripts/lib/fs.mjs'; import { createJobController, ownerIdForSession } from '../scripts/lib/job-control.mjs'; import { buildPrompt } from '../scripts/lib/prompts.mjs'; @@ -18,9 +20,10 @@ import { loadReviewOutputSchema, validateJsonSchema } from '../scripts/lib/revie import { createStateStore } from '../scripts/lib/state.mjs'; import { resolveWorkspaceStorage } from '../scripts/lib/workspace.mjs'; import { releaseManagedZCodeOwner } from '../scripts/lib/zcode-client.mjs'; -import { failBackgroundDelivery, runCompanion, writeInternalResponse } from '../scripts/zcode-companion.mjs'; +import { failBackgroundDelivery, readInternalEnvelope, runCompanion, writeInternalResponse } from '../scripts/zcode-companion.mjs'; const writerProbe = fileURLToPath(new URL('./fixtures/internal-writer-child.mjs', import.meta.url)); +const readerAbortProbe = fileURLToPath(new URL('./fixtures/internal-reader-abort-child.mjs', import.meta.url)); const cancellingHolder = fileURLToPath(new URL('./fixtures/cancelling-holder.mjs', import.meta.url)); const companionCli = fileURLToPath(new URL('../scripts/zcode-companion.mjs', import.meta.url)); const fakeZCode = fileURLToPath(new URL('./fixtures/fake-zcode-cli.mjs', import.meta.url)); @@ -345,6 +348,46 @@ test('internal response writer handles partial writes and stable pipe failures', for (const code of ['EPIPE', 'EBADF']) await assert.rejects(writeInternalResponse({ ok: true }, 44, { timeoutMs: 100, write: (_fd, _buffer, _offset, _length, _position, callback) => queueMicrotask(() => callback(Object.assign(new Error(code), { code }), 0)) }), { code: 'INTERNAL_RESPONSE_WRITE_FAILED' }); }); +test('aborting a real fd3 read rejects the original reason and releases the child process', async (t) => { + const child = spawn(process.execPath, [readerAbortProbe], { stdio: ['ignore', 'pipe', 'pipe', 'pipe'] }); + let stdout = ''; let stderr = ''; let exited = false; + child.stdout.on('data', (chunk) => { stdout += chunk; }); child.stderr.on('data', (chunk) => { stderr += chunk; }); + t.after(() => { child.stdio[3]?.destroy(); if (!exited) child.kill('SIGKILL'); }); + const exitPromise = new Promise((resolve, reject) => { child.once('error', reject); child.once('exit', (code, signal) => { exited = true; resolve({ code, signal }); }); }); + /** @type {NodeJS.Timeout|undefined} */ let deadline; + const exit = await Promise.race([exitPromise, new Promise((resolve, reject) => { void resolve; deadline = setTimeout(() => reject(new Error('aborted fd3 reader retained its pipe handle')), 2_000); })]).finally(() => clearTimeout(deadline)); + assert.deepEqual(exit, { code: 0, signal: null }, stderr); + assert.equal(stdout, 'rejected-original\n'); +}); + +test('internal envelope abort waits for the owned read stream to close', async () => { + const stream = new EventEmitter(); stream.destroyed = false; let destroys = 0; + stream.destroy = () => { stream.destroyed = true; destroys += 1; }; + const controller = new AbortController(); const interruption = new PluginError('JOB_INTERRUPTED', 'wait for close'); + let settled = false; + const reading = readInternalEnvelope(33, { signal: controller.signal, createStream: () => stream }); + reading.then(() => { settled = true; }, () => { settled = true; }); + controller.abort(interruption); + await new Promise((resolve) => setImmediate(resolve)); + assert.equal(destroys, 1); assert.equal(settled, false); + stream.emit('close'); + await assert.rejects(reading, (error) => error === interruption); +}); + +test('internal envelope closes its owned stream once on success, error, and timeout', async () => { + for (const mode of ['success', 'error', 'timeout']) { + const stream = new EventEmitter(); stream.destroyed = false; let destroys = 0; + stream.destroy = () => { stream.destroyed = true; destroys += 1; queueMicrotask(() => stream.emit('close')); }; + const reading = readInternalEnvelope(33, { timeoutMs: 5, createStream: () => stream }); + if (mode === 'success') { stream.emit('data', Buffer.from('{"ok":true}')); stream.emit('end'); } + if (mode === 'error') stream.emit('error', new Error('pipe failed')); + if (mode === 'success') assert.deepEqual(await reading, { ok: true }); + else await assert.rejects(reading, { code: 'INTERNAL_AUTHORIZATION_INVALID' }); + await new Promise((resolve) => setTimeout(resolve, 10)); + assert.equal(destroys, 1, mode); + } +}); + test('internal response writer times out without blocking the event loop and closes once', async () => { let closes = 0; let ticked = false; setImmediate(() => { ticked = true; }); await assert.rejects(writeInternalResponse({ ok: true }, 44, { timeoutMs: 10, write: () => {}, close: (_fd, callback) => { closes += 1; callback(); } }), { code: 'INTERNAL_RESPONSE_WRITE_TIMEOUT' }); From 6f6dbc14518708609511d424d6b8bcedf5edfee6 Mon Sep 17 00:00:00 2001 From: vitry Date: Sat, 8 Aug 2026 07:57:20 +0800 Subject: [PATCH 27/27] fix: normalize authorization stream creation errors --- scripts/zcode-companion.mjs | 4 +++- tests/recovery.test.mjs | 9 +++++++++ 2 files changed, 12 insertions(+), 1 deletion(-) diff --git a/scripts/zcode-companion.mjs b/scripts/zcode-companion.mjs index 64ddfa07..3c4eef08 100644 --- a/scripts/zcode-companion.mjs +++ b/scripts/zcode-companion.mjs @@ -257,7 +257,9 @@ export function readInternalEnvelope(fd = 3, options = {}) { if (!Number.isSafeInteger(fd) || fd < 3 || !Number.isSafeInteger(maxBytes) || maxBytes <= 0 || !Number.isSafeInteger(timeoutMs) || timeoutMs <= 0) throw authorizationInputError(); options.signal?.throwIfAborted(); return new Promise((resolvePromise, reject) => { - const stream = options.createStream?.(fd) ?? new Socket({ fd, readable: true, writable: false }); + let stream; + try { stream = options.createStream?.(fd) ?? new Socket({ fd, readable: true, writable: false }); } + catch { reject(authorizationInputError()); return; } let data = ''; let bytes = 0; let settled = false; let closed = false; let cleaned = false; /** @type {{resolve:true,value:any}|{resolve:false,value:unknown}|null} */ let outcome = null; diff --git a/tests/recovery.test.mjs b/tests/recovery.test.mjs index 8ad93f9b..22863d8d 100644 --- a/tests/recovery.test.mjs +++ b/tests/recovery.test.mjs @@ -388,6 +388,15 @@ test('internal envelope closes its owned stream once on success, error, and time } }); +test('internal envelope maps synchronous stream construction failures to its stable error', async () => { + await assert.rejects( + readInternalEnvelope(33, { createStream: () => { throw new TypeError('secret unsupported descriptor'); } }), + (error) => error instanceof PluginError + && error.code === 'INTERNAL_AUTHORIZATION_INVALID' + && !error.message.includes('secret'), + ); +}); + test('internal response writer times out without blocking the event loop and closes once', async () => { let closes = 0; let ticked = false; setImmediate(() => { ticked = true; }); await assert.rejects(writeInternalResponse({ ok: true }, 44, { timeoutMs: 10, write: () => {}, close: (_fd, callback) => { closes += 1; callback(); } }), { code: 'INTERNAL_RESPONSE_WRITE_TIMEOUT' });