diff --git a/packages/kernel-store/CHANGELOG.md b/packages/kernel-store/CHANGELOG.md index 5cfe39eb5..f49786942 100644 --- a/packages/kernel-store/CHANGELOG.md +++ b/packages/kernel-store/CHANGELOG.md @@ -12,6 +12,11 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - `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 +- `releaseSavepoint` discards the enclosing transaction when `RELEASE` fails, as `rollbackSavepoint` already did for `ROLLBACK TO` ([#1012](https://github.com/MetaMask/ocap-kernel/pull/1012)) + - Otherwise the savepoint stayed on the stack and the transaction open with nothing left to commit or abort it. The release failure is still what gets thrown +- The wasm driver clears `_inTx` when aborting a transaction throws, instead of believing it is still in one ([#1012](https://github.com/MetaMask/ocap-kernel/pull/1012)) + - Left true, `beginIfNeeded` became a permanent no-op and later writes autocommitted. The nodejs driver reads `db.inTransaction` and was never affected +- An abort that fails while recovering from a failed savepoint operation is now logged in both drivers ([#1012](https://github.com/MetaMask/ocap-kernel/pull/1012)) ## [0.6.0] diff --git a/packages/kernel-store/src/sqlite/nodejs.test.ts b/packages/kernel-store/src/sqlite/nodejs.test.ts index a62392fe1..270f018ae 100644 --- a/packages/kernel-store/src/sqlite/nodejs.test.ts +++ b/packages/kernel-store/src/sqlite/nodejs.test.ts @@ -360,6 +360,45 @@ describe('makeSQLKernelDatabase', () => { expect(mockDb._spStack).toStrictEqual([]); }); + // The hazard `rollbackSavepoint` guards against, by the other door. + it('releaseSavepoint discards the transaction when the release 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.releaseSavepoint('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; + }); + + it('releaseSavepoint reports the release 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.releaseSavepoint('point1')).toThrowError( + 'disk I/O error', + ); + + expect(mockDb._spStack).toStrictEqual([]); + mockDb.inTransaction = false; + }); + it('supports nested savepoints', async () => { const db = await makeSQLKernelDatabase({}); db.createSavepoint('outer'); diff --git a/packages/kernel-store/src/sqlite/nodejs.ts b/packages/kernel-store/src/sqlite/nodejs.ts index ec863edc7..fa754bb88 100644 --- a/packages/kernel-store/src/sqlite/nodejs.ts +++ b/packages/kernel-store/src/sqlite/nodejs.ts @@ -298,8 +298,14 @@ export async function makeSQLKernelDatabase({ db._spStack.length = 0; try { rollbackIfNeeded(); - } catch { - // The rollback failure below is the one worth reporting. + } catch (abortError) { + // The rollback failure below is the one worth reporting, but a failed + // abort leaves SQLite holding a transaction the next crank would + // silently write into. Nothing here can repair that. + logger?.error( + 'failed to discard transaction after rollback', + abortError, + ); } throw error; } @@ -321,7 +327,28 @@ export async function makeSQLKernelDatabase({ throw new Error(`No such savepoint: ${name}`); } const query = SQL_QUERIES.RELEASE_SAVEPOINT.replace('%NAME%', name); - db.exec(query); + try { + db.exec(query); + } catch (error) { + // The hazard `rollbackSavepoint` guards against, by the other door: 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. There is no + // committing this transaction now, so discard it. + db._spStack.length = 0; + try { + rollbackIfNeeded(); + } catch (abortError) { + // The release failure below is the one worth reporting, but a failed + // abort leaves SQLite holding a transaction the next crank would + // silently write into. Nothing here can repair that. + logger?.error( + 'failed to discard transaction after release', + abortError, + ); + } + throw error; + } db._spStack.splice(idx); if (db._spStack.length === 0) { commitIfNeeded(); diff --git a/packages/kernel-store/src/sqlite/wasm.test.ts b/packages/kernel-store/src/sqlite/wasm.test.ts index 2cbc96d65..8e82a00bc 100644 --- a/packages/kernel-store/src/sqlite/wasm.test.ts +++ b/packages/kernel-store/src/sqlite/wasm.test.ts @@ -488,7 +488,6 @@ describe('makeSQLKernelDatabase', () => { ); expect(mockDb._spStack).toStrictEqual([]); - mockDb._inTx = false; }); it('releaseSavepoint validates savepoint exists', async () => { @@ -518,6 +517,88 @@ describe('makeSQLKernelDatabase', () => { expect(mockDb._inTx).toBe(false); }); + // The hazard `rollbackSavepoint` guards against, by the other door. + it('releaseSavepoint discards the transaction when the release fails', async () => { + const db = await makeSQLKernelDatabase({}); + mockDb._inTx = true; + mockDb._spStack = ['point1']; + mockDb.exec.mockImplementationOnce(() => { + throw new Error('disk I/O error'); + }); + + expect(() => db.releaseSavepoint('point1')).toThrowError( + 'disk I/O error', + ); + + expect(mockDb._spStack).toStrictEqual([]); + expect(mockDb._inTx).toBe(false); + }); + + it('releaseSavepoint reports the release 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.releaseSavepoint('point1')).toThrowError( + 'disk I/O error', + ); + + expect(mockDb._inTx).toBe(false); + }); + + // A failed abort is the one case that can leave `_inTx` disagreeing with the + // database. Left true, `beginIfNeeded` is a no-op forever after. + it('stops believing it is in a transaction when 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._inTx).toBe(false); + }); + + // Why that matters: a savepoint created outside a transaction commits when + // released (Agoric/agoric-sdk#8423), so an aborted crank would keep its + // writes. + it('begins a transaction for the next savepoint after a failed abort', 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', + ); + + mockDb.exec.mockClear(); + mockStatement.step.mockClear(); + db.createSavepoint('next'); + + // BEGIN is the only prepared statement `createSavepoint` runs; the + // SAVEPOINT itself goes through `exec`. + expect(mockStatement.step).toHaveBeenCalledOnce(); + expect(mockDb.exec).toHaveBeenCalledWith('SAVEPOINT next'); + }); + it('supports nested savepoints', async () => { const db = await makeSQLKernelDatabase({}); db.createSavepoint('outer'); diff --git a/packages/kernel-store/src/sqlite/wasm.ts b/packages/kernel-store/src/sqlite/wasm.ts index c0c32b8a7..a43092732 100644 --- a/packages/kernel-store/src/sqlite/wasm.ts +++ b/packages/kernel-store/src/sqlite/wasm.ts @@ -210,10 +210,16 @@ export async function makeSQLKernelDatabase({ */ function rollbackIfNeeded(): void { if (db._inTx) { - sqlAbortTransaction.step(); - sqlAbortTransaction.reset(); + // Cleared before the abort is attempted, because the abort can throw and + // `_inTx` is tracked here rather than read from SQLite as the nodejs driver + // does. Left true, `beginIfNeeded` is a no-op forever after and writes + // autocommit one statement at a time (see `createSavepoint`). Cleared, a + // still-open transaction surfaces as a failed `BEGIN` — the louder + // failure. db._inTx = false; db._spStack.length = 0; + sqlAbortTransaction.step(); + sqlAbortTransaction.reset(); } } @@ -380,8 +386,14 @@ export async function makeSQLKernelDatabase({ db._spStack.length = 0; try { rollbackIfNeeded(); - } catch { - // The rollback failure below is the one worth reporting. + } catch (abortError) { + // The rollback failure below is the one worth reporting. The next + // `BEGIN` will fail if SQLite really is still in a transaction, but that + // is a crank away and this is where the evidence is. + logger?.error( + 'failed to discard transaction after rollback', + abortError, + ); } throw error; } @@ -403,7 +415,28 @@ export async function makeSQLKernelDatabase({ throw new Error(`No such savepoint: ${name}`); } const query = SQL_QUERIES.RELEASE_SAVEPOINT.replace('%NAME%', name); - db.exec(query); + try { + db.exec(query); + } catch (error) { + // The hazard `rollbackSavepoint` guards against, by the other door: 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. There is no + // committing this transaction now, so discard it. + db._spStack.length = 0; + try { + rollbackIfNeeded(); + } catch (abortError) { + // The release failure below is the one worth reporting. The next + // `BEGIN` will fail if SQLite really is still in a transaction, but that + // is a crank away and this is where the evidence is. + logger?.error( + 'failed to discard transaction after release', + abortError, + ); + } + throw error; + } db._spStack.splice(idx); if (db._spStack.length === 0) { commitIfNeeded(); diff --git a/packages/kernel-test/src/crank-rollback.test.ts b/packages/kernel-test/src/crank-rollback.test.ts index cd2a708aa..edb4fd0e6 100644 --- a/packages/kernel-test/src/crank-rollback.test.ts +++ b/packages/kernel-test/src/crank-rollback.test.ts @@ -138,6 +138,42 @@ describe('crank rollback against a real database', () => { expect(kdb.kernelKVStore.get('second')).toBe('yes'); }); + // An aborted crank still owes work after the rollback — terminating the vat, + // collecting garbage — whose writes have to survive it. + it('keeps the writes a crank makes after rolling its delivery back', async () => { + const { kernelStore, kdb } = await makeStore(); + + kernelStore.startCrank(); + kernelStore.createCrankSavepoint('crank'); + kernelStore.createCrankSavepoint('delivery'); + kdb.kernelKVStore.set('delivered', 'yes'); + + kernelStore.rollbackCrank('delivery'); + kdb.kernelKVStore.set('terminated', 'yes'); + kernelStore.endCrank(); + + expect(kdb.kernelKVStore.get('delivered')).toBeUndefined(); + expect(kdb.kernelKVStore.get('terminated')).toBe('yes'); + }); + + // And survive it *inside the crank's transaction*, not as autocommitted + // statements. Rolling back `crank` is the only way to observe that from here; + // the run loop never does it. + it('holds those writes in the transaction rather than autocommitting them', async () => { + const { kernelStore, kdb } = await makeStore(); + + kernelStore.startCrank(); + kernelStore.createCrankSavepoint('crank'); + kernelStore.createCrankSavepoint('delivery'); + kernelStore.rollbackCrank('delivery'); + kdb.kernelKVStore.set('terminated', 'yes'); + + kernelStore.rollbackCrank('crank'); + kernelStore.endCrank(); + + expect(kdb.kernelKVStore.get('terminated')).toBeUndefined(); + }); + // `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. diff --git a/packages/kernel-test/src/garbage-collection.test.ts b/packages/kernel-test/src/garbage-collection.test.ts index 268ed7920..8496d051b 100644 --- a/packages/kernel-test/src/garbage-collection.test.ts +++ b/packages/kernel-test/src/garbage-collection.test.ts @@ -105,6 +105,29 @@ describe('Garbage Collection', () => { expect(parseReplyBody(useResult.body)).toBe(objectId); }); + /** + * Reap the importer vat until the kernel's bookkeeping catches up with the + * vat's own garbage collection, or the attempts run out. + * + * `bringOutYourDead` reports an import as dropped only once the engine has + * collected the vat's presence and run its finalizer, which `gcAndFinalize` + * does not guarantee on the first attempt. Each attempt needs its own reap — + * `nextReapAction` shifts the one scheduled entry off, so cranking again finds + * nothing to do — plus a message to wake the run loop and consume it. + * + * Gives up after five attempts; the caller's assertion reports the failure. + * + * @param settled - Whether the state under test has arrived yet. + */ + async function reapImporterUntil(settled: () => boolean): Promise { + const isImporter = (vatId: VatId): boolean => vatId === importerVatId; + for (let attempt = 0; attempt < 5 && !settled(); attempt += 1) { + kernel.reapVats(isImporter); + await kernel.queueMessage(importerKRef, 'noop', []); + await waitUntilQuiescent(500); + } + } + it('should trigger GC syscalls through bringOutYourDead', async () => { // Create an object in the exporter vat with a known ID const objectId = 'test-object'; @@ -149,14 +172,10 @@ describe('Garbage Collection', () => { await kernel.queueMessage(importerKRef, 'makeWeak', [objectId]); await waitUntilQuiescent(); - // Schedule reap to trigger bringOutYourDead on next crank - kernel.reapVats((vatId) => vatId === importerVatId); - - // Run 3 cranks to allow bringOutYourDead to be processed - for (let i = 0; i < 3; i++) { - await kernel.queueMessage(importerKRef, 'noop', []); - await waitUntilQuiescent(500); - } + // Reap until the importer reports the drop + await reapImporterUntil( + () => kernelStore.getObjectRefCount(createObjectRef).reachable === 1, + ); // Check reference counts after dropImports const afterWeakRefCounts = kernelStore.getObjectRefCount(createObjectRef); @@ -168,13 +187,10 @@ describe('Garbage Collection', () => { await kernel.queueMessage(importerKRef, 'forgetImport', []); await waitUntilQuiescent(); - // Schedule another reap - kernel.reapVats((vatId) => vatId === importerVatId); - - for (let i = 0; i < 3; i++) { - await kernel.queueMessage(importerKRef, 'noop', []); - await waitUntilQuiescent(500); - } + // Reap until the importer reports the retirement + await reapImporterUntil( + () => kernelStore.getObjectRefCount(createObjectRef).recognizable === 1, + ); // Check reference counts after retireImports const afterForgetRefCounts = kernelStore.getObjectRefCount(createObjectRef); diff --git a/packages/ocap-kernel/CHANGELOG.md b/packages/ocap-kernel/CHANGELOG.md index 87dcabb83..ac82b159f 100644 --- a/packages/ocap-kernel/CHANGELOG.md +++ b/packages/ocap-kernel/CHANGELOG.md @@ -48,6 +48,11 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - 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 +- Keep a crank's store work inside one transaction ([#1012](https://github.com/MetaMask/ocap-kernel/pull/1012)) + - A crank now takes two savepoints, `crank` and `delivery`, and rolls back only `delivery`. Rolling back the outermost one ends the transaction, so terminating the vat and collecting garbage — which follow the rollback and must survive it — were autocommitting a statement at a time + - Buffered vat outputs are flushed after that work rather than before it, so a later failure can no longer roll the crank back underneath an answer already given. Termination still settles the dying vat's own promises immediately +- Forget a crank's savepoints when the store call that ends them fails, in both `rollbackCrank` and `endCrank` ([#1012](https://github.com/MetaMask/ocap-kernel/pull/1012)) + - A failed rollback or release discards the whole transaction, savepoints included. Keeping them listed had `endCrank` throw `No such savepoint: t0` from the run loop's `finally`, over whatever really killed the kernel - 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)) diff --git a/packages/ocap-kernel/src/KernelQueue.test.ts b/packages/ocap-kernel/src/KernelQueue.test.ts index d7beb0e2f..1af58d81f 100644 --- a/packages/ocap-kernel/src/KernelQueue.test.ts +++ b/packages/ocap-kernel/src/KernelQueue.test.ts @@ -91,6 +91,23 @@ describe('KernelQueue', () => { }; }; + /** + * Stop the run loop by failing the *next* crank's start, so that the crank + * under test runs to completion. Throwing from one of a crank's own store calls + * cuts it short, which hides everything the crank does after that call. + */ + const stopAfterOneCrank = (): void => { + let cranks = 0; + (kernelStore.startCrank as unknown as MockInstance).mockImplementation( + () => { + cranks += 1; + if (cranks > 1) { + throw new Error(STOP_RUN_LOOP); + } + }, + ); + }; + /** * Run a single crank whose delivery blows up, killing the run loop. * @@ -127,7 +144,8 @@ describe('KernelQueue', () => { const deliver = vi.fn().mockRejectedValue(deliverError); await expect(kernelQueue.run(deliver)).rejects.toBe(deliverError); expect(kernelStore.startCrank).toHaveBeenCalled(); - expect(kernelStore.createCrankSavepoint).toHaveBeenCalledWith('start'); + expect(kernelStore.createCrankSavepoint).toHaveBeenCalledWith('crank'); + expect(kernelStore.createCrankSavepoint).toHaveBeenCalledWith('delivery'); expect(processGCActionSetSpy).toHaveBeenCalled(); expect(kernelStore.nextReapAction).toHaveBeenCalled(); expect(kernelStore.nextTerminatedVatCleanup).toHaveBeenCalled(); @@ -155,9 +173,9 @@ describe('KernelQueue', () => { }); await expect(kernelQueue.run(deliver)).rejects.toThrow(STOP_RUN_LOOP); expect(kernelStore.startCrank).toHaveBeenCalled(); - expect(kernelStore.createCrankSavepoint).toHaveBeenCalledWith('start'); + expect(kernelStore.createCrankSavepoint).toHaveBeenCalledWith('delivery'); expect(deliver).toHaveBeenCalledWith(mockItem); - expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('start'); + expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('delivery'); expect(kernelStore.collectGarbage).toHaveBeenCalled(); expect(kernelStore.endCrank).toHaveBeenCalled(); }); @@ -194,6 +212,170 @@ describe('KernelQueue', () => { expect(kernelStore.collectGarbage).toHaveBeenCalled(); expect(kernelStore.endCrank).toHaveBeenCalled(); }); + + // Why the flush comes after the crank's fallible work: see + // `#processCrankResult`. Here the terminate is what fails. + it('answers no caller from a crank it then rolls back', async () => { + const mockItem: RunQueueItem = { + type: 'send', + target: 'ko123', + message: { result: 'kp1' } as KernelMessage, + }; + (kernelStore.runQueueLength as unknown as MockInstance) + .mockReturnValueOnce(1) + .mockReturnValue(0); + (kernelStore.dequeueRun as unknown as MockInstance).mockReturnValueOnce( + mockItem, + ); + + // A caller is awaiting this message's result. + const resolve = vi.fn(); + const reject = vi.fn(); + kernelQueue.subscriptions.set('kp1', { resolve, reject }); + + // The delivery succeeds and its result is there for the flush to hand over... + ( + kernelStore.flushCrankBuffer as unknown as MockInstance + ).mockReturnValueOnce([ + { type: 'notify', endpointId: 'v1', kpid: 'kp1' }, + ]); + (kernelStore.getKernelPromise as unknown as MockInstance).mockReturnValue( + { + state: 'fulfilled', + value: { body: '"answer"', slots: [] }, + }, + ); + + // ...but the crank still has fallible work left, and it dies there. + const terminationError = new Error('vat worker already gone'); + (terminateVat as unknown as MockInstance).mockRejectedValueOnce( + terminationError, + ); + const deliver = vi.fn().mockResolvedValue({ + terminate: { vatId: 'v1', info: { body: '"exit"', slots: [] } }, + }); + + await expect(kernelQueue.run(deliver)).rejects.toBe(terminationError); + + expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('delivery'); + expect(resolve).not.toHaveBeenCalled(); + // Told the result will never come, rather than left waiting on a crank the + // store no longer has any record of. + expect(reject).toHaveBeenCalledWith( + expect.objectContaining({ cause: terminationError }), + ); + }); + + // The same invariant inside the flush: `#enqueueRun` is store work and can + // fail part-way, so no caller may be answered until all of it lands. + it('answers no caller until every buffered item is enqueued', async () => { + const mockItem: RunQueueItem = { + type: 'send', + target: 'ko123', + message: { result: 'kp1' } as KernelMessage, + }; + (kernelStore.runQueueLength as unknown as MockInstance) + .mockReturnValueOnce(1) + .mockReturnValue(0); + (kernelStore.dequeueRun as unknown as MockInstance).mockReturnValueOnce( + mockItem, + ); + + const resolve = vi.fn(); + const reject = vi.fn(); + kernelQueue.subscriptions.set('kp1', { resolve, reject }); + + // Two resolutions to hand over, the caller's first. + ( + kernelStore.flushCrankBuffer as unknown as MockInstance + ).mockReturnValueOnce([ + { type: 'notify', endpointId: 'v1', kpid: 'kp1' }, + { type: 'notify', endpointId: 'v2', kpid: 'kp2' }, + ]); + (kernelStore.getKernelPromise as unknown as MockInstance).mockReturnValue( + { state: 'fulfilled', value: { body: '"answer"', slots: [] } }, + ); + + // The second enqueue is the write that fails. + const enqueueError = new Error('database is gone'); + let enqueued = 0; + (kernelStore.enqueueRun as unknown as MockInstance).mockImplementation( + () => { + enqueued += 1; + if (enqueued > 1) { + throw enqueueError; + } + }, + ); + + const deliver = vi.fn().mockResolvedValue(undefined); + await expect(kernelQueue.run(deliver)).rejects.toBe(enqueueError); + + expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('delivery'); + expect(resolve).not.toHaveBeenCalled(); + }); + + // Why two savepoints: see `#runLoop`. This pins that the rollback spares the + // transaction, so the work an aborted crank still owes stays inside it. + it.each([ + { + label: 'an abort', + crankResult: { abort: true }, + storeOrder: ['rollbackCrank', 'collectGarbage'], + }, + { + label: 'an abort that also terminates', + crankResult: { + abort: true, + terminate: { vatId: 'v1', info: { body: '"exit"', slots: [] } }, + }, + storeOrder: ['rollbackCrank', 'terminateVat', 'collectGarbage'], + }, + ])( + 'keeps the crank transactional after rolling back $label', + async ({ crankResult, storeOrder }) => { + const mockItem: RunQueueItem = { + type: 'send', + target: 'ko123', + message: { result: 'kp99' } as KernelMessage, + }; + (kernelStore.runQueueLength as unknown as MockInstance) + .mockReturnValueOnce(1) + .mockReturnValue(0); + (kernelStore.dequeueRun as unknown as MockInstance).mockReturnValueOnce( + mockItem, + ); + + const storeCalls: string[] = []; + ( + kernelStore.rollbackCrank as unknown as MockInstance + ).mockImplementation(() => { + storeCalls.push('rollbackCrank'); + }); + (terminateVat as unknown as MockInstance).mockImplementation( + async () => { + storeCalls.push('terminateVat'); + }, + ); + ( + kernelStore.collectGarbage as unknown as MockInstance + ).mockImplementation(() => { + storeCalls.push('collectGarbage'); + throw new Error(STOP_RUN_LOOP); + }); + + const deliver = vi.fn().mockResolvedValue(crankResult); + await expect(kernelQueue.run(deliver)).rejects.toThrow(STOP_RUN_LOOP); + + expect(storeCalls).toStrictEqual(storeOrder); + expect( + ( + kernelStore.createCrankSavepoint as unknown as MockInstance + ).mock.calls.flat(), + ).toStrictEqual(['crank', 'delivery']); + expect(kernelStore.rollbackCrank).not.toHaveBeenCalledWith('crank'); + }, + ); }); describe('getRunLoopStatus', () => { @@ -286,7 +468,7 @@ describe('KernelQueue', () => { 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'); + expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('delivery'); }); it('does not roll back when the savepoint was never created', async () => { @@ -846,7 +1028,7 @@ describe('KernelQueue', () => { throw new Error(STOP_RUN_LOOP); }); await expect(kernelQueue.run(deliver)).rejects.toThrow(STOP_RUN_LOOP); - expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('start'); + expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('delivery'); expect(rejectSpy).toHaveBeenCalledWith(terminateInfo); expect(kernelQueue.subscriptions.has('kp99')).toBe(false); }); @@ -882,7 +1064,7 @@ describe('KernelQueue', () => { throw new Error(STOP_RUN_LOOP); }); await expect(kernelQueue.run(deliver)).rejects.toThrow(STOP_RUN_LOOP); - expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('start'); + expect(kernelStore.rollbackCrank).toHaveBeenCalledWith('delivery'); expect(rejectedAfterAbort).toBe(false); expect(resolveSpy).not.toHaveBeenCalled(); expect(subscribedAfterAbort).toBe(true); @@ -952,11 +1134,7 @@ describe('KernelQueue', () => { mockItem, ); const deliver = vi.fn().mockResolvedValue(undefined); - ( - kernelStore.collectGarbage as unknown as MockInstance - ).mockImplementation(() => { - throw new Error(STOP_RUN_LOOP); - }); + stopAfterOneCrank(); await expect(kernelQueue.run(deliver)).rejects.toThrow(STOP_RUN_LOOP); expect(rejectSpy).toHaveBeenCalledWith(rejectedValue); expect(resolveSpy).not.toHaveBeenCalled(); @@ -991,11 +1169,7 @@ describe('KernelQueue', () => { mockItem, ); const deliver = vi.fn().mockResolvedValue(undefined); - ( - kernelStore.collectGarbage as unknown as MockInstance - ).mockImplementation(() => { - throw new Error(STOP_RUN_LOOP); - }); + stopAfterOneCrank(); await expect(kernelQueue.run(deliver)).rejects.toThrow(STOP_RUN_LOOP); expect(resolveSpy).toHaveBeenCalledWith(fulfilledValue); expect(rejectSpy).not.toHaveBeenCalled(); diff --git a/packages/ocap-kernel/src/KernelQueue.ts b/packages/ocap-kernel/src/KernelQueue.ts index 4148300ff..c29e334e6 100644 --- a/packages/ocap-kernel/src/KernelQueue.ts +++ b/packages/ocap-kernel/src/KernelQueue.ts @@ -56,14 +56,10 @@ export class KernelQueue { /** * 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. + * Attempted, not necessarily succeeded: it is forgotten either way, so a second + * attempt could only report "no such savepoint" over the real error. Recorded + * at the attempt rather than returned, because `#processCrankResult` can throw + * after rolling back. */ #crankRollbackAttempted: boolean = false; @@ -130,13 +126,18 @@ export class KernelQueue { this.#kernelStore.startCrank(); this.#crankRollbackAttempted = false; try { - this.#kernelStore.createCrankSavepoint('start'); + // Two savepoints, because rolling back the outermost one discards the + // enclosing transaction (see `rollbackSavepoint`) and an aborted crank + // still has writes to make. Only `delivery` is ever rolled back; + // releasing `crank` in `endCrank` is this crank's one commit point. + // `releaseAllSavepoints` names it by ordinal, so `crank` must stay first. + this.#kernelStore.createCrankSavepoint('crank'); + this.#kernelStore.createCrankSavepoint('delivery'); // 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. + // this, `endCrank`'s release commits the half-finished crank: the + // dequeued item is gone for good, refcount increments stick, and + // resolved promises keep their unflushed notifies. try { const queueItem = this.#getNextRunQueueItem(); if (queueItem) { @@ -153,15 +154,14 @@ export class KernelQueue { wakeUpPromise = promise; } } catch (error) { - // An aborted crank already asked, and `rollbackCrank` discards the - // savepoint either way; asking again could only throw "no such - // savepoint" over the real error. + // An aborted crank already asked; asking again could only throw "no + // such savepoint" over the real error. if (!this.#crankRollbackAttempted) { try { - this.#kernelStore.rollbackCrank('start'); + this.#kernelStore.rollbackCrank('delivery'); } catch (rollbackError) { - // The original failure stays the `cause`, since that is the root - // cause an operator needs; the rollback failure is named here. + // The original failure stays the `cause`; the rollback failure is + // named here. throw new Error( `Run loop died and its crank could not be rolled back: ${String(rollbackError)}`, { cause: error }, @@ -304,13 +304,11 @@ 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. try { - this.#kernelStore.rollbackCrank('start'); + this.#kernelStore.rollbackCrank('delivery'); } 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. + // Set even when the rollback threw: the savepoint is gone either way, so + // a second attempt would report a missing savepoint as the reason the + // kernel died, burying the error that actually killed it. this.#crankRollbackAttempted = true; } // Discard kernel subscriptions that were queued for invocation @@ -333,17 +331,26 @@ export class KernelQueue { // TODO: Currently all errors terminate the vat, but instead we could // restart it and terminate the vat only after a certain number of failed // retries. This is probably where we should implement the vat restart logic. - } else { - // Upon on successful crank completion, enqueue buffered vat outputs for delivery. - this.#flushCrankBuffer(); } - // Vat termination during delivery is triggered by an illegal syscall - // or by syscall.exit(). + // This call kills the worker, so its writes must outlive the rollback above: + // a store that still believed the vat was alive would relaunch it after a + // restart and redeliver what killed it. if (crankResult?.terminate) { const { vatId, info } = crankResult.terminate; await this.#terminateVat(vatId, info); } this.#kernelStore.collectGarbage(); + if (!crankResult?.abort) { + // After the fallible work above, not before it. The flush settles the + // promise `enqueueMessage` gave an external caller, so a later rollback + // would discard the state that answer was computed from. + // + // Not airtight: `#terminateVat` resolves the dying vat's promises through + // `resolvePromises`, which defaults to `immediate` and invokes their + // subscriptions before `collectGarbage`. Deferring those too would change + // termination semantics, not crank ordering. + this.#flushCrankBuffer(); + } } /** @@ -366,21 +373,23 @@ export class KernelQueue { */ #flushCrankBuffer(): void { const items = this.#kernelStore.flushCrankBuffer(); + const resolved: KRef[] = []; for (const item of items) { this.#enqueueRun(item); if (item.type === 'notify') { - // Invoke kernel subscription callback if any, reading resolution - // data from the (now committed) promise state - this.#invokeKernelSubscription(item.kpid); + resolved.push(item.kpid); } } + // Plus promises with no vat subscriber to notify, which the kernel is + // nonetheless waiting on (e.g. from `enqueueMessage`). + resolved.push(...this.#resolvedWithKernelSubscription); + this.#resolvedWithKernelSubscription = []; - // Invoke kernel subscriptions for promises resolved during this crank - // that don't have kernel-level subscribers (e.g., promises from enqueueMessage) - for (const kpid of this.#resolvedWithKernelSubscription) { + // Callbacks only once every `#enqueueRun` is done: one that threw partway + // would roll the crank back underneath answers already given. + for (const kpid of resolved) { this.#invokeKernelSubscription(kpid); } - this.#resolvedWithKernelSubscription = []; } /** diff --git a/packages/ocap-kernel/src/store/methods/crank.test.ts b/packages/ocap-kernel/src/store/methods/crank.test.ts index db3de8645..08a1e4925 100644 --- a/packages/ocap-kernel/src/store/methods/crank.test.ts +++ b/packages/ocap-kernel/src/store/methods/crank.test.ts @@ -153,6 +153,27 @@ describe('crank methods', () => { expect(mockCrankBuffer).toHaveLength(0); }); + + // A failed rollback discards every savepoint, not just this one. Truncating + // to the ordinal would have `endCrank` release a `t0` the database lacks and + // throw over whatever really killed the kernel. + it('forgets every savepoint when the rollback fails', () => { + context.inCrank = true; + crankMethods.createCrankSavepoint('crank'); + crankMethods.createCrankSavepoint('delivery'); + vi.mocked(kdb.rollbackSavepoint).mockImplementationOnce(() => { + throw new Error('disk I/O error'); + }); + + expect(() => crankMethods.rollbackCrank('delivery')).toThrow( + 'disk I/O error', + ); + + expect(context.savepoints).toStrictEqual([]); + // The release `endCrank` would otherwise attempt, and throw over. + crankMethods.endCrank(); + expect(kdb.releaseSavepoint).not.toHaveBeenCalled(); + }); }); describe('endCrank', () => { @@ -206,6 +227,21 @@ describe('crank methods', () => { expect(context.resolveCrank).toBeUndefined(); expect(await waiter).toBeUndefined(); }); + + // As `rollbackCrank` does. Left listed, the next crank numbers its savepoint + // `t1` against a database that has none, and every later release and rollback + // aims one crank past its target. + it('forgets its savepoints even if releasing them fails', () => { + crankMethods.startCrank(); + context.savepoints = ['test']; + vi.mocked(kdb.releaseSavepoint).mockImplementationOnce(() => { + throw new Error('database is gone'); + }); + + expect(() => crankMethods.endCrank()).toThrow('database is gone'); + + expect(context.savepoints).toStrictEqual([]); + }); }); describe('releaseAllSavepoints', () => { diff --git a/packages/ocap-kernel/src/store/methods/crank.ts b/packages/ocap-kernel/src/store/methods/crank.ts index 87d2bc65b..887ef2bee 100644 --- a/packages/ocap-kernel/src/store/methods/crank.ts +++ b/packages/ocap-kernel/src/store/methods/crank.ts @@ -51,13 +51,16 @@ export function getCrankMethods(ctx: StoreContext, kdb: KernelDatabase) { if (ctx.savepoints[ordinal] === savepoint) { 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. A failed - // rollback discards the whole transaction instead (see - // `rollbackSavepoint`), which for a crank is the same boundary. + // Left listed, `endCrank`'s release would commit the crank we just + // abandoned. ctx.savepoints.length = ordinal; + } catch (error) { + // A failed rollback discards the whole transaction, so every savepoint + // is gone, not just this one. Truncating to `ordinal` would have + // `endCrank` release a `t0` the database lacks and throw over whatever + // really killed the kernel. + ctx.savepoints.length = 0; + throw error; } // 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. @@ -77,8 +80,15 @@ export function getCrankMethods(ctx: StoreContext, kdb: KernelDatabase) { */ function releaseAllSavepoints(): void { if (ctx.savepoints.length > 0) { - kdb.releaseSavepoint('t0'); - ctx.savepoints.length = 0; + try { + kdb.releaseSavepoint('t0'); + } finally { + // A failed release discards the transaction too, so the database has no + // savepoints left either. Left listed, the next crank would number its + // savepoint `t1` and aim every later release and rollback one crank past + // the one it meant to end. + ctx.savepoints.length = 0; + } } }