From 5c6cb767f921c082e8795d983b352a563d7c5793 Mon Sep 17 00:00:00 2001 From: Claude Date: Mon, 10 Aug 2026 10:23:16 +0000 Subject: [PATCH] Close the two finished-session races the E2E stories surfaced MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Both product findings from #1527 are now fixes, and the stories that found them act inside the old race windows on purpose, as regression tests. 1) Acting on a session the moment its meta flips done raced teardown. The child writes `status: done` and exits; teardown then archives the history, commits the bookkeeping to the run branch, and retires the worktree. A Push/Open-PR/Remove/Delete/Resume fired inside that window ran its own git against the same checkout: the loser reported "could not commit the work this session left uncommitted", and a teardown that lost stranded a worktree it should have removed. Every mutator of one run's checkout now serializes on a per-run lock (run-locks.ts) — teardown, the handoff RPCs' commit step, the worktree removal RPCs, and continuation reuse. Both actors live in the daemon process by design, so the in-process lock is the whole fix. 2) A live event tail whose journal was retired went silent without the final events. Teardown copies events.jsonl verbatim into the archive and removes the worktree; when fs.watch missed the last appends, the poll backstop found the file gone and delivered nothing again — including the run's `end`. tailRunEvents (events-tail.ts) re-resolves the journal's home when the tailed file disappears and retargets the same tailer, carrying its read offset, so exactly the missed lines arrive, once. The first pull after a retarget adopts the copy's mtime so the #567 same-length-rewrite check cannot misread the move as a truncation and replay the feed. Wired into the dashboard's onEvents (with a guard against relocating onto the project-root journal, which after a Delete is another run's feed), the device relay tail, and the E2E harness — which drops its private archive-swap workaround for the product seam. The publish and resume stories now fire at the instant the run flips done; the harness's close() drains in-flight teardowns by acquiring each run's lock before deleting the fixture repos, which is what the stranded-worktree noise in stress runs turned out to be. Verified: full suite 1713 tests green; the two race stories plus every other story file stressed 6-15x each with zero failures and zero stranded-worktree warnings. Co-Authored-By: Claude Fable 5 Claude-Session: https://claude.ai/code/session_01XKihCTfcazhDgt4dhUmfM9 --- .changeset/finished-session-races.md | 5 + packages/the-framework/src/daemon-runtime.ts | 135 ++++++++++-------- .../src/dashboard-rpc/control.telefunc.ts | 22 ++- .../src/dashboard-rpc/events-tail.test.ts | 98 ++++++++++++- .../src/dashboard-rpc/events-tail.ts | 91 ++++++++++++ .../src/dashboard-rpc/events.telefunc.ts | 29 +++- packages/the-framework/src/e2e/harness.ts | 57 +++----- packages/the-framework/src/e2e/spec.md | 8 +- .../e2e/story-projects-and-settings.test.ts | 7 +- .../src/e2e/story-session-lifecycle.test.ts | 28 ++-- packages/the-framework/src/jsonl-tail.ts | 24 +++- packages/the-framework/src/run-locks.test.ts | 66 +++++++++ packages/the-framework/src/run-locks.ts | 41 ++++++ 13 files changed, 487 insertions(+), 124 deletions(-) create mode 100644 .changeset/finished-session-races.md create mode 100644 packages/the-framework/src/run-locks.test.ts create mode 100644 packages/the-framework/src/run-locks.ts diff --git a/.changeset/finished-session-races.md b/.changeset/finished-session-races.md new file mode 100644 index 00000000..369c6d7e --- /dev/null +++ b/.changeset/finished-session-races.md @@ -0,0 +1,5 @@ +--- +'@gemstack/the-framework': patch +--- + +Two races in the finished-session seam are closed. Everything that mutates one run's checkout — teardown's archive-commit-retire, the Push/Open-PR commit step, Remove/Delete of the worktree, and a Resume's checkout reuse — now serializes on a per-run lock, so an action clicked the instant a session flips done waits a beat instead of failing with "could not commit the work this session left uncommitted" (and teardown no longer strands a worktree it lost that race to). And the live event feed follows the run's journal across its relocation into the archive: a fixed-path tail whose fs.watch missed the final appends used to go silent without the run's `end`; the tail now re-resolves the journal's home and carries its read offset, so exactly the missed lines arrive, once — in the dashboard's live channel and the device relay alike. diff --git a/packages/the-framework/src/daemon-runtime.ts b/packages/the-framework/src/daemon-runtime.ts index 37c4f081..bf3f36eb 100644 --- a/packages/the-framework/src/daemon-runtime.ts +++ b/packages/the-framework/src/daemon-runtime.ts @@ -37,7 +37,7 @@ import type { EventsSource, PreviewHandlers, RemoteRuns } from './dashboard/tele import { RelayedRuns, startRemoteRun } from './dashboard/remote-run.js' import { runBranchFor } from './dashboard/run-handoff.js' import { dispatchRelayRpc } from './dashboard-rpc/relay-dispatch.js' -import { tailEvents } from './dashboard-rpc/events-tail.js' +import { tailEvents, tailRunEvents } from './dashboard-rpc/events-tail.js' import { isSafeVia } from './conversations.js' import { ensureSessionsIgnored, resolveUserDir } from './sessions.js' import { createPreviewRuntime } from './preview-runtime.js' @@ -48,6 +48,7 @@ import { resolveProjectRunOptions } from './daemon-services.js' import { installProject, enumerateGitRepos } from './install.js' import { isGitRepo } from './project.js' import { isCliTimeout } from './cli-exec.js' +import { withRunLock } from './run-locks.js' import { errorMessage } from './error-message.js' import { preflight, preflightProblems, type PreflightResult } from './preflight.js' import { isAgentName, type AgentName } from './agent-names.js' @@ -433,26 +434,31 @@ export function createProjectRuntime({ cwd, env, binPath, retryDelayMs, agentPre * The branch is the session's if the agent named one, else the run-id branch it started on. * Returns undefined when none of that is possible, so the caller can fall back to a new run. */ - const continueWorkspace = async (projectCwd: string, runId: string): Promise<{ cwd: string; runId: string } | undefined> => { - try { - const path = worktreePath(projectCwd, runId) - const existing = await stat(path).then(s => s.isDirectory()).catch(() => false) - if (!existing) { - const archived = (await listRuns(projectCwd).catch(() => [])).find(run => run.id === runId) - // The recorded branch first (#1277): an agent that branched itself (#326 allows it) has - // its work there, and re-attaching by the session-name guess would continue the run on a - // branch without its previous commits. - const branch = runBranchFor(archived ?? { id: runId }) - await attachWorktree(projectCwd, { runId, branch }) - await linkDependencies(projectCwd, path).catch(() => []) + const continueWorkspace = (projectCwd: string, runId: string): Promise<{ cwd: string; runId: string } | undefined> => + // Under the same run lock as teardown: a Resume clicked off a freshly-`done` run lands here + // while teardown is still archiving the very history this restores — reusing the checkout + // mid-retirement spawned the continuation into a tree about to be removed. Waiting the + // teardown out costs the click a beat and makes the reuse read a settled archive. + withRunLock(worktreePath(projectCwd, runId), async () => { + try { + const path = worktreePath(projectCwd, runId) + const existing = await stat(path).then(s => s.isDirectory()).catch(() => false) + if (!existing) { + const archived = (await listRuns(projectCwd).catch(() => [])).find(run => run.id === runId) + // The recorded branch first (#1277): an agent that branched itself (#326 allows it) has + // its work there, and re-attaching by the session-name guess would continue the run on a + // branch without its previous commits. + const branch = runBranchFor(archived ?? { id: runId }) + await attachWorktree(projectCwd, { runId, branch }) + await linkDependencies(projectCwd, path).catch(() => []) + } + await restoreArchivedRun(projectCwd, path, runId).catch(() => false) + return { cwd: path, runId } + } catch (err) { + console.log(`[framework] could not continue session ${runId} (${errorMessage(err)}); starting a new one`) + return undefined } - await restoreArchivedRun(projectCwd, path, runId).catch(() => false) - return { cwd: path, runId } - } catch (err) { - console.log(`[framework] could not continue session ${runId} (${errorMessage(err)}); starting a new one`) - return undefined - } - } + }) /** * Whether the agent this run picked can actually start (#1326), as one line to show when it @@ -535,34 +541,40 @@ export function createProjectRuntime({ cwd, env, binPath, retryDelayMs, agentPre */ /** The project half of a preview key from a checkout: the registry id every preview RPC keys by. */ const projectKeyFor = (projectCwd: string): string => projectId(resolve(projectCwd)) - const tearDownWorktree = async (projectCwd: string, worktree: string, runId?: string): Promise => { - try { - // A session can be serving its own checkout (#797), and that dev server holds the directory - // it is about to lose. Stop it first, whether or not the worktree ends up removed: the run - // is over, so the preview is serving a tree nothing is working on. - await previews.preview.stop(projectKeyFor(projectCwd), runId) - // Where the work ended up, recorded before the checkout can go (#799). The branch outlives - // the worktree and is the only handle the dashboard has left on a finished session. - const branch = await currentBranch(worktree) - // Filed under the identity this repo commits as, and the ignore rules taught to keep it, so - // the session survives the repo being cleaned (#1179). - const user = await resolveUserDir(projectCwd) - await ensureSessionsIgnored(projectCwd, user).catch(() => false) - const meta = await archiveWorktreeRun(worktree, projectCwd, undefined, branch, user) - if (meta?.status !== 'done') return // failed / stopped / unreadable: keep it for inspection - // A finished run can still be holding an uncommitted edit (#786), and removing the - // checkout would destroy it. Commit it to the run's branch, which outlives the - // worktree; if that cannot be done, keep the checkout rather than take the diff with it. - if (!(await commitPendingWork(worktree))) { - console.log(`[framework] keeping worktree ${worktree}: its uncommitted work could not be committed`) - return + // Under the run lock: a Push/Remove/Resume fired off a freshly-`done` meta lands in the daemon + // while this is mid-archive, and both sides commit in the same checkout. The loser used to + // report "could not commit the work this session left uncommitted" — or worse, this side lost + // and kept a worktree it should have removed. Serialized, whoever runs first commits the whole + // pending state (`add -A`) and the other side finds a clean tree and carries on. + const tearDownWorktree = (projectCwd: string, worktree: string, runId?: string): Promise => + withRunLock(worktree, async () => { + try { + // A session can be serving its own checkout (#797), and that dev server holds the directory + // it is about to lose. Stop it first, whether or not the worktree ends up removed: the run + // is over, so the preview is serving a tree nothing is working on. + await previews.preview.stop(projectKeyFor(projectCwd), runId) + // Where the work ended up, recorded before the checkout can go (#799). The branch outlives + // the worktree and is the only handle the dashboard has left on a finished session. + const branch = await currentBranch(worktree) + // Filed under the identity this repo commits as, and the ignore rules taught to keep it, so + // the session survives the repo being cleaned (#1179). + const user = await resolveUserDir(projectCwd) + await ensureSessionsIgnored(projectCwd, user).catch(() => false) + const meta = await archiveWorktreeRun(worktree, projectCwd, undefined, branch, user) + if (meta?.status !== 'done') return // failed / stopped / unreadable: keep it for inspection + // A finished run can still be holding an uncommitted edit (#786), and removing the + // checkout would destroy it. Commit it to the run's branch, which outlives the + // worktree; if that cannot be done, keep the checkout rather than take the diff with it. + if (!(await commitPendingWork(worktree))) { + console.log(`[framework] keeping worktree ${worktree}: its uncommitted work could not be committed`) + return + } + await removeWorktree(projectCwd, worktree) + await pruneWorktrees(projectCwd) + } catch { + // A worktree we could not retire is a worktree left on disk, which is the safe direction. } - await removeWorktree(projectCwd, worktree) - await pruneWorktrees(projectCwd) - } catch { - // A worktree we could not retire is a worktree left on disk, which is the safe direction. - } - } + }) // One more try for a run the API dropped mid-work (#1281): the failure is about the transport, // not the work, and the continue-run machinery (#762/#923) reopens the retained checkout on its @@ -1010,21 +1022,22 @@ export function createProjectRuntime({ cwd, env, binPath, retryDelayMs, agentPre // else undefined so `onEvents` tails the on-disk log as usual for an ordinary local run. const remoteEventsSource: EventsSource = (_projectId, runId) => relayedRuns.get(runId) - // Tail a relay-started run's own log (#1067) for the `/_relay/events` endpoint. Resolving the run's - // journal is async, so a stop is returned immediately and the tail attaches once the path is known. + // Tail a relay-started run's own log (#1067) for the `/_relay/events` endpoint. The relocating + // tail, for the same reason as the dashboard's onEvents: teardown moves the journal into the + // archive, and the device's fixed-path tail went silent without the run's final events. The + // initial attach takes whatever the resolver answers (a non-git fallback run's journal IS the + // root one); a relocation refuses the root fallback — there it is another run's feed. + const rootJournal = join(cwd, FRAMEWORK_DIR, EVENTS_FILE) const tailRelayEvents = (runId: string, onEvent: (event: FrameworkEvent) => void): (() => void) => { - let stop = (): void => {} - let cancelled = false - void resolveRunEventsPath(cwd, runId) - .then(path => { - if (cancelled) return - stop = tailEvents(path, onEvent) - }) - .catch(() => {}) - return () => { - cancelled = true - stop() - } + let initial = true + return tailRunEvents(async () => { + const next = await resolveRunEventsPath(cwd, runId) + if (initial) { + initial = false + return next + } + return next === rootJournal ? undefined : next + }, onEvent) } const dispose = async (): Promise => { diff --git a/packages/the-framework/src/dashboard-rpc/control.telefunc.ts b/packages/the-framework/src/dashboard-rpc/control.telefunc.ts index 3d744fe7..905a297a 100644 --- a/packages/the-framework/src/dashboard-rpc/control.telefunc.ts +++ b/packages/the-framework/src/dashboard-rpc/control.telefunc.ts @@ -9,7 +9,8 @@ import { appendFlatTodoEntry, ticketForPrompt } from '../todo-loop.js' import { TICKETS_DIR, todoPriorityForTicket } from '../tickets.js' import { isTicketFile } from '../dashboard/tickets.js' import { releaseTicketLock } from '../ticket-locks.js' -import { findRun, isSafeRunId, type RunMeta } from '../store/index.js' +import { findRun, isSafeRunId, worktreePath, type RunMeta } from '../store/index.js' +import { withRunLock } from '../run-locks.js' import { removeProjectWorktree, deleteProjectRun } from '../worktrees.js' import { commitSessionWork, mergeSessionPr, openSessionPullRequest, pushRunBranch, runBranchFor, type HandoffResult } from '../dashboard/run-handoff.js' import type { ChoiceBy } from '../events.js' @@ -161,7 +162,12 @@ async function withWorktreeRemoval( const preview = contextPreview() const cwd = await resolveProjectPath(projectId) if (!cwd) return { ok: false, error: 'this project has no local path on this server' } - return remove(cwd, { beforeRemove: async id => { await preview?.stop(projectId, id) } }) + // Under the run lock: a Remove/Delete clicked the moment a run ends races teardown's own + // archive-commit-remove of the same checkout; serialized, whichever runs second finds the + // state the first one left and acts on that. + return withRunLock(worktreePath(cwd, runId), () => + remove(cwd, { beforeRemove: async id => { await preview?.stop(projectId, id) } }), + ) } /** @@ -310,7 +316,11 @@ export async function sendPushBranch(projectId: string, runId: string): Promise< const target = await handoffTargetFor(projectId, runId) if (!target) return { ok: false, error: 'unknown session' } const branch = runBranchFor(target.run) - if (!(await commitSessionWork(target.checkout, target.cwd, branch))) { + // The commit step holds the run lock: clicked the moment a session flips `done`, this used + // to commit against the checkout teardown was committing in and lose. Serialized, whichever + // side runs first commits everything pending; the other finds a clean tree — or no checkout + // at all, which commitSessionWork already reads as "the branch is authoritative". + if (!(await withRunLock(target.checkout, () => commitSessionWork(target.checkout, target.cwd, branch)))) { return { ok: false, error: 'could not commit the work this session left uncommitted' } } return pushRunBranch(target.cwd, branch) @@ -328,7 +338,11 @@ export async function sendOpenPullRequest(projectId: string, runId: string): Pro return relayOr(runId, 'sendOpenPullRequest', [projectId, runId], async () => { const target = await handoffTargetFor(projectId, runId) if (!target) return { ok: false, error: 'unknown session' } - if (!(await commitSessionWork(target.checkout, target.cwd, runBranchFor(target.run)))) { + // Same run lock as sendPushBranch, for the same click-at-`done` race. + const committed = await withRunLock(target.checkout, () => + commitSessionWork(target.checkout, target.cwd, runBranchFor(target.run)), + ) + if (!committed) { return { ok: false, error: 'could not commit the work this session left uncommitted' } } return openSessionPullRequest(target.cwd, target.run) diff --git a/packages/the-framework/src/dashboard-rpc/events-tail.test.ts b/packages/the-framework/src/dashboard-rpc/events-tail.test.ts index 8396ceda..497a4789 100644 --- a/packages/the-framework/src/dashboard-rpc/events-tail.test.ts +++ b/packages/the-framework/src/dashboard-rpc/events-tail.test.ts @@ -4,7 +4,7 @@ import { appendFile, mkdtemp, rm, writeFile } from 'node:fs/promises' import { tmpdir } from 'node:os' import { join } from 'node:path' import type { FrameworkEvent } from '../events.js' -import { tailEvents } from './events-tail.js' +import { tailEvents, tailRunEvents } from './events-tail.js' const line = (message: string): string => JSON.stringify({ kind: 'log', message } satisfies FrameworkEvent) + '\n' const sleep = (ms: number): Promise => new Promise(resolve => setTimeout(resolve, ms)) @@ -117,3 +117,99 @@ test('tailEvents reports the replay boundary even when the log does not exist ye await rm(cwd, { recursive: true, force: true }) } }) + +// The relocating tail: a run's journal is copied verbatim into the archive at teardown and the +// worktree is removed. tailRunEvents re-resolves the path when the tailed file disappears and +// carries the read offset across the move, so the feed gets exactly the lines the move would +// have swallowed — once, with no replay of what was already delivered. + +test('tailRunEvents follows the journal into the archive: missed lines arrive exactly once', async () => { + const cwd = await tmpWorkspace() + const live = join(cwd, 'worktree-events.jsonl') + const archive = join(cwd, 'archived-events.jsonl') + await writeFile(live, line('one') + line('two')) + const seen: string[] = [] + let sync = 0 + const { rename } = await import('node:fs/promises') + const stop = tailRunEvents( + async () => ((await import('node:fs')).existsSync(live) ? live : archive), + e => void (e.kind === 'log' && seen.push(e.message)), + () => sync++, + ) + try { + await sleep(200) + assert.deepEqual(seen, ['one', 'two']) + // The retirement, compressed: the final lines land and the journal moves in one breath, so + // whether the watcher saw the appends before the move is scheduling luck — exactly the + // window that used to swallow a fast run's `end`. Either way the tail must deliver + // everything, each line once. + await appendFile(live, line('three') + line('four')) + await rename(live, archive) + await sleep(1600) // fs.watch is unreliable on CI; wait out the poll backstop behind it + assert.deepEqual(seen, ['one', 'two', 'three', 'four']) + // A relocation is not a new replay boundary: the marker stays once-per-subscription (#1383). + assert.equal(sync, 1) + } finally { + stop() + await rm(cwd, { recursive: true, force: true }) + } +}) + +test('tailRunEvents does not replay a fully-consumed journal after the move', async () => { + const cwd = await tmpWorkspace() + const live = join(cwd, 'worktree-events.jsonl') + const archive = join(cwd, 'archived-events.jsonl') + await writeFile(live, line('one') + line('two')) + const seen: string[] = [] + const { copyFile, rm: rmFile } = await import('node:fs/promises') + const stop = tailRunEvents( + async () => ((await import('node:fs')).existsSync(live) ? live : archive), + e => void (e.kind === 'log' && seen.push(e.message)), + ) + try { + await sleep(200) + assert.deepEqual(seen, ['one', 'two']) + await sleep(20) // let the copy's mtime land visibly later than the seeding read + // The archive path: a same-content copy with a NEWER mtime and the SAME length as what was + // consumed — the exact shape the #567 same-length-rewrite detection resets on. The retarget + // must adopt the copy's mtime instead, or every line would be delivered twice. + await copyFile(live, archive) + await rmFile(live) + await sleep(1600) + assert.deepEqual(seen, ['one', 'two']) + } finally { + stop() + await rm(cwd, { recursive: true, force: true }) + } +}) + +test('tailRunEvents stays put while the resolver has no better answer', async () => { + const cwd = await tmpWorkspace() + const live = join(cwd, 'worktree-events.jsonl') + const archive = join(cwd, 'archived-events.jsonl') + await writeFile(live, line('one')) + const seen: string[] = [] + const { copyFile, rm: rmFile } = await import('node:fs/promises') + let archiveVisible = false + const stop = tailRunEvents( + // The window where the live file is gone but the archive is not resolvable yet: the + // resolver answers undefined (a deleted session resolves like this forever), and the tail + // must idle rather than hop somewhere wrong — then catch up once the archive appears. + async () => ((await import('node:fs')).existsSync(live) ? live : archiveVisible ? archive : undefined), + e => void (e.kind === 'log' && seen.push(e.message)), + ) + try { + await sleep(200) + assert.deepEqual(seen, ['one']) + await appendFile(live, line('two')) + await copyFile(live, archive) + await rmFile(live) + await sleep(1300) // a full poll with the resolver still answering undefined + archiveVisible = true + await sleep(1600) + assert.deepEqual(seen, ['one', 'two']) + } finally { + stop() + await rm(cwd, { recursive: true, force: true }) + } +}) diff --git a/packages/the-framework/src/dashboard-rpc/events-tail.ts b/packages/the-framework/src/dashboard-rpc/events-tail.ts index a6d74745..807ac241 100644 --- a/packages/the-framework/src/dashboard-rpc/events-tail.ts +++ b/packages/the-framework/src/dashboard-rpc/events-tail.ts @@ -1,3 +1,4 @@ +import { existsSync } from 'node:fs' import { dirname } from 'node:path' import { JsonlTailer, followFile } from '../jsonl-tail.js' @@ -38,3 +39,93 @@ export function tailEvents(path: string, onEvent: (event: T) => voi stopFollow?.() } } + +/** + * Tail a run's journal across its relocations: the same read-then-follow as {@link tailEvents}, + * but the path is re-resolved whenever the tailed file disappears after having existed. + * + * A run's `events.jsonl` does not sit still. Teardown copies it verbatim into the archive and + * removes the worktree; a continuation restores it into a fresh checkout. A fixed-path tail + * whose file was retired went silent *without the final lines* whenever the last `fs.watch` + * signal was lost — the 1s poll then found the file gone and had nothing to read, so the feed + * never learned the run ended. This tail treats "the file existed and is now gone" as the + * relocation it is: it asks `resolvePath` where the journal lives now (`resolveRunEventsPath` + * already answers the archive once the worktree is gone, #1472), retargets the same tailer — + * the copy is content-identical, so the offset carries and nothing is replayed — and follows + * the new home. + * + * `onReplayed` keeps {@link tailEvents}' once-per-subscription contract: a relocation is not a + * new replay boundary, so it never fires twice. + */ +export function tailRunEvents( + resolvePath: () => Promise, + onEvent: (event: T) => void, + onReplayed?: () => void, +): () => void { + let stopped = false + let stopFollow: (() => void) | undefined + let path: string | undefined + let tailer: JsonlTailer | undefined + let sawFile = false + let relocating = false + + const follow = (): void => { + if (stopped || path === undefined) return + stopFollow = followFile(dirname(path), pullOrRelocate, { pollMs: POLL_MS }) + } + + const relocate = async (): Promise => { + const next = await resolvePath() + // Same answer or none: not moved (or not visible yet) — keep polling the current home. + if (stopped || !tailer || next === undefined || next === path) return + stopFollow?.() + path = next + sawFile = false + tailer.retarget(next) + await tailer.pull() + follow() + } + + const pullOrRelocate = async (): Promise => { + if (stopped || !tailer || path === undefined) return + if (existsSync(path)) { + sawFile = true + await tailer.pull() + return + } + // Gone before anything was written is a run still booting, not a move. + if (!sawFile || relocating) return + relocating = true + try { + await relocate() + } finally { + relocating = false + } + } + + void resolvePath().then( + initial => { + if (stopped) return + // No journal to speak of (unknown project): honor the replay contract and stay silent. + if (initial === undefined) { + onReplayed?.() + return + } + path = initial + tailer = new JsonlTailer(initial, onEvent) + const replayed = (): void => { + if (stopped) return + onReplayed?.() + if (existsSync(initial)) sawFile = true + follow() + } + void tailer.pull().then(replayed, replayed) + }, + () => onReplayed?.(), + ) + + return () => { + stopped = true + stopFollow?.() + } +} diff --git a/packages/the-framework/src/dashboard-rpc/events.telefunc.ts b/packages/the-framework/src/dashboard-rpc/events.telefunc.ts index e19ee5ab..2d5f12fb 100644 --- a/packages/the-framework/src/dashboard-rpc/events.telefunc.ts +++ b/packages/the-framework/src/dashboard-rpc/events.telefunc.ts @@ -2,7 +2,7 @@ import type { ClientChannel } from 'telefunc' import { resolveRunEventsPath } from '../store/index.js' import { contextEventsSource, resolveProjectPath } from './context.js' import type { FrameworkEvent } from '../events.js' -import { tailEvents } from './events-tail.js' +import { tailRunEvents } from './events-tail.js' import { forwardStream, streamChannel } from './stream-channel.js' // The live event stream behind the new dashboard (#405): the selected project's run, @@ -62,6 +62,31 @@ export async function onEvents(projectId: string, runId?: string): Promise(send => forwardStream(stream, send)) } // Everywhere else: tail the run's on-disk events.jsonl (undefined path -> closed channel). + // The relocating tail, because the journal moves mid-subscription: teardown copies it into the + // archive and removes the worktree, and a fixed-path tail whose fs.watch missed the final + // appends went silent without the run's `end`. On the move it re-resolves (the archive, #1472) + // and carries its offset, so the feed gets exactly the lines the move would have swallowed. const path = await resolveEventsPath(projectId, runId) - return streamChannel(send => (path ? tailEvents(path, send, () => send({ kind: 'stream-sync' })) : undefined)) + // The one place a run-scoped feed must NOT relocate to: the project-root journal, which is + // resolveRunEventsPath's last-resort fallback once a Delete has removed worktree and archive + // alike — it is another run's feed (#1472). A deleted session's tab goes quiet instead. The + // initial attach stays permissive: a fallback run (non-git project) legitimately lives there. + const rootJournal = runId === undefined ? undefined : await resolveEventsPath(projectId, undefined) + let initial = true + return streamChannel(send => + path + ? tailRunEvents( + async () => { + const next = await resolveEventsPath(projectId, runId) + if (initial) { + initial = false + return next + } + return rootJournal !== undefined && next === rootJournal ? undefined : next + }, + send, + () => send({ kind: 'stream-sync' }), + ) + : undefined, + ) } diff --git a/packages/the-framework/src/e2e/harness.ts b/packages/the-framework/src/e2e/harness.ts index 0e914669..e8876a03 100644 --- a/packages/the-framework/src/e2e/harness.ts +++ b/packages/the-framework/src/e2e/harness.ts @@ -1,7 +1,7 @@ // The world behind the backend E2E story tests (see spec.md): the daemon's business logic wired // exactly as `runDaemon` wires it, against throwaway state, with runs spawned through // `fake-agent-bin.js` so the full production lifecycle executes offline. -import { existsSync, mkdtempSync } from 'node:fs' +import { mkdtempSync } from 'node:fs' import { mkdir, readFile, rm, stat, writeFile } from 'node:fs/promises' import { execFile } from 'node:child_process' import { tmpdir } from 'node:os' @@ -12,8 +12,9 @@ import { provideTelefuncContext } from 'telefunc' import { createProjectRuntime, type ProjectRuntime } from '../daemon-runtime.js' import { registryPreferencesStore, projectId } from '../registry.js' import { registryDiscordCredentialsStore } from '../discord-credentials-store.js' -import { loadRunEvents, resolveRunEventsPath, type RunMeta, type RunStatus } from '../store/index.js' -import { tailEvents } from '../dashboard-rpc/events-tail.js' +import { resolveRunEventsPath, type RunMeta, type RunStatus } from '../store/index.js' +import { withRunLock } from '../run-locks.js' +import { tailRunEvents } from '../dashboard-rpc/events-tail.js' import { sendAddProject } from '../dashboard-rpc/projects.telefunc.js' import { sendStart } from '../dashboard-rpc/control.telefunc.js' import { onRuns } from '../dashboard-rpc/reads.telefunc.js' @@ -163,6 +164,7 @@ export async function makeWorld(): Promise { const repos: string[] = [] const tails: RunTail[] = [] + const started: Array<{ cwd: string; runId: string }> = [] const rpc: StoryWorld['rpc'] = fn => { return (...args) => { @@ -208,6 +210,7 @@ export async function makeWorld(): Promise { const result = await rpc(sendStart)(project.id, prompt, kind, options) if (!result.ok) throw new Error(`sendStart refused: ${result.error}`) if (!result.runId) throw new Error('sendStart returned no run id for a worktree project') + started.push({ cwd: project.cwd, runId: result.runId }) return result.runId }, @@ -235,38 +238,15 @@ export async function makeWorld(): Promise { }, async tailRun(project, runId) { - const path = await resolveRunEventsPath(project.cwd, runId) const events: FrameworkEvent[] = [] - const stopLive = tailEvents(path, event => events.push(event)) - // Teardown MOVES the live log into the archive and removes the worktree ~100ms after a - // fast run ends, and a tail whose file vanished delivers nothing ever again — the 1s poll - // backstop can lose the final lines to that window when the fs.watch event goes missing. - // The dashboard heals the same way this does: the session view swaps to the archived - // replay once the row settles. So when the live file disappears, finish the feed from the - // run's archived journal (a superset of everything the live tail saw). - let sawFile = false - const finalize = setInterval(() => { - if (existsSync(path)) { - sawFile = true - return - } - if (!sawFile) return // not written yet — the run is still booting, nothing was moved - clearInterval(finalize) - stopLive() - void loadRunEvents(project.cwd, runId) - .then(archived => { - if (archived && archived.length >= events.length) events.splice(0, events.length, ...archived) - }) - .catch(() => {}) - }, 100) - finalize.unref?.() - const tail = { - events, - stop: () => { - clearInterval(finalize) - stopLive() - }, - } + // The relocating tail — the same seam the dashboard's onEvents rides: when teardown moves + // the journal into the archive, the tail re-resolves the run's journal and carries its + // offset, so the feed keeps the final events even when their fs.watch signal was lost. + const stop = tailRunEvents( + () => resolveRunEventsPath(project.cwd, runId), + event => events.push(event), + ) + const tail = { events, stop } tails.push(tail) return tail }, @@ -275,6 +255,15 @@ export async function makeWorld(): Promise { for (const tail of tails) tail.stop() // Same order as daemon shutdown: stop the runs this world spawned, then the previews. await runtime.suspendRuns(2000).catch(() => 0) + // Teardowns fire off child-exit events and outlive the assertions — deleting the repos + // under a mid-flight archive-commit-retire kills its git ("cannot lock ref 'HEAD'") and + // litters the output with stranded-worktree warnings. Acquiring each run's lock is the + // daemon's own way of waiting a teardown out. + await Promise.all( + started.map(({ cwd, runId }) => + withRunLock(join(cwd, '.the-framework', 'worktrees', runId), async () => {}), + ), + ) await runtime.dispose().catch(() => {}) delete process.env.FRAMEWORK_E2E_ARGV_FILE await rm(home, { recursive: true, force: true }).catch(() => {}) diff --git a/packages/the-framework/src/e2e/spec.md b/packages/the-framework/src/e2e/spec.md index ca68b959..788bc181 100644 --- a/packages/the-framework/src/e2e/spec.md +++ b/packages/the-framework/src/e2e/spec.md @@ -14,9 +14,9 @@ Backend end-to-end story tests: each test walks one dashboard user story through `FRAMEWORK_FAKE_AWAIT=choices|multiselect|confirmation` (set before a Start, spawned children inherit the env) makes the fake agent's first turn end on that gate, which is how stories park a run on a question deterministically. Without it the fake agent answers every prompt with one scripted build turn and the run ends on its own. -## Two product races these stories deliberately step around +## Two product races these stories surfaced — and now pin down -Writing the stories surfaced two real windows in the finished-session seam; the harness models the same healing the dashboard relies on, and both are candidates for tightening in the product: +Writing the stories surfaced two real windows in the finished-session seam. Both are fixed in the product, and the stories are their regression tests: -- **Acting on a run the moment its meta flips `done` races teardown.** The child writes `status: done` and exits; the daemon then archives the history, commits the bookkeeping to the run branch, and retires the worktree. A `sendPushBranch`/resume fired inside that window runs `commitPendingWork` against the same checkout teardown is committing in, and the loser reports "could not commit the work this session left uncommitted" (teardown then retains the worktree it would have removed). A user clicking Push the instant a session finishes can hit the same message; clicking again succeeds. Stories wait for `waitRetired` — the honest reading of "finished" — before publishing or resuming. -- **A live tail whose file is retired goes silent without the final events.** Teardown *moves* `events.jsonl` into the archive; `tailEvents`' fs.watch can miss the last appends under watcher pressure, and its 1s poll then finds the file gone — nothing is ever delivered again, including the `end` the transcript needs. The dashboard heals by swapping to the archived replay (`onRun`) once the row settles; `tailRun` mirrors exactly that swap when the live file disappears. +- **Acting on a run the moment its meta flips `done` used to race teardown.** The child writes `status: done` and exits; the daemon then archives the history, commits the bookkeeping to the run branch, and retires the worktree. A Push/Resume fired inside that window ran its own commit against the same checkout, the loser reported "could not commit the work this session left uncommitted", and a losing teardown stranded the worktree. Now every mutator of one run's checkout — teardown, the handoff's commit step, Remove/Delete, continuation reuse — serializes on the run lock (`run-locks.ts`). The publish and resume stories act *at* `done` on purpose; `waitRetired` remains for stories about the retired state itself. +- **A live tail whose file was retired used to go silent without the final events.** Teardown *moves* `events.jsonl` into the archive; when fs.watch missed the last appends, the 1s poll found the file gone and delivered nothing again — including the `end` the transcript needs. `tailRunEvents` (events-tail.ts) now re-resolves the journal's home when the tailed file disappears and carries its read offset across the move — the archive is a verbatim copy, so exactly the missed lines arrive, once. `onEvents`, the relay tail, and this harness's `tailRun` all ride it. diff --git a/packages/the-framework/src/e2e/story-projects-and-settings.test.ts b/packages/the-framework/src/e2e/story-projects-and-settings.test.ts index 7d3d8cf5..badeae9a 100644 --- a/packages/the-framework/src/e2e/story-projects-and-settings.test.ts +++ b/packages/the-framework/src/e2e/story-projects-and-settings.test.ts @@ -79,14 +79,15 @@ test('settings written in the dashboard reach the next resumed run (#858/#1467)' assert.equal(projectPatched.ok, true) assert.equal((await rpc(onProjectPreferences)(project.id)).model, 'fable-e2e') - // First leg: a plain run, finished and fully retired (resuming mid-teardown would race the - // archive of the very history the continuation reopens). + // First leg: a plain run, finished. const runId = await world.startRun(project, 'Build the settings page') await world.waitRun(project, runId, 'done') - await world.waitRetired(project, runId) // The composer's Resume sends only its seed (#1467); the daemon overlays the project's // resolved options, so the model chosen in Settings reaches the continued session's argv. + // Fired the instant the row flips done — deliberately inside teardown's window: the run + // lock makes the continuation wait out the archive it is about to reopen, where it used to + // reuse a checkout mid-retirement. const resumed = await rpc(sendStart)(project.id, 'Keep going', 'prompt', { continueRunId: runId }) assert.equal(resumed.ok, true) await world.waitRun(project, runId, 'done') diff --git a/packages/the-framework/src/e2e/story-session-lifecycle.test.ts b/packages/the-framework/src/e2e/story-session-lifecycle.test.ts index 507b1c24..4f320246 100644 --- a/packages/the-framework/src/e2e/story-session-lifecycle.test.ts +++ b/packages/the-framework/src/e2e/story-session-lifecycle.test.ts @@ -153,24 +153,26 @@ test("publish a finished session: push its branch from the handoff panel (#799)" const runId = await world.startRun(project, 'Ship the settings page', { autoPushBranch: false, autoOpenPr: false }) await world.waitRun(project, runId, 'done') - // Fully finished, not merely `done`: acting before teardown retires the checkout races - // teardown's own commits — the same race a user hits clicking Push the moment a run ends. - await world.waitRetired(project, runId) - - // Before the click: the panel reports the branch, the remote, and that nothing is pushed yet. - const before = await waitFor(async () => (await rpc(onRunHandoff)(project.id, runId)) ?? undefined, 'the handoff read') - assert.equal(before.branch, `the-framework/run-${runId}`) - assert.equal(before.exists, true) - assert.equal(before.hasRemote, true) - assert.equal(before.pushed, false) - // The user's Push click publishes the branch; the remote now has it and the panel says so. + // Pushed the instant the row flips done — deliberately INSIDE teardown's window. This used + // to race teardown's own commits in the same checkout: the click failed with "could not + // commit the work this session left uncommitted" and teardown stranded the worktree. The + // run lock serializes the two, so the first click works and teardown still retires cleanly. const pushed = await rpc(sendPushBranch)(project.id, runId) assert.equal(pushed.ok, true, `push failed: ${'error' in pushed ? pushed.error : ''}`) const remoteBranches = await git(project.cwd, 'ls-remote', '--heads', 'origin') assert.ok(remoteBranches.includes(`the-framework/run-${runId}`), 'the run branch is on origin') - const after = await rpc(onRunHandoff)(project.id, runId) - assert.equal(after?.pushed, true) + await world.waitRetired(project, runId) + assert.deepEqual(await rpc(onRetainedWorktrees)(project.id), [], 'the concurrent push must not strand the worktree') + + // The handoff panel agrees: branch on the remote, session record included. + const after = await waitFor(async () => { + const handoff = await rpc(onRunHandoff)(project.id, runId) + return handoff?.pushed ? handoff : undefined + }, 'the panel to report the branch pushed') + assert.equal(after.branch, `the-framework/run-${runId}`) + assert.equal(after.exists, true) + assert.equal(after.hasRemote, true) } finally { await world.close() } diff --git a/packages/the-framework/src/jsonl-tail.ts b/packages/the-framework/src/jsonl-tail.ts index 33f7b652..029c80af 100644 --- a/packages/the-framework/src/jsonl-tail.ts +++ b/packages/the-framework/src/jsonl-tail.ts @@ -13,12 +13,30 @@ export class JsonlTailer { private offset = 0 private partial = '' private lastMtimeMs = 0 + private adoptMtime = false constructor( - private readonly path: string, + private path: string, private readonly onLine: (value: T) => void, ) {} + /** + * Point the tailer at the journal's new home, keeping the read offset. For a log that is + * *relocated with its content intact* — a run's `events.jsonl` is copied verbatim into the + * archive at teardown (and restored on a continuation) — the bytes already consumed are a + * prefix of the new file, so the next {@link pull} delivers exactly the lines the move would + * otherwise have swallowed, without replaying what was already delivered. + * + * The first pull after a retarget adopts the new home's mtime instead of running the + * same-length-rewrite check: the copy is younger than the original by construction, and a + * fully-consumed journal would otherwise read as "rewritten to the same length" and replay + * every line it already delivered. + */ + retarget(path: string): void { + this.path = path + this.adoptMtime = true + } + /** Read and dispatch any lines appended since the previous call. */ async pull(): Promise { let fd @@ -32,12 +50,14 @@ export class JsonlTailer { // A fresh run truncates the log in place (same inode). Detect it two ways: the // file shrank below what we consumed, or it was rewritten to the same length // (size unchanged but mtime advanced). Either way, re-read from the top. - const rewritten = size === this.offset && this.offset > 0 && mtimeMs > this.lastMtimeMs + // Suspended for the first read after a retarget, whose newer mtime is the copy's, not a rewrite's. + const rewritten = !this.adoptMtime && size === this.offset && this.offset > 0 && mtimeMs > this.lastMtimeMs if (size < this.offset || rewritten) { this.offset = 0 this.partial = '' } this.lastMtimeMs = mtimeMs + this.adoptMtime = false if (size === this.offset) return const buf = Buffer.alloc(size - this.offset) await fd.read(buf, 0, buf.length, this.offset) diff --git a/packages/the-framework/src/run-locks.test.ts b/packages/the-framework/src/run-locks.test.ts new file mode 100644 index 00000000..fd588efe --- /dev/null +++ b/packages/the-framework/src/run-locks.test.ts @@ -0,0 +1,66 @@ +import { strict as assert } from 'node:assert' +import { test } from 'node:test' +import { withRunLock } from './run-locks.js' + +const tick = (): Promise => new Promise(resolve => setImmediate(resolve)) + +test('withRunLock serializes holders of the same checkout, in arrival order', async () => { + const order: string[] = [] + let releaseFirst = (): void => {} + const first = withRunLock('/tmp/a', async () => { + order.push('first:start') + await new Promise(resolve => (releaseFirst = resolve)) + order.push('first:end') + }) + const second = withRunLock('/tmp/a', async () => { + order.push('second') + }) + await tick() + // The second holder must not have started while the first is parked. + assert.deepEqual(order, ['first:start']) + releaseFirst() + await Promise.all([first, second]) + assert.deepEqual(order, ['first:start', 'first:end', 'second']) +}) + +test('different checkouts never contend', async () => { + const order: string[] = [] + let release = (): void => {} + const held = withRunLock('/tmp/a', async () => { + await new Promise(resolve => (release = resolve)) + order.push('a') + }) + await withRunLock('/tmp/b', async () => { + order.push('b') + }) + assert.deepEqual(order, ['b']) // b finished while a was still parked + release() + await held +}) + +test('a failed holder surfaces its own error and does not poison the next one (#refuse-loudly)', async () => { + await assert.rejects( + withRunLock('/tmp/a', async () => { + throw new Error('teardown broke') + }), + /teardown broke/, + ) + assert.equal(await withRunLock('/tmp/a', async () => 'ran'), 'ran') +}) + +test('the key is the resolved path, so spellings of one checkout contend', async () => { + const order: string[] = [] + let release = (): void => {} + const held = withRunLock('/tmp/a/.', async () => { + await new Promise(resolve => (release = resolve)) + order.push('held') + }) + const waiter = withRunLock('/tmp/a', async () => { + order.push('waiter') + }) + await tick() + assert.deepEqual(order, []) + release() + await Promise.all([held, waiter]) + assert.deepEqual(order, ['held', 'waiter']) +}) diff --git a/packages/the-framework/src/run-locks.ts b/packages/the-framework/src/run-locks.ts new file mode 100644 index 00000000..e7e5383c --- /dev/null +++ b/packages/the-framework/src/run-locks.ts @@ -0,0 +1,41 @@ +import { resolve } from 'node:path' + +/** + * Serialize everything that mutates one run's checkout. + * + * A run's meta flips to `done` the moment its child writes it — a beat before the daemon's + * teardown archives the history, commits the bookkeeping to the run branch, and retires the + * worktree. Every run-addressed action a user can fire off that fresh `done` (Push / Open PR's + * commit step, Remove/Delete of the checkout, a Resume that reuses it) used to run its own git + * against the same checkout teardown was committing in: the loser reported "could not commit the + * work this session left uncommitted", and a teardown that lost kept a worktree it should have + * removed. Both actors live in the daemon process by design (the dashboard's RPCs are served + * in-process, and only the daemon writes to the project checkout), so an in-process lock is the + * whole fix — there is no second process to coordinate with. + * + * Keyed by the checkout path, resolved: teardown and the actions all name the same worktree, so + * they contend on one key; actions against a run whose worktree is already gone key on the + * project root, where nothing contends. A waiter chains on the predecessor's *settlement* — a + * failed teardown must not skip the push waiting behind it — and each caller still gets its own + * outcome (or failure) back untouched. + */ +const chains = new Map>() + +/** Run `fn` once every earlier holder of `checkout`'s lock has settled. */ +export async function withRunLock(checkout: string, fn: () => Promise): Promise { + const key = resolve(checkout) + const prev = chains.get(key) ?? Promise.resolve() + const run = prev.then(fn, fn) + // What the next waiter chains on: settlement, never rejection — one failed holder must not + // poison every later acquisition of the same key. + const settled = run.then( + () => {}, + () => {}, + ) + chains.set(key, settled) + try { + return await run + } finally { + if (chains.get(key) === settled) chains.delete(key) + } +}