diff --git a/docs/plans/2026-09-27-ai-workspace-write-status-warning.md b/docs/plans/2026-09-27-ai-workspace-write-status-warning.md new file mode 100644 index 000000000..6a7c77eb8 --- /dev/null +++ b/docs/plans/2026-09-27-ai-workspace-write-status-warning.md @@ -0,0 +1,48 @@ +# An AI Workspace write whose status save fails is reported as done (#1285) + +## Problem +`AiWorkspaceRegistry.writeFile` first replaces the user's file on disk (`atomicWriteTextFile`), then refreshes the entry status. The refresh saves registry state, and a save must first make any preservation copy it owes (#1260: rows the load could not read are copied aside before a save drops them). +- **When the copy is blocked** (for example, a directory sits on `ai-workspaces.json.invalid-.json`), the save throws. `writeFile` then returned `{ ok: false, error: "is a directory" }` although the file was written. +- **What that caused.** An agent or the editor told "failed" retries (converging through the version conflict) or reports a failure that did not happen. +- **Cosmetic.** Refused saves relayed the raw errno text, with no hint that clearing the copy path unblocks them. + +## Evidence +- **The sequence** was reproduced and confirmed by #1260 review B (round 2), and recorded as residual #1285 (steering q24). The owed-copy state itself comes from the real registry file: `testing/fixtures/ai-workspace/real-workspaces-2026-09-25.json`, two real workspaces from the owner's `ai-workspaces.json`. The existing #1260 tests make that state owe a copy by marking one real workspace malformed, and block the copy with a directory. +- **The only consumer** of the write result is the renderer editor over IPC (`src/main/ipc/aiWorkspace.ts` → `AiWorkspaceEditor.tsx`). There is no MCP tool on this path. + +## Decisions (defaults) +1. **A failed status refresh after a successful write does not fail the write.** It returns `ok: true` with an optional `warning` on the success branch of `AiWorkspaceWriteFileResult`, documented as "the file IS written; do not retry". It logs the error, and still emits `file-written` to every workspace holding the file. +2. **The owed-copy invariant is unchanged.** The state file is still never saved while a copy is owed. +3. **A refused save explains itself.** `preserveOwedCopy` rewrites a copy failure: "AI Workspace storage needs attention: N unreadable row(s) must be copied aside before saving, and the copy could not be written (). " (the advice names the state file's folder) Only the errno code is kept, not the raw text. + +## Tests (fail-first, `AiWorkspaceRegistry.test.ts`) +The input is the real recorded workspace state. One real entry is pointed at a temp file (the recorded paths are redacted), and one real workspace is made malformed so a copy is owed. The copy path is blocked with a directory. +- `writeFile` puts the new text on disk and returns `ok: true` with a status warning. The state file is unchanged. Red without the fix: `{ ok: false, error: 'is a directory' }`. +- A following `create` is refused with the actionable message. +- Mutations: dropping the warning, and misreporting the write as failed, each fail the first test. + +## Review a (round 1) +- **The editor showed no warning.** It now keeps a separate `storageWarning`, set from the write result on both Save and Overwrite and cleared by the next write that has no warning. It is shown through the file list's existing alert (`error ?? storageWarning`). It cannot ride `error`, because `loadWorkspace` clears that after every save. +- **The warning is fixed text.** `AI_WORKSPACE_STATUS_NOT_SAVED` is main's own sentence; the raw cause goes only to the log. +- **A throwing `changed` listener no longer fails a landed write.** Each emit is guarded, so every other workspace still hears about the write. +- **Advice matches the cause.** An occupied copy path (EISDIR/EEXIST/ENOTDIR), a missing folder (ENOENT), a permission or read-only refusal, and a full disk each get their own advice. +- **Tests added:** the file reads back after the warning; an ordinary write carries no warning; a throwing listener still gives `ok: true`, and the listener is still called; ENOENT advice. The always-warn, unguarded-emit and wrong-advice mutations each fail. +- **Not tested:** the editor's display of the notice is not covered at the component level (there is no AiWorkspaceEditor renderer harness). The change there is three lines, and it is stated in the body. + +## Review b (round 1) +- **The notice was lost on a workspace switch, and never shown if the switch happened mid-write.** The editor held it only in React state. It is now durable in main: `get` returns a runtime-only `storageWarning` (`AI_WORKSPACE_STORAGE_BLOCKED`) while a copy is owed and its last attempt failed. The flag is set when the copy fails and cleared when it succeeds, and it is never persisted. `loadWorkspace` sets the editor's notice from it on every load, so a remount shows it again. The write-result warning still sets it immediately. +- **Wrong advice for ENOTDIR and EROFS.** ENOTDIR now gets the generic advice, since it means a component of the folder path is a file. EROFS gets its own read-only-volume advice. +- **Surviving mutations, now killed:** + - appending the raw error text to the refusal (asserted absent); + - stopping the fan-out after the first workspace (two-workspace test); + - dropping `get`'s notice. + +## Review c (at 589d42a9; MERGE-READY) +Test-strength notes, not defects: +- The emit on the warning path and the fan-out are now pinned. The two-workspace listener test landed in `d8f1eae6`. +- Four of the six advice branches (EACCES/EPERM, EROFS, ENOSPC, generic) have no test. They are not reachable portably from a unit test without mocking the filesystem module. +- The quoted refusal sentence in this plan and the body is corrected to the code's wording, and a test title is fixed. + +## Verification b +- **The owed copy succeeded, then the state write failed.** `copyBlocked` was already false, so `get` reported nothing, and the editor's next load cleared the notice although the status was unsaved. The registry now also tracks `lastSaveFailed`, set by any failed save step and cleared by a successful save. `get` reports `AI_WORKSPACE_STORAGE_BLOCKED` while the copy is blocked, else `AI_WORKSPACE_STATUS_NOT_SAVED` while the last save failed. +- **Test:** the reviewer's exact sequence on the real recorded state (blocked copy, unblocked, the state path turned into a directory, write, `get`, then a successful save clears it). Red on `2bb9d19c`. diff --git a/docs/plans/2026-09-27-codex-conversations-usermessage.md b/docs/plans/2026-09-27-codex-conversations-usermessage.md new file mode 100644 index 000000000..42c8b9b6c --- /dev/null +++ b/docs/plans/2026-09-27-codex-conversations-usermessage.md @@ -0,0 +1,39 @@ +# Codex 0.157 prompts survive the conversation catalog's no-index fallback (#1363) + +## Evidence +- **The fallback reader.** Without a usable `state_N.sqlite` (missing, failing schema validation, or a rollout the index does not cover), `CodexConversationSource` reads each rollout's head with `readRolloutHead`. That took prompt text ONLY from `event_msg:{type:"user_message"}`. +- **What 0.157 writes instead.** 120 recent local 0.15x rollouts all carry `event_msg:item_completed` with `item.type: 'UserMessage'`: 149 items, each `content: [{type:'text', text, text_elements}]`. None carries a legacy `user_message`. The issue's census found 233 of 233 0.157.x files without the legacy event. +- **Effect.** Every 0.157 row on the degraded path had `userTexts: []`. It was classified `empty` and hidden from the default listing, or lost its label and user activity. + +## Change +`readRolloutHead` also reads `UserMessage` items: the joined text parts, with their record timestamp as user activity. +- **Why the item, not the role-user `response_item`.** Codex builds the item only for what the user sent. The injected AGENTS.md and environment context are role-user response items too, and the item leaves them out, as the index does. +- **Why a file uses one carrier.** Legacy events and items are collected apart. A file with any legacy event uses those alone, so a rollout carrying both shapes never lists its prompt twice. + +## Tests (`codex.userMessage0157.test.ts`) +The fixture `testing/fixtures/conversations/codex-0157/typed-prompt-head.json` is a real 0.157.1 rollout head: `session_meta`, three role-user response items (AGENTS.md, context, the prompt) and the first typed prompt's `UserMessage` item. Text is redacted to the same length. It runs through the real `CodexConversationSource`, with no index beside it. +1. The row's `userTexts` is exactly the typed prompt, not the injected context, and user activity is set. Red on main (`[]`). +2. The same head plus a legacy `user_message` for the same prompt lists it once. Listing both carriers fails this test. + +## Reviews a and b (round 1) +- **Carriers merged, not "legacy wins".** A file with both carriers can hold a prompt only the items have. Both are read in file order, and the same prompt written by both counts once: each carrier consumes a pending match from the other. These are the two carriers Codex's own index reads (`rust-v0.157.1 state/src/extract.rs`). +- **Activity from the tail.** When the 200-record head is truncated, a bounded 512 KiB tail pass takes the newest user timestamp. In 33 of 61 local 0.157.0 files a later prompt lay past the head, one 46.8 h later. `headTruncated` is set as for Claude and Pi. +- **Text and images.** Parts are joined with no separator, as Codex's `UserMessageItem::message()` does. An image-only message reads `[Image]`, Codex's preview text. +- **Comment narrowed.** Older CLIs' UserMessage items can hold injected context or command wrappers. The index lists those too, and `firstUnwrappedPrompt` and classify decide what labels a row. +- **Fixture rebuilt as a CONTIGUOUS real head.** It holds all 10 records from `session_meta` through the first UserMessage of the one local 0.157 file whose first prompt is typed. The expected length and timestamp are recorded independently in the fixture. Composed cases say they are composed. +- **Filed, not fixed here (pre-existing):** #1418 (0.149–0.151 rollouts with no prompt event) and #1419 (search matches injected context). + +## Verification a (round 2) +- **The tail pass missed prompts far back.** In 10 of 46 local 0.157 files with a prompt past the head, that prompt lay wholly before the last 512 KiB, and a record straddling the window's start was dropped. The reader now scans BACKWARD in 512 KiB chunks, carrying each cut line into the next (earlier) chunk, until it finds a user record. It is bounded at 32 MiB, runs only for truncated heads, and is cached by mtime. +- **De-duplication collapsed a prompt repeated in a later turn.** A cross-carrier pair is now matched only within 4 records, since Codex writes the two carriers of one prompt back to back. No local file has both carriers, so there was no recorded distance to calibrate against. +- **Fixture label.** The fixture's `session_meta.cli_version` is 0.157.0; the label is corrected. +- **Tests (red on the previous commit):** a prompt followed by 4 MiB of output; a prompt whose line straddles the last chunk boundary, laid out deterministically; a prompt repeated in a later turn. Dropping the carried partial line fails the straddle test. + +## Verification a (round 3) +- **The exact reported repeat (two records on, 48 h later) still paired.** The pair window is now records AND time: at most 4 records apart and at most 5 s apart. One prompt's two carriers share its instant. +- **A user line longer than two read chunks was lost.** A window with no newline is all one line, so all of it is carried to the next, earlier chunk, and nothing is parsed or dropped. +- **One of 452 files has its newest prompt 55.8 MB from the end, past the 32 MiB bound. Kept by design.** This is the degraded no-index path, rollouts reach gigabytes, and an unbounded scan per discovery is exactly the store-sized cost the head limit prevents. The WHY comment says so. + +## Verification b (at bb183091) +- **A pair crossed an intervening prompt** (`repeat`, `different`, `repeat`, seconds apart). Fixed: a carrier pairs only with the IMMEDIATELY previous user record, which must be the other carrier, within 4 records and 5 s. Test: `start, repeat, different, repeat` keeps all four. It is red on `456e6e1b`. +- **The 32 MiB residual** (the same one file) is the deliberate bound documented at `456e6e1b`. diff --git a/docs/plans/2026-09-27-codex-exec-wrapped-output.md b/docs/plans/2026-09-27-codex-exec-wrapped-output.md new file mode 100644 index 000000000..ba0b6c08b --- /dev/null +++ b/docs/plans/2026-09-27-codex-exec-wrapped-output.md @@ -0,0 +1,34 @@ +# Codex exec_command results survive in resumed history (#1321) + +## Evidence +- **Census of 2,541 local rollouts.** It found 85,355 `function_call_output` lines whose output is wrapped: `Chunk ID:`, `Wall time:`, `Process exited with code N`, `Original token count:`, then `Output:`. It found **0** `exec_command_end` events in any file. +- **Current Codex never writes that event.** codex-rs `rollout/src/policy.rs` puts `EventMsg::ExecCommandEnd` under "Transient, non-durable events". rust-v0.107.0 through v0.136.0 did persist it in extended-history mode (review a), and none of the local rollouts use that mode. +- **The drop rule.** `mapCodexRolloutToFeedEntries` drops every wrapped output that has an exit line (`isCodexExecWrapperOutput`), on the stated belief that "the correlated `exec_command_end` event carries the same result". That belief is false, so the dropped line was the only copy. Every `exec_command` card in resumed history showed no output and no exit status. That covers Codex through 0.144: `exec_command` wrapped outputs occur in 0.1xx through 0.144, and 0.15x uses the `exec` tool. +- **A second bug.** The predicate searched the WHOLE string for "Process exited with code". A still-running chunk whose command output contains those words was dropped too. + +## Change +- **Header-only parsing.** `codexExecWrapperExitCode(output)` reads the exit code from the header only, the part before `\nOutput:\n`. It returns null for unwrapped output and for a still-running chunk. +- **Keep the result.** A wrapped, finished output now maps to a tool result with: + - the stripped output (possibly empty); + - `is_error = exitCode !== 0`; + - the same `codex` metadata the event branch produces (`kind: 'exec_command_end'`, `exitCode`, empty `parsedCmd` and `command`, null `cwd`). + + So the command adapter reads it as the native transport it is: exit-proven, the output owned, and an empty success absorbed by the row dispatcher as before. +- **Comments corrected.** The stale comments that say the wrapper comes from, or is duplicated by, `exec_command_end` are fixed. + +## Tests +`execWrappedOutput.test.ts` runs three real 0.132.0 pairs (exit 0 with output, exit 1, exit 0 with no output) through the real mapper and the real `fromCodexCommandOperation`, plus a still-running chunk whose body contains the exit words. All four are red on main. + +## Not in scope +The 0.15x `exec` tool's `custom_tool_call_output` results are a different carrier, already handled by the code-mode envelope path. + +## Review a (round 1) +- **P1: a running chunk read as a success.** A wrapper whose header says "Process running with session ID N" is a partial chunk. The command's exit arrives on a later `write_stdin` result with another call_id. The adapter's native branch claimed `exitProven: true` for every result, so the card said success. The mapper now marks such a chunk `codex.kind: 'exec_command_running'`, and the adapter does not claim a proven exit for it, so it shows `unknown`. A first attempt, "no exit code means unproven", also flipped synthetic Git-formatter test results that carry no metadata. The explicit mark keeps the change to the one shape the review found. Correlating the later `write_stdin` exit back to the card by session id is a separate feature, not done here. +- **P2: two carriers.** In extended-history rollouts, one call can have both the event and the wrapper. `createCodexTranscriptEntryMapper` keeps the first exec terminal result per call_id, remembering the last 512 per stream. A pair split across a history page boundary is not caught. +- **P3: no `Output:` marker.** Without the LF `\nOutput:\n` marker the wrapper is not parsed, so no exit claim and no stripping. None of the 85,355 local wrappers lacks it. +- **Unpinned metadata.** The exact `codex` metadata is now asserted, which kills the kind/parsedCmd/command/cwd mutations. + +## Review b (round 2) +- **P2: a wrapper with no LF `Output:` marker still painted success.** The mapper returned a plain, metadata-less result, and the native adapter proves every unmarked result. Any `Chunk ID:` wrapper whose header cannot be parsed is now marked `exec_command_unparsed` and kept whole; the adapter shows `unknown` for it, as for `exec_command_running`. Test: that wrapper, through the adapter, shows `unknown` with a null exit. +- **P2: first-carrier dedupe kept the truncated event.** The persisted event's `aggregated_output` is sanitized to 10,000 bytes, and extended mode persisted it through v0.136.0, not v0.131.0. The wrapper now wins. An event that arrives after its wrapper is dropped. A wrapper that follows its event is kept, and later-wins `buildToolResultIndex` hands the card the wrapper. Codex emits the event before the function result (`ToolEventEmitter::finish`). +- **P2: page and burst boundaries bypass the per-mapper memory.** Accepted and documented. Across a boundary both results are kept and later-wins decides, which again favours the wrapper in Codex's emit order. No local rollout has both carriers. diff --git a/docs/plans/2026-09-27-copy-last-response-failure.md b/docs/plans/2026-09-27-copy-last-response-failure.md new file mode 100644 index 000000000..0219a9ce5 --- /dev/null +++ b/docs/plans/2026-09-27-copy-last-response-failure.md @@ -0,0 +1,36 @@ +# Copy commands say when the clipboard refused (#1250 row 9) + +Short plan: a bug with a known root cause. The row comes from `temp/quality-loop/hunt-c3.md` (row 9, P3). #1250 is a batch issue, so this PR is `Refs #1250`. + +## Outcome +**Copy Last Response** shows "Copied to clipboard" only when the copy happened. When `navigator.clipboard.writeText` rejects (the document is not focused, or permission is denied), it says so in fixed words. The sibling **Copy Resume Command** failure shows fixed words, not the raw DOMException text. + +## Root cause (verified in source, origin/main) +- `paneCommands.ts` `copy-last-assistant.run`: `void navigator.clipboard.writeText(text)`, then an unconditional "Copied to clipboard" toast. A rejection is an unhandled promise, and the toast lies. +- `sessionCommands.ts` `copy-resume-command.run`: catches, but renders `copy failed: ${err.message}` (raw browser text, q22). + +## Design (contract) +- `copy-last-assistant.run` awaits the write. On success: "Copied to clipboard". On rejection: "Couldn't copy to the clipboard. Click into the app and try again." + - Clipboard writes need a focused document; the palette or context menu can leave focus elsewhere. +- `copy-resume-command` uses the same failure sentence. The success toast is unchanged. +- The sentence is a constant: `CLIPBOARD_WRITE_FAILED` in `features/workspace/commands/clipboardFailure.ts`. + +## Tests +New `paneCommands.copy.renderer.test.ts`. The runtime entries are the recorded bundle `testing/fixtures/rendering-bundles/2026-05-20T19-11-51-193-d4a44a16.json`; the clipboard is stubbed (the one edge). +- A rejecting write shows the failure sentence, never "Copied". +- A resolving write shows "Copied to clipboard". +- The resume command's rejection shows the fixed sentence, without the raw text. +- Red on main. + +## Out of scope +- #1250's other rows. +- Debug-panel copy buttons (developer surfaces). + +## Review round 1 (a, b: FIX-BEFORE-MERGE; c: MERGE-READY) +- **a1 (Major): a refused copy reports `ran` to `commands.run` callers.** Declined, with reasons: + - Throwing would make `runGuarded` add its own "Command failed: Copy Last Response" toast, so every human path would get two messages for one failure. + - The `commands.run` contract already says `ran` means only that the dispatcher returned, and tells the caller to observe the app afterwards. +- **a2 (Minor): nothing pinned that the command stays pending until the write settles.** Test added with a deferred write: the command is not settled and silent before the write, then says "Copied". It fails with a fire-and-forget `.then`. +- **b1 (Major): Browser Pocket's pick (no composer) swallowed a refused write and said "Element copied".** It now says the refusal. Test in `pick.renderer.test.ts`, red on the old pick. +- **b2 / c1 (Minor): the wording was compared against the constant only.** It is now asserted literally. +- **c2 (Minor): the assistant-message picker and the code-block picker said "Clipboard write failed".** Both now use the shared sentence. The constant moved to `lib/clipboardFailure.ts`, since four features share it. diff --git a/docs/plans/2026-09-27-feed-debug-forget-generation.md b/docs/plans/2026-09-27-feed-debug-forget-generation.md new file mode 100644 index 000000000..38d9d9cec --- /dev/null +++ b/docs/plans/2026-09-27-feed-debug-forget-generation.md @@ -0,0 +1,12 @@ +# Feed-debug per-session state survives a forget that races a queued append (#1207) + +## Problem +`feedDebugLog.ts` keeps three per-session maps: `lastWrittenFeedDebugId`, `lastWrittenFeedDebugEpoch` and `feedDebugCapState`. `forgetFeedDebugSession` deletes them synchronously. But an append that was queued before the forget, and had not started yet, ran afterwards and wrote them back. Queue settlement only reaps `feedDebugWriteQueues`, so the state stayed for the life of the process. The #1111 reviewer's probe: 100 sessions, 100 dead entries in each map. + +## Fix +- **A per-session token,** captured by each append when it is queued. `forget` deletes it. +- **When an append finishes** (in a `finally`, so a failed write counts too), a token that is no longer current means the session was forgotten meanwhile. The append then deletes the three maps again. +- **The token map is cleared by the same forget,** so it cannot grow either. + +## Test +Real queue ordering, no mocks of the queue: append then forget for 100 sessions, and await the writes. The three maps and the token map must be back to their prior sizes. It was red before the fix (105 vs 5 in each map), and removing the drop is red again. diff --git a/docs/plans/2026-09-27-image-paste-unsupported-provider.md b/docs/plans/2026-09-27-image-paste-unsupported-provider.md new file mode 100644 index 000000000..d00945770 --- /dev/null +++ b/docs/plans/2026-09-27-image-paste-unsupported-provider.md @@ -0,0 +1,36 @@ +# Pasting an image into an agent that cannot take one says so (#1250 row 7) + +Short plan: a bug with a known root cause. The row comes from `temp/quality-loop/hunt-c3.md` (row 7, P3). #1250 is a batch issue, so this PR is `Refs #1250`. + +## Outcome +Only Claude takes pasted images today (`supportsImageAttachments`). In a Codex, OpenCode, Grok or Pi composer, pasting a screenshot does nothing at all. The user now sees " can't take pasted images." when the clipboard holds an image file and no text. + +## Root cause (verified in source, origin/main) +- `useClaudeImagePaste.handlePaste` returns `{ handledImages: false }` at once for a provider without image support. The textarea's default paste of an image-only clipboard inserts nothing, and `usePasteToFocus` appends only text. Nothing is said. + +## Design (contract) +- In that early return, read `clipboardData` synchronously. If it has an `image/*` ITEM and no `text/plain`, show a toast (through the hook's `showToast`, the pane toast): " can't take pasted images." +- **Only an image FILE item with no text counts.** Copying from a web page often carries `` in `text/html` alongside text, and that text paste must stay silent. A mixed image+text paste pastes the text as before, with no toast. +- It still returns `handledImages: false`, so the text routing is unchanged. + +## Tests +New `useClaudeImagePaste.renderer.test.tsx` renders the real hook, with a real PNG from `testing/fixtures/image-reads` placed in a `DataTransfer`. +- Codex, image only: the toast shows. Red on main. +- Codex, image plus text: no toast (the text pastes). +- Codex, text only: no toast. +- Claude, image only: no such toast, and the image is taken (`handledImages: true`, draft images set). + +## Out of scope +- #1250's other rows. +- Image support for other providers. + +## Review round 1 (a, b: FIX-BEFORE-MERGE) +- **b1: an image FILE plus text dropped the image silently** ("see attached" with no attachment). The text still pastes, and the toast says "…only the text was pasted." A file item is strong evidence; only an HTML `` beside text (a web-page copy) stays silent. +- **a2 / b2: an image arriving only as a data-URL `` in text/html, with no text, was silent.** It now counts. +- **a3: an image only the async clipboard API shows was silent.** With nothing else in the event (no text, no HTML, no items), `readImagesFromClipboard` is probed. Paste-to-focus's documented miss of this shape is unchanged (it never calls the hook for it). +- **b3: the wording blamed the provider.** Grok's own TUI attaches clipboard images. The sentence is now about this composer: "Pasted images can't be sent to from this composer." +- **a1 (terminal view): declined.** There the paste goes to the provider's own TUI, which owns image handling (Grok's attaches images); the app's capability flag is about its composer. +- **a4: every provider's wording is tested** (Codex, OpenCode, Grok, Pi). +- `parseImagesFromHtml` uses `querySelectorAll('img')` instead of `doc.images`. It is identical in a browser, and the happy-dom test DOM lacks `images` on a parsed document. +- **c (MERGE-READY, reviewing the round-0 head; test gaps pinned):** a non-image file, a type-less file, a string item typed `image/*`, and a null `clipboardData` stay silent. The Claude case asserts the image is taken. The provider label is covered by the per-provider cases. +- **Verification a (Major): an async-only image via paste-to-focus stayed silent.** That path decided "no image" synchronously and appended empty text. An EMPTY event (no text, no HTML, no items) now goes to the shared handler, which probes it; this also lets Claude attach such an image. Ordinary text never takes the branch, so it is never delayed. Test red on the previous head. diff --git a/docs/plans/2026-09-27-node25-renderer-storage.md b/docs/plans/2026-09-27-node25-renderer-storage.md new file mode 100644 index 000000000..46ae529ec --- /dev/null +++ b/docs/plans/2026-09-27-node25-renderer-storage.md @@ -0,0 +1,14 @@ +# Renderer tests on Node 25: a working DOM Storage (#1212) + +**Reproduced** with `/opt/homebrew/bin/node` v25.5.0: `recentCommandHistory.renderer.test.ts` fails with `window.localStorage.clear is not a function` and a read of `undefined`. Node warns "`--localstorage-file` was provided without a valid path". + +**Cause.** Node 25 enables Web Storage by default. Without `--localstorage-file` its `globalThis.localStorage` is a half-initialised placeholder. Because the global already exists, Vitest's happy-dom environment leaves it in place, so renderer code talks to Node's broken storage instead of the DOM's. + +**Fix.** `testing/setup/storage.ts` `installWorkingStorage()` is called from the renderer setup file. It puts a happy-dom `Storage` on `localStorage` / `sessionStorage` wherever the existing one has no `clear`. On Node 22/24 it is a no-op. + +**Tests.** +- `testing/unit/setupStorage.test.ts` pins the repair against a stand-in with Node 25's shape, because CI runs Node 24. +- `src/renderer/src/app/storageEnvironment.renderer.test.ts` checks that the renderer environment's storage works. +- Verified on Node 25.5.0 and 24.14.1. Without the fix, the storage-using renderer tests fail 1 of 4 files on Node 25. + +**Out of scope.** Any other Node 25 incompatibility in the full suite; this issue is the storage setup. diff --git a/docs/plans/2026-09-27-opencode-serve-startup-under-load.md b/docs/plans/2026-09-27-opencode-serve-startup-under-load.md new file mode 100644 index 000000000..e57be2fca --- /dev/null +++ b/docs/plans/2026-09-27-opencode-serve-startup-under-load.md @@ -0,0 +1,30 @@ +# OpenCode agents start under load: the serve readiness wait measures the right thing (#1355) + +## Problem +`orchestration_create_agent` with kind `opencode` failed three times in about an hour on 2026-09-26/27, from three workers, with "Timed out waiting for …/opencode serve to report its URL". I also hit it on #1352's reviewer c. The load average was 40–70 each time. + +The only deadline on this path is `SpawnedServer`'s `startupTimeoutMs`, a package default of 10 s. The app never passes one: `opencodeSession.ts` builds `OpencodeHeadless` without it, and nothing in the app wraps `headless.start()` in a deadline of its own. + +## Evidence (reproduced on the real bundled binary, OpenCode 1.18.31) +Measured as time to the listen line, with `scratchpad/octime.mjs`: it spawns `opencode serve --hostname 127.0.0.1 --port 0` and times stdout. +- **Idle machine** (load average about 4): 0.57 s, 0.73 s, 0.86 s. +- **Under contention:** 16 CPU burners at nice 10, on a machine other workers were already loading: 43.1 s, 16.7 s, 18.3 s. **Every run became ready.** +- **Conclusion:** the server is healthy but CPU-starved. A fixed 10 s wall-clock deadline sized for an idle machine kills it. + +A hung server (alive, never listening) has not been observed. The existing exit path already fails fast when the process dies (`serve exited before readiness`). + +## Decision (defaults) +- **The app sets the readiness wait to 120 s** by passing `startupTimeoutMs` to `OpencodeHeadless`. The app spawns and owns the process, and the package takes the value as an option, so the fix belongs in the app and needs no package change. + - **Why 120 s:** it is about 3× the worst measured healthy start under load (43 s). It still bounds an alive-but-never-listening server, so the ceiling only bites on a real hang. + - A dead server still fails at once through the exit path, so a crash is not slowed down. +- **Considered and deferred:** a CPU-progress watchdog (fail when the child's CPU time stops rising). It would tell a hang from starvation sooner, but it needs a per-platform CPU probe of a child process (`ps` on macOS/Linux, something else on Windows) and would itself be slow under load. The fixed ceiling covers the observed failure; the watchdog is only worth building if a real hang is recorded. +- **Not the same cause:** #1009 (the opencode-terminal live suite waits for a permission condition) is a different wait. + +## Tests +- **`opencodeSession`:** the spawned headless gets the load-tolerant `startupTimeoutMs`. A test double stands in for `opencode-headless`'s constructor, the true edge here. The package's `SpawnedServer.test.ts` already covers the option's behaviour. +- **Real mechanism:** an OpenCode session started against a stub `opencode` binary that reports its URL after 11 s (past the old deadline) reaches the server instead of rejecting. + +## Round 1 review decisions (#1367) +- **a (major): orchestration still loses a start slower than 30 s.** The bridge rejects `create-agent` at 30 s with an unknown outcome. The late-adopted child never gets its bootstrap prompt. This is the orchestration bridge's own deadline, pre-existing and shared by every provider, so it is filed as #1370 and not changed here. Changing it means choosing between late bootstrap delivery and MCP-client timeouts. With this PR, starts that finish between 10 and 30 s now succeed through orchestration too; two of the three recorded contended starts took 16.7 and 18.3 s. So this PR is `Refs #1355`, and #1355 stays open until #1370 lands. +- **a (minor): the package's forwarding was untested.** A system test now goes through `OpencodeHeadless` (`resolveServerUrl` → `SpawnedServer`) with the app's option, and dropping the forwarding fails it. +- **a (surviving mutant): 44 s passed the margin check.** The test now requires at least twice the worst healthy start measured. diff --git a/src/main/aiWorkspace/AiWorkspaceRegistry.test.ts b/src/main/aiWorkspace/AiWorkspaceRegistry.test.ts index 4b710796c..68c6edc6f 100644 --- a/src/main/aiWorkspace/AiWorkspaceRegistry.test.ts +++ b/src/main/aiWorkspace/AiWorkspaceRegistry.test.ts @@ -3,7 +3,7 @@ import { tmpdir } from 'os' import { dirname, join } from 'path' import { afterEach, describe, expect, it } from 'vitest' -import { AiWorkspaceRegistry } from './AiWorkspaceRegistry.js' +import { AI_WORKSPACE_STATUS_NOT_SAVED, AI_WORKSPACE_STORAGE_BLOCKED, AiWorkspaceRegistry } from './AiWorkspaceRegistry.js' const tempRoots: string[] = [] @@ -287,3 +287,172 @@ describe('malformed rows in a real registry (#1246)', () => { expect(await registry.list()).toHaveLength(2) }) }) + +// #1285 (residual of #1260 review B, round 2): the registry owes a +// preservation copy of rows it could not read, and that copy is blocked (a +// directory sits on its path). The user's file write succeeds; only the status +// refresh that follows it, which saves state and so must make the owed copy +// first, fails. Reporting the WRITE as failed told the editor (and an agent) +// that the edit had not landed when it had. +// +// The state is the REAL recorded registry (two workspaces from the owner's +// ai-workspaces.json). Its paths are redacted, so one real entry is pointed at +// a temp file; one real workspace is made malformed, exactly as the #1260 +// owed-copy tests do, so a copy is owed. +describe('a write whose status refresh cannot be saved (#1285)', () => { + it('reports the write as done, with a warning, when only the status save fails', async () => { + const recorded = JSON.parse(await readFile(join(import.meta.dirname, + '../../../testing/fixtures/ai-workspace/real-workspaces-2026-09-25.json'), 'utf8')) as { + state: { workspaces: Array> } + } + const state = recorded.state + const root = await mkdtemp(join(tmpdir(), 'agent-code-ai-workspace-owed-')) + tempRoots.push(root) + const filePath = join(root, 'attached.txt') + await writeFile(filePath, 'v1') + state.workspaces[0]!.entries[0]!.path = filePath + state.workspaces[0]!.entries[0]!.projectRoot = root + state.workspaces[1]!.updatedAt = 1789000000 + const statePath = join(root, 'ai-workspaces.json') + const source = JSON.stringify(state) + await writeFile(statePath, source) + const { createHash } = await import('node:crypto') + const { mkdir } = await import('fs/promises') + await mkdir(join(root, `ai-workspaces.json.invalid-${createHash('sha256').update(source).digest('hex').slice(0, 16)}.json`)) + + const registry = new AiWorkspaceRegistry(statePath) + const target = await realpath(filePath) + const result = await registry.writeFile({ path: target, text: 'v2' }) + + // The write landed, and the result says so, with the status failure as a + // warning rather than as the outcome. + expect(await readFile(target, 'utf8')).toBe('v2') + expect(result).toMatchObject({ ok: true, path: target }) + expect((result as { warning?: string }).warning).toBe(AI_WORKSPACE_STATUS_NOT_SAVED) + // The file stays fully usable: it reads back through the registry. + expect(await registry.readFile(target)).toMatchObject({ ok: true, text: 'v2' }) + // The stored state was not rewritten: the owed copy still blocks saves. + expect(await readFile(statePath, 'utf8')).toBe(source) + // A refused save says why and how to unblock it, not the raw errno text. + const refusal = await registry.create({ name: 'Blocked' }).then(() => null, (err: Error) => err.message) + expect(refusal).toMatch(/needs attention.*\(EISDIR\).*already occupies the copy path/s) + // Only the code, never the raw filesystem message. + expect(refusal).not.toMatch(/illegal operation|is a directory/i) + + // #1416 review b: every LOAD reports the blocked storage, so an editor + // that remounts (a workspace switch) still shows it. + const workspaceId = state.workspaces[0]!.workspaceId as string + expect((await registry.get(workspaceId))?.storageWarning).toBe(AI_WORKSPACE_STORAGE_BLOCKED) + // Unblocked: the next save writes the copy and the notice clears. + await rm(join(root, `ai-workspaces.json.invalid-${createHash('sha256').update(source).digest('hex').slice(0, 16)}.json`), { recursive: true }) + await registry.create({ name: 'Now' }) + expect((await registry.get(workspaceId))?.storageWarning).toBeUndefined() + // It was never persisted. + expect(await readFile(statePath, 'utf8')).not.toContain('storageWarning') + }) + + it('keeps reporting an unsaved status when the copy succeeds but the state write fails', async () => { + // #1416 verification b: copy blocked, then unblocked, then the state file + // itself cannot be written (its path became a directory). copyBlocked is + // false by then, so `get` must still report the unsaved status until a + // state save really succeeds. + const recorded = JSON.parse(await readFile(join(import.meta.dirname, + '../../../testing/fixtures/ai-workspace/real-workspaces-2026-09-25.json'), 'utf8')) as { + state: { workspaces: Array> } + } + const state = recorded.state + const root = await mkdtemp(join(tmpdir(), 'agent-code-ai-workspace-statewrite-')) + tempRoots.push(root) + const filePath = join(root, 'attached.txt') + await writeFile(filePath, 'v1') + state.workspaces[0]!.entries[0]!.path = filePath + state.workspaces[0]!.entries[0]!.projectRoot = root + state.workspaces[1]!.updatedAt = 1789000000 + const statePath = join(root, 'ai-workspaces.json') + const source = JSON.stringify(state) + await writeFile(statePath, source) + const { createHash } = await import('node:crypto') + const { mkdir } = await import('fs/promises') + const copyPath = join(root, `ai-workspaces.json.invalid-${createHash('sha256').update(source).digest('hex').slice(0, 16)}.json`) + await mkdir(copyPath) + const registry = new AiWorkspaceRegistry(statePath) + const workspaceId = state.workspaces[0]!.workspaceId as string + expect((await registry.get(workspaceId))?.storageWarning).toBe(AI_WORKSPACE_STORAGE_BLOCKED) + + await rm(copyPath, { recursive: true }) + await rm(statePath) + await mkdir(statePath) + const target = await realpath(filePath) + const result = await registry.writeFile({ path: target, text: 'v2' }) + expect(result).toMatchObject({ ok: true, warning: AI_WORKSPACE_STATUS_NOT_SAVED }) + expect(await readFile(copyPath, 'utf8')).toBe(source) + expect((await registry.get(workspaceId))?.storageWarning).toBe(AI_WORKSPACE_STATUS_NOT_SAVED) + + // Once the state file can be written again, a save clears it. + await rm(statePath, { recursive: true }) + await registry.create({ name: 'Now' }) + expect((await registry.get(workspaceId))?.storageWarning).toBeUndefined() + }) + + it('gives no warning on an ordinary write, and a throwing listener does not fail it', async () => { + // #1416 review a: a throwing `changed` listener (the production one + // broadcasts to every window) turned a landed write into `ok: false`, + // and stopped the second workspace hearing about it. + const { registry, filePath } = await registryWithAttachedFile('v1') + await registry.list() + const heard: string[] = [] + registry.on('changed', (event: { workspaceId: string }) => { + heard.push(event.workspaceId) + throw new Error('event delivery failed') + }) + const result = await registry.writeFile({ path: filePath, text: 'v2' }) + expect(result).toMatchObject({ ok: true }) + expect(result).not.toHaveProperty('warning') + expect(await readFile(filePath, 'utf8')).toBe('v2') + expect(heard).toEqual(['workspace-1']) + }) + + it('tells every workspace holding the file, even when the first listener call throws', async () => { + const root = await mkdtemp(join(tmpdir(), 'agent-code-ai-workspace-fanout-')) + tempRoots.push(root) + const filePath = join(root, 'shared.txt') + await writeFile(filePath, 'v1') + const entry = (entryId: string) => ({ + entryId, path: filePath, projectRoot: root, title: 'shared.txt', attachedAt: '2026-01-01T00:00:00.000Z', + status: { exists: true, readable: true, staleReason: null, size: 2, mtimeMs: null }, + }) + const workspace = (workspaceId: string) => ({ + workspaceId, name: workspaceId, createdAt: '2026-01-01T00:00:00.000Z', updatedAt: '2026-01-01T00:00:00.000Z', entries: [entry(`${workspaceId}-e`)], + }) + const statePath = join(root, 'ai-workspaces.json') + await writeFile(statePath, JSON.stringify({ workspaces: [workspace('ws-a'), workspace('ws-b')] })) + const registry = new AiWorkspaceRegistry(statePath) + await registry.list() + const heard: string[] = [] + registry.on('changed', (event: { workspaceId: string }) => { + heard.push(event.workspaceId) + throw new Error('event delivery failed') + }) + const result = await registry.writeFile({ path: await realpath(filePath), text: 'v2' }) + expect(result).toMatchObject({ ok: true }) + expect(heard.sort()).toEqual(['ws-a', 'ws-b']) + }) + + it('gives advice that matches the cause when the owed copy cannot be written', async () => { + // A missing state folder is not "something occupies the path". + const root = await mkdtemp(join(tmpdir(), 'agent-code-ai-workspace-enoent-')) + tempRoots.push(root) + const stateDir = join(root, 'state') + const { mkdir } = await import('fs/promises') + await mkdir(stateDir) + const statePath = join(stateDir, 'ai-workspaces.json') + const source = JSON.stringify({ workspaces: [null] }) + await writeFile(statePath, source) + const { createHash } = await import('node:crypto') + await mkdir(join(stateDir, `ai-workspaces.json.invalid-${createHash('sha256').update(source).digest('hex').slice(0, 16)}.json`)) + const registry = new AiWorkspaceRegistry(statePath) + await registry.list() + await rm(stateDir, { recursive: true }) + await expect(registry.create({ name: 'Blocked' })).rejects.toThrow(/\(ENOENT\).*folder holding .* is missing/s) + }) +}) diff --git a/src/main/aiWorkspace/AiWorkspaceRegistry.ts b/src/main/aiWorkspace/AiWorkspaceRegistry.ts index 7572e6671..dcf86b7b2 100644 --- a/src/main/aiWorkspace/AiWorkspaceRegistry.ts +++ b/src/main/aiWorkspace/AiWorkspaceRegistry.ts @@ -161,11 +161,31 @@ export interface AiWorkspaceRegistry { emit(event: 'changed', payload: AiWorkspaceChangeEvent): boolean } +/** The fixed warning a write returns when the file is written but the + * registry could not save its status (#1285). Exported so the editor and + * tests read one sentence. */ +export const AI_WORKSPACE_STATUS_NOT_SAVED = + 'The file was saved, but AI Workspace could not save its status. Other AI Workspace changes will fail until its storage is fixed.' + +/** The fixed notice `get` carries while saves are blocked by an owed copy. */ +export const AI_WORKSPACE_STORAGE_BLOCKED = + 'AI Workspace cannot save changes until its storage is fixed: rows it could not read must be copied aside first, and that copy cannot be written.' + export class AiWorkspaceRegistry extends EventEmitter { private readonly workspaces = new Map() private loadPromise: Promise | null = null /** The loaded file while set-aside rows are not yet preserved; see load(). */ private owedCopy: { text: string; setAside: number } | null = null + // True after the owed copy last FAILED to be written, false once it is + // written. `get` reports it (see AI_WORKSPACE_STORAGE_BLOCKED): a save is + // refused exactly while a copy is owed and cannot be made. + private copyBlocked = false + // True after the last state save failed, whatever step failed; false after + // one succeeds. WHY in addition to copyBlocked (#1416 verification b): the + // owed copy can SUCCEED and the state write then fail. copyBlocked is then + // already false, so `get` reported nothing and the editor's next load + // cleared the notice although the status was still unsaved. + private lastSaveFailed = false private saveQueue: Promise = Promise.resolve() private readonly knownFilePaths = new Set() private readonly gitContextCache = new Map< @@ -262,7 +282,12 @@ export class AiWorkspaceRegistry extends EventEmitter { await this.ensureLoaded() const workspace = this.workspaces.get(workspaceId) if (!workspace) return null - return await this.refreshWorkspace(workspaceId) + const record = await this.refreshWorkspace(workspaceId) + // A copy, so the runtime-only field never reaches the persisted record. + const storageWarning = this.owedCopy && this.copyBlocked + ? AI_WORKSPACE_STORAGE_BLOCKED + : this.lastSaveFailed ? AI_WORKSPACE_STATUS_NOT_SAVED : undefined + return storageWarning ? { ...record, storageWarning } : record } async attachFile(params: AiWorkspaceAttachFileParams): Promise { @@ -413,16 +438,42 @@ export class AiWorkspaceRegistry extends EventEmitter { conflictKind: result.conflictKind, } } - await this.refreshEntriesForPath(target) + // WHY a failed status refresh does not fail the write (#1285): the + // user's file is already replaced on disk by this point. The refresh + // saves registry state, and a save can be refused (a preservation + // copy it owes is blocked; see preserveOwedCopy). Returning + // `ok: false` then told an agent its edit had not landed, so it + // retried or reported a failure that never happened. The write is + // reported as done, and the stale status is a warning. + // + // The warning is a FIXED sentence (#1416 review a): the editor shows + // it, and a raw filesystem message never belongs on a user-visible + // surface. The cause goes to the log. + let warning: string | undefined + try { + await this.refreshEntriesForPath(target) + } catch (err) { + warning = AI_WORKSPACE_STATUS_NOT_SAVED + console.warn('[ai-workspace] status refresh after a write failed:', err) + } // One physical file can be curated into several workspaces. Every // visible consumer needs the write signal; choosing an arbitrary first // workspace would leave the others showing stale buffer metadata. + // + // Each emit is guarded (#1416 review a): a listener that throws (the + // production one broadcasts to every window) must neither turn this + // landed write into `ok: false`, the #1285 failure on another step, + // nor stop the remaining workspaces from hearing about it. for (const workspace of this.workspaces.values()) { if (workspace.entries.some(entry => entry.path === target)) { - this.emit('changed', { - workspaceId: workspace.workspaceId, - kind: 'file-written', - }) + try { + this.emit('changed', { + workspaceId: workspace.workspaceId, + kind: 'file-written', + }) + } catch (err) { + console.warn('[ai-workspace] a file-written listener failed:', err) + } } } return { @@ -431,6 +482,7 @@ export class AiWorkspaceRegistry extends EventEmitter { mtimeMs: result.stat.mtimeMs, size: result.stat.size, version: result.version, + ...(warning ? { warning } : {}), } }) } catch (err) { @@ -605,15 +657,52 @@ export class AiWorkspaceRegistry extends EventEmitter { private async preserveOwedCopy(): Promise { if (!this.owedCopy) return const { text, setAside } = this.owedCopy - const copy = await preserveInvalidBytes(`${this.stateFile}.invalid`, text) + // WHY the error is rewritten (#1285): the raw errno text ("is a + // directory") told the user nothing about why every save was refused or + // how to unblock it. Saves stay refused until the copy exists, because + // the next save drops the unreadable rows. + const copy = await preserveInvalidBytes(`${this.stateFile}.invalid`, text).catch(err => { + this.copyBlocked = true + const code = (err as NodeJS.ErrnoException).code + // WHY the advice depends on the code (#1416 review a): "clear what + // occupies the path" is only true when something occupies it. A + // missing directory, a permission or read-only refusal and a full disk + // each need a different fix, and advice for the wrong one sends the + // user looking for an occupant that does not exist. + // ENOTDIR is NOT an occupant (#1416 review b): it means a component of + // the folder path is a file, so it falls to the generic advice. A + // read-only volume cannot be fixed by permissions. + const advice = code === 'EISDIR' || code === 'EEXIST' + ? `Something already occupies the copy path next to ${this.stateFile}; move it away to continue.` + : code === 'ENOENT' + ? `The folder holding ${this.stateFile} is missing; restore it to continue.` + : code === 'EACCES' || code === 'EPERM' + ? `The folder holding ${this.stateFile} is not writable; fix its permissions to continue.` + : code === 'EROFS' + ? `The folder holding ${this.stateFile} is on a read-only volume; AI Workspace cannot save there.` + : code === 'ENOSPC' + ? 'The disk is full; free some space to continue.' + : `Check that the folder holding ${this.stateFile} exists and is writable to continue.` + throw new Error( + `AI Workspace storage needs attention: ${setAside} unreadable row(s) must be copied aside before saving, ` + + `and the copy could not be written${code ? ` (${code})` : ''}. ${advice}`, + ) + }) this.owedCopy = null + this.copyBlocked = false console.warn(`[ai-workspace] set aside ${setAside} malformed row(s); original preserved at ${copy}`) } private async save(): Promise { const next = this.saveQueue.then(async () => { - await this.preserveOwedCopy() - await this.writeStateFile() + try { + await this.preserveOwedCopy() + await this.writeStateFile() + this.lastSaveFailed = false + } catch (err) { + this.lastSaveFailed = true + throw err + } }) this.saveQueue = next.catch(() => undefined) await next diff --git a/src/main/conversations/sources/codex.ts b/src/main/conversations/sources/codex.ts index 5a25536ca..2a65096aa 100644 --- a/src/main/conversations/sources/codex.ts +++ b/src/main/conversations/sources/codex.ts @@ -1,5 +1,5 @@ import { existsSync } from 'node:fs' -import { readdir, stat } from 'node:fs/promises' +import { open, readdir, stat } from 'node:fs/promises' import { join } from 'node:path' import type { ConversationPrompt } from '@shared/conversations/types.js' @@ -70,6 +70,8 @@ type RolloutHead = { source: string | null userTexts: string[] lastUserAt: number | null + /** The head hit its record bound with no user text (as for Claude and Pi). */ + headTruncated?: boolean } function isSubagentSource(row: IndexRow): boolean { @@ -89,7 +91,51 @@ function isSubagentSource(row: IndexRow): boolean { * contract for a fallback path is not worth a cross-repository change. */ async function readRolloutHead(file: string): Promise { const out: RolloutHead = { cwd: null, gitBranch: null, createdAt: null, originator: null, source: null, userTexts: [], lastUserAt: null } + // Two carriers of a user prompt (#1363). Codex up to 0.14x wrote + // `event_msg:user_message`; 0.157 writes none, and a prompt is + // `event_msg:item_completed` with `item.type: 'UserMessage'` (414 of 416 + // local 0.157 files; the other two are native subagents with no prompt). + // These are exactly the two carriers Codex's own index reads for + // `first_user_message` (rust-v0.157.1 state/src/extract.rs); it ignores the + // role-user response_item, which also carries injected context. WHY both are + // read and merged, not "legacy wins" (#1407 reviews a and b): a file with + // both carriers (a session resumed across writer versions) could then lose + // a prompt only the items hold. The same prompt written by both carriers is + // counted once: see the pairing rule below (the immediately previous user + // record, the other carrier, within 4 records and 5 s). + // What older CLIs put in UserMessage items (sometimes injected context or a + // command wrapper) is what the index lists too; firstUnwrappedPrompt and + // classify decide what is a label, as for every other source. + // WHY a pair is matched only within a few records (#1407 verification a): + // matching identical text anywhere in the head collapsed a prompt the user + // really repeated in a later turn. Codex writes the two carriers of ONE + // prompt back to back, so the other carrier's record must be close. + // Both a record window AND a time window (#1407 verification a, round 2): + // records alone let the same text typed two days later, two records on, + // pass for the other carrier. One prompt's carriers share its instant. + const PAIR_WINDOW_RECORDS = 4 + const PAIR_WINDOW_MS = 5_000 + let lastUser: { carrier: 'legacy' | 'item'; text: string; at: number; ts: number; paired: boolean } | null = null + const noteUser = (carrier: 'legacy' | 'item', text: string, timestamp: unknown, recordIndex: number) => { + const ts = typeof timestamp === 'string' ? Date.parse(timestamp) : NaN + // ...and never across another user prompt (#1407 verification b): the + // other carrier must be the IMMEDIATELY previous user record, so + // `repeat, different, repeat` inside a few seconds keeps both repeats. + const previous = lastUser + const pairs = previous !== null && previous.carrier !== carrier && !previous.paired && + previous.text === text && + recordIndex - previous.at <= PAIR_WINDOW_RECORDS && + Number.isFinite(ts) && Number.isFinite(previous.ts) && Math.abs(ts - previous.ts) <= PAIR_WINDOW_MS + if (pairs) { + previous.paired = true + } else { + lastUser = { carrier, text, at: recordIndex, ts, paired: false } + if (out.userTexts.length < 6) out.userTexts.push(text) + } + if (Number.isFinite(ts)) out.lastUserAt = Math.max(out.lastUserAt ?? ts, ts) + } let records = 0 + let truncated = false for await (const record of streamJsonl>(file)) { if (!record) continue records++ @@ -101,20 +147,134 @@ async function readRolloutHead(file: string): Promise { out.createdAt = typeof payload.timestamp === 'string' && Number.isFinite(Date.parse(payload.timestamp)) ? Date.parse(payload.timestamp) : null out.originator = typeof payload.originator === 'string' ? payload.originator : null out.source = typeof payload.source === 'string' ? payload.source : payload.source ? JSON.stringify(payload.source) : null - } else if (record.type === 'event_msg' && payload?.type === 'user_message' && typeof payload.message === 'string') { - if (out.userTexts.length < 6) out.userTexts.push(payload.message) - const ts = typeof record.timestamp === 'string' ? Date.parse(record.timestamp) : NaN - if (Number.isFinite(ts)) out.lastUserAt = ts + } else { + const user = userPromptOf(record, payload) + if (user !== null) noteUser(user.carrier, user.text, record.timestamp, records) } // WHY the limit is unconditional: a rollout whose first two hundred // records hold no user event (exec runs, synthesized transcripts) has // nothing further up the file the head can label it by, and reading such // files to the end made discovery cost the size of the store. - if (records >= HEAD_RECORD_LIMIT) break + if (records >= HEAD_RECORD_LIMIT) { + truncated = true + break + } + } + if (truncated) { + // WHY a tail pass (#1407 reviews a and b): the listing sorts by user + // activity, and a head-bounded read reported the last prompt within the + // first 200 records. In 33 of 61 local 0.157.0 files a later prompt lay + // beyond them (one 46.8 hours later), so a live session sorted days too + // old. The newest prompt is near the end of the file, so reading a + // bounded tail finds it at a fixed cost; the head keeps the labels. + const tailAt = await newestUserTimestampInTail(file) + if (tailAt !== null) out.lastUserAt = Math.max(out.lastUserAt ?? tailAt, tailAt) + out.headTruncated = out.userTexts.length === 0 } return out } +// The newest user timestamp is found by reading the rollout BACKWARD in +// chunks until a user record appears (#1407 verification a). A fixed 512 KiB +// tail missed it in 10 of 46 local 0.157 files whose latest prompt was past +// the head (a long agent turn can write megabytes after one prompt), and it +// dropped a record straddling the window's start. Reading back in chunks, +// carrying the partial line across each boundary, finds the newest one wherever +// it is. The scan is bounded: a file with no user record in its last +// TAIL_ACTIVITY_MAX_BYTES keeps the head's time, which is at worst the old +// behaviour. It runs only for heads that hit their record bound, and the +// result is cached by mtime with the head. WHY a bound at all, knowing it +// misses (1 of 452 local 0.157 files had its newest prompt 55.8 MB from the +// end, #1407 verification a): this is the degraded no-index path, rollouts +// reach gigabytes, and an unbounded scan per discovery is the store-sized +// cost the head limit above exists to prevent. +const TAIL_ACTIVITY_CHUNK_BYTES = 512 * 1024 +const TAIL_ACTIVITY_MAX_BYTES = 32 * 1024 * 1024 + +async function newestUserTimestampInTail(file: string): Promise { + let handle + try { + handle = await open(file, 'r') + const { size } = await handle.stat() + let end = size + // Bytes of the line that starts before the current chunk and was cut off. + let carry = Buffer.alloc(0) + while (end > 0 && size - end < TAIL_ACTIVITY_MAX_BYTES) { + const start = Math.max(0, end - TAIL_ACTIVITY_CHUNK_BYTES) + const chunk = Buffer.alloc(end - start) + await handle.read(chunk, 0, chunk.length, start) + const window = Buffer.concat([chunk, carry]) + // Unless this chunk starts the file, its first line is incomplete: keep + // its bytes for the next (earlier) chunk rather than dropping it. A + // window with NO newline is all one line longer than a chunk: carry the + // whole of it (#1407 verification a, round 2), never parse or drop it. + const firstBreak = window.indexOf(0x0a) + if (start > 0 && firstBreak < 0) { + carry = window + end = start + continue + } + const complete = start > 0 ? window.subarray(firstBreak + 1).toString('utf8') : window.toString('utf8') + carry = start > 0 ? window.subarray(0, firstBreak) : Buffer.alloc(0) + const newest = newestUserTimestampIn(complete.split('\n')) + if (newest !== null) return newest + if (start === 0) break + end = start + } + return null + } catch { + return null + } finally { + await handle?.close().catch(() => {}) + } +} + +function newestUserTimestampIn(lines: string[]): number | null { + let newest: number | null = null + for (const line of lines) { + if (!line.includes('"user_message"') && !line.includes('"UserMessage"')) continue + let record: Record + try { + record = JSON.parse(line) as Record + } catch { + continue + } + if (userPromptOf(record, asRecord(record.payload)) === null) continue + const ts = typeof record.timestamp === 'string' ? Date.parse(record.timestamp) : NaN + if (Number.isFinite(ts)) newest = Math.max(newest ?? ts, ts) + } + return newest +} + +/** The user prompt a rollout record carries, and through which carrier. */ +function userPromptOf(record: Record, payload: Record | null): { carrier: 'legacy' | 'item'; text: string } | null { + if (record.type !== 'event_msg' || !payload) return null + if (payload.type === 'user_message' && typeof payload.message === 'string') return { carrier: 'legacy', text: payload.message } + if (payload.type === 'item_completed') { + const text = userMessageItemText(payload.item) + if (text !== null) return { carrier: 'item', text } + } + return null +} + +/** The text of a 0.157 `UserMessage` turn item (`{type, id, content: [{type: + * 'text', text, text_elements}]}`), or null for any other item. Text parts + * are joined with no separator, as Codex's own UserMessageItem::message() + * does (protocol/src/items.rs). A message of only images reads `[Image]`, + * Codex's own preview text (protocol.rs user_message_preview), so an + * image-only prompt is still a prompt (#1407 review b). */ +function userMessageItemText(value: unknown): string | null { + const item = asRecord(value) + if (item?.type !== 'UserMessage' || !Array.isArray(item.content)) return null + const parts = item.content.map(part => asRecord(part)).filter(part => part !== null) + const text = parts + .filter(part => part!.type === 'text' && typeof part!.text === 'string') + .map(part => part!.text as string) + .join('') + if (text.length > 0) return text + return parts.some(part => part!.type !== 'text') ? '[Image]' : null +} + export class CodexConversationSource implements ConversationSource { readonly provider = 'codex' as const private downgradeReason: string | null = null @@ -182,6 +342,7 @@ export class CodexConversationSource implements ConversationSource { userTexts: head.userTexts, createdAt: head.createdAt, lastUserActivityAt: head.lastUserAt, + ...(head.headTruncated ? { headTruncated: true } : {}), activitySource: head.lastUserAt !== null ? 'tail' : null, mtime, promptCount: null, diff --git a/src/main/conversations/sources/codex.userMessage0157.test.ts b/src/main/conversations/sources/codex.userMessage0157.test.ts new file mode 100644 index 000000000..9128a17ee --- /dev/null +++ b/src/main/conversations/sources/codex.userMessage0157.test.ts @@ -0,0 +1,168 @@ +import { mkdir, mkdtemp, rm, writeFile } from 'node:fs/promises' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { afterEach, expect, it } from 'vitest' + +import fixture from '../../../../testing/fixtures/conversations/codex-0157/typed-prompt-head.json' + +import { resolveFamily } from '../family.js' +import { CodexConversationSource } from './codex.js' + +// #1363: without a usable index (state_N.sqlite missing or failing schema +// validation, or a rollout the index does not cover) the source reads each +// rollout's head, and it took prompt text ONLY from `event_msg:user_message`. +// Codex 0.157 writes none: a prompt is `event_msg:item_completed` with +// `item.type: 'UserMessage'`. Every 0.157 row came back with no prompt, was +// classified `empty`, and was hidden from the default listing. +// +// The fixture is a REAL, CONTIGUOUS 0.157.0 rollout head (see its evidence), +// with its expected first prompt recorded independently of the parser under +// test. The later cases compose synthetic records AROUND that real head, and +// say so. + +type Rec = Record +const records = fixture.records as Rec[] +const threadId = (records[0]!.payload as { id: string }).id +const expected = fixture.expected +const at = (offsetMs: number) => new Date(Date.parse(expected.firstPromptTimestamp) + offsetMs).toISOString() +const userMessage = (timestamp: string, content: Array>): Rec => ({ + timestamp, type: 'event_msg', payload: { type: 'item_completed', item: { type: 'UserMessage', id: `u-${timestamp}`, content } }, +}) +const legacyMessage = (timestamp: string, message: string): Rec => ({ timestamp, type: 'event_msg', payload: { type: 'user_message', message } }) +const text = (value: string) => ({ type: 'text', text: value, text_elements: [] }) + +const dirs: string[] = [] +afterEach(async () => { for (const dir of dirs.splice(0)) await rm(dir, { recursive: true, force: true }) }) + +async function discoverRow(lines: Rec[]) { + const codexHome = await mkdtemp(join(tmpdir(), 'codex-0157-home-')) + dirs.push(codexHome) + const day = join(codexHome, 'sessions', '2026', '09', '24') + await mkdir(day, { recursive: true }) + await writeFile(join(day, `rollout-2026-09-24T22-40-13-${threadId}.jsonl`), lines.map(line => JSON.stringify(line)).join('\n') + '\n') + const source = new CodexConversationSource({ codexHome }) + const family = await resolveFamily('/fixture/repo', 'everywhere', { listWorktrees: async () => [] }) + const rows = await source.discover({ scope: 'everywhere', family }) + expect(source.lastDowngradeReason()).not.toBeNull() + return rows.find(candidate => candidate.nativeId === threadId)! +} + +it('reads a 0.157 prompt from its UserMessage item when there is no index', async () => { + const row = await discoverRow(records) + // Exactly the prompt: not the injected AGENTS.md or environment context + // that precede it as role-user response items in the real head. + expect(row.userTexts).toEqual(['x'.repeat(expected.firstPromptLength)]) + expect(row.lastUserActivityAt).toBe(Date.parse(expected.firstPromptTimestamp)) +}) + +it('keeps both carriers\' prompts, counting a prompt written by both once', async () => { + // A session resumed across writer versions (#1407 reviews a and b): the + // legacy event and the item for prompt A, then an item for prompt B only. + const row = await discoverRow([ + ...records, + legacyMessage(at(1000), 'prompt A'), + userMessage(at(1001), [text('prompt A')]), + userMessage(at(2000), [text('prompt B')]), + ]) + expect(row.userTexts).toEqual(['x'.repeat(expected.firstPromptLength), 'prompt A', 'prompt B']) + expect(row.lastUserActivityAt).toBe(Date.parse(at(2000))) +}) + +it('joins text parts with no separator and labels an image-only prompt', async () => { + // Codex's UserMessageItem::message() joins parts with no separator, and its + // preview text for an image-only message is `[Image]`. + const row = await discoverRow([ + ...records, + userMessage(at(1000), [text('two '), text('parts')]), + userMessage(at(2000), [{ type: 'image', image_url: 'data:image/png;base64,AAAA' }]), + ]) + expect(row.userTexts.slice(1)).toEqual(['two parts', '[Image]']) +}) + +it('takes user activity from the tail when the head bound hides a later prompt', async () => { + // 33 of 61 local 0.157.0 files have a prompt past the 200-record head; one + // came 46.8 hours after the first. The listing sorts by this time. + const filler = Array.from({ length: 300 }, (_, i) => ({ timestamp: at(10 + i), type: 'event_msg', payload: { type: 'token_count', info: null } })) + const later = at(46.8 * 3600 * 1000) + const row = await discoverRow([...records, ...filler, userMessage(later, [text('much later prompt')])]) + expect(row.userTexts).toEqual(['x'.repeat(expected.firstPromptLength)]) + expect(row.lastUserActivityAt).toBe(Date.parse(later)) +}) + +it('finds the newest prompt far behind a long agent turn', async () => { + // #1407 verification a: in 10 local 0.157 files the latest prompt lay + // wholly before a fixed 512 KiB tail. Here 4 MiB of agent output follow it. + const later = at(46.6 * 3600 * 1000) + const bulk = 'y'.repeat(64 * 1024) + const filler = (n: number, from: number) => Array.from({ length: n }, (_, i) => ({ timestamp: at(from + i), type: 'response_item', payload: { type: 'reasoning', summary: [], content: bulk } })) + const row = await discoverRow([...records, ...filler(250, 10), userMessage(later, [text('much later prompt')]), ...filler(64, 46.6 * 3600 * 1000 + 1)]) + expect(row.lastUserActivityAt).toBe(Date.parse(later)) +}) + +it('finds the newest prompt when its line straddles a read-chunk boundary', async () => { + // #1407 verification a: the tail reader dropped a record that started + // before its window. Lay the file out so the prompt's line ends exactly half + // inside the last 512 KiB chunk: bytes after the line = 512 KiB - half. + const later = at(46.6 * 3600 * 1000) + const bulk = 'y'.repeat(64 * 1024) + const head = [...records, ...Array.from({ length: 250 }, (_, i) => ({ timestamp: at(10 + i), type: 'response_item', payload: { type: 'reasoning', summary: [], content: bulk } }))] + const prompt = userMessage(later, [text('much later prompt')]) + const promptLine = JSON.stringify(prompt) + const bytesAfter = 512 * 1024 - Math.floor(promptLine.length / 2) + // After the prompt line: '\n' + tailLine + '\n' (discoverRow's join and final newline). + const base = { timestamp: at(46.6 * 3600 * 1000 + 1), type: 'response_item', payload: { type: 'reasoning', summary: [], content: '' } } + const pad = bytesAfter - 2 - JSON.stringify(base).length + const tail = { ...base, payload: { ...base.payload, content: 'y'.repeat(pad) } } + expect(Buffer.byteLength(JSON.stringify(tail)) + 2).toBe(bytesAfter) + const row = await discoverRow([...head, prompt, tail]) + expect(row.lastUserActivityAt).toBe(Date.parse(later)) +}) + +it('keeps a prompt the user really repeated in a later turn', async () => { + // #1407 verification a: identical text in a LATER turn is a new prompt, not + // the other carrier of an earlier one. Only a nearby pair is one prompt. + const row = await discoverRow([ + ...records, + legacyMessage(at(1000), 'repeat'), + legacyMessage(at(2000), 'different'), + ...Array.from({ length: 10 }, (_, i) => ({ timestamp: at(3000 + i), type: 'event_msg', payload: { type: 'token_count', info: null } })), + userMessage(at(48 * 3600 * 1000), [text('repeat')]), + ]) + expect(row.userTexts.slice(1)).toEqual(['repeat', 'different', 'repeat']) +}) + +it('keeps a later repeat even when it is only two records on', async () => { + // #1407 verification a, round 2: the exact reported sequence, with no + // records between. The pair window is records AND time. + const row = await discoverRow([ + ...records, + legacyMessage(at(1000), 'repeat'), + legacyMessage(at(2000), 'different'), + userMessage(at(48 * 3600 * 1000), [text('repeat')]), + ]) + expect(row.userTexts.slice(1)).toEqual(['repeat', 'different', 'repeat']) +}) + +it('finds a newest prompt whose single line is longer than two read chunks', async () => { + // #1407 verification a, round 2: a window with no newline is all one line. + const later = at(46.6 * 3600 * 1000) + const bulk = 'y'.repeat(64 * 1024) + const head = [...records, ...Array.from({ length: 250 }, (_, i) => ({ timestamp: at(10 + i), type: 'response_item', payload: { type: 'reasoning', summary: [], content: bulk } }))] + const huge = userMessage(later, [text('z'.repeat(1_200_000))]) + const row = await discoverRow([...head, huge]) + expect(row.lastUserActivityAt).toBe(Date.parse(later)) +}) + +it('never pairs carriers across another prompt', async () => { + // #1407 verification b: `repeat` (legacy), `different` (item), `repeat` + // (item) within a few seconds. The second repeat's previous user record is + // `different`, so it is a new prompt, not the other carrier of the first. + const row = await discoverRow([ + ...records, + legacyMessage(at(1000), 'start'), + legacyMessage(at(1100), 'repeat'), + userMessage(at(1200), [text('different')]), + userMessage(at(1300), [text('repeat')]), + ]) + expect(row.userTexts.slice(1)).toEqual(['start', 'repeat', 'different', 'repeat']) +}) diff --git a/src/main/ipc/debug.test.ts b/src/main/ipc/debug.test.ts index 6574264d1..e01878daf 100644 --- a/src/main/ipc/debug.test.ts +++ b/src/main/ipc/debug.test.ts @@ -4,6 +4,7 @@ const harness = vi.hoisted(() => ({ handlers: new Map unknown>(), order: [] as string[], queueFeedDebugAppend: vi.fn<(sessionId: string, entries: unknown[], epochMs?: number) => Promise>(async () => {}), + forgetFeedDebugSession: vi.fn<(sessionId: string, options?: { persistUnmarkedDrops?: boolean }) => void>(), saveDebugBundle: vi.fn(async () => { harness.order.push('save') return { bundlePath: '/tmp/test-bundle' } @@ -27,6 +28,7 @@ vi.mock('@main/storage/debugBundleLog.js', () => ({ })) vi.mock('@main/storage/feedDebugLog.js', () => ({ queueFeedDebugAppend: harness.queueFeedDebugAppend, + forgetFeedDebugSession: harness.forgetFeedDebugSession, })) vi.mock('@main/storage/proxyEventsReader.js', () => ({ readProxyEventsForBundle: vi.fn(async () => null), @@ -172,3 +174,34 @@ describe('debug:append-feed-log forwarding (#770)', () => { .rejects.toThrow('unknown size') }) }) + +// #1392: the renderer's release of a closed pane's feed-debug log. +describe('debug:forget-feed-log', () => { + const forgetHandler = () => { + registerDebugIpc({} as never, {} as never) + const handler = harness.handlers.get('debug:forget-feed-log') + if (!handler) throw new Error('debug:forget-feed-log was not registered') + return handler + } + + it('forgets the named session in main, persisting unmarked drops by default', () => { + harness.forgetFeedDebugSession.mockClear() + forgetHandler()({}, { sessionId: 'closed-pane' }) + expect(harness.forgetFeedDebugSession).toHaveBeenCalledExactlyOnceWith('closed-pane', { persistUnmarkedDrops: true }) + }) + + it('passes persistUnmarkedDrops: false through (persistence off)', () => { + harness.forgetFeedDebugSession.mockClear() + forgetHandler()({}, { sessionId: 'closed-pane', persistUnmarkedDrops: false }) + expect(harness.forgetFeedDebugSession).toHaveBeenCalledExactlyOnceWith('closed-pane', { persistUnmarkedDrops: false }) + }) + + it.each([undefined, null, {}, { sessionId: '' }, { sessionId: 7 }, { sessionId: ['a'] }])( + 'ignores malformed input %j', + params => { + harness.forgetFeedDebugSession.mockClear() + expect(() => forgetHandler()({}, params)).not.toThrow() + expect(harness.forgetFeedDebugSession).not.toHaveBeenCalled() + }, + ) +}) diff --git a/src/main/ipc/debug.ts b/src/main/ipc/debug.ts index b5d0452b2..dd0c0f96b 100644 --- a/src/main/ipc/debug.ts +++ b/src/main/ipc/debug.ts @@ -1,6 +1,6 @@ import { ipcMain } from 'electron' -import { queueFeedDebugAppend } from '@main/storage/feedDebugLog.js' +import { forgetFeedDebugSession, queueFeedDebugAppend } from '@main/storage/feedDebugLog.js' import type { FeedDebugPersistEntry } from '@main/storage/feedDebugLog.js' import { saveDebugBundle } from '@main/storage/debugBundle.js' import type { SaveDebugBundleParams, SaveDebugBundleResult } from '@main/storage/debugBundle.js' @@ -49,6 +49,20 @@ export function registerDebugIpc( }, ) + // The renderer's release of a feed-debug log whose pane is gone (#1392). + // Main forgets on process exit too, but a pane outlives its process (a + // same-id wake reuses the id) and keeps appending, which re-creates the + // per-session state; only the renderer knows when no append can follow. + // Any append it queued earlier is already in the per-session queue (IPC + // order is preserved and the append handler queues synchronously), and its + // token makes it drop what it writes. + ipcMain.handle('debug:forget-feed-log', (_evt, params: { sessionId?: unknown; persistUnmarkedDrops?: unknown }) => { + if (typeof params?.sessionId !== 'string' || params.sessionId.length === 0) return + // Only an explicit false skips the final marker; an older renderer that + // sends no flag keeps the previous (persisting) behaviour. + forgetFeedDebugSession(params.sessionId, { persistUnmarkedDrops: params.persistUnmarkedDrops !== false }) + }) + ipcMain.handle( 'debug:save-bundle', async (_evt, params: SaveDebugBundleParams): Promise => { diff --git a/src/main/storage/feedDebugLog.test.ts b/src/main/storage/feedDebugLog.test.ts index 9ba00c476..aba10fe24 100644 --- a/src/main/storage/feedDebugLog.test.ts +++ b/src/main/storage/feedDebugLog.test.ts @@ -10,7 +10,7 @@ import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' // `.then` advances the cursor and never resends. The comment described an // intention the code did not implement, and nothing was watching. -let statResult: { mode: 'real' } | { mode: 'throw'; code: string } = { mode: 'real' } +let statResult: { mode: 'real' } | { mode: 'throw'; code: string } | { mode: 'hold'; gate: Promise; reached: () => void } = { mode: 'real' } let stateDir = '' vi.mock('node:fs/promises', async () => { @@ -19,6 +19,11 @@ vi.mock('node:fs/promises', async () => { ...real, default: real, stat: async (path: Parameters[0]) => { + if (statResult.mode === 'hold') { + const held = statResult + held.reached() + await held.gate + } if (statResult.mode === 'throw') { const err = new Error('stat refused') as NodeJS.ErrnoException err.code = statResult.code @@ -155,3 +160,199 @@ describe('#770 — a reload does not re-open a capped log', () => { } }) }) + +// #1207 (the #1111 reviewer's probe, real queue ordering): an append queued +// BEFORE forgetFeedDebugSession, and not started yet, used to run afterwards +// and write the per-session maps back. Nothing removed them again: a few +// numbers per closed session, forever. +describe('forget racing a queued append (#1207)', () => { + it('leaves no per-session state behind for 100 sessions forgotten right after an append', async () => { + const { feedDebugSessionStateSizesForTest } = await import('./feedDebugLog.js') + const before = feedDebugSessionStateSizesForTest() + const writes: Array> = [] + for (let i = 0; i < 100; i++) { + const sessionId = `forget-race-${i}` + writes.push(queueFeedDebugAppend(sessionId, [entry(1)], 1_789_000_000_000).catch(() => undefined)) + forgetFeedDebugSession(sessionId) + } + await Promise.all(writes) + expect(feedDebugSessionStateSizesForTest()).toEqual(before) + }) +}) + +// #1392 reviews a+b: the committed probe only covered successful writes. +describe('forget racing a queued append, other interleavings (#1392)', () => { + it('drops state after a forgotten append fails its size check', async () => { + const { feedDebugSessionStateSizesForTest } = await import('./feedDebugLog.js') + statResult = { mode: 'throw', code: 'EACCES' } + const write = queueFeedDebugAppend('forget-fail', [entry(1)], 1_789_000_000_000) + forgetFeedDebugSession('forget-fail') + await expect(write).rejects.toThrow() + expect(feedDebugSessionStateSizesForTest('forget-fail')).toEqual({ ids: 0, epochs: 0, caps: 0, tokens: 0 }) + }) + + it('lets a re-registered id write its first row after an old append of the same id', async () => { + // Same id, same epoch: if the old append's cleanup only checked that SOME + // token exists, it would keep its cursor and the new generation's id 1 + // would be filtered as already written. + const first = queueFeedDebugAppend('reregistered', [entry(1)], 7_000) + forgetFeedDebugSession('reregistered') + const second = queueFeedDebugAppend('reregistered', [entry(1)], 7_000) + await Promise.all([first, second]) + const lines = (await readFile(logPath('reregistered'), 'utf8')).trim().split('\n') + expect(lines).toHaveLength(2) + }) + + it('keeps rejecting while the size stays unknown', async () => { + forgetFeedDebugSession('still-unknown') + statResult = { mode: 'throw', code: 'EACCES' } + await expect(queueFeedDebugAppend('still-unknown', [entry(1)], 1_000)).rejects.toThrow() + await expect(queueFeedDebugAppend('still-unknown', [entry(2)], 1_000)).rejects.toThrow() + }) +}) + +// #1392 review a, round 3: process exit forgets the session while the pane +// (and its log) stay live. A forget landing during the first `stat` used to +// drop the batch and RESOLVE, so the renderer advanced its cursor past rows +// that were never written. +describe('a forget during the first size check (#1392)', () => { + it('still writes the batch, then leaves no state behind', async () => { + const { feedDebugSessionStateSizesForTest } = await import('./feedDebugLog.js') + let release!: () => void + let reached!: () => void + const atStat = new Promise(resolve => { reached = resolve }) + statResult = { mode: 'hold', gate: new Promise(resolve => { release = resolve }), reached } + const write = queueFeedDebugAppend('exit-during-stat', [entry(1)], 1_000) + await atStat + forgetFeedDebugSession('exit-during-stat') + statResult = { mode: 'real' } + release() + await write + expect(await readFile(logPath('exit-during-stat'), 'utf8')).toContain('"id":1') + expect(feedDebugSessionStateSizesForTest('exit-during-stat')).toEqual({ ids: 0, epochs: 0, caps: 0, tokens: 0 }) + }) +}) + +// #1392 review a, round 4: cap state is rebuilt whenever a session is +// forgotten and appends again. A rebuilt state started its drop count at 0, +// so its tombstone reported 1 drop after an earlier row had reported 1,000. +describe('a rebuilt cap state keeps the file\'s drop count', () => { + async function cappedFileWithMarker(sessionId: string, drops: number) { + await mkdir(join(stateDir, 'feed-debug'), { recursive: true }) + await writeFile(logPath(sessionId), '') + await truncate(logPath(sessionId), 128 * 1024 * 1024) + await writeFile(logPath(sessionId), JSON.stringify({ sessionId, __feedDebugCapped: true, droppedEntriesSoFar: drops }) + '\n', { flag: 'a' }) + } + async function lastMarkerDrops(sessionId: string): Promise { + const handle = await open(logPath(sessionId), 'r') + try { + const size = (await handle.stat()).size + const tail = Buffer.alloc(4096) + await handle.read(tail, 0, 4096, size - 4096) + const tailSize = Math.min(size, 16_384) + const wide = Buffer.alloc(tailSize) + await handle.read(wide, 0, tailSize, size - tailSize) + const markers = wide.toString('utf8').split('\n').flatMap(row => { + try { + const parsed = JSON.parse(row.slice(row.indexOf('{'))) as { __feedDebugCapped?: unknown; droppedEntriesSoFar?: number } + return parsed.__feedDebugCapped === true ? [parsed.droppedEntriesSoFar ?? 0] : [] + } catch { return [] } + }) + void tail + return markers.at(-1) ?? -1 + } finally { + await handle.close() + } + } + + it('after a forget and a new append', async () => { + await cappedFileWithMarker('capped-rebuilt', 1_000) + forgetFeedDebugSession('capped-rebuilt') + await queueFeedDebugAppend('capped-rebuilt', [entry(1)], 1_000) + expect(await lastMarkerDrops('capped-rebuilt')).toBeGreaterThanOrEqual(1_001) + }) + + // Review b, round 5: drops are only persisted at a doubling, so a forget + // discarded up to half of them. Three forget cycles of 1 + 999 drops each + // on a file marked at 1,000 used to leave a last marker of 1,003 for 4,000 + // true drops. + it('across repeated forgets, the last marker stays within 2x of the true drops', async () => { + await cappedFileWithMarker('capped-cycles', 1_000) + let id = 0 + for (let cycle = 0; cycle < 3; cycle++) { + forgetFeedDebugSession('capped-cycles') + await queueFeedDebugAppend('capped-cycles', [entry(++id)], 1_000) + await queueFeedDebugAppend('capped-cycles', Array.from({ length: 999 }, () => entry(++id)), 1_000) + } + forgetFeedDebugSession('capped-cycles') + await queueFeedDebugAppend('capped-cycles', [], 1_000) + await new Promise(resolve => setTimeout(resolve, 20)) + expect(await lastMarkerDrops('capped-cycles')).toBeGreaterThanOrEqual(4_000) + }) + + // Round-5 review a: the tail reader's three blind spots. + it('below the cap: a marker written by an oversized entry keeps its count', async () => { + await mkdir(join(stateDir, 'feed-debug'), { recursive: true }) + await writeFile(logPath('below-cap'), '') + await truncate(logPath('below-cap'), 128 * 1024 * 1024 - 500) + await writeFile(logPath('below-cap'), '\n', { flag: 'a' }) + const big = (id: number) => ({ ...entry(id), summary: 'x'.repeat(1_000) }) + await queueFeedDebugAppend('below-cap', [big(1)], 1_000) + forgetFeedDebugSession('below-cap') + await queueFeedDebugAppend('below-cap', [big(2)], 1_000) + expect(await lastMarkerDrops('below-cap')).toBeGreaterThanOrEqual(2) + }) + + it('an ordinary row carrying the marker text in its data does not hide the real marker', async () => { + await cappedFileWithMarker('marker-in-data', 1_000) + await writeFile(logPath('marker-in-data'), JSON.stringify({ sessionId: 'marker-in-data', id: 9, data: { __feedDebugCapped: true, note: 'ordinary entry' } }) + '\n', { flag: 'a' }) + forgetFeedDebugSession('marker-in-data') + await queueFeedDebugAppend('marker-in-data', [entry(1)], 1_000) + expect(await lastMarkerDrops('marker-in-data')).toBeGreaterThanOrEqual(1_001) + }) + + it('a torn final row neither hides the earlier marker nor swallows the next row', async () => { + await cappedFileWithMarker('torn-tail', 1_000) + await writeFile(logPath('torn-tail'), '{"sessionId":"torn-tail","__feedDebugCapped":true,"droppedEntriesSoFar":20', { flag: 'a' }) + forgetFeedDebugSession('torn-tail') + await queueFeedDebugAppend('torn-tail', [entry(1)], 1_000) + expect(await lastMarkerDrops('torn-tail')).toBeGreaterThanOrEqual(1_001) + }) + + it('finds a marker behind several KiB of later rows', async () => { + await cappedFileWithMarker('rows-after-marker', 1_000) + const rows = Array.from({ length: 80 }, (_, i) => JSON.stringify({ sessionId: 'rows-after-marker', id: 100 + i, summary: 'y'.repeat(100) }) + '\n').join('') + await writeFile(logPath('rows-after-marker'), rows, { flag: 'a' }) + forgetFeedDebugSession('rows-after-marker') + await queueFeedDebugAppend('rows-after-marker', [entry(1)], 1_000) + expect(await lastMarkerDrops('rows-after-marker')).toBeGreaterThanOrEqual(1_001) + }) + + // #1392 review c, round 2: a release sent while persistence is OFF must not + // write the final drop marker either. Persistence off means no disk writes. + it('a forget told not to persist drops writes nothing', async () => { + await cappedFileWithMarker('no-write-forget', 1_000) + await queueFeedDebugAppend('no-write-forget', [entry(1)], 1_000) + await queueFeedDebugAppend('no-write-forget', [entry(2)], 1_000) + const before = await lastMarkerDrops('no-write-forget') + ;(forgetFeedDebugSession as (id: string, options?: { persistUnmarkedDrops?: boolean }) => void)('no-write-forget', { persistUnmarkedDrops: false }) + await queueFeedDebugAppend('no-write-forget', [], 1_000) + await new Promise(resolve => setTimeout(resolve, 20)) + expect(await lastMarkerDrops('no-write-forget')).toBe(before) + }) + + it('after a forget during the first size check', async () => { + await cappedFileWithMarker('capped-during-stat', 1_000) + let release!: () => void + let reached!: () => void + const atStat = new Promise(resolve => { reached = resolve }) + statResult = { mode: 'hold', gate: new Promise(resolve => { release = resolve }), reached } + const write = queueFeedDebugAppend('capped-during-stat', [entry(1)], 1_000) + await atStat + forgetFeedDebugSession('capped-during-stat') + statResult = { mode: 'real' } + release() + await write + expect(await lastMarkerDrops('capped-during-stat')).toBeGreaterThanOrEqual(1_001) + }) +}) diff --git a/src/main/storage/feedDebugLog.ts b/src/main/storage/feedDebugLog.ts index a7502b07a..1160eed26 100644 --- a/src/main/storage/feedDebugLog.ts +++ b/src/main/storage/feedDebugLog.ts @@ -1,4 +1,4 @@ -import { mkdir, stat, writeFile } from 'fs/promises' +import { mkdir, open, stat, writeFile } from 'fs/promises' import { join } from 'path' import { FEED_DEBUG_DIR } from '@main/storage/paths.js' @@ -74,6 +74,65 @@ async function loadInitialFileBytes(filePath: string): Promise { } } +// The drop count of the file's last tombstone row (0 if none), and whether +// the file ends with a complete row. +// +// WHY (#1392 review a, round 4): cap state is process-local and is rebuilt +// whenever a session is forgotten and appends again (process exit with the +// pane still open, a same-id wake, a forget during the first `stat`). A +// rebuilt state started at `droppedEntries: 0`, so its first tombstone +// reported 1 drop after an earlier row had reported thousands, and the LAST +// marker in the file, which the doubling rule promises is within 2x of the +// truth, understated it by orders of magnitude. Re-statting bytes restores the +// size decision; this restores the count. Only the file's tail is read, and +// any failure falls back to 0, the old behaviour. +const TOMBSTONE_TAIL_BYTES = 64 * 1024 +async function readFileTail(filePath: string, size: number): Promise<{ drops: number; endsWithNewline: boolean }> { + // Round-5 review a hardened this reader three ways: + // - it runs for ANY non-empty file, not only one at the cap: an entry too + // big to fit can write a short marker and leave the file BELOW the cap; + // - a row counts only if its PARSED top level is a tombstone. An ordinary + // entry can carry the marker text inside `data`, and a substring match + // let it hide the real marker; + // - an unparsable row (torn by a failed append) is skipped, not fatal, so + // an earlier complete marker is still found. + // Cost: one read of at most 64 KiB per session per process, at its first + // append. A marker further back than that (more than 64 KiB of ordinary + // rows written after it) is not found, which is the old behaviour. + const result = { drops: 0, endsWithNewline: true } + try { + const handle = await open(filePath, 'r') + try { + const length = Math.min(size, TOMBSTONE_TAIL_BYTES) + const buffer = Buffer.alloc(length) + await handle.read(buffer, 0, length, size - length) + result.endsWithNewline = length === 0 || buffer[length - 1] === 0x0a + const lines = buffer.toString('utf8').split('\n') + for (let i = lines.length - 1; i >= 0; i--) { + const line = lines[i]! + if (!line.includes('__feedDebugCapped')) continue + // From the row's first `{`: a tail can start mid-row, and a file that + // was preallocated or torn can carry NUL bytes before the row. + let row: { __feedDebugCapped?: unknown; droppedEntriesSoFar?: unknown } + try { + row = JSON.parse(line.slice(line.indexOf('{'))) + } catch { + continue + } + if (row.__feedDebugCapped !== true) continue + const drops = row.droppedEntriesSoFar + result.drops = typeof drops === 'number' && Number.isFinite(drops) && drops > 0 ? drops : 0 + break + } + } finally { + await handle.close() + } + } catch { + // Unreadable tail: the pre-#1392 count of 0. + } + return result +} + // Per-session feed-debug log writer. // // Why a per-session serialized queue instead of fire-and-forget writes: @@ -122,6 +181,51 @@ const lastWrittenFeedDebugId = new Map() */ const lastWrittenFeedDebugEpoch = new Map() +/** + * One token per live session, captured by each append when it is QUEUED + * (#1207). forgetFeedDebugSession deletes it. + * + * WHY: an append queued before the forget, and not started yet, used to run + * afterwards and write the three maps above back; queue settlement only reaps + * `feedDebugWriteQueues`, so they stayed for the life of the process (a few + * numbers per closed session, unbounded). An append that finds its token gone + * once it has run belongs to a forgotten session and deletes that state again. + * The token map is cleared by the same forget. + * + * An append that ARRIVES after the forget mints a fresh token and keeps its + * state; that is correct when the pane is still open (a same-id wake reuses + * the id, see sessionManager's agentPtyAttachCounts note), and the renderer + * releases the id when the pane really goes away (`debug:forget-feed-log`, + * sent by useFeedDebugPersist after the session's runtime is removed). That + * release, not a cap here, is what bounds these maps (#1392). + * + * WHY not a cap on remembered sessions: round 2 of review found an LRU cap + * broke three ways. Evicting a session whose append was inside its `stat` + * deleted the cap placeholder its identity check relies on, so the append + * resolved WITHOUT writing and the renderer advanced its cursor past lost + * rows; eviction reset a capped file's drop count, so its next tombstone + * under-reported drops by orders of magnitude; and appends already queued for + * evicted ids kept their state while a stalled `stat` held them. A remembered + * set of FORGOTTEN ids fails too: the same-id wake makes a forgotten id live + * again, and every one of its appends would be treated as late. + */ +const feedDebugSessionTokens = new Map() + +function feedDebugSessionToken(sessionId: string): object { + let token = feedDebugSessionTokens.get(sessionId) + if (!token) { + token = {} + feedDebugSessionTokens.set(sessionId, token) + } + return token +} + +function dropFeedDebugSessionState(sessionId: string): void { + lastWrittenFeedDebugId.delete(sessionId) + lastWrittenFeedDebugEpoch.delete(sessionId) + feedDebugCapState.delete(sessionId) +} + // One shape for both the first tombstone and the doubling refreshes so // readers grep for a single `__feedDebugCapped` marker. `fileBytesAtCap` is // the counter value at emit time — on a refresh row it reflects the file @@ -163,9 +267,19 @@ export function queueFeedDebugAppend( epochMs?: number, ): Promise { const previous = feedDebugWriteQueues.get(sessionId) ?? Promise.resolve() + const token = feedDebugSessionToken(sessionId) const next = previous .catch(() => {}) .then(async () => { + try { + await writeQueuedFeedDebugAppend() + } finally { + // Forgotten while this append waited or ran: the state it wrote + // belongs to a closed session (#1207, see feedDebugSessionTokens). + if (feedDebugSessionTokens.get(sessionId) !== token) dropFeedDebugSessionState(sessionId) + } + }) + async function writeQueuedFeedDebugAppend(): Promise { if (entries.length === 0) return if (epochMs !== undefined) { const knownEpoch = lastWrittenFeedDebugEpoch.get(sessionId) @@ -191,7 +305,7 @@ export function queueFeedDebugAppend( const freshEntries = entries.filter(entry => entry.id > lastWritten) if (freshEntries.length === 0) return await mkdir(FEED_DEBUG_DIR, { recursive: true }) - const filePath = join(FEED_DEBUG_DIR, `${sanitizeSessionIdForPath(sessionId)}.jsonl`) + const filePath = feedDebugFilePath(sessionId) // Per-file cap bookkeeping. The counter is process-local: the on-disk // file might already contain bytes from a previous run (feed-debug lives @@ -229,9 +343,15 @@ export function queueFeedDebugAppend( feedDebugCapState.set(sessionId, capState) const startingBytes = await loadInitialFileBytes(filePath) if (feedDebugCapState.get(sessionId) !== capState) { - // forgetFeedDebugSession ran during the stat await — the session is - // gone. Drop this final batch rather than resurrect state for it. - return + // forgetFeedDebugSession ran during the stat await. This used to + // `return`, dropping the batch, and that RESOLVED the IPC: the + // renderer advanced its cursor past rows that were never written + // (#1392 review a, round 3). The forget comes from PROCESS exit + // while the pane, and its log, are still live, so the rows are + // real. Write them: re-install this placeholder (appends are + // serialized per session, so nothing else can own it) and let the + // retired token drop the state again when this append settles. + feedDebugCapState.set(sessionId, capState) } if (startingBytes === null) { // Unknown on-disk size (stat failed, not-ENOENT). Fail CLOSED: @@ -251,6 +371,18 @@ export function queueFeedDebugAppend( throw new Error(`feed-debug: unknown size for ${sessionId}, refusing to append`) } capState.bytesWritten = startingBytes + if (startingBytes > 0) { + const tail = await readFileTail(filePath, startingBytes) + capState.droppedEntries = tail.drops + if (!tail.endsWithNewline) { + // A torn last row (a failed append) has no newline, so this + // session's first row would be glued onto it and neither would + // parse. Close the torn row first. Best effort: if this fails the + // append below fails the same way and the renderer retries. + await writeFile(filePath, '\n', { encoding: 'utf8', flag: 'a' }) + capState.bytesWritten += 1 + } + } } // Already capped in a prior batch — count, drop, and keep the on-disk @@ -362,7 +494,7 @@ export function queueFeedDebugAppend( `tombstone ${capState.tombstoneWritten ? 'written' : 'write FAILED (will retry)'}, ` + 'dropping further appends this run', ) - }) + } feedDebugWriteQueues.set(sessionId, next) // Reap the queue entry once it settles — but only if no NEWER @@ -383,21 +515,78 @@ export function queueFeedDebugAppend( return next } +/** Sizes of the per-session maps (or, given an id, whether each map holds + * it), for the #1207/#1392 leak tests only. The per-id form exists because + * whole-map sizes stop being comparable once the recency cap starts + * evicting other tests' sessions. */ +export function feedDebugSessionStateSizesForTest(sessionId?: string): { ids: number; epochs: number; caps: number; tokens: number } { + const count = (map: Map) => (sessionId === undefined ? map.size : Number(map.has(sessionId))) + return { ids: count(lastWrittenFeedDebugId), epochs: count(lastWrittenFeedDebugEpoch), caps: count(feedDebugCapState), tokens: count(feedDebugSessionTokens) } +} + /** Drop in-memory bookkeeping for a session that has ended. The * on-disk JSONL is intentionally LEFT IN PLACE — debug bundles for * long-since-closed panes still benefit from reading the trail. The * unified sweep in storage/debugRetention.ts is what eventually * deletes the file. */ -export function forgetFeedDebugSession(sessionId: string): void { +function feedDebugFilePath(sessionId: string): string { + return join(FEED_DEBUG_DIR, `${sanitizeSessionIdForPath(sessionId)}.jsonl`) +} + +/** + * Write the drops a capped session counted since its last on-disk marker, + * before its in-memory count is forgotten (#1392 review b, round 5). + * + * WHY: drops are persisted only at a doubling, so up to half of them live + * only in memory. Every forget (process exit with the pane open, a same-id + * wake, the renderer's release) used to discard them, and a session that + * crossed a few forgets reported a fraction of its true total in its last + * marker, breaking the 2x promise. Chained on the session's write queue so it + * lands after any append already queued, which makes it the file's LAST + * marker (the one readFileTail and forensics read). Best effort: a + * failed write loses only what the old code always lost. + * + * Residual: a crash or a kill of main still loses the unmarked drops. Only a + * write per drop could avoid that, which is what the doubling rule exists to + * prevent. + */ +function flushUnmarkedDrops(sessionId: string, capState: FeedDebugCapState | undefined): void { + if (!capState?.tombstoneWritten || capState.droppedEntries <= capState.lastTombstoneDrops) return + const line = buildTombstoneLine(sessionId, capState) + const previous = feedDebugWriteQueues.get(sessionId) ?? Promise.resolve() + const next = previous + .catch(() => {}) + .then(() => writeFile(feedDebugFilePath(sessionId), line, { encoding: 'utf8', flag: 'a' })) + .catch(() => {}) + feedDebugWriteQueues.set(sessionId, next) + void next.then(() => { + if (feedDebugWriteQueues.get(sessionId) === next) feedDebugWriteQueues.delete(sessionId) + }) +} + +export function forgetFeedDebugSession( + sessionId: string, + /** `persistUnmarkedDrops: false` when the caller's user has persistence + * switched OFF (#1392 review c, round 2): the final drop marker is a disk + * write, and "off" means none. Those unmarked drop counts are then lost, + * which is what switching persistence off asks for. Defaults to true, the + * process-exit forget's behaviour. */ + options: { persistUnmarkedDrops?: boolean } = {}, +): void { // We never delete `feedDebugWriteQueues` synchronously here — // there might be an in-flight write that still owns the chain. // The settle-time reaper in queueFeedDebugAppend handles the queue // entry; what we own here is the cursor. + // + // Retiring the token tells any append queued before this call (and still + // pending) to delete what it writes (#1207). + feedDebugSessionTokens.delete(sessionId) lastWrittenFeedDebugId.delete(sessionId) lastWrittenFeedDebugEpoch.delete(sessionId) // Drop the cap-state entry too. If the same sessionId is re-registered later // in this process, we'll re-stat the on-disk file and prime a fresh counter; // never carrying stale cap state across "session forgotten" boundaries keeps // the map from growing unbounded across long-lived main processes. + if (options.persistUnmarkedDrops !== false) flushUnmarkedDrops(sessionId, feedDebugCapState.get(sessionId)) feedDebugCapState.delete(sessionId) } diff --git a/src/mcp/shared/aiWorkspaceTypes.ts b/src/mcp/shared/aiWorkspaceTypes.ts index 61ef7c9a5..7f9e9f0b3 100644 --- a/src/mcp/shared/aiWorkspaceTypes.ts +++ b/src/mcp/shared/aiWorkspaceTypes.ts @@ -37,6 +37,11 @@ export type AiWorkspaceRecord = { createdAt: string updatedAt: string entries: AiWorkspaceFileEntry[] + /** Runtime only, never persisted (#1285, #1416 review b): set by `get` while + * AI Workspace cannot save, because a preservation copy it owes cannot be + * written. Every load sees it, so a remounted editor (or an agent) learns + * that changes will be refused, not only the view that saw a failed write. */ + storageWarning?: string } export type AiWorkspaceSummary = { @@ -100,7 +105,17 @@ export type AiWorkspaceWriteFileParams = { } export type AiWorkspaceWriteFileResult = - | { ok: true; path: string; mtimeMs: number; size: number; version: string } + | { + ok: true + path: string + mtimeMs: number + size: number + version: string + /** The file IS written, but a follow-up step failed: today, saving the + * refreshed file status (#1285). Never set when the write itself + * failed; a caller must not retry the write because of it. */ + warning?: string + } | { ok: false error: string diff --git a/src/preload/api/debug.ts b/src/preload/api/debug.ts index 7f5821ff9..db9cb07d1 100644 --- a/src/preload/api/debug.ts +++ b/src/preload/api/debug.ts @@ -29,6 +29,11 @@ export const debugApi = { }): Promise => ipcRenderer.invoke('debug:append-feed-log', params), + /** Release main's per-session feed-debug state for a pane that is gone + * (#1392). Sent once, after the renderer's last possible append. */ + forgetFeedDebugLog: (params: { sessionId: string; persistUnmarkedDrops: boolean }): Promise => + ipcRenderer.invoke('debug:forget-feed-log', params), + saveDebugBundle: (params: SaveDebugBundleParams): Promise => ipcRenderer.invoke('debug:save-bundle', params), diff --git a/src/providers/codex/renderer/adapters/command.ts b/src/providers/codex/renderer/adapters/command.ts index 2f817816f..fe5fb664e 100644 --- a/src/providers/codex/renderer/adapters/command.ts +++ b/src/providers/codex/renderer/adapters/command.ts @@ -575,13 +575,24 @@ function commandResultEvidence( output: materialized, exitCode: nativeExit, failed, - // Native exec_command_end results always carry exit-derived evidence: - // rollout.ts computes is_error from `exit_code !== 0 || status === - // 'failed'` and stamps codex.exitCode. is_error === false is therefore a - // proven success on THIS transport — unlike code-mode - // custom_tool_call_output, whose is_error never reflects the inner - // command. - exitProven: true, + // Native exec_command_end results carry exit-derived evidence: + // rollout.ts computes is_error from the exit code on both terminal + // carriers (the exec_command_end event, and the wrapped + // function_call_output with a "Process exited with code N" header) and + // stamps codex.exitCode. is_error === false is therefore a proven + // success on THIS transport — unlike code-mode custom_tool_call_output, + // whose is_error never reflects the inner command. + // + // EXCEPT a still-running chunk (#1395 review a, P1). A wrapper whose + // header says "Process running with session ID N" is partial: the + // command goes on in that session, and its exit arrives on a later + // write_stdin result with a different call_id, which this card cannot + // see. rollout.ts marks it `exec_command_running`. Claiming success for + // it painted long-running and later-failing commands green (9,896 such + // chunks in the local corpus); its honest state is "unknown". The same + // holds for a wrapper whose header could not be parsed + // (`exec_command_unparsed`, #1395 review b). + exitProven: codex?.kind === 'exec_command_running' || codex?.kind === 'exec_command_unparsed' ? failed : true, running: false, owned: true, } diff --git a/src/providers/codex/renderer/transcript/entries.ts b/src/providers/codex/renderer/transcript/entries.ts index 7fd5b8c90..1331b392b 100644 --- a/src/providers/codex/renderer/transcript/entries.ts +++ b/src/providers/codex/renderer/transcript/entries.ts @@ -133,8 +133,11 @@ function partToBlock(part: ResultPart): { type: string; text?: string; [key: str } } -/** Codex's `exec_command_end` wraps its output in a "Chunk ID: …\nOutput:\n" - * envelope. The user never wants to see that wrapper — strip it. */ +/** Codex's `exec_command` result (the `function_call_output` rollout line, + * through 0.144) wraps its output in a "Chunk ID: …\nOutput:\n" + * envelope. The user never wants to see that wrapper — strip it. (This used + * to say the envelope came from `exec_command_end`; that event is never + * persisted, #1321.) */ export function stripCodexExecWrapper(output: string): string { const marker = '\nOutput:\n' const idx = output.indexOf(marker) @@ -142,15 +145,49 @@ export function stripCodexExecWrapper(output: string): string { return output.slice(idx + marker.length) } -/** True for ANY exec-wrapped output ("Chunk ID: …" with a "Process exited - * with code …" line), stdout or not. The rollout mapper drops these - * `function_call_output` lines because the correlated `exec_command_end` - * event carries the same result, with exit code and command, and renders - * the card; keeping both would duplicate it. (This comment used to say - * "only the wrapper and nothing else", which the code never did; #1298 - * review B.) */ -export function isCodexExecWrapperOutput(output: string): boolean { - return output.startsWith('Chunk ID:') && output.includes('\nProcess exited with code ') +/** The exit code in an exec-wrapped output's header ("Chunk ID: …" … + * "Process exited with code N" … "Output:"), or null when the output is not + * wrapped or the process was still running ("Process running with session + * ID …", a partial chunk a later write_stdin/poll continues). + * + * WHY only the header is read: the body is the command's own bytes, and a + * command can print "Process exited with code 0" itself (a cat of a captured + * transcript). The old `includes` test scanned the whole string. + * + * WHY this replaced `isCodexExecWrapperOutput` (#1321): that predicate made the + * rollout mapper DROP every wrapped result, on the belief that a correlated + * `exec_command_end` event carried the same result. Current Codex never + * persists that event (codex-rs `rollout/src/policy.rs` lists + * `EventMsg::ExecCommandEnd` as transient), and a census of 2,541 local + * rollouts found 0 of them against 85,355 wrapped outputs with an exit line. + * (rust-v0.107.0 through v0.136.0 did persist it in extended-history mode; + * the transcript mapper then prefers this wrapper, the fuller carrier.) The drop therefore + * removed the ONLY copy of every `exec_command` result (Codex through 0.144) + * from resumed history, and the card showed no output or exit status. */ +export function codexExecWrapperExitCode(output: string): number | null { + if (!output.startsWith('Chunk ID:')) return null + // WHY the marker is required (#1395 review a, P3): without it there is no + // header/body boundary, so the "header" would be the whole string and the + // unstripped wrapper would render as a finished result's output. Every one + // of 85,355 finished local wrappers has the LF marker; anything else is not + // a shape we have seen, and it falls back to a plain result with no exit + // claim (the adapter then shows an unproven outcome, not a success). + const outputMarker = output.indexOf('\nOutput:\n') + if (outputMarker === -1) return null + const header = output.slice(0, outputMarker) + const match = /\nProcess exited with code (-?\d+)(?:\n|$)/.exec(header) + return match ? Number(match[1]) : null +} + +/** True for a wrapped exec output whose header says the process is still + * running ("Process running with session ID N"): a partial chunk whose exit + * arrives later, on a write_stdin result with another call_id. Header only, + * for the same reason as codexExecWrapperExitCode. */ +export function isCodexExecWrapperRunning(output: string): boolean { + if (!output.startsWith('Chunk ID:')) return false + const outputMarker = output.indexOf('\nOutput:\n') + if (outputMarker === -1) return false + return /\nProcess running with session ID \S+(?:\n|$)/.test(output.slice(0, outputMarker)) } /** Build a Claude-shaped assistant Entry containing a single diff --git a/src/providers/codex/renderer/transcript/execWrappedOutput.test.ts b/src/providers/codex/renderer/transcript/execWrappedOutput.test.ts new file mode 100644 index 000000000..b016b5dd8 --- /dev/null +++ b/src/providers/codex/renderer/transcript/execWrappedOutput.test.ts @@ -0,0 +1,186 @@ +import { describe, expect, it } from 'vitest' + +import fixture from '../../../../../testing/fixtures/codex-exec-output/wrapped-exec-command-output.json' + +import { fromCodexCommandOperation } from '@providers/codex/renderer/adapters/command' +import { createCodexTranscriptEntryMapper } from '@providers/codex/renderer/transcript/mapper' +import { mapCodexRolloutToFeedEntries } from '@providers/codex/renderer/transcript/rollout' +import type { ToolResultBlock, ToolUseBlock } from '@shared/types/transcript' + +// #1321: the rollout mapper dropped every wrapped exec_command result, on the +// belief that an `exec_command_end` event carried it. Codex never persists that +// event (codex-rs rollout policy: transient), so resumed history lost the only +// copy of the output and the exit status. Each case is a REAL 0.132.0 pair +// (see the fixture's `evidence`), mapped by the real mapper and read by the +// real command adapter the card uses. +type Case = { cliVersion: string; records: Array> } +const cases = fixture.cases as unknown as Record<'ok' | 'fail' | 'empty', Case> + +function mapPair(name: keyof typeof cases): { toolUse: ToolUseBlock; result: ToolResultBlock | null } { + const entries = cases[name].records.flatMap(record => mapCodexRolloutToFeedEntries(record)) + const blocks = entries.flatMap(entry => { + const content = (entry as { message?: { content?: unknown } }).message?.content + return Array.isArray(content) ? content as Array> : [] + }) + const toolUse = blocks.find(block => block.type === 'tool_use') as ToolUseBlock | undefined + const result = blocks.find(block => block.type === 'tool_result') as ToolResultBlock | undefined + if (!toolUse) throw new Error(`fixture case ${name} has no tool_use`) + return { toolUse, result: result ?? null } +} + +describe('wrapped exec_command results in resumed history (#1321)', () => { + it('keeps a successful result, without the wrapper, with its exit code', () => { + const { toolUse, result } = mapPair('ok') + expect(result).not.toBeNull() + expect(result!.tool_use_id).toBe(toolUse.id) + expect(result!.is_error).toBe(false) + expect(String(result!.content)).not.toContain('Chunk ID:') + expect(String(result!.content)).toMatch(/^x+\nx+/) + // The exact metadata the event carrier stamps (#1395 review a: kind, + // parsedCmd, command and cwd were unpinned; `kind` drives row absorption). + expect((result as unknown as { codex: unknown }).codex).toEqual({ + kind: 'exec_command_end', parsedCmd: [], command: [], cwd: null, exitCode: 0, + }) + + const operation = fromCodexCommandOperation({ toolUse, result }) + expect(operation?.model.exitCode).toBe(0) + expect(operation?.model.output).toBe(result!.content) + expect(operation?.ownsResult).toBe(true) + }) + + it('keeps a failed result and reports it as failed with the real exit code', () => { + const { toolUse, result } = mapPair('fail') + expect(result?.is_error).toBe(true) + + const operation = fromCodexCommandOperation({ toolUse, result }) + expect(operation?.model.exitCode).toBe(1) + expect(operation?.model.status).toBe('failure') + }) + + it('keeps an empty successful result as proof the command finished', () => { + // Without a result the card cannot tell `mkdir` that printed nothing from + // a command interrupted before its result was written. + const { toolUse, result } = mapPair('empty') + expect(result).not.toBeNull() + expect(result!.content).toBe('') + + const operation = fromCodexCommandOperation({ toolUse, result }) + expect(operation?.model.exitCode).toBe(0) + expect(operation?.model.status).not.toBe('running') + }) + + it('reads the exit code from the header only, never from the command output', () => { + // A command can print the header's words itself (a cat of a captured + // transcript). A still-running chunk has no exit line in its header. + const running = { + type: 'response_item', + timestamp: '2026-07-09T21:40:40.079Z', + payload: { + type: 'function_call_output', + call_id: 'call-running', + output: 'Chunk ID: aaaaaa\nWall time: 1.0000 seconds\nProcess running with session ID 1\nOriginal token count: 9\nOutput:\nx\nProcess exited with code 0\n', + }, + } + const [entry] = mapCodexRolloutToFeedEntries(running) + const block = ((entry as { message: { content: Array> } }).message.content)[0]! + // Marked running, with no exit claimed from the body's words. + expect(block.codex).toEqual({ kind: 'exec_command_running' }) + expect(block.content).toBe('x\nProcess exited with code 0\n') + }) + + // A still-running chunk, as the fixture's real header shape with the + // "running" line Codex writes in its place (9,896 in the local corpus). + // Paired with the fixture's real exec_command call, so the adapter sees a + // genuine invocation. + const okCall = cases.ok.records[0]! + const runningPair = () => [ + okCall, + { + type: 'response_item', + timestamp: '2026-07-09T21:40:40.079Z', + payload: { + type: 'function_call_output', + call_id: (okCall.payload as { call_id: string }).call_id, + output: 'Chunk ID: aaaaaa\nWall time: 1.0000 seconds\nProcess running with session ID 42\nOriginal token count: 1\nOutput:\nworking\n', + }, + }, + ] + + it('does not paint a still-running command as a success (#1395 review a, P1)', () => { + const entries = runningPair().flatMap(record => mapCodexRolloutToFeedEntries(record)) + const blocks = entries.flatMap(entry => (entry as { message: { content: Array> } }).message.content) + const toolUse = blocks.find(block => block.type === 'tool_use') as unknown as ToolUseBlock + const result = blocks.find(block => block.type === 'tool_result') as unknown as ToolResultBlock + + const operation = fromCodexCommandOperation({ toolUse, result }) + // Its exit arrives on a later write_stdin result this card cannot see. + expect(operation?.model.status).toBe('unknown') + expect(operation?.model.exitCode).toBeNull() + }) + + // Extended-history rollouts (through rust-v0.136.0) can persist the event + // next to the always-durable wrapper, with the same call_id. The wrapper is + // the fuller carrier (the event's aggregated_output is sanitized to 10,000 + // bytes), so it must be the result the card ends up with (#1395 reviews a, + // b). The feed's result index is later-wins. + const cardResult = (records: Array>) => { + const mapper = createCodexTranscriptEntryMapper() + const results = records + .flatMap(record => mapper.map(record).entries) + .flatMap(entry => (entry as { message: { content: Array> } }).message.content) + .filter(block => block.type === 'tool_result') + return { results, card: results.at(-1) } + } + const [okCallRecord, okOutputRecord] = cases.ok.records + const truncatedEvent = { + type: 'event_msg', + timestamp: '2026-07-09T21:40:40.000Z', + payload: { type: 'exec_command_end', call_id: (okCallRecord!.payload as { call_id: string }).call_id, exit_code: 0, aggregated_output: 'truncated\n' }, + } + const wrapperBody = () => String((okOutputRecord!.payload as { output: string }).output).split('\nOutput:\n')[1] + + it('hands the card the wrapper when the event came first (#1395 review b)', () => { + const { card } = cardResult([okCallRecord!, truncatedEvent, okOutputRecord!]) + expect(card!.content).toBe(wrapperBody()) + }) + + it('drops an event that arrives after its wrapper (#1395 review b)', () => { + const { results } = cardResult([okCallRecord!, okOutputRecord!, truncatedEvent]) + expect(results).toHaveLength(1) + expect(results[0]!.content).toBe(wrapperBody()) + }) + + it('makes no exit claim for a wrapper without its Output marker (#1395 review a, P3)', () => { + const headerOnly = { + type: 'response_item', + timestamp: '2026-07-09T21:40:40.079Z', + payload: { + type: 'function_call_output', + call_id: 'call-header-only', + output: 'Chunk ID: aaaaaa\nWall time: 0.1000 seconds\nProcess exited with code 1\nOriginal token count: 0', + }, + } + const [entry] = mapCodexRolloutToFeedEntries(headerOnly) + const block = (entry as { message: { content: Array> } }).message.content[0]! + expect(block.codex).toEqual({ kind: 'exec_command_unparsed' }) + }) + + it('shows an unparsed wrapper as unknown, never a success (#1395 review b)', () => { + const unparsed = { + type: 'response_item', + timestamp: '2026-07-09T21:40:40.079Z', + payload: { + type: 'function_call_output', + call_id: (okCall.payload as { call_id: string }).call_id, + output: 'Chunk ID: aaaaaa\r\nWall time: 0.1000 seconds\r\nProcess exited with code 1\r\nOriginal token count: 0\r\nOutput:\r\nfailed\r\n', + }, + } + const blocks = [okCall, unparsed].flatMap(record => mapCodexRolloutToFeedEntries(record)) + .flatMap(entry => (entry as { message: { content: Array> } }).message.content) + const toolUse = blocks.find(block => block.type === 'tool_use') as unknown as ToolUseBlock + const result = blocks.find(block => block.type === 'tool_result') as unknown as ToolResultBlock + const operation = fromCodexCommandOperation({ toolUse, result }) + expect(operation?.model.status).toBe('unknown') + expect(operation?.model.exitCode).toBeNull() + }) +}) diff --git a/src/providers/codex/renderer/transcript/mapper.ts b/src/providers/codex/renderer/transcript/mapper.ts index e800c1f4c..ae68ca274 100644 --- a/src/providers/codex/renderer/transcript/mapper.ts +++ b/src/providers/codex/renderer/transcript/mapper.ts @@ -28,10 +28,49 @@ import { } from './rollout' import { codexEventType, codexTurnIdFromEventPayload } from './eventCursor' +// How many exec terminal results a mapper remembers for de-duplication. A +// duplicate carrier sits next to its twin (same turn), so a small window is +// enough, and it keeps a live session's mapper from growing without bound. +const EXEC_TERMINAL_MEMORY = 512 + export function createCodexTranscriptEntryMapper( initialTurnCursor: string | null = null, ): TranscriptEntryMapper { let turnCursor = initialTurnCursor + // WHY (#1395 reviews a and b): one exec_command can have TWO terminal + // carriers. The wrapped function_call_output is always durable. The + // exec_command_end event is transient in current Codex, but the + // extended-history policy persisted it through rust-v0.136.0 (0.137.0 is + // transient again). Both carry the same call_id and both map to an + // `exec_command_end` result. + // + // The WRAPPER wins, because it is the fuller one: the persisted event's + // aggregated_output is sanitized to 10,000 bytes (rollout policy.rs), while + // the wrapper keeps the whole model-visible output. The feed's result index + // is later-wins (buildToolResultIndex), and Codex emits the end event BEFORE + // the function result (core tools/events.rs ToolEventEmitter::finish), so: + // - event first, wrapper later: both are kept, and the wrapper wins the + // index (the command card owns and absorbs both result rows); + // - wrapper first, event later: the event is dropped here, so a late, + // truncated event cannot replace the wrapper. + // A first version kept whichever came FIRST, which kept the truncated event + // (review b). The memory is per mapper, and history pages, previews and + // live bursts each build their own; across such a boundary both results + // are kept and later-wins decides, which again favours the wrapper in + // Codex's own emit order. No local rollout (0 of 2,555) has both carriers. + const wrapperResolvedCalls = new Set() + const keepExecTerminal = (raw: Record) => (entry: ReturnType[number]): boolean => { + const callId = execTerminalCallId(entry) + if (callId === null) return true + if (raw.type === 'response_item') { + wrapperResolvedCalls.add(callId) + if (wrapperResolvedCalls.size > EXEC_TERMINAL_MEMORY) { + wrapperResolvedCalls.delete(wrapperResolvedCalls.values().next().value as string) + } + return true + } + return !wrapperResolvedCalls.has(callId) + } return { map(raw: Record): MappedTranscriptEntry { const turnContextId = codexTurnIdFromRollout(raw) @@ -39,9 +78,9 @@ export function createCodexTranscriptEntryMapper( const payloadTurnId = codexTurnIdFromEventPayload(raw) if (payloadTurnId !== null) turnCursor = payloadTurnId - const entries = mapCodexRolloutToFeedEntries(raw).map(entry => - stampCodexTurnId(entry, turnCursor), - ) + const entries = mapCodexRolloutToFeedEntries(raw) + .filter(keepExecTerminal(raw)) + .map(entry => stampCodexTurnId(entry, turnCursor)) const marker = codexHistoryMarker(raw) const eventType = codexEventType(raw) @@ -84,3 +123,12 @@ export { extractCodexProviderSessionId } from './entries' export function isCodexTypedUserPrompt(_entry: unknown, text: string): boolean { return !text.startsWith('<') } + +/** The call id of an exec terminal result (either carrier), or null. */ +function execTerminalCallId(entry: ReturnType[number]): string | null { + const content = (entry as { message?: { content?: unknown } }).message?.content + if (!Array.isArray(content) || content.length !== 1) return null + const block = content[0] as { type?: unknown; tool_use_id?: unknown; codex?: { kind?: unknown } } + if (block.type !== 'tool_result' || typeof block.tool_use_id !== 'string') return null + return block.codex?.kind === 'exec_command_end' ? block.tool_use_id : null +} diff --git a/src/providers/codex/renderer/transcript/rollout.ts b/src/providers/codex/renderer/transcript/rollout.ts index c175d461b..2f7d11807 100644 --- a/src/providers/codex/renderer/transcript/rollout.ts +++ b/src/providers/codex/renderer/transcript/rollout.ts @@ -9,7 +9,8 @@ import { codexToolResultEntry, codexToolUseEntry, codexOutputText, - isCodexExecWrapperOutput, + codexExecWrapperExitCode, + isCodexExecWrapperRunning, parseCodexJson, stripCodexExecWrapper, } from '@providers/codex/renderer/transcript/entries' @@ -400,6 +401,14 @@ function mapCodexRolloutToFeedEntriesUnstamped(entry: Record): // its result was persisted. The provider renderer absorbs this empty // result after it has updated the command card, so retaining terminal // evidence does not reintroduce a blank standalone row. + // + // WHERE this event comes from (#1321): almost never a rollout. Current + // codex-rs treats `ExecCommandEnd` as transient, and 0 of 2,541 local + // rollouts contain one. rust-v0.107.0 through v0.136.0 persisted it in + // extended-history mode (app-server `persist_extended_history`), next to + // the always-durable wrapped `function_call_output` below, which is + // stamped with this same metadata. createCodexTranscriptEntryMapper + // prefers the wrapper, the fuller carrier (#1395 reviews a, b). return [ codexToolResultEntry( uuid, @@ -483,9 +492,42 @@ function mapCodexRolloutToFeedEntriesUnstamped(entry: Record): return [codexToolResultEntry(uuid, timestamp, payload.call_id, structured)] } const output = stripCodexExecWrapper(structured) - if (!output.trim() || isCodexExecWrapperOutput(structured)) { - return [] + const exitCode = codexExecWrapperExitCode(structured) + if (exitCode !== null) { + // A finished exec: the wrapper is the durable carrier of the result AND + // its exit status (#1321; see codexExecWrapperExitCode for why nothing + // else in the rollout carries them). It is stamped with the same + // `exec_command_end` metadata the live event produced, so the command + // card reads it as the native transport it is: bytes are the command's + // own, is_error and exitCode come from the real exit line. An EMPTY + // successful result is kept on purpose, exactly as for the event: it is + // the only proof the command finished rather than being interrupted, + // and the row dispatcher absorbs it once the card has its status. + return [ + codexToolResultEntry(uuid, timestamp, payload.call_id, output, exitCode !== 0, { + kind: 'exec_command_end', + parsedCmd: [], + command: [], + cwd: null, + exitCode, + }), + ] } + if (isCodexExecWrapperRunning(structured)) { + // A partial chunk of a command still running (#1395 review a, P1). Its + // bytes are real output; its outcome is not known yet, so it is marked + // for the command adapter, which then shows "unknown" instead of success. + return [codexToolResultEntry(uuid, timestamp, payload.call_id, output, false, { kind: 'exec_command_running' })] + } + if (structured.startsWith('Chunk ID:')) { + // A wrapper whose header we could not parse (no LF `Output:` marker, a + // CRLF header, an unknown status line). None of 95,251 local wrappers + // has such a shape, but if one appears its outcome is unknown, not a + // success (#1395 review b): the bytes are kept whole, since there is no + // proven header/body boundary to strip at. + return [codexToolResultEntry(uuid, timestamp, payload.call_id, structured, false, { kind: 'exec_command_unparsed' })] + } + if (!output.trim()) return [] return [codexToolResultEntry(uuid, timestamp, payload.call_id, output)] } diff --git a/src/providers/opencode/runtime/opencodeServeStartup.system.test.ts b/src/providers/opencode/runtime/opencodeServeStartup.system.test.ts new file mode 100644 index 000000000..79da3f06f --- /dev/null +++ b/src/providers/opencode/runtime/opencodeServeStartup.system.test.ts @@ -0,0 +1,63 @@ +import { chmodSync, mkdtempSync, rmSync, writeFileSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' + +import { afterEach, expect, it } from 'vitest' +import { OpencodeHeadless, SpawnedServer } from 'opencode-headless' + +import { OPENCODE_SERVE_STARTUP_TIMEOUT_MS } from './opencodeSession.js' + +// #1355, on the real readiness mechanism: SpawnedServer spawns a real child +// and waits for its listen line. The stub stands in for a CPU-starved but +// healthy `opencode serve` (the real binary took 16.7-43.1 s under load, +// 0.6-0.9 s idle): it prints the same listen line OpenCode prints, 11 s late. +// Under the package's 10 s default that start was killed; under the app's +// wait it succeeds. +const dirs: string[] = [] +afterEach(() => { for (const dir of dirs.splice(0)) rmSync(dir, { recursive: true, force: true }) }) + +// WHY the positive cases' test budget follows the product deadline (#1367 +// review b): they assert "the app keeps waiting", so the test must never give +// up before the app would. A fixed 30 s let a loaded runner fail them while +// SpawnedServer would still have waited; this only fails when the app would. +const WAITS_LIKE_THE_APP = OPENCODE_SERVE_STARTUP_TIMEOUT_MS + 10_000 + +function slowServe(delayMs: number): string { + const dir = mkdtempSync(join(tmpdir(), 'opencode-slow-serve-')) + dirs.push(dir) + const bin = join(dir, 'opencode') + writeFileSync(bin, `#!/usr/bin/env node +setTimeout(() => { console.log('opencode server listening on http://127.0.0.1:4096') }, ${delayMs}) +setInterval(() => {}, 1000) +`) + chmodSync(bin, 0o755) + return bin +} + +it('waits out a slow but healthy serve start', async () => { + const server = new SpawnedServer({ binary: slowServe(11_000), cwd: tmpdir(), startupTimeoutMs: OPENCODE_SERVE_STARTUP_TIMEOUT_MS }) + const info = await server.start() + expect(info.url).toBe('http://127.0.0.1:4096') + await server.stop() +}, WAITS_LIKE_THE_APP) + +it('is what the package default killed', async () => { + const server = new SpawnedServer({ binary: slowServe(11_000), cwd: tmpdir() }) + await expect(server.start()).rejects.toThrow('to report its URL') +}, 30_000) + +// #1367 review a (surviving mutation): the app hands the wait to +// OpencodeHeadless, not to SpawnedServer, so the package's forwarding is part +// of the fix. Dropping it put structured panes back on the 10 s default while +// both tests above stayed green. This goes through the same package method a +// structured start uses (resolveServerUrl -> SpawnedServer) with the app's +// option, and stops before the SDK connects (the stub serves no API). +it('forwards the wait through OpencodeHeadless to the spawned serve', async () => { + const headless = new OpencodeHeadless({ binary: slowServe(11_000), cwd: tmpdir(), startupTimeoutMs: OPENCODE_SERVE_STARTUP_TIMEOUT_MS }) + try { + const url = await (headless as unknown as { resolveServerUrl(): Promise }).resolveServerUrl() + expect(url).toBe('http://127.0.0.1:4096') + } finally { + await headless.stop() + } +}, WAITS_LIKE_THE_APP) diff --git a/src/providers/opencode/runtime/opencodeSession.readiness.test.ts b/src/providers/opencode/runtime/opencodeSession.readiness.test.ts index 1d4a29765..e639e6d2e 100644 --- a/src/providers/opencode/runtime/opencodeSession.readiness.test.ts +++ b/src/providers/opencode/runtime/opencodeSession.readiness.test.ts @@ -2,18 +2,25 @@ import { beforeEach, describe, expect, it, vi } from 'vitest' const headlessControl = vi.hoisted(() => ({ exitDuringStart: false, + rejectStart: null as Error | null, stop: vi.fn(async (): Promise => {}), + options: [] as Array>, })) vi.mock('opencode-headless', async () => { const { EventEmitter } = await import('node:events') return { OpencodeHeadless: class FakeOpencodeHeadless extends EventEmitter { + constructor(options: Record) { + super() + headlessControl.options.push(options) + } readonly screen = new EventEmitter() readonly committed = new EventEmitter() readonly semantic = new EventEmitter() async start(): Promise { if (headlessControl.exitDuringStart) this.emit('exit', { exitCode: 17 }) + if (headlessControl.rejectStart) throw headlessControl.rejectStart } async stop(): Promise { await headlessControl.stop() @@ -22,11 +29,12 @@ vi.mock('opencode-headless', async () => { } }) -import { OpencodeSession } from './opencodeSession.js' +import { OPENCODE_SERVE_STARTUP_TIMEOUT_MS, OpencodeSession } from './opencodeSession.js' describe('OpencodeSession composer readiness', () => { beforeEach(() => { headlessControl.exitDuringStart = false + headlessControl.rejectStart = null headlessControl.stop.mockClear() }) @@ -57,4 +65,32 @@ describe('OpencodeSession composer readiness', () => { expect(started).not.toHaveBeenCalled() expect(headlessControl.stop).toHaveBeenCalledTimes(1) }) + + // #1355: the package's serve readiness default (10 s) was sized for an idle + // machine; under load a healthy server took 16.7-43.1 s to report its URL + // (plan evidence). The app owns the process and passes its own wait. + it('gives the spawned server the load-tolerant startup wait', async () => { + headlessControl.options.length = 0 + await new OpencodeSession({ cwd: '/tmp/project' }).start() + expect(headlessControl.options.at(-1)).toMatchObject({ startupTimeoutMs: OPENCODE_SERVE_STARTUP_TIMEOUT_MS }) + // At least twice the worst healthy start measured (43.1 s), the margin the + // constant's comment claims; merely above it (#1367 review a: 44 s passed) + // would fail the next slightly slower machine. + expect(OPENCODE_SERVE_STARTUP_TIMEOUT_MS).toBeGreaterThanOrEqual(2 * 43_100) + // And at most about four times it (#1367 review c): the wait is also how + // long a serve that stays alive but never listens holds the pane on + // "starting". A stray zero (1_200_000) would make that twenty minutes. + expect(OPENCODE_SERVE_STARTUP_TIMEOUT_MS).toBeLessThanOrEqual(4 * 43_100) + }) + + // #1367 review c: a start that rejects after the server is already up (a + // resume whose history replay fails) must stop the server it spawned. With + // the longer wait this rollback is where every rejected start ends, and + // without it a live `opencode serve` child outlives the pane that owned it. + it('stops the server when startup rejects', async () => { + headlessControl.rejectStart = new Error('history replay failed') + const session = new OpencodeSession({ cwd: '/tmp/project' }) + await expect(session.start()).rejects.toThrow('history replay failed') + expect(headlessControl.stop).toHaveBeenCalledTimes(1) + }) }) diff --git a/src/providers/opencode/runtime/opencodeSession.ts b/src/providers/opencode/runtime/opencodeSession.ts index 5cc864755..98b43bb3c 100644 --- a/src/providers/opencode/runtime/opencodeSession.ts +++ b/src/providers/opencode/runtime/opencodeSession.ts @@ -114,6 +114,26 @@ export interface OpencodeSession { ): boolean } +/** + * How long a spawned `opencode serve` may take to report its URL (#1355). + * + * WHY the app sets it rather than taking the package's 10 s default: that + * default was sized for an idle machine. Measured on the bundled binary + * (OpenCode 1.18.31), the server reports its URL in 0.6-0.9 s idle, but + * 16.7 s, 18.3 s and 43.1 s under CPU contention like a worker fleet's + * (plan: docs/plans/2026-09-27-opencode-serve-startup-under-load.md), and + * every one of those starts was healthy. The fixed deadline killed healthy + * servers, so orchestration's OpenCode reviewers failed to spawn under load. + * + * 120 s is about 3x the worst healthy start measured. The ceiling only has to + * bound a server that stays alive but never listens, a hang no recording has + * shown. A server that DIES still fails at once through the package's exit + * path, so a real crash is not slowed down. A CPU-progress watchdog would tell + * a hang from starvation sooner; it needs a per-platform child CPU probe, and + * is only worth it if a real hang is ever recorded. + */ +export const OPENCODE_SERVE_STARTUP_TIMEOUT_MS = 120_000 + export class OpencodeSession extends EventEmitter implements AgentSession { private headless: OpencodeHeadless | null = null private exited = false @@ -172,6 +192,8 @@ export class OpencodeSession extends EventEmitter implements AgentSession { cwd: this.cwd, binary: this.binary, env, + // See OPENCODE_SERVE_STARTUP_TIMEOUT_MS (#1355). + startupTimeoutMs: OPENCODE_SERVE_STARTUP_TIMEOUT_MS, // Resume replays that session's committed history inside start() // (publishSessionMessages), which is why every listener below is // attached BEFORE start() is awaited — otherwise the replayed diff --git a/src/renderer/src/app/storageEnvironment.renderer.test.ts b/src/renderer/src/app/storageEnvironment.renderer.test.ts new file mode 100644 index 000000000..c9e45a46b --- /dev/null +++ b/src/renderer/src/app/storageEnvironment.renderer.test.ts @@ -0,0 +1,19 @@ +import { expect, it } from 'vitest' + +// #1212: under Node 25 the global localStorage was Node's half-initialised Web +// Storage (no clear, reads undefined) instead of happy-dom's. +// testing/setup/renderer.ts installs a working one; this checks the renderer +// test environment really has it. +// Review c of #1408: with --localstorage-file, Node 25's storage is +// file-backed and was kept, so a file could start with another process's keys. +it('starts every test file with an empty DOM storage', () => { + expect(window.localStorage.length).toBe(0) + expect(window.sessionStorage.length).toBe(0) +}) + +it('leaves the test environment with a working storage', () => { + expect(typeof window.localStorage.clear).toBe('function') + window.localStorage.setItem('probe', '1') + expect(window.localStorage.getItem('probe')).toBe('1') + window.localStorage.clear() +}) diff --git a/src/renderer/src/features/ai-workspace/ui/AiWorkspaceEditor.tsx b/src/renderer/src/features/ai-workspace/ui/AiWorkspaceEditor.tsx index bd4781d3d..b80da9707 100644 --- a/src/renderer/src/features/ai-workspace/ui/AiWorkspaceEditor.tsx +++ b/src/renderer/src/features/ai-workspace/ui/AiWorkspaceEditor.tsx @@ -75,6 +75,16 @@ export function AiWorkspaceEditor({ workspaceId, visible, onClose, toolbarAction const [loading, setLoading] = useState(true) const [saveAllPending, setSaveAllPending] = useState(false) const [error, setError] = useState(() => cached?.error ?? null) + // WHY a separate, retained notice (#1285, #1416 review a): a write can land + // while the registry fails to save its status (a preservation copy it owes + // is blocked). The file is saved, so this is not the tab's error, but the + // user must learn that AI Workspace storage is blocked, since every later + // collection change will be refused. It cannot ride `error`: loadWorkspace, + // which runs after every save, clears that. It is set from the write + // result AND from every load (main's `storageWarning`), so it survives a + // remount. The text is main's fixed sentence, never a raw filesystem + // message. + const [storageWarning, setStorageWarning] = useState(null) const [fileOrder, setFileOrder] = useState(() => cached?.fileOrder ?? []) const [openFiles, setOpenFiles] = useState>( () => cached?.openFiles ?? {}, @@ -191,6 +201,10 @@ export function AiWorkspaceEditor({ workspaceId, visible, onClose, toolbarAction } setWorkspace(next) setError(next ? null : 'AI Workspace not found') + // The durable source of the storage notice (#1416 review b): main + // reports it on every load, so a remounted editor (a workspace switch) + // still shows it, and so does one that missed the write's own result. + setStorageWarning(next?.storageWarning ?? null) return next } catch (err) { if ( @@ -554,6 +568,7 @@ export function AiWorkspaceEditor({ workspaceId, visible, onClose, toolbarAction }) return null } + if (mountedRef.current) setStorageWarning(result.warning ?? null) applyOpenFiles(prev => { const current = prev[entryId] if (!current || current.generation !== buffer.generation) return prev @@ -760,6 +775,7 @@ export function AiWorkspaceEditor({ workspaceId, visible, onClose, toolbarAction } }) if (result.ok) { + if (mountedRef.current) setStorageWarning(result.warning ?? null) await revalidateEntryAfterWrite(entryId, entry.path, buffer.generation) } else { entryReadGenerationRef.current.set( @@ -794,7 +810,7 @@ export function AiWorkspaceEditor({ workspaceId, visible, onClose, toolbarAction title={workspace?.name ?? 'AI Workspace'} entries={workspace?.entries ?? []} loading={loading} - error={error} + error={error ?? storageWarning} activeEntryId={activeFilePath} onOpenEntry={entry => void openEntry(entry)} onRefresh={() => void refreshWorkspace()} diff --git a/src/renderer/src/features/browser-pocket/ui/pick.renderer.test.ts b/src/renderer/src/features/browser-pocket/ui/pick.renderer.test.ts index 84e80eb3f..7a72f8790 100644 --- a/src/renderer/src/features/browser-pocket/ui/pick.renderer.test.ts +++ b/src/renderer/src/features/browser-pocket/ui/pick.renderer.test.ts @@ -63,6 +63,17 @@ describe('pickIntoComposer', () => { expect(toast).toHaveBeenCalledWith(expect.stringMatching(/copied/i)) }) + // #1421 review b: a refused write was swallowed and "Element copied" shown + // anyway, so the user pasted whatever the clipboard held before. + it('without a composer, says a refused copy instead of claiming it', async () => { + const writeText = vi.fn(async () => { throw new DOMException('Document is not focused.', 'NotAllowedError') }) + Object.defineProperty(navigator, 'clipboard', { value: { writeText }, configurable: true }) + const toast = vi.fn() + const { ws } = workspace('claude', '') + await pickIntoComposer('p1', 's1' as never, ws, vi.fn(), toast) + expect(toast.mock.calls).toEqual([["Couldn't copy to the clipboard. Click into the app and try again."]]) + }) + it('a cancelled pick changes nothing', async () => { window.api = { ...(window.api ?? {}), pickInPocket: vi.fn(async () => null) } as unknown as typeof window.api composer('s1', 'draft', 5) diff --git a/src/renderer/src/features/browser-pocket/ui/pick.ts b/src/renderer/src/features/browser-pocket/ui/pick.ts index 8eb0e338a..b190e849c 100644 --- a/src/renderer/src/features/browser-pocket/ui/pick.ts +++ b/src/renderer/src/features/browser-pocket/ui/pick.ts @@ -1,4 +1,5 @@ import { getRendererProviderCapabilities } from '@providers/registry.renderer.capabilities' +import { CLIPBOARD_WRITE_FAILED } from '@renderer/lib/clipboardFailure' import { formatElementChip, insertAtCaret } from '@shared/browserPocket/elementChip' import { isAgentProviderKind } from '@shared/types/providerKind' import type { Workspace } from '@renderer/workspace/workspaceStore' @@ -31,7 +32,15 @@ export async function pickIntoComposer(pocketId: string, sessionId: SessionId, w const chip = formatElementChip(result) const composer = document.querySelector(`[data-composer-input="${CSS.escape(sessionId)}"]`) if (!composer) { - await navigator.clipboard.writeText(chip).catch(() => {}) + // WHY the write is checked (#1421 review b): a refused write was + // swallowed and "Element copied" shown anyway, so the user pasted + // whatever the clipboard held before. + try { + await navigator.clipboard.writeText(chip) + } catch { + showToast(CLIPBOARD_WRITE_FAILED) + return + } showToast('Element copied — paste it into the agent') return } diff --git a/src/renderer/src/features/workspace/commands/copyCommands.clipboard.renderer.test.ts b/src/renderer/src/features/workspace/commands/copyCommands.clipboard.renderer.test.ts new file mode 100644 index 000000000..33048f360 --- /dev/null +++ b/src/renderer/src/features/workspace/commands/copyCommands.clipboard.renderer.test.ts @@ -0,0 +1,105 @@ +import { readFileSync } from 'node:fs' + +import { afterEach, describe, expect, it, vi } from 'vitest' + +import { emptyRuntime } from '@renderer/session-runtime/state' +import type { CommandContext } from '@renderer/features/command-palette/types' +import type { Workspace } from '@renderer/workspace/hook' +import { CLIPBOARD_WRITE_FAILED } from '@renderer/lib/clipboardFailure' +import { paneCommands } from '@renderer/features/workspace/commands/paneCommands' +import { sessionCommands } from '@renderer/features/workspace/commands/sessionCommands' +import { oneLaneStage } from '@renderer/workspace/testing/stageFixtures' + +// #1250 row 9: Copy Last Response wrote to the clipboard fire-and-forget and +// said "Copied to clipboard" whatever happened, so a refused write (Electron +// refuses when the document is not focused) was silent under a toast that said +// the opposite. The resume-command copy did catch, but showed the raw +// DOMException text (q22). +// +// The runtime entries are a RECORDED session (a Codex rendering bundle). The +// clipboard is the one replaced edge: its rejection is the case under test. + +const bundle = JSON.parse(readFileSync('testing/fixtures/rendering-bundles/2026-05-20T19-11-51-193-d4a44a16.json', 'utf8')) as { + input: { provider: string; entries: unknown[] } +} + +const originalClipboard = Object.getOwnPropertyDescriptor(navigator, 'clipboard') +afterEach(() => { + if (originalClipboard) Object.defineProperty(navigator, 'clipboard', originalClipboard) + else Reflect.deleteProperty(navigator, 'clipboard') +}) + +function stubClipboard(writeText: (text: string) => Promise) { + Object.defineProperty(navigator, 'clipboard', { configurable: true, value: { writeText: vi.fn(writeText) } }) +} + +function context(kind: string) { + const toasts: string[] = [] + const ctx = { + workspace: { + state: { + activeTabId: 'tab', + stage: oneLaneStage('agent'), + pinnedSessionIds: [], + sessions: { agent: { cwd: '/projects/app', kind, providerSessionId: 'provider-abc', projectId: 'tab', joinedAt: 0 } }, + tabs: [{ id: 'tab' }], + }, + getRuntime: () => ({ ...emptyRuntime(), entries: bundle.input.entries }), + showPaneToast: (_sessionId: string, message: string) => { toasts.push(message) }, + } as unknown as Workspace, + ui: { closePalette: vi.fn() }, + flags: {}, + } as unknown as CommandContext + return { ctx, toasts } +} + +const copyLast = paneCommands.find(command => command.id === 'copy-last-assistant')! +const copyResume = sessionCommands.find(command => command.id === 'copy-resume-command')! + +describe('copy commands and a refused clipboard', () => { + const refused = () => Promise.reject(new DOMException('Document is not focused.', 'NotAllowedError')) + + it('says a refused Copy Last Response did not copy, and never claims it did', async () => { + stubClipboard(refused) + const { ctx, toasts } = context(bundle.input.provider) + await copyLast.run(ctx) + // The literal words (#1421 review b, c): comparing against the constant + // alone would let the advice be reworded away unnoticed. + expect(toasts).toEqual(["Couldn't copy to the clipboard. Click into the app and try again."]) + expect(CLIPBOARD_WRITE_FAILED).toBe(toasts[0]) + }) + + // #1421 review a: the command's promise is the dispatcher's single-flight + // and outcome; it must not resolve (or say anything) before the write does. + it('stays pending, and silent, until the clipboard write settles', async () => { + let finish!: () => void + stubClipboard(() => new Promise(resolve => { finish = resolve })) + const { ctx, toasts } = context(bundle.input.provider) + let settled = false + const running = Promise.resolve(copyLast.run(ctx)).then(() => { settled = true }) + await Promise.resolve(); await Promise.resolve() + expect(settled).toBe(false) + expect(toasts).toEqual([]) + finish() + await running + expect(toasts).toEqual(['Copied to clipboard']) + }) + + it('says Copied only after the clipboard took the recorded response', async () => { + let written = '' + stubClipboard(async text => { written = text }) + const { ctx, toasts } = context(bundle.input.provider) + await copyLast.run(ctx) + expect(written.length).toBeGreaterThan(0) + expect(toasts).toEqual(['Copied to clipboard']) + }) + + it('says a refused resume-command copy in fixed words, not the browser text', async () => { + stubClipboard(refused) + const { ctx, toasts } = context('claude') + expect(copyResume.when?.(ctx)).toBe(true) + await copyResume.run(ctx) + expect(toasts).toEqual([CLIPBOARD_WRITE_FAILED]) + expect(toasts.join(' ')).not.toContain('not focused') + }) +}) diff --git a/src/renderer/src/features/workspace/commands/paneCommands.ts b/src/renderer/src/features/workspace/commands/paneCommands.ts index 009999f9c..9cbd949d8 100644 --- a/src/renderer/src/features/workspace/commands/paneCommands.ts +++ b/src/renderer/src/features/workspace/commands/paneCommands.ts @@ -15,6 +15,7 @@ import { commandTargetSessionId } from '@renderer/workspace/hook/selectors/comma import { submitActiveComposer } from '@renderer/workspace/tile-tree/TileLeaf/composerEnterRegistry' import { sessionHasTranscript } from '@renderer/workspace/transcriptAvailability' import { isWorkingAgent } from '@renderer/workspace/agentFollow' +import { CLIPBOARD_WRITE_FAILED } from '@renderer/lib/clipboardFailure' // DELETED with the unified layout (#992) — see RETIRED_COMMAND_IDS in // catalog.test.ts for the ledger: @@ -454,14 +455,23 @@ export const paneCommands: CommandDef[] = [ // its committed entries, so there is a real last response to copy. return sessionHasTranscript(workspace.state.sessions[sessionId]) }, - run: ({ workspace, target }) => { + run: async ({ workspace, target }) => { const sessionId = commandTarget({ workspace, target }) if (!sessionId) return const runtime = workspace.getRuntime(sessionId) const kind = workspace.state.sessions[sessionId]?.kind ?? DEFAULT_PROVIDER const text = extractLastAssistantText(runtime.entries, kind) if (text) { - void navigator.clipboard.writeText(text) + // WHY awaited (#1250 row 9): the write used to be fire-and-forget + // with "Copied" shown unconditionally, so a refused write (an + // unfocused document) was an unhandled rejection under a toast that + // said the opposite. + try { + await navigator.clipboard.writeText(text) + } catch { + workspace.showPaneToast(sessionId, CLIPBOARD_WRITE_FAILED) + return + } workspace.showPaneToast(sessionId, 'Copied to clipboard') return } diff --git a/src/renderer/src/features/workspace/commands/sessionCommands.ts b/src/renderer/src/features/workspace/commands/sessionCommands.ts index 905804847..b8e8281c0 100644 --- a/src/renderer/src/features/workspace/commands/sessionCommands.ts +++ b/src/renderer/src/features/workspace/commands/sessionCommands.ts @@ -1,4 +1,5 @@ import { commandTarget } from '@renderer/features/command-palette/commandTarget' +import { CLIPBOARD_WRITE_FAILED } from '@renderer/lib/clipboardFailure' import { clonedMcpOverrides } from '@renderer/workspace/mcpDomains' import { DEFAULT_PROVIDER, effectiveProviderRuntime, isAgentProviderKind } from '@shared/types/providerKind' import { getRendererProviderCapabilities } from '@providers/registry.renderer.capabilities' @@ -775,9 +776,10 @@ export const sessionCommands: CommandDef[] = [ try { await navigator.clipboard.writeText(command) workspace.showPaneToast(sessionId, `copied resume command · ${command}`, 5000) - } catch (err) { - const msg = (err as Error)?.message ?? String(err) - workspace.showPaneToast(sessionId, `copy failed: ${msg}`, 4000) + } catch { + // Fixed words (q22, #1250 row 9): the rejection's message is browser + // text, not something written for the user. + workspace.showPaneToast(sessionId, CLIPBOARD_WRITE_FAILED, 4000) } }, contextMenu: { group: 'copy', order: 10 }, diff --git a/src/renderer/src/lib/clipboardFailure.ts b/src/renderer/src/lib/clipboardFailure.ts new file mode 100644 index 000000000..bd145d97f --- /dev/null +++ b/src/renderer/src/lib/clipboardFailure.ts @@ -0,0 +1,9 @@ +// What a copy action says when the clipboard refused the write (#1250 row 9): +// the copy commands, the assistant-message picker and Browser Pocket's pick, +// so one failure mode has one sentence (#1421 review c). +// +// WHY fixed words: the rejection is a DOMException whose message is browser +// text ("Document is not focused."), and user-visible text is curated (q22). +// WHY this advice: Electron's clipboard write needs a focused document, and +// the usual cause is focus left elsewhere by the palette or a context menu. +export const CLIPBOARD_WRITE_FAILED = "Couldn't copy to the clipboard. Click into the app and try again." diff --git a/src/renderer/src/workspace/hook/actions/picker.ts b/src/renderer/src/workspace/hook/actions/picker.ts index 1e080a56d..2b8781b15 100644 --- a/src/renderer/src/workspace/hook/actions/picker.ts +++ b/src/renderer/src/workspace/hook/actions/picker.ts @@ -1,5 +1,6 @@ import { useCallback } from 'react' +import { CLIPBOARD_WRITE_FAILED } from '@renderer/lib/clipboardFailure' import { emptyRuntime } from '@renderer/session-runtime/state' import type { SessionId } from '@renderer/workspace/types' import { @@ -150,7 +151,8 @@ export function usePickerActions( await navigator.clipboard.writeText(text) showPaneToast(sessionId, 'Copied assistant message') } catch { - showPaneToast(sessionId, 'Clipboard write failed') + // The shared sentence (#1421 review c), with its advice. + showPaneToast(sessionId, CLIPBOARD_WRITE_FAILED) } }, [refs.latestRuntimesRef, setRuntimes, showPaneToast], diff --git a/src/renderer/src/workspace/hook/persistence/useFeedDebugPersist.renderer.test.tsx b/src/renderer/src/workspace/hook/persistence/useFeedDebugPersist.renderer.test.tsx index f5a6d44a8..98fedd953 100644 --- a/src/renderer/src/workspace/hook/persistence/useFeedDebugPersist.renderer.test.tsx +++ b/src/renderer/src/workspace/hook/persistence/useFeedDebugPersist.renderer.test.tsx @@ -12,6 +12,7 @@ import { useFeedDebugPersist } from './useFeedDebugPersist' const originalApiDescriptor = Object.getOwnPropertyDescriptor(window, 'api') const append = vi.fn<(input: Parameters[0]) => Promise>() +const forget = vi.fn<(input: Parameters[0]) => Promise>() beforeEach(() => { // The cadence tests below are about HOW persistence works once it is on @@ -19,7 +20,8 @@ beforeEach(() => { useDevDebugConfig.setState({ enabled: true, sessionRecordingEnabled: false }) vi.useFakeTimers() append.mockReset().mockResolvedValue(undefined) - Object.defineProperty(window, 'api', { configurable: true, value: { appendFeedDebugLog: append } }) + forget.mockReset().mockResolvedValue(undefined) + Object.defineProperty(window, 'api', { configurable: true, value: { appendFeedDebugLog: append, forgetFeedDebugLog: forget } }) }) afterEach(() => { @@ -279,6 +281,141 @@ describe('feed debug persistence cadence and durability', () => { }) }) +// #1392: main forgets a session's feed-debug state at PROCESS exit, but the +// pane outlives the process and its later appends re-create that state. Only +// the renderer knows when a session can never append again: its runtime is +// gone. Then, and only then, it releases the id to main. +describe('releasing a session whose runtime is gone (#1392)', () => { + it('forgets a removed session once, after its last flush, and keeps live ones', async () => { + const refs = makeRefs({ a: add(emptyRuntime(), 'a row'), b: add(emptyRuntime(), 'b row') }) + renderHook(() => useFeedDebugPersist(refs)) + await advance(1_000) + expect(append).toHaveBeenCalledTimes(2) + expect(forget).not.toHaveBeenCalled() + + // Pane `a` closes: its runtime is removed. + refs.latestRuntimesRef.current = { b: refs.latestRuntimesRef.current.b! } + await advance(1_000) + expect(forget).toHaveBeenCalledExactlyOnceWith({ sessionId: 'a', persistUnmarkedDrops: true }) + expect(refs.persistedFeedDebugIdRef.current).not.toHaveProperty('a') + expect(refs.persistedFeedDebugIdRef.current.b).toBe(1) + + await advance(3_000) + expect(forget).toHaveBeenCalledTimes(1) + }) + + it('retries a release main did not acknowledge', async () => { + const refs = makeRefs({ a: add(emptyRuntime(), 'a row') }) + renderHook(() => useFeedDebugPersist(refs)) + await advance(1_000) + forget.mockRejectedValueOnce(new Error('ipc down')) + refs.latestRuntimesRef.current = {} + await advance(1_000) + await advance(1_000) + expect(forget).toHaveBeenCalledTimes(2) + await advance(2_000) + expect(forget).toHaveBeenCalledTimes(2) + }) + + it('drops the in-flight reservation, so a re-added id can flush again', async () => { + const pending = deferred() + append.mockReturnValueOnce(pending.promise) + const refs = makeRefs({ a: add(emptyRuntime(), 'first') }) + renderHook(() => useFeedDebugPersist(refs)) + await advance(1_000) + expect(refs.inFlightFeedDebugIdRef.current.a).toBe(1) + refs.latestRuntimesRef.current = {} + await advance(1_000) + expect(refs.inFlightFeedDebugIdRef.current).not.toHaveProperty('a') + refs.latestRuntimesRef.current = { a: add(emptyRuntime(), 'new generation') } + await advance(1_000) + expect(append).toHaveBeenCalledTimes(2) + pending.resolve() + }) + + it('sends one release while its acknowledgement is pending', async () => { + const ack = deferred() + forget.mockReturnValueOnce(ack.promise) + const refs = makeRefs({ a: add(emptyRuntime(), 'a row') }) + renderHook(() => useFeedDebugPersist(refs)) + await advance(1_000) + refs.latestRuntimesRef.current = {} + await advance(4_000) + expect(forget).toHaveBeenCalledTimes(1) + ack.resolve() + await advance(2_000) + expect(forget).toHaveBeenCalledTimes(1) + }) + + it('does not let a late acknowledgement retire a later lifetime of the same id', async () => { + const ack = deferred() + forget.mockReturnValueOnce(ack.promise) + const first = add(emptyRuntime(), 'first lifetime') + const refs = makeRefs({ a: first }) + renderHook(() => useFeedDebugPersist(refs)) + await advance(1_000) + refs.latestRuntimesRef.current = {} + await advance(1_000) + expect(forget).toHaveBeenCalledTimes(1) + // The id comes back and appends (main re-creates its state), then goes + // away again, all before the first release is acknowledged. + refs.latestRuntimesRef.current = { a: add(emptyRuntime(), 'second lifetime') } + await advance(1_000) + expect(append).toHaveBeenCalledTimes(2) + refs.latestRuntimesRef.current = {} + ack.resolve() + await advance(2_000) + expect(forget).toHaveBeenCalledTimes(2) + }) + + it('does not throw from the interval when the API lacks the release method', async () => { + Object.defineProperty(window, 'api', { configurable: true, value: { appendFeedDebugLog: append } }) + const refs = makeRefs({ a: add(emptyRuntime(), 'a row') }) + renderHook(() => useFeedDebugPersist(refs)) + await advance(1_000) + refs.latestRuntimesRef.current = {} + await expect(advance(3_000)).resolves.toBeUndefined() + }) + + // Review c: switching persistence off destroyed the release bookkeeping, so + // a pane closed across the toggle was never released, one leaked entry per + // such session for the life of main. + it('releases a session that closed while persistence was off', async () => { + const refs = makeRefs({ a: add(emptyRuntime(), 'persisted row') }) + renderHook(() => useFeedDebugPersist(refs)) + await advance(1_000) + expect(append).toHaveBeenCalledTimes(1) + act(() => { useDevDebugConfig.setState({ enabled: false, sessionRecordingEnabled: false }) }) + refs.latestRuntimesRef.current = {} + await advance(2_000) + // Review c, round 2: an off-state release must not make main write the + // final drop marker. + expect(forget).toHaveBeenCalledExactlyOnceWith({ sessionId: 'a', persistUnmarkedDrops: false }) + expect(append).toHaveBeenCalledTimes(1) + }) + + it('releases it after persistence is switched back on too', async () => { + const refs = makeRefs({ a: add(emptyRuntime(), 'persisted row') }) + renderHook(() => useFeedDebugPersist(refs)) + await advance(1_000) + forget.mockRejectedValue(new Error('ipc down')) + act(() => { useDevDebugConfig.setState({ enabled: false, sessionRecordingEnabled: false }) }) + refs.latestRuntimesRef.current = {} + await advance(1_000) + forget.mockResolvedValue(undefined) + act(() => { useDevDebugConfig.setState({ enabled: true, sessionRecordingEnabled: false }) }) + await advance(2_000) + expect(forget.mock.calls.at(-1)).toEqual([{ sessionId: 'a', persistUnmarkedDrops: true }]) + }) + + it('does not forget a session that never had a runtime while mounted', async () => { + const refs = makeRefs({}) + renderHook(() => useFeedDebugPersist(refs)) + await advance(2_000) + expect(forget).not.toHaveBeenCalled() + }) +}) + // #767 item 1: disk persistence is opt-in. The ring keeps recording either way — // debug bundles read the ring, not the file. describe('feed debug persistence gate', () => { diff --git a/src/renderer/src/workspace/hook/persistence/useFeedDebugPersist.ts b/src/renderer/src/workspace/hook/persistence/useFeedDebugPersist.ts index b8e021966..14e56b016 100644 --- a/src/renderer/src/workspace/hook/persistence/useFeedDebugPersist.ts +++ b/src/renderer/src/workspace/hook/persistence/useFeedDebugPersist.ts @@ -95,8 +95,16 @@ export function useFeedDebugPersist(refs: WorkspaceRefs): void { // still wrote one last batch to disk). const enabledRef = useRef(enabled) enabledRef.current = enabled + // The release bookkeeping (see releaseGone) lives in a ref, not in the + // effect: the effect re-runs whenever persistence is switched on or off, + // and a set recreated there forgot every id it was tracking, so a pane + // closed across a persistence toggle was never released (#1392 review c). + const releaseStateRef = useRef({ + known: new Set(), + releasing: new Set(), + seenSinceRelease: new Set(), + }) useEffect(() => { - if (!enabled) return const flushSession = (sessionId: SessionId, runtime: SessionRuntime): void => { if (runtime.feedDebugLog.length === 0) return const lastPersistedId = refs.persistedFeedDebugIdRef.current[sessionId] ?? 0 @@ -158,10 +166,66 @@ export function useFeedDebugPersist(refs: WorkspaceRefs): void { }) } + // Sessions this hook has seen a runtime for. A session whose runtime is + // gone (pane closed, or replaced by a new id) can never append again, so + // it is released here: its flush cursors, and main's per-session state + // (#1392). Main's own forget runs at PROCESS exit, but the pane outlives + // the process (exit rows, a same-id wake) and its later appends + // re-created that state with nothing left to forget it. + // + // Entries not yet flushed when the runtime was removed are lost, as they + // were before: this changes only what is forgotten, not what is written. + // + // An id leaves `known` only once main has ACKNOWLEDGED the release: a + // failed IPC is retried on the next tick (#1392 review a, round 3), or + // main would keep that session's state until the process exits. + // `releasing` stops a slow acknowledgement from sending it twice. + // + // A release covers only the lifetime it was SENT for (#1392 review b, + // round 4): if the id reappears (and appends, re-creating main's state) + // while an acknowledgement is still in flight, that late ACK must not + // retire the later lifetime. `seenSinceRelease` records a reappearance; + // the ACK then leaves the id in `known`, and the next absence sends a new + // release. + // + // Releasing keeps running while persistence is OFF (#767): a session that + // appended while persistence was on still has state in main after the + // user switches persistence off (#1392 review c). The release then tells + // main not to persist unmarked drops, so it causes no disk write either + // (review c, round 2). + // + // Known residual: a release that fails during the hook's own teardown + // (workspace unmount) has no later tick to retry it. Main keeps that one + // session's few numbers until it exits. + const { known, releasing, seenSinceRelease } = releaseStateRef.current + const releaseGone = (): void => { + const runtimes = refs.latestRuntimesRef.current + for (const sessionId of known) { + if (runtimes[sessionId] || releasing.has(sessionId)) continue + delete refs.persistedFeedDebugIdRef.current[sessionId] + delete refs.inFlightFeedDebugIdRef.current[sessionId] + releasing.add(sessionId) + seenSinceRelease.delete(sessionId) + // Promise.resolve().then: a synchronous throw (a test double without + // the method) becomes a rejection, retried like any failed release, + // instead of escaping the interval with `releasing` held. + void Promise.resolve() + // Off means no disk writes, including main's final drop marker + // (#1392 review c, round 2); read at send time, not effect time. + .then(() => window.api.forgetFeedDebugLog({ sessionId, persistUnmarkedDrops: enabledRef.current })) + .then(() => { if (!seenSinceRelease.has(sessionId)) known.delete(sessionId) }, () => {}) + .finally(() => releasing.delete(sessionId)) + } + } + const flush = (): void => { for (const [sessionId, runtime] of Object.entries(refs.latestRuntimesRef.current)) { - flushSession(sessionId, runtime) + known.add(sessionId) + if (releasing.has(sessionId)) seenSinceRelease.add(sessionId) + // Disk writes only while persistence is on; releases always. + if (enabled) flushSession(sessionId, runtime) } + releaseGone() } // WHY an interval independent of runtimes: busy agents replace that map @@ -179,6 +243,7 @@ export function useFeedDebugPersist(refs: WorkspaceRefs): void { // Not when persistence was just switched off: the user asked for no // more disk writes. if (enabledRef.current) flush() + else releaseGone() } }, [ enabled, diff --git a/src/renderer/src/workspace/tile-tree/TileLeaf/claudeImages.ts b/src/renderer/src/workspace/tile-tree/TileLeaf/claudeImages.ts index af4d98bbb..abcfa94c0 100644 --- a/src/renderer/src/workspace/tile-tree/TileLeaf/claudeImages.ts +++ b/src/renderer/src/workspace/tile-tree/TileLeaf/claudeImages.ts @@ -86,7 +86,9 @@ export function parseImagesFromHtml(html: string): ClaudeDraftImage[] { // the HTML is never injected into the live DOM. const doc = new DOMParser().parseFromString(html, 'text/html') const images: ClaudeDraftImage[] = [] - for (const img of Array.from(doc.images)) { + // querySelectorAll, not `doc.images`: identical in a browser, and the + // happy-dom test DOM has no `images` collection on a parsed document. + for (const img of Array.from(doc.querySelectorAll('img'))) { const src = img.getAttribute('src')?.trim() ?? '' if (!src.startsWith('data:image/')) continue try { diff --git a/src/renderer/src/workspace/tile-tree/TileLeaf/useClaudeImagePaste.renderer.test.tsx b/src/renderer/src/workspace/tile-tree/TileLeaf/useClaudeImagePaste.renderer.test.tsx new file mode 100644 index 000000000..47507da93 --- /dev/null +++ b/src/renderer/src/workspace/tile-tree/TileLeaf/useClaudeImagePaste.renderer.test.tsx @@ -0,0 +1,117 @@ +import { readFileSync } from 'node:fs' + +import { act, renderHook } from '@testing-library/react' +import { afterEach, describe, expect, it, vi } from 'vitest' + +import { useClaudeImagePaste } from './useClaudeImagePaste' + +// #1250 row 7: only Claude's composer takes pasted images. A screenshot +// pasted into a Codex, OpenCode, Grok or Pi composer was dropped with nothing +// said. +// +// The REAL hook with the real provider capabilities. The image bytes are a +// RECORDED user attachment (testing/fixtures/image-reads/claude-user-attachment.json); +// the paste event's clipboardData, and navigator.clipboard.read for the async +// case, are the stubbed edges, shaped as the browser gives them. + +const recorded = JSON.parse(readFileSync('testing/fixtures/image-reads/claude-user-attachment.json', 'utf8')) as { + entry: { message: { content: Array<{ source?: { data: string; media_type: string } }> } } +} +const source = recorded.entry.message.content[1]!.source! +const png = new File([Buffer.from(source.data, 'base64')], 'screenshot.png', { type: source.media_type }) +const dataUrlImg = `` + +const originalClipboard = Object.getOwnPropertyDescriptor(navigator, 'clipboard') +afterEach(() => { + if (originalClipboard) Object.defineProperty(navigator, 'clipboard', originalClipboard) + else Reflect.deleteProperty(navigator, 'clipboard') +}) + +function paste(options: { image?: boolean; text?: string; html?: string; items?: Array<{ kind: string; type: string }> }) { + const items = options.items ?? (options.image ? [{ kind: 'file', type: png.type, getAsFile: () => png }] : []) + return { + clipboardData: { + items, + getData: (type: string) => (type === 'text/plain' ? options.text ?? '' : type === 'text/html' ? options.html ?? '' : ''), + } as unknown as DataTransfer, + preventDefault: vi.fn(), + } +} + +function hook(provider: 'codex' | 'opencode' | 'grok' | 'pi' | 'claude') { + const showToast = vi.fn() + const setDraftImages = vi.fn() + const { result } = renderHook(() => useClaudeImagePaste({ provider, sessionId: 's1' as never, setDraftImages, showToast })) + return { handlePaste: result.current.handlePaste, showToast, setDraftImages } +} + +describe('pasting an image into a composer that cannot take one', () => { + // Each provider is named: the sentence is built from its label (#1426 review a). + it.each([ + ['codex', 'Codex'], + ['opencode', 'OpenCode'], + ['grok', 'Grok'], + ['pi', 'Pi'], + ] as const)('says so for an image-only paste into %s', async (provider, label) => { + const { handlePaste, showToast } = hook(provider) + let answer: unknown + await act(async () => { answer = await handlePaste(paste({ image: true })) }) + expect(showToast).toHaveBeenCalledWith(`Pasted images can't be sent to ${label} from this composer.`) + expect(answer).toEqual({ handledImages: false }) + }) + + // #1426 review b: "see attached" with the attachment silently dropped. + it('says the image was left out of an image-plus-text paste', async () => { + const { handlePaste, showToast } = hook('codex') + await act(async () => { await handlePaste(paste({ image: true, text: 'see attached' })) }) + expect(showToast).toHaveBeenCalledWith("Pasted images can't be sent to Codex from this composer; only the text was pasted.") + }) + + // #1426 review a, b: a browser image copy that arrives only as a data-URL + // in text/html. + it('says so for an image that arrives only as HTML', async () => { + const { handlePaste, showToast } = hook('codex') + await act(async () => { await handlePaste(paste({ html: dataUrlImg })) }) + expect(showToast).toHaveBeenCalledWith("Pasted images can't be sent to Codex from this composer.") + }) + + // #1426 review a: an image only the async clipboard API shows. + it('says so for an image only the async clipboard shows', async () => { + Object.defineProperty(navigator, 'clipboard', { + configurable: true, + value: { read: vi.fn(async () => [{ types: [png.type], getType: async () => png }]) }, + }) + const { handlePaste, showToast } = hook('codex') + await act(async () => { await handlePaste(paste({})) }) + expect(showToast).toHaveBeenCalledWith("Pasted images can't be sent to Codex from this composer.") + }) + + it('stays silent for plain text, and for a web-page copy (an beside its text)', async () => { + const { handlePaste, showToast } = hook('codex') + await act(async () => { await handlePaste(paste({ text: 'hello' })) }) + await act(async () => { await handlePaste(paste({ text: 'an article', html: `

an article

${dataUrlImg}` })) }) + expect(showToast).not.toHaveBeenCalled() + }) + + it('does not say it for Claude, which takes the image', async () => { + const { handlePaste, showToast, setDraftImages } = hook('claude') + let answer: unknown + await act(async () => { answer = await handlePaste(paste({ image: true })) }) + expect(showToast).not.toHaveBeenCalledWith(expect.stringContaining("can't be sent")) + // Taken, not just unmentioned (#1426 review c). + expect(answer).toEqual({ handledImages: true }) + expect(setDraftImages).toHaveBeenCalled() + }) + + // #1426 review c: only an IMAGE FILE counts. A PDF, a type-less Finder file, + // or a string item that happens to say image/* is not an image paste, and a + // missing clipboardData says nothing. + it('stays silent for a non-image file, a string item, and no clipboard data', async () => { + const { handlePaste, showToast } = hook('codex') + await act(async () => { await handlePaste(paste({ items: [{ kind: 'file', type: 'application/pdf' }] })) }) + await act(async () => { await handlePaste(paste({ items: [{ kind: 'file', type: '' }] })) }) + await act(async () => { await handlePaste(paste({ items: [{ kind: 'string', type: 'image/png' }] })) }) + await act(async () => { await handlePaste({ clipboardData: null, preventDefault: vi.fn() }) }) + expect(showToast).not.toHaveBeenCalled() + }) +}) diff --git a/src/renderer/src/workspace/tile-tree/TileLeaf/useClaudeImagePaste.ts b/src/renderer/src/workspace/tile-tree/TileLeaf/useClaudeImagePaste.ts index d40e76de2..cdd8a61aa 100644 --- a/src/renderer/src/workspace/tile-tree/TileLeaf/useClaudeImagePaste.ts +++ b/src/renderer/src/workspace/tile-tree/TileLeaf/useClaudeImagePaste.ts @@ -95,9 +95,43 @@ export function useClaudeImagePaste({ const handlePaste = useCallback( async (e: ClipboardLike): Promise => { - // Codex has no inline-image content — fall through so the - // caller routes the clipboard's text instead. - if (!getRendererProviderCapabilities(provider).supportsImageAttachments) return { handledImages: false } + // Providers without inline-image content fall through, so the caller + // routes the clipboard's text instead. + const capabilities = getRendererProviderCapabilities(provider) + if (!capabilities.supportsImageAttachments) { + // WHY say so (#1250 row 7): an image pasted into a Codex, OpenCode, + // Grok or Pi composer was dropped with nothing said. The wording is + // about THIS composer, not the provider (#1426 review b): Grok's own + // TUI attaches clipboard images in Terminal view, where a paste goes + // to the TUI and this hook never runs. + // + // What counts as an image (#1426 review a, b): + // - an image FILE item, with or without text. A mixed paste pastes + // its text and says the image was left out ("see attached" with + // no attachment is the silent loss); + // - a data-URL in text/html with NO text. A web-page copy + // carries beside its text, and that text paste stays silent; + // - with nothing else at all, an image only the async clipboard API + // shows (an Electron/macOS shape claudeImages.ts documents). + // Everything is read synchronously first; the event's data is only + // reliable during dispatch. + const data = e.clipboardData + if (!data) return { handledImages: false } + const text = data.getData('text/plain') + const hasImageFile = Array.from(data.items).some(item => item.kind === 'file' && item.type.startsWith('image/')) + const html = data.getData('text/html') + const hasHtmlImage = parseImagesFromHtml(html).length > 0 + const where = `${capabilities.shortLabel} from this composer` + if (hasImageFile && text) { + showToast(`Pasted images can't be sent to ${where}; only the text was pasted.`) + } else if (hasImageFile || (hasHtmlImage && !text)) { + showToast(`Pasted images can't be sent to ${where}.`) + } else if (!text && !html && data.items.length === 0) { + const asyncImages = await readImagesFromClipboard().catch(() => []) + if (asyncImages.length > 0) showToast(`Pasted images can't be sent to ${where}.`) + } + return { handledImages: false } + } const clipboardData = e.clipboardData if (!clipboardData) return { handledImages: false } diff --git a/src/renderer/src/workspace/tile-tree/TileLeaf/usePasteToFocus.asyncImage.renderer.test.tsx b/src/renderer/src/workspace/tile-tree/TileLeaf/usePasteToFocus.asyncImage.renderer.test.tsx new file mode 100644 index 000000000..0b9c73a62 --- /dev/null +++ b/src/renderer/src/workspace/tile-tree/TileLeaf/usePasteToFocus.asyncImage.renderer.test.tsx @@ -0,0 +1,37 @@ +import { fireEvent, render } from '@testing-library/react' +import { useRef } from 'react' +import { afterEach, describe, expect, it, vi } from 'vitest' + +import { usePasteToFocus } from './usePasteToFocus' + +// #1426 verification a: a paste landing outside the composer (paste-to-focus) +// whose image only the async clipboard API shows arrives as an EMPTY event: +// no text, no HTML, no items. It never reached the shared image handler, so +// nothing was said (and Claude never attached it). It now does; ordinary text +// still appends synchronously and never calls the handler. + +function Harness({ handlePaste }: { handlePaste: Parameters[0]['handlePaste'] }) { + const inputRef = useRef(null) + usePasteToFocus({ focused: true, sessionId: 's1' as never, inputRef, setDraftInput: vi.fn(), handlePaste }) + return