From 6678692da00c65434e8fd65d585b87dac436b57a Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Tue, 4 Aug 2026 17:13:38 +0200 Subject: [PATCH 01/15] fix(ocap-kernel): report a dead run loop instead of a healthy kernel The run loop's error was logged and swallowed, so the kernel kept answering getStatus with the record it returns when healthy while nothing on the run queue was ever processed again, and every queueMessage promise hung forever. KernelQueue now records the failure, rejects the message results waiting on it, and fails later enqueueMessage calls. Kernel reports runLoop status in getStatus (without waiting for a crank that may never end) and hands the failure to a new onRunLoopFailure option. endCrank settles its waiters even if releasing savepoints throws. The daemon logs the failure and exits non-zero. Co-Authored-By: Claude Opus 5 (1M context) --- packages/kernel-cli/CHANGELOG.md | 2 + .../kernel-cli/src/commands/daemon-entry.ts | 45 ++++++ packages/kernel-node-runtime/CHANGELOG.md | 4 + .../src/kernel/make-kernel.ts | 5 + packages/ocap-kernel/CHANGELOG.md | 8 + packages/ocap-kernel/src/Kernel.test.ts | 125 ++++++++++++++- packages/ocap-kernel/src/Kernel.ts | 46 ++++-- packages/ocap-kernel/src/KernelQueue.test.ts | 145 +++++++++++++++++- packages/ocap-kernel/src/KernelQueue.ts | 77 ++++++++++ packages/ocap-kernel/src/index.ts | 1 + .../src/store/methods/crank.test.ts | 13 ++ .../ocap-kernel/src/store/methods/crank.ts | 14 +- packages/ocap-kernel/src/types.ts | 15 ++ 13 files changed, 483 insertions(+), 17 deletions(-) diff --git a/packages/kernel-cli/CHANGELOG.md b/packages/kernel-cli/CHANGELOG.md index 6d2f044716..0f86294227 100644 --- a/packages/kernel-cli/CHANGELOG.md +++ b/packages/kernel-cli/CHANGELOG.md @@ -23,6 +23,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - `kernel daemon start` refuses to start when another daemon is already listening on the same Unix socket, instead of unlinking the socket and orphaning the running process ([#952](https://github.com/MetaMask/ocap-kernel/pull/952)) - Daemon fatal-path visibility: `daemon-entry` now installs handlers for `uncaughtException`, `unhandledRejection`, `SIGHUP`, and `exit` that append a synchronous fingerprint line to `daemon.log` before terminating ([#966](https://github.com/MetaMask/ocap-kernel/pull/966)) - Without these, silent daemon deaths under `stdio: 'ignore'` (the CLI's default spawn mode) left no trace in the log; the operator saw only that the daemon was gone. Every terminating path now leaves at least one line. +- The daemon logs the failure and shuts down with a non-zero exit code when the kernel's run loop dies, instead of staying up with a socket that answers RPCs for a kernel that processes nothing ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) + - A run loop death during startup aborts `daemon start` rather than publishing a socket and pid file for a dead kernel ## [0.1.0] diff --git a/packages/kernel-cli/src/commands/daemon-entry.ts b/packages/kernel-cli/src/commands/daemon-entry.ts index 77d96b00ea..217e91493e 100644 --- a/packages/kernel-cli/src/commands/daemon-entry.ts +++ b/packages/kernel-cli/src/commands/daemon-entry.ts @@ -74,10 +74,25 @@ async function main(): Promise { process.env.OCAP_SOCKET_PATH ?? join(ocapDir, 'daemon.sock'); const dbFilename = join(ocapDir, 'kernel.sqlite'); + + // Left alone, a dead run loop leaves the daemon answering RPCs for a kernel + // that processes nothing: an outage no client can detect. Terminate instead, + // non-zero, so the failure is visible and `ocap daemon start` can recover. + // Reassigned below once there is a daemon to shut down. + let runLoopFailure: Error | undefined; + let handleRunLoopFailure = (failure: Error): void => { + runLoopFailure = failure; + logger.error( + 'Kernel run loop died during startup.', + failure.stack ?? failure.message, + ); + }; + const { kernel, kernelDatabase } = await makeKernel({ resetStorage: false, dbFilename, logger, + onRunLoopFailure: (error) => handleRunLoopFailure(error), }); const pidPath = join(ocapDir, 'daemon.pid'); @@ -101,6 +116,11 @@ async function main(): Promise { let handle: DaemonHandle; try { await kernel.initIdentity(); + if (runLoopFailure) { + throw new Error('Kernel run loop died during startup', { + cause: runLoopFailure, + }); + } await writeFile(pidPath, String(process.pid)); handle = await startDaemon({ @@ -139,6 +159,31 @@ async function main(): Promise { return shutdownPromise; } + handleRunLoopFailure = (failure: Error): void => { + if (shutdownPromise !== undefined) { + // Expected teardown, not an outage: don't fail a deliberate stop. + logger.info( + 'Kernel run loop stopped during shutdown.', + failure.stack ?? failure.message, + ); + return; + } + logger.error( + 'Kernel run loop died; shutting down the daemon.', + failure.stack ?? failure.message, + ); + process.exitCode = 1; + shutdown('run loop failure').catch((shutdownError: unknown) => { + logger.error('Shutdown after run loop failure failed.', shutdownError); + }); + }; + + // A failure recorded between the startup check and this handler still has to + // bring the daemon down. + if (runLoopFailure) { + handleRunLoopFailure(runLoopFailure); + } + process.on('SIGTERM', () => { shutdown('SIGTERM').catch(() => (process.exitCode = 1)); }); diff --git a/packages/kernel-node-runtime/CHANGELOG.md b/packages/kernel-node-runtime/CHANGELOG.md index 67ae0c9adc..5da4acc93c 100644 --- a/packages/kernel-node-runtime/CHANGELOG.md +++ b/packages/kernel-node-runtime/CHANGELOG.md @@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Added + +- Add `onRunLoopFailure` to `makeKernel`, forwarded to `Kernel.make` and called with the error that killed the kernel's run loop ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) + ### Changed - **BREAKING:** Drop `platformOptions.fetch` from `makeNodeJsVatSupervisor` ([#942](https://github.com/MetaMask/ocap-kernel/pull/942)) diff --git a/packages/kernel-node-runtime/src/kernel/make-kernel.ts b/packages/kernel-node-runtime/src/kernel/make-kernel.ts index 81e4a37e43..7ec3dd7838 100644 --- a/packages/kernel-node-runtime/src/kernel/make-kernel.ts +++ b/packages/kernel-node-runtime/src/kernel/make-kernel.ts @@ -29,6 +29,8 @@ export type MakeKernelResult = { * @param options.keySeed - Optional seed for libp2p key generation. * @param options.ioChannelFactory - Optional factory for creating IO channels. * @param options.systemSubclusters - Optional system subcluster configurations. + * @param options.onRunLoopFailure - Optional handler called if the kernel's run + * loop dies, after which the kernel must be restarted. * @returns The kernel and its database. */ export async function makeKernel({ @@ -39,6 +41,7 @@ export async function makeKernel({ keySeed, ioChannelFactory, systemSubclusters, + onRunLoopFailure, }: { workerFilePath?: string; resetStorage?: boolean; @@ -47,6 +50,7 @@ export async function makeKernel({ keySeed?: string | undefined; ioChannelFactory?: IOChannelFactory; systemSubclusters?: SystemSubclusterConfig[]; + onRunLoopFailure?: (error: Error) => void; }): Promise { const rootLogger = logger ?? new Logger('kernel-worker'); const platformServicesClient = new NodejsPlatformServices({ @@ -64,6 +68,7 @@ export async function makeKernel({ keySeed, ioChannelFactory: ioChannelFactory ?? makeIOChannelFactory(), ...(systemSubclusters ? { systemSubclusters } : {}), + ...(onRunLoopFailure ? { onRunLoopFailure } : {}), }); return { kernel, kernelDatabase }; diff --git a/packages/ocap-kernel/CHANGELOG.md b/packages/ocap-kernel/CHANGELOG.md index ed8da249c2..7eac93488e 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -9,6 +9,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added +- Report run loop health in `KernelStatus` via the new optional `runLoop` field (`{ state: 'idle' | 'running' }` or `{ state: 'failed', error }`), exported as the `RunLoopStatus` type ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Add `onRunLoopFailure` to the `Kernel.make` options, called with the error that killed the run loop so an embedder that outlives the kernel (e.g. a daemon) can exit or restart ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - Add `fetch`, `Request`, `Headers`, and `Response` to available vat endowments ([#942](https://github.com/MetaMask/ocap-kernel/pull/942)) - Add `VatConfig.network: { allowedHosts: string[] }`; requesting `'fetch'` without it rejects `initVat` - Integrate Snaps attenuated endowment factories into vat globals ([#937](https://github.com/MetaMask/ocap-kernel/pull/937)) @@ -38,6 +40,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed +- Stop reporting a healthy kernel after the run loop dies ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) + - The error that killed the run loop was logged and swallowed, so the kernel went on answering `getStatus` with the same record it returns when healthy while nothing on the run queue was ever processed again, and every `queueMessage` promise hung forever — an outage no caller could detect + - `getStatus` now reports `runLoop: { state: 'failed', error }`, and returns it without waiting for a crank that may never end + - Message results in flight when the loop dies reject with `Kernel run loop died; this message result will never be delivered` (the killing error as `cause`), and later `queueMessage` calls reject immediately instead of hanging + - `KernelQueue.run` now refuses to start a second run loop +- Settle a crank's `waitForCrank` waiters even when releasing its savepoints throws, so a database error can no longer strand `getStatus`, `stop`, `reset`, and `clearStorage` forever ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - Deserialize CapData rejections in `Kernel.queueMessage` so vat errors surface as plain `Error` objects to all callers ([#928](https://github.com/MetaMask/ocap-kernel/pull/928)) - Detect peer restart across receiver state loss so the receiving kernel no longer silently drops a restarted peer's `seq=1` messages ([#948](https://github.com/MetaMask/ocap-kernel/pull/948)) - Persist the peer's last-observed incarnation and compare it on every successful handshake; on a detected restart, clear the peer's c-list contributions and reject the promises it was deciding before the new incarnation reuses any erefs diff --git a/packages/ocap-kernel/src/Kernel.test.ts b/packages/ocap-kernel/src/Kernel.test.ts index ca1dde78b8..9a316fcd53 100644 --- a/packages/ocap-kernel/src/Kernel.test.ts +++ b/packages/ocap-kernel/src/Kernel.test.ts @@ -1,6 +1,7 @@ import { VatNotFoundError } from '@metamask/kernel-errors'; import type { KernelDatabase } from '@metamask/kernel-store'; import type { JsonRpcMessage } from '@metamask/kernel-utils'; +import { waitUntilQuiescent } from '@metamask/kernel-utils'; import { Logger } from '@metamask/logger'; import type { DuplexStream } from '@metamask/streams'; import type { Mocked, MockInstance } from 'vitest'; @@ -25,7 +26,33 @@ const mocks = vi.hoisted(() => { .fn() .mockResolvedValue({ body: '{"result":"ok"}', slots: [] }); - run = vi.fn().mockResolvedValue(undefined); + #runLoopFailure: Error | undefined; + + #rejectRunLoop: ((error: Error) => void) | undefined; + + // Like the real run loop, this settles only if the kernel dies. + run = vi.fn( + async () => + new Promise((_resolve, reject) => { + this.#rejectRunLoop = reject; + }), + ); + + /** + * Kill the run loop the way `KernelQueue.run` does for real. + * + * @param error - The error that killed the run loop. + */ + killRunLoop(error: Error): void { + this.#runLoopFailure = error; + this.#rejectRunLoop?.(error); + } + + getRunLoopStatus = vi.fn(() => + this.#runLoopFailure + ? { state: 'failed', error: this.#runLoopFailure.message } + : { state: 'running' }, + ); stop = vi.fn(); @@ -505,12 +532,52 @@ describe('Kernel', () => { expect(status).toStrictEqual({ vats: [], subclusters: [], + runLoop: { state: 'running' }, remoteComms: { state: 'disconnected', }, }); }); + it('reports the kernel as failed once the run loop dies', async () => { + const kernel = await Kernel.make( + mockPlatformServices, + mockKernelDatabase, + ); + await kernel.launchSubcluster(makeSingleVatClusterConfig()); + expect((await kernel.getStatus()).runLoop).toStrictEqual({ + state: 'running', + }); + + mocks.KernelQueue.lastInstance.killRunLoop(new Error('run loop boom')); + await waitUntilQuiescent(); + + const status = await kernel.getStatus(); + expect(status.runLoop).toStrictEqual({ + state: 'failed', + error: 'run loop boom', + }); + // The vats are still in the store, but nothing is delivering to them. + expect(status.vats).toHaveLength(1); + }); + + it('reports a failed run loop without waiting for the crank to finish', async () => { + const kernel = await Kernel.make( + mockPlatformServices, + mockKernelDatabase, + ); + const { waitForCrank } = mocks.KernelQueue.lastInstance; + // A crank that never finishes, as when the run loop died mid-crank. + waitForCrank.mockReturnValue(new Promise(() => undefined)); + mocks.KernelQueue.lastInstance.killRunLoop(new Error('run loop boom')); + await waitUntilQuiescent(); + + expect((await kernel.getStatus()).runLoop).toStrictEqual({ + state: 'failed', + error: 'run loop boom', + }); + }); + it('includes vats and subclusters in status', async () => { const kernel = await Kernel.make( mockPlatformServices, @@ -872,6 +939,62 @@ describe('Kernel', () => { }); }); + describe('run loop failure', () => { + it('logs and notifies the embedder when the run loop dies', async () => { + const logger = new Logger('test'); + const logErrorSpy = vi.spyOn(logger, 'error'); + const onRunLoopFailure = vi.fn(); + await Kernel.make(mockPlatformServices, mockKernelDatabase, { + logger, + onRunLoopFailure, + }); + const failure = new Error('run loop boom'); + + mocks.KernelQueue.lastInstance.killRunLoop(failure); + await waitUntilQuiescent(); + + expect(logErrorSpy).toHaveBeenCalledWith( + 'Run loop died; the kernel can no longer process messages and must be restarted:', + failure, + ); + expect(onRunLoopFailure).toHaveBeenCalledWith(failure); + }); + + it('wraps a non-Error run loop failure for the embedder', async () => { + const onRunLoopFailure = vi.fn(); + await Kernel.make(mockPlatformServices, mockKernelDatabase, { + onRunLoopFailure, + }); + + mocks.KernelQueue.lastInstance.killRunLoop( + 'not an error' as unknown as Error, + ); + await waitUntilQuiescent(); + + expect(onRunLoopFailure).toHaveBeenCalledWith(new Error('not an error')); + }); + + it('logs a failure handler that throws', async () => { + const logger = new Logger('test'); + const logErrorSpy = vi.spyOn(logger, 'error'); + const handlerError = new Error('handler boom'); + await Kernel.make(mockPlatformServices, mockKernelDatabase, { + logger, + onRunLoopFailure: () => { + throw handlerError; + }, + }); + + mocks.KernelQueue.lastInstance.killRunLoop(new Error('run loop boom')); + await waitUntilQuiescent(); + + expect(logErrorSpy).toHaveBeenCalledWith( + 'Run loop failure handler threw:', + handlerError, + ); + }); + }); + describe('system subcluster cleanup', () => { it('deletes orphaned system subclusters without starting their vats', async () => { const db = makeMapKernelDatabase(); diff --git a/packages/ocap-kernel/src/Kernel.ts b/packages/ocap-kernel/src/Kernel.ts index 6cff649624..9c29eebeb4 100644 --- a/packages/ocap-kernel/src/Kernel.ts +++ b/packages/ocap-kernel/src/Kernel.ts @@ -93,6 +93,8 @@ export class Kernel { /** Manages IO channel lifecycle (optional, requires factory injection) */ readonly #ioManager: IOManager | undefined; + readonly #onRunLoopFailure: ((error: Error) => void) | undefined; + /** * Construct a new kernel instance. * @@ -105,6 +107,7 @@ export class Kernel { * @param options.mnemonic - Optional BIP39 mnemonic for deriving the kernel identity. * @param options.ioChannelFactory - Optional factory for creating IO channels. * @param options.allowedGlobalNames - Optional list of allowed global names for vat endowments. + * @param options.onRunLoopFailure - Optional handler called if the run loop dies. */ // eslint-disable-next-line no-restricted-syntax private constructor( @@ -117,10 +120,12 @@ export class Kernel { mnemonic?: string | undefined; ioChannelFactory?: IOChannelFactory; allowedGlobalNames?: AllowedGlobalName[]; + onRunLoopFailure?: (error: Error) => void; } = {}, ) { this.#platformServices = platformServices; this.#kernelDatabase = kernelDatabase; + this.#onRunLoopFailure = options.onRunLoopFailure; this.#logger = options.logger ?? new Logger('ocap-kernel'); this.#kernelStore = makeKernelStore(kernelDatabase, this.#logger); if (!this.#kernelStore.isInitialized()) { @@ -234,6 +239,7 @@ export class Kernel { * @param options.ioChannelFactory - Optional factory for creating IO channels. * @param options.systemSubclusters - Optional array of system subcluster configurations. * @param options.allowedGlobalNames - Optional list of allowed global names for vat endowments. When set, only these names from the `VatSupervisor`'s configured endowments (see `createDefaultEndowments`) are available to vats. + * @param options.onRunLoopFailure - Optional handler called if the run loop dies. The kernel must be restarted after that, so an embedder that outlives it (e.g. a daemon) should use this to terminate or restart. * @returns A promise for the new kernel instance. */ static async make( @@ -247,6 +253,7 @@ export class Kernel { ioChannelFactory?: IOChannelFactory; systemSubclusters?: SystemSubclusterConfig[]; allowedGlobalNames?: AllowedGlobalName[]; + onRunLoopFailure?: (error: Error) => void; } = {}, ): Promise { const kernel = new Kernel(platformServices, kernelDatabase, options); @@ -296,18 +303,32 @@ export class Kernel { // This runs for the entire lifetime of the kernel this.#kernelQueue .run(this.#kernelRouter.deliver.bind(this.#kernelRouter)) - .catch((error) => { - this.#logger.error( - 'Run loop error (kernel may be non-functional):', - error, - ); - // Don't re-throw to avoid unhandled rejection in this long-running task - }); + .catch((error) => this.#handleRunLoopFailure(error)); // Launch new system subclusters (requires queue to be running) await this.#subclusterManager.launchNewSystemSubclusters(configs); } + /** + * Tell the embedder the kernel is finished, since it owns the decision to + * exit or restart. Deliberately not re-thrown: an unhandled rejection would + * take the process down without giving it that chance. + * + * @param error - The error that killed the run loop. + */ + #handleRunLoopFailure(error: unknown): void { + this.#logger.error( + 'Run loop died; the kernel can no longer process messages and must be restarted:', + error, + ); + const failure = error instanceof Error ? error : new Error(String(error)); + try { + this.#onRunLoopFailure?.(failure); + } catch (handlerError) { + this.#logger.error('Run loop failure handler threw:', handlerError); + } + } + /** * Provide the kernel facet, creating and registering it as a kernel service * if it doesn't already exist. @@ -631,12 +652,19 @@ export class Kernel { * Get the current kernel status, defined as the current cluster configuration * and a list of all running vats. * - * @returns A promise for the current kernel status containing vats, subclusters, and remote comms information. + * @returns A promise for the current kernel status containing run loop health, + * vats, subclusters, and remote comms information. */ async getStatus(): Promise { - await this.#kernelQueue.waitForCrank(); + const runLoop = this.#kernelQueue.getRunLoopStatus(); + // A dead kernel must still be able to report that it's dead, and the crank + // it died in may never finish. + if (runLoop.state !== 'failed') { + await this.#kernelQueue.waitForCrank(); + } const status: KernelStatus = { + runLoop, vats: this.getVats(), subclusters: this.#subclusterManager.getSubclusters(), }; diff --git a/packages/ocap-kernel/src/KernelQueue.test.ts b/packages/ocap-kernel/src/KernelQueue.test.ts index 1c7101d496..91e253f64b 100644 --- a/packages/ocap-kernel/src/KernelQueue.test.ts +++ b/packages/ocap-kernel/src/KernelQueue.test.ts @@ -66,6 +66,48 @@ describe('KernelQueue', () => { kernelQueue = new KernelQueue(kernelStore, terminateVat); }); + /** + * Make a promise kit that actually settles, for tests where the module-level + * `makePromiseKit` mock's inert kit won't do. + * + * @returns A promise and its settlement functions. + */ + const makeRealPromiseKit = (): { + promise: Promise>; + resolve: (value: CapData) => void; + reject: (reason: unknown) => void; + } => { + let settleWithValue!: (value: CapData) => void; + let settleWithReason!: (reason: unknown) => void; + const promise = new Promise>((resolve, reject) => { + settleWithValue = resolve; + settleWithReason = reject; + }); + return { + promise, + resolve: settleWithValue, + reject: settleWithReason, + }; + }; + + /** + * Run a single crank whose delivery blows up, killing the run loop. + * + * @param error - The error the delivery fails with. + */ + const killRunLoop = async (error: Error): Promise => { + (kernelStore.runQueueLength as unknown as MockInstance).mockReturnValueOnce( + 1, + ); + (kernelStore.dequeueRun as unknown as MockInstance).mockReturnValueOnce({ + type: 'send', + target: 'ko123', + message: {} as KernelMessage, + }); + const deliver = vi.fn().mockRejectedValue(error); + await expect(kernelQueue.run(deliver)).rejects.toBe(error); + }; + describe('run', () => { it('processes items from the run queue and performs cleanup', async () => { const mockItem: RunQueueItem = { @@ -153,6 +195,99 @@ describe('KernelQueue', () => { }); }); + describe('getRunLoopStatus', () => { + it('reports idle before the run loop starts', () => { + expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ state: 'idle' }); + }); + + it('reports running while the run loop is processing', async () => { + ( + kernelStore.runQueueLength as unknown as MockInstance + ).mockReturnValueOnce(1); + (kernelStore.dequeueRun as unknown as MockInstance).mockReturnValueOnce({ + type: 'send', + target: 'ko123', + message: {} as KernelMessage, + }); + // A delivery that never settles parks the loop mid-crank. + const deliver = vi.fn().mockReturnValue(new Promise(() => undefined)); + kernelQueue.run(deliver).catch(() => undefined); + await Promise.resolve(); + expect(deliver).toHaveBeenCalled(); + expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ + state: 'running', + }); + }); + + it('reports failed once the run loop dies', async () => { + await killRunLoop(new Error('crank exploded')); + expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ + state: 'failed', + error: 'crank exploded', + }); + }); + + it('reports failed for a non-Error run loop failure', async () => { + ( + kernelStore.runQueueLength as unknown as MockInstance + ).mockReturnValueOnce(1); + (kernelStore.dequeueRun as unknown as MockInstance).mockReturnValueOnce({ + type: 'send', + target: 'ko123', + message: {} as KernelMessage, + }); + const deliver = vi.fn().mockRejectedValue('not an error'); + await expect(kernelQueue.run(deliver)).rejects.toBe('not an error'); + expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ + state: 'failed', + error: 'not an error', + }); + }); + }); + + describe('run loop death', () => { + it('rejects in-flight message results', async () => { + const kit = makeRealPromiseKit(); + (makePromiseKit as unknown as MockInstance).mockReturnValueOnce(kit); + const resultPromise = kernelQueue.enqueueMessage('ko123', 'test', []); + expect(kernelQueue.subscriptions.has('kp1')).toBe(true); + + const failure = new Error('crank exploded'); + await killRunLoop(failure); + + await expect(resultPromise).rejects.toThrow( + 'Kernel run loop died; this message result will never be delivered', + ); + await expect(resultPromise).rejects.toHaveProperty('cause', failure); + expect(kernelQueue.subscriptions.size).toBe(0); + }); + + it('rejects messages queued after the run loop dies', async () => { + const failure = new Error('crank exploded'); + await killRunLoop(failure); + await expect( + kernelQueue.enqueueMessage('ko123', 'test', []), + ).rejects.toThrow('Kernel run loop died; cannot queue a message'); + expect(kernelStore.enqueueRun).not.toHaveBeenCalled(); + }); + + it('refuses to start the run loop twice', async () => { + ( + kernelStore.runQueueLength as unknown as MockInstance + ).mockReturnValueOnce(1); + (kernelStore.dequeueRun as unknown as MockInstance).mockReturnValueOnce({ + type: 'send', + target: 'ko123', + message: {} as KernelMessage, + }); + const deliver = vi.fn().mockReturnValue(new Promise(() => undefined)); + kernelQueue.run(deliver).catch(() => undefined); + await expect(kernelQueue.run(deliver)).rejects.toThrow( + 'run loop already started', + ); + }); + }); + describe('enqueueMessage', () => { it('creates a message, enqueues it, and returns a promise for the result', async () => { const target = 'ko123'; @@ -512,16 +647,22 @@ describe('KernelQueue', () => { mockItem, ); const deliver = vi.fn().mockResolvedValue({ abort: true }); + // Sample at the end of the aborted crank: the sentinel error below kills + // the run loop, which discards every subscription still waiting. + let subscribedAfterAbort: boolean | undefined; + let rejectedAfterAbort: boolean | undefined; ( kernelStore.collectGarbage as unknown as MockInstance ).mockImplementation(() => { + subscribedAfterAbort = kernelQueue.subscriptions.has('kp99'); + rejectedAfterAbort = rejectSpy.mock.calls.length > 0; throw new Error(STOP_RUN_LOOP); }); await expect(kernelQueue.run(deliver)).rejects.toThrow(STOP_RUN_LOOP); expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('start'); - expect(rejectSpy).not.toHaveBeenCalled(); + expect(rejectedAfterAbort).toBe(false); expect(resolveSpy).not.toHaveBeenCalled(); - expect(kernelQueue.subscriptions.has('kp99')).toBe(true); + expect(subscribedAfterAbort).toBe(true); }); }); diff --git a/packages/ocap-kernel/src/KernelQueue.ts b/packages/ocap-kernel/src/KernelQueue.ts index f0cba6d132..e6443aae14 100644 --- a/packages/ocap-kernel/src/KernelQueue.ts +++ b/packages/ocap-kernel/src/KernelQueue.ts @@ -10,6 +10,7 @@ import type { KRef, KernelMessage, KernelOneResolution, + RunLoopStatus, RunQueueItem, RunQueueItemNotify, RunQueueItemSend, @@ -48,6 +49,11 @@ export class KernelQueue { /** Thunk to signal run queue transition from empty to non-empty */ #wakeUpTheRunQueue: (() => void) | null; + #runLoopStarted: boolean = false; + + /** The error that killed the run loop. Once set, the queue is never drained again. */ + #runLoopFailure: Error | undefined; + /** * Construct a new KernelQueue instance. * @@ -66,11 +72,31 @@ export class KernelQueue { /** * The kernel's run loop: take an item off the run queue, deliver it, * repeat. Note that this loops forever: the returned promise never resolves. + * If it rejects, the kernel is dead — see {@link getRunLoopStatus}. * * @param deliver - A function that delivers an item to the kernel. + * @returns A promise that rejects with the error that killed the run loop. */ async run( deliver: (item: RunQueueItem) => Promise, + ): Promise { + !this.#runLoopStarted || Fail`run loop already started`; + this.#runLoopStarted = true; + try { + return await this.#runLoop(deliver); + } catch (error) { + this.#failRunLoop(error); + throw error; + } + } + + /** + * Take an item off the run queue, deliver it, repeat. + * + * @param deliver - A function that delivers an item to the kernel. + */ + async #runLoop( + deliver: (item: RunQueueItem) => Promise, ): Promise { for (;;) { let wakeUpPromise: Promise | undefined; @@ -102,6 +128,51 @@ export class KernelQueue { } } + /** + * Record the death of the run loop and fail everything that was waiting on + * it, which would otherwise hang forever. + * + * @param error - The error that killed the run loop. + */ + #failRunLoop(error: unknown): void { + const failure = error instanceof Error ? error : new Error(String(error)); + this.#runLoopFailure = failure; + + const orphaned = [...this.subscriptions.values()]; + this.subscriptions.clear(); + this.#resolvedWithKernelSubscription = []; + for (const { reject } of orphaned) { + reject( + this.#makeDeadRunLoopError( + 'Kernel run loop died; this message result will never be delivered', + ), + ); + } + } + + /** + * @param message - The message for the caller. + * @returns An error whose cause is the failure that killed the run loop. + */ + #makeDeadRunLoopError(message: string): Error { + return new Error(message, { cause: this.#runLoopFailure }); + } + + /** + * Report whether the kernel is able to process its run queue at all. + * + * @returns The current run loop status. + */ + getRunLoopStatus(): RunLoopStatus { + if (this.#runLoopFailure) { + return harden({ + state: 'failed', + error: this.#runLoopFailure.message, + }); + } + return harden({ state: this.#runLoopStarted ? 'running' : 'idle' }); + } + /** * Get the next item from the kernel run queue. * **ATTN:** Mutates the kernel store if the queue is not empty. @@ -245,6 +316,12 @@ export class KernelQueue { method: string, args: unknown[], ): Promise> { + // Nothing is draining the run queue, so a returned promise could never settle. + if (this.#runLoopFailure) { + throw this.#makeDeadRunLoopError( + 'Kernel run loop died; cannot queue a message', + ); + } // TODO(#562): Use logger instead. // eslint-disable-next-line no-console console.debug('enqueueMessage', target, method, args); diff --git a/packages/ocap-kernel/src/index.ts b/packages/ocap-kernel/src/index.ts index 33bbbcab84..ba97ea8667 100644 --- a/packages/ocap-kernel/src/index.ts +++ b/packages/ocap-kernel/src/index.ts @@ -22,6 +22,7 @@ export type { PlatformServices, VatConfig, KernelStatus, + RunLoopStatus, Subcluster, SubclusterId, SubclusterLaunchResult, diff --git a/packages/ocap-kernel/src/store/methods/crank.test.ts b/packages/ocap-kernel/src/store/methods/crank.test.ts index 421a64e8e2..f276454500 100644 --- a/packages/ocap-kernel/src/store/methods/crank.test.ts +++ b/packages/ocap-kernel/src/store/methods/crank.test.ts @@ -158,6 +158,19 @@ describe('crank methods', () => { 'endCrank outside of crank', ); }); + + it('settles the crank even if releasing savepoints fails', async () => { + crankMethods.startCrank(); + context.savepoints = ['test']; + const waiter = crankMethods.waitForCrank(); + vi.mocked(kdb.releaseSavepoint).mockImplementationOnce(() => { + throw new Error('database is gone'); + }); + expect(() => crankMethods.endCrank()).toThrow('database is gone'); + expect(context.inCrank).toBe(false); + expect(context.resolveCrank).toBeUndefined(); + expect(await waiter).toBeUndefined(); + }); }); describe('releaseAllSavepoints', () => { diff --git a/packages/ocap-kernel/src/store/methods/crank.ts b/packages/ocap-kernel/src/store/methods/crank.ts index 4cc88d8778..bdeb4dbd89 100644 --- a/packages/ocap-kernel/src/store/methods/crank.ts +++ b/packages/ocap-kernel/src/store/methods/crank.ts @@ -72,14 +72,18 @@ export function getCrankMethods(ctx: StoreContext, kdb: KernelDatabase) { } /** - * End a crank. + * End a crank. Settles even if releasing the savepoints fails, so that a + * database error can't strand every `waitForCrank()` waiter forever. */ function endCrank(): void { ctx.inCrank || Fail`endCrank outside of crank`; - releaseAllSavepoints(); - ctx.inCrank = false; - ctx.resolveCrank?.(); - ctx.resolveCrank = undefined; + try { + releaseAllSavepoints(); + } finally { + ctx.inCrank = false; + ctx.resolveCrank?.(); + ctx.resolveCrank = undefined; + } } /** diff --git a/packages/ocap-kernel/src/types.ts b/packages/ocap-kernel/src/types.ts index e5ea314b01..643f97bb7b 100644 --- a/packages/ocap-kernel/src/types.ts +++ b/packages/ocap-kernel/src/types.ts @@ -763,6 +763,18 @@ const RemoteCommsConnectedStruct = object({ listenAddresses: array(string()), }); +/** + * Whether the kernel is capable of processing its run queue. `failed` means + * nothing will ever be processed again and the kernel must be restarted. + */ +export const RunLoopStatusStruct = union([ + object({ state: literal('idle') }), + object({ state: literal('running') }), + object({ state: literal('failed'), error: string() }), +]); + +export type RunLoopStatus = Infer; + export const KernelStatusStruct = type({ subclusters: array(SubclusterStruct), vats: array( @@ -772,6 +784,9 @@ export const KernelStatusStruct = type({ subclusterId: SubclusterIdStruct, }), ), + // Optional because the RPC client validates results against this struct, and + // requiring it would fail every `getStatus` against a kernel built before it. + runLoop: exactOptional(RunLoopStatusStruct), remoteComms: exactOptional( union([ RemoteCommsDisconnectedStruct, From 4fb9ca611e040da2f54ff40ca5b347fb4d09b151 Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Tue, 4 Aug 2026 18:03:59 +0200 Subject: [PATCH 02/15] fix(ocap-kernel): roll back the crank the run loop died in Review of the previous commit found that a delivery which throws (rather than returning {abort:true}) left endCrank's savepoint release to commit the half-finished crank: the dequeued item was lost, refcounts stuck, and promises resolved mid-crank stayed resolved with their notifies unflushed. The restart that commit recommends resumed from that state. Also refuse run queue ingress (enqueueSend, enqueueNotify, resolvePromises) once the loop is dead, so a remote peer's delivery rolls back unacknowledged and it retries instead of trusting a black hole; bound the daemon's post-failure shutdown at 10s so a stalled kernel.stop() can't leave a pid file that blocks the next start; surface runLoop in the kernel panel and log it in the browser worker; keep a thrown non-Error as the wrapper's cause. Co-Authored-By: Claude Opus 5 (1M context) --- packages/kernel-browser-runtime/CHANGELOG.md | 4 + .../src/kernel-worker/kernel-worker.ts | 8 ++ packages/kernel-cli/CHANGELOG.md | 1 + .../kernel-cli/src/commands/daemon-entry.ts | 41 +++++-- packages/kernel-ui/CHANGELOG.md | 5 + packages/kernel-ui/src/App.tsx | 2 + .../src/components/RunLoopBanner.test.tsx | 86 ++++++++++++++ .../src/components/RunLoopBanner.tsx | 44 +++++++ packages/ocap-kernel/CHANGELOG.md | 6 + packages/ocap-kernel/src/Kernel.test.ts | 10 +- packages/ocap-kernel/src/Kernel.ts | 14 ++- packages/ocap-kernel/src/KernelQueue.test.ts | 108 +++++++++++++++++- packages/ocap-kernel/src/KernelQueue.ts | 93 +++++++++++---- packages/ocap-kernel/src/types.ts | 11 +- 14 files changed, 391 insertions(+), 42 deletions(-) create mode 100644 packages/kernel-ui/src/components/RunLoopBanner.test.tsx create mode 100644 packages/kernel-ui/src/components/RunLoopBanner.tsx diff --git a/packages/kernel-browser-runtime/CHANGELOG.md b/packages/kernel-browser-runtime/CHANGELOG.md index b63734215d..eab0f384be 100644 --- a/packages/kernel-browser-runtime/CHANGELOG.md +++ b/packages/kernel-browser-runtime/CHANGELOG.md @@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Added + +- Log a fatal message when the kernel's run loop dies, since the worker outlives the kernel and has no exit to take ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) + ### Fixed - Process platform-services RPC request handlers in the background so a request handler that fires a reentrant outbound RPC (e.g. transport handshake calling back into the kernel) cannot deadlock waiting for its response ([#948](https://github.com/MetaMask/ocap-kernel/pull/948)) diff --git a/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts b/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts index b5e33df321..52027a390e 100644 --- a/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts +++ b/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts @@ -64,6 +64,14 @@ async function main(): Promise { const kernelP = Kernel.make(platformServicesClient, kernelDatabase, { resetStorage, systemSubclusters, + // The worker outlives the kernel and has no exit to take, so all it can do + // is say so loudly; the panel reads `runLoop` from `getStatus` as well. + onRunLoopFailure: (error) => { + logger.error( + 'Kernel run loop died; this worker must be reloaded.', + error.stack ?? error.message, + ); + }, }); const handlerP = kernelP.then((kernel) => { diff --git a/packages/kernel-cli/CHANGELOG.md b/packages/kernel-cli/CHANGELOG.md index 0f86294227..21f796c138 100644 --- a/packages/kernel-cli/CHANGELOG.md +++ b/packages/kernel-cli/CHANGELOG.md @@ -25,6 +25,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Without these, silent daemon deaths under `stdio: 'ignore'` (the CLI's default spawn mode) left no trace in the log; the operator saw only that the daemon was gone. Every terminating path now leaves at least one line. - The daemon logs the failure and shuts down with a non-zero exit code when the kernel's run loop dies, instead of staying up with a socket that answers RPCs for a kernel that processes nothing ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - A run loop death during startup aborts `daemon start` rather than publishing a socket and pid file for a dead kernel + - That shutdown is bounded at 10 seconds, after which the pid file is removed and the process exits non-zero; a stalled `kernel.stop()` would otherwise leave a live pid file whose interlock refuses the next `daemon start` — the opposite of the recovery the exit is for ## [0.1.0] diff --git a/packages/kernel-cli/src/commands/daemon-entry.ts b/packages/kernel-cli/src/commands/daemon-entry.ts index 217e91493e..5e4231ebcb 100644 --- a/packages/kernel-cli/src/commands/daemon-entry.ts +++ b/packages/kernel-cli/src/commands/daemon-entry.ts @@ -4,13 +4,16 @@ import { startDaemon } from '@metamask/kernel-node-runtime/daemon'; import type { DaemonHandle } from '@metamask/kernel-node-runtime/daemon'; import type { LogEntry } from '@metamask/logger'; import { Logger } from '@metamask/logger'; -import { appendFileSync } from 'node:fs'; +import { appendFileSync, rmSync } from 'node:fs'; import { mkdir, readFile, rm, writeFile } from 'node:fs/promises'; import { join } from 'node:path'; import { getOcapHome } from '../ocap-home.ts'; import { isProcessAlive } from '../utils.ts'; +/** How long a post-failure shutdown may take before the process is killed. */ +const SHUTDOWN_TIMEOUT_MS = 10_000; + // Mirror of @metamask/logger's level ordering (`logLevels` is not part // of the package's public surface). Higher numbers are more severe. // Declared above the file-scope logger construction so the transport @@ -76,9 +79,10 @@ async function main(): Promise { const dbFilename = join(ocapDir, 'kernel.sqlite'); // Left alone, a dead run loop leaves the daemon answering RPCs for a kernel - // that processes nothing: an outage no client can detect. Terminate instead, - // non-zero, so the failure is visible and `ocap daemon start` can recover. - // Reassigned below once there is a daemon to shut down. + // that processes nothing — an outage only a client that reads `runLoop` in + // `getStatus` can spot. Terminate instead, non-zero, so the failure is + // visible and `ocap daemon start` can recover. + // `handleRunLoopFailure` is reassigned below once there is a daemon to close. let runLoopFailure: Error | undefined; let handleRunLoopFailure = (failure: Error): void => { runLoopFailure = failure; @@ -92,6 +96,8 @@ async function main(): Promise { resetStorage: false, dbFilename, logger, + // Indirection, not redundancy: the kernel captures this function value for + // good, so the late call is what lets the reassignment below take effect. onRunLoopFailure: (error) => handleRunLoopFailure(error), }); @@ -173,9 +179,30 @@ async function main(): Promise { failure.stack ?? failure.message, ); process.exitCode = 1; - shutdown('run loop failure').catch((shutdownError: unknown) => { - logger.error('Shutdown after run loop failure failed.', shutdownError); - }); + + // A hung shutdown would leave the socket gone but the pid file in place, + // and the interlock above then refuses the next `ocap daemon start` — the + // opposite of the recovery this exit is for. Kill the process instead, + // clearing the pid file first since `shutdown`'s cleanup won't have run. + const killTimer = setTimeout(() => { + logger.error( + `Shutdown stalled for ${SHUTDOWN_TIMEOUT_MS} ms after run loop failure; exiting now.`, + ); + try { + // eslint-disable-next-line n/no-sync -- must finish before process.exit + rmSync(pidPath, { force: true }); + } catch (rmError) { + logger.error('Could not remove the pid file before exiting.', rmError); + } + // eslint-disable-next-line n/no-process-exit -- a stalled shutdown must still terminate + process.exit(1); + }, SHUTDOWN_TIMEOUT_MS); + + shutdown('run loop failure') + .catch((shutdownError: unknown) => { + logger.error('Shutdown after run loop failure failed.', shutdownError); + }) + .finally(() => clearTimeout(killTimer)); }; // A failure recorded between the startup check and this handler still has to diff --git a/packages/kernel-ui/CHANGELOG.md b/packages/kernel-ui/CHANGELOG.md index 30e1a149e6..caac0ce0de 100644 --- a/packages/kernel-ui/CHANGELOG.md +++ b/packages/kernel-ui/CHANGELOG.md @@ -7,6 +7,11 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Added + +- Show a banner when `getStatus` reports the kernel's run loop as failed ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) + - The vat and subcluster tables keep rendering their last known contents after the kernel dies, so without this a dead kernel is indistinguishable from a healthy idle one + ## [0.5.0] ### Changed diff --git a/packages/kernel-ui/src/App.tsx b/packages/kernel-ui/src/App.tsx index c0a7c1fcac..46bfe5dfbc 100644 --- a/packages/kernel-ui/src/App.tsx +++ b/packages/kernel-ui/src/App.tsx @@ -11,6 +11,7 @@ import { DatabaseInspector } from './components/DatabaseInspector.tsx'; import { MessagePanel } from './components/MessagePanel.tsx'; import { ObjectRegistry } from './components/ObjectRegistry.tsx'; import { RemoteComms } from './components/RemoteComms.tsx'; +import { RunLoopBanner } from './components/RunLoopBanner.tsx'; import { Tabs } from './components/shared/Tabs.tsx'; import { PanelProvider } from './context/PanelContext.tsx'; import { useDarkMode } from './hooks/useDarkMode.ts'; @@ -70,6 +71,7 @@ export const App: React.FC = () => { + {tabs.find((tab) => tab.value === activeTab)?.component} diff --git a/packages/kernel-ui/src/components/RunLoopBanner.test.tsx b/packages/kernel-ui/src/components/RunLoopBanner.test.tsx new file mode 100644 index 0000000000..4ace61f8e5 --- /dev/null +++ b/packages/kernel-ui/src/components/RunLoopBanner.test.tsx @@ -0,0 +1,86 @@ +import type { KernelStatus } from '@metamask/ocap-kernel'; +import { render, screen, cleanup } from '@testing-library/react'; +import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; + +import { RunLoopBanner } from './RunLoopBanner.tsx'; +import { usePanelContext } from '../context/PanelContext.tsx'; + +vi.mock('../context/PanelContext.tsx', () => ({ + usePanelContext: vi.fn(), +})); + +const mockUsePanelContext = vi.mocked(usePanelContext); + +const makeMockPanelContext = (status: KernelStatus | undefined) => ({ + status, + callKernelMethod: vi.fn(), + logMessage: vi.fn(), + messageContent: '', + setMessageContent: vi.fn(), + panelLogs: [], + clearLogs: vi.fn(), + isLoading: false, + objectRegistry: null, + setObjectRegistry: vi.fn(), +}); + +const makeMockStatus = (runLoop: KernelStatus['runLoop']): KernelStatus => ({ + vats: [], + subclusters: [], + ...(runLoop ? { runLoop } : {}), +}); + +describe('RunLoopBanner', () => { + beforeEach(() => { + vi.clearAllMocks(); + }); + + afterEach(() => { + cleanup(); + }); + + it('announces a dead run loop with the reason it died', () => { + mockUsePanelContext.mockReturnValue( + makeMockPanelContext( + makeMockStatus({ state: 'failed', error: 'crank exploded' }), + ) as unknown as ReturnType, + ); + + render(); + + expect(screen.getByTestId('run-loop-failure')).toHaveTextContent( + 'Kernel run loop has died', + ); + expect(screen.getByTestId('run-loop-failure-error')).toHaveTextContent( + 'crank exploded', + ); + }); + + it.each([ + { name: 'running', runLoop: { state: 'running' } as const }, + { name: 'idle', runLoop: { state: 'idle' } as const }, + { name: 'absent, as on an older kernel', runLoop: undefined }, + ])('renders nothing when the run loop is $name', ({ runLoop }) => { + mockUsePanelContext.mockReturnValue( + makeMockPanelContext(makeMockStatus(runLoop)) as unknown as ReturnType< + typeof usePanelContext + >, + ); + + render(); + + expect(screen.queryByTestId('run-loop-failure')).toBeNull(); + }); + + it('renders nothing before the first status arrives', () => { + mockUsePanelContext.mockReturnValue( + makeMockPanelContext(undefined) as unknown as ReturnType< + typeof usePanelContext + >, + ); + + render(); + + expect(screen.queryByTestId('run-loop-failure')).toBeNull(); + }); +}); diff --git a/packages/kernel-ui/src/components/RunLoopBanner.tsx b/packages/kernel-ui/src/components/RunLoopBanner.tsx new file mode 100644 index 0000000000..afb6d60e86 --- /dev/null +++ b/packages/kernel-ui/src/components/RunLoopBanner.tsx @@ -0,0 +1,44 @@ +import { + Box, + Text as TextComponent, + TextColor, + TextVariant, + FontWeight, +} from '@metamask/design-system-react'; + +import { usePanelContext } from '../context/PanelContext.tsx'; + +// Announces that the kernel's run loop has died. Worth saying loudly because +// every other panel keeps rendering its last known contents, so a dead kernel +// looks identical to a healthy idle one. +export const RunLoopBanner: React.FC = () => { + const { status } = usePanelContext(); + const runLoop = status?.runLoop; + + if (runLoop?.state !== 'failed') { + return null; + } + + return ( + + + Kernel run loop has died. Nothing shown below is live and no message + will be processed until the kernel is restarted. + + + {runLoop.error} + + + ); +}; diff --git a/packages/ocap-kernel/CHANGELOG.md b/packages/ocap-kernel/CHANGELOG.md index 7eac93488e..205643d63d 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -45,6 +45,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - `getStatus` now reports `runLoop: { state: 'failed', error }`, and returns it without waiting for a crank that may never end - Message results in flight when the loop dies reject with `Kernel run loop died; this message result will never be delivered` (the killing error as `cause`), and later `queueMessage` calls reject immediately instead of hanging - `KernelQueue.run` now refuses to start a second run loop +- Roll back the crank the run loop died in, instead of committing it ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) + - A delivery that _threw_ (rather than returning `{ abort: true }`) left `endCrank`'s savepoint release to commit the half-finished crank: the item that crank had already dequeued was gone for good, refcount increments stuck, and promises resolved during it stayed resolved while their notifies died unflushed in the crank buffer — so the restart this change recommends resumed from half-applied state + - An aborted crank that then throws is not rolled back twice; if the rollback itself fails, both failures are reported together +- Refuse run queue ingress once the run loop is dead ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) + - `enqueueSend`, `enqueueNotify`, and `resolvePromises` now throw instead of appending to a queue nothing drains. This matters most for remote peers: inbound deliveries are processed inside a savepoint that rolls back without advancing the received-sequence number, so the peer retries and then gives up rather than being acknowledged by a black hole +- Preserve a thrown non-`Error` as the `cause` when wrapping it, in both the run loop failure path and the embedder notification ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - Settle a crank's `waitForCrank` waiters even when releasing its savepoints throws, so a database error can no longer strand `getStatus`, `stop`, `reset`, and `clearStorage` forever ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - Deserialize CapData rejections in `Kernel.queueMessage` so vat errors surface as plain `Error` objects to all callers ([#928](https://github.com/MetaMask/ocap-kernel/pull/928)) - Detect peer restart across receiver state loss so the receiving kernel no longer silently drops a restarted peer's `seq=1` messages ([#948](https://github.com/MetaMask/ocap-kernel/pull/948)) diff --git a/packages/ocap-kernel/src/Kernel.test.ts b/packages/ocap-kernel/src/Kernel.test.ts index 9a316fcd53..75b2c94648 100644 --- a/packages/ocap-kernel/src/Kernel.test.ts +++ b/packages/ocap-kernel/src/Kernel.test.ts @@ -39,7 +39,9 @@ const mocks = vi.hoisted(() => { ); /** - * Kill the run loop the way `KernelQueue.run` does for real. + * Fail the run loop, in the order the real `KernelQueue.run` does: the + * status flips before the rejection is observable. Does not reproduce + * `#failRunLoop`'s rejection of in-flight subscriptions. * * @param error - The error that killed the run loop. */ @@ -971,7 +973,11 @@ describe('Kernel', () => { ); await waitUntilQuiescent(); - expect(onRunLoopFailure).toHaveBeenCalledWith(new Error('not an error')); + expect(onRunLoopFailure).toHaveBeenCalledOnce(); + const [failure] = onRunLoopFailure.mock.calls[0] as [Error]; + expect(failure.message).toBe('not an error'); + // The original value survives, so a thrown non-Error isn't lost. + expect(failure.cause).toBe('not an error'); }); it('logs a failure handler that throws', async () => { diff --git a/packages/ocap-kernel/src/Kernel.ts b/packages/ocap-kernel/src/Kernel.ts index 9c29eebeb4..ca05ae76e5 100644 --- a/packages/ocap-kernel/src/Kernel.ts +++ b/packages/ocap-kernel/src/Kernel.ts @@ -321,7 +321,10 @@ export class Kernel { 'Run loop died; the kernel can no longer process messages and must be restarted:', error, ); - const failure = error instanceof Error ? error : new Error(String(error)); + const failure = + error instanceof Error + ? error + : new Error(String(error), { cause: error }); try { this.#onRunLoopFailure?.(failure); } catch (handlerError) { @@ -649,16 +652,17 @@ export class Kernel { } /** - * Get the current kernel status, defined as the current cluster configuration - * and a list of all running vats. + * Get the current kernel status: run loop health, the current cluster + * configuration, and a list of all running vats. * * @returns A promise for the current kernel status containing run loop health, * vats, subclusters, and remote comms information. */ async getStatus(): Promise { const runLoop = this.#kernelQueue.getRunLoopStatus(); - // A dead kernel must still be able to report that it's dead, and the crank - // it died in may never finish. + // A dead kernel must still be able to report that it's dead. `endCrank` + // runs in a `finally` and settles its waiters even when it throws, so this + // is belt-and-braces against a future crank that can't be waited out. if (runLoop.state !== 'failed') { await this.#kernelQueue.waitForCrank(); } diff --git a/packages/ocap-kernel/src/KernelQueue.test.ts b/packages/ocap-kernel/src/KernelQueue.test.ts index 91e253f64b..aada529ba0 100644 --- a/packages/ocap-kernel/src/KernelQueue.test.ts +++ b/packages/ocap-kernel/src/KernelQueue.test.ts @@ -67,8 +67,9 @@ describe('KernelQueue', () => { }); /** - * Make a promise kit that actually settles, for tests where the module-level - * `makePromiseKit` mock's inert kit won't do. + * Make a promise kit whose `resolve`/`reject` actually settle its promise, + * for tests where the module-level `makePromiseKit` mock's bare `vi.fn()` + * settlers won't do. * * @returns A promise and its settlement functions. */ @@ -271,6 +272,109 @@ describe('KernelQueue', () => { expect(kernelStore.enqueueRun).not.toHaveBeenCalled(); }); + it('rolls back the crank it died in', async () => { + await killRunLoop(new Error('crank exploded')); + // Without this, endCrank's savepoint release commits the half-finished + // crank and the dequeued item is lost. + expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('start'); + }); + + it('does not roll back when the savepoint was never created', async () => { + ( + kernelStore.createCrankSavepoint as unknown as MockInstance + ).mockImplementationOnce(() => { + throw new Error('database is gone'); + }); + await expect(kernelQueue.run(vi.fn())).rejects.toThrow( + 'database is gone', + ); + expect(kernelStore.rollbackCrank).not.toHaveBeenCalled(); + }); + + it('does not roll back twice when an aborted crank then throws', async () => { + (kernelStore.runQueueLength as unknown as MockInstance) + .mockReturnValueOnce(1) + .mockReturnValue(0); + (kernelStore.dequeueRun as unknown as MockInstance).mockReturnValueOnce({ + type: 'send', + target: 'ko123', + message: { result: 'kp99' } as KernelMessage, + }); + const deliver = vi.fn().mockResolvedValue({ abort: true }); + ( + kernelStore.collectGarbage as unknown as MockInstance + ).mockImplementation(() => { + throw new Error(STOP_RUN_LOOP); + }); + + // A second rollback would throw "no such savepoint" over this error. + await expect(kernelQueue.run(deliver)).rejects.toThrow(STOP_RUN_LOOP); + expect(kernelStore.rollbackCrank).toHaveBeenCalledOnce(); + }); + + it('reports both failures when the rollback also fails', async () => { + ( + kernelStore.runQueueLength as unknown as MockInstance + ).mockReturnValueOnce(1); + (kernelStore.dequeueRun as unknown as MockInstance).mockReturnValueOnce({ + type: 'send', + target: 'ko123', + message: {} as KernelMessage, + }); + const rollbackError = new Error('database is gone'); + ( + kernelStore.rollbackCrank as unknown as MockInstance + ).mockImplementationOnce(() => { + throw rollbackError; + }); + const deliver = vi.fn().mockRejectedValue(new Error('crank exploded')); + + await expect(kernelQueue.run(deliver)).rejects.toThrow( + 'Run loop died and its crank could not be rolled back: Error: crank exploded', + ); + expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ + state: 'failed', + error: + 'Run loop died and its crank could not be rolled back: Error: crank exploded', + }); + }); + + it.each([ + { + ingress: 'enqueueSend', + call: (queue: KernelQueue) => + queue.enqueueSend('ko123', { + methargs: { body: 'x', slots: [] }, + result: null, + }), + message: 'cannot enqueue a send', + }, + { + ingress: 'enqueueNotify', + call: (queue: KernelQueue) => queue.enqueueNotify('v1', 'kp1'), + message: 'cannot enqueue a notify', + }, + { + ingress: 'resolvePromises', + call: (queue: KernelQueue) => + queue.resolvePromises('v1', [ + ['kp1', false, { body: 'x', slots: [] }], + ]), + message: 'cannot resolve promises', + }, + ])( + 'rejects $ingress so remote ingress is not silently queued', + async ({ call, message }) => { + await killRunLoop(new Error('crank exploded')); + (kernelStore.enqueueRun as unknown as MockInstance).mockClear(); + (kernelStore.incrementRefCount as unknown as MockInstance).mockClear(); + + expect(() => call(kernelQueue)).toThrow(message); + expect(kernelStore.enqueueRun).not.toHaveBeenCalled(); + expect(kernelStore.incrementRefCount).not.toHaveBeenCalled(); + }, + ); + it('refuses to start the run loop twice', async () => { ( kernelStore.runQueueLength as unknown as MockInstance diff --git a/packages/ocap-kernel/src/KernelQueue.ts b/packages/ocap-kernel/src/KernelQueue.ts index e6443aae14..124dcca86f 100644 --- a/packages/ocap-kernel/src/KernelQueue.ts +++ b/packages/ocap-kernel/src/KernelQueue.ts @@ -51,9 +51,15 @@ export class KernelQueue { #runLoopStarted: boolean = false; - /** The error that killed the run loop. Once set, the queue is never drained again. */ + /** + * The error that killed the run loop. Once set, the queue is never drained + * again; note that only `enqueueMessage` refuses new work. + */ #runLoopFailure: Error | undefined; + /** Whether this crank's savepoint has already been rolled back */ + #crankRolledBack: boolean = false; + /** * Construct a new KernelQueue instance. * @@ -72,7 +78,8 @@ export class KernelQueue { /** * The kernel's run loop: take an item off the run queue, deliver it, * repeat. Note that this loops forever: the returned promise never resolves. - * If it rejects, the kernel is dead — see {@link getRunLoopStatus}. + * If it rejects with anything but `run loop already started`, the kernel is + * dead — see {@link getRunLoopStatus}. * * @param deliver - A function that delivers an item to the kernel. * @returns A promise that rejects with the error that killed the run loop. @@ -102,22 +109,44 @@ export class KernelQueue { let wakeUpPromise: Promise | undefined; this.#kernelStore.startCrank(); + this.#crankRolledBack = false; try { this.#kernelStore.createCrankSavepoint('start'); - const queueItem = this.#getNextRunQueueItem(); - if (queueItem) { - this.#kernelStore.nextTerminatedVatCleanup(); - const crankResult = await deliver(queueItem); - await this.#processCrankResult(crankResult, queueItem); - } else { - if (this.#wakeUpTheRunQueue !== null) { - Fail`run queue already waiting to be woken; cannot sleep again before the previous wake handler is consumed`; + // The savepoint exists from here on, so a throw can be undone. Without + // this, `endCrank`'s savepoint release commits the half-finished crank: + // the item this crank dequeued is gone for good, refcount increments + // stick, and promises resolved during it stay resolved while their + // notifies die unflushed. A restart would resume from that. + try { + const queueItem = this.#getNextRunQueueItem(); + if (queueItem) { + this.#kernelStore.nextTerminatedVatCleanup(); + const crankResult = await deliver(queueItem); + await this.#processCrankResult(crankResult, queueItem); + } else { + if (this.#wakeUpTheRunQueue !== null) { + Fail`run queue already waiting to be woken; cannot sleep again before the previous wake handler is consumed`; + } + + const { promise, resolve } = makePromiseKit(); + this.#wakeUpTheRunQueue = resolve; + wakeUpPromise = promise; } - - const { promise, resolve } = makePromiseKit(); - this.#wakeUpTheRunQueue = resolve; - wakeUpPromise = promise; + } catch (error) { + // An aborted crank already rolled back and released the savepoint; + // asking again would throw "no such savepoint" over the real error. + if (!this.#crankRolledBack) { + try { + this.#kernelStore.rollbackCrank('start'); + } catch (rollbackError) { + throw new Error( + `Run loop died and its crank could not be rolled back: ${String(error)}`, + { cause: rollbackError }, + ); + } + } + throw error; } } finally { this.#kernelStore.endCrank(); @@ -129,13 +158,18 @@ export class KernelQueue { } /** - * Record the death of the run loop and fail everything that was waiting on - * it, which would otherwise hang forever. + * Record the death of the run loop and fail the kernel's own message-result + * subscriptions, which would otherwise hang forever. Kernel promises in the + * store stay unresolved, so vats awaiting a notify the dead loop owed them + * are not rescued by this. * * @param error - The error that killed the run loop. */ #failRunLoop(error: unknown): void { - const failure = error instanceof Error ? error : new Error(String(error)); + const failure = + error instanceof Error + ? error + : new Error(String(error), { cause: error }); this.#runLoopFailure = failure; const orphaned = [...this.subscriptions.values()]; @@ -158,6 +192,20 @@ export class KernelQueue { return new Error(message, { cause: this.#runLoopFailure }); } + /** + * Refuse work that would otherwise sit in a queue nobody drains. Inbound + * remote deliveries are processed inside a savepoint that rolls back on a + * throw without advancing the received-sequence number, so the peer retries + * and then gives up rather than believing a black hole accepted its message. + * + * @param what - What is being refused, completing "cannot ...". + */ + #assertRunLoopAlive(what: string): void { + if (this.#runLoopFailure) { + throw this.#makeDeadRunLoopError(`Kernel run loop died; cannot ${what}`); + } + } + /** * Report whether the kernel is able to process its run queue at all. * @@ -214,6 +262,7 @@ export class KernelQueue { // For active vats, this allows the message to be retried in a future crank. // For terminated vats, the message will just go splat. this.#kernelStore.rollbackCrank('start'); + this.#crankRolledBack = true; // Discard kernel subscriptions that were queued for invocation this.#resolvedWithKernelSubscription = []; @@ -317,11 +366,7 @@ export class KernelQueue { args: unknown[], ): Promise> { // Nothing is draining the run queue, so a returned promise could never settle. - if (this.#runLoopFailure) { - throw this.#makeDeadRunLoopError( - 'Kernel run loop died; cannot queue a message', - ); - } + this.#assertRunLoopAlive('queue a message'); // TODO(#562): Use logger instead. // eslint-disable-next-line no-console console.debug('enqueueMessage', target, method, args); @@ -343,6 +388,7 @@ export class KernelQueue { * @param immediate - If true (the default), enqueue immediately; if false, buffer for crank completion. */ enqueueSend(target: KRef, message: KernelMessage, immediate = true): void { + this.#assertRunLoopAlive('enqueue a send'); this.#kernelStore.incrementRefCount(target, 'queue|target'); if (message.result) { this.#kernelStore.incrementRefCount(message.result, 'queue|result'); @@ -366,6 +412,7 @@ export class KernelQueue { * @param immediate - If true (the default), enqueue immediately; if false, buffer for crank completion. */ enqueueNotify(endpointId: EndpointId, kpid: KRef, immediate = true): void { + this.#assertRunLoopAlive('enqueue a notify'); this.#kernelStore.incrementRefCount(kpid, 'notify'); const item: RunQueueItemNotify = { type: 'notify', endpointId, kpid }; if (immediate) { @@ -402,6 +449,8 @@ export class KernelQueue { resolutions: KernelOneResolution[], immediate = true, ): void { + // Before any store mutation, so a dead kernel leaves nothing half-applied. + this.#assertRunLoopAlive('resolve promises'); for (const resolution of resolutions) { const [kpid, rejected, data] = resolution; diff --git a/packages/ocap-kernel/src/types.ts b/packages/ocap-kernel/src/types.ts index 643f97bb7b..8d16700198 100644 --- a/packages/ocap-kernel/src/types.ts +++ b/packages/ocap-kernel/src/types.ts @@ -764,8 +764,10 @@ const RemoteCommsConnectedStruct = object({ }); /** - * Whether the kernel is capable of processing its run queue. `failed` means - * nothing will ever be processed again and the kernel must be restarted. + * Whether the kernel is capable of processing its run queue. `idle` means the + * run loop was never started, not that it has nothing to do — a loop parked on + * an empty queue reports `running`. `failed` means nothing will ever be + * processed again and the kernel must be restarted. */ export const RunLoopStatusStruct = union([ object({ state: literal('idle') }), @@ -784,8 +786,9 @@ export const KernelStatusStruct = type({ subclusterId: SubclusterIdStruct, }), ), - // Optional because the RPC client validates results against this struct, and - // requiring it would fail every `getStatus` against a kernel built before it. + // Optional because this struct and `KernelStatus` are published, so a + // required key breaks external code that constructs the type. Matches + // `remoteComms` below. runLoop: exactOptional(RunLoopStatusStruct), remoteComms: exactOptional( union([ From ead5e1724f2559853b0d46bd61c8f8ed4bbd9647 Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Tue, 4 Aug 2026 18:15:53 +0200 Subject: [PATCH 03/15] fix(ocap-kernel): report run loop health sampled after the crank wait MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review found getStatus sampled the run loop status before awaiting waitForCrank, so a loop that died during that wait — the likeliest moment — was reported as running. Read it after instead. Collapse the two internal run-loop fields into one discriminated value so a failure recorded for a never-started loop is unrepresentable; name and export OnRunLoopFailure in place of four inline copies; export RunLoopStatusStruct; make the union arms type() so a client shipped against them tolerates a newer kernel adding a field; contain an async handler's rejection. Adds tests tying RunLoopStatusStruct to what getRunLoopStatus emits (they were two independent declarations of one shape, and a mismatch fails every getStatus RPC), pinning that a healthy getStatus still waits for the crank, and covering the makeKernel option passthrough via module mocking. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/kernel/make-kernel-options.test.ts | 40 +++++++++ .../src/kernel/make-kernel.ts | 3 +- packages/ocap-kernel/CHANGELOG.md | 7 +- packages/ocap-kernel/src/Kernel.test.ts | 21 +++++ packages/ocap-kernel/src/Kernel.ts | 38 +++++--- packages/ocap-kernel/src/KernelQueue.ts | 40 +++++---- packages/ocap-kernel/src/index.test.ts | 1 + packages/ocap-kernel/src/index.ts | 2 + .../src/rpc/kernel-control/get-status.test.ts | 88 +++++++++++++++++++ packages/ocap-kernel/src/types.ts | 24 +++-- 10 files changed, 227 insertions(+), 37 deletions(-) create mode 100644 packages/kernel-node-runtime/src/kernel/make-kernel-options.test.ts diff --git a/packages/kernel-node-runtime/src/kernel/make-kernel-options.test.ts b/packages/kernel-node-runtime/src/kernel/make-kernel-options.test.ts new file mode 100644 index 0000000000..de74cea999 --- /dev/null +++ b/packages/kernel-node-runtime/src/kernel/make-kernel-options.test.ts @@ -0,0 +1,40 @@ +import { Kernel } from '@metamask/ocap-kernel'; +import { describe, expect, it, vi } from 'vitest'; + +import { makeKernel } from './make-kernel.ts'; + +vi.mock('@metamask/kernel-store/sqlite/nodejs', async () => { + const { makeMapKernelDatabase } = await import( + '../../../ocap-kernel/test/storage.ts' + ); + return { + makeSQLKernelDatabase: makeMapKernelDatabase, + }; +}); + +// `harden(Kernel)` freezes the class, so `vi.spyOn(Kernel, 'make')` throws +// "Cannot redefine property". Replacing the module binding sidesteps that. +vi.mock('@metamask/ocap-kernel', async (importOriginal) => ({ + ...(await importOriginal()), + Kernel: { make: vi.fn().mockResolvedValue({}) }, +})); + +const makeMock = vi.mocked(Kernel.make); + +describe('makeKernel options', () => { + it('forwards onRunLoopFailure to the kernel', async () => { + const onRunLoopFailure = vi.fn(); + + await makeKernel({ onRunLoopFailure }); + + expect(makeMock.mock.calls[0]?.[2]).toMatchObject({ onRunLoopFailure }); + }); + + // The conditional spread that forwards the option is the shape that silently + // drops it, which would reinstate the outage the option exists to report. + it('omits onRunLoopFailure when none is given', async () => { + await makeKernel({}); + + expect(makeMock.mock.calls[0]?.[2]).not.toHaveProperty('onRunLoopFailure'); + }); +}); diff --git a/packages/kernel-node-runtime/src/kernel/make-kernel.ts b/packages/kernel-node-runtime/src/kernel/make-kernel.ts index 7ec3dd7838..4cbda735b3 100644 --- a/packages/kernel-node-runtime/src/kernel/make-kernel.ts +++ b/packages/kernel-node-runtime/src/kernel/make-kernel.ts @@ -4,6 +4,7 @@ import { Logger } from '@metamask/logger'; import { Kernel } from '@metamask/ocap-kernel'; import type { IOChannelFactory, + OnRunLoopFailure, SystemSubclusterConfig, } from '@metamask/ocap-kernel'; @@ -50,7 +51,7 @@ export async function makeKernel({ keySeed?: string | undefined; ioChannelFactory?: IOChannelFactory; systemSubclusters?: SystemSubclusterConfig[]; - onRunLoopFailure?: (error: Error) => void; + onRunLoopFailure?: OnRunLoopFailure; }): Promise { const rootLogger = logger ?? new Logger('kernel-worker'); const platformServicesClient = new NodejsPlatformServices({ diff --git a/packages/ocap-kernel/CHANGELOG.md b/packages/ocap-kernel/CHANGELOG.md index 205643d63d..0e4e0c6cd4 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -9,7 +9,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added -- Report run loop health in `KernelStatus` via the new optional `runLoop` field (`{ state: 'idle' | 'running' }` or `{ state: 'failed', error }`), exported as the `RunLoopStatus` type ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Report run loop health in `KernelStatus` via the new `runLoop` field (`{ state: 'idle' | 'running' }` or `{ state: 'failed', error }`), with `RunLoopStatus` and `RunLoopStatusStruct` exported ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) + - `runLoop` is optional in the TypeScript type so that adding it doesn't break external constructors of `KernelStatus`, but it is required on the wire: `exactOptional` only permits an absent key inside `object()`, and `KernelStatusStruct` is a `type()`. `Kernel.getStatus` always populates it + - `idle` means the run loop was never started, not that it has nothing to do; a loop parked on an empty queue reports `running` +- Export `OnRunLoopFailure` for typing a run loop failure handler ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - Add `onRunLoopFailure` to the `Kernel.make` options, called with the error that killed the run loop so an embedder that outlives the kernel (e.g. a daemon) can exit or restart ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - Add `fetch`, `Request`, `Headers`, and `Response` to available vat endowments ([#942](https://github.com/MetaMask/ocap-kernel/pull/942)) - Add `VatConfig.network: { allowedHosts: string[] }`; requesting `'fetch'` without it rejects `initVat` @@ -51,6 +54,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Refuse run queue ingress once the run loop is dead ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - `enqueueSend`, `enqueueNotify`, and `resolvePromises` now throw instead of appending to a queue nothing drains. This matters most for remote peers: inbound deliveries are processed inside a savepoint that rolls back without advancing the received-sequence number, so the peer retries and then gives up rather than being acknowledged by a black hole - Preserve a thrown non-`Error` as the `cause` when wrapping it, in both the run loop failure path and the embedder notification ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Read run loop health in `getStatus` after waiting for the crank rather than before, so a loop that dies during that wait — the likeliest moment for it to die — is not reported as `running` ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Contain a rejection from an `async` run loop failure handler, which `OnRunLoopFailure`'s `void` return type permits but only a synchronous throw was caught ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - Settle a crank's `waitForCrank` waiters even when releasing its savepoints throws, so a database error can no longer strand `getStatus`, `stop`, `reset`, and `clearStorage` forever ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - Deserialize CapData rejections in `Kernel.queueMessage` so vat errors surface as plain `Error` objects to all callers ([#928](https://github.com/MetaMask/ocap-kernel/pull/928)) - Detect peer restart across receiver state loss so the receiving kernel no longer silently drops a restarted peer's `seq=1` messages ([#948](https://github.com/MetaMask/ocap-kernel/pull/948)) diff --git a/packages/ocap-kernel/src/Kernel.test.ts b/packages/ocap-kernel/src/Kernel.test.ts index 75b2c94648..0941386062 100644 --- a/packages/ocap-kernel/src/Kernel.test.ts +++ b/packages/ocap-kernel/src/Kernel.test.ts @@ -539,6 +539,27 @@ describe('Kernel', () => { state: 'disconnected', }, }); + // A healthy status must not race an in-flight crank. + expect( + mocks.KernelQueue.lastInstance.waitForCrank, + ).toHaveBeenCalledOnce(); + }); + + it('reports a run loop that dies while waiting for the crank', async () => { + const kernel = await Kernel.make( + mockPlatformServices, + mockKernelDatabase, + ); + const queue = mocks.KernelQueue.lastInstance; + // An in-flight crank is exactly when the loop is most likely to die. + queue.waitForCrank.mockImplementationOnce(async () => { + queue.killRunLoop(new Error('died mid-crank')); + }); + + expect((await kernel.getStatus()).runLoop).toStrictEqual({ + state: 'failed', + error: 'died mid-crank', + }); }); it('reports the kernel as failed once the run loop dies', async () => { diff --git a/packages/ocap-kernel/src/Kernel.ts b/packages/ocap-kernel/src/Kernel.ts index ca05ae76e5..ed25490721 100644 --- a/packages/ocap-kernel/src/Kernel.ts +++ b/packages/ocap-kernel/src/Kernel.ts @@ -29,6 +29,7 @@ import type { ClusterConfig, VatConfig, KernelStatus, + OnRunLoopFailure, Subcluster, SubclusterLaunchResult, EndpointHandle, @@ -93,7 +94,7 @@ export class Kernel { /** Manages IO channel lifecycle (optional, requires factory injection) */ readonly #ioManager: IOManager | undefined; - readonly #onRunLoopFailure: ((error: Error) => void) | undefined; + readonly #onRunLoopFailure: OnRunLoopFailure | undefined; /** * Construct a new kernel instance. @@ -120,7 +121,7 @@ export class Kernel { mnemonic?: string | undefined; ioChannelFactory?: IOChannelFactory; allowedGlobalNames?: AllowedGlobalName[]; - onRunLoopFailure?: (error: Error) => void; + onRunLoopFailure?: OnRunLoopFailure; } = {}, ) { this.#platformServices = platformServices; @@ -253,7 +254,7 @@ export class Kernel { ioChannelFactory?: IOChannelFactory; systemSubclusters?: SystemSubclusterConfig[]; allowedGlobalNames?: AllowedGlobalName[]; - onRunLoopFailure?: (error: Error) => void; + onRunLoopFailure?: OnRunLoopFailure; } = {}, ): Promise { const kernel = new Kernel(platformServices, kernelDatabase, options); @@ -314,19 +315,30 @@ export class Kernel { * exit or restart. Deliberately not re-thrown: an unhandled rejection would * take the process down without giving it that chance. * - * @param error - The error that killed the run loop. + * @param runLoopError - The error that killed the run loop. */ - #handleRunLoopFailure(error: unknown): void { + #handleRunLoopFailure(runLoopError: unknown): void { this.#logger.error( 'Run loop died; the kernel can no longer process messages and must be restarted:', - error, + runLoopError, ); const failure = - error instanceof Error - ? error - : new Error(String(error), { cause: error }); + runLoopError instanceof Error + ? runLoopError + : new Error(String(runLoopError), { cause: runLoopError }); try { - this.#onRunLoopFailure?.(failure); + // `OnRunLoopFailure` returns void, but TypeScript admits an async + // function there, whose rejection would become the very unhandled + // rejection this method exists to avoid. Contain it either way. + const handled = this.#onRunLoopFailure?.(failure) as unknown; + if (handled instanceof Promise) { + handled.catch((handlerError: unknown) => { + this.#logger.error( + 'Run loop failure handler rejected:', + handlerError, + ); + }); + } } catch (handlerError) { this.#logger.error('Run loop failure handler threw:', handlerError); } @@ -659,13 +671,15 @@ export class Kernel { * vats, subclusters, and remote comms information. */ async getStatus(): Promise { - const runLoop = this.#kernelQueue.getRunLoopStatus(); // A dead kernel must still be able to report that it's dead. `endCrank` // runs in a `finally` and settles its waiters even when it throws, so this // is belt-and-braces against a future crank that can't be waited out. - if (runLoop.state !== 'failed') { + if (this.#kernelQueue.getRunLoopStatus().state !== 'failed') { await this.#kernelQueue.waitForCrank(); } + // Read after the wait: an in-flight crank is exactly when the loop is most + // likely to die, and a status sampled before it would report `running`. + const runLoop = this.#kernelQueue.getRunLoopStatus(); const status: KernelStatus = { runLoop, diff --git a/packages/ocap-kernel/src/KernelQueue.ts b/packages/ocap-kernel/src/KernelQueue.ts index 124dcca86f..2c78decdf1 100644 --- a/packages/ocap-kernel/src/KernelQueue.ts +++ b/packages/ocap-kernel/src/KernelQueue.ts @@ -49,13 +49,16 @@ export class KernelQueue { /** Thunk to signal run queue transition from empty to non-empty */ #wakeUpTheRunQueue: (() => void) | null; - #runLoopStarted: boolean = false; - /** - * The error that killed the run loop. Once set, the queue is never drained - * again; note that only `enqueueMessage` refuses new work. + * The run loop's state, as one value so that a failure recorded for a loop + * that never started can't be represented. `failed` keeps the whole `Error`; + * only its message crosses the wire. Once failed, the queue is never drained + * again and every ingress point refuses work. */ - #runLoopFailure: Error | undefined; + #runLoopState: + | { state: 'idle' } + | { state: 'running' } + | { state: 'failed'; error: Error } = { state: 'idle' }; /** Whether this crank's savepoint has already been rolled back */ #crankRolledBack: boolean = false; @@ -87,8 +90,8 @@ export class KernelQueue { async run( deliver: (item: RunQueueItem) => Promise, ): Promise { - !this.#runLoopStarted || Fail`run loop already started`; - this.#runLoopStarted = true; + this.#runLoopState.state === 'idle' || Fail`run loop already started`; + this.#runLoopState = { state: 'running' }; try { return await this.#runLoop(deliver); } catch (error) { @@ -170,7 +173,7 @@ export class KernelQueue { error instanceof Error ? error : new Error(String(error), { cause: error }); - this.#runLoopFailure = failure; + this.#runLoopState = { state: 'failed', error: failure }; const orphaned = [...this.subscriptions.values()]; this.subscriptions.clear(); @@ -189,7 +192,12 @@ export class KernelQueue { * @returns An error whose cause is the failure that killed the run loop. */ #makeDeadRunLoopError(message: string): Error { - return new Error(message, { cause: this.#runLoopFailure }); + return new Error(message, { + cause: + this.#runLoopState.state === 'failed' + ? this.#runLoopState.error + : undefined, + }); } /** @@ -201,7 +209,7 @@ export class KernelQueue { * @param what - What is being refused, completing "cannot ...". */ #assertRunLoopAlive(what: string): void { - if (this.#runLoopFailure) { + if (this.#runLoopState.state === 'failed') { throw this.#makeDeadRunLoopError(`Kernel run loop died; cannot ${what}`); } } @@ -212,13 +220,11 @@ export class KernelQueue { * @returns The current run loop status. */ getRunLoopStatus(): RunLoopStatus { - if (this.#runLoopFailure) { - return harden({ - state: 'failed', - error: this.#runLoopFailure.message, - }); - } - return harden({ state: this.#runLoopStarted ? 'running' : 'idle' }); + return harden( + this.#runLoopState.state === 'failed' + ? { state: 'failed', error: this.#runLoopState.error.message } + : { state: this.#runLoopState.state }, + ); } /** diff --git a/packages/ocap-kernel/src/index.test.ts b/packages/ocap-kernel/src/index.test.ts index b1bffc5be6..d0614cc21a 100644 --- a/packages/ocap-kernel/src/index.test.ts +++ b/packages/ocap-kernel/src/index.test.ts @@ -10,6 +10,7 @@ describe('index', () => { 'ClusterConfigStruct', 'Kernel', 'KernelStatusStruct', + 'RunLoopStatusStruct', 'SubclusterStruct', 'VatConfigStruct', 'VatHandle', diff --git a/packages/ocap-kernel/src/index.ts b/packages/ocap-kernel/src/index.ts index ba97ea8667..41a7e4c831 100644 --- a/packages/ocap-kernel/src/index.ts +++ b/packages/ocap-kernel/src/index.ts @@ -22,6 +22,7 @@ export type { PlatformServices, VatConfig, KernelStatus, + OnRunLoopFailure, RunLoopStatus, Subcluster, SubclusterId, @@ -53,6 +54,7 @@ export { ClusterConfigStruct, CapDataStruct, KernelStatusStruct, + RunLoopStatusStruct, SubclusterStruct, } from './types.ts'; export { AllowedGlobalNameStruct } from './vats/endowments.ts'; diff --git a/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts b/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts index 57fb559f71..072a9b3197 100644 --- a/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts +++ b/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts @@ -1,7 +1,11 @@ +import { is } from '@metamask/superstruct'; import { describe, it, expect, vi, beforeEach } from 'vitest'; import { getStatusHandler } from './get-status.ts'; import type { Kernel } from '../../Kernel.ts'; +import { KernelQueue } from '../../KernelQueue.ts'; +import type { KernelStore } from '../../store/index.ts'; +import { KernelStatusStruct } from '../../types.ts'; describe('getStatusHandler', () => { let mockKernel: Kernel; @@ -37,6 +41,90 @@ describe('getStatusHandler', () => { }); }); + // `RpcClient` validates every result against `KernelStatusStruct`, so a + // `runLoop` shape the struct rejects fails the whole getStatus call for every + // client — the outage class this field exists to report. + describe('runLoop passes result validation', () => { + const makeStatus = (runLoop: unknown) => ({ + vats: [], + subclusters: [], + remoteComms: { state: 'disconnected' }, + runLoop, + }); + + /** + * @returns A queue whose store does nothing, for reading its run loop status. + */ + const makeKernelQueue = (): { queue: KernelQueue; store: KernelStore } => { + const store = { + startCrank: vi.fn(), + endCrank: vi.fn(), + createCrankSavepoint: vi.fn(), + rollbackCrank: vi.fn(), + collectGarbage: vi.fn(), + nextReapAction: vi.fn().mockReturnValue(null), + getGCActions: vi.fn().mockReturnValue([]), + runQueueLength: vi.fn().mockReturnValue(0), + nextTerminatedVatCleanup: vi.fn(), + dequeueRun: vi.fn(), + flushCrankBuffer: vi.fn().mockReturnValue([]), + } as unknown as KernelStore; + return { queue: new KernelQueue(store, vi.fn()), store }; + }; + + it.each([ + { name: 'idle', runLoop: { state: 'idle' } }, + { name: 'running', runLoop: { state: 'running' } }, + { name: 'failed', runLoop: { state: 'failed', error: 'boom' } }, + ])('accepts $name', ({ runLoop }) => { + expect(is(makeStatus(runLoop), KernelStatusStruct)).toBe(true); + }); + + it.each([ + { name: 'an unknown state', runLoop: { state: 'wedged' } }, + { name: 'failed without an error', runLoop: { state: 'failed' } }, + { name: 'a non-string error', runLoop: { state: 'failed', error: 1 } }, + { name: 'a bare string', runLoop: 'failed' }, + ])('rejects $name', ({ runLoop }) => { + expect(is(makeStatus(runLoop), KernelStatusStruct)).toBe(false); + }); + + // `exactOptional` only permits an absent key inside `object()`, and + // `KernelStatusStruct` is a `type()`. So `runLoop` is optional in the + // TypeScript type but required on the wire, and a reply from a kernel built + // before this field fails validation outright rather than losing one field. + it('rejects a status with no runLoop at all', () => { + expect( + is( + { vats: [], subclusters: [], remoteComms: undefined }, + KernelStatusStruct, + ), + ).toBe(false); + }); + + // Ties the struct to what the queue actually emits, which are otherwise two + // independent declarations of one shape. + it('accepts what getRunLoopStatus returns before the run loop starts', () => { + const { queue } = makeKernelQueue(); + expect(is(makeStatus(queue.getRunLoopStatus()), KernelStatusStruct)).toBe( + true, + ); + }); + + it('accepts what getRunLoopStatus returns after the run loop dies', async () => { + const { queue, store } = makeKernelQueue(); + vi.mocked(store.createCrankSavepoint).mockImplementationOnce(() => { + throw new Error('boom'); + }); + + await expect(queue.run(vi.fn())).rejects.toThrow('boom'); + + expect(is(makeStatus(queue.getRunLoopStatus()), KernelStatusStruct)).toBe( + true, + ); + }); + }); + it('should propagate errors from getVats', async () => { const error = new Error('Status check failed'); vi.mocked(mockKernel.getStatus).mockRejectedValueOnce(error); diff --git a/packages/ocap-kernel/src/types.ts b/packages/ocap-kernel/src/types.ts index 8d16700198..1f698ae7a4 100644 --- a/packages/ocap-kernel/src/types.ts +++ b/packages/ocap-kernel/src/types.ts @@ -769,14 +769,24 @@ const RemoteCommsConnectedStruct = object({ * an empty queue reports `running`. `failed` means nothing will ever be * processed again and the kernel must be restarted. */ +// The arms are `type()`, not `object()`, for the same reason `runLoop` itself is +// optional below: a client shipped against these arms must tolerate a newer +// kernel adding a field, or an exact arm would fail the whole `getStatus` call. export const RunLoopStatusStruct = union([ - object({ state: literal('idle') }), - object({ state: literal('running') }), - object({ state: literal('failed'), error: string() }), + type({ state: literal('idle') }), + type({ state: literal('running') }), + type({ state: literal('failed'), error: string() }), ]); export type RunLoopStatus = Infer; +/** + * Notified when the kernel's run loop dies. Must not be async: only a + * synchronous throw can be contained, and the kernel is reporting a failure it + * cannot recover from, so there is nothing to await. + */ +export type OnRunLoopFailure = (error: Error) => void; + export const KernelStatusStruct = type({ subclusters: array(SubclusterStruct), vats: array( @@ -786,9 +796,11 @@ export const KernelStatusStruct = type({ subclusterId: SubclusterIdStruct, }), ), - // Optional because this struct and `KernelStatus` are published, so a - // required key breaks external code that constructs the type. Matches - // `remoteComms` below. + // Optional in the *type* because this struct and `KernelStatus` are + // published, so a required key breaks external code that constructs the type. + // Not optional at runtime: `exactOptional` only permits an absent key inside + // `object()`, and this is a `type()`, so validation requires the key to be + // present — same as `remoteComms`. `Kernel.getStatus` always sets both. runLoop: exactOptional(RunLoopStatusStruct), remoteComms: exactOptional( union([ From 9c9a0c0ad1b29d5e27816f9f82ac3c4477c151b7 Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Tue, 4 Aug 2026 19:02:23 +0200 Subject: [PATCH 04/15] fix(ocap-kernel): guard remote ingress at the boundary, not on the queue MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit PR review found two blockers. Guarding KernelQueue's mutators broke teardown: VatHandle.terminate and RemoteManager reject the promises a dead endpoint was deciding via resolvePromises, and terminateAllVats has no per-vat catch, so terminateAllVats and reset — the recovery actions a failed status invites — would throw and leave vats half-removed. The check now sits in RemoteHandle where remote deliveries actually enter, which still rolls back unacknowledged so the peer retries. Second blocker: the daemon's post-failure watchdog cleared its kill timer in a .finally, disarming it on the failed-shutdown path it exists for; a thrown kernel.stop() left live vat workers holding the event loop open with the pid file already removed, an orphan on kernel.sqlite invisible to both interlocks. Also: keep the original failure as the cause when a rollback fails, create a savepoint before recording its name so a failed create stops masking the real death reason, tolerate thenables in the failure handler, and drop type-defeating casts from the banner test. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/kernel-worker/kernel-worker.ts | 2 +- packages/kernel-cli/CHANGELOG.md | 2 +- .../kernel-cli/src/commands/daemon-entry.ts | 49 ++++++++---- .../src/kernel/make-kernel-options.test.ts | 1 + .../src/components/RunLoopBanner.test.tsx | 17 ++-- packages/ocap-kernel/CHANGELOG.md | 9 ++- packages/ocap-kernel/src/Kernel.ts | 4 +- packages/ocap-kernel/src/KernelQueue.test.ts | 80 ++++++++++++------- packages/ocap-kernel/src/KernelQueue.ts | 32 ++++---- .../src/remotes/kernel/RemoteHandle.test.ts | 43 ++++++++++ .../src/remotes/kernel/RemoteHandle.ts | 6 ++ .../ocap-kernel/src/store/methods/crank.ts | 5 +- packages/ocap-kernel/src/types.ts | 6 +- packages/ocap-kernel/test/remotes-mocks.ts | 1 + 14 files changed, 176 insertions(+), 81 deletions(-) diff --git a/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts b/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts index 52027a390e..229429069b 100644 --- a/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts +++ b/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts @@ -69,7 +69,7 @@ async function main(): Promise { onRunLoopFailure: (error) => { logger.error( 'Kernel run loop died; this worker must be reloaded.', - error.stack ?? error.message, + error, ); }, }); diff --git a/packages/kernel-cli/CHANGELOG.md b/packages/kernel-cli/CHANGELOG.md index 21f796c138..c6f24b854f 100644 --- a/packages/kernel-cli/CHANGELOG.md +++ b/packages/kernel-cli/CHANGELOG.md @@ -25,7 +25,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Without these, silent daemon deaths under `stdio: 'ignore'` (the CLI's default spawn mode) left no trace in the log; the operator saw only that the daemon was gone. Every terminating path now leaves at least one line. - The daemon logs the failure and shuts down with a non-zero exit code when the kernel's run loop dies, instead of staying up with a socket that answers RPCs for a kernel that processes nothing ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - A run loop death during startup aborts `daemon start` rather than publishing a socket and pid file for a dead kernel - - That shutdown is bounded at 10 seconds, after which the pid file is removed and the process exits non-zero; a stalled `kernel.stop()` would otherwise leave a live pid file whose interlock refuses the next `daemon start` — the opposite of the recovery the exit is for + - That shutdown is bounded at 10 seconds, and a shutdown that throws exits immediately, in both cases removing the pid file first. A `kernel.stop()` that hangs or throws would otherwise leave live vat workers holding the event loop open — so `process.exitCode` never takes effect — with the socket gone and the pid file already cleaned up, an orphan holding `kernel.sqlite` that neither interlock can see, letting the next `daemon start` succeed alongside it ## [0.1.0] diff --git a/packages/kernel-cli/src/commands/daemon-entry.ts b/packages/kernel-cli/src/commands/daemon-entry.ts index 5e4231ebcb..245fd2a33a 100644 --- a/packages/kernel-cli/src/commands/daemon-entry.ts +++ b/packages/kernel-cli/src/commands/daemon-entry.ts @@ -87,7 +87,7 @@ async function main(): Promise { let handleRunLoopFailure = (failure: Error): void => { runLoopFailure = failure; logger.error( - 'Kernel run loop died during startup.', + 'Kernel run loop died before shutdown handling was installed.', failure.stack ?? failure.message, ); }; @@ -180,29 +180,48 @@ async function main(): Promise { ); process.exitCode = 1; - // A hung shutdown would leave the socket gone but the pid file in place, - // and the interlock above then refuses the next `ocap daemon start` — the - // opposite of the recovery this exit is for. Kill the process instead, - // clearing the pid file first since `shutdown`'s cleanup won't have run. - const killTimer = setTimeout(() => { - logger.error( - `Shutdown stalled for ${SHUTDOWN_TIMEOUT_MS} ms after run loop failure; exiting now.`, - ); + // A shutdown that hangs or throws would leave the socket gone and the pid + // file removed by `shutdown`'s own cleanup, while live vat workers keep the + // event loop alive — an orphan holding kernel.sqlite that neither interlock + // can see, so the next `ocap daemon start` succeeds and two kernels contend + // for the database. Terminate instead. `process.exitCode` is not enough + // precisely because those worker handles keep the process running. + const exitNow = (): void => { try { // eslint-disable-next-line n/no-sync -- must finish before process.exit rmSync(pidPath, { force: true }); } catch (rmError) { logger.error('Could not remove the pid file before exiting.', rmError); } - // eslint-disable-next-line n/no-process-exit -- a stalled shutdown must still terminate + // eslint-disable-next-line n/no-process-exit -- a broken shutdown must still terminate process.exit(1); + }; + + const killTimer = setTimeout(() => { + logger.error( + `Shutdown stalled for ${SHUTDOWN_TIMEOUT_MS} ms after run loop failure; exiting now.`, + ); + exitNow(); }, SHUTDOWN_TIMEOUT_MS); - shutdown('run loop failure') - .catch((shutdownError: unknown) => { - logger.error('Shutdown after run loop failure failed.', shutdownError); - }) - .finally(() => clearTimeout(killTimer)); + // Only a *successful* shutdown disarms the watchdog. Clearing it in a + // `finally` would disarm it on the failure path it exists for. + const shutdownOrExit = async (): Promise => { + try { + await shutdown('run loop failure'); + } catch (shutdownError) { + clearTimeout(killTimer); + logger.error( + 'Shutdown after run loop failure failed; exiting now.', + shutdownError, + ); + exitNow(); + return; + } + clearTimeout(killTimer); + }; + // Nothing can escape: every path above is handled or exits. + shutdownOrExit().catch(() => undefined); }; // A failure recorded between the startup check and this handler still has to diff --git a/packages/kernel-node-runtime/src/kernel/make-kernel-options.test.ts b/packages/kernel-node-runtime/src/kernel/make-kernel-options.test.ts index de74cea999..0c031b1c23 100644 --- a/packages/kernel-node-runtime/src/kernel/make-kernel-options.test.ts +++ b/packages/kernel-node-runtime/src/kernel/make-kernel-options.test.ts @@ -35,6 +35,7 @@ describe('makeKernel options', () => { it('omits onRunLoopFailure when none is given', async () => { await makeKernel({}); + expect(makeMock).toHaveBeenCalledOnce(); expect(makeMock.mock.calls[0]?.[2]).not.toHaveProperty('onRunLoopFailure'); }); }); diff --git a/packages/kernel-ui/src/components/RunLoopBanner.test.tsx b/packages/kernel-ui/src/components/RunLoopBanner.test.tsx index 4ace61f8e5..0fae3c50cf 100644 --- a/packages/kernel-ui/src/components/RunLoopBanner.test.tsx +++ b/packages/kernel-ui/src/components/RunLoopBanner.test.tsx @@ -4,6 +4,7 @@ import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; import { RunLoopBanner } from './RunLoopBanner.tsx'; import { usePanelContext } from '../context/PanelContext.tsx'; +import type { PanelContextType } from '../context/PanelContext.tsx'; vi.mock('../context/PanelContext.tsx', () => ({ usePanelContext: vi.fn(), @@ -11,7 +12,9 @@ vi.mock('../context/PanelContext.tsx', () => ({ const mockUsePanelContext = vi.mocked(usePanelContext); -const makeMockPanelContext = (status: KernelStatus | undefined) => ({ +const makeMockPanelContext = ( + status: KernelStatus | undefined, +): PanelContextType => ({ status, callKernelMethod: vi.fn(), logMessage: vi.fn(), @@ -43,7 +46,7 @@ describe('RunLoopBanner', () => { mockUsePanelContext.mockReturnValue( makeMockPanelContext( makeMockStatus({ state: 'failed', error: 'crank exploded' }), - ) as unknown as ReturnType, + ), ); render(); @@ -62,9 +65,7 @@ describe('RunLoopBanner', () => { { name: 'absent, as on an older kernel', runLoop: undefined }, ])('renders nothing when the run loop is $name', ({ runLoop }) => { mockUsePanelContext.mockReturnValue( - makeMockPanelContext(makeMockStatus(runLoop)) as unknown as ReturnType< - typeof usePanelContext - >, + makeMockPanelContext(makeMockStatus(runLoop)), ); render(); @@ -73,11 +74,7 @@ describe('RunLoopBanner', () => { }); it('renders nothing before the first status arrives', () => { - mockUsePanelContext.mockReturnValue( - makeMockPanelContext(undefined) as unknown as ReturnType< - typeof usePanelContext - >, - ); + mockUsePanelContext.mockReturnValue(makeMockPanelContext(undefined)); render(); diff --git a/packages/ocap-kernel/CHANGELOG.md b/packages/ocap-kernel/CHANGELOG.md index 0e4e0c6cd4..a569a6efb4 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -50,9 +50,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - `KernelQueue.run` now refuses to start a second run loop - Roll back the crank the run loop died in, instead of committing it ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - A delivery that _threw_ (rather than returning `{ abort: true }`) left `endCrank`'s savepoint release to commit the half-finished crank: the item that crank had already dequeued was gone for good, refcount increments stuck, and promises resolved during it stayed resolved while their notifies died unflushed in the crank buffer — so the restart this change recommends resumed from half-applied state - - An aborted crank that then throws is not rolled back twice; if the rollback itself fails, both failures are reported together -- Refuse run queue ingress once the run loop is dead ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - - `enqueueSend`, `enqueueNotify`, and `resolvePromises` now throw instead of appending to a queue nothing drains. This matters most for remote peers: inbound deliveries are processed inside a savepoint that rolls back without advancing the received-sequence number, so the peer retries and then gives up rather than being acknowledged by a black hole + - An aborted crank that then throws is not rolled back twice; if the rollback itself fails, the error names it and keeps the original failure as its `cause` + - The rollback covers store state only. A crank that had already flushed its buffer settled JS-side subscriptions irreversibly, so a `queueMessage` caller may hold a result for a delivery the store no longer records + - `createCrankSavepoint` now records a savepoint name only once the database has actually created it, so a failed create no longer leaves `endCrank` releasing a savepoint that never existed and reporting that instead of the real failure +- Refuse inbound remote deliveries once the run loop is dead ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) + - A peer's `message` or `notify` was previously queued and acknowledged with nothing left to deliver it, so the sending kernel waited forever. `RemoteHandle` now refuses them via the new `KernelQueue.assertRunLoopAlive`, and because inbound deliveries are processed inside a savepoint that rolls back without advancing the received-sequence number, the peer retries and then gives up instead + - The check deliberately sits at that ingress boundary rather than on the queue's mutators, because teardown legitimately drains queue state after the loop is dead — `VatHandle.terminate` and `RemoteManager` reject the promises a dead endpoint was deciding, and refusing those would break `terminateAllVats` and `reset`, the very recovery actions a failed status invites - Preserve a thrown non-`Error` as the `cause` when wrapping it, in both the run loop failure path and the embedder notification ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - Read run loop health in `getStatus` after waiting for the crank rather than before, so a loop that dies during that wait — the likeliest moment for it to die — is not reported as `running` ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - Contain a rejection from an `async` run loop failure handler, which `OnRunLoopFailure`'s `void` return type permits but only a synchronous throw was caught ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) diff --git a/packages/ocap-kernel/src/Kernel.ts b/packages/ocap-kernel/src/Kernel.ts index ed25490721..29605fa7f0 100644 --- a/packages/ocap-kernel/src/Kernel.ts +++ b/packages/ocap-kernel/src/Kernel.ts @@ -331,8 +331,8 @@ export class Kernel { // function there, whose rejection would become the very unhandled // rejection this method exists to avoid. Contain it either way. const handled = this.#onRunLoopFailure?.(failure) as unknown; - if (handled instanceof Promise) { - handled.catch((handlerError: unknown) => { + if (typeof (handled as PromiseLike)?.then === 'function') { + Promise.resolve(handled).catch((handlerError: unknown) => { this.#logger.error( 'Run loop failure handler rejected:', handlerError, diff --git a/packages/ocap-kernel/src/KernelQueue.test.ts b/packages/ocap-kernel/src/KernelQueue.test.ts index aada529ba0..8f3ff510b3 100644 --- a/packages/ocap-kernel/src/KernelQueue.test.ts +++ b/packages/ocap-kernel/src/KernelQueue.test.ts @@ -327,53 +327,73 @@ describe('KernelQueue', () => { ).mockImplementationOnce(() => { throw rollbackError; }); - const deliver = vi.fn().mockRejectedValue(new Error('crank exploded')); + const crankError = new Error('crank exploded'); + const deliver = vi.fn().mockRejectedValue(crankError); - await expect(kernelQueue.run(deliver)).rejects.toThrow( - 'Run loop died and its crank could not be rolled back: Error: crank exploded', - ); + // The rollback failure names itself; the original stays the `cause`, since + // that is the root cause an operator needs. + await expect(kernelQueue.run(deliver)).rejects.toMatchObject({ + message: + 'Run loop died and its crank could not be rolled back: Error: database is gone', + cause: crankError, + }); expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ state: 'failed', error: - 'Run loop died and its crank could not be rolled back: Error: crank exploded', + 'Run loop died and its crank could not be rolled back: Error: database is gone', }); }); + it('refuses ingress via assertRunLoopAlive', async () => { + const failure = new Error('crank exploded'); + expect(() => kernelQueue.assertRunLoopAlive('accept work')).not.toThrow(); + + await killRunLoop(failure); + + expect(() => kernelQueue.assertRunLoopAlive('accept work')).toThrow( + 'Kernel run loop died; cannot accept work', + ); + // The failure that killed the loop is the root cause. + await expect(async () => + kernelQueue.assertRunLoopAlive('accept work'), + ).rejects.toHaveProperty('cause', failure); + }); + + // Teardown drains queue state rather than adding work to it, so it must + // keep working after the loop dies — `VatHandle.terminate` and + // `RemoteManager` reject the promises a dead endpoint was deciding. it.each([ { - ingress: 'enqueueSend', + teardown: 'resolvePromises', call: (queue: KernelQueue) => - queue.enqueueSend('ko123', { - methargs: { body: 'x', slots: [] }, - result: null, - }), - message: 'cannot enqueue a send', + queue.resolvePromises('v1', [ + ['kp1', true, { body: 'x', slots: [] }], + ]), }, { - ingress: 'enqueueNotify', + teardown: 'enqueueNotify', call: (queue: KernelQueue) => queue.enqueueNotify('v1', 'kp1'), - message: 'cannot enqueue a notify', }, { - ingress: 'resolvePromises', + teardown: 'enqueueSend', call: (queue: KernelQueue) => - queue.resolvePromises('v1', [ - ['kp1', false, { body: 'x', slots: [] }], - ]), - message: 'cannot resolve promises', - }, - ])( - 'rejects $ingress so remote ingress is not silently queued', - async ({ call, message }) => { - await killRunLoop(new Error('crank exploded')); - (kernelStore.enqueueRun as unknown as MockInstance).mockClear(); - (kernelStore.incrementRefCount as unknown as MockInstance).mockClear(); - - expect(() => call(kernelQueue)).toThrow(message); - expect(kernelStore.enqueueRun).not.toHaveBeenCalled(); - expect(kernelStore.incrementRefCount).not.toHaveBeenCalled(); + queue.enqueueSend('ko123', { + methargs: { body: 'x', slots: [] }, + result: null, + }), }, - ); + ])('still allows $teardown after the run loop dies', async ({ call }) => { + (kernelStore.getKernelPromise as unknown as MockInstance).mockReturnValue( + { + state: 'unresolved', + decider: 'v1', + subscribers: [], + }, + ); + await killRunLoop(new Error('crank exploded')); + + expect(() => call(kernelQueue)).not.toThrow(); + }); it('refuses to start the run loop twice', async () => { ( diff --git a/packages/ocap-kernel/src/KernelQueue.ts b/packages/ocap-kernel/src/KernelQueue.ts index 2c78decdf1..763e0980ec 100644 --- a/packages/ocap-kernel/src/KernelQueue.ts +++ b/packages/ocap-kernel/src/KernelQueue.ts @@ -49,6 +49,14 @@ export class KernelQueue { /** Thunk to signal run queue transition from empty to non-empty */ #wakeUpTheRunQueue: (() => void) | null; + /** + * Whether this crank's savepoint has already been rolled back. This has to be + * recorded at the moment of rollback rather than returned from + * `#processCrankResult`, because that method can throw after rolling back + * (`collectGarbage`), and the catch below must still know not to ask twice. + */ + #crankRolledBack: boolean = false; + /** * The run loop's state, as one value so that a failure recorded for a loop * that never started can't be represented. `failed` keeps the whole `Error`; @@ -60,9 +68,6 @@ export class KernelQueue { | { state: 'running' } | { state: 'failed'; error: Error } = { state: 'idle' }; - /** Whether this crank's savepoint has already been rolled back */ - #crankRolledBack: boolean = false; - /** * Construct a new KernelQueue instance. * @@ -143,9 +148,11 @@ export class KernelQueue { try { this.#kernelStore.rollbackCrank('start'); } catch (rollbackError) { + // The original failure stays the `cause`, since that is the root + // cause an operator needs; the rollback failure is named here. throw new Error( - `Run loop died and its crank could not be rolled back: ${String(error)}`, - { cause: rollbackError }, + `Run loop died and its crank could not be rolled back: ${String(rollbackError)}`, + { cause: error }, ); } } @@ -201,14 +208,13 @@ export class KernelQueue { } /** - * Refuse work that would otherwise sit in a queue nobody drains. Inbound - * remote deliveries are processed inside a savepoint that rolls back on a - * throw without advancing the received-sequence number, so the peer retries - * and then gives up rather than believing a black hole accepted its message. + * Refuse work that would otherwise sit in a queue nobody drains. For callers + * at an ingress boundary only: teardown paths legitimately drain the queue's + * state after the loop is dead and must not be refused. * * @param what - What is being refused, completing "cannot ...". */ - #assertRunLoopAlive(what: string): void { + assertRunLoopAlive(what: string): void { if (this.#runLoopState.state === 'failed') { throw this.#makeDeadRunLoopError(`Kernel run loop died; cannot ${what}`); } @@ -372,7 +378,7 @@ export class KernelQueue { args: unknown[], ): Promise> { // Nothing is draining the run queue, so a returned promise could never settle. - this.#assertRunLoopAlive('queue a message'); + this.assertRunLoopAlive('queue a message'); // TODO(#562): Use logger instead. // eslint-disable-next-line no-console console.debug('enqueueMessage', target, method, args); @@ -394,7 +400,6 @@ export class KernelQueue { * @param immediate - If true (the default), enqueue immediately; if false, buffer for crank completion. */ enqueueSend(target: KRef, message: KernelMessage, immediate = true): void { - this.#assertRunLoopAlive('enqueue a send'); this.#kernelStore.incrementRefCount(target, 'queue|target'); if (message.result) { this.#kernelStore.incrementRefCount(message.result, 'queue|result'); @@ -418,7 +423,6 @@ export class KernelQueue { * @param immediate - If true (the default), enqueue immediately; if false, buffer for crank completion. */ enqueueNotify(endpointId: EndpointId, kpid: KRef, immediate = true): void { - this.#assertRunLoopAlive('enqueue a notify'); this.#kernelStore.incrementRefCount(kpid, 'notify'); const item: RunQueueItemNotify = { type: 'notify', endpointId, kpid }; if (immediate) { @@ -455,8 +459,6 @@ export class KernelQueue { resolutions: KernelOneResolution[], immediate = true, ): void { - // Before any store mutation, so a dead kernel leaves nothing half-applied. - this.#assertRunLoopAlive('resolve promises'); for (const resolution of resolutions) { const [kpid, rejected, data] = resolution; diff --git a/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.test.ts b/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.test.ts index e114834029..9a42b13dcd 100644 --- a/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.test.ts +++ b/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.test.ts @@ -191,6 +191,49 @@ describe('RemoteHandle', () => { }); }); + // A dead run loop will never deliver the message, and `handleRemoteMessage` + // rolls back without advancing the received sequence number, so the peer + // retries and gives up rather than being acknowledged by a black hole. + it.each([ + { + kind: 'message', + params: [ + 'message', + 'ro+1', + { methargs: { body: '["method",[]]', slots: [] }, result: 'rp+2' }, + ], + handedToQueue: () => mockKernelQueue.enqueueSend, + }, + { + kind: 'notify', + params: ['notify', [['rp+1', false, { body: '"x"', slots: [] }]]], + handedToQueue: () => mockKernelQueue.resolvePromises, + }, + ])( + 'refuses an incoming $kind when the run loop is dead', + async ({ params, handedToQueue }) => { + const remote = makeRemote(); + const delivery = JSON.stringify({ seq: 1, method: 'deliver', params }); + const failure = new Error('Kernel run loop died; cannot accept it'); + vi.mocked(mockKernelQueue.assertRunLoopAlive).mockImplementation(() => { + throw failure; + }); + + await expect(remote.handleRemoteMessage(delivery)).rejects.toBe( + failure, + ); + expect(handedToQueue()).not.toHaveBeenCalled(); + + // The refusal must not advance the received sequence number, or the + // peer's retry would be discarded as a duplicate. + vi.mocked(mockKernelQueue.assertRunLoopAlive).mockImplementation( + () => undefined, + ); + await remote.handleRemoteMessage(delivery); + expect(handedToQueue()).toHaveBeenCalledOnce(); + }, + ); + it('does not send BOYD back when remotely triggered (ping-pong prevention)', async () => { const remote = makeRemote(); diff --git a/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.ts b/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.ts index 9a619789d6..f0e78aeb8a 100644 --- a/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.ts +++ b/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.ts @@ -807,6 +807,11 @@ export class RemoteHandle implements EndpointHandle { const [method] = params; switch (method) { case 'message': { + // Refuse rather than queue work for a loop that will never drain it. + // The caller rolls this delivery back without advancing the received + // sequence number, so the peer retries and then gives up instead of + // believing a black hole accepted its message. + this.#kernelQueue.assertRunLoopAlive('accept a remote message'); const [, target, message] = params; this.#kernelQueue.enqueueSend( this.#kernelStore.translateRefEtoK(this.remoteId, target), @@ -815,6 +820,7 @@ export class RemoteHandle implements EndpointHandle { break; } case 'notify': { + this.#kernelQueue.assertRunLoopAlive('accept a remote notify'); const [, resolutions] = params; const kResolutions: KernelOneResolution[] = resolutions.map( (resolution) => { diff --git a/packages/ocap-kernel/src/store/methods/crank.ts b/packages/ocap-kernel/src/store/methods/crank.ts index bdeb4dbd89..4a517f4186 100644 --- a/packages/ocap-kernel/src/store/methods/crank.ts +++ b/packages/ocap-kernel/src/store/methods/crank.ts @@ -32,8 +32,11 @@ export function getCrankMethods(ctx: StoreContext, kdb: KernelDatabase) { function createCrankSavepoint(name: string): void { ctx.inCrank || Fail`createCrankSavepoint outside of crank`; const ordinal = ctx.savepoints.length; - ctx.savepoints.push(name); + // Record the name only once the database has the savepoint. Recording it + // first would leave `endCrank` trying to release a savepoint that was never + // created, and that error would replace whatever really went wrong. kdb.createSavepoint(`t${ordinal}`); + ctx.savepoints.push(name); } /** diff --git a/packages/ocap-kernel/src/types.ts b/packages/ocap-kernel/src/types.ts index 1f698ae7a4..97938c96a6 100644 --- a/packages/ocap-kernel/src/types.ts +++ b/packages/ocap-kernel/src/types.ts @@ -781,9 +781,9 @@ export const RunLoopStatusStruct = union([ export type RunLoopStatus = Infer; /** - * Notified when the kernel's run loop dies. Must not be async: only a - * synchronous throw can be contained, and the kernel is reporting a failure it - * cannot recover from, so there is nothing to await. + * Notified when the kernel's run loop dies. Should not be async: the kernel is + * reporting a failure it cannot recover from, so there is nothing to await. An + * async handler's rejection is logged rather than awaited. */ export type OnRunLoopFailure = (error: Error) => void; diff --git a/packages/ocap-kernel/test/remotes-mocks.ts b/packages/ocap-kernel/test/remotes-mocks.ts index c7a4b4e7e0..0e37b4a77c 100644 --- a/packages/ocap-kernel/test/remotes-mocks.ts +++ b/packages/ocap-kernel/test/remotes-mocks.ts @@ -77,6 +77,7 @@ export class MockRemotesFactory { enqueueSend: vi.fn(), enqueueNotify: vi.fn(), resolvePromises: vi.fn(), + assertRunLoopAlive: vi.fn(), waitForCrank: vi.fn(), run: vi.fn(), } as unknown as KernelQueue; From 7aab306a19df2c65bff0a94218c2bb3031dda8ee Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Tue, 4 Aug 2026 19:11:40 +0200 Subject: [PATCH 05/15] fix(ocap-kernel): call the run loop failure handler off a local, not off this MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A private-field call is still a member call, so this.#onRunLoopFailure(failure) handed a non-arrow handler the whole hardened kernel as its receiver — reset, terminateAllVats, queueMessage — on a boundary whose business is one Error. No escalation today, since every supplier already holds the kernel, but an unintended authority grant. Also fixes a struct test that passed for the wrong reason (remoteComms: undefined is invalid on its own account, so the missing runLoop was never what failed) and documents that rolling back the killing crank means a restart re-dequeues the same item. Co-Authored-By: Claude Opus 5 (1M context) --- packages/ocap-kernel/CHANGELOG.md | 1 + packages/ocap-kernel/src/Kernel.test.ts | 14 ++++++++++++++ packages/ocap-kernel/src/Kernel.ts | 6 +++++- .../src/rpc/kernel-control/get-status.test.ts | 8 +++++++- 4 files changed, 27 insertions(+), 2 deletions(-) diff --git a/packages/ocap-kernel/CHANGELOG.md b/packages/ocap-kernel/CHANGELOG.md index a569a6efb4..f66d522348 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -52,6 +52,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - A delivery that _threw_ (rather than returning `{ abort: true }`) left `endCrank`'s savepoint release to commit the half-finished crank: the item that crank had already dequeued was gone for good, refcount increments stuck, and promises resolved during it stayed resolved while their notifies died unflushed in the crank buffer — so the restart this change recommends resumed from half-applied state - An aborted crank that then throws is not rolled back twice; if the rollback itself fails, the error names it and keeps the original failure as its `cause` - The rollback covers store state only. A crank that had already flushed its buffer settled JS-side subscriptions irreversibly, so a `queueMessage` caller may hold a result for a delivery the store no longer records + - Trade-off to be aware of: because the killing item is no longer consumed, a restart re-dequeues it and can die again on the same item, where previously the commit carried the kernel past it. Integrity is the reason for the change, but an item that reliably kills a crank now needs `clearState`/`reset` (or a `executeDBQuery` against the run queue) rather than a restart - `createCrankSavepoint` now records a savepoint name only once the database has actually created it, so a failed create no longer leaves `endCrank` releasing a savepoint that never existed and reporting that instead of the real failure - Refuse inbound remote deliveries once the run loop is dead ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) - A peer's `message` or `notify` was previously queued and acknowledged with nothing left to deliver it, so the sending kernel waited forever. `RemoteHandle` now refuses them via the new `KernelQueue.assertRunLoopAlive`, and because inbound deliveries are processed inside a savepoint that rolls back without advancing the received-sequence number, the peer retries and then gives up instead diff --git a/packages/ocap-kernel/src/Kernel.test.ts b/packages/ocap-kernel/src/Kernel.test.ts index 0941386062..76140203a0 100644 --- a/packages/ocap-kernel/src/Kernel.test.ts +++ b/packages/ocap-kernel/src/Kernel.test.ts @@ -983,6 +983,20 @@ describe('Kernel', () => { expect(onRunLoopFailure).toHaveBeenCalledWith(failure); }); + it('does not hand the kernel to the failure handler as its receiver', async () => { + let gotAReceiver = true; + await Kernel.make(mockPlatformServices, mockKernelDatabase, { + onRunLoopFailure: function onRunLoopFailure(this: unknown): void { + gotAReceiver = this !== undefined; + }, + }); + + mocks.KernelQueue.lastInstance.killRunLoop(new Error('run loop boom')); + await waitUntilQuiescent(); + + expect(gotAReceiver).toBe(false); + }); + it('wraps a non-Error run loop failure for the embedder', async () => { const onRunLoopFailure = vi.fn(); await Kernel.make(mockPlatformServices, mockKernelDatabase, { diff --git a/packages/ocap-kernel/src/Kernel.ts b/packages/ocap-kernel/src/Kernel.ts index 29605fa7f0..40e7239dd4 100644 --- a/packages/ocap-kernel/src/Kernel.ts +++ b/packages/ocap-kernel/src/Kernel.ts @@ -326,11 +326,15 @@ export class Kernel { runLoopError instanceof Error ? runLoopError : new Error(String(runLoopError), { cause: runLoopError }); + // Called off a local, not off `this`: `this.#onRunLoopFailure(...)` is a + // member call, so a non-arrow handler would receive the whole kernel as its + // receiver. The handler's business here is one `Error`. + const notify = this.#onRunLoopFailure; try { // `OnRunLoopFailure` returns void, but TypeScript admits an async // function there, whose rejection would become the very unhandled // rejection this method exists to avoid. Contain it either way. - const handled = this.#onRunLoopFailure?.(failure) as unknown; + const handled = notify?.(failure) as unknown; if (typeof (handled as PromiseLike)?.then === 'function') { Promise.resolve(handled).catch((handlerError: unknown) => { this.#logger.error( diff --git a/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts b/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts index 072a9b3197..38ecf9999b 100644 --- a/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts +++ b/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts @@ -94,9 +94,15 @@ describe('getStatusHandler', () => { // TypeScript type but required on the wire, and a reply from a kernel built // before this field fails validation outright rather than losing one field. it('rejects a status with no runLoop at all', () => { + // Everything else present and valid, so only the missing `runLoop` can be + // what fails: `remoteComms: undefined` would fail on its own account. expect( is( - { vats: [], subclusters: [], remoteComms: undefined }, + { + vats: [], + subclusters: [], + remoteComms: { state: 'disconnected' }, + }, KernelStatusStruct, ), ).toBe(false); From f793d8f98812010cbea271872f962911a80feb3f Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Tue, 4 Aug 2026 19:25:22 +0200 Subject: [PATCH 06/15] docs: Update changelogs --- packages/kernel-browser-runtime/CHANGELOG.md | 2 +- packages/kernel-cli/CHANGELOG.md | 2 +- packages/kernel-node-runtime/CHANGELOG.md | 2 +- packages/kernel-ui/CHANGELOG.md | 2 +- packages/ocap-kernel/CHANGELOG.md | 20 ++++++++++---------- 5 files changed, 14 insertions(+), 14 deletions(-) diff --git a/packages/kernel-browser-runtime/CHANGELOG.md b/packages/kernel-browser-runtime/CHANGELOG.md index eab0f384be..e101fdcb30 100644 --- a/packages/kernel-browser-runtime/CHANGELOG.md +++ b/packages/kernel-browser-runtime/CHANGELOG.md @@ -9,7 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added -- Log a fatal message when the kernel's run loop dies, since the worker outlives the kernel and has no exit to take ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Log a fatal message when the kernel's run loop dies, since the worker outlives the kernel and has no exit to take ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) ### Fixed diff --git a/packages/kernel-cli/CHANGELOG.md b/packages/kernel-cli/CHANGELOG.md index c6f24b854f..5d008b9368 100644 --- a/packages/kernel-cli/CHANGELOG.md +++ b/packages/kernel-cli/CHANGELOG.md @@ -23,7 +23,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - `kernel daemon start` refuses to start when another daemon is already listening on the same Unix socket, instead of unlinking the socket and orphaning the running process ([#952](https://github.com/MetaMask/ocap-kernel/pull/952)) - Daemon fatal-path visibility: `daemon-entry` now installs handlers for `uncaughtException`, `unhandledRejection`, `SIGHUP`, and `exit` that append a synchronous fingerprint line to `daemon.log` before terminating ([#966](https://github.com/MetaMask/ocap-kernel/pull/966)) - Without these, silent daemon deaths under `stdio: 'ignore'` (the CLI's default spawn mode) left no trace in the log; the operator saw only that the daemon was gone. Every terminating path now leaves at least one line. -- The daemon logs the failure and shuts down with a non-zero exit code when the kernel's run loop dies, instead of staying up with a socket that answers RPCs for a kernel that processes nothing ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- The daemon logs the failure and shuts down with a non-zero exit code when the kernel's run loop dies, instead of staying up with a socket that answers RPCs for a kernel that processes nothing ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - A run loop death during startup aborts `daemon start` rather than publishing a socket and pid file for a dead kernel - That shutdown is bounded at 10 seconds, and a shutdown that throws exits immediately, in both cases removing the pid file first. A `kernel.stop()` that hangs or throws would otherwise leave live vat workers holding the event loop open — so `process.exitCode` never takes effect — with the socket gone and the pid file already cleaned up, an orphan holding `kernel.sqlite` that neither interlock can see, letting the next `daemon start` succeed alongside it diff --git a/packages/kernel-node-runtime/CHANGELOG.md b/packages/kernel-node-runtime/CHANGELOG.md index 5da4acc93c..934b2c4f7d 100644 --- a/packages/kernel-node-runtime/CHANGELOG.md +++ b/packages/kernel-node-runtime/CHANGELOG.md @@ -9,7 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added -- Add `onRunLoopFailure` to `makeKernel`, forwarded to `Kernel.make` and called with the error that killed the kernel's run loop ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Add `onRunLoopFailure` to `makeKernel`, forwarded to `Kernel.make` and called with the error that killed the kernel's run loop ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) ### Changed diff --git a/packages/kernel-ui/CHANGELOG.md b/packages/kernel-ui/CHANGELOG.md index caac0ce0de..8fbc5096ac 100644 --- a/packages/kernel-ui/CHANGELOG.md +++ b/packages/kernel-ui/CHANGELOG.md @@ -9,7 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added -- Show a banner when `getStatus` reports the kernel's run loop as failed ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Show a banner when `getStatus` reports the kernel's run loop as failed ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - The vat and subcluster tables keep rendering their last known contents after the kernel dies, so without this a dead kernel is indistinguishable from a healthy idle one ## [0.5.0] diff --git a/packages/ocap-kernel/CHANGELOG.md b/packages/ocap-kernel/CHANGELOG.md index f66d522348..8e722d49ed 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -9,11 +9,11 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added -- Report run loop health in `KernelStatus` via the new `runLoop` field (`{ state: 'idle' | 'running' }` or `{ state: 'failed', error }`), with `RunLoopStatus` and `RunLoopStatusStruct` exported ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Report run loop health in `KernelStatus` via the new `runLoop` field (`{ state: 'idle' | 'running' }` or `{ state: 'failed', error }`), with `RunLoopStatus` and `RunLoopStatusStruct` exported ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - `runLoop` is optional in the TypeScript type so that adding it doesn't break external constructors of `KernelStatus`, but it is required on the wire: `exactOptional` only permits an absent key inside `object()`, and `KernelStatusStruct` is a `type()`. `Kernel.getStatus` always populates it - `idle` means the run loop was never started, not that it has nothing to do; a loop parked on an empty queue reports `running` -- Export `OnRunLoopFailure` for typing a run loop failure handler ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) -- Add `onRunLoopFailure` to the `Kernel.make` options, called with the error that killed the run loop so an embedder that outlives the kernel (e.g. a daemon) can exit or restart ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Export `OnRunLoopFailure` for typing a run loop failure handler ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) +- Add `onRunLoopFailure` to the `Kernel.make` options, called with the error that killed the run loop so an embedder that outlives the kernel (e.g. a daemon) can exit or restart ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - Add `fetch`, `Request`, `Headers`, and `Response` to available vat endowments ([#942](https://github.com/MetaMask/ocap-kernel/pull/942)) - Add `VatConfig.network: { allowedHosts: string[] }`; requesting `'fetch'` without it rejects `initVat` - Integrate Snaps attenuated endowment factories into vat globals ([#937](https://github.com/MetaMask/ocap-kernel/pull/937)) @@ -43,24 +43,24 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed -- Stop reporting a healthy kernel after the run loop dies ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Stop reporting a healthy kernel after the run loop dies ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - The error that killed the run loop was logged and swallowed, so the kernel went on answering `getStatus` with the same record it returns when healthy while nothing on the run queue was ever processed again, and every `queueMessage` promise hung forever — an outage no caller could detect - `getStatus` now reports `runLoop: { state: 'failed', error }`, and returns it without waiting for a crank that may never end - Message results in flight when the loop dies reject with `Kernel run loop died; this message result will never be delivered` (the killing error as `cause`), and later `queueMessage` calls reject immediately instead of hanging - `KernelQueue.run` now refuses to start a second run loop -- Roll back the crank the run loop died in, instead of committing it ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Roll back the crank the run loop died in, instead of committing it ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - A delivery that _threw_ (rather than returning `{ abort: true }`) left `endCrank`'s savepoint release to commit the half-finished crank: the item that crank had already dequeued was gone for good, refcount increments stuck, and promises resolved during it stayed resolved while their notifies died unflushed in the crank buffer — so the restart this change recommends resumed from half-applied state - An aborted crank that then throws is not rolled back twice; if the rollback itself fails, the error names it and keeps the original failure as its `cause` - The rollback covers store state only. A crank that had already flushed its buffer settled JS-side subscriptions irreversibly, so a `queueMessage` caller may hold a result for a delivery the store no longer records - Trade-off to be aware of: because the killing item is no longer consumed, a restart re-dequeues it and can die again on the same item, where previously the commit carried the kernel past it. Integrity is the reason for the change, but an item that reliably kills a crank now needs `clearState`/`reset` (or a `executeDBQuery` against the run queue) rather than a restart - `createCrankSavepoint` now records a savepoint name only once the database has actually created it, so a failed create no longer leaves `endCrank` releasing a savepoint that never existed and reporting that instead of the real failure -- Refuse inbound remote deliveries once the run loop is dead ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Refuse inbound remote deliveries once the run loop is dead ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - A peer's `message` or `notify` was previously queued and acknowledged with nothing left to deliver it, so the sending kernel waited forever. `RemoteHandle` now refuses them via the new `KernelQueue.assertRunLoopAlive`, and because inbound deliveries are processed inside a savepoint that rolls back without advancing the received-sequence number, the peer retries and then gives up instead - The check deliberately sits at that ingress boundary rather than on the queue's mutators, because teardown legitimately drains queue state after the loop is dead — `VatHandle.terminate` and `RemoteManager` reject the promises a dead endpoint was deciding, and refusing those would break `terminateAllVats` and `reset`, the very recovery actions a failed status invites -- Preserve a thrown non-`Error` as the `cause` when wrapping it, in both the run loop failure path and the embedder notification ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) -- Read run loop health in `getStatus` after waiting for the crank rather than before, so a loop that dies during that wait — the likeliest moment for it to die — is not reported as `running` ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) -- Contain a rejection from an `async` run loop failure handler, which `OnRunLoopFailure`'s `void` return type permits but only a synchronous throw was caught ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) -- Settle a crank's `waitForCrank` waiters even when releasing its savepoints throws, so a database error can no longer strand `getStatus`, `stop`, `reset`, and `clearStorage` forever ([#985](https://github.com/MetaMask/ocap-kernel/pull/985)) +- Preserve a thrown non-`Error` as the `cause` when wrapping it, in both the run loop failure path and the embedder notification ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) +- Read run loop health in `getStatus` after waiting for the crank rather than before, so a loop that dies during that wait — the likeliest moment for it to die — is not reported as `running` ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) +- Contain a rejection from an `async` run loop failure handler, which `OnRunLoopFailure`'s `void` return type permits but only a synchronous throw was caught ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) +- Settle a crank's `waitForCrank` waiters even when releasing its savepoints throws, so a database error can no longer strand `getStatus`, `stop`, `reset`, and `clearStorage` forever ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - Deserialize CapData rejections in `Kernel.queueMessage` so vat errors surface as plain `Error` objects to all callers ([#928](https://github.com/MetaMask/ocap-kernel/pull/928)) - Detect peer restart across receiver state loss so the receiving kernel no longer silently drops a restarted peer's `seq=1` messages ([#948](https://github.com/MetaMask/ocap-kernel/pull/948)) - Persist the peer's last-observed incarnation and compare it on every successful handshake; on a detected restart, clear the peer's c-list contributions and reject the promises it was deciding before the new incarnation reuses any erefs From d95b710bb9c2652909607f5063af35e7c77de2aa Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Tue, 4 Aug 2026 19:38:17 +0200 Subject: [PATCH 07/15] test(ocap-kernel): cover the run-loop rollback and crank bookkeeping gaps MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Mutation testing found three surviving mutants: deleting the per-crank reset of #crankRolledBack, the savepoint-recording order in createCrankSavepoint, and RunLoopBanner's wiring into App all left the suite green. Each now has a test verified to fail without its production line. Also fixes a real hole the Cursor bot caught: when rollbackCrank's database call threw, the savepoint stayed listed, so endCrank's release committed the very crank being abandoned — persisting the half-finished state while the status reported the rollback had failed. Adds the missing coverage for the thenable containment branch, asserts teardown does its work rather than merely not throwing, and condenses the changelog entries. Co-Authored-By: Claude Opus 5 (1M context) --- packages/kernel-cli/CHANGELOG.md | 4 +- packages/kernel-ui/CHANGELOG.md | 3 +- packages/kernel-ui/src/App.test.tsx | 27 +++++++++ packages/ocap-kernel/CHANGELOG.md | 31 +++------- packages/ocap-kernel/src/Kernel.test.ts | 40 +++++++++++++ packages/ocap-kernel/src/KernelQueue.test.ts | 57 ++++++++++++++++--- .../src/store/methods/crank.test.ts | 35 ++++++++++++ .../ocap-kernel/src/store/methods/crank.ts | 10 +++- 8 files changed, 171 insertions(+), 36 deletions(-) diff --git a/packages/kernel-cli/CHANGELOG.md b/packages/kernel-cli/CHANGELOG.md index 5d008b9368..24594fa5cd 100644 --- a/packages/kernel-cli/CHANGELOG.md +++ b/packages/kernel-cli/CHANGELOG.md @@ -24,8 +24,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Daemon fatal-path visibility: `daemon-entry` now installs handlers for `uncaughtException`, `unhandledRejection`, `SIGHUP`, and `exit` that append a synchronous fingerprint line to `daemon.log` before terminating ([#966](https://github.com/MetaMask/ocap-kernel/pull/966)) - Without these, silent daemon deaths under `stdio: 'ignore'` (the CLI's default spawn mode) left no trace in the log; the operator saw only that the daemon was gone. Every terminating path now leaves at least one line. - The daemon logs the failure and shuts down with a non-zero exit code when the kernel's run loop dies, instead of staying up with a socket that answers RPCs for a kernel that processes nothing ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - - A run loop death during startup aborts `daemon start` rather than publishing a socket and pid file for a dead kernel - - That shutdown is bounded at 10 seconds, and a shutdown that throws exits immediately, in both cases removing the pid file first. A `kernel.stop()` that hangs or throws would otherwise leave live vat workers holding the event loop open — so `process.exitCode` never takes effect — with the socket gone and the pid file already cleaned up, an orphan holding `kernel.sqlite` that neither interlock can see, letting the next `daemon start` succeed alongside it + - A death during startup aborts `daemon start` rather than publishing a socket and pid file for a dead kernel + - The shutdown is bounded at 10 seconds and exits immediately if it throws, removing the pid file first, so a stalled `kernel.stop()` cannot leave an orphan holding `kernel.sqlite` that the next `daemon start` runs alongside ## [0.1.0] diff --git a/packages/kernel-ui/CHANGELOG.md b/packages/kernel-ui/CHANGELOG.md index 8fbc5096ac..0839dc9344 100644 --- a/packages/kernel-ui/CHANGELOG.md +++ b/packages/kernel-ui/CHANGELOG.md @@ -9,8 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added -- Show a banner when `getStatus` reports the kernel's run loop as failed ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - - The vat and subcluster tables keep rendering their last known contents after the kernel dies, so without this a dead kernel is indistinguishable from a healthy idle one +- Show a banner when `getStatus` reports the kernel's run loop as failed; the vat and subcluster tables keep rendering their last known contents, so a dead kernel otherwise looks like a healthy idle one ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) ## [0.5.0] diff --git a/packages/kernel-ui/src/App.test.tsx b/packages/kernel-ui/src/App.test.tsx index 33c8bbf3b2..4f7ce60b36 100644 --- a/packages/kernel-ui/src/App.test.tsx +++ b/packages/kernel-ui/src/App.test.tsx @@ -14,6 +14,10 @@ vi.mock('./hooks/useDarkMode.ts', () => ({ useDarkMode: vi.fn(), })); +vi.mock('./hooks/useStatusPolling.ts', () => ({ + useStatusPolling: vi.fn(), +})); + describe('App', () => { beforeEach(() => { cleanup(); @@ -57,6 +61,29 @@ describe('App', () => { expect(screen.getByText('Control Panel')).toBeInTheDocument(); }); + // Without this, deleting the banner from App leaves every test green, and the + // panel is the only remediation signal the browser worker has — it cannot exit. + it('surfaces a failed run loop above the tabs', async () => { + const { useStream } = await import('./hooks/useStream.ts'); + vi.mocked(useStream).mockReturnValue({ + callKernelMethod: vi.fn(), + error: undefined, + } as unknown as StreamState); + const { useStatusPolling } = await import('./hooks/useStatusPolling.ts'); + vi.mocked(useStatusPolling).mockReturnValue({ + vats: [], + subclusters: [], + runLoop: { state: 'failed', error: 'crank exploded' }, + }); + const { App } = await import('./App.tsx'); + render(); + + expect(screen.getByTestId('run-loop-failure')).toBeInTheDocument(); + expect(screen.getByTestId('run-loop-failure-error')).toHaveTextContent( + 'crank exploded', + ); + }); + it('renders all tab labels including the new Remote Comms tab', async () => { const { useStream } = await import('./hooks/useStream.ts'); vi.mocked(useStream).mockReturnValue({ diff --git a/packages/ocap-kernel/CHANGELOG.md b/packages/ocap-kernel/CHANGELOG.md index 8e722d49ed..fc5901bd50 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -9,11 +9,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added -- Report run loop health in `KernelStatus` via the new `runLoop` field (`{ state: 'idle' | 'running' }` or `{ state: 'failed', error }`), with `RunLoopStatus` and `RunLoopStatusStruct` exported ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - - `runLoop` is optional in the TypeScript type so that adding it doesn't break external constructors of `KernelStatus`, but it is required on the wire: `exactOptional` only permits an absent key inside `object()`, and `KernelStatusStruct` is a `type()`. `Kernel.getStatus` always populates it - - `idle` means the run loop was never started, not that it has nothing to do; a loop parked on an empty queue reports `running` -- Export `OnRunLoopFailure` for typing a run loop failure handler ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) -- Add `onRunLoopFailure` to the `Kernel.make` options, called with the error that killed the run loop so an embedder that outlives the kernel (e.g. a daemon) can exit or restart ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) +- Report run loop health in `KernelStatus.runLoop` (`{ state: 'idle' | 'running' }` or `{ state: 'failed', error }`), exporting `RunLoopStatus`, `RunLoopStatusStruct`, and `OnRunLoopFailure` ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) + - `idle` means never started; a loop parked on an empty queue reports `running`. The field is optional in the type but required on the wire, so a reply from a kernel built before it fails result validation +- Add `onRunLoopFailure` to `Kernel.make` options, called with the error that killed the run loop so an embedder that outlives the kernel can exit or restart ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - Add `fetch`, `Request`, `Headers`, and `Response` to available vat endowments ([#942](https://github.com/MetaMask/ocap-kernel/pull/942)) - Add `VatConfig.network: { allowedHosts: string[] }`; requesting `'fetch'` without it rejects `initVat` - Integrate Snaps attenuated endowment factories into vat globals ([#937](https://github.com/MetaMask/ocap-kernel/pull/937)) @@ -44,23 +42,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed - Stop reporting a healthy kernel after the run loop dies ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - - The error that killed the run loop was logged and swallowed, so the kernel went on answering `getStatus` with the same record it returns when healthy while nothing on the run queue was ever processed again, and every `queueMessage` promise hung forever — an outage no caller could detect - - `getStatus` now reports `runLoop: { state: 'failed', error }`, and returns it without waiting for a crank that may never end - - Message results in flight when the loop dies reject with `Kernel run loop died; this message result will never be delivered` (the killing error as `cause`), and later `queueMessage` calls reject immediately instead of hanging - - `KernelQueue.run` now refuses to start a second run loop -- Roll back the crank the run loop died in, instead of committing it ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - - A delivery that _threw_ (rather than returning `{ abort: true }`) left `endCrank`'s savepoint release to commit the half-finished crank: the item that crank had already dequeued was gone for good, refcount increments stuck, and promises resolved during it stayed resolved while their notifies died unflushed in the crank buffer — so the restart this change recommends resumed from half-applied state - - An aborted crank that then throws is not rolled back twice; if the rollback itself fails, the error names it and keeps the original failure as its `cause` - - The rollback covers store state only. A crank that had already flushed its buffer settled JS-side subscriptions irreversibly, so a `queueMessage` caller may hold a result for a delivery the store no longer records - - Trade-off to be aware of: because the killing item is no longer consumed, a restart re-dequeues it and can die again on the same item, where previously the commit carried the kernel past it. Integrity is the reason for the change, but an item that reliably kills a crank now needs `clearState`/`reset` (or a `executeDBQuery` against the run queue) rather than a restart - - `createCrankSavepoint` now records a savepoint name only once the database has actually created it, so a failed create no longer leaves `endCrank` releasing a savepoint that never existed and reporting that instead of the real failure -- Refuse inbound remote deliveries once the run loop is dead ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - - A peer's `message` or `notify` was previously queued and acknowledged with nothing left to deliver it, so the sending kernel waited forever. `RemoteHandle` now refuses them via the new `KernelQueue.assertRunLoopAlive`, and because inbound deliveries are processed inside a savepoint that rolls back without advancing the received-sequence number, the peer retries and then gives up instead - - The check deliberately sits at that ingress boundary rather than on the queue's mutators, because teardown legitimately drains queue state after the loop is dead — `VatHandle.terminate` and `RemoteManager` reject the promises a dead endpoint was deciding, and refusing those would break `terminateAllVats` and `reset`, the very recovery actions a failed status invites -- Preserve a thrown non-`Error` as the `cause` when wrapping it, in both the run loop failure path and the embedder notification ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) -- Read run loop health in `getStatus` after waiting for the crank rather than before, so a loop that dies during that wait — the likeliest moment for it to die — is not reported as `running` ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) -- Contain a rejection from an `async` run loop failure handler, which `OnRunLoopFailure`'s `void` return type permits but only a synchronous throw was caught ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) -- Settle a crank's `waitForCrank` waiters even when releasing its savepoints throws, so a database error can no longer strand `getStatus`, `stop`, `reset`, and `clearStorage` forever ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) + - The error was logged and swallowed, so `getStatus` kept returning its healthy-looking record while nothing on the run queue was processed and every `queueMessage` hung forever. Results in flight now reject with the killing error as their `cause`, later calls reject immediately, and `getStatus` answers without waiting on a crank that may never end +- Roll back the crank the run loop died in instead of committing it, so a restart resumes from a consistent boundary ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) + - Because the killing item is no longer consumed, a restart re-dequeues it; an item that reliably kills a crank needs `clearState`/`reset` rather than a restart + - Store state only — a crank that had already flushed its buffer settled JS-side subscriptions irreversibly +- Refuse inbound remote deliveries once the run loop is dead, rolling back without acknowledging them, so the peer retries and gives up instead of waiting on a kernel that will never deliver ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) +- Keep crank bookkeeping consistent when the database misbehaves: `endCrank` settles its `waitForCrank` waiters even if releasing savepoints throws (previously stranding `getStatus`, `stop`, `reset`, and `clearStorage`), `rollbackCrank` forgets its savepoint even if the rollback throws (which otherwise had `endCrank` commit the crank being abandoned), and `createCrankSavepoint` records a name only once the database created it ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - Deserialize CapData rejections in `Kernel.queueMessage` so vat errors surface as plain `Error` objects to all callers ([#928](https://github.com/MetaMask/ocap-kernel/pull/928)) - Detect peer restart across receiver state loss so the receiving kernel no longer silently drops a restarted peer's `seq=1` messages ([#948](https://github.com/MetaMask/ocap-kernel/pull/948)) - Persist the peer's last-observed incarnation and compare it on every successful handshake; on a detected restart, clear the peer's c-list contributions and reject the promises it was deciding before the new incarnation reuses any erefs diff --git a/packages/ocap-kernel/src/Kernel.test.ts b/packages/ocap-kernel/src/Kernel.test.ts index 76140203a0..cf0a19c019 100644 --- a/packages/ocap-kernel/src/Kernel.test.ts +++ b/packages/ocap-kernel/src/Kernel.test.ts @@ -12,6 +12,7 @@ import { kser } from './liveslots/kernel-marshal.ts'; import type { VatId, VatConfig, + OnRunLoopFailure, PlatformServices, ClusterConfig, } from './types.ts'; @@ -1015,6 +1016,45 @@ describe('Kernel', () => { expect(failure.cause).toBe('not an error'); }); + // The handler slot returns void, but TypeScript admits anything thenable + // there, and an escaping rejection is what the containment exists to stop. + it.each([ + { + kind: 'an async handler', + makeHandler: (handlerError: Error) => async (): Promise => { + throw handlerError; + }, + }, + { + kind: 'a non-native thenable', + makeHandler: (handlerError: Error) => (): PromiseLike => ({ + then: (_onFulfilled, onRejected) => + onRejected?.(handlerError) as PromiseLike, + }), + }, + ])( + 'logs a failure handler that rejects, given $kind', + async ({ makeHandler }) => { + const logger = new Logger('test'); + const logErrorSpy = vi.spyOn(logger, 'error'); + const handlerError = new Error('handler boom'); + await Kernel.make(mockPlatformServices, mockKernelDatabase, { + logger, + onRunLoopFailure: makeHandler( + handlerError, + ) as unknown as OnRunLoopFailure, + }); + + mocks.KernelQueue.lastInstance.killRunLoop(new Error('run loop boom')); + await waitUntilQuiescent(); + + expect(logErrorSpy).toHaveBeenCalledWith( + 'Run loop failure handler rejected:', + handlerError, + ); + }, + ); + it('logs a failure handler that throws', async () => { const logger = new Logger('test'); const logErrorSpy = vi.spyOn(logger, 'error'); diff --git a/packages/ocap-kernel/src/KernelQueue.test.ts b/packages/ocap-kernel/src/KernelQueue.test.ts index 8f3ff510b3..26899493c3 100644 --- a/packages/ocap-kernel/src/KernelQueue.test.ts +++ b/packages/ocap-kernel/src/KernelQueue.test.ts @@ -344,6 +344,39 @@ describe('KernelQueue', () => { }); }); + // The rollback flag is per-crank. If an earlier abort could latch it, every + // later crank that died would skip its rollback and commit half its work. + it('rolls back a later crank after an earlier one aborted', async () => { + const items: RunQueueItem[] = [ + { type: 'send', target: 'ko1', message: {} as KernelMessage }, + { type: 'send', target: 'ko2', message: {} as KernelMessage }, + ]; + let dequeued = 0; + ( + kernelStore.runQueueLength as unknown as MockInstance + ).mockImplementation(() => (dequeued < items.length ? 1 : 0)); + (kernelStore.dequeueRun as unknown as MockInstance).mockImplementation( + () => { + const item = items[dequeued]; + dequeued += 1; + return item; + }, + ); + const secondError = new Error('second crank exploded'); + const deliver = vi + .fn() + .mockResolvedValueOnce({ abort: true }) + .mockRejectedValueOnce(secondError); + + await expect(kernelQueue.run(deliver)).rejects.toBe(secondError); + + expect(kernelStore.rollbackCrank).toHaveBeenCalledTimes(2); + expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ + state: 'failed', + error: 'second crank exploded', + }); + }); + it('refuses ingress via assertRunLoopAlive', async () => { const failure = new Error('crank exploded'); expect(() => kernelQueue.assertRunLoopAlive('accept work')).not.toThrow(); @@ -369,10 +402,12 @@ describe('KernelQueue', () => { queue.resolvePromises('v1', [ ['kp1', true, { body: 'x', slots: [] }], ]), + didWork: () => kernelStore.resolveKernelPromise, }, { teardown: 'enqueueNotify', call: (queue: KernelQueue) => queue.enqueueNotify('v1', 'kp1'), + didWork: () => kernelStore.enqueueRun, }, { teardown: 'enqueueSend', @@ -381,19 +416,25 @@ describe('KernelQueue', () => { methargs: { body: 'x', slots: [] }, result: null, }), + didWork: () => kernelStore.enqueueRun, }, - ])('still allows $teardown after the run loop dies', async ({ call }) => { - (kernelStore.getKernelPromise as unknown as MockInstance).mockReturnValue( - { + ])( + 'still allows $teardown after the run loop dies', + async ({ call, didWork }) => { + ( + kernelStore.getKernelPromise as unknown as MockInstance + ).mockReturnValue({ state: 'unresolved', decider: 'v1', subscribers: [], - }, - ); - await killRunLoop(new Error('crank exploded')); + }); + await killRunLoop(new Error('crank exploded')); - expect(() => call(kernelQueue)).not.toThrow(); - }); + expect(() => call(kernelQueue)).not.toThrow(); + // "Allows" has to mean the work happened, not merely that nothing threw. + expect(didWork()).toHaveBeenCalled(); + }, + ); it('refuses to start the run loop twice', async () => { ( diff --git a/packages/ocap-kernel/src/store/methods/crank.test.ts b/packages/ocap-kernel/src/store/methods/crank.test.ts index f276454500..db3de86450 100644 --- a/packages/ocap-kernel/src/store/methods/crank.test.ts +++ b/packages/ocap-kernel/src/store/methods/crank.test.ts @@ -65,6 +65,23 @@ describe('crank methods', () => { expect(kdb.createSavepoint).toHaveBeenCalledWith('t1'); }); + it('does not record a savepoint the database refused', () => { + context.inCrank = true; + vi.mocked(kdb.createSavepoint).mockImplementationOnce(() => { + throw new Error('database is gone'); + }); + + expect(() => crankMethods.createCrankSavepoint('start')).toThrow( + 'database is gone', + ); + + expect(context.savepoints).toStrictEqual([]); + // Otherwise `endCrank` releases a savepoint that never existed, and that + // error replaces whatever really went wrong. + crankMethods.endCrank(); + expect(kdb.releaseSavepoint).not.toHaveBeenCalled(); + }); + it('should throw when not in a crank', () => { expect(() => crankMethods.createCrankSavepoint('test')).toThrow( 'createCrankSavepoint outside of crank', @@ -73,6 +90,24 @@ describe('crank methods', () => { }); describe('rollbackCrank', () => { + it('forgets the savepoint even if the database rollback fails', () => { + context.inCrank = true; + context.savepoints = ['start']; + vi.mocked(kdb.rollbackSavepoint).mockImplementationOnce(() => { + throw new Error('database is gone'); + }); + + expect(() => crankMethods.rollbackCrank('start')).toThrow( + 'database is gone', + ); + + // Still listed, `endCrank` would release it — committing the crank this + // rollback was abandoning. + expect(context.savepoints).toStrictEqual([]); + crankMethods.endCrank(); + expect(kdb.releaseSavepoint).not.toHaveBeenCalled(); + }); + it('should rollback to specified savepoint', () => { context.inCrank = true; context.savepoints = ['first', 'second', 'third']; diff --git a/packages/ocap-kernel/src/store/methods/crank.ts b/packages/ocap-kernel/src/store/methods/crank.ts index 4a517f4186..dc61a99604 100644 --- a/packages/ocap-kernel/src/store/methods/crank.ts +++ b/packages/ocap-kernel/src/store/methods/crank.ts @@ -49,8 +49,14 @@ export function getCrankMethods(ctx: StoreContext, kdb: KernelDatabase) { ctx.crankBuffer.length = 0; // Discard buffered outputs for (const ordinal of ctx.savepoints.keys()) { if (ctx.savepoints[ordinal] === savepoint) { - kdb.rollbackSavepoint(`t${ordinal}`); - ctx.savepoints.length = ordinal; + try { + kdb.rollbackSavepoint(`t${ordinal}`); + } finally { + // Forget the savepoint even if the rollback failed. Leaving it listed + // would have `endCrank`'s release commit the crank we just abandoned — + // the half-finished state this rollback exists to discard. + ctx.savepoints.length = ordinal; + } // The rollback reverted DB state but in-memory caches are stale. // Recreate the run queue so its cached head/tail are re-read from DB. ctx.refreshRunQueue(); From 4d1f5d2cabd0e1aaf43a14c07bb2c49141804bf9 Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Tue, 4 Aug 2026 21:21:35 +0200 Subject: [PATCH 08/15] fix(ocap-kernel): name the real error when an abort rollback fails MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit PR review found that the abort path recorded its rollback only after the call succeeded, so a throwing rollbackCrank left the flag unset and the run loop's catch asked again — against the savepoint rollbackCrank had already discarded in its own finally. The second attempt's "no such savepoint" then became the reported cause of death, and since only error.message crosses the wire, the database error that actually killed the kernel reached neither getStatus nor daemon.log. The flag now means "attempted", set in a finally, which is exactly what the crank.ts change makes correct. runLoop becomes required on KernelStatus. exactOptional left the type saying "may be absent" while validation demanded the key, and optional cannot fix that here: it widens the property to | undefined and an RPC result must satisfy Json. Required is the only self-consistent option, so get-status and RunLoopBanner stop documenting contradictory intents about an older kernel's reply. The daemon's post-failure handler moves to its own module and gets tested: 93 lines shaped around process.exit had no coverage at all, and the watchdog needed fake timers, which lockdown's frozen Date rules out (hence the mock shim). Failures now log through stringify, which keeps the cause chain that error.stack drops. Strengthens the double-start test to assert the running loop survives a refused second run(), and corrects comments that overstated what they guarded: teardown enqueues rather than drains, and a stalled kernel.stop() leaves an orphan the pid interlock can still see. Not fixed, deliberately: a crank that rolls back after flushing its buffer leaves a caller holding a fulfilled promise for work that replays. main already settled subscriptions mid-crank via resolvePromises(immediate) and already rolled back on abort, so this is pre-existing in kind; the fix is to defer subscription settlement past the commit, which is too broad for a review pass. Co-Authored-By: Claude Opus 5 (1M context) --- packages/kernel-cli/CHANGELOG.md | 3 +- .../kernel-cli/src/commands/daemon-entry.ts | 123 +++----- .../src/commands/run-loop-failure.test.ts | 269 ++++++++++++++++++ .../src/commands/run-loop-failure.ts | 138 +++++++++ .../src/components/RunLoopBanner.test.tsx | 3 +- .../src/components/RunLoopBanner.tsx | 1 + packages/ocap-kernel/CHANGELOG.md | 7 +- packages/ocap-kernel/src/KernelQueue.test.ts | 51 +++- packages/ocap-kernel/src/KernelQueue.ts | 48 +++- .../src/rpc/kernel-control/get-status.test.ts | 9 +- packages/ocap-kernel/src/types.ts | 22 +- 11 files changed, 548 insertions(+), 126 deletions(-) create mode 100644 packages/kernel-cli/src/commands/run-loop-failure.test.ts create mode 100644 packages/kernel-cli/src/commands/run-loop-failure.ts diff --git a/packages/kernel-cli/CHANGELOG.md b/packages/kernel-cli/CHANGELOG.md index 24594fa5cd..84945dd5ca 100644 --- a/packages/kernel-cli/CHANGELOG.md +++ b/packages/kernel-cli/CHANGELOG.md @@ -25,7 +25,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Without these, silent daemon deaths under `stdio: 'ignore'` (the CLI's default spawn mode) left no trace in the log; the operator saw only that the daemon was gone. Every terminating path now leaves at least one line. - The daemon logs the failure and shuts down with a non-zero exit code when the kernel's run loop dies, instead of staying up with a socket that answers RPCs for a kernel that processes nothing ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - A death during startup aborts `daemon start` rather than publishing a socket and pid file for a dead kernel - - The shutdown is bounded at 10 seconds and exits immediately if it throws, removing the pid file first, so a stalled `kernel.stop()` cannot leave an orphan holding `kernel.sqlite` that the next `daemon start` runs alongside + - The shutdown is bounded at 10 seconds and exits immediately if it throws, removing the pid file first. A `kernel.stop()` that throws would otherwise leave an orphan holding `kernel.sqlite` with its socket gone and its pid file already cleaned up, invisible to both start-time interlocks; one that merely stalls stays visible to the pid interlock but is an orphan all the same + - Failures are logged with their `cause` chain, so a run loop death reported through a failed crank rollback still names the error that actually killed the kernel ## [0.1.0] diff --git a/packages/kernel-cli/src/commands/daemon-entry.ts b/packages/kernel-cli/src/commands/daemon-entry.ts index 245fd2a33a..7d06a2ee70 100644 --- a/packages/kernel-cli/src/commands/daemon-entry.ts +++ b/packages/kernel-cli/src/commands/daemon-entry.ts @@ -2,18 +2,17 @@ import '@metamask/kernel-shims/endoify-node'; import { makeKernel } from '@metamask/kernel-node-runtime'; import { startDaemon } from '@metamask/kernel-node-runtime/daemon'; import type { DaemonHandle } from '@metamask/kernel-node-runtime/daemon'; +import { stringify } from '@metamask/kernel-utils'; import type { LogEntry } from '@metamask/logger'; import { Logger } from '@metamask/logger'; import { appendFileSync, rmSync } from 'node:fs'; import { mkdir, readFile, rm, writeFile } from 'node:fs/promises'; import { join } from 'node:path'; +import { makeRunLoopFailureHandler } from './run-loop-failure.ts'; import { getOcapHome } from '../ocap-home.ts'; import { isProcessAlive } from '../utils.ts'; -/** How long a post-failure shutdown may take before the process is killed. */ -const SHUTDOWN_TIMEOUT_MS = 10_000; - // Mirror of @metamask/logger's level ordering (`logLevels` is not part // of the package's public surface). Higher numbers are more severe. // Declared above the file-scope logger construction so the transport @@ -63,6 +62,9 @@ const logger = new Logger({ installFatalHandlers(); main().catch((error) => { + // stderr is `ignore` under the CLI spawner, so the log file is the only place + // this can be read; `stringify` keeps the `cause` chain that `String` drops. + logger.error('Daemon fatal', stringify(error, 0)); process.stderr.write(`Daemon fatal: ${String(error)}\n`); process.exitCode = 1; }); @@ -77,32 +79,38 @@ async function main(): Promise { process.env.OCAP_SOCKET_PATH ?? join(ocapDir, 'daemon.sock'); const dbFilename = join(ocapDir, 'kernel.sqlite'); + const pidPath = join(ocapDir, 'daemon.pid'); - // Left alone, a dead run loop leaves the daemon answering RPCs for a kernel - // that processes nothing — an outage only a client that reads `runLoop` in - // `getStatus` can spot. Terminate instead, non-zero, so the failure is - // visible and `ocap daemon start` can recover. - // `handleRunLoopFailure` is reassigned below once there is a daemon to close. + // Declared before `makeKernel` so the failure handler can close over them: the + // kernel may report a death before `startDaemon` has returned. let runLoopFailure: Error | undefined; - let handleRunLoopFailure = (failure: Error): void => { - runLoopFailure = failure; - logger.error( - 'Kernel run loop died before shutdown handling was installed.', - failure.stack ?? failure.message, - ); - }; + let daemonStarted = false; + let shutdownPromise: Promise | undefined; + + const handleRunLoopFailure = makeRunLoopFailureHandler({ + logger, + shutdown: async (reason) => shutdown(reason), + isStarted: () => daemonStarted, + isShuttingDown: () => shutdownPromise !== undefined, + recordFailure: (failure) => { + runLoopFailure ??= failure; + }, + // eslint-disable-next-line n/no-sync -- must finish before process.exit + removePidFile: () => rmSync(pidPath, { force: true }), + setExitCode: (code) => { + process.exitCode = code; + }, + // eslint-disable-next-line n/no-process-exit -- a broken shutdown must still terminate + exit: (code) => process.exit(code), + }); const { kernel, kernelDatabase } = await makeKernel({ resetStorage: false, dbFilename, logger, - // Indirection, not redundancy: the kernel captures this function value for - // good, so the late call is what lets the reassignment below take effect. - onRunLoopFailure: (error) => handleRunLoopFailure(error), + onRunLoopFailure: handleRunLoopFailure, }); - const pidPath = join(ocapDir, 'daemon.pid'); - // Interlock: refuse to start a second daemon under the same OCAP_HOME. // The socket-binding interlock in startDaemon handles the live-socket // case; this catches the rarer case where an orphan still holds the @@ -146,9 +154,9 @@ async function main(): Promise { throw error; } + daemonStarted = true; logger.info(`Daemon started. Socket: ${handle.socketPath}`); - let shutdownPromise: Promise | undefined; /** * Shut down the daemon idempotently. Concurrent calls coalesce. * @@ -165,67 +173,8 @@ async function main(): Promise { return shutdownPromise; } - handleRunLoopFailure = (failure: Error): void => { - if (shutdownPromise !== undefined) { - // Expected teardown, not an outage: don't fail a deliberate stop. - logger.info( - 'Kernel run loop stopped during shutdown.', - failure.stack ?? failure.message, - ); - return; - } - logger.error( - 'Kernel run loop died; shutting down the daemon.', - failure.stack ?? failure.message, - ); - process.exitCode = 1; - - // A shutdown that hangs or throws would leave the socket gone and the pid - // file removed by `shutdown`'s own cleanup, while live vat workers keep the - // event loop alive — an orphan holding kernel.sqlite that neither interlock - // can see, so the next `ocap daemon start` succeeds and two kernels contend - // for the database. Terminate instead. `process.exitCode` is not enough - // precisely because those worker handles keep the process running. - const exitNow = (): void => { - try { - // eslint-disable-next-line n/no-sync -- must finish before process.exit - rmSync(pidPath, { force: true }); - } catch (rmError) { - logger.error('Could not remove the pid file before exiting.', rmError); - } - // eslint-disable-next-line n/no-process-exit -- a broken shutdown must still terminate - process.exit(1); - }; - - const killTimer = setTimeout(() => { - logger.error( - `Shutdown stalled for ${SHUTDOWN_TIMEOUT_MS} ms after run loop failure; exiting now.`, - ); - exitNow(); - }, SHUTDOWN_TIMEOUT_MS); - - // Only a *successful* shutdown disarms the watchdog. Clearing it in a - // `finally` would disarm it on the failure path it exists for. - const shutdownOrExit = async (): Promise => { - try { - await shutdown('run loop failure'); - } catch (shutdownError) { - clearTimeout(killTimer); - logger.error( - 'Shutdown after run loop failure failed; exiting now.', - shutdownError, - ); - exitNow(); - return; - } - clearTimeout(killTimer); - }; - // Nothing can escape: every path above is handled or exits. - shutdownOrExit().catch(() => undefined); - }; - - // A failure recorded between the startup check and this handler still has to - // bring the daemon down. + // A failure recorded before there was a daemon to close still has to bring it + // down, now that there is one. if (runLoopFailure) { handleRunLoopFailure(runLoopFailure); } @@ -310,17 +259,11 @@ function makeFileTransport(logFilePath: string, minLevel: LogLevelName) { function installFatalHandlers(): void { /* eslint-disable n/no-process-exit -- fatal handlers must terminate deterministically */ process.on('uncaughtException', (error: unknown) => { - const detail = - error instanceof Error ? (error.stack ?? error.message) : String(error); - logger.error('Uncaught exception', detail); + logger.error('Uncaught exception', stringify(error, 0)); process.exit(1); }); process.on('unhandledRejection', (reason: unknown) => { - const detail = - reason instanceof Error - ? (reason.stack ?? reason.message) - : String(reason); - logger.error('Unhandled rejection', detail); + logger.error('Unhandled rejection', stringify(reason, 0)); process.exit(1); }); process.on('SIGHUP', () => { diff --git a/packages/kernel-cli/src/commands/run-loop-failure.test.ts b/packages/kernel-cli/src/commands/run-loop-failure.test.ts new file mode 100644 index 0000000000..e4a342b633 --- /dev/null +++ b/packages/kernel-cli/src/commands/run-loop-failure.test.ts @@ -0,0 +1,269 @@ +// The mock shim rather than real lockdown: `vi.useFakeTimers()` cannot install +// its clock over a hardened `Date`, and this module's watchdog is the thing +// under test. +import '@ocap/repo-tools/test-utils/mock-endoify'; + +import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; + +import { + makeRunLoopFailureHandler, + SHUTDOWN_TIMEOUT_MS, +} from './run-loop-failure.ts'; +import type { RunLoopFailureHandlerOptions } from './run-loop-failure.ts'; + +/** + * Make a handler over spies, defaulting to "the daemon is up and not shutting + * down" so each test overrides only what it is about. + * + * @param overrides - Options to replace. + * @returns The handler and the spies it was built from. + */ +const makeHandler = ( + overrides: Partial = {}, +): { + handle: (failure: Error) => void; + logger: { error: ReturnType; info: ReturnType }; + shutdown: ReturnType; + recordFailure: ReturnType; + removePidFile: ReturnType; + setExitCode: ReturnType; + exit: ReturnType; +} => { + const logger = { error: vi.fn(), info: vi.fn() }; + const shutdown = vi.fn().mockResolvedValue(undefined); + const recordFailure = vi.fn(); + const removePidFile = vi.fn(); + const setExitCode = vi.fn(); + const exit = vi.fn(); + const handle = makeRunLoopFailureHandler({ + logger, + shutdown, + isStarted: () => true, + isShuttingDown: () => false, + recordFailure, + removePidFile, + setExitCode, + exit, + ...overrides, + }); + return { + handle, + logger, + shutdown, + recordFailure, + removePidFile, + setExitCode, + exit, + }; +}; + +describe('makeRunLoopFailureHandler', () => { + beforeEach(() => { + vi.useFakeTimers(); + }); + + afterEach(() => { + vi.useRealTimers(); + }); + + it('shuts the daemon down and marks the exit non-zero', async () => { + const { handle, shutdown, setExitCode, logger, exit } = makeHandler(); + + handle(new Error('crank exploded')); + await vi.runAllTimersAsync(); + + expect(shutdown).toHaveBeenCalledWith('run loop failure'); + expect(setExitCode).toHaveBeenCalledWith(1); + expect(logger.error).toHaveBeenCalledWith( + 'Kernel run loop died; shutting down the daemon.', + expect.stringContaining('crank exploded'), + ); + // A shutdown that worked leaves the process to wind down on its own. + expect(exit).not.toHaveBeenCalled(); + }); + + // `stringify` is what carries the chain; `error.stack` would drop it, and when + // a crank's rollback fails the rollback is the outer error and the failure that + // actually killed the kernel is only reachable through `cause`. + it('logs the cause chain, not just the outermost error', () => { + const { handle, logger } = makeHandler(); + + handle( + new Error('could not be rolled back', { + cause: new Error('database is gone'), + }), + ); + + expect(logger.error).toHaveBeenCalledWith( + 'Kernel run loop died; shutting down the daemon.', + expect.stringContaining('database is gone'), + ); + }); + + it('records the failure before doing anything else', () => { + const failure = new Error('crank exploded'); + const { handle, recordFailure } = makeHandler({ isStarted: () => false }); + + handle(failure); + + expect(recordFailure).toHaveBeenCalledWith(failure); + }); + + it('only records the first failure', () => { + let recorded: Error | undefined; + const { handle } = makeHandler({ + recordFailure: (failure) => { + recorded ??= failure; + }, + isStarted: () => false, + }); + + handle(new Error('first')); + handle(new Error('second')); + + expect(recorded?.message).toBe('first'); + }); + + it('does not shut down before the daemon has started', () => { + const { handle, shutdown, setExitCode, logger } = makeHandler({ + isStarted: () => false, + }); + + handle(new Error('died during startup')); + + expect(shutdown).not.toHaveBeenCalled(); + expect(setExitCode).not.toHaveBeenCalled(); + expect(logger.error).toHaveBeenCalledWith( + 'Kernel run loop died before the daemon started.', + expect.stringContaining('died during startup'), + ); + }); + + // A loop stopping because someone asked the daemon to stop is not an outage, + // and must not turn a deliberate `ocap daemon stop` into a non-zero exit. + it('does not fail a shutdown already under way', () => { + const { handle, shutdown, setExitCode, exit, logger } = makeHandler({ + isShuttingDown: () => true, + }); + + handle(new Error('loop stopped')); + + expect(shutdown).not.toHaveBeenCalled(); + expect(setExitCode).not.toHaveBeenCalled(); + expect(exit).not.toHaveBeenCalled(); + expect(logger.info).toHaveBeenCalledWith( + 'Kernel run loop stopped during shutdown.', + expect.stringContaining('loop stopped'), + ); + }); + + // Live vat workers hold the event loop open, so `setExitCode` alone would leave + // an orphan on kernel.sqlite with its socket already gone. + it('kills the process when the shutdown stalls', async () => { + const { handle, removePidFile, exit, logger } = makeHandler({ + shutdown: vi.fn().mockReturnValue(new Promise(() => undefined)), + }); + + handle(new Error('crank exploded')); + expect(exit).not.toHaveBeenCalled(); + + await vi.advanceTimersByTimeAsync(SHUTDOWN_TIMEOUT_MS); + + expect(logger.error).toHaveBeenCalledWith( + `Shutdown stalled for ${SHUTDOWN_TIMEOUT_MS} ms after run loop failure; exiting now.`, + ); + // Removed before exiting, so the next `ocap daemon start` isn't blocked by a + // pid file whose owner is gone. + expect(removePidFile).toHaveBeenCalled(); + expect(exit).toHaveBeenCalledWith(1); + }); + + it('waits the full timeout before killing the process', async () => { + const { handle, exit } = makeHandler({ + shutdown: vi.fn().mockReturnValue(new Promise(() => undefined)), + timeoutMs: 5_000, + }); + + handle(new Error('crank exploded')); + await vi.advanceTimersByTimeAsync(4_999); + expect(exit).not.toHaveBeenCalled(); + + await vi.advanceTimersByTimeAsync(1); + expect(exit).toHaveBeenCalledWith(1); + }); + + it('kills the process when the shutdown throws', async () => { + const { handle, removePidFile, exit, logger } = makeHandler({ + shutdown: vi.fn().mockRejectedValue(new Error('close failed')), + }); + + handle(new Error('crank exploded')); + await vi.runAllTimersAsync(); + + expect(logger.error).toHaveBeenCalledWith( + 'Shutdown after run loop failure failed; exiting now.', + expect.stringContaining('close failed'), + ); + expect(removePidFile).toHaveBeenCalled(); + expect(exit).toHaveBeenCalledWith(1); + }); + + // The watchdog must not fire after the process is already on its way out, or a + // second `exit` lands during teardown. + it('disarms the watchdog once the shutdown settles', async () => { + const { handle, exit } = makeHandler({ + shutdown: vi.fn().mockRejectedValue(new Error('close failed')), + }); + + handle(new Error('crank exploded')); + await vi.runAllTimersAsync(); + expect(exit).toHaveBeenCalledOnce(); + + await vi.advanceTimersByTimeAsync(SHUTDOWN_TIMEOUT_MS * 2); + + expect(exit).toHaveBeenCalledOnce(); + }); + + it('still exits when removing the pid file fails', async () => { + const { handle, exit, logger } = makeHandler({ + shutdown: vi.fn().mockRejectedValue(new Error('close failed')), + removePidFile: () => { + throw new Error('EPERM'); + }, + }); + + handle(new Error('crank exploded')); + await vi.runAllTimersAsync(); + + expect(logger.error).toHaveBeenCalledWith( + 'Could not remove the pid file before exiting.', + expect.stringContaining('EPERM'), + ); + expect(exit).toHaveBeenCalledWith(1); + }); + + // An unhandled rejection here would be reported as the cause of death instead + // of the run loop failure that actually killed the kernel. + it('does not reject when a log transport throws', async () => { + const logger = { + error: vi.fn().mockImplementation(() => { + throw new Error('ENOSPC'); + }), + info: vi.fn(), + }; + const onUnhandled = vi.fn(); + process.once('unhandledRejection', onUnhandled); + + const { handle } = makeHandler({ + logger, + shutdown: vi.fn().mockRejectedValue(new Error('close failed')), + }); + + expect(() => handle(new Error('crank exploded'))).toThrow('ENOSPC'); + await vi.runAllTimersAsync(); + await Promise.resolve(); + + expect(onUnhandled).not.toHaveBeenCalled(); + process.off('unhandledRejection', onUnhandled); + }); +}); diff --git a/packages/kernel-cli/src/commands/run-loop-failure.ts b/packages/kernel-cli/src/commands/run-loop-failure.ts new file mode 100644 index 0000000000..2c913c5043 --- /dev/null +++ b/packages/kernel-cli/src/commands/run-loop-failure.ts @@ -0,0 +1,138 @@ +import { stringify } from '@metamask/kernel-utils'; +import type { Logger } from '@metamask/logger'; + +/** How long a post-failure shutdown may take before the process is killed. */ +export const SHUTDOWN_TIMEOUT_MS = 10_000; + +/** The subset of `Logger` this handler needs. */ +type FailureLogger = Pick; + +export type RunLoopFailureHandlerOptions = { + logger: FailureLogger; + /** Shut the daemon down. Idempotent; concurrent calls coalesce. */ + shutdown: (reason: string) => Promise; + /** Whether there is a daemon to shut down yet. */ + isStarted: () => boolean; + /** Whether a shutdown is already under way. */ + isShuttingDown: () => boolean; + /** Record the failure so startup can consult it. */ + recordFailure: (failure: Error) => void; + /** Remove the pid file. Must complete before the process exits. */ + removePidFile: () => void; + setExitCode: (code: number) => void; + exit: (code: number) => void; + timeoutMs?: number; +}; + +/** + * Build the daemon's run loop failure handler. + * + * Left alone, a dead run loop leaves the daemon answering RPCs for a kernel that + * processes nothing — an outage only a client that reads `runLoop` in + * `getStatus` can spot. Terminate instead, non-zero, so the failure is visible + * and `ocap daemon start` can recover. + * + * Extracted from `daemon-entry` because that module shuts the process down as a + * side effect of being imported, which leaves this logic untestable in place. + * + * @param options - Options bag. + * @param options.logger - Where to record the failure. + * @param options.shutdown - Shut the daemon down. Idempotent; calls coalesce. + * @param options.isStarted - Whether there is a daemon to shut down yet. + * @param options.isShuttingDown - Whether a shutdown is already under way. + * @param options.recordFailure - Record the failure so startup can consult it. + * @param options.removePidFile - Remove the pid file, synchronously. + * @param options.setExitCode - Set the code the process will exit with. + * @param options.exit - Terminate the process now. + * @param options.timeoutMs - How long the shutdown may take before the process + * is killed. Defaults to {@link SHUTDOWN_TIMEOUT_MS}. + * @returns A handler suitable for `makeKernel`'s `onRunLoopFailure`. + */ +export function makeRunLoopFailureHandler({ + logger, + shutdown, + isStarted, + isShuttingDown, + recordFailure, + removePidFile, + setExitCode, + exit, + timeoutMs = SHUTDOWN_TIMEOUT_MS, +}: RunLoopFailureHandlerOptions): (failure: Error) => void { + return (failure: Error): void => { + recordFailure(failure); + + if (!isStarted()) { + // No daemon to close yet. Startup either unwinds at its own check or + // replays this failure once there is something to shut down. + logger.error( + 'Kernel run loop died before the daemon started.', + stringify(failure, 0), + ); + return; + } + + if (isShuttingDown()) { + // Expected teardown, not an outage: don't fail a deliberate stop. + logger.info( + 'Kernel run loop stopped during shutdown.', + stringify(failure, 0), + ); + return; + } + + // `stringify` rather than `failure.stack`, which omits the cause chain. When + // a crank dies and its rollback then fails, the rollback failure is the + // outermost message and the error that actually killed the kernel is only + // reachable through `cause`. + logger.error( + 'Kernel run loop died; shutting down the daemon.', + stringify(failure, 0), + ); + setExitCode(1); + + // A shutdown that throws would leave the socket gone and the pid file + // removed by `shutdown`'s own cleanup, while live vat workers keep the event + // loop alive — an orphan holding kernel.sqlite that neither interlock can + // see, so the next `ocap daemon start` succeeds and two kernels contend for + // the database. A shutdown that *hangs* never reaches that cleanup, so the + // pid file survives and the pid interlock does still see the orphan — but it + // is an orphan either way. Terminate in both cases. `setExitCode` is not + // enough precisely because those worker handles keep the process running. + const exitNow = (): void => { + try { + removePidFile(); + } catch (rmError) { + logger.error( + 'Could not remove the pid file before exiting.', + stringify(rmError, 0), + ); + } + exit(1); + }; + + const killTimer = setTimeout(() => { + logger.error( + `Shutdown stalled for ${timeoutMs} ms after run loop failure; exiting now.`, + ); + exitNow(); + }, timeoutMs); + + shutdown('run loop failure') + .then( + () => clearTimeout(killTimer), + (shutdownError: unknown) => { + clearTimeout(killTimer); + logger.error( + 'Shutdown after run loop failure failed; exiting now.', + stringify(shutdownError, 0), + ); + exitNow(); + }, + ) + // Reached only if a handler above throws — a log transport out of disk + // space, say. There is nothing further to do, and an unhandled rejection + // here would be reported as the cause of death instead of the run loop. + .catch(() => undefined); + }; +} diff --git a/packages/kernel-ui/src/components/RunLoopBanner.test.tsx b/packages/kernel-ui/src/components/RunLoopBanner.test.tsx index 0fae3c50cf..936556b486 100644 --- a/packages/kernel-ui/src/components/RunLoopBanner.test.tsx +++ b/packages/kernel-ui/src/components/RunLoopBanner.test.tsx @@ -30,7 +30,7 @@ const makeMockPanelContext = ( const makeMockStatus = (runLoop: KernelStatus['runLoop']): KernelStatus => ({ vats: [], subclusters: [], - ...(runLoop ? { runLoop } : {}), + runLoop, }); describe('RunLoopBanner', () => { @@ -62,7 +62,6 @@ describe('RunLoopBanner', () => { it.each([ { name: 'running', runLoop: { state: 'running' } as const }, { name: 'idle', runLoop: { state: 'idle' } as const }, - { name: 'absent, as on an older kernel', runLoop: undefined }, ])('renders nothing when the run loop is $name', ({ runLoop }) => { mockUsePanelContext.mockReturnValue( makeMockPanelContext(makeMockStatus(runLoop)), diff --git a/packages/kernel-ui/src/components/RunLoopBanner.tsx b/packages/kernel-ui/src/components/RunLoopBanner.tsx index afb6d60e86..5dd89dbd7f 100644 --- a/packages/kernel-ui/src/components/RunLoopBanner.tsx +++ b/packages/kernel-ui/src/components/RunLoopBanner.tsx @@ -23,6 +23,7 @@ export const RunLoopBanner: React.FC = () => { { }); }); + // `rollbackCrank` discards the savepoint even when its database call throws, + // so a second attempt could only report a missing savepoint. Without the + // `finally` that records the attempt, the abort path leaves the flag unset, + // the catch asks again, and "no such savepoint" becomes the reason the + // kernel reports for its own death — the database error reaching nobody, + // since only `error.message` crosses the wire. + it('reports the database failure when an aborted crank cannot roll back', async () => { + (kernelStore.runQueueLength as unknown as MockInstance) + .mockReturnValueOnce(1) + .mockReturnValue(0); + (kernelStore.dequeueRun as unknown as MockInstance).mockReturnValueOnce({ + type: 'send', + target: 'ko123', + message: { result: 'kp99' } as KernelMessage, + }); + const rollbackError = new Error('database is gone'); + ( + kernelStore.rollbackCrank as unknown as MockInstance + ).mockImplementationOnce(() => { + throw rollbackError; + }); + const deliver = vi.fn().mockResolvedValue({ abort: true }); + + await expect(kernelQueue.run(deliver)).rejects.toBe(rollbackError); + expect(kernelStore.rollbackCrank).toHaveBeenCalledOnce(); + expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ + state: 'failed', + error: 'database is gone', + }); + }); + // The rollback flag is per-crank. If an earlier abort could latch it, every // later crank that died would skip its rollback and commit half its work. it('rolls back a later crank after an earlier one aborted', async () => { @@ -392,9 +423,10 @@ describe('KernelQueue', () => { ).rejects.toHaveProperty('cause', failure); }); - // Teardown drains queue state rather than adding work to it, so it must - // keep working after the loop dies — `VatHandle.terminate` and - // `RemoteManager` reject the promises a dead endpoint was deciding. + // Teardown enqueues too, so the guard cannot sit on these mutators: it must + // keep working after the loop dies, because `VatHandle.terminate` and + // `RemoteManager` reject the promises a dead endpoint was deciding, and + // refusing that would break `terminateAllVats` and `reset`. it.each([ { teardown: 'resolvePromises', @@ -436,7 +468,10 @@ describe('KernelQueue', () => { }, ); - it('refuses to start the run loop twice', async () => { + // The guard sits outside `run`'s try, so the refusal must not be mistaken + // for the loop dying: were it inside, a stray second call would mark a + // healthy kernel failed and reject every in-flight result. + it('refuses to start the run loop twice without killing the running one', async () => { ( kernelStore.runQueueLength as unknown as MockInstance ).mockReturnValueOnce(1); @@ -447,9 +482,17 @@ describe('KernelQueue', () => { }); const deliver = vi.fn().mockReturnValue(new Promise(() => undefined)); kernelQueue.run(deliver).catch(() => undefined); + await kernelQueue.enqueueMessage('ko123', 'method', []); + expect(kernelQueue.subscriptions.has('kp1')).toBe(true); + await expect(kernelQueue.run(deliver)).rejects.toThrow( 'run loop already started', ); + + expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ + state: 'running', + }); + expect(kernelQueue.subscriptions.has('kp1')).toBe(true); }); }); diff --git a/packages/ocap-kernel/src/KernelQueue.ts b/packages/ocap-kernel/src/KernelQueue.ts index 763e0980ec..0ea7b8fca6 100644 --- a/packages/ocap-kernel/src/KernelQueue.ts +++ b/packages/ocap-kernel/src/KernelQueue.ts @@ -50,12 +50,17 @@ export class KernelQueue { #wakeUpTheRunQueue: (() => void) | null; /** - * Whether this crank's savepoint has already been rolled back. This has to be - * recorded at the moment of rollback rather than returned from - * `#processCrankResult`, because that method can throw after rolling back - * (`collectGarbage`), and the catch below must still know not to ask twice. + * Whether this crank's savepoint has already been handed to `rollbackCrank`. + * Attempted, not necessarily succeeded: `rollbackCrank` forgets the savepoint + * whether or not the database call throws, so after either outcome a second + * attempt can only report "no such savepoint" over the real error. + * + * This has to be recorded at the moment of the attempt rather than returned + * from `#processCrankResult`, because that method can throw after rolling back + * (`#terminateVat`, `collectGarbage`), and the catch below must still know not + * to ask twice. */ - #crankRolledBack: boolean = false; + #crankRollbackAttempted: boolean = false; /** * The run loop's state, as one value so that a failure recorded for a loop @@ -117,7 +122,7 @@ export class KernelQueue { let wakeUpPromise: Promise | undefined; this.#kernelStore.startCrank(); - this.#crankRolledBack = false; + this.#crankRollbackAttempted = false; try { this.#kernelStore.createCrankSavepoint('start'); @@ -142,9 +147,10 @@ export class KernelQueue { wakeUpPromise = promise; } } catch (error) { - // An aborted crank already rolled back and released the savepoint; - // asking again would throw "no such savepoint" over the real error. - if (!this.#crankRolledBack) { + // An aborted crank already asked, and `rollbackCrank` discards the + // savepoint either way; asking again could only throw "no such + // savepoint" over the real error. + if (!this.#crankRollbackAttempted) { try { this.#kernelStore.rollbackCrank('start'); } catch (rollbackError) { @@ -208,11 +214,17 @@ export class KernelQueue { } /** - * Refuse work that would otherwise sit in a queue nobody drains. For callers - * at an ingress boundary only: teardown paths legitimately drain the queue's - * state after the loop is dead and must not be refused. + * Refuse work that would otherwise sit in a queue nobody drains. + * + * For callers at an ingress boundary only. Teardown must not be refused even + * though it also enqueues: `VatHandle.terminate` and `RemoteManager` reject the + * promises a dying endpoint was deciding, via `resolvePromises`, which enqueues + * notifies for their subscribers. Those notifies are never delivered, but that + * is acceptable — the endpoint is going away — whereas refusing them would + * break `terminateAllVats` and `reset`, the recovery a failed status invites. * * @param what - What is being refused, completing "cannot ...". + * @throws If the run loop has died. */ assertRunLoopAlive(what: string): void { if (this.#runLoopState.state === 'failed') { @@ -273,8 +285,16 @@ export class KernelQueue { // Rollback the kernel state to before the failed delivery attempt. // For active vats, this allows the message to be retried in a future crank. // For terminated vats, the message will just go splat. - this.#kernelStore.rollbackCrank('start'); - this.#crankRolledBack = true; + try { + this.#kernelStore.rollbackCrank('start'); + } finally { + // Set even when the rollback threw. `rollbackCrank` forgets the + // savepoint in its own `finally`, so "attempted" and "the savepoint is + // gone" now coincide exactly — and a second attempt from the run loop's + // catch would report a missing savepoint as the reason the kernel died, + // burying the database error that actually killed it. + this.#crankRollbackAttempted = true; + } // Discard kernel subscriptions that were queued for invocation this.#resolvedWithKernelSubscription = []; diff --git a/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts b/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts index 38ecf9999b..030db09038 100644 --- a/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts +++ b/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts @@ -89,10 +89,11 @@ describe('getStatusHandler', () => { expect(is(makeStatus(runLoop), KernelStatusStruct)).toBe(false); }); - // `exactOptional` only permits an absent key inside `object()`, and - // `KernelStatusStruct` is a `type()`. So `runLoop` is optional in the - // TypeScript type but required on the wire, and a reply from a kernel built - // before this field fails validation outright rather than losing one field. + // `runLoop` is required, so `RpcClient`'s result validation fails the whole + // `getStatus` call for a reply from a kernel built before this field, rather + // than quietly losing it. Pinned because the alternatives don't typecheck + // here: `optional` widens the property to `| undefined` and `KernelStatus` + // must satisfy `Json`. it('rejects a status with no runLoop at all', () => { // Everything else present and valid, so only the missing `runLoop` can be // what fails: `remoteComms: undefined` would fail on its own account. diff --git a/packages/ocap-kernel/src/types.ts b/packages/ocap-kernel/src/types.ts index 97938c96a6..7e16078398 100644 --- a/packages/ocap-kernel/src/types.ts +++ b/packages/ocap-kernel/src/types.ts @@ -769,9 +769,10 @@ const RemoteCommsConnectedStruct = object({ * an empty queue reports `running`. `failed` means nothing will ever be * processed again and the kernel must be restarted. */ -// The arms are `type()`, not `object()`, for the same reason `runLoop` itself is -// optional below: a client shipped against these arms must tolerate a newer -// kernel adding a field, or an exact arm would fail the whole `getStatus` call. +// The arms are `type()`, not `object()`, so a client shipped against them +// tolerates a newer kernel adding a field to an arm. Note the limit of that: +// a newer kernel adding a whole new *state* is rejected by the union either +// way, so adding an arm here is a breaking wire change for older clients. export const RunLoopStatusStruct = union([ type({ state: literal('idle') }), type({ state: literal('running') }), @@ -796,12 +797,15 @@ export const KernelStatusStruct = type({ subclusterId: SubclusterIdStruct, }), ), - // Optional in the *type* because this struct and `KernelStatus` are - // published, so a required key breaks external code that constructs the type. - // Not optional at runtime: `exactOptional` only permits an absent key inside - // `object()`, and this is a `type()`, so validation requires the key to be - // present — same as `remoteComms`. `Kernel.getStatus` always sets both. - runLoop: exactOptional(RunLoopStatusStruct), + // Required, in the type as well as on the wire. `exactOptional` would make the + // type say "may be absent" while validation still demanded the key, since + // `exactOptional` only permits an absent key inside `object()` and this is a + // `type()`. `optional` would agree with the type but cannot be used: it widens + // the inferred property to `| undefined`, and `KernelStatus` is an RPC result, + // so it must satisfy `Json`. Required is the only self-consistent option — at + // the cost that a reply from a kernel predating this field fails validation + // outright, which `remoteComms` already implies for older kernels too. + runLoop: RunLoopStatusStruct, remoteComms: exactOptional( union([ RemoteCommsDisconnectedStruct, From 845516384001492c472dabc663d32b7612924f60 Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Tue, 4 Aug 2026 21:35:01 +0200 Subject: [PATCH 09/15] test: cover crank rollback against real SQLite and runLoop on the wire MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit KernelQueue's tests mock the store, so rollbackCrank is a vi.fn() and every claim about what the rollback actually does to SQLite went unverified. The new kernel-test suite exercises the real thing: the dequeued item returns to the run queue (the "a restart re-dequeues it" claim), the length cache is recomputed rather than left stale at zero, endCrank's unconditional release does not commit the crank the rollback abandoned, the connection is still writable afterwards and a later crank still commits, and a savepoint that was never created is refused. Verified by mutation: removing the cache invalidation fails 2 of 6, removing refreshRunQueue fails 1, and reverting the savepoint-forgetting fix fails 5 — the last being the consequence the unit tests cannot see, since they assert the bookkeeping rather than that leaving it listed really commits. Both socket e2e tests round-tripped getStatus while asserting only vats and subclusters, and neither transport validates results — sendCommand and sendJsonRpc are raw JSON-RPC, not RpcClient. So now that runLoop is required, a kernel that stopped emitting it would break every RpcClient consumer, the UI panel included, while both tests stayed green. They now assert a live daemon reports the loop running. Co-Authored-By: Claude Opus 5 (1M context) --- packages/kernel-cli/test/e2e/daemon.test.ts | 5 + .../test/e2e/daemon-stack.test.ts | 4 + .../kernel-test/src/crank-rollback.test.ts | 154 ++++++++++++++++++ 3 files changed, 163 insertions(+) create mode 100644 packages/kernel-test/src/crank-rollback.test.ts diff --git a/packages/kernel-cli/test/e2e/daemon.test.ts b/packages/kernel-cli/test/e2e/daemon.test.ts index aae6aa7aca..1531eff7fe 100644 --- a/packages/kernel-cli/test/e2e/daemon.test.ts +++ b/packages/kernel-cli/test/e2e/daemon.test.ts @@ -34,6 +34,11 @@ describe('Daemon CLI e2e', { timeout: 60_000 }, () => { const result = response.result as Record; expect(result).toHaveProperty('vats'); expect(result).toHaveProperty('subclusters'); + // `runLoop` is required by `KernelStatusStruct`, and `sendCommand` doesn't + // validate results — so without this assertion a kernel that stopped + // emitting it would break every `RpcClient` consumer (the UI panel) while + // this test stayed green. A live daemon reports the loop running. + expect(result).toHaveProperty('runLoop', { state: 'running' }); }); it('returns error for unknown method', async () => { diff --git a/packages/kernel-node-runtime/test/e2e/daemon-stack.test.ts b/packages/kernel-node-runtime/test/e2e/daemon-stack.test.ts index fb30696199..237d260c81 100644 --- a/packages/kernel-node-runtime/test/e2e/daemon-stack.test.ts +++ b/packages/kernel-node-runtime/test/e2e/daemon-stack.test.ts @@ -125,6 +125,10 @@ describe('Daemon Stack (JSON-RPC socket protocol)', { timeout: 30_000 }, () => { const result = response.result as Record; expect(result).toHaveProperty('vats'); expect(result).toHaveProperty('subclusters'); + // `runLoop` is required by `KernelStatusStruct`, and this transport doesn't + // validate results — so without this assertion a kernel that stopped emitting + // it would break every `RpcClient` consumer while this test stayed green. + expect(result).toHaveProperty('runLoop', { state: 'running' }); }); it('returns error for unknown method', async () => { diff --git a/packages/kernel-test/src/crank-rollback.test.ts b/packages/kernel-test/src/crank-rollback.test.ts new file mode 100644 index 0000000000..cd2a708aa0 --- /dev/null +++ b/packages/kernel-test/src/crank-rollback.test.ts @@ -0,0 +1,154 @@ +import type { KernelDatabase } from '@metamask/kernel-store'; +import { makeSQLKernelDatabase } from '@metamask/kernel-store/sqlite/nodejs'; +import { makeKernelStore } from '@metamask/ocap-kernel'; +import type { RunQueueItem } from '@metamask/ocap-kernel'; +import { describe, it, expect } from 'vitest'; + +/** + * The run loop rolls back the crank it died in, so that a restart resumes from a + * consistent boundary rather than from a half-finished crank. `KernelQueue`'s own + * tests mock the store, so they prove only that `rollbackCrank` is *called* + * correctly. These exercise what it actually does against real SQLite: the + * savepoint, the run queue and its length cache, and the release that `endCrank` + * performs afterwards. + */ + +/** + * Make a kernel store over a fresh in-memory database. + * + * @returns The store and the database beneath it. + */ +const makeStore = async (): Promise<{ + kernelStore: ReturnType; + kdb: KernelDatabase; +}> => { + const kdb = await makeSQLKernelDatabase({ dbFilename: ':memory:' }); + return { kernelStore: makeKernelStore(kdb), kdb }; +}; + +const makeItem = (target: string): RunQueueItem => + ({ + type: 'send', + target, + message: { methargs: { body: '#[]', slots: [] } }, + }) as unknown as RunQueueItem; + +describe('crank rollback against a real database', () => { + // The claim the changelog makes: because the killing crank is rolled back, the + // item it dequeued is still there to be re-dequeued after a restart. With the + // store mocked this is unobservable. + it('returns the dequeued item to the run queue', async () => { + const { kernelStore } = await makeStore(); + kernelStore.enqueueRun(makeItem('ko1')); + + kernelStore.startCrank(); + kernelStore.createCrankSavepoint('start'); + const dequeued = kernelStore.dequeueRun(); + expect(dequeued).toBeDefined(); + expect(kernelStore.runQueueLength()).toBe(0); + + kernelStore.rollbackCrank('start'); + kernelStore.endCrank(); + + expect(kernelStore.runQueueLength()).toBe(1); + expect(kernelStore.dequeueRun()).toStrictEqual(dequeued); + }); + + // `rollbackCrank` invalidates the length cache precisely because the rollback + // restored rows the cache no longer knows about. Reading the length *before* + // the rollback primes that cache, which is what makes the invalidation matter. + it('recomputes the run queue length after a rollback', async () => { + const { kernelStore } = await makeStore(); + kernelStore.enqueueRun(makeItem('ko1')); + kernelStore.enqueueRun(makeItem('ko2')); + + kernelStore.startCrank(); + kernelStore.createCrankSavepoint('start'); + kernelStore.dequeueRun(); + kernelStore.dequeueRun(); + // Prime the cache at 0 so a stale read would be visible below. + expect(kernelStore.runQueueLength()).toBe(0); + + kernelStore.rollbackCrank('start'); + kernelStore.endCrank(); + + expect(kernelStore.runQueueLength()).toBe(2); + }); + + // `endCrank` releases savepoints unconditionally, and releasing the savepoint a + // rollback abandoned would commit the crank being discarded. It cannot, because + // `rollbackCrank` forgets the savepoint — but that reasoning is about SQLite's + // savepoint stack, so it is worth pinning against a real one. + it('does not commit the abandoned crank when endCrank releases afterwards', async () => { + const { kernelStore, kdb } = await makeStore(); + kdb.kernelKVStore.set('before', 'yes'); + + kernelStore.startCrank(); + kernelStore.createCrankSavepoint('start'); + kdb.kernelKVStore.set('during', 'yes'); + kdb.kernelKVStore.delete('before'); + + kernelStore.rollbackCrank('start'); + kernelStore.endCrank(); + + expect(kdb.kernelKVStore.get('during')).toBeUndefined(); + expect(kdb.kernelKVStore.get('before')).toBe('yes'); + }); + + // A rollback that left the transaction open would swallow every later write on + // the connection, including the ones `Kernel.stop()` makes on the way out. + it('leaves the database writable after a rolled-back crank', async () => { + const { kernelStore, kdb } = await makeStore(); + + kernelStore.startCrank(); + kernelStore.createCrankSavepoint('start'); + kdb.kernelKVStore.set('discarded', 'yes'); + kernelStore.rollbackCrank('start'); + kernelStore.endCrank(); + + kdb.kernelKVStore.set('after', 'yes'); + expect(kdb.kernelKVStore.get('after')).toBe('yes'); + + // Survives the commit boundary a subsequent crank draws, so the write really + // landed rather than sitting in a transaction that never resolves. + kernelStore.startCrank(); + kernelStore.createCrankSavepoint('start'); + kernelStore.endCrank(); + expect(kdb.kernelKVStore.get('after')).toBe('yes'); + expect(kdb.kernelKVStore.get('discarded')).toBeUndefined(); + }); + + // The abort path rolls back mid-crank and the run loop then keeps going, so the + // next crank has to be able to create its own savepoint and commit normally. + it('commits a later crank after an earlier one rolled back', async () => { + const { kernelStore, kdb } = await makeStore(); + + kernelStore.startCrank(); + kernelStore.createCrankSavepoint('start'); + kdb.kernelKVStore.set('first', 'yes'); + kernelStore.rollbackCrank('start'); + kernelStore.endCrank(); + + kernelStore.startCrank(); + kernelStore.createCrankSavepoint('start'); + kdb.kernelKVStore.set('second', 'yes'); + kernelStore.endCrank(); + + expect(kdb.kernelKVStore.get('first')).toBeUndefined(); + expect(kdb.kernelKVStore.get('second')).toBe('yes'); + }); + + // `createCrankSavepoint` records the name only once the database has the + // savepoint. Asking to roll back one that was never created must therefore say + // so, rather than releasing someone else's savepoint. + it('refuses to roll back a savepoint that was never created', async () => { + const { kernelStore } = await makeStore(); + + kernelStore.startCrank(); + + expect(() => kernelStore.rollbackCrank('start')).toThrow( + 'no such savepoint', + ); + kernelStore.endCrank(); + }); +}); From be4fb35eeb9614dcaecd44fd91d9fa11fe048958 Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Wed, 5 Aug 2026 12:29:47 +0200 Subject: [PATCH 10/15] docs: say that a failed kernel is not recoverable in place MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `assertRunLoopAlive` called `terminateAllVats` and `reset` "the recovery a failed status invites", but neither restarts the run loop: nothing clears a `failed` state and `run` refuses a second call, so a kernel that has failed stays failed for the life of the instance. They are cleanup. Name them as such, and say the same on `reset` itself, which is where someone looking for a way out would land. Agoric's swingset takes the same position — `panic` is never cleared and every later `run`/`step` re-throws it — so this is the intended design, not a gap. Also record why the browser worker deliberately stays up instead of closing itself. The old comment claimed it "has no exit to take", which is untrue and made the choice look forced: `self.close()` would remove the only diagnostic without buying any recovery, since nothing respawns the worker, the vat iframes belong to the offscreen document and would outlive it, and the panel keeps its last successful status when polling fails. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/kernel-worker/kernel-worker.ts | 10 ++++++++-- packages/ocap-kernel/src/Kernel.ts | 4 ++++ packages/ocap-kernel/src/KernelQueue.ts | 6 +++++- 3 files changed, 17 insertions(+), 3 deletions(-) diff --git a/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts b/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts index 229429069b..832a57a906 100644 --- a/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts +++ b/packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts @@ -64,8 +64,14 @@ async function main(): Promise { const kernelP = Kernel.make(platformServicesClient, kernelDatabase, { resetStorage, systemSubclusters, - // The worker outlives the kernel and has no exit to take, so all it can do - // is say so loudly; the panel reads `runLoop` from `getStatus` as well. + // Log and stay up, deliberately. `self.close()` would match what the daemon + // does, but here it would remove the only diagnostic without buying any + // recovery: nothing respawns this worker, the vat iframes belong to the + // offscreen document and would outlive it as orphans, and the panel keeps + // its last successful status when polling fails — so it would go on showing + // a healthy kernel forever. Staying up is what lets `getStatus` report + // `runLoop: failed` and the panel say so. Reviving the browser kernel means + // teardown and respawn driven from the offscreen document. onRunLoopFailure: (error) => { logger.error( 'Kernel run loop died; this worker must be reloaded.', diff --git a/packages/ocap-kernel/src/Kernel.ts b/packages/ocap-kernel/src/Kernel.ts index 40e7239dd4..e4fafc2e70 100644 --- a/packages/ocap-kernel/src/Kernel.ts +++ b/packages/ocap-kernel/src/Kernel.ts @@ -792,6 +792,10 @@ export class Kernel { /** * Stop all running vats and reset the kernel state. * This is for debugging purposes only. + * + * Does not revive a kernel whose run loop has died: this clears state, it does + * not restart the loop, so `getStatus` still reports `failed` afterwards and + * the queue still refuses new work. */ async reset(): Promise { await this.#kernelQueue.waitForCrank(); diff --git a/packages/ocap-kernel/src/KernelQueue.ts b/packages/ocap-kernel/src/KernelQueue.ts index 0ea7b8fca6..2a4b211e01 100644 --- a/packages/ocap-kernel/src/KernelQueue.ts +++ b/packages/ocap-kernel/src/KernelQueue.ts @@ -221,7 +221,11 @@ export class KernelQueue { * promises a dying endpoint was deciding, via `resolvePromises`, which enqueues * notifies for their subscribers. Those notifies are never delivered, but that * is acceptable — the endpoint is going away — whereas refusing them would - * break `terminateAllVats` and `reset`, the recovery a failed status invites. + * break `terminateAllVats` and `reset`. Note that those are cleanup, not + * recovery: nothing clears a `failed` state and `run` refuses to be called + * twice, so a kernel that has failed stays failed for the life of the + * instance. Recovery means a new kernel, which in practice means a new + * process. * * @param what - What is being refused, completing "cannot ...". * @throws If the run loop has died. From c3eb0a0a634173e83950157fe63f5e61b795cc3b Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Wed, 5 Aug 2026 20:14:15 +0200 Subject: [PATCH 11/15] fix(kernel-store): close the transaction a failed savepoint rollback abandoned MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `rollbackSavepoint` only reached its stack bookkeeping and `rollbackIfNeeded` after `ROLLBACK TO` returned, so a throwing rollback left the savepoint listed and the transaction open with nothing to ever commit or abort it. Every later write on the connection then joined that transaction, reported success, and vanished on close — invisible in the daemon, which exits and lets SQLite unwind it, but permanent in the browser worker, which deliberately stays up. Discard the whole transaction instead. That is no wider than the caller asked for: the transaction begins with the outermost savepoint, so it holds only the work the rollback was already abandoning, which for a crank is the same boundary. The rollback failure is still what gets thrown, even when aborting fails too. Co-Authored-By: Claude Opus 5 (1M context) --- packages/kernel-store/CHANGELOG.md | 6 +++ .../kernel-store/src/sqlite/nodejs.test.ts | 42 +++++++++++++++++++ packages/kernel-store/src/sqlite/nodejs.ts | 17 +++++++- packages/kernel-store/src/sqlite/wasm.test.ts | 39 +++++++++++++++++ packages/kernel-store/src/sqlite/wasm.ts | 17 +++++++- .../ocap-kernel/src/store/methods/crank.ts | 4 +- 6 files changed, 122 insertions(+), 3 deletions(-) diff --git a/packages/kernel-store/CHANGELOG.md b/packages/kernel-store/CHANGELOG.md index 40c550d2c6..5cfe39eb5e 100644 --- a/packages/kernel-store/CHANGELOG.md +++ b/packages/kernel-store/CHANGELOG.md @@ -7,6 +7,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Fixed + +- `rollbackSavepoint` discards the enclosing transaction when `ROLLBACK TO` itself fails, instead of leaving the savepoint on its stack and the transaction open ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) + - Nothing would ever commit or abort that transaction, so every later write on the connection silently joined it, reported success, and vanished on close. Discarding it is no wider than the caller asked for: the transaction begins with the outermost savepoint, so it holds only the work the rollback was abandoning + - The rollback failure is still what gets thrown, even if aborting the transaction fails too + ## [0.6.0] ### Changed diff --git a/packages/kernel-store/src/sqlite/nodejs.test.ts b/packages/kernel-store/src/sqlite/nodejs.test.ts index 36b342401a..a62392fe19 100644 --- a/packages/kernel-store/src/sqlite/nodejs.test.ts +++ b/packages/kernel-store/src/sqlite/nodejs.test.ts @@ -292,6 +292,48 @@ describe('makeSQLKernelDatabase', () => { expect(mockDb._spStack).toStrictEqual([]); }); + // Otherwise every later write on this connection joins a transaction nothing + // will ever commit, reports success, and vanishes on close. + it('rollbackSavepoint discards the transaction when the rollback fails', async () => { + const db = await makeSQLKernelDatabase({}); + mockDb.inTransaction = true; + mockDb._spStack = ['point1']; + mockStatement.run.mockClear(); + mockDb.exec.mockImplementationOnce(() => { + throw new Error('disk I/O error'); + }); + + expect(() => db.rollbackSavepoint('point1')).toThrowError( + 'disk I/O error', + ); + + expect(mockDb._spStack).toStrictEqual([]); + // The abort is the only prepared statement this path runs. + expect(mockStatement.run).toHaveBeenCalledOnce(); + mockDb.inTransaction = false; + }); + + // The rollback failure is the diagnosis; a failed abort on top of it only + // repeats that the same connection is broken. + it('rollbackSavepoint reports the rollback failure even if the abort fails too', async () => { + const db = await makeSQLKernelDatabase({}); + mockDb.inTransaction = true; + mockDb._spStack = ['point1']; + mockDb.exec.mockImplementationOnce(() => { + throw new Error('disk I/O error'); + }); + mockStatement.run.mockImplementationOnce(() => { + throw new Error('cannot rollback'); + }); + + expect(() => db.rollbackSavepoint('point1')).toThrowError( + 'disk I/O error', + ); + + expect(mockDb._spStack).toStrictEqual([]); + mockDb.inTransaction = false; + }); + it('releaseSavepoint validates savepoint exists', async () => { const db = await makeSQLKernelDatabase({}); mockDb.inTransaction = true; diff --git a/packages/kernel-store/src/sqlite/nodejs.ts b/packages/kernel-store/src/sqlite/nodejs.ts index 0dc7c7d460..ec863edc7c 100644 --- a/packages/kernel-store/src/sqlite/nodejs.ts +++ b/packages/kernel-store/src/sqlite/nodejs.ts @@ -287,7 +287,22 @@ export async function makeSQLKernelDatabase({ throw new Error(`No such savepoint: ${name}`); } const query = SQL_QUERIES.ROLLBACK_SAVEPOINT.replace('%NAME%', name); - db.exec(query); + try { + db.exec(query); + } catch (error) { + // Left as it was, the savepoint stays on the stack and the transaction open + // with nothing to ever commit or abort it, so every later write on this + // connection joins it, reports success, and vanishes on close. Discarding + // the whole transaction is safe: it begins with the outermost savepoint, so + // it holds only what this rollback was abandoning anyway. + db._spStack.length = 0; + try { + rollbackIfNeeded(); + } catch { + // The rollback failure below is the one worth reporting. + } + throw error; + } db._spStack.splice(idx); if (db._spStack.length === 0) { rollbackIfNeeded(); diff --git a/packages/kernel-store/src/sqlite/wasm.test.ts b/packages/kernel-store/src/sqlite/wasm.test.ts index 5e17138021..2cbc96d658 100644 --- a/packages/kernel-store/src/sqlite/wasm.test.ts +++ b/packages/kernel-store/src/sqlite/wasm.test.ts @@ -452,6 +452,45 @@ describe('makeSQLKernelDatabase', () => { expect(mockDb._inTx).toBe(false); }); + // Otherwise every later write on this connection joins a transaction nothing + // will ever commit, reports success, and vanishes on close. + it('rollbackSavepoint discards the transaction when the rollback fails', async () => { + const db = await makeSQLKernelDatabase({}); + mockDb._inTx = true; + mockDb._spStack = ['point1']; + mockDb.exec.mockImplementationOnce(() => { + throw new Error('disk I/O error'); + }); + + expect(() => db.rollbackSavepoint('point1')).toThrowError( + 'disk I/O error', + ); + + expect(mockDb._spStack).toStrictEqual([]); + expect(mockDb._inTx).toBe(false); + }); + + // The rollback failure is the diagnosis; a failed abort on top of it only + // repeats that the same connection is broken. + it('rollbackSavepoint reports the rollback failure even if the abort fails too', async () => { + const db = await makeSQLKernelDatabase({}); + mockDb._inTx = true; + mockDb._spStack = ['point1']; + mockDb.exec.mockImplementationOnce(() => { + throw new Error('disk I/O error'); + }); + mockStatement.step.mockImplementationOnce(() => { + throw new Error('cannot rollback'); + }); + + expect(() => db.rollbackSavepoint('point1')).toThrowError( + 'disk I/O error', + ); + + expect(mockDb._spStack).toStrictEqual([]); + mockDb._inTx = false; + }); + it('releaseSavepoint validates savepoint exists', async () => { const db = await makeSQLKernelDatabase({}); mockDb._inTx = true; diff --git a/packages/kernel-store/src/sqlite/wasm.ts b/packages/kernel-store/src/sqlite/wasm.ts index 6278f98957..c0c32b8a72 100644 --- a/packages/kernel-store/src/sqlite/wasm.ts +++ b/packages/kernel-store/src/sqlite/wasm.ts @@ -369,7 +369,22 @@ export async function makeSQLKernelDatabase({ throw new Error(`No such savepoint: ${name}`); } const query = SQL_QUERIES.ROLLBACK_SAVEPOINT.replace('%NAME%', name); - db.exec(query); + try { + db.exec(query); + } catch (error) { + // Left as it was, the savepoint stays on the stack and the transaction open + // with nothing to ever commit or abort it, so every later write on this + // connection joins it, reports success, and vanishes on close. Discarding + // the whole transaction is safe: it begins with the outermost savepoint, so + // it holds only what this rollback was abandoning anyway. + db._spStack.length = 0; + try { + rollbackIfNeeded(); + } catch { + // The rollback failure below is the one worth reporting. + } + throw error; + } db._spStack.splice(idx); if (db._spStack.length === 0) { rollbackIfNeeded(); diff --git a/packages/ocap-kernel/src/store/methods/crank.ts b/packages/ocap-kernel/src/store/methods/crank.ts index dc61a99604..87d2bc65b8 100644 --- a/packages/ocap-kernel/src/store/methods/crank.ts +++ b/packages/ocap-kernel/src/store/methods/crank.ts @@ -54,7 +54,9 @@ export function getCrankMethods(ctx: StoreContext, kdb: KernelDatabase) { } finally { // Forget the savepoint even if the rollback failed. Leaving it listed // would have `endCrank`'s release commit the crank we just abandoned — - // the half-finished state this rollback exists to discard. + // the half-finished state this rollback exists to discard. A failed + // rollback discards the whole transaction instead (see + // `rollbackSavepoint`), which for a crank is the same boundary. ctx.savepoints.length = ordinal; } // The rollback reverted DB state but in-memory caches are stale. From 29affc3e03fdf8325cbaf13d52020a58a935e174 Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Wed, 5 Aug 2026 20:14:29 +0200 Subject: [PATCH 12/15] fix(kernel-cli): remediate a dead run loop before logging it MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The failure log ran ahead of `setExitCode`, the watchdog and the shutdown, and the daemon's transport is `appendFileSync` — so a full disk threw, the kernel swallowed it, and the whole remediation was dropped. The daemon stayed up serving a dead kernel: the outage this handler exists to end. Logging is now best-effort and the exit code is set first. The test that appeared to cover this was tautological for the same reason: the mocked logger threw on its first call, so the shutdown was never reached and the trailing `.catch` was never exercised. Replaced with tests that let the first log succeed, and one that makes `exit` throw so the `.catch` is load-bearing. Extract `makeDaemonRunLoopWiring` for the lifecycle state `daemon-entry` owned inline. Deleting the started flag, the post-`initIdentity` check or the pre-start replay left the whole suite green, because `daemon-entry` shuts the process down as a side effect of being imported and so has no unit test at all. Co-Authored-By: Claude Opus 5 (1M context) --- packages/kernel-cli/CHANGELOG.md | 1 + .../kernel-cli/src/commands/daemon-entry.ts | 29 +-- .../src/commands/run-loop-failure.test.ts | 184 +++++++++++++++++- .../src/commands/run-loop-failure.ts | 127 +++++++++++- 4 files changed, 300 insertions(+), 41 deletions(-) diff --git a/packages/kernel-cli/CHANGELOG.md b/packages/kernel-cli/CHANGELOG.md index 84945dd5ca..3fec5b0c49 100644 --- a/packages/kernel-cli/CHANGELOG.md +++ b/packages/kernel-cli/CHANGELOG.md @@ -27,6 +27,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - A death during startup aborts `daemon start` rather than publishing a socket and pid file for a dead kernel - The shutdown is bounded at 10 seconds and exits immediately if it throws, removing the pid file first. A `kernel.stop()` that throws would otherwise leave an orphan holding `kernel.sqlite` with its socket gone and its pid file already cleaned up, invisible to both start-time interlocks; one that merely stalls stays visible to the pid interlock but is an orphan all the same - Failures are logged with their `cause` chain, so a run loop death reported through a failed crank rollback still names the error that actually killed the kernel + - Logging is best-effort: the transport is `appendFileSync`, so a full disk would otherwise throw and take the shutdown with it, leaving up the daemon this exists to bring down ## [0.1.0] diff --git a/packages/kernel-cli/src/commands/daemon-entry.ts b/packages/kernel-cli/src/commands/daemon-entry.ts index 7d06a2ee70..9c7ca44e9c 100644 --- a/packages/kernel-cli/src/commands/daemon-entry.ts +++ b/packages/kernel-cli/src/commands/daemon-entry.ts @@ -9,7 +9,7 @@ import { appendFileSync, rmSync } from 'node:fs'; import { mkdir, readFile, rm, writeFile } from 'node:fs/promises'; import { join } from 'node:path'; -import { makeRunLoopFailureHandler } from './run-loop-failure.ts'; +import { makeDaemonRunLoopWiring } from './run-loop-failure.ts'; import { getOcapHome } from '../ocap-home.ts'; import { isProcessAlive } from '../utils.ts'; @@ -81,20 +81,14 @@ async function main(): Promise { const dbFilename = join(ocapDir, 'kernel.sqlite'); const pidPath = join(ocapDir, 'daemon.pid'); - // Declared before `makeKernel` so the failure handler can close over them: the + // Declared before `makeKernel` so the failure wiring can close over it: the // kernel may report a death before `startDaemon` has returned. - let runLoopFailure: Error | undefined; - let daemonStarted = false; let shutdownPromise: Promise | undefined; - const handleRunLoopFailure = makeRunLoopFailureHandler({ + const runLoop = makeDaemonRunLoopWiring({ logger, shutdown: async (reason) => shutdown(reason), - isStarted: () => daemonStarted, isShuttingDown: () => shutdownPromise !== undefined, - recordFailure: (failure) => { - runLoopFailure ??= failure; - }, // eslint-disable-next-line n/no-sync -- must finish before process.exit removePidFile: () => rmSync(pidPath, { force: true }), setExitCode: (code) => { @@ -108,7 +102,7 @@ async function main(): Promise { resetStorage: false, dbFilename, logger, - onRunLoopFailure: handleRunLoopFailure, + onRunLoopFailure: runLoop.onRunLoopFailure, }); // Interlock: refuse to start a second daemon under the same OCAP_HOME. @@ -130,11 +124,7 @@ async function main(): Promise { let handle: DaemonHandle; try { await kernel.initIdentity(); - if (runLoopFailure) { - throw new Error('Kernel run loop died during startup', { - cause: runLoopFailure, - }); - } + runLoop.assertSurvivedStartup(); await writeFile(pidPath, String(process.pid)); handle = await startDaemon({ @@ -154,7 +144,6 @@ async function main(): Promise { throw error; } - daemonStarted = true; logger.info(`Daemon started. Socket: ${handle.socketPath}`); /** @@ -173,11 +162,9 @@ async function main(): Promise { return shutdownPromise; } - // A failure recorded before there was a daemon to close still has to bring it - // down, now that there is one. - if (runLoopFailure) { - handleRunLoopFailure(runLoopFailure); - } + // Must follow `shutdown`, which a replayed failure calls and which needs + // `handle`. + runLoop.daemonStarted(); process.on('SIGTERM', () => { shutdown('SIGTERM').catch(() => (process.exitCode = 1)); diff --git a/packages/kernel-cli/src/commands/run-loop-failure.test.ts b/packages/kernel-cli/src/commands/run-loop-failure.test.ts index e4a342b633..0cff64d128 100644 --- a/packages/kernel-cli/src/commands/run-loop-failure.test.ts +++ b/packages/kernel-cli/src/commands/run-loop-failure.test.ts @@ -6,10 +6,15 @@ import '@ocap/repo-tools/test-utils/mock-endoify'; import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; import { + makeDaemonRunLoopWiring, makeRunLoopFailureHandler, SHUTDOWN_TIMEOUT_MS, } from './run-loop-failure.ts'; -import type { RunLoopFailureHandlerOptions } from './run-loop-failure.ts'; +import type { + DaemonRunLoopWiring, + DaemonRunLoopWiringOptions, + RunLoopFailureHandlerOptions, +} from './run-loop-failure.ts'; /** * Make a handler over spies, defaulting to "the daemon is up and not shutting @@ -242,24 +247,63 @@ describe('makeRunLoopFailureHandler', () => { expect(exit).toHaveBeenCalledWith(1); }); + // The daemon logs with `appendFileSync`, and the kernel swallows what this + // handler throws, so a failed log would leave a daemon serving a dead kernel. + it('shuts down even when the log transport throws', async () => { + const { handle, shutdown, setExitCode, exit } = makeHandler({ + logger: { + error: vi.fn().mockImplementation(() => { + throw new Error('ENOSPC'); + }), + info: vi.fn(), + }, + }); + + expect(() => handle(new Error('crank exploded'))).not.toThrow(); + await vi.runAllTimersAsync(); + + expect(setExitCode).toHaveBeenCalledWith(1); + expect(shutdown).toHaveBeenCalledWith('run loop failure'); + expect(exit).not.toHaveBeenCalled(); + }); + + // The disk can fill up between the first log and the last. + it('kills the process when a later log transport throws', async () => { + let calls = 0; + const { handle, removePidFile, exit } = makeHandler({ + logger: { + error: vi.fn().mockImplementation(() => { + calls += 1; + if (calls > 1) { + throw new Error('ENOSPC'); + } + }), + info: vi.fn(), + }, + shutdown: vi.fn().mockReturnValue(new Promise(() => undefined)), + }); + + handle(new Error('crank exploded')); + await vi.advanceTimersByTimeAsync(SHUTDOWN_TIMEOUT_MS); + + expect(removePidFile).toHaveBeenCalled(); + expect(exit).toHaveBeenCalledWith(1); + }); + // An unhandled rejection here would be reported as the cause of death instead // of the run loop failure that actually killed the kernel. - it('does not reject when a log transport throws', async () => { - const logger = { - error: vi.fn().mockImplementation(() => { - throw new Error('ENOSPC'); - }), - info: vi.fn(), - }; + it('does not reject when exiting throws', async () => { const onUnhandled = vi.fn(); process.once('unhandledRejection', onUnhandled); const { handle } = makeHandler({ - logger, shutdown: vi.fn().mockRejectedValue(new Error('close failed')), + exit: vi.fn().mockImplementation(() => { + throw new Error('exit refused'); + }), }); - expect(() => handle(new Error('crank exploded'))).toThrow('ENOSPC'); + handle(new Error('crank exploded')); await vi.runAllTimersAsync(); await Promise.resolve(); @@ -267,3 +311,123 @@ describe('makeRunLoopFailureHandler', () => { process.off('unhandledRejection', onUnhandled); }); }); + +/** + * Make the daemon wiring over spies. + * + * @param overrides - Options to replace. + * @returns The wiring and the spies it was built from. + */ +const makeWiring = ( + overrides: Partial = {}, +): { + wiring: DaemonRunLoopWiring; + shutdown: ReturnType; + setExitCode: ReturnType; +} => { + const shutdown = vi.fn().mockResolvedValue(undefined); + const setExitCode = vi.fn(); + const wiring = makeDaemonRunLoopWiring({ + logger: { error: vi.fn(), info: vi.fn() }, + shutdown, + isShuttingDown: () => false, + removePidFile: vi.fn(), + setExitCode, + exit: vi.fn(), + ...overrides, + }); + return { wiring, shutdown, setExitCode }; +}; + +describe('makeDaemonRunLoopWiring', () => { + beforeEach(() => { + vi.useFakeTimers(); + }); + + afterEach(() => { + vi.useRealTimers(); + }); + + it('shuts the daemon down when the run loop dies after startup', async () => { + const { wiring, shutdown } = makeWiring(); + wiring.daemonStarted(); + + wiring.onRunLoopFailure(new Error('crank exploded')); + await vi.runAllTimersAsync(); + + expect(shutdown).toHaveBeenCalledWith('run loop failure'); + }); + + // The kernel can report a death before `startDaemon` has returned. + it('holds a failure that arrives before the daemon has started', () => { + const { wiring, shutdown, setExitCode } = makeWiring(); + + wiring.onRunLoopFailure(new Error('died during startup')); + + expect(shutdown).not.toHaveBeenCalled(); + expect(setExitCode).not.toHaveBeenCalled(); + }); + + it('unwinds startup when the run loop died on the way up', () => { + const { wiring } = makeWiring(); + const failure = new Error('died during startup'); + + wiring.onRunLoopFailure(failure); + + // Only `cause` carries the reason it died. + expect(() => wiring.assertSurvivedStartup()).toThrow( + expect.objectContaining({ + message: 'Kernel run loop died during startup', + cause: failure, + }), + ); + }); + + it('lets startup proceed while the run loop is alive', () => { + const { wiring } = makeWiring(); + + expect(() => wiring.assertSurvivedStartup()).not.toThrow(); + }); + + // A loop that died between startup's check and the daemon coming up would + // otherwise leave it serving RPCs for a dead kernel forever. + it('replays a held failure once there is a daemon to close', async () => { + const { wiring, shutdown, setExitCode } = makeWiring(); + wiring.onRunLoopFailure(new Error('died during startup')); + + wiring.daemonStarted(); + await vi.runAllTimersAsync(); + + expect(shutdown).toHaveBeenCalledWith('run loop failure'); + expect(setExitCode).toHaveBeenCalledWith(1); + }); + + it('does not shut down a daemon whose run loop is alive', async () => { + const { wiring, shutdown } = makeWiring(); + + wiring.daemonStarted(); + await vi.runAllTimersAsync(); + + expect(shutdown).not.toHaveBeenCalled(); + }); + + // Whatever the loop reports afterwards is fallout from the first failure. + it('replays the first failure when several arrive before the daemon starts', async () => { + const logger = { error: vi.fn(), info: vi.fn() }; + const { wiring } = makeWiring({ logger }); + wiring.onRunLoopFailure(new Error('first')); + wiring.onRunLoopFailure(new Error('second')); + + wiring.daemonStarted(); + await vi.runAllTimersAsync(); + + expect(logger.error).toHaveBeenCalledWith( + 'Kernel run loop died; shutting down the daemon.', + expect.stringContaining('first'), + ); + expect(logger.error).not.toHaveBeenCalledWith( + 'Kernel run loop died; shutting down the daemon.', + expect.stringContaining('second'), + ); + }); +}); diff --git a/packages/kernel-cli/src/commands/run-loop-failure.ts b/packages/kernel-cli/src/commands/run-loop-failure.ts index 2c913c5043..13d4a119b8 100644 --- a/packages/kernel-cli/src/commands/run-loop-failure.ts +++ b/packages/kernel-cli/src/commands/run-loop-failure.ts @@ -59,13 +59,29 @@ export function makeRunLoopFailureHandler({ exit, timeoutMs = SHUTDOWN_TIMEOUT_MS, }: RunLoopFailureHandlerOptions): (failure: Error) => void { + // The daemon's transport is `appendFileSync`, so a full disk throws; the kernel + // swallows what this handler throws, so a failed log would otherwise leave the + // daemon up and serving a dead kernel. + const report = ( + level: 'error' | 'info', + message: string, + ...data: string[] + ): void => { + try { + logger[level](message, ...data); + } catch { + // No transport left to report the transport with. + } + }; + return (failure: Error): void => { recordFailure(failure); if (!isStarted()) { // No daemon to close yet. Startup either unwinds at its own check or // replays this failure once there is something to shut down. - logger.error( + report( + 'error', 'Kernel run loop died before the daemon started.', stringify(failure, 0), ); @@ -74,22 +90,25 @@ export function makeRunLoopFailureHandler({ if (isShuttingDown()) { // Expected teardown, not an outage: don't fail a deliberate stop. - logger.info( + report( + 'info', 'Kernel run loop stopped during shutdown.', stringify(failure, 0), ); return; } + setExitCode(1); + // `stringify` rather than `failure.stack`, which omits the cause chain. When // a crank dies and its rollback then fails, the rollback failure is the // outermost message and the error that actually killed the kernel is only // reachable through `cause`. - logger.error( + report( + 'error', 'Kernel run loop died; shutting down the daemon.', stringify(failure, 0), ); - setExitCode(1); // A shutdown that throws would leave the socket gone and the pid file // removed by `shutdown`'s own cleanup, while live vat workers keep the event @@ -103,7 +122,8 @@ export function makeRunLoopFailureHandler({ try { removePidFile(); } catch (rmError) { - logger.error( + report( + 'error', 'Could not remove the pid file before exiting.', stringify(rmError, 0), ); @@ -112,7 +132,8 @@ export function makeRunLoopFailureHandler({ }; const killTimer = setTimeout(() => { - logger.error( + report( + 'error', `Shutdown stalled for ${timeoutMs} ms after run loop failure; exiting now.`, ); exitNow(); @@ -123,16 +144,102 @@ export function makeRunLoopFailureHandler({ () => clearTimeout(killTimer), (shutdownError: unknown) => { clearTimeout(killTimer); - logger.error( + report( + 'error', 'Shutdown after run loop failure failed; exiting now.', stringify(shutdownError, 0), ); exitNow(); }, ) - // Reached only if a handler above throws — a log transport out of disk - // space, say. There is nothing further to do, and an unhandled rejection - // here would be reported as the cause of death instead of the run loop. + // Reached only if a handler above throws, and an unhandled rejection here + // would be reported as the cause of death instead of the run loop. .catch(() => undefined); }; } + +export type DaemonRunLoopWiringOptions = { + logger: FailureLogger; + /** Shut the daemon down. Idempotent; concurrent calls coalesce. */ + shutdown: (reason: string) => Promise; + isShuttingDown: () => boolean; + /** Remove the pid file. Must complete before the process exits. */ + removePidFile: () => void; + setExitCode: (code: number) => void; + exit: (code: number) => void; + timeoutMs?: number; +}; + +export type DaemonRunLoopWiring = { + /** Pass to `makeKernel` as `onRunLoopFailure`. */ + onRunLoopFailure: (failure: Error) => void; + /** @throws If the run loop has already died, to unwind startup. */ + assertSurvivedStartup: () => void; + /** Replays a failure that arrived before there was a daemon to shut down. */ + daemonStarted: () => void; +}; + +/** + * Wire the run loop failure handler to the daemon's lifecycle. + * + * A failure can land before there is a daemon to shut down, so it is held for + * startup's own check and replayed once there is one. Extracted from + * `daemon-entry` because that module shuts the process down as a side effect of + * being imported, which leaves this untestable in place. + * + * @param options - Options bag, forwarded to {@link makeRunLoopFailureHandler} + * apart from the lifecycle state this owns. + * @param options.logger - Where to record the failure. + * @param options.shutdown - Shut the daemon down. Idempotent; calls coalesce. + * @param options.isShuttingDown - Whether a shutdown is already under way. + * @param options.removePidFile - Remove the pid file, synchronously. + * @param options.setExitCode - Set the code the process will exit with. + * @param options.exit - Terminate the process now. + * @param options.timeoutMs - How long the shutdown may take before the process + * is killed. + * @returns The wiring `daemon-entry` hangs off the kernel and its own startup. + */ +export function makeDaemonRunLoopWiring({ + logger, + shutdown, + isShuttingDown, + removePidFile, + setExitCode, + exit, + timeoutMs = SHUTDOWN_TIMEOUT_MS, +}: DaemonRunLoopWiringOptions): DaemonRunLoopWiring { + let failure: Error | undefined; + let started = false; + + const onRunLoopFailure = makeRunLoopFailureHandler({ + logger, + shutdown, + isStarted: () => started, + isShuttingDown, + // Whatever the loop reports next is fallout, including the replay below. + recordFailure: (first) => { + failure ??= first; + }, + removePidFile, + setExitCode, + exit, + timeoutMs, + }); + + return harden({ + onRunLoopFailure, + assertSurvivedStartup: () => { + if (failure) { + throw new Error('Kernel run loop died during startup', { + cause: failure, + }); + } + }, + daemonStarted: () => { + started = true; + if (failure) { + onRunLoopFailure(failure); + } + }, + }); +} From 029380384efdfce85727f3b3b984d146e8d6da9b Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Wed, 5 Aug 2026 20:14:44 +0200 Subject: [PATCH 13/15] fix(ocap-kernel): guard the last ingress points and carry the cause to the panel MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `bringOutYourDead` and `launchSubcluster` both queue work only the run loop consumes, and neither was refused: a peer's reap was acknowledged and never performed, and a launch spawned a worker per vat in the config before rejecting at the bootstrap message, leaking every one of them. The `#runLoopState` comment claiming every ingress point refused work was wrong, and disagreed with `assertRunLoopAlive`'s own doc; it now points there instead. Only `error.message` crossed the wire, so in a double failure the panel showed "...could not be rolled back" and the error that actually killed the kernel was unreachable from the one consumer built to report it. Add `detail` to the failed arm, rendered under the banner's headline. `RpcClient` now includes the struct failures too, so a union mismatch names the branch and key rather than only the union — the field most likely to fail on version skew is now a required union. `run` re-threw the raw value, so a non-`Error` throw was normalized separately here and in `Kernel`, leaving the embedder's handler and `getStatus` describing two distinct objects. Throw the recorded failure and drop the second copy. Deriving the internal state from the wire type caught `detail` missing from `getRunLoopStatus` at compile time. Co-Authored-By: Claude Opus 5 (1M context) --- packages/kernel-rpc-methods/CHANGELOG.md | 5 +++ .../kernel-rpc-methods/src/RpcClient.test.ts | 25 ++++++++++++ packages/kernel-rpc-methods/src/RpcClient.ts | 18 ++++++++- packages/kernel-ui/CHANGELOG.md | 1 + packages/kernel-ui/src/App.test.tsx | 6 ++- .../src/components/RunLoopBanner.test.tsx | 27 ++++++++++++- .../src/components/RunLoopBanner.tsx | 18 +++++++++ packages/ocap-kernel/CHANGELOG.md | 7 +++- packages/ocap-kernel/src/Kernel.test.ts | 31 ++++++++++----- packages/ocap-kernel/src/Kernel.ts | 11 ++---- packages/ocap-kernel/src/KernelQueue.test.ts | 17 ++++++++- packages/ocap-kernel/src/KernelQueue.ts | 38 +++++++++++++------ .../src/remotes/kernel/RemoteHandle.test.ts | 29 ++++++++++++++ .../src/remotes/kernel/RemoteHandle.ts | 4 ++ .../src/rpc/kernel-control/get-status.test.ts | 14 ++++++- packages/ocap-kernel/src/types.ts | 5 ++- .../src/vats/SubclusterManager.test.ts | 16 ++++++++ .../ocap-kernel/src/vats/SubclusterManager.ts | 3 ++ .../src/test-utils/env/mock-kernel.ts | 9 +++++ 19 files changed, 248 insertions(+), 36 deletions(-) diff --git a/packages/kernel-rpc-methods/CHANGELOG.md b/packages/kernel-rpc-methods/CHANGELOG.md index 3e6b845604..2c606b0344 100644 --- a/packages/kernel-rpc-methods/CHANGELOG.md +++ b/packages/kernel-rpc-methods/CHANGELOG.md @@ -7,6 +7,11 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Changed + +- `RpcClient` result-validation errors now include the individual struct failures, not just the top-level message ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) + - A union's own message names only the union, so a reply from a peer built against an older schema was indistinguishable from an ordinary bad value; the failures name the branch and the key + ## [0.6.0] ### Changed diff --git a/packages/kernel-rpc-methods/src/RpcClient.test.ts b/packages/kernel-rpc-methods/src/RpcClient.test.ts index c60cd8085e..2fa63f85d3 100644 --- a/packages/kernel-rpc-methods/src/RpcClient.test.ts +++ b/packages/kernel-rpc-methods/src/RpcClient.test.ts @@ -1,4 +1,5 @@ import type { Logger } from '@metamask/logger'; +import { literal, string, tuple, type, union } from '@metamask/superstruct'; import { jsonrpc2 } from '@metamask/utils'; import { describe, it, vi, expect } from 'vitest'; @@ -61,6 +62,30 @@ describe('RpcClient', () => { ); }); + // A union's own message names only the union, so without the branch failures + // a peer built against an older schema reads as an ordinary bad value. + it('names the mismatched key when a union result fails validation', async () => { + const methods = { + method1: { + method: 'method1', + params: tuple([string()]), + result: union([ + type({ state: literal('running') }), + type({ state: literal('failed'), error: string() }), + ]), + }, + } as unknown as ReturnType; + const client = new RpcClient(methods, vi.fn(), 'test'); + const resultP = client.call('method1', ['test']); + client.handleResponse('test1', { + jsonrpc: jsonrpc2, + id: 'test1', + result: { state: 'failed' }, + }); + + await expect(resultP).rejects.toThrow('error: Expected a string'); + }); + it('should throw an error for invalid responses', async () => { const client = new RpcClient(getMethods(), vi.fn(), 'test'); const resultP = client.call('method1', ['test']); diff --git a/packages/kernel-rpc-methods/src/RpcClient.ts b/packages/kernel-rpc-methods/src/RpcClient.ts index 186b1791e5..6d2f3cb292 100644 --- a/packages/kernel-rpc-methods/src/RpcClient.ts +++ b/packages/kernel-rpc-methods/src/RpcClient.ts @@ -3,6 +3,7 @@ import { makeCounter, stringify } from '@metamask/kernel-utils'; import type { PromiseCallbacks } from '@metamask/kernel-utils'; import { Logger } from '@metamask/logger'; import { assert as assertStruct } from '@metamask/superstruct'; +import type { StructError } from '@metamask/superstruct'; import { isJsonRpcFailure, isJsonRpcSuccess } from '@metamask/utils'; import type { JsonRpcNotification, @@ -152,7 +153,22 @@ export class RpcClient< // `Method` must be a key of `this.#methods`. assertStruct(result, this.#methods[method].result); } catch (error) { - throw new Error(`Invalid result: ${(error as Error).message}`); + // A union's own message names only the union, so which branch mismatched + // and at which key is reachable only through `failures()` — the detail that + // distinguishes a bad value from a peer built against an older schema. + const { message, failures } = error as StructError; + const detail = + typeof failures === 'function' + ? failures() + .map(({ path, message: why }) => + path.length > 0 ? `${path.join('.')}: ${why}` : why, + ) + .filter((why) => why !== message) + .join('; ') + : ''; + throw new Error( + `Invalid result: ${message}${detail ? ` (${detail})` : ''}`, + ); } } diff --git a/packages/kernel-ui/CHANGELOG.md b/packages/kernel-ui/CHANGELOG.md index 0839dc9344..69ae0f2266 100644 --- a/packages/kernel-ui/CHANGELOG.md +++ b/packages/kernel-ui/CHANGELOG.md @@ -10,6 +10,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added - Show a banner when `getStatus` reports the kernel's run loop as failed; the vat and subcluster tables keep rendering their last known contents, so a dead kernel otherwise looks like a healthy idle one ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) + - The banner's details section shows `runLoop.detail`, the whole cause chain: when a crank dies and its rollback then fails, the headline names the rollback and only the chain names what killed the kernel ## [0.5.0] diff --git a/packages/kernel-ui/src/App.test.tsx b/packages/kernel-ui/src/App.test.tsx index 4f7ce60b36..83a6e0c75b 100644 --- a/packages/kernel-ui/src/App.test.tsx +++ b/packages/kernel-ui/src/App.test.tsx @@ -73,7 +73,11 @@ describe('App', () => { vi.mocked(useStatusPolling).mockReturnValue({ vats: [], subclusters: [], - runLoop: { state: 'failed', error: 'crank exploded' }, + runLoop: { + state: 'failed', + error: 'crank exploded', + detail: '{"message":"crank exploded"}', + }, }); const { App } = await import('./App.tsx'); render(); diff --git a/packages/kernel-ui/src/components/RunLoopBanner.test.tsx b/packages/kernel-ui/src/components/RunLoopBanner.test.tsx index 936556b486..0aee16c885 100644 --- a/packages/kernel-ui/src/components/RunLoopBanner.test.tsx +++ b/packages/kernel-ui/src/components/RunLoopBanner.test.tsx @@ -45,7 +45,11 @@ describe('RunLoopBanner', () => { it('announces a dead run loop with the reason it died', () => { mockUsePanelContext.mockReturnValue( makeMockPanelContext( - makeMockStatus({ state: 'failed', error: 'crank exploded' }), + makeMockStatus({ + state: 'failed', + error: 'crank exploded', + detail: '{"message":"crank exploded"}', + }), ), ); @@ -59,6 +63,27 @@ describe('RunLoopBanner', () => { ); }); + // When a crank dies and its rollback then fails, the headline names the + // rollback and only the chain names what killed the kernel. + it('shows the cause chain behind the headline', () => { + mockUsePanelContext.mockReturnValue( + makeMockPanelContext( + makeMockStatus({ + state: 'failed', + error: 'Run loop died and its crank could not be rolled back', + detail: + '{"message":"rollback failed","cause":{"message":"disk gone"}}', + }), + ), + ); + + render(); + + expect(screen.getByTestId('run-loop-failure-detail')).toHaveTextContent( + 'disk gone', + ); + }); + it.each([ { name: 'running', runLoop: { state: 'running' } as const }, { name: 'idle', runLoop: { state: 'idle' } as const }, diff --git a/packages/kernel-ui/src/components/RunLoopBanner.tsx b/packages/kernel-ui/src/components/RunLoopBanner.tsx index 5dd89dbd7f..e7567e5915 100644 --- a/packages/kernel-ui/src/components/RunLoopBanner.tsx +++ b/packages/kernel-ui/src/components/RunLoopBanner.tsx @@ -40,6 +40,24 @@ export const RunLoopBanner: React.FC = () => { > {runLoop.error} + {/* When a crank dies and its rollback then fails, the headline above names + the rollback and only the chain below names what killed the kernel. */} +
+ + + Details + + + 
+          {runLoop.detail}
+
+
); }; diff --git a/packages/ocap-kernel/CHANGELOG.md b/packages/ocap-kernel/CHANGELOG.md index c092129b5c..87dcabb833 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -9,8 +9,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added -- Report run loop health in `KernelStatus.runLoop` (`{ state: 'idle' | 'running' }` or `{ state: 'failed', error }`), exporting `RunLoopStatus`, `RunLoopStatusStruct`, and `OnRunLoopFailure` ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) +- Report run loop health in `KernelStatus.runLoop` (`{ state: 'idle' | 'running' }` or `{ state: 'failed', error, detail }`), exporting `RunLoopStatus`, `RunLoopStatusStruct`, and `OnRunLoopFailure` ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - `idle` means never started; a loop parked on an empty queue reports `running` + - `error` is the failure's message and `detail` its whole cause chain, because only strings cross the wire: when a crank dies and its rollback then fails, the message names the rollback and only the chain names what killed the kernel - **BREAKING:** `runLoop` is required, so `KernelStatus` gains a mandatory property and a `getStatus` reply from a kernel built before this field fails result validation outright. It cannot be made optional: `exactOptional` would leave the type and the validator disagreeing inside a `type()`, and `optional` widens the property to `| undefined`, which an RPC result may not be - Add `onRunLoopFailure` to `Kernel.make` options, called with the error that killed the run loop so an embedder that outlives the kernel can exit or restart ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - Add `fetch`, `Request`, `Headers`, and `Response` to available vat endowments ([#942](https://github.com/MetaMask/ocap-kernel/pull/942)) @@ -48,9 +49,13 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Because the killing item is no longer consumed, a restart re-dequeues it; an item that reliably kills a crank needs `clearState`/`reset` rather than a restart - Store state only — a crank that had already flushed its buffer settled JS-side subscriptions irreversibly - Refuse inbound remote deliveries once the run loop is dead, rolling back without acknowledging them, so the peer retries and gives up instead of waiting on a kernel that will never deliver ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) + - Covers `bringOutYourDead` as well as `message` and `notify`: a reap is queue work too, consumed only by the run loop. The remaining GC arms need no guard, since they only touch refcounts +- Refuse `launchSubcluster` once the run loop is dead ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) + - The bootstrap message can't be queued either way, but the launch reached that point having already spawned a vat worker per entry in the config, none of which its cleanup path tears down - Keep crank bookkeeping consistent when the database misbehaves: `endCrank` settles its `waitForCrank` waiters even if releasing savepoints throws (previously stranding `getStatus`, `stop`, `reset`, `clearStorage`, and the `VatManager`/`SubclusterManager` waiters), `rollbackCrank` forgets its savepoint even if the rollback throws (which otherwise had `endCrank` commit the crank being abandoned), and `createCrankSavepoint` records a name only once the database created it ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - Report the database error when an aborted crank cannot be rolled back, instead of a spurious "no such savepoint" ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - The abort path recorded the rollback only after it succeeded, so a throwing rollback had the run loop try again against the savepoint `rollbackCrank` had already discarded. The second attempt's "no such savepoint" then became the reported cause of death — and since only `error.message` crosses the wire, the real failure reached neither `getStatus` nor the daemon log +- Reject the run loop's promise with the same `Error` its status reports, rather than re-throwing a non-`Error` for the embedder to normalize a second time ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - Deserialize CapData rejections in `Kernel.queueMessage` so vat errors surface as plain `Error` objects to all callers ([#928](https://github.com/MetaMask/ocap-kernel/pull/928)) - Detect peer restart across receiver state loss so the receiving kernel no longer silently drops a restarted peer's `seq=1` messages ([#948](https://github.com/MetaMask/ocap-kernel/pull/948)) - Persist the peer's last-observed incarnation and compare it on every successful handshake; on a detected restart, clear the peer's c-list contributions and reject the promises it was deciding before the new incarnation reuses any erefs diff --git a/packages/ocap-kernel/src/Kernel.test.ts b/packages/ocap-kernel/src/Kernel.test.ts index cf0a19c019..670da38c04 100644 --- a/packages/ocap-kernel/src/Kernel.test.ts +++ b/packages/ocap-kernel/src/Kernel.test.ts @@ -53,10 +53,22 @@ const mocks = vi.hoisted(() => { getRunLoopStatus = vi.fn(() => this.#runLoopFailure - ? { state: 'failed', error: this.#runLoopFailure.message } + ? { + state: 'failed', + error: this.#runLoopFailure.message, + detail: `{"message":"${this.#runLoopFailure.message}"}`, + } : { state: 'running' }, ); + assertRunLoopAlive = vi.fn((what: string) => { + if (this.#runLoopFailure) { + throw new Error(`Kernel run loop died; cannot ${what}`, { + cause: this.#runLoopFailure, + }); + } + }); + stop = vi.fn(); constructor() { @@ -560,6 +572,7 @@ describe('Kernel', () => { expect((await kernel.getStatus()).runLoop).toStrictEqual({ state: 'failed', error: 'died mid-crank', + detail: expect.stringContaining('died mid-crank'), }); }); @@ -580,6 +593,7 @@ describe('Kernel', () => { expect(status.runLoop).toStrictEqual({ state: 'failed', error: 'run loop boom', + detail: expect.stringContaining('run loop boom'), }); // The vats are still in the store, but nothing is delivering to them. expect(status.vats).toHaveLength(1); @@ -599,6 +613,7 @@ describe('Kernel', () => { expect((await kernel.getStatus()).runLoop).toStrictEqual({ state: 'failed', error: 'run loop boom', + detail: expect.stringContaining('run loop boom'), }); }); @@ -998,22 +1013,20 @@ describe('Kernel', () => { expect(gotAReceiver).toBe(false); }); - it('wraps a non-Error run loop failure for the embedder', async () => { + // `run` rejects with the same object its status reports, so re-wrapping here + // would leave the embedder and `getStatus` describing two different errors. + it('hands the embedder the error the run loop died with, unwrapped', async () => { const onRunLoopFailure = vi.fn(); await Kernel.make(mockPlatformServices, mockKernelDatabase, { onRunLoopFailure, }); + const failure = new Error('run loop boom'); - mocks.KernelQueue.lastInstance.killRunLoop( - 'not an error' as unknown as Error, - ); + mocks.KernelQueue.lastInstance.killRunLoop(failure); await waitUntilQuiescent(); expect(onRunLoopFailure).toHaveBeenCalledOnce(); - const [failure] = onRunLoopFailure.mock.calls[0] as [Error]; - expect(failure.message).toBe('not an error'); - // The original value survives, so a thrown non-Error isn't lost. - expect(failure.cause).toBe('not an error'); + expect(onRunLoopFailure.mock.calls[0]?.[0]).toBe(failure); }); // The handler slot returns void, but TypeScript admits anything thenable diff --git a/packages/ocap-kernel/src/Kernel.ts b/packages/ocap-kernel/src/Kernel.ts index e4fafc2e70..912c1f6929 100644 --- a/packages/ocap-kernel/src/Kernel.ts +++ b/packages/ocap-kernel/src/Kernel.ts @@ -315,17 +315,14 @@ export class Kernel { * exit or restart. Deliberately not re-thrown: an unhandled rejection would * take the process down without giving it that chance. * - * @param runLoopError - The error that killed the run loop. + * @param failure - The error that killed the run loop, normalized by + * `KernelQueue.run`, which reports this same object in `getStatus`. */ - #handleRunLoopFailure(runLoopError: unknown): void { + #handleRunLoopFailure(failure: Error): void { this.#logger.error( 'Run loop died; the kernel can no longer process messages and must be restarted:', - runLoopError, + failure, ); - const failure = - runLoopError instanceof Error - ? runLoopError - : new Error(String(runLoopError), { cause: runLoopError }); // Called off a local, not off `this`: `this.#onRunLoopFailure(...)` is a // member call, so a non-arrow handler would receive the whole kernel as its // receiver. The handler's business here is one `Error`. diff --git a/packages/ocap-kernel/src/KernelQueue.test.ts b/packages/ocap-kernel/src/KernelQueue.test.ts index 5ac8c73733..d7beb0e2f1 100644 --- a/packages/ocap-kernel/src/KernelQueue.test.ts +++ b/packages/ocap-kernel/src/KernelQueue.test.ts @@ -225,9 +225,12 @@ describe('KernelQueue', () => { expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ state: 'failed', error: 'crank exploded', + detail: expect.stringContaining('crank exploded'), }); }); + // One normalization, so what `run` rejects with and what the status reports + // are the same object rather than two wrappers that happen to agree. it('reports failed for a non-Error run loop failure', async () => { ( kernelStore.runQueueLength as unknown as MockInstance @@ -238,10 +241,17 @@ describe('KernelQueue', () => { message: {} as KernelMessage, }); const deliver = vi.fn().mockRejectedValue('not an error'); - await expect(kernelQueue.run(deliver)).rejects.toBe('not an error'); + + const failure = await kernelQueue.run(deliver).catch((error) => error); + + expect(failure).toBeInstanceOf(Error); + expect(failure.message).toBe('not an error'); + // The thrown value survives, so it isn't lost to the normalization. + expect(failure.cause).toBe('not an error'); expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ state: 'failed', error: 'not an error', + detail: expect.stringContaining('not an error'), }); }); }); @@ -341,6 +351,9 @@ describe('KernelQueue', () => { state: 'failed', error: 'Run loop died and its crank could not be rolled back: Error: database is gone', + // The headline names the rollback, so only `detail` can carry the error + // that actually killed the kernel to the one consumer that reports it. + detail: expect.stringContaining('crank exploded'), }); }); @@ -372,6 +385,7 @@ describe('KernelQueue', () => { expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ state: 'failed', error: 'database is gone', + detail: expect.stringContaining('database is gone'), }); }); @@ -405,6 +419,7 @@ describe('KernelQueue', () => { expect(kernelQueue.getRunLoopStatus()).toStrictEqual({ state: 'failed', error: 'second crank exploded', + detail: expect.stringContaining('second crank exploded'), }); }); diff --git a/packages/ocap-kernel/src/KernelQueue.ts b/packages/ocap-kernel/src/KernelQueue.ts index 2a4b211e01..4148300ff7 100644 --- a/packages/ocap-kernel/src/KernelQueue.ts +++ b/packages/ocap-kernel/src/KernelQueue.ts @@ -1,5 +1,6 @@ import type { CapData } from '@endo/marshal'; import { makePromiseKit } from '@endo/promise-kit'; +import { stringify } from '@metamask/kernel-utils'; import { processGCActionSet } from './garbage-collection/garbage-collection.ts'; import { kser } from './liveslots/kernel-marshal.ts'; @@ -18,6 +19,10 @@ import type { } from './types.ts'; import { Fail } from './utils/assert.ts'; +type RunLoopState = + | Exclude + | { state: 'failed'; error: Error }; + /** * The kernel's run queue. * @@ -64,14 +69,14 @@ export class KernelQueue { /** * The run loop's state, as one value so that a failure recorded for a loop - * that never started can't be represented. `failed` keeps the whole `Error`; - * only its message crosses the wire. Once failed, the queue is never drained - * again and every ingress point refuses work. + * that never started can't be represented. Once failed, nothing drains the + * queue again; for which ingress points refuse work and why teardown does not, + * see {@link assertRunLoopAlive}. + * + * Derived from the wire type so that a field added to its `failed` arm fails to + * compile until `getRunLoopStatus` produces it. */ - #runLoopState: - | { state: 'idle' } - | { state: 'running' } - | { state: 'failed'; error: Error } = { state: 'idle' }; + #runLoopState: RunLoopState = { state: 'idle' }; /** * Construct a new KernelQueue instance. @@ -95,7 +100,7 @@ export class KernelQueue { * dead — see {@link getRunLoopStatus}. * * @param deliver - A function that delivers an item to the kernel. - * @returns A promise that rejects with the error that killed the run loop. + * @returns A promise that rejects with the `Error` that killed the run loop. */ async run( deliver: (item: RunQueueItem) => Promise, @@ -105,8 +110,9 @@ export class KernelQueue { try { return await this.#runLoop(deliver); } catch (error) { - this.#failRunLoop(error); - throw error; + // The recorded failure rather than the raw throw, so that the embedder's + // handler and `getRunLoopStatus` describe one object rather than two. + throw this.#failRunLoop(error); } } @@ -180,8 +186,9 @@ export class KernelQueue { * are not rescued by this. * * @param error - The error that killed the run loop. + * @returns The failure, as an `Error` whatever was thrown. */ - #failRunLoop(error: unknown): void { + #failRunLoop(error: unknown): Error { const failure = error instanceof Error ? error @@ -198,6 +205,7 @@ export class KernelQueue { ), ); } + return failure; } /** @@ -244,7 +252,13 @@ export class KernelQueue { getRunLoopStatus(): RunLoopStatus { return harden( this.#runLoopState.state === 'failed' - ? { state: 'failed', error: this.#runLoopState.error.message } + ? { + state: 'failed', + error: this.#runLoopState.error.message, + // The message drops the cause chain, and in a double failure it names + // the failed rollback rather than what killed the kernel. + detail: stringify(this.#runLoopState.error, 0), + } : { state: this.#runLoopState.state }, ); } diff --git a/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.test.ts b/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.test.ts index 9a42b13dcd..c14539bc6c 100644 --- a/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.test.ts +++ b/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.test.ts @@ -191,6 +191,35 @@ describe('RemoteHandle', () => { }); }); + // Only the run loop consumes `nextReapAction`, so a dead loop would leave the + // peer's request acknowledged and never performed. + it('refuses an incoming bringOutYourDead when the run loop is dead', async () => { + const remote = makeRemote(); + const delivery = JSON.stringify({ + seq: 1, + method: 'deliver', + params: ['bringOutYourDead'], + }); + const failure = new Error('Kernel run loop died; cannot accept it'); + vi.mocked(mockKernelQueue.assertRunLoopAlive).mockImplementation(() => { + throw failure; + }); + + await expect(remote.handleRemoteMessage(delivery)).rejects.toBe(failure); + expect(mockKernelStore.nextReapAction()).toBeUndefined(); + + // The refusal must not advance the received sequence number, or the peer's + // retry would be discarded as a duplicate. + vi.mocked(mockKernelQueue.assertRunLoopAlive).mockImplementation( + () => undefined, + ); + await remote.handleRemoteMessage(delivery); + expect(mockKernelStore.nextReapAction()).toStrictEqual({ + type: 'bringOutYourDead', + endpointId: remote.remoteId, + }); + }); + // A dead run loop will never deliver the message, and `handleRemoteMessage` // rolls back without advancing the received sequence number, so the peer // retries and gives up rather than being acknowledged by a black hole. diff --git a/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.ts b/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.ts index f0e78aeb8a..d92359b5c0 100644 --- a/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.ts +++ b/packages/ocap-kernel/src/remotes/kernel/RemoteHandle.ts @@ -855,6 +855,10 @@ export class RemoteHandle implements EndpointHandle { break; } case 'bringOutYourDead': { + // Queue work like the arms above: `scheduleReap` is consumed only by the + // run loop, via `nextReapAction`. The other GC arms need no guard — they + // only touch refcounts, which the caller's crank commits by itself. + this.#kernelQueue.assertRunLoopAlive('accept a remote reap request'); this.#kernelStore.scheduleReap(this.remoteId); break; } diff --git a/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts b/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts index 030db09038..6440b1401b 100644 --- a/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts +++ b/packages/ocap-kernel/src/rpc/kernel-control/get-status.test.ts @@ -75,7 +75,10 @@ describe('getStatusHandler', () => { it.each([ { name: 'idle', runLoop: { state: 'idle' } }, { name: 'running', runLoop: { state: 'running' } }, - { name: 'failed', runLoop: { state: 'failed', error: 'boom' } }, + { + name: 'failed', + runLoop: { state: 'failed', error: 'boom', detail: '{}' }, + }, ])('accepts $name', ({ runLoop }) => { expect(is(makeStatus(runLoop), KernelStatusStruct)).toBe(true); }); @@ -83,7 +86,14 @@ describe('getStatusHandler', () => { it.each([ { name: 'an unknown state', runLoop: { state: 'wedged' } }, { name: 'failed without an error', runLoop: { state: 'failed' } }, - { name: 'a non-string error', runLoop: { state: 'failed', error: 1 } }, + { + name: 'failed without a detail', + runLoop: { state: 'failed', error: 'boom' }, + }, + { + name: 'a non-string error', + runLoop: { state: 'failed', error: 1, detail: '{}' }, + }, { name: 'a bare string', runLoop: 'failed' }, ])('rejects $name', ({ runLoop }) => { expect(is(makeStatus(runLoop), KernelStatusStruct)).toBe(false); diff --git a/packages/ocap-kernel/src/types.ts b/packages/ocap-kernel/src/types.ts index 7e16078398..aeefa76800 100644 --- a/packages/ocap-kernel/src/types.ts +++ b/packages/ocap-kernel/src/types.ts @@ -776,7 +776,10 @@ const RemoteCommsConnectedStruct = object({ export const RunLoopStatusStruct = union([ type({ state: literal('idle') }), type({ state: literal('running') }), - type({ state: literal('failed'), error: string() }), + // Two strings because one cannot be both: `error` is the message, `detail` the + // cause chain. When a crank dies and its rollback then fails, the message names + // the rollback and only the chain names what killed the kernel. + type({ state: literal('failed'), error: string(), detail: string() }), ]); export type RunLoopStatus = Infer; diff --git a/packages/ocap-kernel/src/vats/SubclusterManager.test.ts b/packages/ocap-kernel/src/vats/SubclusterManager.test.ts index 43c15657cf..f46a7bd499 100644 --- a/packages/ocap-kernel/src/vats/SubclusterManager.test.ts +++ b/packages/ocap-kernel/src/vats/SubclusterManager.test.ts @@ -69,6 +69,7 @@ describe('SubclusterManager', () => { mockKernelQueue = { waitForCrank: vi.fn().mockResolvedValue(undefined), + assertRunLoopAlive: vi.fn(), } as unknown as Mocked; mockVatManager = { @@ -127,6 +128,21 @@ describe('SubclusterManager', () => { }); }); + // The launch fails at the bootstrap message either way; only refusing up + // front keeps it from leaking a spawned worker per vat in the config. + it('refuses to launch when the run loop has died', async () => { + vi.mocked(mockKernelQueue.assertRunLoopAlive).mockImplementation(() => { + throw new Error('Kernel run loop died; cannot launch a subcluster'); + }); + + await expect( + subclusterManager.launchSubcluster(createMockClusterConfig()), + ).rejects.toThrow('Kernel run loop died; cannot launch a subcluster'); + + expect(mockVatManager.launchVat).not.toHaveBeenCalled(); + expect(mockKernelStore.addSubcluster).not.toHaveBeenCalled(); + }); + it('launches subcluster with multiple vats', async () => { const config: ClusterConfig = { bootstrap: 'alice', diff --git a/packages/ocap-kernel/src/vats/SubclusterManager.ts b/packages/ocap-kernel/src/vats/SubclusterManager.ts index a32ac7a5d4..ebbcc384e1 100644 --- a/packages/ocap-kernel/src/vats/SubclusterManager.ts +++ b/packages/ocap-kernel/src/vats/SubclusterManager.ts @@ -116,6 +116,9 @@ export class SubclusterManager { { isSystem = false }: { isSystem?: boolean } = {}, ): Promise { await this.#kernelQueue.waitForCrank(); + // It would fail at the bootstrap message anyway, but only refusing here fails + // before spawning a worker per vat, which the catch below leaks. + this.#kernelQueue.assertRunLoopAlive('launch a subcluster'); isClusterConfig(config) || Fail`invalid cluster config`; if (!config.vats[config.bootstrap]) { Fail`invalid bootstrap vat name ${config.bootstrap}`; diff --git a/packages/repo-tools/src/test-utils/env/mock-kernel.ts b/packages/repo-tools/src/test-utils/env/mock-kernel.ts index d38ec0c253..1744c09ab0 100644 --- a/packages/repo-tools/src/test-utils/env/mock-kernel.ts +++ b/packages/repo-tools/src/test-utils/env/mock-kernel.ts @@ -8,6 +8,7 @@ import { exactOptional, array, type, + union, } from '@metamask/superstruct'; import { vi } from 'vitest'; @@ -44,6 +45,12 @@ export const setupOcapKernelMock = (): { const KRefStruct = define('KRef', () => isKRefMock); + const RunLoopStatusStruct = union([ + type({ state: literal('idle') }), + type({ state: literal('running') }), + type({ state: literal('failed'), error: string(), detail: string() }), + ]); + return { isVatId: () => isVatIdMock, isVatConfig: () => isVatConfigMock, @@ -63,6 +70,7 @@ export const setupOcapKernelMock = (): { slots: array(string()), }), ClusterConfigStruct, + RunLoopStatusStruct, KernelStatusStruct: type({ subclusters: array(SubclusterStruct), vats: array( @@ -72,6 +80,7 @@ export const setupOcapKernelMock = (): { subclusterId: SubclusterIdStruct, }), ), + runLoop: RunLoopStatusStruct, }), KernelSendMessageStruct: object({ id: literal('v0'), From 3af30a694c0a87c69939adaaf1ecfabc49d1e6ea Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Wed, 5 Aug 2026 20:55:18 +0200 Subject: [PATCH 14/15] fix(kernel-cli): tear the kernel down when startup aborts, and terminate MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The startup abort this branch added unwound through cleanup that produced the exact orphan the rest of it exists to prevent. `kernel.stop()` was fired and forgotten, so the synchronous `kernelDatabase.close()` on the next line landed first; `stop` then threw on `recordLastActiveTime`, two steps short of `terminateAll`, and its rejection went to a bare `.catch`. `Kernel.make` starts a worker thread per persisted vat before the run loop runs, so there are live workers by the time a death can be reported — and a worker thread keeps the parent's event loop open, so `main().catch` setting `process.exitCode` never took effect. Socket gone, pid file already removed: an orphan invisible to both start-time interlocks, which is what the changelog claimed this branch fixed. Await the stop, bounded, before closing the database, then exit rather than setting a code. The bound is not optional: `stop` waits for the current crank, and a loop that died mid-crank may never end it. Extracted as `cleanUpFailedStartup` for the same reason `makeDaemonRunLoopWiring` was — `daemon-entry` shuts the process down as a side effect of being imported, so nothing in it can be tested in place. `process.exit` in `main().catch` also covers the already-running interlock, which throws after `makeKernel` has opened the database and launched every persisted vat, and does no cleanup at all. Hoist `report` to module scope so both paths log best-effort; the transport is `appendFileSync`, and a full disk must not take the cleanup with it. Co-Authored-By: Claude Opus 5 (1M context) --- packages/kernel-cli/CHANGELOG.md | 1 + .../kernel-cli/src/commands/daemon-entry.ts | 27 ++- .../src/commands/run-loop-failure.test.ts | 165 ++++++++++++++++++ .../src/commands/run-loop-failure.ts | 131 ++++++++++++-- 4 files changed, 300 insertions(+), 24 deletions(-) diff --git a/packages/kernel-cli/CHANGELOG.md b/packages/kernel-cli/CHANGELOG.md index 3fec5b0c49..37f5f939f7 100644 --- a/packages/kernel-cli/CHANGELOG.md +++ b/packages/kernel-cli/CHANGELOG.md @@ -25,6 +25,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Without these, silent daemon deaths under `stdio: 'ignore'` (the CLI's default spawn mode) left no trace in the log; the operator saw only that the daemon was gone. Every terminating path now leaves at least one line. - The daemon logs the failure and shuts down with a non-zero exit code when the kernel's run loop dies, instead of staying up with a socket that answers RPCs for a kernel that processes nothing ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - A death during startup aborts `daemon start` rather than publishing a socket and pid file for a dead kernel + - An aborted startup stops the kernel before closing the database, bounded at 10 seconds, and then terminates the process. `Kernel.make` launches a worker thread per persisted vat, and `stop` reaches those workers only after writing the last-active timestamp, so closing the database first made that write throw and left the workers running — and a live worker thread keeps the event loop open, so an exit code alone never took effect - The shutdown is bounded at 10 seconds and exits immediately if it throws, removing the pid file first. A `kernel.stop()` that throws would otherwise leave an orphan holding `kernel.sqlite` with its socket gone and its pid file already cleaned up, invisible to both start-time interlocks; one that merely stalls stays visible to the pid interlock but is an orphan all the same - Failures are logged with their `cause` chain, so a run loop death reported through a failed crank rollback still names the error that actually killed the kernel - Logging is best-effort: the transport is `appendFileSync`, so a full disk would otherwise throw and take the shutdown with it, leaving up the daemon this exists to bring down diff --git a/packages/kernel-cli/src/commands/daemon-entry.ts b/packages/kernel-cli/src/commands/daemon-entry.ts index 9c7ca44e9c..3c6691ff88 100644 --- a/packages/kernel-cli/src/commands/daemon-entry.ts +++ b/packages/kernel-cli/src/commands/daemon-entry.ts @@ -9,7 +9,10 @@ import { appendFileSync, rmSync } from 'node:fs'; import { mkdir, readFile, rm, writeFile } from 'node:fs/promises'; import { join } from 'node:path'; -import { makeDaemonRunLoopWiring } from './run-loop-failure.ts'; +import { + cleanUpFailedStartup, + makeDaemonRunLoopWiring, +} from './run-loop-failure.ts'; import { getOcapHome } from '../ocap-home.ts'; import { isProcessAlive } from '../utils.ts'; @@ -66,7 +69,13 @@ main().catch((error) => { // this can be read; `stringify` keeps the `cause` chain that `String` drops. logger.error('Daemon fatal', stringify(error, 0)); process.stderr.write(`Daemon fatal: ${String(error)}\n`); - process.exitCode = 1; + // Not `process.exitCode`: a kernel that got as far as launching vats holds + // live worker threads, and those keep the event loop running, so a code alone + // would leave the daemon up with no socket and no pid file — an orphan + // neither interlock can see. Both writes above are synchronous, so nothing is + // lost by exiting here. + // eslint-disable-next-line n/no-process-exit -- a daemon that cannot start must not linger + process.exit(1); }); /** @@ -134,13 +143,13 @@ async function main(): Promise { onShutdown: async () => shutdown('RPC shutdown'), }); } catch (error) { - try { - kernel.stop().catch(() => undefined); - kernelDatabase.close(); - } catch { - // Best-effort cleanup. - } - rm(pidPath, { force: true }).catch(() => undefined); + await cleanUpFailedStartup({ + logger, + stopKernel: async () => kernel.stop(), + closeDatabase: () => kernelDatabase.close(), + // eslint-disable-next-line n/no-sync -- must finish before process.exit + removePidFile: () => rmSync(pidPath, { force: true }), + }); throw error; } diff --git a/packages/kernel-cli/src/commands/run-loop-failure.test.ts b/packages/kernel-cli/src/commands/run-loop-failure.test.ts index 0cff64d128..2e2fac0618 100644 --- a/packages/kernel-cli/src/commands/run-loop-failure.test.ts +++ b/packages/kernel-cli/src/commands/run-loop-failure.test.ts @@ -6,6 +6,7 @@ import '@ocap/repo-tools/test-utils/mock-endoify'; import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; import { + cleanUpFailedStartup, makeDaemonRunLoopWiring, makeRunLoopFailureHandler, SHUTDOWN_TIMEOUT_MS, @@ -13,6 +14,7 @@ import { import type { DaemonRunLoopWiring, DaemonRunLoopWiringOptions, + FailedStartupCleanupOptions, RunLoopFailureHandlerOptions, } from './run-loop-failure.ts'; @@ -312,6 +314,169 @@ describe('makeRunLoopFailureHandler', () => { }); }); +/** + * Make the cleanup's options over spies, defaulting to a kernel that stops + * cleanly, so each test overrides only what it is about. + * + * @param overrides - Options to replace. + * @returns The options, with their spies reachable. + */ +const makeCleanupOptions = ( + overrides: Partial = {}, +): FailedStartupCleanupOptions & { + logger: { error: ReturnType; info: ReturnType }; +} => ({ + logger: { error: vi.fn(), info: vi.fn() }, + stopKernel: vi.fn().mockResolvedValue(undefined), + closeDatabase: vi.fn(), + removePidFile: vi.fn(), + ...overrides, +}); + +describe('cleanUpFailedStartup', () => { + beforeEach(() => { + vi.useFakeTimers(); + }); + + afterEach(() => { + vi.useRealTimers(); + }); + + // `stop` terminates the vat workers only after writing the last-active + // timestamp, so a database closed first makes that write throw and the worker + // threads that hold the event loop open survive. + it('waits for the kernel to stop before closing the database', async () => { + const order: string[] = []; + const options = makeCleanupOptions({ + stopKernel: async () => { + await Promise.resolve(); + order.push('stop'); + }, + closeDatabase: () => order.push('close'), + removePidFile: () => order.push('removePid'), + }); + + await cleanUpFailedStartup(options); + + expect(order).toStrictEqual(['stop', 'close', 'removePid']); + }); + + it('gives up on a kernel that never stops', async () => { + const options = makeCleanupOptions({ + stopKernel: vi.fn().mockReturnValue(new Promise(() => undefined)), + }); + + const cleanup = cleanUpFailedStartup(options); + await vi.advanceTimersByTimeAsync(SHUTDOWN_TIMEOUT_MS); + await cleanup; + + expect(options.logger.error).toHaveBeenCalledWith( + `Kernel did not stop within ${SHUTDOWN_TIMEOUT_MS} ms during startup cleanup.`, + ); + expect(options.closeDatabase).toHaveBeenCalled(); + expect(options.removePidFile).toHaveBeenCalled(); + }); + + it('waits the full timeout before giving up on the kernel', async () => { + const options = makeCleanupOptions({ + stopKernel: vi.fn().mockReturnValue(new Promise(() => undefined)), + timeoutMs: 5_000, + }); + + const cleanup = cleanUpFailedStartup(options); + await vi.advanceTimersByTimeAsync(4_999); + expect(options.closeDatabase).not.toHaveBeenCalled(); + + await vi.advanceTimersByTimeAsync(1); + await cleanup; + + expect(options.closeDatabase).toHaveBeenCalled(); + }); + + it('closes the database when the kernel could not be stopped', async () => { + const options = makeCleanupOptions({ + stopKernel: vi.fn().mockRejectedValue(new Error('crank never ended')), + }); + + await cleanUpFailedStartup(options); + + expect(options.logger.error).toHaveBeenCalledWith( + 'Could not stop the kernel during startup cleanup.', + expect.stringContaining('crank never ended'), + ); + expect(options.closeDatabase).toHaveBeenCalled(); + expect(options.removePidFile).toHaveBeenCalled(); + }); + + // A `stop` that ran to completion closed the database itself, so the second + // close throwing is the expected case and must not strand the pid file. + it('removes the pid file when closing the database throws', async () => { + const options = makeCleanupOptions({ + closeDatabase: () => { + throw new Error('database is not open'); + }, + }); + + await cleanUpFailedStartup(options); + + expect(options.removePidFile).toHaveBeenCalled(); + }); + + it('logs a pid file that could not be removed', async () => { + const options = makeCleanupOptions({ + removePidFile: () => { + throw new Error('EPERM'); + }, + }); + + // Rejecting here would take the startup error with it, replacing the reason + // the daemon could not start with the reason its cleanup could not finish. + await cleanUpFailedStartup(options); + + expect(options.logger.error).toHaveBeenCalledWith( + 'Could not remove the pid file during startup cleanup.', + expect.stringContaining('EPERM'), + ); + }); + + // Only `cause` carries the reason the kernel would not stop. + it('logs the cause chain of a stop that failed', async () => { + const options = makeCleanupOptions({ + stopKernel: vi + .fn() + .mockRejectedValue( + new Error('could not stop', { cause: new Error('database is gone') }), + ), + }); + + await cleanUpFailedStartup(options); + + expect(options.logger.error).toHaveBeenCalledWith( + 'Could not stop the kernel during startup cleanup.', + expect.stringContaining('database is gone'), + ); + }); + + // The daemon logs with `appendFileSync`, so a full disk throws, and cleanup is + // the last thing standing between a failed startup and an orphan. + it('cleans up even when the log transport throws', async () => { + const options = makeCleanupOptions({ + logger: { + error: vi.fn().mockImplementation(() => { + throw new Error('ENOSPC'); + }), + info: vi.fn(), + }, + stopKernel: vi.fn().mockRejectedValue(new Error('crank never ended')), + }); + + await cleanUpFailedStartup(options); + + expect(options.closeDatabase).toHaveBeenCalled(); + expect(options.removePidFile).toHaveBeenCalled(); + }); +}); + /** * Make the daemon wiring over spies. * diff --git a/packages/kernel-cli/src/commands/run-loop-failure.ts b/packages/kernel-cli/src/commands/run-loop-failure.ts index 13d4a119b8..1015506118 100644 --- a/packages/kernel-cli/src/commands/run-loop-failure.ts +++ b/packages/kernel-cli/src/commands/run-loop-failure.ts @@ -7,6 +7,31 @@ export const SHUTDOWN_TIMEOUT_MS = 10_000; /** The subset of `Logger` this handler needs. */ type FailureLogger = Pick; +/** + * Log without letting the transport's own failure escape. + * + * The daemon's transport is `appendFileSync`, so a full disk throws; the kernel + * swallows what the failure handler throws, so a failed log would otherwise + * leave the daemon up and serving a dead kernel. + * + * @param logger - Where to record the message. + * @param level - The severity to record it at. + * @param message - The message. + * @param data - Additional detail, already stringified. + */ +function report( + logger: FailureLogger, + level: 'error' | 'info', + message: string, + ...data: string[] +): void { + try { + logger[level](message, ...data); + } catch { + // No transport left to report the transport with. + } +} + export type RunLoopFailureHandlerOptions = { logger: FailureLogger; /** Shut the daemon down. Idempotent; concurrent calls coalesce. */ @@ -59,21 +84,6 @@ export function makeRunLoopFailureHandler({ exit, timeoutMs = SHUTDOWN_TIMEOUT_MS, }: RunLoopFailureHandlerOptions): (failure: Error) => void { - // The daemon's transport is `appendFileSync`, so a full disk throws; the kernel - // swallows what this handler throws, so a failed log would otherwise leave the - // daemon up and serving a dead kernel. - const report = ( - level: 'error' | 'info', - message: string, - ...data: string[] - ): void => { - try { - logger[level](message, ...data); - } catch { - // No transport left to report the transport with. - } - }; - return (failure: Error): void => { recordFailure(failure); @@ -81,6 +91,7 @@ export function makeRunLoopFailureHandler({ // No daemon to close yet. Startup either unwinds at its own check or // replays this failure once there is something to shut down. report( + logger, 'error', 'Kernel run loop died before the daemon started.', stringify(failure, 0), @@ -91,6 +102,7 @@ export function makeRunLoopFailureHandler({ if (isShuttingDown()) { // Expected teardown, not an outage: don't fail a deliberate stop. report( + logger, 'info', 'Kernel run loop stopped during shutdown.', stringify(failure, 0), @@ -105,6 +117,7 @@ export function makeRunLoopFailureHandler({ // outermost message and the error that actually killed the kernel is only // reachable through `cause`. report( + logger, 'error', 'Kernel run loop died; shutting down the daemon.', stringify(failure, 0), @@ -123,6 +136,7 @@ export function makeRunLoopFailureHandler({ removePidFile(); } catch (rmError) { report( + logger, 'error', 'Could not remove the pid file before exiting.', stringify(rmError, 0), @@ -133,6 +147,7 @@ export function makeRunLoopFailureHandler({ const killTimer = setTimeout(() => { report( + logger, 'error', `Shutdown stalled for ${timeoutMs} ms after run loop failure; exiting now.`, ); @@ -145,6 +160,7 @@ export function makeRunLoopFailureHandler({ (shutdownError: unknown) => { clearTimeout(killTimer); report( + logger, 'error', 'Shutdown after run loop failure failed; exiting now.', stringify(shutdownError, 0), @@ -158,6 +174,91 @@ export function makeRunLoopFailureHandler({ }; } +export type FailedStartupCleanupOptions = { + logger: FailureLogger; + /** Stop the kernel, terminating the vat workers it launched. */ + stopKernel: () => Promise; + /** Close the kernel database. */ + closeDatabase: () => void; + /** Remove the pid file. Must complete before the process exits. */ + removePidFile: () => void; + /** How long the kernel may take to stop. Defaults to {@link SHUTDOWN_TIMEOUT_MS}. */ + timeoutMs?: number; +}; + +/** + * Tear down a kernel that startup could not finish bringing up. + * + * `Kernel.make` launches a worker thread per persisted vat before the run loop + * starts, so by the time startup can fail there are usually live workers, and a + * worker thread keeps the parent's event loop running. Nothing here can be + * fired and forgotten: `stop` is what terminates those workers, and it only + * reaches them after writing the last-active timestamp, so closing the database + * first makes that write throw and the workers survive. The caller is expected + * to terminate the process afterwards. + * + * @param options - Options bag. + * @param options.logger - Where to record what could not be cleaned up. + * @param options.stopKernel - Stop the kernel, terminating its vat workers. + * @param options.closeDatabase - Close the kernel database. + * @param options.removePidFile - Remove the pid file, synchronously. + * @param options.timeoutMs - How long the kernel may take to stop. + */ +export async function cleanUpFailedStartup({ + logger, + stopKernel, + closeDatabase, + removePidFile, + timeoutMs = SHUTDOWN_TIMEOUT_MS, +}: FailedStartupCleanupOptions): Promise { + // Bounded: `stop` waits for the current crank first, and a run loop that died + // mid-crank may never end it. + let giveUpTimer: ReturnType | undefined; + try { + await Promise.race([ + stopKernel(), + new Promise((resolve) => { + giveUpTimer = setTimeout(() => { + report( + logger, + 'error', + `Kernel did not stop within ${timeoutMs} ms during startup cleanup.`, + ); + resolve(); + }, timeoutMs); + }), + ]); + } catch (stopError) { + report( + logger, + 'error', + 'Could not stop the kernel during startup cleanup.', + stringify(stopError, 0), + ); + } finally { + clearTimeout(giveUpTimer); + } + + try { + closeDatabase(); + } catch { + // A `stop` that ran to completion closed the database itself, which is the + // expected case rather than a fault. Nothing to salvage either way: the + // process exits next, which releases the file lock regardless. + } + + try { + removePidFile(); + } catch (rmError) { + report( + logger, + 'error', + 'Could not remove the pid file during startup cleanup.', + stringify(rmError, 0), + ); + } +} + export type DaemonRunLoopWiringOptions = { logger: FailureLogger; /** Shut the daemon down. Idempotent; concurrent calls coalesce. */ From b5c129d1040286845f4befa580b2fe16b94cc901 Mon Sep 17 00:00:00 2001 From: Dimitris Marlagkoutsos Date: Wed, 5 Aug 2026 21:18:32 +0200 Subject: [PATCH 15/15] fix(kernel-cli): log best-effort in front of every fatal exit MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `main().catch` logged unguarded before the `process.exit(1)` the previous commit added, and the daemon's transport is `appendFileSync`, so a full disk threw and that exit was never reached. The process still died, but only by accident: the throw escaped to `unhandledRejection`, whose handler logs too and so threw again, and Node aborts when its own exception handler fails. Exit code 7 rather than 1, and the `exit` fingerprint — the last-ditch record #966 added — lost with it. Verified both the old path and the fix against a worker thread standing in for a vat. The four fatal handlers had the same shape for the same reason, each logging in front of its own exit. `report` already existed for exactly this and was already used on every run-loop failure path; export it as `logBestEffort` rather than write a second one, and put it in front of all five exits. Co-Authored-By: Claude Opus 5 (1M context) --- packages/kernel-cli/CHANGELOG.md | 9 +++--- .../kernel-cli/src/commands/daemon-entry.ts | 31 +++++++++++++------ .../src/commands/run-loop-failure.test.ts | 29 +++++++++++++++++ .../src/commands/run-loop-failure.ts | 28 +++++++++-------- 4 files changed, 70 insertions(+), 27 deletions(-) diff --git a/packages/kernel-cli/CHANGELOG.md b/packages/kernel-cli/CHANGELOG.md index 37f5f939f7..e09095da01 100644 --- a/packages/kernel-cli/CHANGELOG.md +++ b/packages/kernel-cli/CHANGELOG.md @@ -24,11 +24,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Daemon fatal-path visibility: `daemon-entry` now installs handlers for `uncaughtException`, `unhandledRejection`, `SIGHUP`, and `exit` that append a synchronous fingerprint line to `daemon.log` before terminating ([#966](https://github.com/MetaMask/ocap-kernel/pull/966)) - Without these, silent daemon deaths under `stdio: 'ignore'` (the CLI's default spawn mode) left no trace in the log; the operator saw only that the daemon was gone. Every terminating path now leaves at least one line. - The daemon logs the failure and shuts down with a non-zero exit code when the kernel's run loop dies, instead of staying up with a socket that answers RPCs for a kernel that processes nothing ([#1005](https://github.com/MetaMask/ocap-kernel/pull/1005)) - - A death during startup aborts `daemon start` rather than publishing a socket and pid file for a dead kernel - - An aborted startup stops the kernel before closing the database, bounded at 10 seconds, and then terminates the process. `Kernel.make` launches a worker thread per persisted vat, and `stop` reaches those workers only after writing the last-active timestamp, so closing the database first made that write throw and left the workers running — and a live worker thread keeps the event loop open, so an exit code alone never took effect - - The shutdown is bounded at 10 seconds and exits immediately if it throws, removing the pid file first. A `kernel.stop()` that throws would otherwise leave an orphan holding `kernel.sqlite` with its socket gone and its pid file already cleaned up, invisible to both start-time interlocks; one that merely stalls stays visible to the pid interlock but is an orphan all the same - - Failures are logged with their `cause` chain, so a run loop death reported through a failed crank rollback still names the error that actually killed the kernel - - Logging is best-effort: the transport is `appendFileSync`, so a full disk would otherwise throw and take the shutdown with it, leaving up the daemon this exists to bring down + - A death during startup aborts `daemon start` instead of publishing a socket and pid file for a dead kernel + - Shutdown is bounded at 10 seconds and terminates the process either way, removing the pid file first. Live vat worker threads hold the event loop open, so an exit code alone never took effect, leaving an orphan on `kernel.sqlite` that neither start-time interlock could see + - Failures carry their `cause` chain, so a death reported through a failed crank rollback still names the error that killed the kernel + - Logging in front of a shutdown or `process.exit` is best-effort, the fatal handlers included: the transport is `appendFileSync`, so a full disk would otherwise take the termination with it ## [0.1.0] diff --git a/packages/kernel-cli/src/commands/daemon-entry.ts b/packages/kernel-cli/src/commands/daemon-entry.ts index 3c6691ff88..b4c8d69406 100644 --- a/packages/kernel-cli/src/commands/daemon-entry.ts +++ b/packages/kernel-cli/src/commands/daemon-entry.ts @@ -11,6 +11,7 @@ import { join } from 'node:path'; import { cleanUpFailedStartup, + logBestEffort, makeDaemonRunLoopWiring, } from './run-loop-failure.ts'; import { getOcapHome } from '../ocap-home.ts'; @@ -65,15 +66,23 @@ const logger = new Logger({ installFatalHandlers(); main().catch((error) => { + // Best-effort, because the exit below is downstream of it: a throwing + // transport would otherwise escape to `unhandledRejection`, whose handler logs + // too and so throws again, leaving the process to die only because Node aborts + // when its own exception handler fails — code 7, and not even the `exit` + // fingerprint survives that. // stderr is `ignore` under the CLI spawner, so the log file is the only place // this can be read; `stringify` keeps the `cause` chain that `String` drops. - logger.error('Daemon fatal', stringify(error, 0)); - process.stderr.write(`Daemon fatal: ${String(error)}\n`); + logBestEffort(logger, 'error', 'Daemon fatal', stringify(error, 0)); + try { + process.stderr.write(`Daemon fatal: ${String(error)}\n`); + } catch { + // A closed stderr must not preempt the exit either. + } // Not `process.exitCode`: a kernel that got as far as launching vats holds // live worker threads, and those keep the event loop running, so a code alone // would leave the daemon up with no socket and no pid file — an orphan - // neither interlock can see. Both writes above are synchronous, so nothing is - // lost by exiting here. + // neither interlock can see. // eslint-disable-next-line n/no-process-exit -- a daemon that cannot start must not linger process.exit(1); }); @@ -233,7 +242,11 @@ function makeFileTransport(logFilePath: string, minLevel: LogLevelName) { * file transport we're using here is `appendFileSync` under the * hood, so `logger.error(...)` from inside a fatal handler flushes * to disk before the process exits — no separate sync-write path - * is required. + * is required. That same `appendFileSync` throws on a full disk, + * though, and here the log runs *before* the `process.exit` that + * terminates the vat workers holding the event loop open, so every + * one of these logs best-effort: the line is worth less than the + * exit it would otherwise block. * * Handlers registered: * @@ -255,19 +268,19 @@ function makeFileTransport(logFilePath: string, minLevel: LogLevelName) { function installFatalHandlers(): void { /* eslint-disable n/no-process-exit -- fatal handlers must terminate deterministically */ process.on('uncaughtException', (error: unknown) => { - logger.error('Uncaught exception', stringify(error, 0)); + logBestEffort(logger, 'error', 'Uncaught exception', stringify(error, 0)); process.exit(1); }); process.on('unhandledRejection', (reason: unknown) => { - logger.error('Unhandled rejection', stringify(reason, 0)); + logBestEffort(logger, 'error', 'Unhandled rejection', stringify(reason, 0)); process.exit(1); }); process.on('SIGHUP', () => { - logger.error('SIGHUP received; exiting.'); + logBestEffort(logger, 'error', 'SIGHUP received; exiting.'); process.exit(0); }); process.on('exit', (code) => { - logger.error(`Process exiting (code=${code}).`); + logBestEffort(logger, 'error', `Process exiting (code=${code}).`); }); /* eslint-enable n/no-process-exit */ } diff --git a/packages/kernel-cli/src/commands/run-loop-failure.test.ts b/packages/kernel-cli/src/commands/run-loop-failure.test.ts index 2e2fac0618..31f5b1e56d 100644 --- a/packages/kernel-cli/src/commands/run-loop-failure.test.ts +++ b/packages/kernel-cli/src/commands/run-loop-failure.test.ts @@ -7,6 +7,7 @@ import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; import { cleanUpFailedStartup, + logBestEffort, makeDaemonRunLoopWiring, makeRunLoopFailureHandler, SHUTDOWN_TIMEOUT_MS, @@ -64,6 +65,34 @@ const makeHandler = ( }; }; +// `daemon-entry` calls this in front of every `process.exit` it owns, and that +// exit is the only thing that terminates live vat workers. +describe('logBestEffort', () => { + it('records the message', () => { + const logger = { error: vi.fn(), info: vi.fn() }; + + logBestEffort(logger, 'error', 'Daemon fatal', 'the detail'); + + expect(logger.error).toHaveBeenCalledWith('Daemon fatal', 'the detail'); + }); + + it.each(['error', 'info'] as const)( + 'swallows a %s transport that throws', + (level) => { + const logger = { + error: vi.fn().mockImplementation(() => { + throw new Error('ENOSPC'); + }), + info: vi.fn().mockImplementation(() => { + throw new Error('ENOSPC'); + }), + }; + + expect(() => logBestEffort(logger, level, 'Daemon fatal')).not.toThrow(); + }, + ); +}); + describe('makeRunLoopFailureHandler', () => { beforeEach(() => { vi.useFakeTimers(); diff --git a/packages/kernel-cli/src/commands/run-loop-failure.ts b/packages/kernel-cli/src/commands/run-loop-failure.ts index 1015506118..bbd352bc87 100644 --- a/packages/kernel-cli/src/commands/run-loop-failure.ts +++ b/packages/kernel-cli/src/commands/run-loop-failure.ts @@ -10,16 +10,18 @@ type FailureLogger = Pick; /** * Log without letting the transport's own failure escape. * - * The daemon's transport is `appendFileSync`, so a full disk throws; the kernel - * swallows what the failure handler throws, so a failed log would otherwise - * leave the daemon up and serving a dead kernel. + * The daemon's transport is `appendFileSync`, so a full disk throws. Every + * caller is on a path where that throw would cost more than the lost line: the + * kernel swallows what the failure handler throws, so a daemon serving a dead + * kernel would stay up, and in the fatal handlers the log sits in front of the + * `process.exit` that is the only thing terminating live vat workers. * * @param logger - Where to record the message. * @param level - The severity to record it at. * @param message - The message. * @param data - Additional detail, already stringified. */ -function report( +export function logBestEffort( logger: FailureLogger, level: 'error' | 'info', message: string, @@ -90,7 +92,7 @@ export function makeRunLoopFailureHandler({ if (!isStarted()) { // No daemon to close yet. Startup either unwinds at its own check or // replays this failure once there is something to shut down. - report( + logBestEffort( logger, 'error', 'Kernel run loop died before the daemon started.', @@ -101,7 +103,7 @@ export function makeRunLoopFailureHandler({ if (isShuttingDown()) { // Expected teardown, not an outage: don't fail a deliberate stop. - report( + logBestEffort( logger, 'info', 'Kernel run loop stopped during shutdown.', @@ -116,7 +118,7 @@ export function makeRunLoopFailureHandler({ // a crank dies and its rollback then fails, the rollback failure is the // outermost message and the error that actually killed the kernel is only // reachable through `cause`. - report( + logBestEffort( logger, 'error', 'Kernel run loop died; shutting down the daemon.', @@ -135,7 +137,7 @@ export function makeRunLoopFailureHandler({ try { removePidFile(); } catch (rmError) { - report( + logBestEffort( logger, 'error', 'Could not remove the pid file before exiting.', @@ -146,7 +148,7 @@ export function makeRunLoopFailureHandler({ }; const killTimer = setTimeout(() => { - report( + logBestEffort( logger, 'error', `Shutdown stalled for ${timeoutMs} ms after run loop failure; exiting now.`, @@ -159,7 +161,7 @@ export function makeRunLoopFailureHandler({ () => clearTimeout(killTimer), (shutdownError: unknown) => { clearTimeout(killTimer); - report( + logBestEffort( logger, 'error', 'Shutdown after run loop failure failed; exiting now.', @@ -219,7 +221,7 @@ export async function cleanUpFailedStartup({ stopKernel(), new Promise((resolve) => { giveUpTimer = setTimeout(() => { - report( + logBestEffort( logger, 'error', `Kernel did not stop within ${timeoutMs} ms during startup cleanup.`, @@ -229,7 +231,7 @@ export async function cleanUpFailedStartup({ }), ]); } catch (stopError) { - report( + logBestEffort( logger, 'error', 'Could not stop the kernel during startup cleanup.', @@ -250,7 +252,7 @@ export async function cleanUpFailedStartup({ try { removePidFile(); } catch (rmError) { - report( + logBestEffort( logger, 'error', 'Could not remove the pid file during startup cleanup.',