diff --git a/docs/superpowers/plans/2026-09-11-live-turn-block-order.md b/docs/superpowers/plans/2026-09-11-live-turn-block-order.md new file mode 100644 index 000000000..92691b831 --- /dev/null +++ b/docs/superpowers/plans/2026-09-11-live-turn-block-order.md @@ -0,0 +1,60 @@ +# Live Turn Block Order Implementation Plan + +> **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking. + +**Goal:** While a Claude turn streams, a block that has already been written to the transcript stays where it was produced, above the turn's still-streaming blocks, instead of dropping below them. + +**Architecture:** One amendment to the ledger's ordering law (`src/renderer/src/rendering/model/order.ts`): a committed candidate whose `messageId` is the id of a selected `semantic-current` turn takes that turn's time slot, and the existing equal-time tiebreak (committed before semantic-current) places it ahead of the turn's live blocks. Ownership (D3) is untouched; only placement changes. + +**Tech Stack:** TypeScript, Vitest 4 (`unit` project). + +**Spec:** GitHub issue #868. + +## Global Constraints + +- Worktree `.worktrees/live-turn-block-order`, branch `fix/live-turn-block-order`, based on `origin/main` @ `fddf2596`. +- Node 24 for tests (`source /opt/homebrew/opt/nvm/nvm.sh && nvm use 24`); type gate `npx tsc -b --pretty false` / `npm run typecheck`. +- Never launch the app. Thick WHY comments. Conventional Commits, scope `rendering`. +- Run the rendering corpus (`bundleCorpus.test.ts`, `recordingCorpus.test.ts`) before the PR: an ordering change is exactly what that net exists to catch. + +## Root cause and evidence + +- `rendering/observations/semantic.ts` `collectTurn` stamps every block of the **current** turn with the turn's `startedAtMs` (local receipt time). +- `rendering/model/order.ts` merges planes by `timestampMs`; a committed JSONL line carries its producer timestamp. +- Claude Code writes **one JSONL line per content block as the block completes**, in block order, all with the message's `message.id`. Measured on real transcripts in `~/.claude/projects/-Users-juliusolsson-Desktop-Development-agent-code/` (offsets from the first line of the message): `[thinking 0.0s, text +0.84s, tool_use +2.27s, tool_use +4.01s]`, `[thinking 0.0s, text +1.48s, tool_use +4.82s, tool_use +5.71s]`, `[thinking 0.0s, text +0.86s, tool_use +9.79s, tool_use +30.4s]`. +- So while a turn streams, its committed lines are a prefix of its blocks, but each carries a later time than the turn start and sorts below every live block. The common visible case is not only #868's web-search shape: in any "text, then tool call" message the explanatory text drops below the streaming tool call until the tool_use line lands (up to ~30s for large tool inputs above). + +## Why this fix and not the alternatives + +- **Per-block start times** (stamp `block_started` receipt time and order live blocks by it): still compares a producer clock (JSONL timestamp) with a local receipt clock (proxy poll delivery, 0–200ms+ late), so the order would depend on a race. +- **Anchor a committed row to the semantic block it suppressed**: deterministic, but ownership keeps only key sets (no committed-id per suppressed candidate), and several committed rows of the turn (thinking, text) suppress different things or nothing. +- **Anchor by message identity** (chosen): the committed rows of the live message are, by the producer's write order, earlier than every still-live block of it. Identity is already the ledger's Claude handoff key (whole-turn ownership, `ownership.ts`). No clock comparison is involved, and the anchor is the turn's own slot, so the rows also stay after any previous turn that ended before this one started, regardless of producer/receipt clock skew. +- Scope is message identity, so it applies whenever ids match; Codex/OpenCode committed ids that differ from their semantic turn ids are unaffected. + +--- + +### Task 1: Committed rows of the live turn order inside it + +**Files:** +- Modify: `src/renderer/src/rendering/model/order.ts` +- Test: `src/renderer/src/rendering/model/ledger.test.ts` (ordering law describe) +- Test: `src/renderer/src/features/feed/ledger/ledgerFeedItems.test.ts` (view bridge, real fold) + +- [ ] **Step 1: Failing ledger tests** + 1. Prompt at T0; live turn `msg_1` has a `semantic-current` tool_use block stamped T0+100 (turn start); the committed text line of `msg_1` at T0+150. Expected rows: prompt, committed text, live tool_use (today: prompt, live tool_use, committed text). + 2. Clock skew: a `semantic-history` turn ended at T0+120 (local), the live turn started at T0+130 (local), its committed line has producer time T0+110. Expected: history, committed, live (anchoring to the turn slot, not `min`, keeps it after the previous turn). + 3. A committed row whose `messageId` matches no live turn keeps its own time. +- [ ] **Step 2: Failing view-bridge test** with the production fold: a `msg_live` turn streams a text block then a tool_use block; the text's committed entry (same `message.id`, later timestamp) lands while the tool_use input still streams. Expected items: prompt, committed text entry, live tool_use block, work. +- [ ] **Step 3: Implement** the anchor in `orderCandidates`: build `turnId → timestampMs` from selected `semantic-current` candidates; a `committed` candidate whose `messageId` is in that map sorts at the mapped time (tiebreak unchanged). Record the anchoring in the row's `order.source` so a debug bundle explains the placement (D5). +- [ ] **Step 4: Verify** the ledger, view-bridge, and rendering corpus suites (`src/renderer/src/rendering/*Corpus.test.ts`), then `tsc -b`. +- [ ] **Step 5: Commit** `fix(rendering): keep committed blocks of a live turn above its streaming blocks` with `Fixes #868`. + +### Task 2: PR + +- [ ] Full `npm test` once (known local env failures: see memory; compare against origin/main if anything else fails), push, open the PR with `Fixes #868`. Do not merge. + +## Implementation note (scope extended during Task 1) + +The first version anchored only committed rows whose `messageId` matched the live turn. The rendering corpus flagged two real bundles (`2026-06-22 …7733b0fc`, `2026-06-29 …1b2b5e96`): Claude Code **executes a tool as soon as its tool_use block completes, while the message still streams**. In 7733b0fc the tool_use line lands at 42.238s, its tool_result 9ms later, the next tool_use at 44.141s, and block 2 is still live. Tool results are user rows with no `message.id`, so they stayed at their own time and sank below the live block, separated from their tool calls. + +The anchor now also covers a committed row whose `ownedToolResultIds` answer a tool_use id of the live turn (from its committed tool_use lines or live tool blocks). With every anchored row tied at the turn's slot, `sequence` orders them in transcript order. Both bundles then match their recorded triage exactly, with no re-bless, which independently confirms the order is the transcript's. The added ledger test encodes the 7733b0fc shape. diff --git a/src/renderer/src/features/feed/ledger/ledgerFeedItems.test.ts b/src/renderer/src/features/feed/ledger/ledgerFeedItems.test.ts index a002faa82..f236d2bc3 100644 --- a/src/renderer/src/features/feed/ledger/ledgerFeedItems.test.ts +++ b/src/renderer/src/features/feed/ledger/ledgerFeedItems.test.ts @@ -1,9 +1,10 @@ -import { describe, expect, it } from 'vitest' +import { describe, expect, it, vi } from 'vitest' import type { Entry } from '@shared/types/transcript' import type { FeedRenderItem } from '@renderer/features/feed/model/renderModel' import { emptyRuntime } from '@renderer/session-runtime/state' import type { SemanticLiveTurn, SessionRuntime } from '@renderer/session-runtime/state' +import { foldSemanticEvent } from '@renderer/session-runtime/semantic/foldEvent' import { createLedgerInputAdapter } from '@renderer/rendering/adapter/collectLedgerInput' import type { RuntimeLedgerSlices } from '@renderer/rendering/adapter/collectLedgerInput' import { createSessionLedger } from '@renderer/rendering/model/ledger' @@ -318,3 +319,48 @@ describe('view bridge: ledger rows drive block-level FeedRenderItems', () => { expect(items.some(item => item.type === 'empty')).toBe(true) }) }) + +describe('view bridge: committed blocks of a live turn (#868)', () => { + // Built with the production reducer and the event order ClaudeProxyAdapter + // publishes, then the committed line Claude Code writes when the text block + // completes. Measured on real transcripts: one JSONL line per content block, + // written as each block completes, all with the message's id — so the text's + // line lands while the next tool call's input is still streaming (for large + // tool inputs that window was 10–30s). + it('keeps the text of a "text, then tool call" message above its streaming tool call once the text is committed', () => { + const clock = vi.spyOn(Date, 'now').mockReturnValue(T + 1_000) + let semantic = emptyRuntime().semantic + try { + for (const event of [ + { type: 'turn_started', turnId: 'msg_live', role: 'assistant', source: 'proxy' }, + { type: 'block_started', turnId: 'msg_live', blockIndex: 0, kind: 'text', source: 'proxy' }, + { type: 'text_delta', turnId: 'msg_live', blockIndex: 0, textSoFar: 'Let me edit the config.', source: 'proxy' }, + { type: 'block_completed', turnId: 'msg_live', blockIndex: 0, kind: 'text', text: 'Let me edit the config.', source: 'proxy' }, + { type: 'block_started', turnId: 'msg_live', blockIndex: 1, kind: 'tool_use', toolName: 'Edit', toolUseId: 'toolu_edit', source: 'proxy' }, + { type: 'tool_input_delta', turnId: 'msg_live', blockIndex: 1, toolName: 'Edit', toolUseId: 'toolu_edit', partialJson: '{"file_path":"/p/c', inputJsonSoFar: '{"file_path":"/p/c', source: 'proxy' }, + ]) semantic = foldSemanticEvent(semantic, event, 'claude') + } finally { + clock.mockRestore() + } + + const rt = emptyRuntime() + rt.semantic = semantic + rt.streamPhase = 'responding' + rt.entries = [ + userEntry('u1', T, 'fix the config'), + // The text block's JSONL line: same message id as the live turn, stamped + // when the block completed (after the turn started). + assistantEntry('a_text', 'msg_live', T + 1_840, 'Let me edit the config.'), + ] + rt.lastJsonlEntryAt = T + 1_840 + + const { items, dropped } = bridgeItems(rt) + expect(dropped).toEqual([]) + expect(items.map(shape)).toEqual([ + 'entry:u1', + 'entry:a_text', + 'semantic-block:msg_live#1', + 'work', + ]) + }) +}) diff --git a/src/renderer/src/rendering/model/ledger.test.ts b/src/renderer/src/rendering/model/ledger.test.ts index 81b5915cf..0d2d5786b 100644 --- a/src/renderer/src/rendering/model/ledger.test.ts +++ b/src/renderer/src/rendering/model/ledger.test.ts @@ -89,6 +89,79 @@ describe('ledger: ordering law (D4)', () => { expect(rowIds(l)).toEqual(['ts', 'no-ts']) }) + // #868: Claude Code writes one JSONL line per content block AS THE BLOCK + // COMPLETES, in block order, all carrying the message's id (measured: + // thinking +0.0s, text +0.84s, tool_use +2.27s, tool_use +4.01s). Live + // blocks of the current turn are stamped with the turn's start, so a + // committed line of that same message — always earlier content than any + // still-live block of it — used to sort BELOW them. + it('#868: a committed block of the live turn orders inside that turn, above its still-streaming blocks', () => { + const l = run({ + provider: 'claude', + committed: [ + cand({ id: 'prompt', owner: 'committed', provider: 'claude', contentKind: 'user-text', timestampMs: T0 }), + // The text block's line landed while the tool_use input still streams. + cand({ id: 'text', owner: 'committed', provider: 'claude', contentKind: 'assistant-text', messageId: 'msg_1', turnId: 'msg_1', timestampMs: T0 + 150 }), + ], + live: [ + cand({ id: 'tool', owner: 'semantic-current', provider: 'claude', contentKind: 'tool-use', turnId: 'msg_1', blockIndex: 1, toolUseId: 'tu_1', timestampMs: T0 + 100 }), + ], + statics: [cand({ id: 'work', owner: 'work', contentKind: 'work' })], + }) + expect(rowIds(l)).toEqual(['prompt', 'text', 'tool', 'work']) + }) + + it('#868: the anchor is the live turn\'s own slot, so a skewed producer clock cannot pull the row above the previous turn', () => { + // Producer time (JSONL) and local receipt time (semantic turn start) are + // different clocks. Anchoring to min(own, turn) would let a producer time + // that reads earlier than the previous turn's local end jump above it. + const l = run({ + provider: 'claude', + committed: [ + cand({ id: 'text', owner: 'committed', provider: 'claude', contentKind: 'assistant-text', messageId: 'msg_2', turnId: 'msg_2', timestampMs: T0 + 110 }), + ], + live: [ + cand({ id: 'prev', owner: 'semantic-history', provider: 'claude', contentKind: 'assistant-text', turnId: 'msg_1', timestampMs: T0 + 120 }), + cand({ id: 'tool', owner: 'semantic-current', provider: 'claude', contentKind: 'tool-use', turnId: 'msg_2', blockIndex: 1, toolUseId: 'tu_2', timestampMs: T0 + 130 }), + ], + }) + expect(rowIds(l)).toEqual(['prev', 'text', 'tool']) + }) + + it('#868: a tool result of the live turn stays with its tool call (streaming tool execution)', () => { + // Shape of real bundle 2026-06-22 …7733b0fc: Claude Code EXECUTES a tool as + // soon as its tool_use block completes, while the message still streams — + // tool_use line at 42.238s, its tool_result 9ms later, the next tool_use + // at 44.141s, block 2 still live. The result is a user row with no + // message.id; only its tool_use_id ties it to the live turn. + const l = run({ + provider: 'claude', + committed: [ + cand({ id: 'use0', owner: 'committed', provider: 'claude', contentKind: 'tool-use', messageId: 'msg_1', turnId: 'msg_1', ownedToolUseIds: ['tu_0'], timestampMs: T0 + 200 }), + cand({ id: 'result0', owner: 'committed', provider: 'claude', contentKind: 'tool-result', ownedToolResultIds: ['tu_0'], timestampMs: T0 + 209 }), + cand({ id: 'use1', owner: 'committed', provider: 'claude', contentKind: 'tool-use', messageId: 'msg_1', turnId: 'msg_1', ownedToolUseIds: ['tu_1'], timestampMs: T0 + 400 }), + cand({ id: 'result1', owner: 'committed', provider: 'claude', contentKind: 'tool-result', ownedToolResultIds: ['tu_1'], timestampMs: T0 + 407 }), + ], + live: [ + cand({ id: 'block2', owner: 'semantic-current', provider: 'claude', contentKind: 'tool-use', turnId: 'msg_1', blockIndex: 2, toolUseId: 'tu_2', timestampMs: T0 + 100 }), + ], + }) + expect(rowIds(l)).toEqual(['use0', 'result0', 'use1', 'result1', 'block2']) + }) + + it('#868: a committed row of another message keeps its own time', () => { + const l = run({ + provider: 'claude', + committed: [ + cand({ id: 'other', owner: 'committed', provider: 'claude', contentKind: 'assistant-text', messageId: 'msg_0', turnId: 'msg_0', timestampMs: T0 + 150 }), + ], + live: [ + cand({ id: 'tool', owner: 'semantic-current', provider: 'claude', contentKind: 'tool-use', turnId: 'msg_1', blockIndex: 1, toolUseId: 'tu_1', timestampMs: T0 + 100 }), + ], + }) + expect(rowIds(l)).toEqual(['tool', 'other']) + }) + it('empty + work is a legal output (work is lifecycle, not text)', () => { const l = run({ statics: [ diff --git a/src/renderer/src/rendering/model/order.ts b/src/renderer/src/rendering/model/order.ts index f9ae65ef3..54b4e5007 100644 --- a/src/renderer/src/rendering/model/order.ts +++ b/src/renderer/src/rendering/model/order.ts @@ -51,20 +51,113 @@ const SOURCE_RANK: Record = { * sequence. (Dump: "Null timestamps sort after timestamped content, not as * 'now'.") */ -function timeOf(c: RenderCandidate): number { +function timeOf(c: RenderCandidate, slots: LiveTurnSlots): number { + const anchor = liveTurnAnchor(c, slots) + if (anchor !== null) return anchor.timeMs return c.timestampMs ?? Number.MAX_SAFE_INTEGER } +// --------------------------------------------------------------------------- +// Amendment (#868): a committed row of the LIVE turn orders inside that turn. +// +// The law above compares a committed row's producer time with a live turn's +// start, and every block of the current turn carries that start +// (observations/semantic.ts collectTurn). That is right for rows of OTHER +// messages, and wrong for the live message's own rows: Claude Code writes one +// JSONL line per content block as the block completes, in block order, all with +// the message's id (measured on real transcripts: thinking +0.0s, text +0.84s, +// tool_use +2.27s, tool_use +4.01s). While the turn streams, its committed +// lines are therefore always EARLIER content than every block still live — yet +// each carries a time after the turn start, so it sorted below them. The +// everyday symptom is a "text, then tool call" message: once the text's line +// lands, the explanation drops below the still-streaming tool call until the +// tool_use line lands (10–30s for large tool inputs). +// +// So a committed row whose message id is the id of a selected semantic-current +// turn takes that turn's slot, and the equal-time tiebreak above (committed +// before semantic-current) puts it ahead of the turn's live blocks. Anchored +// rows tie with each other too, so `sequence` (transcript order) orders them. +// +// The same holds for TOOL RESULTS of the live turn, which carry no message id: +// Claude Code executes a tool as soon as its tool_use block completes, while +// the message is still streaming (bundle 2026-06-22 …7733b0fc: tool_use line at +// 42.238s, its tool_result 9ms later, the next tool_use at 44.141s, block 2 +// still live). A committed row answering a tool_use id that belongs to the live +// turn — one of its committed tool_use lines or live tool blocks — takes the +// turn's slot as well, so the turn's committed prefix reads in transcript order +// (tool_use, result, tool_use, result) above whatever is still streaming, +// instead of the results sinking below it. +// +// WHY identity and not a better clock: per-block receipt times would still +// compare the producer clock (JSONL timestamp) with the local receipt clock +// (proxy events land 0–200ms+ late), which is a race. Message identity is the +// ledger's existing Claude handoff key (whole-turn ownership in ownership.ts). +// +// WHY the turn's slot exactly and not min(own, turn): the two times come from +// different clocks. A producer time that reads earlier than a PREVIOUS turn's +// local end would otherwise pull the row above that turn; the live turn's slot +// is, by construction, already after it. +// +// Rows of other messages, and every row when no turn is live, keep their own +// time. Ownership is untouched: this only answers "where", never "whether". +// --------------------------------------------------------------------------- +type LiveTurnSlots = { + /** live turn id → the turn's slot (its semantic-current timestamp) */ + byTurn: ReadonlyMap + /** tool_use id belonging to a live turn → that turn's id */ + toolTurn: ReadonlyMap +} + +function liveTurnSlotsOf(selected: readonly RenderCandidate[]): LiveTurnSlots { + const byTurn = new Map() + const toolTurn = new Map() + for (const c of selected) { + if (c.owner !== 'semantic-current' || !c.turnId || c.timestampMs === null) continue + // All blocks of one turn share the turn's start; keep the earliest in case + // a producer ever stamps them differently. + const existing = byTurn.get(c.turnId) + if (existing === undefined || c.timestampMs < existing) byTurn.set(c.turnId, c.timestampMs) + const toolId = c.toolUseId ?? c.callId + if (toolId) toolTurn.set(toolId, c.turnId) + } + // A live turn also owns the tool calls it has already committed: those + // tool_use blocks are usually suppressed as live candidates (committed tool + // ownership), so only their committed lines still name the ids. + for (const c of selected) { + if (c.owner !== 'committed' || !c.messageId || !byTurn.has(c.messageId)) continue + for (const id of c.ownedToolUseIds ?? []) toolTurn.set(id, c.messageId) + } + return { byTurn, toolTurn } +} + +function liveTurnAnchor( + c: RenderCandidate, + slots: LiveTurnSlots, +): { turnId: string; timeMs: number } | null { + if (c.owner !== 'committed') return null + if (c.messageId) { + const timeMs = slots.byTurn.get(c.messageId) + if (timeMs !== undefined) return { turnId: c.messageId, timeMs } + } + for (const id of c.ownedToolResultIds ?? []) { + const turnId = slots.toolTurn.get(id) + const timeMs = turnId === undefined ? undefined : slots.byTurn.get(turnId) + if (turnId !== undefined && timeMs !== undefined) return { turnId, timeMs } + } + return null +} + export function orderCandidates( selected: readonly RenderCandidate[], ): RenderRow[] { + const liveTurnSlots = liveTurnSlotsOf(selected) const sorted = [...selected].sort((a, b) => { const pa = PHASE_RANK[phaseOf(a)] const pb = PHASE_RANK[phaseOf(b)] if (pa !== pb) return pa - pb if (phaseOf(a) === 'content') { - const ta = timeOf(a) - const tb = timeOf(b) + const ta = timeOf(a, liveTurnSlots) + const tb = timeOf(b, liveTurnSlots) if (ta !== tb) return ta - tb const sa = SOURCE_RANK[a.owner] ?? 3 const sb = SOURCE_RANK[b.owner] ?? 3 @@ -72,14 +165,21 @@ export function orderCandidates( } return a.sequence - b.sequence }) - return sorted.map((candidate, i) => ({ - candidate, - order: { - sequence: i, - timeMs: candidate.timestampMs, - // The row explains its own placement so a debug bundle can answer - // "why is this row here" without reconstructing the sort (plan D5). - source: `${phaseOf(candidate)}:${candidate.owner}:${candidate.timestampMs ?? 'null'}`, - }, - })) + return sorted.map((candidate, i) => { + const anchor = liveTurnAnchor(candidate, liveTurnSlots) + return { + candidate, + order: { + sequence: i, + timeMs: candidate.timestampMs, + // The row explains its own placement so a debug bundle can answer + // "why is this row here" without reconstructing the sort (plan D5) — + // including when it sorted by its live turn's slot instead of its own + // time. + source: anchor !== null + ? `${phaseOf(candidate)}:${candidate.owner}:live-turn:${anchor.turnId}@${anchor.timeMs}` + : `${phaseOf(candidate)}:${candidate.owner}:${candidate.timestampMs ?? 'null'}`, + }, + } + }) }