Log the refusal we didn't send

src/app.ts

@@ -44,7 +44,7 @@ export function createApp(ctx: StackContext, config: Config, logger: Logger): Ho
       exposeHeaders: ['X-Request-Id', 'Content-Disposition'],
     }),
   );
-  app.onError(errorMiddleware(logger));
+  app.onError(errorMiddleware(logger, ctx.stack));
   app.use(authMiddleware(config.ownerToken, ctx));
 
   // Cap request body size globally — not per-prefix, so a route added later

src/middleware/errors.ts

@@ -1,7 +1,7 @@
 import type { ErrorHandler } from 'hono';
 import type { ContentfulStatusCode } from 'hono/utils/http-status';
 import type { Logger } from 'pino';
-import { StackPermissionError } from '@haverstack/core';
+import { StackPermissionError, StackNotFoundError, type Stack } from '@haverstack/core';
 import type { AppEnv } from '../types.js';
 import { serializeError } from '@haverstack/wire-types';
 
@@ -11,9 +11,13 @@ import { serializeError } from '@haverstack/wire-types';
  * the wire-format's typed `{ error: { code, message } }` body. Anything
  * else is an unanticipated bug: log it and return a bodyless 500 rather
  * than guessing at a taxonomy it doesn't belong to.
+ *
+ * `stack` is the unscoped root Stack, used only to probe existence for the
+ * refusal log below — never to read content or bypass a permission check
+ * for the response itself.
  */
-export function errorMiddleware(logger: Logger): ErrorHandler<AppEnv> {
-  return (err, c) => {
+export function errorMiddleware(logger: Logger, stack: Stack): ErrorHandler<AppEnv> {
+  return async (err, c) => {
     const wire = serializeError(err);
     if (wire) {
       // A permission denial with a resolved auth means the requester's DID
@@ -33,6 +37,40 @@ export function errorMiddleware(logger: Logger): ErrorHandler<AppEnv> {
           'Denied a verified requester',
         );
       }
+      // A StackNotFoundError for a verified requester is deliberately
+      // indistinguishable, on the wire, from a genuinely missing record
+      // (docs/spec/wire-format.md § Server implementation checklist,
+      // "Log the refusal you didn't send") — that's the anti-oracle rule
+      // #79 adopted. But the operator is not the adversary: an unscoped
+      // existence probe here (one extra read, only on a path that's
+      // already failing) recovers the distinction for the log without
+      // ever surfacing it to the client. `check` is always 'read' because
+      // ScopedStack's denialFor()/get() both collapse into
+      // StackNotFoundError exactly when canRead() is false, regardless of
+      // which verb (update/delete/etc.) the request asked for — there's no
+      // second gate to name here.
+      //
+      // Logged at debug, not warn: unlike the denial line above, this one
+      // is "who asked after what, and was refused" — the sharing graph,
+      // written down — and the spec asks that it not ship to a
+      // general-purpose aggregator by default (default LOG_LEVEL is info).
+      if (err instanceof StackNotFoundError && auth) {
+        const recordId = c.req.param('id');
+        if (recordId) {
+          const existing = await stack.get(recordId);
+          logger.debug(
+            {
+              requestId: c.get('requestId'),
+              principalId: auth.principalId,
+              subjectId: auth.subjectId,
+              recordId,
+              existed: existing !== null,
+              check: 'read',
+            },
+            'Refused a verified requester a 404',
+          );
+        }
+      }
       // An anonymous requester gets the same 404 for a private record as for
       // a missing one (docs/spec/wire-format.md § Server implementation
       // checklist): a bare 403 or 401 here would confirm the record exists

tests/middleware/errors.test.ts

@@ -13,10 +13,16 @@ import type { StackContext } from '../../src/stack.js';
 import { rm } from 'node:fs/promises';
 import { dirname } from 'node:path';
 
-function spyLogger(): Logger & { warn: ReturnType<typeof vi.fn> } {
-  return { warn: vi.fn(), error: vi.fn(), info: vi.fn() } as unknown as Logger & {
-    warn: ReturnType<typeof vi.fn>;
-  };
+function spyLogger(): Logger & {
+  warn: ReturnType<typeof vi.fn>;
+  debug: ReturnType<typeof vi.fn>;
+} {
+  return {
+    warn: vi.fn(),
+    error: vi.fn(),
+    info: vi.fn(),
+    debug: vi.fn(),
+  } as unknown as Logger & { warn: ReturnType<typeof vi.fn>; debug: ReturnType<typeof vi.fn> };
 }
 
 describe('errorMiddleware — denied-but-verified logging', () => {
@@ -67,6 +73,77 @@ describe('errorMiddleware — denied-but-verified logging', () => {
   });
 });
 
+const NOTE_TYPE_ID = 'com.example.test/note@1';
+
+describe('errorMiddleware — refusal logging (StackNotFoundError)', () => {
+  let dbPath: string;
+  let ctx: StackContext;
+
+  beforeEach(async () => {
+    dbPath = tempDbPath();
+    ctx = await createTestContext(dbPath);
+    await ctx.stack.defineType(NOTE_TYPE_ID, 'Note', {
+      body: { kind: 'text' as const, required: true as const },
+    });
+  });
+
+  afterEach(async () => {
+    await ctx.queryWorker.close();
+    await ctx.stack.close();
+    await ctx.tokens.close();
+    await rm(dirname(dbPath), { recursive: true, force: true }).catch(() => {});
+  });
+
+  it('logs existed: true for a verified requester denied read on an existing record', async () => {
+    const record = await ctx.stack.create(NOTE_TYPE_ID, { body: 'private' });
+    const { token } = await ctx.adapter.createToken(OTHER_ENTITY_ID);
+    const debug = spyLogger();
+    const app = createApp(ctx, testConfig(dbPath), debug);
+
+    const { status } = await req(app, 'GET', `/records/${record.id}`, { token });
+    expect(status).toBe(404);
+    expect(debug.debug).toHaveBeenCalledWith(
+      expect.objectContaining({
+        principalId: OTHER_ENTITY_ID,
+        subjectId: OTHER_ENTITY_ID,
+        recordId: record.id,
+        existed: true,
+        check: 'read',
+      }),
+      expect.stringMatching(/refus/i),
+    );
+  });
+
+  it('logs existed: false for a verified requester on a genuinely missing record', async () => {
+    const { token } = await ctx.adapter.createToken(OTHER_ENTITY_ID);
+    const debug = spyLogger();
+    const app = createApp(ctx, testConfig(dbPath), debug);
+
+    const { status } = await req(app, 'GET', '/records/nonexistent', { token });
+    expect(status).toBe(404);
+    expect(debug.debug).toHaveBeenCalledWith(
+      expect.objectContaining({
+        principalId: OTHER_ENTITY_ID,
+        subjectId: OTHER_ENTITY_ID,
+        recordId: 'nonexistent',
+        existed: false,
+        check: 'read',
+      }),
+      expect.stringMatching(/refus/i),
+    );
+  });
+
+  it('does not log for an anonymous 404 on a private record', async () => {
+    const record = await ctx.stack.create(NOTE_TYPE_ID, { body: 'private' });
+    const debug = spyLogger();
+    const app = createApp(ctx, testConfig(dbPath), debug);
+
+    const { status } = await req(app, 'GET', `/records/${record.id}`);
+    expect(status).toBe(404);
+    expect(debug.debug).not.toHaveBeenCalled();
+  });
+});
+
 describe('errorMiddleware — malformed JSON bodies', () => {
   let dbPath: string;
   let ctx: StackContext;