fix: Remove redundant kernel promise ref count increment (#565)

rekmarks · web-flow · commit 7dd602deeb2c · 2025-07-04T13:34:50.000+02:00
While doing preliminary research to begin expanding our integration test
suite in `packages/kernel-test`, we discovered that the refcounts for an
object in `garbage-collection.test.ts` seemed too high by a count of 1
or 2. As it turned out, they were definitely at least off by one,
because we were redundantly incrementing the refcounts of kernel promise
data slots in `KernelStore.resolveKernelPromise()`. These are already
incremented in `KernelQueue.resolvePromise()`, which calls
`resolveKernelPromise()`. With this change, we keep the former and
abolish the latter.

We also include some changes that were made in the course of debugging,
that may prove generally helpful. This includes:
- A handful of `console.debug()` calls that help when debugging
refcounts.
- Logging an error if `Kernel.reset()` fails.

Finally, we remove some incidental tooling cruft from `kernel-test`.
diff --git a/package.json b/package.json
@@ -16,7 +16,7 @@
     "build:clean": "yarn clean && yarn build",
     "build:docs": "yarn workspaces foreach --all --exclude @ocap/monorepo --exclude @ocap/extension --parallel --interlaced --verbose run build:docs",
     "build:source": "ts-bridge --project tsconfig.build.json --verbose",
-    "build:special": "yarn workspace @ocap/vite-plugins run build && yarn workspace @metamask/kernel-shims run build && yarn workspace @metamask/kernel-browser-runtime run build:vite && yarn workspace @metamask/kernel-ui run build && yarn workspace @ocap/extension run build && yarn workspace @ocap/kernel-test run build:vats",
+    "build:special": "yarn workspace @ocap/vite-plugins run build && yarn workspace @metamask/kernel-shims run build && yarn workspace @metamask/kernel-browser-runtime run build:vite && yarn workspace @metamask/kernel-ui run build && yarn workspace @ocap/extension run build && yarn workspace @ocap/kernel-test run build",
     "bundle": "node ./scripts/bundle-vat.js",
     "changelog:update": "yarn workspaces foreach --all --no-private --parallel --interlaced --verbose run changelog:update",
     "changelog:validate": "yarn workspaces foreach --all --no-private --parallel --interlaced --verbose run changelog:validate",
diff --git a/packages/create-package/src/utils.test.ts b/packages/create-package/src/utils.test.ts
@@ -190,7 +190,6 @@ describe('create-package/utils', () => {
       (execa as Mock)
         .mockResolvedValueOnce(undefined)
         .mockImplementationOnce(() => {
-          console.log('FOOBAR');
           throw new Error('foo');
         });
 
diff --git a/packages/kernel-test/CHANGELOG.md b/packages/kernel-test/CHANGELOG.md
diff --git a/packages/kernel-test/README.md b/packages/kernel-test/README.md
@@ -2,14 +2,6 @@
 
 Run tests on the kernel that involve interaction with vats
 
-## Installation
-
-`yarn add @ocap/kernel-test`
-
-or
-
-`npm install @ocap/kernel-test`
-
 ## Contributing
 
 This package is part of a monorepo. Instructions for contributing can be found in the [monorepo README](https://github.com/MetaMask/ocap-kernel#readme).
diff --git a/packages/kernel-test/package.json b/packages/kernel-test/package.json
@@ -29,10 +29,7 @@
     "dist/"
   ],
   "scripts": {
-    "build": "ts-bridge --project tsconfig.build.json --clean && yarn build:vats",
-    "build:vats": "ocap bundle src/vats",
-    "build:docs": "typedoc",
-    "changelog:validate": "../../scripts/validate-changelog.sh @ocap/kernel-test",
+    "build": "ocap bundle src/vats",
     "clean": "rimraf --glob './*.tsbuildinfo' ./.eslintcache ./coverage ./dist './src/**/*.bundle'",
     "lint": "yarn lint:eslint && yarn lint:misc --check && yarn constraints && yarn lint:dependencies",
     "lint:dependencies": "depcheck",
@@ -64,13 +61,10 @@
   },
   "devDependencies": {
     "@arethetypeswrong/cli": "^0.17.4",
-    "@metamask/auto-changelog": "^5.0.1",
     "@metamask/eslint-config": "^14.0.0",
     "@metamask/eslint-config-nodejs": "^14.0.0",
     "@metamask/eslint-config-typescript": "^14.0.0",
     "@ocap/cli": "workspace:^",
-    "@ts-bridge/cli": "^0.6.3",
-    "@ts-bridge/shims": "^0.1.1",
     "@typescript-eslint/eslint-plugin": "^8.29.0",
     "@typescript-eslint/parser": "^8.29.0",
     "@typescript-eslint/utils": "^8.29.0",
@@ -87,7 +81,6 @@
     "jsdom": "^26.0.0",
     "prettier": "^3.5.3",
     "rimraf": "^6.0.1",
-    "typedoc": "^0.28.1",
     "typescript": "~5.8.2",
     "typescript-eslint": "^8.29.0",
     "vite": "^6.3.5",
diff --git a/packages/kernel-test/src/garbage-collection.test.ts b/packages/kernel-test/src/garbage-collection.test.ts
@@ -83,8 +83,8 @@ describe('Garbage Collection', () => {
     const createObjectRef = createObjectData.slots[0] as KRef;
     // Verify initial reference counts from database
     const initialRefCounts = kernelStore.getObjectRefCount(createObjectRef);
-    expect(initialRefCounts.reachable).toBe(3);
-    expect(initialRefCounts.recognizable).toBe(3);
+    expect(initialRefCounts.reachable).toBe(2);
+    expect(initialRefCounts.recognizable).toBe(2);
     // Send the object to the importer vat
     const objectRef = kunser(createObjectData);
     await kernel.queueMessage(importerKRef, 'storeImport', [objectRef]);
@@ -117,8 +117,8 @@ describe('Garbage Collection', () => {
 
     // Store initial reference count information
     const initialRefCounts = kernelStore.getObjectRefCount(createObjectRef);
-    expect(initialRefCounts.reachable).toBe(3);
-    expect(initialRefCounts.recognizable).toBe(3);
+    expect(initialRefCounts.reachable).toBe(2);
+    expect(initialRefCounts.recognizable).toBe(2);
 
     // Store the reference in the importer vat
     const objectRef = kunser(createObjectData);
@@ -159,8 +159,8 @@ describe('Garbage Collection', () => {
 
     // Check reference counts after dropImports
     const afterWeakRefCounts = kernelStore.getObjectRefCount(createObjectRef);
-    expect(afterWeakRefCounts.reachable).toBe(2);
-    expect(afterWeakRefCounts.recognizable).toBe(3);
+    expect(afterWeakRefCounts.reachable).toBe(1);
+    expect(afterWeakRefCounts.recognizable).toBe(2);
 
     // Now completely forget the import in the importer vat
     // This should trigger retireImports when GC runs
@@ -177,8 +177,8 @@ describe('Garbage Collection', () => {
 
     // Check reference counts after retireImports
     const afterForgetRefCounts = kernelStore.getObjectRefCount(createObjectRef);
-    expect(afterForgetRefCounts.reachable).toBe(2);
-    expect(afterForgetRefCounts.recognizable).toBe(2);
+    expect(afterForgetRefCounts.reachable).toBe(1);
+    expect(afterForgetRefCounts.recognizable).toBe(1);
 
     // Now forget the object in the exporter vat
     // This should trigger retireExports when GC runs
diff --git a/packages/kernel-test/src/utils.ts b/packages/kernel-test/src/utils.ts
@@ -2,7 +2,7 @@
 /// <reference types="vite/client" />
 
 import type { KernelDatabase } from '@metamask/kernel-store';
-import { waitUntilQuiescent } from '@metamask/kernel-utils';
+import { stringify, waitUntilQuiescent } from '@metamask/kernel-utils';
 import { Logger, makeArrayTransport } from '@metamask/logger';
 import type { LogEntry } from '@metamask/logger';
 import { Kernel, kunser } from '@metamask/ocap-kernel';
@@ -170,7 +170,7 @@ export function logDatabase(
   logger: Logger = console as unknown as Logger,
 ): void {
   const result = kernelDatabase.executeQuery('SELECT * FROM kv');
-  logger.log('kv result', result);
+  logger.log('kv result', stringify(result));
 }
 
 /**
diff --git a/packages/kernel-test/tsconfig.build.json b/packages/kernel-test/tsconfig.build.json
diff --git a/packages/kernel-test/tsconfig.json b/packages/kernel-test/tsconfig.json
@@ -4,6 +4,7 @@
     "allowJs": true,
     "baseUrl": "./",
     "lib": ["ES2022"],
+    "noEmit": true,
     "types": ["vitest"]
   },
   "references": [
@@ -14,10 +15,5 @@
     { "path": "../ocap-kernel" },
     { "path": "../kernel-store" }
   ],
-  "include": [
-    "../../vitest.config.ts",
-    "./src",
-    "./vite.config.ts",
-    "./vitest.config.ts"
-  ]
+  "include": ["../../vitest.config.ts", "./src", "./vitest.config.ts"]
 }
diff --git a/packages/kernel-test/typedoc.json b/packages/kernel-test/typedoc.json
diff --git a/packages/kernel-ui/src/hooks/useKernelActions.test.ts b/packages/kernel-ui/src/hooks/useKernelActions.test.ts
@@ -126,12 +126,12 @@ describe('useKernelActions', () => {
       const { useKernelActions } = await import('./useKernelActions.ts');
       const { result } = renderHook(() => useKernelActions());
 
-      mockSendMessage.mockRejectedValueOnce(new Error());
+      mockSendMessage.mockRejectedValueOnce(new Error('test error'));
 
       result.current.clearState();
       await waitFor(() => {
         expect(mockLogMessage).toHaveBeenCalledWith(
-          'Failed to clear state',
+          'Failed to clear state: test error',
           'error',
         );
       });
diff --git a/packages/kernel-ui/src/hooks/useKernelActions.ts b/packages/kernel-ui/src/hooks/useKernelActions.ts
@@ -50,7 +50,9 @@ export function useKernelActions(): {
       params: [],
     })
       .then(() => logMessage('State cleared', 'success'))
-      .catch(() => logMessage('Failed to clear state', 'error'));
+      .catch((error: Error) =>
+        logMessage(`Failed to clear state: ${error.message}`, 'error'),
+      );
   }, [callKernelMethod, logMessage]);
 
   /**
diff --git a/packages/ocap-kernel/src/Kernel.test.ts b/packages/ocap-kernel/src/Kernel.test.ts
@@ -1,6 +1,7 @@
 import { VatNotFoundError } from '@metamask/kernel-errors';
 import type { KernelDatabase } from '@metamask/kernel-store';
 import type { JsonRpcMessage } from '@metamask/kernel-utils';
+import { Logger } from '@metamask/logger';
 import type { DuplexStream } from '@metamask/streams';
 import type { JsonRpcResponse, JsonRpcRequest } from '@metamask/utils';
 import { TestDuplexStream } from '@ocap/test-utils/streams';
@@ -800,6 +801,25 @@ describe('Kernel', () => {
       expect(clearSpy).toHaveBeenCalled();
       expect(kernel.getVatIds()).toHaveLength(0);
     });
+
+    it('logs an error if resetting the kernel state fails', async () => {
+      const mockDb = makeMapKernelDatabase();
+      const logger = new Logger('test');
+      const logErrorSpy = vi.spyOn(logger, 'error');
+      const kernel = await Kernel.make(mockStream, mockWorkerService, mockDb, {
+        logger,
+      });
+      await kernel.launchSubcluster(makeSingleVatClusterConfig());
+
+      vi.spyOn(mockDb, 'clear').mockImplementationOnce(() => {
+        throw new Error('test error');
+      });
+      await expect(kernel.reset()).rejects.toThrow('test error');
+      expect(logErrorSpy).toHaveBeenCalledWith(
+        'Error resetting kernel:',
+        new Error('test error'),
+      );
+    });
   });
 
   describe('revoke and isRevoked', () => {
diff --git a/packages/ocap-kernel/src/Kernel.ts b/packages/ocap-kernel/src/Kernel.ts
@@ -617,8 +617,13 @@ export class Kernel {
    * This is for debugging purposes only.
    */
   async reset(): Promise<void> {
-    await this.terminateAllVats();
-    this.#resetKernelState();
+    try {
+      await this.terminateAllVats();
+      this.#resetKernelState();
+    } catch (error) {
+      this.#logger.error('Error resetting kernel:', error);
+      throw error;
+    }
   }
 
   /**
diff --git a/packages/ocap-kernel/src/KernelQueue.test.ts b/packages/ocap-kernel/src/KernelQueue.test.ts
@@ -8,12 +8,7 @@ import { KernelQueue } from './KernelQueue.ts';
 import * as gc from './services/garbage-collection.ts';
 import type { KernelStore } from './store/index.ts';
 import * as types from './types.ts';
-import type {
-  KRef,
-  Message,
-  RunQueueItem,
-  RunQueueItemNotify,
-} from './types.ts';
+import type { KRef, Message, RunQueueItem } from './types.ts';
 
 vi.mock('./services/garbage-collection.ts', () => ({
   processGCActionSet: vi.fn().mockReturnValue(null),
@@ -252,12 +247,11 @@ describe('KernelQueue', () => {
       const vatId = 'v1';
       const kpid = 'kp123';
       kernelQueue.enqueueNotify(vatId, kpid);
-      const expectedNotifyItem: RunQueueItemNotify = {
+      expect(kernelStore.enqueueRun).toHaveBeenCalledWith({
         type: 'notify',
         vatId,
         kpid,
-      };
-      expect(kernelStore.enqueueRun).toHaveBeenCalledWith(expectedNotifyItem);
+      });
       expect(kernelStore.incrementRefCount).toHaveBeenCalledWith(
         kpid,
         'notify',
diff --git a/packages/ocap-kernel/src/KernelQueue.ts b/packages/ocap-kernel/src/KernelQueue.ts
@@ -152,6 +152,9 @@ export class KernelQueue {
     method: string,
     args: unknown[],
   ): Promise<CapData<KRef>> {
+    // TODO(#562): Use logger instead.
+    // eslint-disable-next-line no-console
+    console.debug('enqueueMessage', target, method, args);
     const result = this.#kernelStore.initKernelPromise()[0];
     const { promise, resolve } = makePromiseKit<CapData<KRef>>();
     this.subscriptions.set(result, resolve);
@@ -232,9 +235,11 @@ export class KernelQueue {
       if (!subscribers) {
         throw Fail`${kpid} subscribers not set`;
       }
+
       for (const subscriber of subscribers) {
         this.enqueueNotify(subscriber, kpid);
       }
+
       this.#kernelStore.resolveKernelPromise(kpid, rejected, data);
       const kernelResolve = this.subscriptions.get(kpid);
       if (kernelResolve) {
diff --git a/packages/ocap-kernel/src/store/methods/object.ts b/packages/ocap-kernel/src/store/methods/object.ts
@@ -31,6 +31,9 @@ export function getObjectMethods(ctx: StoreContext) {
     const koId = getNextObjectId();
     ctx.kv.set(getOwnerKey(koId), owner);
     setObjectRefCount(koId, { reachable: 1, recognizable: 1 });
+    // TODO(#562): Use logger instead.
+    // eslint-disable-next-line no-console
+    console.debug('initKernelObject', koId, owner, getObjectRefCount(koId));
     return koId;
   }
 
diff --git a/packages/ocap-kernel/src/store/methods/promise.test.ts b/packages/ocap-kernel/src/store/methods/promise.test.ts
@@ -59,7 +59,6 @@ describe('promise store methods', () => {
   };
   let context: StoreContext;
   let promiseMethods: ReturnType<typeof getPromiseMethods>;
-  const mockIncrementRefCount = vi.fn();
   const mockDecrementRefCount = vi.fn();
 
   beforeEach(() => {
@@ -87,7 +86,6 @@ describe('promise store methods', () => {
     });
 
     (getRefCountMethods as ReturnType<typeof vi.fn>).mockReturnValue({
-      incrementRefCount: mockIncrementRefCount,
       decrementRefCount: mockDecrementRefCount,
     });
 
@@ -338,7 +336,6 @@ describe('promise store methods', () => {
       expect(mockKV.has(`${kpid}.decider`)).toBe(false);
       expect(mockKV.has(`${kpid}.subscribers`)).toBe(false);
       expect(mockQueue.delete).toHaveBeenCalled();
-      expect(mockIncrementRefCount).toHaveBeenCalledTimes(2);
       expect(mockDecrementRefCount).toHaveBeenCalledTimes(1);
     });
 
diff --git a/packages/ocap-kernel/src/store/methods/promise.ts b/packages/ocap-kernel/src/store/methods/promise.ts
@@ -30,7 +30,7 @@ export function getPromiseMethods(ctx: StoreContext) {
   const { incCounter, provideStoredQueue, getPrefixedKeys, refCountKey } =
     getBaseMethods(ctx.kv);
   const { enqueueRun } = getQueueMethods(ctx);
-  const { incrementRefCount, decrementRefCount } = getRefCountMethods(ctx);
+  const { decrementRefCount } = getRefCountMethods(ctx);
 
   /**
    * Create a new, unresolved kernel promise. The new promise will be born with
@@ -50,6 +50,14 @@ export function getPromiseMethods(ctx: StoreContext) {
     ctx.kv.set(`${kpid}.state`, 'unresolved');
     ctx.kv.set(`${kpid}.subscribers`, '[]');
     ctx.kv.set(refCountKey(kpid), '1');
+    // TODO(#562): Use logger instead.
+    // eslint-disable-next-line no-console
+    console.debug(
+      'initKernelPromise',
+      kpid,
+      ctx.kv.get(refCountKey(kpid)),
+      kpr,
+    );
     return [kpid, kpr];
   }
 
@@ -156,12 +164,6 @@ export function getPromiseMethods(ctx: StoreContext) {
     rejected: boolean,
     value: CapData<KRef>,
   ): void {
-    let idx = 0;
-    for (const dataSlot of value.slots) {
-      incrementRefCount(dataSlot, `resolve|${kpid}|s${idx}`);
-      idx += 1;
-    }
-
     const queue = provideStoredQueue(kpid, false);
     for (const message of getKernelPromiseMessageQueue(kpid)) {
       const messageItem: RunQueueItemSend = {
diff --git a/packages/ocap-kernel/src/store/methods/vat.ts b/packages/ocap-kernel/src/store/methods/vat.ts
@@ -340,6 +340,7 @@ export function getVatMethods(ctx: StoreContext) {
       isExport: true,
       onlyRecognizable: true,
     });
+    ctx.logger?.debug('exportFromVat', vatId, vref, kref);
     return kref;
   }
 
diff --git a/packages/vite-plugins/README.md b/packages/vite-plugins/README.md
diff --git a/tsconfig.build.json b/tsconfig.build.json
diff --git a/vitest.config.ts b/vitest.config.ts
diff --git a/yarn.config.cjs b/yarn.config.cjs
diff --git a/yarn.lock b/yarn.lock
