fix: keep a crank's store work inside one transaction

packages/kernel-browser-runtime/CHANGELOG.md

@@ -13,6 +13,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ### Fixed
 
+- The kernel worker gives the kernel store a logger, so the wasm SQLite driver's diagnostics reach the log rather than nowhere ([#1021](https://github.com/Consensys-Incorporated/ocap-kernel/pull/1021))
 - Process platform-services RPC request handlers in the background so a request handler that fires a reentrant outbound RPC (e.g. transport handshake calling back into the kernel) cannot deadlock waiting for its response ([#948](https://github.com/MetaMask/ocap-kernel/pull/948))
 
 ## [0.6.0]

packages/kernel-browser-runtime/src/kernel-worker/kernel-worker.ts

@@ -44,7 +44,10 @@ async function main(): Promise<void> {
         isJsonRpcMessage,
       ),
       PlatformServicesClient.make(globalThis as PostMessageTarget),
-      makeSQLKernelDatabase({ dbFilename: DB_FILENAME }),
+      makeSQLKernelDatabase({
+        dbFilename: DB_FILENAME,
+        logger: logger.subLogger({ tags: ['kernel-store'] }),
+      }),
     ]);
 
   setupConsoleForwarding({

packages/kernel-node-runtime/CHANGELOG.md

@@ -23,6 +23,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ### Fixed
 
+- `makeKernel` gives the kernel store a logger, so the SQLite driver's diagnostics reach the log rather than nowhere ([#1021](https://github.com/Consensys-Incorporated/ocap-kernel/pull/1021))
 - The RPC socket server refuses to bind a Unix socket that has a live listener, rather than unlinking it and orphaning the previous owner; stale socket files with no listener are still cleaned up automatically ([#952](https://github.com/MetaMask/ocap-kernel/pull/952))
 
 ## [0.1.0]

packages/kernel-node-runtime/src/kernel/make-kernel.test.ts

@@ -1,3 +1,5 @@
+import { makeSQLKernelDatabase } from '@metamask/kernel-store/sqlite/nodejs';
+import { Logger } from '@metamask/logger';
 import { Kernel } from '@metamask/ocap-kernel';
 import { describe, expect, it, vi } from 'vitest';
 
@@ -8,7 +10,7 @@ vi.mock('@metamask/kernel-store/sqlite/nodejs', async () => {
     '../../../ocap-kernel/test/storage.ts'
   );
   return {
-    makeSQLKernelDatabase: makeMapKernelDatabase,
+    makeSQLKernelDatabase: vi.fn(makeMapKernelDatabase),
   };
 });
 
@@ -18,4 +20,12 @@ describe('makeKernel', () => {
 
     expect(kernel).toBeInstanceOf(Kernel);
   });
+
+  it('gives the kernel store a logger', async () => {
+    await makeKernel({});
+
+    expect(vi.mocked(makeSQLKernelDatabase)).toHaveBeenCalledWith(
+      expect.objectContaining({ logger: expect.any(Logger) }),
+    );
+  });
 });

packages/kernel-node-runtime/src/kernel/make-kernel.ts

@@ -60,7 +60,10 @@ export async function makeKernel({
   });
 
   // Initialize kernel store.
-  const kernelDatabase = await makeSQLKernelDatabase({ dbFilename });
+  const kernelDatabase = await makeSQLKernelDatabase({
+    dbFilename,
+    logger: rootLogger.subLogger({ tags: ['kernel-store'] }),
+  });
 
   // Create and start kernel.
   const kernel = await Kernel.make(platformServicesClient, kernelDatabase, {

packages/kernel-store/CHANGELOG.md

@@ -12,6 +12,17 @@ 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`; the release failure is still what gets thrown ([#1021](https://github.com/Consensys-Incorporated/ocap-kernel/pull/1021))
+- The wasm driver no longer considers itself in a transaction after a commit or abort throws, and discards the transaction a failed `COMMIT` leaves open ([#1021](https://github.com/Consensys-Incorporated/ocap-kernel/pull/1021))
+  - Otherwise later writes autocommitted — including the next savepoint, created bare, where `RELEASE` commits and no rollback can undo the work. The nodejs driver reads `db.inTransaction` and was never affected by the wedged flag
+- The nodejs driver discards the transaction a failed `COMMIT` leaves open, as the wasm driver already did ([#1021](https://github.com/Consensys-Incorporated/ocap-kernel/pull/1021))
+  - `releaseSavepoint` reaches `commitIfNeeded` outside any try of its own, so a throwing `COMMIT` left the transaction open with nothing to end it. Reading `db.inTransaction` prevents a wedged flag but does not end an unowned transaction
+- Neither driver commits a transaction whose discarding abort failed ([#1021](https://github.com/Consensys-Incorporated/ocap-kernel/pull/1021))
+  - The savepoint list was emptied while SQLite still held the transaction, so the next `createSavepoint` skipped `BEGIN`, nested inside it, and committed the abandoned crank on release. Both drivers now retry the abort before beginning, and abort rather than commit while one is outstanding
+- Every write refuses while a transaction the drivers could not abort is outstanding, not just the ones that pass through `beginIfNeeded` or `commitIfNeeded` ([#1021](https://github.com/Consensys-Incorporated/ocap-kernel/pull/1021))
+  - `kernelKVStore.set`, `kernelKVStore.delete`, `clear`, `deleteVatStore`, the savepoint operations, and the nodejs driver's vatstore update joined the abandoned transaction and reported success. Teardown such as `reset` looked like it had landed, and the writes went with the transaction on close
+  - `executeQuery` stays exempt: its callers are debug surfaces, which would not expect a query to roll anything back
+- Both drivers log an abort that fails while recovering from a failed savepoint operation ([#1021](https://github.com/Consensys-Incorporated/ocap-kernel/pull/1021))
 
 ## [0.6.0]
 

packages/kernel-store/src/sqlite/nodejs.savepoint-interleaving.test.ts

@@ -0,0 +1,94 @@
+import { describe, it, expect } from 'vitest';
+
+import { makeSQLKernelDatabase } from './nodejs.ts';
+
+/**
+ * Why a crank and a savepoint of someone else's must never overlap.
+ *
+ * `KernelQueue.#runLoop` calls releasing its `crank` savepoint "this crank's one
+ * commit point". `releaseAllSavepoints` releases `t0`, which is the outermost
+ * savepoint only if the crank opened the first one, and `KernelStore`'s own
+ * `createSavepoint` bypasses `ctx.savepoints` and so is invisible to the ordinal
+ * numbering. Two production paths use it: `RemoteHandle.handleRemoteMessage` and
+ * `RemoteManager.handleIncarnationChange`.
+ *
+ * Real SQLite through the real driver, one test per interleaving. Each records
+ * what SQLite actually does, which is the reason the kernel now serializes the
+ * two: `createSavepoint` refuses inside a crank, `startCrank` refuses while a
+ * caller holds the store outside one, and callers take their turn through
+ * `beginOutOfCrank`. See `crank.out-of-crank.test.ts` for the enforcement.
+ */
+describe('a savepoint the crank does not know about', () => {
+  it('outside the crank, leaves the crank release with nothing to commit', async () => {
+    const kdb = await makeSQLKernelDatabase({ dbFilename: ':memory:' });
+    const kv = kdb.kernelKVStore;
+
+    // RemoteHandle.handleRemoteMessage, parked on its await.
+    kdb.createSavepoint('receive_r1_7');
+
+    // The run loop wakes: startCrank, then the two crank savepoints.
+    kdb.createSavepoint('t0');
+    kdb.createSavepoint('t1');
+    kv.set('crankWrite', 'durable');
+
+    // endCrank -> releaseAllSavepoints -> releaseSavepoint('t0'). `t0` is not the
+    // outermost savepoint, so this releases into the remote's, not to a commit.
+    kdb.releaseSavepoint('t0');
+
+    // The remote message then fails, so RemoteHandle rolls its savepoint back,
+    // and takes the whole committed-looking crank with it.
+    kdb.rollbackSavepoint('receive_r1_7');
+
+    expect(kv.get('crankWrite')).toBeUndefined();
+    kdb.close();
+  });
+
+  it('inside the crank, is destroyed by the delivery rollback behind its owner', async () => {
+    const kdb = await makeSQLKernelDatabase({ dbFilename: ':memory:' });
+    const kv = kdb.kernelKVStore;
+
+    // startCrank
+    kdb.createSavepoint('t0');
+    kdb.createSavepoint('t1');
+
+    // A remote message arrives during `await deliver(queueItem)`.
+    kdb.createSavepoint('receive_r1_7');
+    kv.set('remoteSeq.r1.highestReceivedSeq', '7');
+
+    // The delivery aborts: rollbackCrank('delivery') issues ROLLBACK TO t1, and
+    // SQLite cancels every savepoint started after t1 -- including the remote's.
+    kdb.rollbackSavepoint('t1');
+
+    // The remote handler, still inside its own try, reaches its release and
+    // finds the savepoint gone along with everything it wrote.
+    expect(() => kdb.releaseSavepoint('receive_r1_7')).toThrow(
+      'No such savepoint: receive_r1_7',
+    );
+    expect(kv.get('remoteSeq.r1.highestReceivedSeq')).toBeUndefined();
+    kdb.close();
+  });
+
+  it('inside a crank that succeeds, is committed under its owner', async () => {
+    const kdb = await makeSQLKernelDatabase({ dbFilename: ':memory:' });
+    const kv = kdb.kernelKVStore;
+
+    // A remote message arrives and gets as far as its await, so the seq row it
+    // writes "at the end, within the transaction" is not written yet.
+    kdb.createSavepoint('t0');
+    kdb.createSavepoint('t1');
+    kdb.createSavepoint('receive_r1_7');
+    kv.set('remoteHalfDone', 'yes');
+
+    // endCrank releases t0, and with it everything stacked above.
+    kdb.releaseSavepoint('t0');
+
+    // The remote handler resumes to find its savepoint gone -- and its
+    // half-finished work durable regardless, so it reports a failure for an
+    // effect that has landed and the peer retries it.
+    expect(() => kdb.releaseSavepoint('receive_r1_7')).toThrow(
+      'No such savepoint: receive_r1_7',
+    );
+    expect(kv.get('remoteHalfDone')).toBe('yes');
+    kdb.close();
+  });
+});

packages/kernel-store/src/sqlite/nodejs.test.ts

@@ -308,7 +308,6 @@ describe('makeSQLKernelDatabase', () => {
       );
 
       expect(mockDb._spStack).toStrictEqual([]);
-      // The abort is the only prepared statement this path runs.
       expect(mockStatement.run).toHaveBeenCalledOnce();
       mockDb.inTransaction = false;
     });
@@ -360,6 +359,44 @@ describe('makeSQLKernelDatabase', () => {
       expect(mockDb._spStack).toStrictEqual([]);
     });
 
+    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');