diff --git a/.gitignore b/.gitignore index 8c551a117..bb53e2bd1 100644 --- a/.gitignore +++ b/.gitignore @@ -2,6 +2,7 @@ dist/ coverage/ docs/* +reviews/ !docs/*.md !docs/contributing @@ -96,4 +97,4 @@ test-results # Claude **/.claude/settings.local.json -.playwright-mcp/ \ No newline at end of file +.playwright-mcp/ diff --git a/packages/kernel-test/src/persistence.test.ts b/packages/kernel-test/src/persistence.test.ts index e8b6e2781..3b187bdb8 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: the working directory is the monorepo + // root, where `*.bundle` is gitignored, 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 8af7998ec..784fb5b06 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -48,6 +48,18 @@ 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 ([#1025](https://github.com/MetaMask/ocap-kernel/pull/1025)) + - 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 reaped (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. 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)) +- A `notify`, GC action, or `bringOutYourDead` addressed to an endpoint that is not running is skipped instead of killing the run loop ([#1025](https://github.com/MetaMask/ocap-kernel/pull/1025)) + - These deliveries looked up their endpoint unguarded, so an endpoint named by persisted state but absent from the running kernel threw `VatNotFoundError` from inside the crank, which killed the run loop permanently. Because the crank was rolled back, the item was re-dequeued on the next boot and killed that one too. Reachable whenever ownership entries outlive their vat — a terminated vat awaiting cleanup, or a vat skipped at boot per the entry above + - Unlike a `send`, none of these has a caller to reject; `send` already tolerated a vanished endpoint by rejecting the caller with `ENDPOINT_UNREACHABLE`. A skipped `notify` still releases the reference it was holding, and no longer translates the resolution first — those translations import if needed, which would mint c-list entries and take references in an endpoint that will never be told and so can never release them + - An endpoint id that names neither a vat nor a remote still throws, since that is corrupt state rather than an endpoint that has gone away +- `terminateVat` now retires a vat that is persisted but not running, instead of throwing `VatNotFoundError` ([#1025](https://github.com/MetaMask/ocap-kernel/pull/1025)) + - Such a vat could not be terminated, and `terminateSubcluster` — which walks persisted membership — rejected part-way through, after deleting the system-subcluster mapping and before removing the subcluster record. A subcluster containing one could not be torn down at all + - Retiring one discards its persisted record and rejects the promises it was deciding, as stopping a running vat does. Marking it terminated is not enough on its own: the deferred cleanup that follows leaves the record that decides whether the next boot restores the vat, and states that its caller has already rejected those promises. Left half-done, a terminated vat came back at the next boot whose code was reachable — running, in a subcluster that no longer existed, which then failed every `getStatus` — and anything awaiting a result from it waited forever + - A vat that is neither running nor persisted still throws - A message delivered to a kernel-owned kref with no registered service now rejects the caller with `ENDPOINT_UNREACHABLE` instead of throwing, which escaped the crank and killed the run loop — turning one unreachable reference into a dead kernel ([#1007](https://github.com/MetaMask/ocap-kernel/pull/1007)) - Reachable without any kernel bug: an anonymous kernel object hosts something that cannot outlive the process, such as an accepted socket connection, so a vat holding one across a restart or a message to one still queued from the previous incarnation lands here. Kernel objects are born with a `(1, 1)` refcount, so the init sweep cannot delete such an object and its `kernel` owner survives (see [#1006](https://github.com/MetaMask/ocap-kernel/issues/1006)) - Matches what `KernelRouter` already does for a delivery whose endpoint has vanished. A message sent with no result promise has nobody to report to, so it is logged instead 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/KernelRouter.test.ts b/packages/ocap-kernel/src/KernelRouter.test.ts index ea833293a..9ed33dee4 100644 --- a/packages/ocap-kernel/src/KernelRouter.test.ts +++ b/packages/ocap-kernel/src/KernelRouter.test.ts @@ -1,3 +1,4 @@ +import { Logger } from '@metamask/logger'; import { describe, it, expect, vi, beforeEach } from 'vitest'; import type { MockInstance } from 'vitest'; @@ -675,6 +676,159 @@ describe('KernelRouter', () => { }); }); + describe('an endpoint named by persisted state that is not running', () => { + // A vat is addressable without being live: boot skips one whose code can + // no longer be loaded (`VatManager.#restoreVat`), and a terminated vat's + // ownership entries outlive it until cleanup. Its c-lists and reachable + // flags stay in the store, so the kernel goes on addressing it — and + // unlike a send, none of these deliveries has a caller to reject. + const endpointId = 'v2'; + + beforeEach(() => { + (getEndpoint as unknown as MockInstance).mockImplementation( + (requested: EndpointId) => { + if (requested === endpointId) { + throw new Error(`Vat not found: ${requested}`); + } + return endpointHandle; + }, + ); + }); + + /** + * Set up a notify whose promise is resolved and still in the endpoint's + * c-list, so delivery is reached rather than short-circuited. + * + * @returns The notify item to deliver. + */ + const makeLiveNotify = (): RunQueueItemNotify => { + const kpid = 'kp123'; + ( + kernelStore.getKernelPromise as unknown as MockInstance + ).mockReturnValue({ + state: 'fulfilled', + value: { body: JSON.stringify({ value: 'v' }), slots: [] }, + }); + (kernelStore.krefToEref as unknown as MockInstance).mockReturnValue( + 'p+123', + ); + ( + kernelStore.getKpidsToRetire as unknown as MockInstance + ).mockReturnValue([kpid]); + return { type: 'notify', endpointId, kpid }; + }; + + it.each([ + [ + 'notify', + (): RunQueueItem => makeLiveNotify(), + 'deliverNotify' as const, + ], + [ + 'dropExports', + (): RunQueueItem => ({ + type: 'dropExports' as GCRunQueueType, + endpointId, + krefs: ['ko1'], + }), + 'deliverDropExports' as const, + ], + [ + 'bringOutYourDead', + (): RunQueueItem => ({ type: 'bringOutYourDead', endpointId }), + 'deliverBringOutYourDead' as const, + ], + ])( + 'skips a %s addressed to it instead of throwing out of the crank', + async (_what, makeItem, deliverMethod) => { + // Throwing here would escape the crank and kill the run loop for + // good — and because the crank is rolled back, the same item is + // re-dequeued on the next boot and kills that one too. + const result = await kernelRouter.deliver(makeItem()); + + expect(result).toStrictEqual({ didDelivery: endpointId }); + expect( + endpointHandle[deliverMethod as keyof EndpointHandle], + ).not.toHaveBeenCalled(); + }, + ); + + it('allocates nothing in the c-list of an endpoint it is skipping', async () => { + await kernelRouter.deliver(makeLiveNotify()); + + // Both translations import if needed, minting a c-list entry with the + // reachable flag set and incrementing the refcount of every slot. Doing + // that for an endpoint nobody will tell writes rows only that endpoint + // could ever release, and it can't — the crank commits now that the + // delivery no longer throws, so what a rollback used to undo persists. + expect(kernelStore.translateRefKtoE).not.toHaveBeenCalled(); + expect(kernelStore.translateCapDataKtoE).not.toHaveBeenCalled(); + }); + + it('throws for an endpoint id that is neither a vat nor a remote', async () => { + (getEndpoint as unknown as MockInstance).mockImplementation( + (requested: EndpointId) => { + throw new Error(`invalid endpoint ID ${requested}`); + }, + ); + + // A missing vat and a missing remote are ordinary; an id that is + // neither is corrupt state or a kernel bug, and GC actions are parsed + // through `insistEndpointId` before they are ever queued. Swallowing it + // buys nothing and hides the one case worth hearing about. + await expect( + kernelRouter.deliver({ + type: 'bringOutYourDead', + endpointId: 'bogus' as EndpointId, + }), + ).rejects.toThrow('invalid endpoint ID bogus'); + }); + + it('reports the skip above the per-delivery trace level', async () => { + const logger = new Logger('test'); + const warnSpy = vi.spyOn(logger, 'warn'); + const router = new KernelRouter( + kernelStore, + kernelQueue, + getEndpoint, + vi.fn(), + logger, + ); + + await router.deliver({ type: 'bringOutYourDead', endpointId }); + + // A delivery dropped on the floor is not routine traffic, and it is the + // only trace of a vat that has quietly stopped doing anything. + expect(warnSpy).toHaveBeenCalledWith( + expect.stringContaining(endpointId), + expect.anything(), + ); + }); + + it('still releases the notify’s own reference when it is skipped', async () => { + const notifyItem = makeLiveNotify(); + + await kernelRouter.deliver(notifyItem); + + // `enqueueNotify` took a reference for this item; an endpoint that is + // not there to be told is no reason to hold it forever. + expect(kernelStore.decrementRefCount).toHaveBeenCalledWith( + notifyItem.kpid, + 'deliver|notify', + ); + }); + + it('still delivers to endpoints that are running', async () => { + const result = await kernelRouter.deliver({ + type: 'bringOutYourDead', + endpointId: 'v1', + }); + + expect(endpointHandle.deliverBringOutYourDead).toHaveBeenCalled(); + expect(result).toStrictEqual({ didDelivery: 'v1' }); + }); + }); + it('throws on unknown run queue item type', async () => { // @ts-expect-error - deliberately using an invalid type const invalidItem: RunQueueItem = { type: 'invalid' }; diff --git a/packages/ocap-kernel/src/KernelRouter.ts b/packages/ocap-kernel/src/KernelRouter.ts index 5cfb8335d..653eb96b9 100644 --- a/packages/ocap-kernel/src/KernelRouter.ts +++ b/packages/ocap-kernel/src/KernelRouter.ts @@ -20,6 +20,7 @@ import type { RunQueueItemGCAction, CrankResult, } from './types.ts'; +import { isRemoteId, isVatId } from './types.ts'; import { assert, Fail } from './utils/assert.ts'; type MessageRoute = { @@ -340,6 +341,53 @@ export class KernelRouter { return { didDelivery: 'kernel' }; } + /** + * Look up an endpoint for a housekeeping delivery — a notify, a GC action, or + * a reap — tolerating one that is not running. + * + * An endpoint can be named by persisted state without being live. A vat whose + * code can no longer be loaded is skipped at boot rather than taking the whole + * kernel down with it (`VatManager.#restoreVat`), and a terminated vat's + * ownership entries outlive it until cleanup gets to them. Either way its + * c-lists and reachable flags are still in the store, so the kernel goes on + * addressing it. + * + * Unlike a `send`, these deliveries have no caller to reject: nobody is + * waiting on a `dropExport`. Throwing here instead escapes the crank and kills + * the run loop for good — and since the crank is rolled back, the same item is + * re-dequeued on the next boot and kills that one too. An endpoint that isn't + * there is something to skip, not a kernel fault. + * + * @param endpointId - The endpoint the item is addressed to. + * @param what - What was being delivered, for the log. + * @returns The endpoint's handle, or undefined if it is not running. + */ + #getEndpointIfRunning( + endpointId: EndpointId, + what: string, + ): EndpointHandle | undefined { + // An id that names neither a vat nor a remote is not an endpoint that has + // gone away; it is corrupt state or a kernel bug, and GC actions pass + // `insistEndpointId` before they are ever queued. Let it through. + if (!isVatId(endpointId) && !isRemoteId(endpointId)) { + return this.#getEndpoint(endpointId); + } + try { + return this.#getEndpoint(endpointId); + } catch (error) { + // Deliberately broad over the rest: `#getEndpoint` reports a missing vat + // and a missing remote as different error types, and neither is worth + // killing the kernel over. Reported above the per-delivery trace channel, + // since a delivery dropped on the floor is not routine traffic — it is + // the only trace of a vat that has quietly stopped doing anything. + this.#logger?.warn( + `Skipped ${what} for endpoint ${endpointId}, which is not running:`, + error, + ); + return undefined; + } + } + /** * Deliver a 'notify' run queue item. * @@ -371,6 +419,20 @@ export class KernelRouter { // no kpids to retire, already done return { didDelivery: endpointId }; } + // Looked up before the translations below, not after: those import if + // needed, minting c-list entries with the reachable flag set and taking a + // reference on every slot. Doing that for an endpoint that will never be + // told writes rows only that endpoint could release, and it cannot. While + // an absent endpoint threw, the rollback undid them; now that it is skipped, + // the crank commits. + const endpoint = this.#getEndpointIfRunning(endpointId, `notify ${kpid}`); + if (!endpoint) { + // Still release the reference the notify itself holds + // (`KernelQueue.enqueueNotify`): an endpoint that is not there to be told + // is no reason to keep it forever. + this.#kernelStore.decrementRefCount(kpid, 'deliver|notify'); + return { didDelivery: endpointId }; + } const resolutions: VatOneResolution[] = []; for (const toResolve of targets) { const tPromise = this.#kernelStore.getKernelPromise(toResolve); @@ -390,7 +452,6 @@ export class KernelRouter { this.#kernelStore.decrementRefCount(toResolve, 'deliver|notify|slot'); } } - const endpoint = this.#getEndpoint(endpointId); const crankResult = await endpoint.deliverNotify(resolutions); // Decrement reference count for processed 'notify' item this.#kernelStore.decrementRefCount(kpid, 'deliver|notify'); @@ -408,7 +469,10 @@ export class KernelRouter { this.#logger?.log( `@@@@ deliver ${endpointId} ${type} ${JSON.stringify(krefs)}`, ); - const endpoint = this.#getEndpoint(endpointId); + const endpoint = this.#getEndpointIfRunning(endpointId, type); + if (!endpoint) { + return { didDelivery: endpointId }; + } const erefs = this.#kernelStore.krefsToExistingErefs(endpointId, krefs); const method = `deliver${(type[0] as string).toUpperCase()}${type.slice(1)}` as @@ -430,7 +494,10 @@ export class KernelRouter { ): Promise { const { endpointId } = item; this.#logger?.log(`@@@@ deliver ${endpointId} bringOutYourDead`); - const endpoint = this.#getEndpoint(endpointId); + const endpoint = this.#getEndpointIfRunning(endpointId, 'bringOutYourDead'); + if (!endpoint) { + return { didDelivery: endpointId }; + } const crankResult = await endpoint.deliverBringOutYourDead(); return crankResult; } diff --git a/packages/ocap-kernel/src/store/methods/subclusters.test.ts b/packages/ocap-kernel/src/store/methods/subclusters.test.ts index eda07e6bb..5058e3632 100644 --- a/packages/ocap-kernel/src/store/methods/subclusters.test.ts +++ b/packages/ocap-kernel/src/store/methods/subclusters.test.ts @@ -495,11 +495,19 @@ describe('getSubclusterMethods', () => { expect(map[vatId2]).toBe(scId); }); - it('should throw an error if the vat is not in any subcluster', () => { + it('leaves a vat that is in no subcluster alone', () => { const nonMappedVat = 'vNonMapped' as VatId; + + // Already in the state this asks for. Reporting it instead would strand + // the teardown that called it part-way through, which is the whole reason + // a vat gets removed from its subcluster. expect(() => subclusterMethods.removeVatFromSubcluster(nonMappedVat), - ).toThrow('Vat "vNonMapped" has no subcluster'); + ).not.toThrow(); + expect(subclusterMethods.getSubcluster(scId)?.vats).toStrictEqual({ + vat1: vatId1, + vat2: vatId2, + }); }); it('should handle removing the last vat from a subcluster', () => { diff --git a/packages/ocap-kernel/src/store/methods/subclusters.ts b/packages/ocap-kernel/src/store/methods/subclusters.ts index 7d77d936a..9aa6f8c7e 100644 --- a/packages/ocap-kernel/src/store/methods/subclusters.ts +++ b/packages/ocap-kernel/src/store/methods/subclusters.ts @@ -239,11 +239,17 @@ export function getSubclusterMethods(ctx: StoreContext) { /** * Removes a vat from its subcluster. * + * A vat that belongs to no subcluster is already in the state this asks for, + * so it is left alone rather than reported: this runs while a vat is being + * discarded, and failing there is what strands a teardown part-way through. + * * @param vatId - The ID of the vat to remove. */ function removeVatFromSubcluster(vatId: VatId): void { - const subclusterId = getVatSubcluster(vatId); - deleteSubclusterVat(subclusterId, vatId); + const subclusterId = getVatToSubclusterMap()[vatId]; + if (subclusterId) { + deleteSubclusterVat(subclusterId, vatId); + } } // System subcluster mapping methods diff --git a/packages/ocap-kernel/src/vats/VatManager.test.ts b/packages/ocap-kernel/src/vats/VatManager.test.ts index d5e92b1aa..5433700eb 100644 --- a/packages/ocap-kernel/src/vats/VatManager.test.ts +++ b/packages/ocap-kernel/src/vats/VatManager.test.ts @@ -69,7 +69,10 @@ describe('VatManager', () => { })(), ), getVatSubcluster: vi.fn().mockReturnValue('s1'), + isVatActive: vi.fn().mockReturnValue(true), markVatAsTerminated: vi.fn(), + deleteVat: vi.fn(), + getPromisesByDecider: vi.fn().mockReturnValue([]), getRootObject: vi.fn().mockReturnValue('ko1'), pinObject: vi.fn(), unpinObject: vi.fn(), @@ -80,6 +83,7 @@ describe('VatManager', () => { mockKernelQueue = { waitForCrank: vi.fn().mockResolvedValue(undefined), + resolvePromises: vi.fn(), } as unknown as Mocked; mockLogger = new Logger('test'); @@ -144,6 +148,198 @@ 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'); + // Only that one: reaping the healthy vat's worker would leave the + // kernel holding a `VatHandle` for a vat whose worker is dead. + expect(mockPlatformServices.terminate).toHaveBeenCalledTimes(1); + }); + + it('confines each failure to its own vat when several cannot be restored', async () => { + // The case that cannot be satisfied by catching around the whole batch: + // each unrestorable vat has to be reaped and reported on its own, and + // the healthy one still has to come up. + mockKernelStore.getAllVatRecords.mockReturnValue( + (function* () { + yield { vatID: 'v1' as VatId, vatConfig: createMockVatConfig() }; + yield { + vatID: 'v2' as VatId, + vatConfig: { bundleSpec: MISSING_BUNDLE }, + }; + yield { + vatID: 'v3' as VatId, + vatConfig: { bundleSpec: 'file:///bundles/also-gone.bundle' }, + }; + })(), + ); + mockPlatformServices.launch.mockImplementation(async (vatId) => { + if (vatId === 'v2' || vatId === 'v3') { + throw new Error(`ENOENT: no such file or directory`); + } + return { end: vi.fn() } as unknown as DuplexStream< + JsonRpcMessage, + JsonRpcMessage + >; + }); + const logErrorSpy = vi.spyOn(mockLogger, 'error'); + + await vatManager.initializeAllVats(); + + expect(vatManager.getVatIds()).toStrictEqual(['v1']); + expect(mockPlatformServices.terminate).toHaveBeenCalledWith('v2'); + expect(mockPlatformServices.terminate).toHaveBeenCalledWith('v3'); + const reported = logErrorSpy.mock.calls.map(([message]) => + String(message), + ); + expect(reported.filter((line) => line.includes('vat v2'))).toHaveLength( + 1, + ); + expect(reported.filter((line) => line.includes('vat v3'))).toHaveLength( + 1, + ); + }); + + 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', () => { @@ -319,6 +515,65 @@ describe('VatManager', () => { expect.objectContaining({ message: 'Vat termination: Custom reason' }), ); }); + + it('retires a persisted vat that is not running', async () => { + // A vat skipped at boot has no worker to stop, but must still be + // retirable — otherwise the only way to be rid of one is to discard the + // whole store, and terminating its subcluster strands half-done. + await vatManager.terminateVat('v2'); + + expect(mockPlatformServices.terminate).not.toHaveBeenCalled(); + expect(mockKernelStore.markVatAsTerminated).toHaveBeenCalledWith('v2'); + }); + + it('discards the persisted record of a vat that is not running', async () => { + // `markVatAsTerminated` alone does not retire a vat. The deferred cleanup + // it schedules walks keys prefixed `${vatId}.`, which never matches + // `vatConfig.${vatId}` — only `deleteVat` removes that, along with the + // vat's own store and its subcluster membership. Leave it behind and the + // next boot restores the vat the operator just terminated. + await vatManager.terminateVat('v2'); + + expect(mockKernelStore.deleteVat).toHaveBeenCalledWith('v2'); + }); + + it('rejects the promises a vat that is not running was deciding', async () => { + mockKernelStore.getPromisesByDecider.mockReturnValue(['kp1', 'kp2']); + + await vatManager.terminateVat('v2'); + + // `cleanupTerminatedVat` deletes these promises' c-list entries and drops + // the decider's refcount on the stated understanding that its caller has + // already rejected them. Nothing else can: a promise left unresolved with + // a decider that no longer exists hangs its waiters for good. + expect(mockKernelQueue.resolvePromises).toHaveBeenCalledWith('v2', [ + ['kp1', true, expect.anything()], + ]); + expect(mockKernelQueue.resolvePromises).toHaveBeenCalledWith('v2', [ + ['kp2', true, expect.anything()], + ]); + }); + + it('carries the termination reason into those rejections', async () => { + mockKernelStore.getPromisesByDecider.mockReturnValue(['kp1']); + + await vatManager.terminateVat('v2', { body: 'Custom reason', slots: [] }); + + const [, resolutions] = mockKernelQueue.resolvePromises.mock.calls[0] as [ + string, + [string, boolean, { body: string }][], + ]; + expect(resolutions[0]?.[2]?.body).toContain('Custom reason'); + }); + + it('throws for a vat that is neither running nor persisted', async () => { + mockKernelStore.isVatActive.mockReturnValue(false); + + await expect(vatManager.terminateVat('v9')).rejects.toThrow( + VatNotFoundError, + ); + expect(mockKernelStore.markVatAsTerminated).not.toHaveBeenCalled(); + }); }); describe('restartVat', () => { diff --git a/packages/ocap-kernel/src/vats/VatManager.ts b/packages/ocap-kernel/src/vats/VatManager.ts index b90f6f30c..10f5e3cb9 100644 --- a/packages/ocap-kernel/src/vats/VatManager.ts +++ b/packages/ocap-kernel/src/vats/VatManager.ts @@ -8,6 +8,7 @@ import { stringify } from '@metamask/kernel-utils'; import { Logger, splitLoggerStream } from '@metamask/logger'; import type { KernelQueue } from '../KernelQueue.ts'; +import { makeKernelError } from '../liveslots/kernel-marshal.ts'; import type { KernelStore } from '../store/index.ts'; import type { VatId, @@ -21,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; @@ -86,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. * @@ -193,15 +264,57 @@ export class VatManager { this.#vats.delete(vatId); } + /** + * Retire a persisted vat that is not running. + * + * A vat skipped at boot because its code could not be loaded (`#restoreVat`) + * has no worker to stop, so it never reaches `VatHandle.terminate` — which is + * where a running vat's records are discarded and the promises it was + * deciding are rejected. Neither has anyone else to do it: the deferred + * `cleanupTerminatedVat` states outright that its caller has already rejected + * those promises, and it walks keys prefixed `${vatId}.`, which never matches + * the `vatConfig.${vatId}` that decides whether the next boot restores this + * vat. Left to `markVatAsTerminated` alone, terminating such a vat neither + * retires it nor releases anything waiting on it. + * + * @param vatId - The ID of the vat. + * @param reason - The reason for the termination, if any. + */ + #retirePersistedVat(vatId: VatId, reason?: CapData): void { + const terminationError = reason + ? new Error(`Vat termination: ${reason.body}`) + : new VatDeletedError(vatId); + const failure = makeKernelError('VAT_TERMINATED', terminationError.message); + for (const kpid of this.#kernelStore.getPromisesByDecider(vatId)) { + this.#kernelQueue.resolvePromises(vatId, [[kpid, true, failure]]); + } + this.#kernelStore.deleteVat(vatId); + } + /** * Terminate a vat with extreme prejudice. * + * Terminates a persisted vat that is not running as readily as one that is. + * A vat skipped at boot because its code could not be loaded (`#restoreVat`) + * has no worker to stop, but its records must still be retirable — otherwise + * the only way to be rid of one would be to discard the whole store, and + * `SubclusterManager.terminateSubcluster`, which walks persisted membership, + * would strand every subcluster containing one. + * * @param vatId - The ID of the vat. * @param reason - If the vat is being terminated, the reason for the termination. */ async terminateVat(vatId: VatId, reason?: CapData): Promise { await this.#kernelQueue.waitForCrank(); - await this.stopVat(vatId, true, reason); + if (this.hasVat(vatId)) { + await this.stopVat(vatId, true, reason); + } else if (this.#kernelStore.isVatActive(vatId)) { + this.#retirePersistedVat(vatId, reason); + } else { + // Not running *and* not persisted: this vat is simply unknown, and + // saying so beats silently retiring records that were never there. + throw new VatNotFoundError(vatId); + } // Mark for deletion (which will happen later, in vat-cleanup events) this.#kernelStore.markVatAsTerminated(vatId); }