From 50ad6cfc3f00beb95ac0d75d62995a87b46769ee Mon Sep 17 00:00:00 2001 From: Pippa-2697 Date: Fri, 16 Oct 2026 01:16:20 -0400 Subject: [PATCH 1/4] fix(create): a failed create() releases what it had acquired (#389) create() opened the Chronicle store first, and went on to start modules, the liveness watchdog and the event gate and to connect MCPL servers. Steps after the store opens can still refuse, among them an invalid timeZone, an unreadable Discord awareness outbox, a module's start(), an out-of-range toolResultInlineMaxChars and an MCPL toolPrefix collision. Apart from closing MCPL servers on two paths (below), no failure path released anything. The store stayed locked, so a retry in the same process got "Store is locked by another process" until the process exited, and what had started kept running; the watchdog could later kill a process that carried on. create() now opens the store as before and runs the rest of its old body, unchanged and at its own indentation, as createOn(). The framework is named in `building` as soon as it is constructed. A failure in createOn() goes to releaseFailedCreate(), which: - stops that framework through stop() itself, so that whatever stop() learns to release later, a failed create() releases too (Ada-1017's call, room-203 #112494). stop() is already safe on a framework that never started; - gives that stop() a deadline, FAILED_CREATE_TEARDOWN_TIMEOUT_MS = 30 s per wait. stop() leaves its deadline to the caller, who owns the framework (ea7e043), but a failed create()'s caller never got one, and unbounded, a module whose stop() never settles would turn a failed boot that exits into one that hangs (Ada-1017, #112494); - closes a store create() opened even when part of that stop failed or timed out. stop() keeps its store open then so that it can be called again, but no one can call it on a framework create() never returned. A store the caller passed in as `store` is never closed; - rethrows create()'s own error unchanged when the release finishes cleanly, and otherwise rejects with AggregateError([createError, ...releaseErrors]), "AgentFramework.create() failed: . Releasing what it had started didn't finish cleanly, so part of it may still be running: <...>". Keeping createOn()'s body at its old indentation keeps the diff to create()'s first lines, so open PRs that edit its body (#194, #371, #377, #378) still merge cleanly onto this. Two of #389's suspicions don't show on main 91e70eda: nothing after the SIGUSR2 listener's install can throw (checkToolPatterns catches its own errors), and the failures I found after an MCPL child spawns (a DiscordAwarenessAccountingError on connect, a failed startup barrier) already close the children, in initializeMcpl's two catches. Should a later step fail, stop() closes them. stop() itself never removes that listener; that is F47. test/failed-create-releases.test.ts, each test red on main for the reason it names: - refused at the toolPrefix check (#389's reproduction): the module it started is stopped, and a retry on the same storePath succeeds; - refused at an invalid timeZone, before the framework exists: the store is closed, and a retry succeeds; - a store passed in as `store` stays open through both kinds of failure, and the module is still stopped; - a module whose stop() rejects: an AggregateError naming both, and the store is closed anyway, so a retry succeeds; - a module whose stop() never settles: still pending at 29.999 s (mocked), rejected at 30 s with the double-fault message naming the timeout; - in a child process, a create() failing after the watchdog started leaves no watchdog: a 5 s busy stretch past its 2 s threshold isn't killed. Co-Authored-By: Claude Opus 5.5 --- .../389-failed-create-releases.fixed.md | 3 + src/framework.ts | 60 ++++++- test/failed-create-releases.test.ts | 168 ++++++++++++++++++ 3 files changed, 229 insertions(+), 2 deletions(-) create mode 100644 changelog.d/389-failed-create-releases.fixed.md create mode 100644 test/failed-create-releases.test.ts diff --git a/changelog.d/389-failed-create-releases.fixed.md b/changelog.d/389-failed-create-releases.fixed.md new file mode 100644 index 000000000..707592645 --- /dev/null +++ b/changelog.d/389-failed-create-releases.fixed.md @@ -0,0 +1,3 @@ +- A failed `AgentFramework.create()` now releases what it had acquired before its error reaches the caller, so the same process can call `create()` again (#389). Before, a `create()` that failed after opening its store, such as on an invalid `timeZone`, an MCPL `toolPrefix` collision or an out-of-range `toolResultInlineMaxChars`, left the store locked: every later `create()` on that `storePath` got `Store is locked by another process` until the process exited. It also left running what it had started, the liveness watchdog among it, which could then kill a process that carried on after the failure. Now the framework it had begun is stopped as `stop()` stops one (its modules, MCPL servers, event gate, tune-out coordinator and watchdog), and a store it opened from `storePath` is closed. A store passed in as `store` stays open. + - The caller of a failed `create()` has no framework to give `stop()` a deadline, so `create()` waits at most 30 s for each part of the release, where `stop()`'s default has no deadline. A module whose `stop()` never settles would otherwise turn a failed boot that exits into one that hangs. + - When the release fails or doesn't finish within that time, `create()` rejects with an `AggregateError` holding its own error first and then the release's. Its message begins `AgentFramework.create() failed:` and says that part of what it started may still be running. The store is closed even then. When the release finishes cleanly, `create()`'s own error is rethrown unchanged. diff --git a/src/framework.ts b/src/framework.ts index 81b0c2d40..780f2d342 100644 --- a/src/framework.ts +++ b/src/framework.ts @@ -1027,6 +1027,12 @@ const WITHHELD_SPILL_DEADLINE_MS = 30_000; const DEFAULT_MAINTENANCE_INTERVAL_MS = 5000; /** Bound one pass so a large backlog yields to inference and other agents. */ const MAINTENANCE_TICKS_PER_PASS = 8; +/** How long a failed create() waits for each part of its release, as stop()'s + * teardownTimeoutMs. stop() leaves its deadline to its caller, who owns the + * framework, but the caller of a failed create() never got one: unbounded, a + * module whose stop() never settles would turn a failed boot that exits into + * one that hangs. */ +const FAILED_CREATE_TEARDOWN_TIMEOUT_MS = 30_000; /** Local per-residence provider admission (AF #114 bounded first slice). */ interface LocalProviderGate { @@ -2107,7 +2113,11 @@ export class AgentFramework { } /** - * Create and start the framework. + * Create and start the framework. A create() that fails releases what it + * had acquired before its error reaches the caller, so that the caller can + * try again in the same process: the framework it had begun is stopped, as + * stop() stops one but waiting at most 30 s for each part, and a store it + * opened is closed. A store the caller passed in is left open. */ static async create(config: FrameworkConfig): Promise { // Before anything opens or starts: a refused config must leave nothing behind. @@ -2127,6 +2137,52 @@ export class AgentFramework { throw new Error('Either storePath or store must be provided'); } + const building: { framework?: AgentFramework } = {}; + try { + return await AgentFramework.createOn(store, ownsStore, config, building); + } catch (error) { + throw await AgentFramework.releaseFailedCreate(error, building.framework, store, ownsStore); + } + } + + /** + * The error a failed create() rejects with, once what it acquired is + * released: the framework it had begun is stopped, within + * FAILED_CREATE_TEARDOWN_TIMEOUT_MS, and a store create() opened is closed, + * even where part of that stop failed or didn't finish. stop() then keeps + * its store open, so that it can be called again, but no one can call it on + * a framework that create() never returned. When the release doesn't finish + * cleanly, the rejection carries create()'s error and then the release's, + * and says that part of what it started may still be running. + */ + private static async releaseFailedCreate( + error: unknown, + framework: AgentFramework | undefined, + store: JsStore, + ownsStore: boolean, + ): Promise { + const failures: unknown[] = []; + if (framework) { + try { await framework.stop(FAILED_CREATE_TEARDOWN_TIMEOUT_MS); } catch (stopError) { failures.push(stopError); } + } + if (ownsStore && !store.isClosed()) { + try { store.close(); } catch (closeError) { failures.push(closeError); } + } + if (failures.length === 0) return error; + return new AggregateError([error, ...failures], + `AgentFramework.create() failed: ${shutdownErrorMessage(error)}. Releasing what it had started ` + + `didn't finish cleanly, so part of it may still be running: ${failures.map(shutdownErrorMessage).join('; ')}`); + } + + /** create()'s work once it holds its store. The framework is named in + * `building` as soon as it exists, so that create() can stop it if a later + * step fails. */ + private static async createOn( + store: JsStore, + ownsStore: boolean, + config: FrameworkConfig, + building: { framework?: AgentFramework }, + ): Promise { // Register framework states try { store.registerState({ id: FRAMEWORK_STATE_ID, strategy: 'snapshot' }); @@ -2201,7 +2257,7 @@ export class AgentFramework { ); } - const framework = new AgentFramework( + const framework = building.framework = new AgentFramework( store, ownsStore, config.membrane, diff --git a/test/failed-create-releases.test.ts b/test/failed-create-releases.test.ts new file mode 100644 index 000000000..acdc5f24d --- /dev/null +++ b/test/failed-create-releases.test.ts @@ -0,0 +1,168 @@ +/** + * A create() that fails releases what it had acquired before its error reaches + * the caller, so the caller can retry it in the same process (#389). + */ +import { test } from 'node:test'; +import assert from 'node:assert/strict'; +import { spawn } from 'node:child_process'; +import { mkdtempSync, rmSync, writeFileSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import { pathToFileURL } from 'node:url'; +import { JsStore } from '@animalabs/chronicle'; +import { AgentFramework, type Module } from '../src/index.js'; +import { MockMembrane } from './helpers/mock-membrane.js'; + +function recordingModule(name: string, stop: () => Promise = async () => {}) { + const calls: string[] = []; + const module: Module = { + name, + async start() { calls.push('start'); }, + async stop() { calls.push('stop'); await stop(); }, + async onProcess() { return {}; }, + getTools: () => [], + async handleToolCall() { throw new Error('No tool calls expected'); }, + }; + return { module, calls }; +} + +function tempDir(t: import('node:test').TestContext): string { + const dir = mkdtempSync(join(tmpdir(), 'failed-create-')); + t.after(() => rmSync(dir, { recursive: true, force: true })); + return dir; +} + +function baseConfig(storePath: string) { + return { storePath, membrane: new MockMembrane().asMembrane(), agents: [], modules: [] as Module[], + syncIntervalMs: 0, maintenanceIntervalMs: 0 }; +} + +// Two servers on one prefix: refused after the modules have started, before +// any MCPL server is spawned (the reproduction in #389). +const COLLIDING_SERVERS = [ + { id: 'first', command: process.execPath, args: ['-e', ''], toolPrefix: 'shared' }, + { id: 'second', command: process.execPath, args: ['-e', ''], toolPrefix: 'shared' }, +]; + +test('a create() refused after its modules started stops them and frees its store', async t => { + const storePath = join(tempDir(t), 'store'); + const { module, calls } = recordingModule('started'); + await assert.rejects( + AgentFramework.create({ ...baseConfig(storePath), modules: [module], mcplServers: COLLIDING_SERVERS }), + /toolPrefix "shared" collides with server "first"/, + ); + assert.deepEqual(calls, ['start', 'stop']); + const retried = await AgentFramework.create(baseConfig(storePath)); + await retried.stop(); +}); + +test('a create() refused before the framework is built frees its store', async t => { + const storePath = join(tempDir(t), 'store'); + await assert.rejects( + AgentFramework.create({ ...baseConfig(storePath), timeZone: 'Not/AZone' }), + /Invalid IANA time zone/, + ); + const retried = await AgentFramework.create(baseConfig(storePath)); + await retried.stop(); +}); + +test('a failed create() leaves a store the caller owns open, and stops what it started', async t => { + const dir = mkdtempSync(join(tmpdir(), 'failed-create-')); + const store = JsStore.openOrCreate({ path: join(dir, 'store') }); + t.after(() => { try { store.close(); } finally { rmSync(dir, { recursive: true, force: true }); } }); + const { module, calls } = recordingModule('started'); + const { storePath: _unused, ...config } = baseConfig(''); + await assert.rejects( + AgentFramework.create({ ...config, store, modules: [module], mcplServers: COLLIDING_SERVERS }), + /collides with server "first"/, + ); + assert.deepEqual(calls, ['start', 'stop']); + assert.equal(store.isClosed(), false); + await assert.rejects( + AgentFramework.create({ ...config, store, timeZone: 'Not/AZone' }), + /Invalid IANA time zone/, + ); + assert.equal(store.isClosed(), false); + const retried = await AgentFramework.create({ ...config, store }); + await retried.stop(); +}); + +test('a failed create() whose teardown also fails reports both, and still frees its store', async t => { + const storePath = join(tempDir(t), 'store'); + const { module } = recordingModule('stuck', async () => { throw new Error('the socket would not close'); }); + await assert.rejects( + AgentFramework.create({ ...baseConfig(storePath), modules: [module], mcplServers: COLLIDING_SERVERS }), + (error: unknown) => { + assert.ok(error instanceof AggregateError, `expected an AggregateError, got ${String(error)}`); + assert.match(error.message, /^AgentFramework\.create\(\) failed: MCPL server "second" toolPrefix "shared" collides with server "first"/); + assert.match(error.message, /the socket would not close/); + assert.match(String((error.errors[0] as Error).message), /collides with server "first"/); + return true; + }, + ); + const retried = await AgentFramework.create(baseConfig(storePath)); + await retried.stop(); +}); + +test('a failed create() waits at most 30 s for its release, then says the release did not finish', async t => { + const storePath = join(tempDir(t), 'store'); + let release!: () => void; + const stopping = new Promise(done => { release = done; }); + t.after(() => release()); + const { module, calls } = recordingModule('hung', () => stopping); + t.mock.timers.enable({ apis: ['setTimeout'] }); + let settled = false; + const rejection = AgentFramework.create({ ...baseConfig(storePath), modules: [module], mcplServers: COLLIDING_SERVERS }) + .then(() => assert.fail('create() should fail'), (error: unknown) => error) + .finally(() => { settled = true; }); + // The module's stop() is called once the release's deadline is armed. + for (let turns = 0; !calls.includes('stop'); turns++) { + assert.ok(turns < 1000, 'the release never reached the module'); + await new Promise(done => setImmediate(done)); + } + t.mock.timers.tick(29_999); + await new Promise(done => setImmediate(done)); + assert.equal(settled, false); + t.mock.timers.tick(1); + for (let turns = 0; !settled; turns++) { + assert.ok(turns < 1000, 'create() still waits on its release after 30 s'); + await new Promise(done => setImmediate(done)); + } + const error = await rejection; + assert.ok(error instanceof AggregateError, `expected an AggregateError, got ${String(error)}`); + assert.match(error.message, /^AgentFramework\.create\(\) failed: MCPL server "second" toolPrefix "shared" collides with server "first"\. Releasing what it had started didn't finish cleanly, so part of it may still be running: Shutdown timed out after 30000 ms; pending: module:hung$/); + t.mock.timers.reset(); + const retried = await AgentFramework.create(baseConfig(storePath)); + await retried.stop(); +}); + +// The watchdog's worker kills the whole process once the main thread stops +// beating for its threshold. One a failed create() left running would kill a +// process that carried on after the failure. +test('a failed create() leaves no liveness watchdog to kill the process later', async t => { + const dir = tempDir(t); + const script = join(dir, 'child.mjs'); + const index = pathToFileURL(join(import.meta.dirname, '../src/index.js')).href; + const membrane = pathToFileURL(join(import.meta.dirname, 'helpers/mock-membrane.js')).href; + writeFileSync(script, ` + import { AgentFramework } from ${JSON.stringify(index)}; + import { MockMembrane } from ${JSON.stringify(membrane)}; + const failed = await AgentFramework.create({ + storePath: ${JSON.stringify(join(dir, 'store'))}, membrane: new MockMembrane().asMembrane(), + agents: [], modules: [], syncIntervalMs: 0, maintenanceIntervalMs: 0, + watchdog: { enabled: true, thresholdMs: 2000, action: 'exit' }, + toolResultInlineMaxChars: 1, + }).then(() => false, () => true); + if (!failed) process.exit(3); + await new Promise(done => setTimeout(done, 200)); + const end = Date.now() + 5000; + while (Date.now() < end) {} + process.exit(0); + `); + const { code, signal } = await new Promise<{ code: number | null; signal: string | null }>(resolve => { + const child = spawn(process.execPath, [script], { stdio: 'ignore' }); + const safety = setTimeout(() => child.kill('SIGTERM'), 20_000); + child.on('exit', (code, signal) => { clearTimeout(safety); resolve({ code, signal }); }); + }); + assert.deepEqual({ code, signal }, { code: 0, signal: null }); +}); From c7302a3ccf2536753158da9be3da1da6aeef26c0 Mon Sep 17 00:00:00 2001 From: Pippa-2697 Date: Fri, 16 Oct 2026 16:40:24 -0400 Subject: [PATCH 2/4] fix(create): the internal review's round on a failed create()'s release (#389) From the review af389-failed-create (wf-1931, 20 issues, judged at 5a81605b): - initializeMcpl's two failure catches no longer close the MCPL servers themselves (I2, I19). They ran inside createOn(), before the release, with no deadline, and a closeAll() that rejected there replaced create()'s own error. create()'s release now closes every server through stop(), within FAILED_CREATE_TEARDOWN_TIMEOUT_MS, with create()'s error first. On connectMcplServer's lazy path the registry is new and empty when the barrier runs, so nothing there changes. - The rejection's message says what didn't finish (I14): a stop that failed or ran out of time says part of what create() started may still be running; a close that failed says the store may still be locked. - The docs, the changelog and the constant's comment name the waits the 30 s covers, stop()'s waits on operator operations and on modules and MCPL servers, instead of "each part of the release" (I1, I12), and say exactly when stop() keeps an owned store open (I15). Tests, in test/failed-create-releases.test.ts: - a clean release rejects with create()'s own error, unwrapped and with its exact message (I7); - a module whose start() throws: every module started is stopped, that one included, and a retry works (I5); - a create() that fails at the MCPL startup barrier after its server connected: create()'s own error, the child process gone, a retry works (I3; the awareness-barrier fixture with an injected reconcile failure); - a store whose close() fails during a release whose stop() also failed: the AggregateError carries all three, create()'s first (I11); - the watchdog test checks the watchdog's "armed" line and the refusal's message in the child's output, written to a file (I4). Not fixed here, as judged: stop()'s synchronous steps before its watchdog stop (I6) and its not waiting for Discord awareness drains (I10) are stop()'s on every path, for a change of its own. Co-Authored-By: Claude Opus 5.5 --- .../389-failed-create-releases.fixed.md | 6 +- src/framework.ts | 67 +++++--- test/failed-create-releases.test.ts | 154 +++++++++++++++--- 3 files changed, 174 insertions(+), 53 deletions(-) diff --git a/changelog.d/389-failed-create-releases.fixed.md b/changelog.d/389-failed-create-releases.fixed.md index 707592645..67dda15f7 100644 --- a/changelog.d/389-failed-create-releases.fixed.md +++ b/changelog.d/389-failed-create-releases.fixed.md @@ -1,3 +1,3 @@ -- A failed `AgentFramework.create()` now releases what it had acquired before its error reaches the caller, so the same process can call `create()` again (#389). Before, a `create()` that failed after opening its store, such as on an invalid `timeZone`, an MCPL `toolPrefix` collision or an out-of-range `toolResultInlineMaxChars`, left the store locked: every later `create()` on that `storePath` got `Store is locked by another process` until the process exited. It also left running what it had started, the liveness watchdog among it, which could then kill a process that carried on after the failure. Now the framework it had begun is stopped as `stop()` stops one (its modules, MCPL servers, event gate, tune-out coordinator and watchdog), and a store it opened from `storePath` is closed. A store passed in as `store` stays open. - - The caller of a failed `create()` has no framework to give `stop()` a deadline, so `create()` waits at most 30 s for each part of the release, where `stop()`'s default has no deadline. A module whose `stop()` never settles would otherwise turn a failed boot that exits into one that hangs. - - When the release fails or doesn't finish within that time, `create()` rejects with an `AggregateError` holding its own error first and then the release's. Its message begins `AgentFramework.create() failed:` and says that part of what it started may still be running. The store is closed even then. When the release finishes cleanly, `create()`'s own error is rethrown unchanged. +- A failed `AgentFramework.create()` now releases what it had acquired before its error reaches the caller, so the same process can call `create()` again (#389). Before, a `create()` that failed after opening its store, such as on an invalid `timeZone`, an MCPL `toolPrefix` collision, a module whose `start()` threw or an out-of-range `toolResultInlineMaxChars`, left the store locked: every later `create()` on that `storePath` got `Store is locked by another process` until the process exited. It also left running what it had started, the liveness watchdog among it, which could then kill a process that carried on after the failure. Now the framework it had begun is stopped as `stop()` stops one (its modules, MCPL servers, event gate, tune-out coordinator and watchdog), and a store it opened from `storePath` is closed. A store passed in as `store` stays open. + - The caller of a failed `create()` has no framework to give `stop()` a deadline, so `create()` gives it one: it waits at most 30 s for its modules and MCPL servers to stop, where `stop()`'s default waits with no deadline. A module whose `stop()` never settles would otherwise turn a failed boot that exits into one that hangs. + - When stopping them fails or runs out of time, or closing the store fails, `create()` rejects with an `AggregateError` holding its own error first and then those failures. Its message begins `AgentFramework.create() failed:` and says what didn't finish: that part of what it started may still be running, or that its store may still be locked. It closes a store it opened even when stopping failed. When the release finishes cleanly, `create()`'s own error is rethrown unchanged, as before. diff --git a/src/framework.ts b/src/framework.ts index 780f2d342..40db0f8db 100644 --- a/src/framework.ts +++ b/src/framework.ts @@ -1027,11 +1027,14 @@ const WITHHELD_SPILL_DEADLINE_MS = 30_000; const DEFAULT_MAINTENANCE_INTERVAL_MS = 5000; /** Bound one pass so a large backlog yields to inference and other agents. */ const MAINTENANCE_TICKS_PER_PASS = 8; -/** How long a failed create() waits for each part of its release, as stop()'s - * teardownTimeoutMs. stop() leaves its deadline to its caller, who owns the +/** The teardownTimeoutMs a failed create() gives stop(): how long each of its + * cleanup waits, on operator operations and then on modules and MCPL servers + * together, may take. stop() leaves its deadline to its caller, who owns the * framework, but the caller of a failed create() never got one: unbounded, a * module whose stop() never settles would turn a failed boot that exits into - * one that hangs. */ + * one that hangs. stop()'s other waits are on streams, the event loop, + * maintenance and guard annotations, which a framework create() never + * started has none of. */ const FAILED_CREATE_TEARDOWN_TIMEOUT_MS = 30_000; /** Local per-residence provider admission (AF #114 bounded first slice). */ @@ -2116,8 +2119,9 @@ export class AgentFramework { * Create and start the framework. A create() that fails releases what it * had acquired before its error reaches the caller, so that the caller can * try again in the same process: the framework it had begun is stopped, as - * stop() stops one but waiting at most 30 s for each part, and a store it - * opened is closed. A store the caller passed in is left open. + * stop() stops one, but giving up on its modules' and MCPL servers' stops + * after 30 s, and a store it opened is closed. A store the caller passed in + * is left open. */ static async create(config: FrameworkConfig): Promise { // Before anything opens or starts: a refused config must leave nothing behind. @@ -2147,13 +2151,14 @@ export class AgentFramework { /** * The error a failed create() rejects with, once what it acquired is - * released: the framework it had begun is stopped, within - * FAILED_CREATE_TEARDOWN_TIMEOUT_MS, and a store create() opened is closed, - * even where part of that stop failed or didn't finish. stop() then keeps - * its store open, so that it can be called again, but no one can call it on - * a framework that create() never returned. When the release doesn't finish - * cleanly, the rejection carries create()'s error and then the release's, - * and says that part of what it started may still be running. + * released: the framework it had begun is stopped, with + * FAILED_CREATE_TEARDOWN_TIMEOUT_MS as stop()'s teardownTimeoutMs, and a + * store create() opened is closed even when that stop failed or timed out. + * stop() keeps an owned store open when its waits on operator operations, + * modules or MCPL servers fail or time out, so that it can be called again, + * but no one can call it on a framework that create() never returned. When + * the release doesn't finish cleanly, the rejection carries create()'s error + * and then the release's, and its message says what didn't finish. */ private static async releaseFailedCreate( error: unknown, @@ -2162,16 +2167,27 @@ export class AgentFramework { ownsStore: boolean, ): Promise { const failures: unknown[] = []; + const unfinished: string[] = []; if (framework) { - try { await framework.stop(FAILED_CREATE_TEARDOWN_TIMEOUT_MS); } catch (stopError) { failures.push(stopError); } + try { + await framework.stop(FAILED_CREATE_TEARDOWN_TIMEOUT_MS); + } catch (stopError) { + failures.push(stopError); + unfinished.push('Stopping what it had started didn\'t finish, so part of it may still be running: ' + + shutdownErrorMessage(stopError)); + } } if (ownsStore && !store.isClosed()) { - try { store.close(); } catch (closeError) { failures.push(closeError); } + try { + store.close(); + } catch (closeError) { + failures.push(closeError); + unfinished.push('Closing its store failed, so the store may still be locked: ' + shutdownErrorMessage(closeError)); + } } if (failures.length === 0) return error; return new AggregateError([error, ...failures], - `AgentFramework.create() failed: ${shutdownErrorMessage(error)}. Releasing what it had started ` + - `didn't finish cleanly, so part of it may still be running: ${failures.map(shutdownErrorMessage).join('; ')}`); + `AgentFramework.create() failed: ${shutdownErrorMessage(error)}. ${unfinished.join('. ')}`); } /** create()'s work once it holds its store. The framework is named in @@ -16419,10 +16435,9 @@ export class AgentFramework { // awareness generation. await this.connectMcplServerInternal(config, true); } catch (error) { - if (error instanceof DiscordAwarenessAccountingError) { - await this.mcplServerRegistry.closeAll(); - throw error; - } + // An accounting failure ends startup. create()'s release closes every + // server connected so far, within its deadline. + if (error instanceof DiscordAwarenessAccountingError) throw error; // Fail-open: log and continue with remaining servers const err = error instanceof Error ? error : new Error(String(error)); console.error(`Failed to connect MCPL server "${config.id}": ${err.message}${withStderr(err)}`); @@ -16445,15 +16460,13 @@ export class AgentFramework { // Start the durable drain only after all startup connections are staged. // The awareness tools/call is written before control-plane registration is // flushed, preserving the server-side queue -> registration -> call order. + // A barrier that fails ends startup the same way, and create()'s release + // closes the servers. (A lazy initialization from connectMcplServer has + // connected none yet.) const startupBarrier = this.installMcplDataPlaneGate(); this.releaseMcplDataPlaneGate(startupBarrier); - try { - await startupBarrier.promise; - this.completeMcplDataPlaneGate(startupBarrier); - } catch (error) { - await this.mcplServerRegistry.closeAll(); - throw error; - } + await startupBarrier.promise; + this.completeMcplDataPlaneGate(startupBarrier); // Discover tools from all connected servers await this.refreshMcplTools(); diff --git a/test/failed-create-releases.test.ts b/test/failed-create-releases.test.ts index acdc5f24d..306b5104b 100644 --- a/test/failed-create-releases.test.ts +++ b/test/failed-create-releases.test.ts @@ -5,19 +5,20 @@ import { test } from 'node:test'; import assert from 'node:assert/strict'; import { spawn } from 'node:child_process'; -import { mkdtempSync, rmSync, writeFileSync } from 'node:fs'; +import { closeSync, mkdtempSync, openSync, readFileSync, rmSync, writeFileSync } from 'node:fs'; import { tmpdir } from 'node:os'; import { join } from 'node:path'; -import { pathToFileURL } from 'node:url'; +import { fileURLToPath, pathToFileURL } from 'node:url'; import { JsStore } from '@animalabs/chronicle'; import { AgentFramework, type Module } from '../src/index.js'; +import { DiscordAwarenessOutbox } from '../src/recovery/discord-awareness-outbox.js'; import { MockMembrane } from './helpers/mock-membrane.js'; -function recordingModule(name: string, stop: () => Promise = async () => {}) { +function recordingModule(name: string, stop: () => Promise = async () => {}, start: () => Promise = async () => {}) { const calls: string[] = []; const module: Module = { name, - async start() { calls.push('start'); }, + async start() { calls.push('start'); await start(); }, async stop() { calls.push('stop'); await stop(); }, async onProcess() { return {}; }, getTools: () => [], @@ -37,30 +38,100 @@ function baseConfig(storePath: string) { syncIntervalMs: 0, maintenanceIntervalMs: 0 }; } +/** A release that finished cleanly rejects with create()'s own error, unwrapped. */ +function rejectsWithItsOwnError(creating: Promise, message: string | RegExp) { + return assert.rejects(creating, (error: unknown) => { + assert.ok(error instanceof Error && !(error instanceof AggregateError), `expected create()'s own error, got ${String(error)}`); + if (typeof message === 'string') assert.equal(error.message, message); + else assert.match(error.message, message); + return true; + }); +} + // Two servers on one prefix: refused after the modules have started, before // any MCPL server is spawned (the reproduction in #389). const COLLIDING_SERVERS = [ { id: 'first', command: process.execPath, args: ['-e', ''], toolPrefix: 'shared' }, { id: 'second', command: process.execPath, args: ['-e', ''], toolPrefix: 'shared' }, ]; +const COLLISION = 'MCPL server "second" toolPrefix "shared" collides with server "first"'; test('a create() refused after its modules started stops them and frees its store', async t => { const storePath = join(tempDir(t), 'store'); const { module, calls } = recordingModule('started'); - await assert.rejects( + await rejectsWithItsOwnError( AgentFramework.create({ ...baseConfig(storePath), modules: [module], mcplServers: COLLIDING_SERVERS }), - /toolPrefix "shared" collides with server "first"/, + COLLISION, ); assert.deepEqual(calls, ['start', 'stop']); const retried = await AgentFramework.create(baseConfig(storePath)); await retried.stop(); }); +test('a create() whose module fails to start stops every module it started, that one included', async t => { + const storePath = join(tempDir(t), 'store'); + const first = recordingModule('first'); + const failing = recordingModule('failing', undefined, async () => { throw new Error('the port is taken'); }); + await rejectsWithItsOwnError( + AgentFramework.create({ ...baseConfig(storePath), modules: [first.module, failing.module] }), + 'the port is taken', + ); + assert.deepEqual(first.calls, ['start', 'stop']); + assert.deepEqual(failing.calls, ['start', 'stop']); + const retried = await AgentFramework.create(baseConfig(storePath)); + await retried.stop(); +}); + +test('a create() that fails after its MCPL server connected closes the server and frees its store', async t => { + const dir = tempDir(t); + const outboxPath = join(dir, 'awareness.json'); + // A pending Discord awareness batch makes startup run the awareness barrier + // after the server connects; its second reconciliation fails. + const outbox = new DiscordAwarenessOutbox(outboxPath); + const batch = outbox.prepare({ agentName: 'assistant', sourceBranch: 'source', targetBranch: 'main', + activationPolicy: 'explicit', + refs: [{ serverId: 'discord', channelId: 'discord:guild:startup', messageId: 'message-1' }] }); + assert.ok(batch); + outbox.activate(batch.id); + const config = { + ...baseConfig(join(dir, 'store')), + agents: [{ name: 'assistant', model: 'test', systemPrompt: 'test' }], + discordAwarenessOutboxPath: outboxPath, + discordAwarenessDeadlineMs: 1_000, + mcplServers: [{ + id: 'discord', command: process.execPath, + args: [fileURLToPath(new URL('./fixtures/awareness-barrier-mcpl-server.mjs', import.meta.url))], + requestTimeoutMs: 1_000, enabledFeatureSets: ['chat'], + env: { STATUS_PATH: join(dir, 'status.jsonl'), LEDGER_PATH: outboxPath }, + }], + }; + const children = () => process.getActiveResourcesInfo().filter(resource => resource === 'ProcessWrap').length; + const before = children(); + const reconcile = DiscordAwarenessOutbox.prototype.reconcileForBranch; + let reconciliations = 0; + const injected = t.mock.method(DiscordAwarenessOutbox.prototype, 'reconcileForBranch', + function (this: DiscordAwarenessOutbox, ...args: Parameters) { + if (++reconciliations === 2) throw new Error('injected reconcile failure'); + return reconcile.apply(this, args); + }); + await rejectsWithItsOwnError(AgentFramework.create(config), + /^Discord awareness accounting failed during .*: injected reconcile failure$/); + injected.mock.restore(); + assert.match(readFileSync(join(dir, 'status.jsonl'), 'utf8'), /"event":"initialized"/, + 'the MCPL server had finished its handshake before the failure'); + for (let waits = 0; children() > before; waits++) { + assert.ok(waits < 200, 'the MCPL server is still running after create() rejected'); + await new Promise(done => setTimeout(done, 10)); + } + const retried = await AgentFramework.create(config); + await retried.stop(); +}); + test('a create() refused before the framework is built frees its store', async t => { const storePath = join(tempDir(t), 'store'); - await assert.rejects( + await rejectsWithItsOwnError( AgentFramework.create({ ...baseConfig(storePath), timeZone: 'Not/AZone' }), - /Invalid IANA time zone/, + 'Invalid IANA time zone: "Not/AZone"', ); const retried = await AgentFramework.create(baseConfig(storePath)); await retried.stop(); @@ -72,31 +143,59 @@ test('a failed create() leaves a store the caller owns open, and stops what it s t.after(() => { try { store.close(); } finally { rmSync(dir, { recursive: true, force: true }); } }); const { module, calls } = recordingModule('started'); const { storePath: _unused, ...config } = baseConfig(''); - await assert.rejects( + await rejectsWithItsOwnError( AgentFramework.create({ ...config, store, modules: [module], mcplServers: COLLIDING_SERVERS }), - /collides with server "first"/, + COLLISION, ); assert.deepEqual(calls, ['start', 'stop']); assert.equal(store.isClosed(), false); - await assert.rejects( + await rejectsWithItsOwnError( AgentFramework.create({ ...config, store, timeZone: 'Not/AZone' }), - /Invalid IANA time zone/, + 'Invalid IANA time zone: "Not/AZone"', ); assert.equal(store.isClosed(), false); const retried = await AgentFramework.create({ ...config, store }); await retried.stop(); }); -test('a failed create() whose teardown also fails reports both, and still frees its store', async t => { +test('a failed create() whose module fails to stop reports both, and still frees its store', async t => { + const storePath = join(tempDir(t), 'store'); + const { module } = recordingModule('stuck', async () => { throw new Error('the socket would not close'); }); + await assert.rejects( + AgentFramework.create({ ...baseConfig(storePath), modules: [module], mcplServers: COLLIDING_SERVERS }), + (error: unknown) => { + assert.ok(error instanceof AggregateError, `expected an AggregateError, got ${String(error)}`); + assert.equal(error.message, `AgentFramework.create() failed: ${COLLISION}. Stopping what it had started ` + + `didn't finish, so part of it may still be running: the socket would not close`); + assert.equal((error.errors[0] as Error).message, COLLISION); + assert.equal(error.errors.length, 2); + return true; + }, + ); + const retried = await AgentFramework.create(baseConfig(storePath)); + await retried.stop(); +}); + +test('a failed create() whose store fails to close says so, after its own error', async t => { const storePath = join(tempDir(t), 'store'); const { module } = recordingModule('stuck', async () => { throw new Error('the socket would not close'); }); + // The store does close, so the retry below can open it; close() then reports + // a failure, as a close whose final sync fails would. + const close = JsStore.prototype.close; + const failing = t.mock.method(JsStore.prototype, 'close', function (this: JsStore) { + failing.mock.restore(); + close.call(this); + throw new Error('the final sync failed'); + }); await assert.rejects( AgentFramework.create({ ...baseConfig(storePath), modules: [module], mcplServers: COLLIDING_SERVERS }), (error: unknown) => { assert.ok(error instanceof AggregateError, `expected an AggregateError, got ${String(error)}`); - assert.match(error.message, /^AgentFramework\.create\(\) failed: MCPL server "second" toolPrefix "shared" collides with server "first"/); - assert.match(error.message, /the socket would not close/); - assert.match(String((error.errors[0] as Error).message), /collides with server "first"/); + assert.equal(error.message, `AgentFramework.create() failed: ${COLLISION}. Stopping what it had started ` + + `didn't finish, so part of it may still be running: the socket would not close. Closing its store ` + + `failed, so the store may still be locked: the final sync failed`); + assert.deepEqual(error.errors.map(e => (e as Error).message), + [COLLISION, 'the socket would not close', 'the final sync failed']); return true; }, ); @@ -104,7 +203,7 @@ test('a failed create() whose teardown also fails reports both, and still frees await retried.stop(); }); -test('a failed create() waits at most 30 s for its release, then says the release did not finish', async t => { +test('a failed create() gives up on a module\'s stop after 30 s, and says what did not finish', async t => { const storePath = join(tempDir(t), 'store'); let release!: () => void; const stopping = new Promise(done => { release = done; }); @@ -130,7 +229,8 @@ test('a failed create() waits at most 30 s for its release, then says the releas } const error = await rejection; assert.ok(error instanceof AggregateError, `expected an AggregateError, got ${String(error)}`); - assert.match(error.message, /^AgentFramework\.create\(\) failed: MCPL server "second" toolPrefix "shared" collides with server "first"\. Releasing what it had started didn't finish cleanly, so part of it may still be running: Shutdown timed out after 30000 ms; pending: module:hung$/); + assert.equal(error.message, `AgentFramework.create() failed: ${COLLISION}. Stopping what it had started ` + + `didn't finish, so part of it may still be running: Shutdown timed out after 30000 ms; pending: module:hung`); t.mock.timers.reset(); const retried = await AgentFramework.create(baseConfig(storePath)); await retried.stop(); @@ -139,7 +239,7 @@ test('a failed create() waits at most 30 s for its release, then says the releas // The watchdog's worker kills the whole process once the main thread stops // beating for its threshold. One a failed create() left running would kill a // process that carried on after the failure. -test('a failed create() leaves no liveness watchdog to kill the process later', async t => { +test('a create() refused after it started the watchdog leaves none to kill the process later', async t => { const dir = tempDir(t); const script = join(dir, 'child.mjs'); const index = pathToFileURL(join(import.meta.dirname, '../src/index.js')).href; @@ -147,22 +247,30 @@ test('a failed create() leaves no liveness watchdog to kill the process later', writeFileSync(script, ` import { AgentFramework } from ${JSON.stringify(index)}; import { MockMembrane } from ${JSON.stringify(membrane)}; - const failed = await AgentFramework.create({ + const refusal = await AgentFramework.create({ storePath: ${JSON.stringify(join(dir, 'store'))}, membrane: new MockMembrane().asMembrane(), agents: [], modules: [], syncIntervalMs: 0, maintenanceIntervalMs: 0, watchdog: { enabled: true, thresholdMs: 2000, action: 'exit' }, toolResultInlineMaxChars: 1, - }).then(() => false, () => true); - if (!failed) process.exit(3); + }).then(() => 'none', error => error.message); + console.error('refused: ' + refusal); await new Promise(done => setTimeout(done, 200)); const end = Date.now() + 5000; while (Date.now() < end) {} process.exit(0); `); + // A file, not a pipe: writes to it are synchronous on every platform, so a + // killed child's lines are all there. + const logPath = join(dir, 'child.log'); + const log = openSync(logPath, 'w'); const { code, signal } = await new Promise<{ code: number | null; signal: string | null }>(resolve => { - const child = spawn(process.execPath, [script], { stdio: 'ignore' }); + const child = spawn(process.execPath, [script], { stdio: ['ignore', log, log] }); const safety = setTimeout(() => child.kill('SIGTERM'), 20_000); child.on('exit', (code, signal) => { clearTimeout(safety); resolve({ code, signal }); }); }); + closeSync(log); + const output = readFileSync(logPath, 'utf8'); + assert.match(output, /\[liveness-watchdog\] armed/, 'the watchdog started before the refusal'); + assert.match(output, /refused: FrameworkConfig\.toolResultInlineMaxChars must be a number >= 1000/); assert.deepEqual({ code, signal }, { code: 0, signal: null }); }); From 955a374c22d3f79642277084010586b510fbc01c Mon Sep 17 00:00:00 2001 From: Pippa-2697 Date: Sat, 17 Oct 2026 00:39:27 -0400 Subject: [PATCH 3/4] fix(create): the internal review's second round on a failed create()'s release (#389) The second internal review of the release (af389-failed-create-r1) found: - A stop that fails only after everything it waits on has stopped, in a guard's storage work, its final sync or closing the store, was reported as "Stopping what it had started didn't finish, so part of it may still be running", though everything it waits on had stopped then, as stop() counts it. stop() now records whether its teardown finished (stopFinishedTeardown), and the release then says "What it had started stopped, but finishing the stop failed". A new test has stop()'s own store close fail after a clean teardown. - create()'s doc and the changelog said only the modules' and MCPL servers' stops get 30 s. stop() gives the deadline to each of its two cleanup waits, its wait for an operator's operations already running first, so both now name both waits. - The MCPL test judged the server's exit by a process-wide count of child handles, for about 2 s. It now waits on the server's own process, by the pid the fixture records with its handshake, for up to 10 s. - A comment in connectMcplServerInternal still said an awareness accounting error goes to initializeMcpl, which tears down the other servers and aborts create(). That branch runs only for a runtime connect or restart, and since the first round initializeMcpl tears nothing down. It now says where the error goes. Co-Authored-By: Claude Opus 5.5 --- .../389-failed-create-releases.fixed.md | 4 +- src/framework.ts | 32 ++++++++++---- test/failed-create-releases.test.ts | 43 ++++++++++++++++--- .../awareness-barrier-mcpl-server.mjs | 2 +- 4 files changed, 64 insertions(+), 17 deletions(-) diff --git a/changelog.d/389-failed-create-releases.fixed.md b/changelog.d/389-failed-create-releases.fixed.md index 67dda15f7..8faa7bca7 100644 --- a/changelog.d/389-failed-create-releases.fixed.md +++ b/changelog.d/389-failed-create-releases.fixed.md @@ -1,3 +1,3 @@ - A failed `AgentFramework.create()` now releases what it had acquired before its error reaches the caller, so the same process can call `create()` again (#389). Before, a `create()` that failed after opening its store, such as on an invalid `timeZone`, an MCPL `toolPrefix` collision, a module whose `start()` threw or an out-of-range `toolResultInlineMaxChars`, left the store locked: every later `create()` on that `storePath` got `Store is locked by another process` until the process exited. It also left running what it had started, the liveness watchdog among it, which could then kill a process that carried on after the failure. Now the framework it had begun is stopped as `stop()` stops one (its modules, MCPL servers, event gate, tune-out coordinator and watchdog), and a store it opened from `storePath` is closed. A store passed in as `store` stays open. - - The caller of a failed `create()` has no framework to give `stop()` a deadline, so `create()` gives it one: it waits at most 30 s for its modules and MCPL servers to stop, where `stop()`'s default waits with no deadline. A module whose `stop()` never settles would otherwise turn a failed boot that exits into one that hangs. - - When stopping them fails or runs out of time, or closing the store fails, `create()` rejects with an `AggregateError` holding its own error first and then those failures. Its message begins `AgentFramework.create() failed:` and says what didn't finish: that part of what it started may still be running, or that its store may still be locked. It closes a store it opened even when stopping failed. When the release finishes cleanly, `create()`'s own error is rethrown unchanged, as before. + - The caller of a failed `create()` has no framework to give `stop()` a deadline, so `create()` gives it one: it gives up after 30 s on each of `stop()`'s two cleanup waits, for an operator's operations already running and then for its modules and MCPL servers to stop, where `stop()`'s default waits with no deadline. A module whose `stop()` never settles would otherwise turn a failed boot that exits into one that hangs. + - When stopping them fails or runs out of time, or closing the store fails, `create()` rejects with an `AggregateError` holding its own error first and then those failures. Its message begins `AgentFramework.create() failed:` and says what didn't finish: that part of what it started may still be running, that stopping failed only after everything it started had stopped, or that its store may still be locked. It closes a store it opened even when stopping failed. When the release finishes cleanly, `create()`'s own error is rethrown unchanged, as before. diff --git a/src/framework.ts b/src/framework.ts index 40db0f8db..e397a16ee 100644 --- a/src/framework.ts +++ b/src/framework.ts @@ -1611,6 +1611,11 @@ export class AgentFramework { private stopPromise: Promise | null = null; private stopCompleted = false; private ownedStoreClosed = false; + /** Whether the latest stop() stopped in time everything it waits on with + * its deadline (an operator's operations, modules and MCPL servers), + * whatever failed after that. create()'s release reads it to say whether + * part of what a failed create() started may still be running. */ + private stopFinishedTeardown = false; /** An operator's operations in flight, and the config materializations they * start. stop() waits until this set is empty before it tears down, unless * its wait budget runs out. */ @@ -2119,9 +2124,10 @@ export class AgentFramework { * Create and start the framework. A create() that fails releases what it * had acquired before its error reaches the caller, so that the caller can * try again in the same process: the framework it had begun is stopped, as - * stop() stops one, but giving up on its modules' and MCPL servers' stops - * after 30 s, and a store it opened is closed. A store the caller passed in - * is left open. + * stop() stops one, but giving up after 30 s on each of stop()'s two cleanup + * waits, for an operator's operations already running and then for its + * modules and MCPL servers, and a store it opened is closed. A store the + * caller passed in is left open. */ static async create(config: FrameworkConfig): Promise { // Before anything opens or starts: a refused config must leave nothing behind. @@ -2173,8 +2179,14 @@ export class AgentFramework { await framework.stop(FAILED_CREATE_TEARDOWN_TIMEOUT_MS); } catch (stopError) { failures.push(stopError); - unfinished.push('Stopping what it had started didn\'t finish, so part of it may still be running: ' + - shutdownErrorMessage(stopError)); + // A stop can fail after everything it waits on has stopped, as stop() + // counts it (an MCPL server once its transport has sent the kill): + // finishing a guard's storage work, in its final sync, or closing the + // store. The message then doesn't say part of it may still be running. + unfinished.push(framework.stopFinishedTeardown + ? 'What it had started stopped, but finishing the stop failed: ' + shutdownErrorMessage(stopError) + : 'Stopping what it had started didn\'t finish, so part of it may still be running: ' + + shutdownErrorMessage(stopError)); } } if (ownsStore && !store.isClosed()) { @@ -2756,6 +2768,7 @@ export class AgentFramework { } private async stopOwned(teardownTimeoutMs: number | undefined): Promise { + this.stopFinishedTeardown = false; this.pushCoalescer?.suspend(); this.flushCoalescingSnapshot(); this.running = false; @@ -2878,6 +2891,7 @@ export class AgentFramework { } const teardownSucceeded = shutdownErrors.length === 0; + this.stopFinishedTeardown = teardownSucceeded; // Those later annotations write nothing, so they finish at once; let them // record and edit their stubs before the store closes. @@ -16949,13 +16963,15 @@ export class AgentFramework { try { await awarenessBarrier.promise; } catch (error) { - // Startup cannot fail open on a broken awareness ledger. Disable the + // A connect cannot fail open on a broken awareness ledger. Disable the // reconnecting stub/connection before propagating the distinct error to - // initializeMcpl, which tears down any other servers and aborts create(). + // the runtime connect or restart that asked for it. (A startup connect + // defers awareness and returns before this gate; a startup that fails + // ends in create()'s release, which closes its servers.) // Ordering matters: awareness accounting settles BEFORE the §5.3 // policy round-trip below, so an accounting failure aborts with the // grant still empty and every buffered event still behind the gate — - // a failed startup never reports a released data plane. (The reverse + // a failed connect never reports a released data plane. (The reverse // order let a push arrive during the policy await and get flushed by // teardown.) await connection.close().catch(() => {}); diff --git a/test/failed-create-releases.test.ts b/test/failed-create-releases.test.ts index 306b5104b..4e380f3fd 100644 --- a/test/failed-create-releases.test.ts +++ b/test/failed-create-releases.test.ts @@ -105,8 +105,6 @@ test('a create() that fails after its MCPL server connected closes the server an env: { STATUS_PATH: join(dir, 'status.jsonl'), LEDGER_PATH: outboxPath }, }], }; - const children = () => process.getActiveResourcesInfo().filter(resource => resource === 'ProcessWrap').length; - const before = children(); const reconcile = DiscordAwarenessOutbox.prototype.reconcileForBranch; let reconciliations = 0; const injected = t.mock.method(DiscordAwarenessOutbox.prototype, 'reconcileForBranch', @@ -117,10 +115,18 @@ test('a create() that fails after its MCPL server connected closes the server an await rejectsWithItsOwnError(AgentFramework.create(config), /^Discord awareness accounting failed during .*: injected reconcile failure$/); injected.mock.restore(); - assert.match(readFileSync(join(dir, 'status.jsonl'), 'utf8'), /"event":"initialized"/, - 'the MCPL server had finished its handshake before the failure'); - for (let waits = 0; children() > before; waits++) { - assert.ok(waits < 200, 'the MCPL server is still running after create() rejected'); + const initialized = readFileSync(join(dir, 'status.jsonl'), 'utf8').split('\n').filter(Boolean) + .map(line => JSON.parse(line) as { event: string; pid?: number }) + .find(record => record.event === 'initialized'); + assert.ok(initialized?.pid, 'the MCPL server had finished its handshake before the failure'); + // Wait on that child itself, with room for a loaded machine: only a child + // still running after 10 s fails this. + const running = (pid: number) => { + try { process.kill(pid, 0); return true; } + catch (error) { return (error as NodeJS.ErrnoException).code === 'EPERM'; } + }; + for (let waits = 0; running(initialized.pid); waits++) { + assert.ok(waits < 1000, 'the MCPL server is still running after create() rejected'); await new Promise(done => setTimeout(done, 10)); } const retried = await AgentFramework.create(config); @@ -203,6 +209,31 @@ test('a failed create() whose store fails to close says so, after its own error' await retried.stop(); }); +test('a failed create() whose stop fails only at the end says nothing it started is still running', async t => { + const storePath = join(tempDir(t), 'store'); + const { module, calls } = recordingModule('clean'); + // Once everything it waits on has stopped, stop() closes the store itself. + // That close fails without closing, as a close whose final sync fails before + // the handle goes would, and the release's own close then succeeds. + const failing = t.mock.method(JsStore.prototype, 'close', function (this: JsStore) { + failing.mock.restore(); + throw new Error('the final sync failed'); + }); + await assert.rejects( + AgentFramework.create({ ...baseConfig(storePath), modules: [module], mcplServers: COLLIDING_SERVERS }), + (error: unknown) => { + assert.ok(error instanceof AggregateError, `expected an AggregateError, got ${String(error)}`); + assert.equal(error.message, `AgentFramework.create() failed: ${COLLISION}. What it had started stopped, ` + + `but finishing the stop failed: the final sync failed`); + assert.deepEqual(error.errors.map(e => (e as Error).message), [COLLISION, 'the final sync failed']); + return true; + }, + ); + assert.deepEqual(calls, ['start', 'stop']); + const retried = await AgentFramework.create(baseConfig(storePath)); + await retried.stop(); +}); + test('a failed create() gives up on a module\'s stop after 30 s, and says what did not finish', async t => { const storePath = join(tempDir(t), 'store'); let release!: () => void; diff --git a/test/fixtures/awareness-barrier-mcpl-server.mjs b/test/fixtures/awareness-barrier-mcpl-server.mjs index f8789d22d..b83fff1a5 100644 --- a/test/fixtures/awareness-barrier-mcpl-server.mjs +++ b/test/fixtures/awareness-barrier-mcpl-server.mjs @@ -161,7 +161,7 @@ function sendDataRequest(id, phase) { function beginServerTraffic() { if (initialized) return; initialized = true; - log('initialized'); + log('initialized', { pid: process.pid }); request(200, 'channels/register', { channels: [channel('startup')] }); // The reconnect generation carries an inference-bearing event in the same // registration window. Initial-start tests use generation 1 as well. From a7a69206526f2dd5faed861e78b334071d73be4f Mon Sep 17 00:00:00 2001 From: Pippa-2697 Date: Sat, 17 Oct 2026 01:33:34 -0400 Subject: [PATCH 4/4] fix(create): a failed restart leaves the workspace's saved pins as they were (#389) Greptile's review of #426 found that the release this PR adds reaches a module's stop() at a point no stop() reached before: after the module's start(), but before the host has the framework, so before anything the host wires up after create() returns. WorkspaceModule is wired that way. On a restart its start() decodes the saved state and holds it until initStore() makes the mounts, and connectome-host calls initStore() only after create() returns. Its stop() saved its mounts whenever it had a context, so a create() refused after the workspace module started (a later module's start(), a toolPrefix collision) saved { mounts: {} } over modules/workspace/state. The retry then restored no pin, and materialize no longer refused a branch that had diverged from the one last materialized to disk: #72's consequence, reached by a new path. WorkspaceModule.stop() now saves only once initStore() has run and the state start() was handed has been applied (savedState is cleared then). Before that the module has made no pass or write, so it has nothing of its own to save, and the stored state stays as it was. The second term also covers an initStore() that throws after taking the store and making the mounts, before it applies the saved state (at the disk agreement's open(), say), which would otherwise leave a later stop() saving default pins over the saved ones. Module.stop()'s doc now says it is also called when a create() that started the module fails, before any of the host's wiring. The other modules found saving state in stop() (Discord's here, and connectome-host's subscription GC) restore that state at the top of start(), so they save back what they were handed. Two tests: in failed-create-releases, a session that materializes, then a restart refused after the workspace module started, after which the stored state is as the session left it; in workspace-restore-order, a restart stopped before initStore() and one stopped after an initStore() that threw at the disk agreement's open(), neither of which saves. Each fails with the guard taken out, and the second fails with only its savedState term taken out. --- .../389-failed-create-releases.fixed.md | 1 + src/modules/workspace/index.ts | 13 +++++-- src/types/module.ts | 7 +++- test/failed-create-releases.test.ts | 35 ++++++++++++++++++- test/workspace-restore-order.test.ts | 25 +++++++++++++ 5 files changed, 76 insertions(+), 5 deletions(-) diff --git a/changelog.d/389-failed-create-releases.fixed.md b/changelog.d/389-failed-create-releases.fixed.md index 8faa7bca7..0d63464b8 100644 --- a/changelog.d/389-failed-create-releases.fixed.md +++ b/changelog.d/389-failed-create-releases.fixed.md @@ -1,3 +1,4 @@ - A failed `AgentFramework.create()` now releases what it had acquired before its error reaches the caller, so the same process can call `create()` again (#389). Before, a `create()` that failed after opening its store, such as on an invalid `timeZone`, an MCPL `toolPrefix` collision, a module whose `start()` threw or an out-of-range `toolResultInlineMaxChars`, left the store locked: every later `create()` on that `storePath` got `Store is locked by another process` until the process exited. It also left running what it had started, the liveness watchdog among it, which could then kill a process that carried on after the failure. Now the framework it had begun is stopped as `stop()` stops one (its modules, MCPL servers, event gate, tune-out coordinator and watchdog), and a store it opened from `storePath` is closed. A store passed in as `store` stays open. - The caller of a failed `create()` has no framework to give `stop()` a deadline, so `create()` gives it one: it gives up after 30 s on each of `stop()`'s two cleanup waits, for an operator's operations already running and then for its modules and MCPL servers to stop, where `stop()`'s default waits with no deadline. A module whose `stop()` never settles would otherwise turn a failed boot that exits into one that hangs. - When stopping them fails or runs out of time, or closing the store fails, `create()` rejects with an `AggregateError` holding its own error first and then those failures. Its message begins `AgentFramework.create() failed:` and says what didn't finish: that part of what it started may still be running, that stopping failed only after everything it started had stopped, or that its store may still be locked. It closes a store it opened even when stopping failed. When the release finishes cleanly, `create()`'s own error is rethrown unchanged, as before. + - A `WorkspaceModule` that stops before its `initStore()` has applied the state it was handed, as one does when a `create()` that started it fails, or after an `initStore()` that threw partway, no longer saves over its stored state. Its `stop()` saved empty or default mounts there, losing the branch last materialized to disk, so on the next start `materialize` no longer refused a branch that had diverged from it. diff --git a/src/modules/workspace/index.ts b/src/modules/workspace/index.ts index 479000375..3becf2b44 100644 --- a/src/modules/workspace/index.ts +++ b/src/modules/workspace/index.ts @@ -1050,9 +1050,16 @@ export class WorkspaceModule implements Module { // the pins and watermarks as the last work left them. this.stopped = true; - // Persist state - if (this.ctx) { - const activeBranchId = this.store ? this.store.currentBranch().id : undefined; + // Persist state, once initStore() has run and the state start() was + // handed has been applied (savedState is cleared then). Before that this + // session has made no pass or write, so it has nothing to save, and the + // stored state stays as it was: saving would put empty or default mounts + // over the saved pins. A create() that fails after starting this module + // stops it before the host can call initStore() (#389), and an + // initStore() that throws after taking the store leaves the state + // unapplied. + if (this.ctx && this.store && this.savedState === null) { + const activeBranchId = this.store.currentBranch().id; const state: WorkspaceModuleState = { mounts: {}, activeBranchId }; for (const [name, mount] of this.mounts) { state.mounts[name] = { diff --git a/src/types/module.ts b/src/types/module.ts index a6fda9ed2..ca9cb3816 100644 --- a/src/types/module.ts +++ b/src/types/module.ts @@ -53,7 +53,12 @@ export interface Module { /** * Stop the module. - * Called when the framework stops or when the module is removed. + * Called when the framework stops or when the module is removed. Also called + * when a create() that started the module fails (#389): create() stops the + * framework before it rejects, so before the host has it and before anything + * a host wires up after create() returns, such as a WorkspaceModule's + * initStore(). A stop() that saves state can therefore run before that + * wiring, and shouldn't then save over state it was handed and hasn't used. */ stop(): Promise; diff --git a/test/failed-create-releases.test.ts b/test/failed-create-releases.test.ts index 4e380f3fd..7d063defc 100644 --- a/test/failed-create-releases.test.ts +++ b/test/failed-create-releases.test.ts @@ -5,12 +5,13 @@ import { test } from 'node:test'; import assert from 'node:assert/strict'; import { spawn } from 'node:child_process'; -import { closeSync, mkdtempSync, openSync, readFileSync, rmSync, writeFileSync } from 'node:fs'; +import { closeSync, mkdirSync, mkdtempSync, openSync, readFileSync, rmSync, writeFileSync } from 'node:fs'; import { tmpdir } from 'node:os'; import { join } from 'node:path'; import { fileURLToPath, pathToFileURL } from 'node:url'; import { JsStore } from '@animalabs/chronicle'; import { AgentFramework, type Module } from '../src/index.js'; +import { WorkspaceModule } from '../src/modules/workspace/index.js'; import { DiscordAwarenessOutbox } from '../src/recovery/discord-awareness-outbox.js'; import { MockMembrane } from './helpers/mock-membrane.js'; @@ -305,3 +306,35 @@ test('a create() refused after it started the watchdog leaves none to kill the p assert.match(output, /refused: FrameworkConfig\.toolResultInlineMaxChars must be a number >= 1000/); assert.deepEqual({ code, signal }, { code: 0, signal: null }); }); + +test('a failed create() on a restart leaves the workspace\'s saved pins as they were', async t => { + const dir = tempDir(t); + const storePath = join(dir, 'store'); + const mountDir = join(dir, 'mount'); + mkdirSync(mountDir); + const workspace = () => new WorkspaceModule({ mounts: [{ name: 'work', path: mountDir, mode: 'read-write', watch: 'never' }] }); + const savedState = () => { + const store = JsStore.openOrCreate({ path: storePath }); + try { return store.getStateJson('modules/workspace/state'); } finally { store.close(); } + }; + + // A session that materializes, so its stop() saves the branch it pinned. + const first = workspace(); + const framework = await AgentFramework.create({ ...baseConfig(storePath), modules: [first] }); + first.initStore(framework.getStore()); + let result = await first.handleToolCall({ id: 'w', name: 'write', input: { path: 'work/one.txt', content: 'one' } }); + assert.equal(result.success, true, `write failed: ${result.error}`); + result = await first.handleToolCall({ id: 'm', name: 'materialize', input: {} }); + assert.equal(result.success, true, `materialize failed: ${result.error}`); + await framework.stop(); + const pinned = savedState() as { mounts: { work?: { lastMaterializedBranchId?: string } } }; + assert.ok(pinned.mounts.work?.lastMaterializedBranchId, 'the session saved a pin'); + + // A restart refused after the workspace module started, so before the host + // could call its initStore(). + await rejectsWithItsOwnError( + AgentFramework.create({ ...baseConfig(storePath), modules: [workspace()], mcplServers: COLLIDING_SERVERS }), + COLLISION, + ); + assert.deepEqual(savedState(), pinned, 'the saved state is as the session left it'); +}); diff --git a/test/workspace-restore-order.test.ts b/test/workspace-restore-order.test.ts index 4cf8401a0..85c0bbf1a 100644 --- a/test/workspace-restore-order.test.ts +++ b/test/workspace-restore-order.test.ts @@ -20,6 +20,7 @@ import { tmpdir } from 'node:os'; import { join } from 'node:path'; import { JsStore } from '@animalabs/chronicle'; import { WorkspaceModule } from '../src/modules/workspace/index.js'; +import { DiskAgreement } from '../src/modules/workspace/disk-agreement.js'; import type { WorkspaceModuleState } from '../src/modules/workspace/types.js'; import type { ModuleContext } from '../src/types/module.js'; @@ -166,3 +167,27 @@ test('a fresh (non-restart) start still initializes mounts at zero', async (t) = assert.equal(status.lastMaterializedBranch, null); assert.equal(status.canMaterialize, true); }); + +test('a restart stopped before its saved state is applied leaves the stored state as it was', async (t) => { + const { store, makeModule } = setup(t); + const { saved } = await runFirstSession(store, makeModule); + const saves: unknown[] = []; + const ctx = { ...makeCtx({ isRestart: true, saved }), setState: (state: unknown) => { saves.push(state); } } as unknown as ModuleContext; + + // Stopped before initStore(), as a create() that fails after starting it + // stops it (#389). + const notWired = makeModule(); + await notWired.start(ctx); + await notWired.stop(); + + // Stopped after an initStore() that threw once it had taken the store and + // made the mounts, before it applied the saved state. + const failedInit = makeModule(); + await failedInit.start(ctx); + const open = t.mock.method(DiskAgreement.prototype, 'open', () => { throw new Error('the journal is unreadable'); }); + assert.throws(() => failedInit.initStore(store), /the journal is unreadable/); + open.mock.restore(); + await failedInit.stop(); + + assert.deepEqual(saves, [], 'neither stop saved over the stored state'); +});