diff --git a/packages/kernel-test/src/persistence.test.ts b/packages/kernel-test/src/persistence.test.ts index b1c91f3f4..acde5f774 100644 --- a/packages/kernel-test/src/persistence.test.ts +++ b/packages/kernel-test/src/persistence.test.ts @@ -2,7 +2,8 @@ import type { CapData } from '@endo/marshal'; import { makeSQLKernelDatabase } from '@metamask/kernel-store/sqlite/nodejs'; import { waitUntilQuiescent } from '@metamask/kernel-utils'; import { kunser } from '@metamask/ocap-kernel'; -import { unlink } from 'node:fs/promises'; +import { copyFile, readFile, unlink, writeFile } from 'node:fs/promises'; +import { fileURLToPath, pathToFileURL } from 'node:url'; import { describe, expect, it, beforeEach, afterEach } from 'vitest'; import { @@ -18,19 +19,27 @@ const v1Root = 'ko4'; describe('persistent storage', { timeout: 20_000 }, () => { let logger: ReturnType; let databasePath: string; + let doomedBundlePath: string; beforeEach(async () => { // Create a unique database file for each test in the current directory databasePath = `./persistence-test-${Date.now()}-${Math.random()}.db`; + // A bundle one test takes away mid-scenario. Declared here so it is removed + // even when that test fails partway: these land in `packages/kernel-test/`, + // where `*.bundle` is gitignored repo-wide, so a leaked copy is invisible to + // `git status` and survives `yarn clean`. + doomedBundlePath = `./doomed-vat-${Date.now()}-${Math.random()}.bundle`; logger = makeTestLogger(); }); afterEach(async () => { // Clean up the database file - try { - await unlink(databasePath); - } catch { - // Ignore errors if file doesn't exist + for (const path of [databasePath, doomedBundlePath]) { + try { + await unlink(path); + } catch { + // Ignore errors if file doesn't exist + } } }); @@ -46,6 +55,147 @@ describe('persistent storage', { timeout: 20_000 }, () => { }, }; + it('boots past a vat whose bundle vanished between incarnations', async () => { + // A vat outlives the code it was launched from: a bundle gets rebuilt to a + // new path, pruned, or recorded as an absolute path that did not survive + // relocation. Copy a bundle so this test owns one it can take away. + await copyFile( + fileURLToPath(getBundleSpec('persistence-counter-vat')), + doomedBundlePath, + ); + const database1 = await makeSQLKernelDatabase({ dbFilename: databasePath }); + const kernel1 = await makeKernel( + database1, + false, + logger.logger.subLogger({ tags: ['test'] }), + ); + // Two subclusters, one vat each. The keeper's bundle stays where it is; the + // doomed one's does not. + const { rootKref: keeperRoot } = + await kernel1.launchSubcluster(testSubcluster); + await waitUntilQuiescent(); + const { subclusterId: doomedSubcluster } = await kernel1.launchSubcluster({ + bootstrap: 'counter', + vats: { + counter: { + bundleSpec: pathToFileURL(doomedBundlePath).toString(), + parameters: { name: 'Doomed' }, + }, + }, + }); + await waitUntilQuiescent(); + await kernel1.stop(); + + await unlink(doomedBundlePath); + + const database2 = await makeSQLKernelDatabase({ dbFilename: databasePath }); + const kernel2 = await makeKernel( + database2, + false, + logger.logger.subLogger({ tags: ['test'] }), + ); + + // Booting at all is the claim. The doomed vat's bundle is fetched inside its + // own worker, so the failure arrives mid-boot from a worker that is already + // running; restoring every vat as one unit turned that into a kernel nobody + // could start. (`makeKernel` awaits `initializeAllVats`, so by the time it + // returns the skip has already happened.) + expect(kernel2.getVatIds()).toStrictEqual(['v1']); + // The keeper is untouched by its neighbour's loss, state and all. + expect(await runResume(kernel2, keeperRoot)).toBe( + 'Counter incremented to: 2', + ); + + // The skipped vat is still a member of its subcluster, so tearing that + // subcluster down walks straight into a vat with no worker. It has to + // succeed: otherwise the operator's one remedy strands half-done, with no + // way to be rid of the vat short of discarding the store. + await kernel2.terminateSubcluster(doomedSubcluster); + expect(kernel2.getSubcluster(doomedSubcluster)).toBeUndefined(); + + // Nothing the teardown did disturbed the healthy neighbour. + expect(await runResume(kernel2, keeperRoot)).toBe( + 'Counter incremented to: 3', + ); + await kernel2.stop(); + + // Terminating it has to mean terminating it. Give the bundle back and boot + // again: a record left in the store outlives the subcluster that owned it, + // so the vat the operator was rid of comes back — running, with its durable + // state intact but its c-lists cleaned up underneath it, and belonging to + // nothing. `getVats` asks every vat for its subcluster, so from then on + // `getStatus` throws for every caller that asks. + await copyFile( + fileURLToPath(getBundleSpec('persistence-counter-vat')), + doomedBundlePath, + ); + const database3 = await makeSQLKernelDatabase({ dbFilename: databasePath }); + const kernel3 = await makeKernel( + database3, + false, + logger.logger.subLogger({ tags: ['test'] }), + ); + + expect(kernel3.getVatIds()).toStrictEqual(['v1']); + expect(await kernel3.getStatus()).toBeDefined(); + await kernel3.stop(); + }); + + it('restores a vat whose code becomes reachable again', async () => { + // The other half of retaining the record rather than pruning it: a bundle + // that comes back brings its vat back, with the state it left off with. + await copyFile( + fileURLToPath(getBundleSpec('persistence-counter-vat')), + doomedBundlePath, + ); + const doomedCluster = { + bootstrap: 'counter', + vats: { + counter: { + bundleSpec: pathToFileURL(doomedBundlePath).toString(), + parameters: { name: 'Doomed' }, + }, + }, + }; + const database1 = await makeSQLKernelDatabase({ dbFilename: databasePath }); + const kernel1 = await makeKernel( + database1, + false, + logger.logger.subLogger({ tags: ['test'] }), + ); + const { rootKref } = await kernel1.launchSubcluster(doomedCluster); + await waitUntilQuiescent(); + await kernel1.stop(); + + // Incarnation 2: the bundle is gone, so the vat is skipped. + const bundleContents = await readFile(doomedBundlePath); + await unlink(doomedBundlePath); + const database2 = await makeSQLKernelDatabase({ dbFilename: databasePath }); + const kernel2 = await makeKernel( + database2, + false, + logger.logger.subLogger({ tags: ['test'] }), + ); + expect(kernel2.getVatIds()).toStrictEqual([]); + await kernel2.stop(); + + // Incarnation 3: the bundle is back, and so is the vat. + await writeFile(doomedBundlePath, bundleContents); + const database3 = await makeSQLKernelDatabase({ dbFilename: databasePath }); + const kernel3 = await makeKernel( + database3, + false, + logger.logger.subLogger({ tags: ['test'] }), + ); + expect(kernel3.getVatIds()).toStrictEqual(['v1']); + // Count 1 came from the incarnation that ran `bootstrap`; picking up at 2 + // shows the durable store survived the incarnation it sat out. + expect(await runResume(kernel3, rootKref)).toBe( + 'Counter incremented to: 2', + ); + await kernel3.stop(); + }); + it('maintains state across kernel restarts', async () => { const database1 = await makeSQLKernelDatabase({ dbFilename: databasePath }); const kernel1 = await makeKernel( diff --git a/packages/ocap-kernel/CHANGELOG.md b/packages/ocap-kernel/CHANGELOG.md index 302a2a678..7004abf42 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -61,6 +61,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed +- A persisted vat whose code can no longer be loaded no longer makes the whole kernel unbootable ([#1031](https://github.com/MetaMask/ocap-kernel/pull/1031)) + - A vat outlives the code it was launched from: a bundle can be rebuilt to a new path, pruned, or recorded as an absolute path that did not survive relocation. Boot restored every persisted vat in one `Promise.all`, so one such vat rejected `Kernel.make` outright and every other subcluster was lost with it. Under the daemon that surfaced only as a startup timeout + - The failure is now confined to the vat that owns it: that vat is skipped, its leftover worker is terminated (a bundle is fetched inside the worker, so the worker is live by the time the load fails — one left running is the wedged process this failure mode is known by), and an error naming the vat, its subcluster, and its code source is logged. The rest of the kernel boots + - The skipped vat's persisted record is kept rather than pruned, so a vat whose code becomes reachable again is restored by a later boot, resuming from the durable state it left off with. Recovering one without restarting the kernel is not yet possible: `restartVat` requires a running vat. Whether an unrestorable vat should instead take its subcluster down with it is left to the subcluster lifecycle ([#979](https://github.com/MetaMask/ocap-kernel/issues/979)) - `terminateVat` now retires a vat that is persisted but not running, instead of throwing `VatNotFoundError` ([#1030](https://github.com/MetaMask/ocap-kernel/pull/1030)) - Reachable through `restartVat`: it stops the vat and then runs it again, and a relaunch that fails leaves the vat gone from the running map with its record, its own store and its root pin all still in place. Such a vat could not be terminated at all, so the only way to be rid of one was to discard the whole store, and `terminateSubcluster` — which walks persisted membership — rejected part-way through on reaching one, after deleting the system-subcluster mapping and before removing the subcluster record - Retiring one does everything `stopVat` does apart from stopping a worker: it discards the vat's persisted record, rejects the promises the vat was deciding, and releases the pin `launchVat` took on its root. Marking it terminated is not enough on its own — the deferred cleanup that follows walks keys prefixed `${vatId}.`, which never matches the `vatConfig.${vatId}` that decides whether the next boot restores the vat, and it states that its caller has already rejected those promises diff --git a/packages/ocap-kernel/src/Kernel.test.ts b/packages/ocap-kernel/src/Kernel.test.ts index d85cb0223..5fbffff37 100644 --- a/packages/ocap-kernel/src/Kernel.test.ts +++ b/packages/ocap-kernel/src/Kernel.test.ts @@ -2,6 +2,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 type { LogEntry } from '@metamask/logger'; import { Logger } from '@metamask/logger'; import type { DuplexStream } from '@metamask/streams'; import type { Mocked, MockInstance } from 'vitest'; @@ -130,6 +131,42 @@ const makeSingleVatClusterConfig = (): ClusterConfig => ({ }, }); +const HEALTHY_BUNDLE = 'file:///bundles/present.bundle'; +const MISSING_BUNDLE = 'file:///bundles/gone.bundle'; + +const makeBundleVatClusterConfig = (bundleSpec: string): ClusterConfig => ({ + bootstrap: 'testVat', + vats: { + testVat: { bundleSpec }, + }, +}); + +/** + * Build a `launch` implementation standing in for a worker whose bundle fetch + * fails. `fetchBlob` hands back whatever `fs.readFile` rejected with, so the + * failure arrives as a Node errno object rather than a well-formed `Error` + * with a useful stack. + * + * @returns A `PlatformServices['launch']` implementation that rejects for the + * vat configured with `MISSING_BUNDLE` and succeeds for every other vat. + */ +const makeMissingBundleLaunch = () => { + return async (_vatId: VatId, vatConfig: VatConfig) => { + if ('bundleSpec' in vatConfig && vatConfig.bundleSpec === MISSING_BUNDLE) { + throw Object.assign( + new Error( + `ENOENT: no such file or directory, open '${MISSING_BUNDLE}'`, + ), + { code: 'ENOENT', errno: -2, syscall: 'open' }, + ); + } + return { end: vi.fn() } as unknown as DuplexStream< + JsonRpcMessage, + JsonRpcMessage + >; + }; +}; + const makeMockClusterConfig = (): ClusterConfig => ({ bootstrap: 'alice', vats: { @@ -247,6 +284,75 @@ describe('Kernel', () => { expect(makeVatHandleMock).toHaveBeenCalledOnce(); expect(kernel2.getVatIds()).toStrictEqual(['v1']); }); + + it('boots when a persisted vat is no longer restorable', async () => { + const db = makeMapKernelDatabase(); + const kernel1 = await Kernel.make(mockPlatformServices, db); + // Two subclusters, one vat each. The unrestorable vat is deliberately + // in a *different* subcluster from the healthy one: under every + // lifecycle policy in play (including bootstrap-vat death cascading to + // its own subcluster, per #979), a failure in one subcluster leaves + // another subcluster's vats running. That keeps this test a statement + // about the defect rather than about a chosen remedy. + await kernel1.launchSubcluster( + makeBundleVatClusterConfig(HEALTHY_BUNDLE), + ); + await kernel1.launchSubcluster( + makeBundleVatClusterConfig(MISSING_BUNDLE), + ); + expect(kernel1.getVatIds()).toStrictEqual(['v1', 'v2']); + + // The bundle behind v2 goes away between incarnations — rebuilt to a new + // path, pruned, or an absolute path that did not survive relocation. + // `fetchBlob` rejects with a bare Node errno object when that happens. + launchWorkerMock.mockImplementation(makeMissingBundleLaunch()); + + const kernel2 = await Kernel.make(mockPlatformServices, db); + + // Booting at all is the claim: the rejection used to propagate out of + // `initializeAllVats`, so `Kernel.make` rejected and the daemon died + // during init. The healthy vat comes up and the unrestorable one does + // not; whether it should instead take its own subcluster down with it is + // #979's to decide. + expect(kernel2.getVatIds()).toStrictEqual(['v1']); + }); + + it('names the unrestorable vat and its bundle when booting past it', async () => { + const db = makeMapKernelDatabase(); + // Capture through a transport rather than by spying on the logger's + // methods. `subLogger` builds a *fresh* `Logger` that shares its parent's + // transports, so a sub-logger's output never passes through the parent's + // methods — and every kernel component, the vat manager included, logs + // through one. + const entries: LogEntry[] = []; + const logger = new Logger({ + tags: ['test'], + transports: [(entry) => entries.push(entry)], + }); + const kernel1 = await Kernel.make(mockPlatformServices, db, { logger }); + await kernel1.launchSubcluster( + makeBundleVatClusterConfig(HEALTHY_BUNDLE), + ); + await kernel1.launchSubcluster( + makeBundleVatClusterConfig(MISSING_BUNDLE), + ); + + launchWorkerMock.mockImplementation(makeMissingBundleLaunch()); + entries.length = 0; + + await Kernel.make(mockPlatformServices, db, { logger }); + + // Skipping a persisted vat silently would trade an unbootable kernel for + // a kernel that is quietly missing a vat. One entry has to carry both the + // vat and its bundle — satisfying this by logging them from two unrelated + // places would tell an operator nothing. + const reported = entries.filter( + ({ level, message }) => + level === 'error' && String(message).includes('v2'), + ); + expect(reported).toHaveLength(1); + expect(String(reported[0]?.message)).toContain(MISSING_BUNDLE); + }); }); describe('queueMessage()', () => { diff --git a/packages/ocap-kernel/src/vats/VatManager.test.ts b/packages/ocap-kernel/src/vats/VatManager.test.ts index 9f23826c1..70d986b29 100644 --- a/packages/ocap-kernel/src/vats/VatManager.test.ts +++ b/packages/ocap-kernel/src/vats/VatManager.test.ts @@ -148,6 +148,151 @@ describe('VatManager', () => { expect(mockPlatformServices.launch).not.toHaveBeenCalled(); expect(vatManager.getVatIds()).toStrictEqual([]); }); + + describe('a vat whose code can no longer be loaded', () => { + const MISSING_BUNDLE = 'file:///bundles/gone.bundle'; + + /** + * Persist one healthy vat and one whose code is gone. The two are + * unrelated: losing the healthy vat because of the other one is the + * defect under test. + * + * @param unrestorableConfig - The config of the vat that cannot be + * restored. Defaults to one naming a missing bundle. + */ + const persistOneUnrestorableVat = ( + unrestorableConfig: VatConfig = { bundleSpec: MISSING_BUNDLE }, + ): void => { + mockKernelStore.getAllVatRecords.mockReturnValue( + (function* () { + yield { vatID: 'v1' as VatId, vatConfig: createMockVatConfig() }; + yield { vatID: 'v2' as VatId, vatConfig: unrestorableConfig }; + })(), + ); + }; + + /** Fail `v2` where a worker never comes up at all. */ + const failAtLaunch = (): void => { + mockPlatformServices.launch.mockImplementation(async (vatId) => { + if (vatId === 'v2') { + // `fetchBlob` hands back whatever `fs.readFile` rejected with, so + // the failure arrives as a Node errno object. + throw Object.assign( + new Error( + `ENOENT: no such file or directory, open '${MISSING_BUNDLE}'`, + ), + { code: 'ENOENT', errno: -2, syscall: 'open' }, + ); + } + return { end: vi.fn() } as unknown as DuplexStream< + JsonRpcMessage, + JsonRpcMessage + >; + }); + }; + + /** + * Fail `v2` the way production does: the worker starts, and the bundle + * fetch it performs fails inside the `initVat` delivery. + */ + const failAfterWorkerIsLive = (): void => { + makeVatHandleMock.mockImplementation(async ({ vatId, vatConfig }) => { + if (vatId === 'v2') { + throw new Error( + `Failed to initialize vat ${vatId}: ENOENT: no such file or directory, open '${MISSING_BUNDLE}'`, + ); + } + return createMockVatHandle(vatId, vatConfig); + }); + }; + + it.each([ + ['before its worker comes up', failAtLaunch], + ['after its worker is live', failAfterWorkerIsLive], + ])('restores the other vats when it fails %s', async (_when, fail) => { + persistOneUnrestorableVat(); + fail(); + + await vatManager.initializeAllVats(); + + expect(vatManager.getVatIds()).toStrictEqual(['v1']); + }); + + it('reaps the worker left behind by a vat that failed to initialize', async () => { + persistOneUnrestorableVat(); + failAfterWorkerIsLive(); + + await vatManager.initializeAllVats(); + + // The worker outlives the failed vat — `VatHandle.make` is reached only + // once `launch` has resolved — and a worker nobody owns is the wedged + // process this failure mode is known by. + expect(mockPlatformServices.terminate).toHaveBeenCalledWith('v2'); + }); + + it('boots even when the leftover worker cannot be reaped', async () => { + persistOneUnrestorableVat(); + failAfterWorkerIsLive(); + mockPlatformServices.terminate.mockRejectedValue( + new Error('No worker found for vatId v2'), + ); + + await vatManager.initializeAllVats(); + + expect(vatManager.getVatIds()).toStrictEqual(['v1']); + }); + + it('keeps the vat persisted rather than pruning it', async () => { + persistOneUnrestorableVat(); + failAtLaunch(); + + await vatManager.initializeAllVats(); + + // A bundle that is missing now may be present at the next boot, so the + // vat's record is left alone; discarding persisted state is not a call + // the restore path gets to make. + expect(mockKernelStore.markVatAsTerminated).not.toHaveBeenCalled(); + }); + + it.each([ + [{ bundleSpec: MISSING_BUNDLE }, `bundleSpec ${MISSING_BUNDLE}`], + [{ sourceSpec: 'gone.js' }, 'sourceSpec gone.js'], + [{ bundleName: 'gone' }, 'bundleName gone'], + ])( + 'names the vat, its subcluster and its code source: %o', + async (unrestorableConfig, expectedSource) => { + persistOneUnrestorableVat(unrestorableConfig); + failAtLaunch(); + const logErrorSpy = vi.spyOn(mockLogger, 'error'); + + await vatManager.initializeAllVats(); + + expect(logErrorSpy).toHaveBeenCalledWith( + expect.stringContaining(expectedSource), + expect.anything(), + ); + const [message] = logErrorSpy.mock.calls[0] as [string]; + expect(message).toContain('vat v2'); + expect(message).toContain('subcluster s1'); + }, + ); + + it('reports a vat that belongs to no subcluster', async () => { + persistOneUnrestorableVat(); + failAtLaunch(); + mockKernelStore.getVatSubcluster.mockImplementation(() => { + throw new Error('Vat v2 has no subcluster'); + }); + const logErrorSpy = vi.spyOn(mockLogger, 'error'); + + await vatManager.initializeAllVats(); + + expect(logErrorSpy).toHaveBeenCalledWith( + expect.stringContaining('subcluster none'), + expect.anything(), + ); + }); + }); }); describe('launchVat', () => { diff --git a/packages/ocap-kernel/src/vats/VatManager.ts b/packages/ocap-kernel/src/vats/VatManager.ts index ff5e56cee..4eb783967 100644 --- a/packages/ocap-kernel/src/vats/VatManager.ts +++ b/packages/ocap-kernel/src/vats/VatManager.ts @@ -22,6 +22,24 @@ import type { AllowedGlobalName } from './endowments.ts'; import { VatHandle } from './VatHandle.ts'; import type { PingVatResult } from '../rpc/index.ts'; +/** + * Describe where a vat's code comes from, for diagnostics. A vat that cannot be + * restored is almost always a vat whose code has become unreachable, so the + * spec that names that code is the actionable part of the report. + * + * @param vatConfig - The vat's configuration. + * @returns A human-readable description of the vat's code source. + */ +function describeVatSource(vatConfig: VatConfig): string { + if ('bundleSpec' in vatConfig) { + return `bundleSpec ${vatConfig.bundleSpec}`; + } + if ('sourceSpec' in vatConfig) { + return `sourceSpec ${vatConfig.sourceSpec}`; + } + return `bundleName ${vatConfig.bundleName}`; +} + type VatManagerOptions = { platformServices: PlatformServices; kernelStore: KernelStore; @@ -87,11 +105,63 @@ export class VatManager { async initializeAllVats(): Promise { const starts: Promise[] = []; for (const { vatID, vatConfig } of this.#kernelStore.getAllVatRecords()) { - starts.push(this.runVat(vatID, vatConfig)); + starts.push(this.#restoreVat(vatID, vatConfig)); } await Promise.all(starts); } + /** + * Restore one persisted vat, tolerating a vat that can no longer be run. + * + * A vat outlives the code it was launched from: a bundle can be rebuilt to a + * new path, pruned, or recorded as an absolute path that did not survive + * relocation. Restoring every vat in one `Promise.all` made a single such vat + * reject the whole boot, so one unreachable bundle left the entire kernel — + * every other subcluster included — unbootable. Here the failure is confined + * to the vat that owns it: the vat is skipped and the rest of the kernel comes + * up. + * + * The vat's persisted record is kept, not pruned, so a vat whose code becomes + * reachable again is restored by a later boot. Whether an unrestorable vat + * should instead take its subcluster down with it is a lifecycle-policy + * question (see #979); this method only declines to lose the healthy vats. + * + * @param vatId - The ID of the vat to restore. + * @param vatConfig - Its configuration. + */ + async #restoreVat(vatId: VatId, vatConfig: VatConfig): Promise { + try { + await this.runVat(vatId, vatConfig); + } catch (error) { + // The worker may well be alive even though the vat is not: `runVat` + // reaches `VatHandle.make` only once `launch` has resolved, and it is the + // `initVat` delivery inside `make` that fails when a vat's code cannot be + // loaded. A worker left running that way is the wedged process this whole + // failure mode is known by, so reap it before moving on. Failure to + // terminate is expected when `launch` itself was what failed — there is no + // worker to reap — so it is reported at debug level only. + await this.#platformServices.terminate(vatId).catch((terminateError) => { + this.#logger.debug( + `No worker to reap for unrestorable vat ${vatId}`, + terminateError, + ); + }); + // `getVatSubcluster` fails rather than returning undefined for a vat with + // no subcluster, and a diagnostic is no place to acquire a second way to + // fail. + let subclusterId: SubclusterId | 'none'; + try { + subclusterId = this.#kernelStore.getVatSubcluster(vatId); + } catch { + subclusterId = 'none'; + } + this.#logger.error( + `Cannot restore vat ${vatId} of subcluster ${subclusterId} (${describeVatSource(vatConfig)}); skipping it. Its state is retained, so it returns if its code becomes reachable again.`, + error, + ); + } + } + /** * Launch a new vat. *