fix(objectql): file-field hydration asks canReadObject before reading sys_file, so a record read logs no access denial

.changeset/24335-file-hydration-no-denial.md

@@ -0,0 +1,17 @@
+---
+'@objectstack/objectql': patch
+---
+
+fix(objectql): a record read that hydrates a file field no longer makes a `sys_file` access attempt for a reader without `sys_file` read
+
+The engine expands a stored file id by reading `sys_file`, and it issued that read as the caller. A member who may read the record but not `sys_file` (the platform default) was refused it, and the security layer logged `[Security] Access denied: operation 'find' on object 'sys_file'` at WARN on every by-id and list read by that member, although the body served was right. Those lines buried the real denials in the operator's log.
+
+The engine now asks the security service's `canReadObject('sys_file')` first, the same object-level read gate the security middleware applies, and serves a refused caller the field-owned answer without the read. Nothing else changes:
+
+- The served body is byte-identical, by id and by list, for a reader with and without `sys_file` read. A file owned by the record still hydrates, and every other id still reads `{ id, metadataRefused: true }`.
+- A direct `GET /api/v1/data/sys_file/:id` by the same reader still answers `403 PERMISSION_DENIED` and still logs its denial.
+- With no security service, or one that offers no `canReadObject`, the engine reads as the caller, as before.
+
+The ask is one cached permission check per read, not per row.
+
+Clause-②: no (no accept set or public surface moves: the served bodies and every refusal are unchanged; owes the seat's review of record at `TIER_DEFAULT` before the queue)

packages/objectql/src/engine-file-hydrate-refused.test.ts

@@ -27,11 +27,18 @@
  * `file-field-hydration-refused.test.ts`; this file holds the seam's own
  * branches with a fake DRIVER (not a fake engine) and an engine middleware
  * standing in for the security layer's refusal.
+ *
+ * [#24335] ASKED BEFORE READ: with a security service in the engine's slot,
+ * the engine asks its `canReadObject('sys_file')` first and a refused caller
+ * is served the refused arm without the `sys_file` read — so the security
+ * layer, which logs every refusal at WARN, sees no access attempt. The last
+ * block pins that against the same fixture, and that the served body is the
+ * one the refused read produced.
  */
 
 import { describe, it, expect } from 'vitest';
 import { FileRefusedValueSchema, valueSchemaFor } from '@objectstack/spec/data';
-import { ObjectQL } from './engine';
+import { ObjectQL, SECURITY_SERVICE_SOURCE_SLOT } from './engine';
 
 const FILE_ID = 'f_7cQx2Lm90a';
 const SECOND_ID = 'f_zz11yy22xx';
@@ -142,9 +149,11 @@ function makeCapturingLogger() {
  * field), a registered `sys_file`, and three rows: one holding a file, one
  * holding two files plus a legacy URL, one holding none. When `refuseReader`
  * is set, a middleware refuses every non-system `sys_file` read the way the
- * security layer's CRUD gate does.
+ * security layer's CRUD gate does, and records each read it refuses in
+ * `attempts` (the reads plugin-security would log a denial for). `security`,
+ * when given, is what the engine's security-service slot resolves.
  */
-async function boot(opts: { sysFileRead?: () => Promise<any[]>; refuseReader?: boolean } = {}) {
+async function boot(opts: { sysFileRead?: () => Promise<any[]>; refuseReader?: boolean; security?: unknown } = {}) {
   const logger = makeCapturingLogger();
   const engine = new ObjectQL({ logger } as any);
   const { driver, storeFor } = makeDriver(opts.sysFileRead ?? (async () => COMMITTED_ROWS));
@@ -167,10 +176,17 @@ async function boot(opts: { sysFileRead?: () => Promise<any[]>; refuseReader?: b
       status: { type: 'text' },
     },
   } as any);
+  const attempts: any[] = [];
+  if (opts.security !== undefined) {
+    (engine as unknown as Record<symbol, unknown>)[SECURITY_SERVICE_SOURCE_SLOT] = () => opts.security;
+  }
   if (opts.refuseReader) {
     engine.registerMiddleware(
       async (ctx: any, next: () => Promise<void>) => {
-        if (!ctx.context?.isSystem) throw refusal();
+        if (!ctx.context?.isSystem) {
+          attempts.push(ctx.context);
+          throw refusal();
+        }
         return next();
       },
       { object: 'sys_file' },
@@ -184,7 +200,7 @@ async function boot(opts: { sysFileRead?: () => Promise<any[]>; refuseReader?: b
     gallery: [FILE_ID, SECOND_ID, 'https://cdn.example.com/legacy.png'],
   });
   storeFor('doc').set('d3', { id: 'd3', title: 'Empty', attachment: null, gallery: null });
-  return { engine, logger };
+  return { engine, logger, attempts };
 }
 
 const byId = (rows: any[]) => Object.fromEntries(rows.map((r) => [r.id, r]));
@@ -296,3 +312,116 @@ describe('a refused sys_file read marks the file field refused — not absent',
     expect(logger.lines.debug.filter((l: any) => /sys_file read refused/.test(l.msg))).toEqual([]);
   });
 });
+
+/**
+ * A security service the engine's slot resolves, answering `canReadObject` as
+ * `admits` says (the fixture's middleware refuses every non-system reader, so
+ * `false` is the true answer for READER_CTX), and recording every ask.
+ */
+function makeSecurity(admits: (object: string, context: any) => boolean | Promise<boolean>) {
+  const asks: Array<{ object: string; context: any }> = [];
+  const svc: Record<string, unknown> = {
+    getReadFilter: async () => undefined,
+    canReadObject: async (object: string, context: any) => {
+      asks.push({ object, context });
+      return admits(object, context);
+    },
+  };
+  return { svc, asks };
+}
+
+describe('[#24335] the engine asks before it reads sys_file — a refused reader makes no access attempt', () => {
+  it('a reader the admission refuses is served the refused arm and never reaches the sys_file read', async () => {
+    const { svc, asks } = makeSecurity((_o, ctx) => ctx?.isSystem === true);
+    const { engine, attempts } = await boot({ refuseReader: true, security: svc });
+
+    const rows = byId(await engine.find('doc', { context: READER_CTX }));
+
+    // No read of sys_file reached the security layer: nothing for it to log.
+    expect(attempts).toEqual([]);
+    expect(rows.d1.attachment).toEqual({ id: FILE_ID, metadataRefused: true });
+    // One ask per read, about sys_file, with the caller's own envelope.
+    expect(asks).toHaveLength(1);
+    expect(asks[0].object).toBe('sys_file');
+    expect(asks[0].context).toMatchObject(READER_CTX);
+    expect(Object.keys(asks[0].context).filter((k) => k.startsWith('__'))).toEqual([]);
+  });
+
+  it('the body is byte-identical to the one the refused read served, by list and by id', async () => {
+    const asked = await boot({ refuseReader: true, security: makeSecurity(() => false).svc });
+    const unasked = await boot({ refuseReader: true });
+
+    const listAsked = await asked.engine.find('doc', { context: READER_CTX });
+    const listUnasked = await unasked.engine.find('doc', { context: READER_CTX });
+    const oneAsked = await asked.engine.findOne('doc', { where: { id: 'd2' }, context: READER_CTX });
+    const oneUnasked = await unasked.engine.findOne('doc', { where: { id: 'd2' }, context: READER_CTX });
+
+    // The comparison is armed: the unasked engine did attempt, and was refused.
+    expect(unasked.attempts.length).toBeGreaterThan(0);
+    expect(asked.attempts).toEqual([]);
+    expect(oneAsked?.gallery?.[0]).toEqual({ id: FILE_ID, metadataRefused: true });
+    expect(JSON.stringify(listAsked)).toBe(JSON.stringify(listUnasked));
+    expect(JSON.stringify(oneAsked)).toBe(JSON.stringify(oneUnasked));
+  });
+
+  it('the reader\'s own sys_file read is still refused, and still reaches the security layer', async () => {
+    const { engine, attempts } = await boot({ refuseReader: true, security: makeSecurity(() => false).svc });
+
+    const err = await engine.find('sys_file', { context: READER_CTX }).catch((e: unknown) => e);
+
+    expect((err as any)?.code).toBe('PERMISSION_DENIED');
+    expect((err as any)?.statusCode).toBe(403);
+    expect(attempts).toHaveLength(1);
+  });
+
+  it('CONTROL a reader the admission admits still reads sys_file as itself, and is hydrated', async () => {
+    const { svc, asks } = makeSecurity(() => true);
+    const { engine } = await boot({ security: svc });
+
+    const rows = byId(await engine.find('doc', { context: READER_CTX }));
+
+    expect(asks).toHaveLength(1);
+    expect(rows.d1.attachment).toEqual({
+      id: FILE_ID,
+      name: 'contract.pdf',
+      size: 1024,
+      mimeType: 'application/pdf',
+      url: `/api/v1/storage/files/${FILE_ID}`,
+    });
+  });
+
+  it('CONTROL an admitted read the security layer still refuses takes the same refused arm', async () => {
+    const { engine, attempts } = await boot({ refuseReader: true, security: makeSecurity(() => true).svc });
+
+    const rows = byId(await engine.find('doc', { context: READER_CTX }));
+
+    expect(attempts).toHaveLength(1);
+    expect(rows.d1.attachment).toEqual({ id: FILE_ID, metadataRefused: true });
+  });
+
+  it('CONTROL unasked — no canReadObject, or an ask that throws — the read goes to the security layer as before', async () => {
+    const noMethod = await boot({ refuseReader: true, security: { getReadFilter: async () => undefined } });
+    const throwing = await boot({
+      refuseReader: true,
+      security: makeSecurity(() => {
+        throw new Error('admission unavailable');
+      }).svc,
+    });
+
+    for (const { engine, attempts } of [noMethod, throwing]) {
+      const rows = byId(await engine.find('doc', { context: READER_CTX }));
+      expect(attempts).toHaveLength(1);
+      expect(rows.d1.attachment).toEqual({ id: FILE_ID, metadataRefused: true });
+    }
+  });
+
+  it('CONTROL a record holding no file id asks nothing', async () => {
+    const { svc, asks } = makeSecurity(() => false);
+    const { engine } = await boot({ refuseReader: true, security: svc });
+
+    const row = await engine.findOne('doc', { where: { id: 'd3' }, context: READER_CTX });
+
+    expect(row?.id).toBe('d3');
+    expect(asks).toEqual([]);
+  });
+});

packages/objectql/src/engine.ts

@@ -13305,10 +13305,19 @@ export class ObjectQL implements IObjectQLEngine {
    * that record — and hydrates when it allows. Every other id keeps the
    * refused marker. See {@link readParentDerivedFiles}.
    *
-   * Batched: at most one `sys_file` `id $in […]` read per call (no N+1) — and,
-   * on the refused arm only, one more system read plus one verdict call; zero
-   * reads when no field holds a string value (the blob-only case), so the step
-   * is free for objects that have not adopted references.
+   * ASKED BEFORE READ (#24335): the caller's `sys_file` read is issued only
+   * when the security service admits it — {@link callerMayReadSysFile}, the
+   * middleware's own object-level read gate. A caller it refuses goes
+   * straight to the refused arm, the answer that read's refusal produced, so
+   * the served value is the same and no access attempt is made: the security
+   * layer logs no denial for a read the reader never asked for. A direct
+   * `sys_file` read by that reader is refused, and logged, exactly as before.
+   *
+   * Batched: one admission ask and at most one `sys_file` `id $in […]` read
+   * per call (no N+1) — and, on the refused arm only, one more system read
+   * plus one verdict call; zero of each when no field holds a string value
+   * (the blob-only case), so the step is free for objects that have not
+   * adopted references.
    */
   private async resolveFileReferences(
     objectName: string,
@@ -13355,6 +13364,13 @@ export class ObjectQL implements IObjectQLEngine {
     const uniqueIds = [...new Set(candidateIds)];
     if (uniqueIds.length === 0) return records; // blob-only / empty → zero cost
 
+    // [#24335] Ask before reading: a caller the security service refuses
+    // `sys_file` read is served the refused arm without the read whose
+    // refusal would have produced it.
+    if (!(await this.callerMayReadSysFile(execCtx))) {
+      return this.serveRefusedFileHydration(objectName, records, fileFields, uniqueIds, execCtx);
+    }
+
     // One batched sys_file read. `__expandRead` mirrors the lookup-expansion
     // sub-read (a system-built marker, never from client input). Metadata only —
     // byte-download authorization is enforced at the /files/:fileId resolver.
@@ -13408,37 +13424,12 @@ export class ObjectQL implements IObjectQLEngine {
       // them. The marker stays on everything else: an id another record owns
       // (copied in), an attachment-only or unclaimed file, an id with no row,
       // and every id when the verdict is unwired or cannot be asked.
+      //
+      // [#24335] A caller the security service's admission already refused
+      // never reaches this read (see {@link callerMayReadSysFile}); this arm
+      // still serves a refusal the admission did not foresee, the same way.
       if (isReadRefusal(error)) {
-        const owned = await this.readParentDerivedFiles(objectName, records, uniqueIds, execCtx);
-        this.logger.debug('sys_file read refused for this caller; file fields carry the refused marker', {
-          object: objectName,
-          fields: fileFields,
-          refusedIds: uniqueIds.length,
-          parentDerivedIds: owned.size,
-        });
-        const refused = (id: string): FileRefusedValue => ({ id, metadataRefused: true });
-        // Judged per ELEMENT and per RECORD: the verdict covers a file only on
-        // the record whose field owns it, so the same id copied into a second
-        // record is still refused there. An owned, allowed id with no servable
-        // row reads as the bare id — what a `sys_file` reader gets for it.
-        const valueFor = (record: any, v: unknown): unknown => {
-          if (!isFileIdToken(v)) return v;
-          const hit = owned.get(v);
-          if (!hit || record?.id == null || hit.ownerId !== String(record.id)) return refused(v);
-          return hit.row ? toFileValue(hit.row) : v;
-        };
-        for (const record of records) {
-          for (const fieldName of fileFields) {
-            const val = record[fieldName];
-            if (val == null) continue;
-            if (Array.isArray(val)) {
-              record[fieldName] = val.map((v: unknown) => valueFor(record, v));
-            } else {
-              record[fieldName] = valueFor(record, val);
-            }
-          }
-        }
-        return records;
+        return this.serveRefusedFileHydration(objectName, records, fileFields, uniqueIds, execCtx);
       }
       // Everything else (connection drop, timeout, a database-level permission
       // fault, query error) means the rows may well exist and simply were not
@@ -13485,6 +13476,87 @@ export class ObjectQL implements IObjectQLEngine {
     return records;
   }
 
+  /**
+   * [#24335] May this caller read `sys_file` at all? Asked of the registered
+   * security service's `canReadObject` BEFORE {@link resolveFileReferences}
+   * issues the caller's own `sys_file` read, as the parent-record read gate
+   * asks before it reads a parent object ("A skipped object is not an access
+   * attempt", plugin-audit). `canReadObject` is the security middleware's own
+   * object-level read gate, arm for arm, and answers without logging or
+   * throwing; the read it spares is one that gate would refuse, and
+   * plugin-security logs every refusal at WARN — a line on every ordinary
+   * record read by a reader without `sys_file` read, burying the real denials.
+   *
+   * Asked with the caller's envelope minus its operation-private `__` keys
+   * (`withoutOperationPrivateKeys`, as {@link readParentDerivedFiles} asks its
+   * verdict): no second derivation of authority, and no muting of the
+   * middleware's log — the reader's own `sys_file` read still logs its denial.
+   *
+   * It only ever NARROWS what is read: `true` still reads as the caller, and
+   * that read still decides. Unasked ⇒ `true`, the read goes to the middleware
+   * as it did before: no usable security service, one whose contract omits the
+   * optional `canReadObject`, or an ask that throws. Any other answer than
+   * `true` ⇒ the refused arm, which is what that read's refusal served.
+   */
+  private async callerMayReadSysFile(execCtx?: ExecutionContext): Promise<boolean> {
+    const security = this.resolveReadableIdsSecurity();
+    if (security.kind !== 'usable' || typeof security.svc.canReadObject !== 'function') return true;
+    const caller = withoutOperationPrivateKeys((execCtx ?? {}) as Record<string, unknown>);
+    try {
+      return (await security.svc.canReadObject('sys_file', caller as ExecutionContext)) === true;
+    } catch {
+      return true;
+    }
+  }
+
+  /**
+   * The refused arm of {@link resolveFileReferences}: this caller may not read
+   * `sys_file`, whether its admission said so up front (#24335) or its read was
+   * refused. Each id a record of this result owns is put to the field-owned
+   * verdict ({@link readParentDerivedFiles}, #22637) and hydrates when it
+   * allows; every other id becomes `{ id, metadataRefused: true }`
+   * (`FileRefusedValueSchema`). Logged at `debug`: the answer is handed to
+   * the caller in the value.
+   */
+  private async serveRefusedFileHydration(
+    objectName: string,
+    records: any[],
+    fileFields: string[],
+    uniqueIds: string[],
+    execCtx?: ExecutionContext,
+  ): Promise<any[]> {
+    const owned = await this.readParentDerivedFiles(objectName, records, uniqueIds, execCtx);
+    this.logger.debug('sys_file read refused for this caller; file fields carry the refused marker', {
+      object: objectName,
+      fields: fileFields,
+      refusedIds: uniqueIds.length,
+      parentDerivedIds: owned.size,
+    });
+    const refused = (id: string): FileRefusedValue => ({ id, metadataRefused: true });
+    // Judged per ELEMENT and per RECORD: the verdict covers a file only on
+    // the record whose field owns it, so the same id copied into a second
+    // record is still refused there. An owned, allowed id with no servable
+    // row reads as the bare id — what a `sys_file` reader gets for it.
+    const valueFor = (record: any, v: unknown): unknown => {
+      if (!isFileIdToken(v)) return v;
+      const hit = owned.get(v);
+      if (!hit || record?.id == null || hit.ownerId !== String(record.id)) return refused(v);
+      return hit.row ? toFileValue(hit.row) : v;
+    };
+    for (const record of records) {
+      for (const fieldName of fileFields) {
+        const val = record[fieldName];
+        if (val == null) continue;
+        if (Array.isArray(val)) {
+          record[fieldName] = val.map((v: unknown) => valueFor(record, v));
+        } else {
+          record[fieldName] = valueFor(record, val);
+        }
+      }
+    }
+    return records;
+  }
+
   /**
    * The servable subset of some `sys_file` rows, keyed by id — the rule both
    * arms of {@link resolveFileReferences} serve by, so a row hydrates under