Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
165 changes: 165 additions & 0 deletions src/renderer/src/session-runtime/ghosts.remint.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,165 @@
import { readFileSync } from 'node:fs'
import { join } from 'node:path'

import { afterEach, describe, expect, it, vi } from 'vitest'
import type { GhostEntry } from 'agent-transcript-parser/ghost'

import {
gcSupersededGhosts,
ghostsFromSemanticTurn,
reconcileUpstream,
sweepGhosts,
} from '@renderer/session-runtime/ghosts'
import type { SemanticLiveTurn } from '@renderer/session-runtime/state'
import type { Entry } from '@shared/types/transcript'

// #730: a superseded ghost of the turn that is STILL current was evicted 5 s
// after supersedure, and the next semantic tick minted it again with no
// `supersededBy`. Its committed entry had already been reconciled, so nothing
// superseded it a second time: 30 s later it orphaned with an `updatedAt`
// newer than the JSONL tail, which is the one state the render predicate
// still paints (a duplicate of the committed tool call).
//
// The fixture is the real on-disk log of one such ghost (see its README):
// minted, superseded at +2.9 s, re-minted at +8.9 s, orphaned at +38.9 s.
// Across this machine's 1,955 logs the same sequence happened 3,231 times.

type Rec = GhostEntry & { _atp: GhostEntry['_atp'] & { supersededBy?: string } }
const records = readFileSync(
join(import.meta.dirname, '../../../../testing/fixtures/ghost-remint/claude-tool-use-remint.ghost.jsonl'),
'utf8',
).trim().split('\n').map(line => JSON.parse(line) as Rec)

const minted = records[0]!
const superseding = records.find(record => record._atp.supersededBy !== undefined)!
const reminted = records.find(record => record._atp.createdAt !== minted._atp.createdAt)!
const toolUse = (superseding.message.content as Array<{ id: string; name: string; input: unknown }>)[0]!

// The live turn exactly as the proxy described it when the ghost was minted:
// the Bash tool_use at blockIndex 2, input fully parsed, the tool running.
const liveTurn = {
turnId: minted._atp.turnId,
text: '',
source: 'proxy',
blocks: {
[minted._atp.blockIndex]: {
blockIndex: minted._atp.blockIndex,
kind: 'tool_use',
toolName: toolUse.name,
toolUseId: toolUse.id,
parsedInput: toolUse.input as Record<string, unknown>,
finalized: true,
},
},
blockOrder: [minted._atp.blockIndex],
stopReason: null,
usage: null,
startedAt: minted._atp.createdAt,
endedAt: null,
} as unknown as SemanticLiveTurn

// The committed JSONL entry that superseded it: Claude's assistant record
// carries the message id the ghost's turn id was minted from.
const committed = {
type: 'assistant',
uuid: superseding._atp.supersededBy,
timestamp: new Date(superseding._atp.updatedAt).toISOString(),
message: { id: minted._atp.turnId, role: 'assistant', content: [toolUse] },
} as unknown as Entry

const GC_MS = 5_000
const SESSION = minted.sessionId as string

afterEach(() => { vi.useRealTimers() })

function supersededGhostOfLiveTurn(): Map<string, GhostEntry> {
vi.useFakeTimers({ now: minted._atp.createdAt })
const live = ghostsFromSemanticTurn(liveTurn, SESSION, new Map())
vi.setSystemTime(superseding._atp.updatedAt)
const reconciled = reconcileUpstream(committed, live)
expect(reconciled.get(minted.uuid)?._atp.supersededBy).toBe(superseding._atp.supersededBy)
return reconciled
}

describe('a superseded ghost of the still-current turn (#730)', () => {
it('is not evicted and re-minted un-superseded by the next semantic tick', () => {
const reconciled = supersededGhostOfLiveTurn()

// The recorded re-mint time: the sweep has run past the 5 s grace and
// the semantic tick that follows sees the same current turn.
const now = reminted._atp.createdAt
vi.setSystemTime(now)
const swept = gcSupersededGhosts(reconciled, now, GC_MS, liveTurn.turnId)
const ticked = ghostsFromSemanticTurn(liveTurn, SESSION, swept)

const ghost = ticked.get(minted.uuid)
expect(ghost?._atp.supersededBy).toBe(superseding._atp.supersededBy)
expect(ghost?._atp.createdAt).toBe(minted._atp.createdAt)
})

it('is evicted once its turn is no longer current, and is not minted again', () => {
const reconciled = supersededGhostOfLiveTurn()
const now = reminted._atp.createdAt
vi.setSystemTime(now)

// The next API request started a new turn. Only the new turn's blocks
// are ever minted from here, so the old ghost can go.
const nextTurn = { ...liveTurn, turnId: 'msg_next', blocks: {}, blockOrder: [] } as SemanticLiveTurn
const swept = gcSupersededGhosts(reconciled, now, GC_MS, nextTurn.turnId)
expect(swept.has(minted.uuid)).toBe(false)
expect(ghostsFromSemanticTurn(nextTurn, SESSION, swept).has(minted.uuid)).toBe(false)
})

it('is evicted as before when no turn is current', () => {
const reconciled = supersededGhostOfLiveTurn()
const now = reminted._atp.createdAt
expect(gcSupersededGhosts(reconciled, now, GC_MS, null).has(minted.uuid)).toBe(false)
})

// #1228 review: the fix is one argument at the call site, and the sweep
// used to assemble its reducers inline where nothing tested them. These go
// through the composed tick the 1 s timer runs, with the turn id read from
// the runtime slice exactly as production passes it.
it('survives the real sweep tick while its turn is current, and goes once it is not', () => {
const reconciled = supersededGhostOfLiveTurn()
const now = reminted._atp.createdAt
vi.setSystemTime(now)
const timing = { orphanTtlMs: 30_000, gcMs: GC_MS }
const live = { ghosts: reconciled, lastJsonlEntryAt: superseding._atp.updatedAt, semantic: { currentTurn: liveTurn } }
const swept = sweepGhosts(live, now, timing)
expect(ghostsFromSemanticTurn(liveTurn, SESSION, swept).get(minted.uuid)?._atp.supersededBy)
.toBe(superseding._atp.supersededBy)

const idle = { ...live, ghosts: swept, semantic: { currentTurn: null } }
expect(sweepGhosts(idle, now, timing).has(minted.uuid)).toBe(false)
})

it('stays frozen when its live block keeps streaming after supersedure', () => {
// The supersede guard in ghostsFromSemanticTurn: a late delta for a block
// whose committed record already landed must not rewrite the ghost or
// bump its updatedAt (log noise, and a reset of its eviction clock).
const reconciled = supersededGhostOfLiveTurn()
const before = reconciled.get(minted.uuid)!
vi.setSystemTime(reminted._atp.createdAt)
const block = liveTurn.blocks[minted._atp.blockIndex]!
const streamedOn = {
...liveTurn,
blocks: { [minted._atp.blockIndex]: { ...block, parsedInput: { command: 'echo a later delta' } } },
} as SemanticLiveTurn
const ticked = ghostsFromSemanticTurn(streamedOn, SESSION, reconciled)
expect(ticked.get(minted.uuid)).toBe(before)
})

it('orphans on the orphan TTL, not the superseded-GC grace (#1228 review)', () => {
// The composed tick takes two timings; swapping them orphans a live
// ghost after 5 s instead of 30. A ghost 10 s quiet must still be live.
vi.useFakeTimers({ now: minted._atp.createdAt })
const live = ghostsFromSemanticTurn(liveTurn, SESSION, new Map())
const now = minted._atp.createdAt + 10_000
const swept = sweepGhosts({ ghosts: live, lastJsonlEntryAt: null, semantic: { currentTurn: null } }, now, { orphanTtlMs: 30_000, gcMs: GC_MS })
expect(swept.get(minted.uuid)?._atp.orphanedAt).toBeUndefined()
const later = minted._atp.createdAt + 31_000
expect(sweepGhosts({ ghosts: live, lastJsonlEntryAt: null, semantic: { currentTurn: null } }, later, { orphanTtlMs: 30_000, gcMs: GC_MS })
.get(minted.uuid)?._atp.orphanedAt).toBe(later)
})
})
2 changes: 1 addition & 1 deletion src/renderer/src/session-runtime/ghosts.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -91,7 +91,7 @@ describe('gcHiddenOrphanGhosts', () => {
])

expect(gcHiddenOrphanGhosts(prev, tail, null, NOW, GC_MS)).toBe(prev)
expect(gcSupersededGhosts(prev, NOW, GC_MS).size).toBe(0)
expect(gcSupersededGhosts(prev, NOW, GC_MS, null).size).toBe(0)
})

it('is reference-stable on no-op and copies only when it evicts', () => {
Expand Down
60 changes: 60 additions & 0 deletions src/renderer/src/session-runtime/ghosts.ts
Original file line number Diff line number Diff line change
Expand Up @@ -513,17 +513,33 @@ export function orphanStale(
* upstream has been visible for a couple of seconds, no renderer
* still needs the ghost for transition smoothing.
*
* WHY ghosts of the live `currentTurn` are exempt (#730), the same rule
* `gcHiddenOrphanGhosts` follows: `ghostsFromSemanticTurn` re-mints any
* block of the current turn whose uuid is missing, on every semantic tick.
* The superseded marker IS what stops it touching that block, so evicting
* it while the turn is still current (a tool running, the next block still
* streaming) made the next tick create the same uuid again with no
* `supersededBy`. Its committed entry had already been reconciled, so
* nothing superseded it twice: 30 s later it orphaned with an `updatedAt`
* newer than the JSONL tail and painted as a duplicate of the committed
* block. The ghost logs on the author's machine held 3,231 of these
* (Codex and Claude, 93% tool_use), each 5–6 s after supersedure. Those
* ghosts wait until the turn is no longer current, which bounds them to
* one turn's blocks.
*
* Called from the same periodic tick as `orphanStale`.
*/
export function gcSupersededGhosts(
prev: ReadonlyMap<string, GhostEntry>,
now: number,
gcMs: number,
currentTurnId: string | null,
): Map<string, GhostEntry> {
if (prev.size === 0) return prev as Map<string, GhostEntry>
let next: Map<string, GhostEntry> | null = null
for (const [uuid, ghost] of prev) {
if (ghost._atp.supersededBy === undefined) continue
if (currentTurnId !== null && ghost._atp.turnId === currentTurnId) continue
if (ghost._atp.updatedAt + gcMs >= now) continue
if (next === null) next = new Map(prev)
next.delete(uuid)
Expand Down Expand Up @@ -617,6 +633,50 @@ export function gcHiddenOrphanGhosts(
return next ?? (prev as Map<string, GhostEntry>)
}

// -----------------------------------------------------------------------------
// The periodic sweep, composed
// -----------------------------------------------------------------------------

/**
* One tick of the ghost sweep: flag stale ghosts orphaned, then evict the
* superseded and the hidden orphans — both sparing the live turn.
*
* WHY the composition lives here and reads `currentTurn` itself (#1228
* review, both reviewers): the #730 fix is one argument at the call site,
* and passing `null` there type-checks and silently brings the duplicate
* back. The call site used to assemble three reducers inline, where no test
* could reach it. Deriving the turn id from the runtime slice inside a
* tested function removes the argument a refactor could drop.
*
* Reference-stable on no-op, like every reducer it composes.
*/
export function sweepGhosts(
runtime: {
ghosts: ReadonlyMap<string, GhostEntry>
lastJsonlEntryAt: number | null
semantic: { currentTurn: { turnId: string } | null }
},
now: number,
timing: { orphanTtlMs: number; gcMs: number },
): Map<string, GhostEntry> {
if (runtime.ghosts.size === 0) return runtime.ghosts as Map<string, GhostEntry>
// Both evictions spare the live turn: ghostsFromSemanticTurn re-mints any
// missing block of it on the next tick (#724, #730).
const currentTurnId = runtime.semantic.currentTurn?.turnId ?? null
const orphaned = orphanStale(runtime.ghosts, now, timing.orphanTtlMs)
// Hidden orphans (orphaned AND at-or-before the committed JSONL tail) can
// never render again and would otherwise pin the live-entry trim bound for
// the rest of the session (#724). Same grace as superseded GC, for the same
// persistence reason.
return gcHiddenOrphanGhosts(
gcSupersededGhosts(orphaned, now, timing.gcMs, currentTurnId),
runtime.lastJsonlEntryAt,
currentTurnId,
now,
timing.gcMs,
)
}

// -----------------------------------------------------------------------------
// Diff helper for persistence
// -----------------------------------------------------------------------------
Expand Down
24 changes: 5 additions & 19 deletions src/renderer/src/workspace/hook/ipc/useIpcSubscriptions.ts
Original file line number Diff line number Diff line change
Expand Up @@ -65,11 +65,9 @@ import {
import { emitRendererMemoryGauges } from '@renderer/performance/memoryInstrumentation'
import { pickerEqual } from '@renderer/workspace/layout/helpers'
import {
gcHiddenOrphanGhosts,
gcSupersededGhosts,
ghostsFromSemanticTurn,
ghostsToPersist,
orphanStale,
sweepGhosts,
reconcileUpstream,
} from '@renderer/session-runtime/ghosts'
import {
Expand Down Expand Up @@ -517,22 +515,10 @@ export function useIpcSubscriptions(
// Only runs when there are ghosts to consider; otherwise leaves
// `working` untouched so the queue pass below still gets a chance.
if (runtime.ghosts.size > 0) {
const orphanedGhosts = orphanStale(runtime.ghosts, now, GHOST_ORPHAN_TTL_MS)
// Hidden orphans (orphaned AND at-or-before the committed JSONL
// tail) can never render again and would otherwise pin the
// live-entry trim bound for the rest of the session (#724).
// Same grace as superseded GC, for the same persistence reason.
const nextGhosts = gcHiddenOrphanGhosts(
gcSupersededGhosts(
orphanedGhosts,
now,
GHOST_SUPERSEDED_GC_MS,
),
runtime.lastJsonlEntryAt,
runtime.semantic.currentTurn?.turnId ?? null,
now,
GHOST_SUPERSEDED_GC_MS,
)
const nextGhosts = sweepGhosts(runtime, now, {
orphanTtlMs: GHOST_ORPHAN_TTL_MS,
gcMs: GHOST_SUPERSEDED_GC_MS,
})
if (nextGhosts !== runtime.ghosts) {
for (const ghost of ghostsToPersist(runtime.ghosts, nextGhosts)) {
window.api.ghostAppend(sessionId, ghost)
Expand Down
16 changes: 16 additions & 0 deletions testing/fixtures/ghost-remint/README.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,16 @@
# ghost-remint (#730)

`claude-tool-use-remint.ghost.jsonl` holds every record, unedited, that one live Claude session wrote for a single ghost uuid (`g-msg_011CeqUioX694UZnQ6y1tC98-2`, a Bash `tool_use`). It was copied from `~/Library/Application Support/agent-code/ghost-logs/0219ff65-….ghost.jsonl` on 2026-09-25.

The timeline, from `_atp`:

| # | updatedAt offset | state |
|---|---|---|
| 1–3 | 0 / +164 ms / +617 ms | minted, then streamed input |
| 4 | +2.9 s | superseded by the committed JSONL entry |
| 5 | +8.9 s | minted AGAIN, with a fresh `createdAt` and no `supersededBy` |
| 6 | +38.9 s | orphaned (30 s TTL) |

Record 5 is the bug: `gcSupersededGhosts` evicted the superseded ghost 5 s after supersedure, while its turn was still `semantic.currentTurn` (the Bash tool was running). On the next semantic tick, `ghostsFromSemanticTurn` re-created it.

The same scan over all 1,955 logs on this machine found 3,231 such re-mints in 419 logs: 2,128 Codex and 1,103 Claude; 3,010 were `tool_use`. 3,226 of them were later orphaned. The minimum supersede-to-re-mint gap was 5,040 ms, which is the 5 s GC grace plus the 1 s sweep.
Original file line number Diff line number Diff line change
@@ -0,0 +1,6 @@
{"type":"assistant","uuid":"g-msg_011CeqUioX694UZnQ6y1tC98-2","parentUuid":null,"sessionId":"0219ff65-eee3-44c6-970b-fda786b47fb3","timestamp":"2026-09-08T06:13:20.478Z","message":{"role":"assistant","content":[{"type":"tool_use","id":"toolu_01R5HhRTnQeG6ybcpuf23grM","name":"Bash","input":{}}]},"_atp":{"origin":"ghost","turnId":"msg_011CeqUioX694UZnQ6y1tC98","blockIndex":2,"createdAt":1788848000478,"updatedAt":1788848000478,"context":{"source":"proxy","toolUseId":"toolu_01R5HhRTnQeG6ybcpuf23grM"}}}
{"type":"assistant","uuid":"g-msg_011CeqUioX694UZnQ6y1tC98-2","parentUuid":null,"sessionId":"0219ff65-eee3-44c6-970b-fda786b47fb3","timestamp":"2026-09-08T06:13:20.642Z","message":{"role":"assistant","content":[{"type":"tool_use","id":"toolu_01R5HhRTnQeG6ybcpuf23grM","name":"Bash","input":{"__rawJson":"{\"command\": \"git diff ef72d24..HEAD -- services/control/src/bringdown_engine/worker.py services/control/src/bringdown_engine/runtime.py services/control/src/bringdown_engine/docker.py runtime/agent-image/entrypoint.py harness/profiles/web_assessment_v1/toolkit."}}]},"_atp":{"origin":"ghost","turnId":"msg_011CeqUioX694UZnQ6y1tC98","blockIndex":2,"createdAt":1788848000478,"updatedAt":1788848000642,"context":{"source":"proxy","toolUseId":"toolu_01R5HhRTnQeG6ybcpuf23grM"}}}
{"type":"assistant","uuid":"g-msg_011CeqUioX694UZnQ6y1tC98-2","parentUuid":null,"sessionId":"0219ff65-eee3-44c6-970b-fda786b47fb3","timestamp":"2026-09-08T06:13:21.095Z","message":{"role":"assistant","content":[{"type":"tool_use","id":"toolu_01R5HhRTnQeG6ybcpuf23grM","name":"Bash","input":{"__rawJson":"{\"command\": \"git diff ef72d24..HEAD -- services/control/src/bringdown_engine/worker.py services/control/src/bringdown_engine/runtime.py services/control/src/bringdown_engine/docker.py runtime/agent-image/entrypoint.py harness/profiles/web_assessment_v1/toolkit.yaml services/control/scripts/export_openapi.py\", \"description\": \"Diff worker, runtime, docker, entrypoint, toolkit\"}"}}]},"_atp":{"origin":"ghost","turnId":"msg_011CeqUioX694UZnQ6y1tC98","blockIndex":2,"createdAt":1788848000478,"updatedAt":1788848001095,"context":{"source":"proxy","toolUseId":"toolu_01R5HhRTnQeG6ybcpuf23grM"}}}
{"type":"assistant","uuid":"g-msg_011CeqUioX694UZnQ6y1tC98-2","parentUuid":null,"sessionId":"0219ff65-eee3-44c6-970b-fda786b47fb3","timestamp":"2026-09-08T06:13:22.924Z","message":{"role":"assistant","content":[{"type":"tool_use","id":"toolu_01R5HhRTnQeG6ybcpuf23grM","name":"Bash","input":{"command":"git diff ef72d24..HEAD -- services/control/src/bringdown_engine/worker.py services/control/src/bringdown_engine/runtime.py services/control/src/bringdown_engine/docker.py runtime/agent-image/entrypoint.py harness/profiles/web_assessment_v1/toolkit.yaml services/control/scripts/export_openapi.py","description":"Diff worker, runtime, docker, entrypoint, toolkit"}}]},"_atp":{"origin":"ghost","turnId":"msg_011CeqUioX694UZnQ6y1tC98","blockIndex":2,"createdAt":1788848000478,"updatedAt":1788848002924,"context":{"source":"proxy","toolUseId":"toolu_01R5HhRTnQeG6ybcpuf23grM"},"supersededBy":"e62a3376-5134-46b0-a157-08284b1bf950"}}
{"type":"assistant","uuid":"g-msg_011CeqUioX694UZnQ6y1tC98-2","parentUuid":null,"sessionId":"0219ff65-eee3-44c6-970b-fda786b47fb3","timestamp":"2026-09-08T06:13:28.878Z","message":{"role":"assistant","content":[{"type":"tool_use","id":"toolu_01R5HhRTnQeG6ybcpuf23grM","name":"Bash","input":{"command":"git diff ef72d24..HEAD -- services/control/src/bringdown_engine/worker.py services/control/src/bringdown_engine/runtime.py services/control/src/bringdown_engine/docker.py runtime/agent-image/entrypoint.py harness/profiles/web_assessment_v1/toolkit.yaml services/control/scripts/export_openapi.py","description":"Diff worker, runtime, docker, entrypoint, toolkit"}}]},"_atp":{"origin":"ghost","turnId":"msg_011CeqUioX694UZnQ6y1tC98","blockIndex":2,"createdAt":1788848008878,"updatedAt":1788848008878,"context":{"source":"proxy","toolUseId":"toolu_01R5HhRTnQeG6ybcpuf23grM"}}}
{"type":"assistant","uuid":"g-msg_011CeqUioX694UZnQ6y1tC98-2","parentUuid":null,"sessionId":"0219ff65-eee3-44c6-970b-fda786b47fb3","timestamp":"2026-09-08T06:13:59.008Z","message":{"role":"assistant","content":[{"type":"tool_use","id":"toolu_01R5HhRTnQeG6ybcpuf23grM","name":"Bash","input":{"command":"git diff ef72d24..HEAD -- services/control/src/bringdown_engine/worker.py services/control/src/bringdown_engine/runtime.py services/control/src/bringdown_engine/docker.py runtime/agent-image/entrypoint.py harness/profiles/web_assessment_v1/toolkit.yaml services/control/scripts/export_openapi.py","description":"Diff worker, runtime, docker, entrypoint, toolkit"}}]},"_atp":{"origin":"ghost","turnId":"msg_011CeqUioX694UZnQ6y1tC98","blockIndex":2,"createdAt":1788848008878,"updatedAt":1788848039008,"context":{"source":"proxy","toolUseId":"toolu_01R5HhRTnQeG6ybcpuf23grM"},"orphanedAt":1788848039008}}
Loading