fix(ocap-kernel): log the result promise a failed delivery leaves settled

Review follow-up. The caller then gets the endpoint's answer rather than
`DELIVERY_FAILED`, and nothing else said so. The regression test runs the
crank's reference count audit, and `KernelRouter.test.ts`'s shared store
mock reports an unresolved promise by default.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

Author: sirtimid

packages/ocap-kernel/src/KernelRouter.result-promise.test.ts

@@ -1,4 +1,5 @@
 import { makeSQLKernelDatabase } from '@metamask/kernel-store/sqlite/nodejs';
+import type { Logger } from '@metamask/logger';
 import { describe, it, expect, vi } from 'vitest';
 
 import { KernelQueue } from './KernelQueue.ts';
@@ -9,8 +10,7 @@ import type { EndpointHandle, KRef, RunQueueItem } from './types.ts';
 
 /**
  * `KernelRouter`'s own tests mock `resolvePromises`, so nothing there can see a
- * second resolution of one promise — which is a `Fail`, and reaches the run
- * loop from inside the very catch meant to contain the delivery's failure.
+ * second resolution of one promise. These run against a real store and queue.
  */
 describe('a result promise whose delivery fails', () => {
   /**
@@ -22,10 +22,12 @@ describe('a result promise whose delivery fails', () => {
   async function makeFixture(deliverMessage: () => Promise<never>): Promise<{
     kernelStore: ReturnType<typeof makeKernelStore>;
     kernelQueue: KernelQueue;
+    logger: Logger;
     runCrank: () => Promise<void>;
   }> {
     const kdb = await makeSQLKernelDatabase({ dbFilename: ':memory:' });
     const kernelStore = makeKernelStore(kdb);
+    kernelStore.setRefCountAuditing(true);
     const kernelQueue = new KernelQueue(kernelStore, async () => undefined);
     const endpoint = {
       deliverMessage: vi.fn(deliverMessage),
@@ -35,11 +37,13 @@ describe('a result promise whose delivery fails', () => {
       deliverRetireImports: vi.fn(),
       deliverBringOutYourDead: vi.fn(),
     } as unknown as EndpointHandle;
+    const logger = { error: vi.fn(), log: vi.fn() } as unknown as Logger;
     const kernelRouter = new KernelRouter(
       kernelStore,
       kernelQueue,
       () => endpoint,
       () => undefined,
+      logger,
     );
 
     // The run loop's crank, minus the run loop.
@@ -50,12 +54,13 @@ describe('a result promise whose delivery fails', () => {
         const item = kernelStore.dequeueRun() as RunQueueItem;
         await kernelRouter.deliver(item);
         kernelStore.collectGarbage();
+        kernelStore.assertRefCountsIfAuditing();
       } finally {
         kernelStore.endCrank();
       }
     };
 
-    return { kernelStore, kernelQueue, runCrank };
+    return { kernelStore, kernelQueue, logger, runCrank };
   }
 
   /**
@@ -93,9 +98,6 @@ describe('a result promise whose delivery fails', () => {
     expect(kernelStore.getKernelPromise(result).state).toBe('rejected');
   });
 
-  // A vat that resolves the result and then loses its stream is one way in; a
-  // stream that dies mid-delivery is the other, since retiring the vat rejects
-  // every promise it was deciding and this one's decider was just set.
   it.each([
     { how: 'fulfilled', rejected: false, state: 'fulfilled' },
     { how: 'rejected', rejected: true, state: 'rejected' },
@@ -105,7 +107,7 @@ describe('a result promise whose delivery fails', () => {
       // Held in an object so the endpoint can reach it before the queue that
       // settles the promise exists.
       const endpointDoes = { settleTheResult: (): void => undefined };
-      const { kernelStore, kernelQueue, runCrank } = await makeFixture(
+      const { kernelStore, kernelQueue, logger, runCrank } = await makeFixture(
         async () => {
           endpointDoes.settleTheResult();
           throw new Error('stream closed');
@@ -117,12 +119,15 @@ describe('a result promise whose delivery fails', () => {
           [result, rejected, kser('settled by the endpoint')],
         ]);
 
-      expect(await runCrank()).toBeUndefined();
+      await runCrank();
 
       const settled = kernelStore.getKernelPromise(result);
       expect(settled.state).toBe(state);
       // The endpoint's own settlement, not the delivery's `DELIVERY_FAILED`.
       expect(settled.value?.body).toContain('settled by the endpoint');
+      expect(logger.error).toHaveBeenCalledWith(
+        expect.stringContaining(`already ${state}`),
+      );
     },
   );
 });

packages/ocap-kernel/src/KernelRouter.test.ts

@@ -46,7 +46,9 @@ describe('KernelRouter', () => {
     kernelStore = {
       getOwner: vi.fn(),
       isRevoked: vi.fn(),
-      getKernelPromise: vi.fn(),
+      // Unresolved is the default so that reading a promise's state is never
+      // a `TypeError` in a test that does not care about it.
+      getKernelPromise: vi.fn().mockReturnValue({ state: 'unresolved' }),
       decrementRefCount: vi.fn(),
       setPromiseDecider: vi.fn(),
       translateRefKtoE: vi.fn(
@@ -490,10 +492,6 @@ describe('KernelRouter', () => {
         (
           endpointHandle.deliverMessage as unknown as MockInstance
         ).mockRejectedValueOnce(new Error('queue full'));
-        (
-          kernelStore.getKernelPromise as unknown as MockInstance
-        ).mockReturnValueOnce({ state: 'unresolved' });
-
         const message: Message = {
           methargs: { body: 'method args', slots: [] },
           result: 'kp1',

packages/ocap-kernel/src/KernelRouter.ts

@@ -212,6 +212,11 @@ export class KernelRouter {
   ): void {
     const { state } = this.#kernelStore.getKernelPromise(kpid);
     if (state !== 'unresolved') {
+      // The caller gets the endpoint's answer, not the delivery's failure, and
+      // the `error` above is the only other trace of either.
+      this.#logger?.error(
+        `Result ${kpid} of the failed delivery to ${endpointId} is already ${state}; leaving it alone`,
+      );
       return;
     }
     this.#kernelQueue.resolvePromises(endpointId, [[kpid, true, failure]]);