fix(service-analytics): log the admitObjectRead bridge's init-time security absence at info; WARN once at the first query that finds none

.changeset/22154-analytics-security-absence-info.md

@@ -0,0 +1,11 @@
+---
+"@objectstack/service-analytics": patch
+---
+
+fix(service-analytics): a default boot no longer warns that no "security" service is registered; the warning moves to the first query that finds none
+
+Clause-②: no
+
+- **What changed.** `AnalyticsServicePlugin` used to log a WARN at init, `[Analytics] No admitObjectRead configured and no "security" service registered at init …`, on every default boot. `@objectstack/plugin-security` registers the `security` service in its `start()`, after every plugin's `init()`, and the object-level read bridge resolves that service per query. So the warning described a consequence that did not apply to the running app. Init now logs the same situation at `info`, as the sibling row-scope bridge already did: `[Analytics] admitObjectRead bridged to the "security" service; that service is not registered yet at init and will be resolved per query`.
+- **Where the warning went.** When an analytics query needs the object-level gate and the plugin context returns no `security` service, the bridge logs one WARN: `[Analytics] No admitObjectRead configured and no "security" service registered when an analytics query needed one (first: "OBJECT") …`. It is logged once per plugin instance, not once per query.
+- **Unchanged.** What the bridge enforces. When the plugin context answers a lookup for `security` with nothing, the query is admitted, as before. A lookup that throws, or a service that answers neither `canReadObject` nor `explain`, still denies the query fail-closed and logs an `error`, as before. The in-repo kernels (`ObjectKernel`, `LiteKernel`) throw on a lookup for a service nobody registered, so on those kernels a query with no security service ever registered is still denied, with an `error` per query, as before. A deployment that supplies `admitObjectRead` sees no change.

packages/services/service-analytics/src/__tests__/admission-absence-report.test.ts

@@ -0,0 +1,231 @@
+// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
+
+/**
+ * WHEN the analytics → `security` admission bridge reports that no security
+ * service answers the object-level read grant, and at what level.
+ *
+ * The bridge resolves the `security` service PER QUERY, so plugin order is not
+ * significant — and plugin-security registers that service in its `start()`,
+ * after every plugin's `init()`. A WARN at init therefore asserted a verdict
+ * the same boot contradicts (AGENTS.md "Startup registry reads — never record
+ * a verdict the boot can still contradict"), on every default boot.
+ *
+ * So:
+ *   - init reports the absence at `info`, as the read-scope sibling already
+ *     does for the identical situation;
+ *   - the WARN belongs to the first query that needs the gate and finds no
+ *     service — once per bridge, not once per query;
+ *   - what the bridge ENFORCES does not move. Each case below asserts the
+ *     verdict next to the log line, so a change that quietened the log by
+ *     changing the answer cannot pass.
+ *
+ * The three resolutions themselves (absent / threw / cannot answer) are
+ * `admission-bridge-resolution.test.ts`'s subject; this file is about the
+ * report, not the verdict.
+ */
+
+import { describe, it, expect, vi } from 'vitest';
+import { LiteKernel, type Plugin, type PluginContext } from '@objectstack/core';
+import { DatasetSchema } from '@objectstack/spec/ui';
+import type { ExecutionContext } from '@objectstack/spec/kernel';
+import { AnalyticsServicePlugin } from '../plugin.js';
+import type { AnalyticsService } from '../analytics-service.js';
+
+const probe = DatasetSchema.parse({
+  name: 'probe_member',
+  label: 'probe',
+  object: 'employer_member',
+  dimensions: [],
+  measures: [{ name: 'cnt', label: 'Count', aggregate: 'count' }],
+});
+
+const CALLER = { userId: 'u_seeker', tenantId: 'org_a' } as ExecutionContext;
+
+/** The SQL posture — the path where nothing but this gate stands in the way. */
+const nativeSql = () => ({ nativeSql: true, objectqlAggregate: false, inMemory: false });
+
+/** Engine double; every read it serves is recorded, so "denied" means "never read". */
+function fakeEngine() {
+  const reads: string[] = [];
+  return {
+    reads,
+    engine: {
+      execute: async (_sql: unknown, options?: { object?: string }) => {
+        reads.push(`execute:${options?.object ?? '?'}`);
+        return { rows: [{ cnt: 24 }] };
+      },
+      aggregate: async (object: string) => {
+        reads.push(`aggregate:${object}`);
+        return [{ cnt: 24 }];
+      },
+      hasObjectMiddleware: () => false,
+      getObject: (name: string) =>
+        name === 'employer_member' ? { fields: { id: { type: 'text' } } } : undefined,
+      resolveEffectiveDatasource: () => undefined,
+    },
+  };
+}
+
+/** The lines this file is about: anything naming the object-level admission. */
+const ADMISSION = /admitObjectRead|OBJECT-LEVEL|object-level read admission/;
+
+type Lines = { info: string[]; warn: string[]; error: string[] };
+const about = (lines: string[]) => lines.filter((l) => ADMISSION.test(l));
+
+const runProbe = (service: AnalyticsService) =>
+  service.queryDataset(probe as never, { measures: ['cnt'] } as never, CALLER);
+
+// ── A REAL kernel: the default composition, in the default order ─────────────
+
+/**
+ * Boots a real `LiteKernel` with a `data` provider, this plugin, and — when
+ * given — a security provider that registers AFTER this plugin's `init()`,
+ * which is what every composition shipping plugin-security produces (it
+ * registers `security` in its `start()`). The first plugin taps the kernel's
+ * logger so every line the analytics plugin writes, at init and at query
+ * time, is seen.
+ */
+async function bootKernel(security?: Record<string, unknown>) {
+  const lines: Lines = { info: [], warn: [], error: [] };
+  const { engine, reads } = fakeEngine();
+  const tap: Plugin = {
+    name: 'test.log-tap',
+    init: async (ctx: PluginContext) => {
+      for (const level of ['info', 'warn', 'error'] as const) {
+        vi.spyOn(ctx.logger, level).mockImplementation((message: unknown) => {
+          lines[level].push(String(message));
+        });
+      }
+    },
+  };
+  const data: Plugin = {
+    name: 'test.data',
+    init: async (ctx: PluginContext) => { ctx.registerService('data', engine); },
+  };
+  const kernel = new LiteKernel({ logger: { level: 'silent' } });
+  kernel.use(tap);
+  kernel.use(data);
+  kernel.use(new AnalyticsServicePlugin({ queryCapabilities: nativeSql }));
+  if (security) {
+    // Registered from start(), the phase plugin-security registers it in.
+    kernel.use({
+      name: 'test.security',
+      init: async () => {},
+      start: async (ctx: PluginContext) => { ctx.registerService('security', security); },
+    } satisfies Plugin);
+  }
+  await kernel.bootstrap();
+  return { service: kernel.getService<AnalyticsService>('analytics'), reads, lines };
+}
+
+/** A working security service's row-scope half; `undefined` = no row restriction. */
+const rowScopeOpen = { getReadFilter: async () => undefined };
+
+describe('admission absence report — a default composition (security registered after analytics init)', () => {
+  it('boots with no admitObjectRead WARN: the init-time absence is an info line', async () => {
+    const canReadObject = vi.fn(() => true);
+    const { lines } = await bootKernel({ ...rowScopeOpen, canReadObject });
+
+    expect(about(lines.warn)).toEqual([]);
+    expect(about(lines.error)).toEqual([]);
+    expect(about(lines.info).join('\n')).toMatch(
+      /admitObjectRead bridged to the "security" service; that service is not registered yet at init/,
+    );
+  });
+
+  it('its first query asks the security service that registered later — both verdicts, as before', async () => {
+    const canReadObject = vi.fn(() => true);
+    const admitted = await bootKernel({ ...rowScopeOpen, canReadObject });
+
+    expect((await runProbe(admitted.service)).rows).toEqual([{ cnt: 24 }]);
+    expect(canReadObject).toHaveBeenCalledWith('employer_member', CALLER);
+    expect(admitted.reads).toHaveLength(1);
+    // Asking the service that is there is not an absence: nothing to report.
+    expect(about(admitted.lines.warn)).toEqual([]);
+
+    const refused = await bootKernel({ ...rowScopeOpen, canReadObject: () => false });
+    await expect(runProbe(refused.service)).rejects.toMatchObject({
+      code: 'PERMISSION_DENIED',
+      status: 403,
+    });
+    expect(refused.reads).toEqual([]);
+    expect(about(refused.lines.warn).join('\n')).not.toMatch(/No admitObjectRead configured/);
+  });
+});
+
+describe('admission absence report — a real kernel that never registers a security service', () => {
+  it('logs no init-time WARN, and absence stays loud at query time with the outcome unchanged', async () => {
+    // The in-repo kernels answer a missing service by THROWING
+    // ("[Kernel] Service 'security' not found"), which this bridge classifies
+    // as a resolution that threw: it denies, fail-closed, and says so at
+    // `error` on every query. That outcome is what this boot produced before
+    // the init-time WARN moved, and it is not this file's to change; what is
+    // pinned is that dropping the init-time WARN left this case loud.
+    const { service, reads, lines } = await bootKernel(undefined);
+
+    expect(about(lines.warn)).toEqual([]);
+
+    await expect(runProbe(service)).rejects.toMatchObject({
+      code: 'PERMISSION_DENIED',
+      status: 403,
+    });
+    expect(reads).toEqual([]);
+    expect(about(lines.error).join('\n')).toMatch(
+      /object-level read admission could not be resolved for "employer_member" .* denying the query \(fail-closed\)/s,
+    );
+  });
+});
+
+// ── The ABSENT resolution: a context that answers a missing service with nothing ─
+
+function fakePluginContext() {
+  const { engine, reads } = fakeEngine();
+  const registered: Record<string, unknown> = {};
+  const lines: Lines = { info: [], warn: [], error: [] };
+  const record = (level: keyof Lines) => (message: unknown) => { lines[level].push(String(message)); };
+  return {
+    reads,
+    lines,
+    registered,
+    ctx: {
+      getService: (name: string) => (name === 'data' ? engine : registered[name]),
+      registerService: (name: string, svc: unknown) => { registered[name] = svc; },
+      replaceService: (name: string, svc: unknown) => { registered[name] = svc; },
+      logger: { info: record('info'), warn: record('warn'), error: record('error'), debug() {} },
+    },
+  };
+}
+
+describe('admission absence report — no security service ever registered (the ABSENT resolution)', () => {
+  it('WARNs at the first query, once: a second query does not repeat it, and both are admitted as before', async () => {
+    const { ctx, registered, reads, lines } = fakePluginContext();
+    await new AnalyticsServicePlugin({ queryCapabilities: nativeSql }).init(ctx as never);
+    const service = registered.analytics as AnalyticsService;
+
+    // Nothing at init beyond the heads-up: the verdict is the first query's.
+    expect(about(lines.warn)).toEqual([]);
+
+    expect((await runProbe(service)).rows).toEqual([{ cnt: 24 }]);
+    expect(reads).toHaveLength(1);
+    const first = about(lines.warn);
+    expect(first).toHaveLength(1);
+    expect(first[0]).toMatch(
+      /No admitObjectRead configured and no "security" service registered when an analytics query needed one \(first: "employer_member"\)/,
+    );
+    expect(first[0]).toMatch(/do NOT enforce the OBJECT-LEVEL read grant/);
+
+    expect((await runProbe(service)).rows).toEqual([{ cnt: 24 }]);
+    expect(reads).toHaveLength(2);
+    expect(about(lines.warn)).toEqual(first);
+    expect(about(lines.error)).toEqual([]);
+  });
+
+  it('reports per plugin instance, not per process: a second plugin init gets its own report', async () => {
+    for (let i = 0; i < 2; i++) {
+      const { ctx, registered, lines } = fakePluginContext();
+      await new AnalyticsServicePlugin({ queryCapabilities: nativeSql }).init(ctx as never);
+      await runProbe(registered.analytics as AnalyticsService);
+      expect(about(lines.warn)).toHaveLength(1);
+    }
+  });
+});

packages/services/service-analytics/src/__tests__/admission-bridge-resolution.test.ts

@@ -11,8 +11,9 @@
  *   - the `security` service is ABSENT — this deployment has no object-level
  *     gate anywhere, `GET /data/<object>` included, because that gate IS the
  *     absent middleware. The two doors agree, which is the equivalence property
- *     the card asks for, so the query is ADMITTED and the state is reported at
- *     init;
+ *     the card asks for, so the query is ADMITTED and the state is reported
+ *     once, by the first query that finds it (`admission-absence-report.test.ts`
+ *     pins when, and at what level);
  *   - resolving the service THREW — a security service exists on this
  *     deployment and could not be reached;
  *   - the service resolved but exposes NEITHER `canReadObject` NOR `explain` —

packages/services/service-analytics/src/__tests__/raw-sql-object-routing.test.ts

@@ -258,9 +258,9 @@ describe('executeRawSql auto-bridge routes by object (#5033)', () => {
       { stage: 'lost', deal_count: 1 },
     ]);
     // The blanket `expect(warn).not.toHaveBeenCalled()` this replaces could no
-    // longer hold: the plugin reports at init when no `security` service is
-    // registered to answer the OBJECT-LEVEL read grant, and this fixture
-    // deliberately registers none.
+    // longer hold: the object-level bridge reports, once, at the first query
+    // that finds no `security` service to answer the OBJECT-LEVEL read grant,
+    // and this fixture deliberately registers none.
     //
     // ⛔ But the replacement is not "anything except the routing phrase"
     // either — that admits every OTHER new warning into a case whose whole job
@@ -270,7 +270,7 @@ describe('executeRawSql auto-bridge routes by object (#5033)', () => {
     const warnings = warn.mock.calls.map((c) => String(c[0]));
     expect(warnings).toHaveLength(1);
     expect(warnings[0]).toMatch(
-      /No admitObjectRead configured and no "security" service registered at init/,
+      /No admitObjectRead configured and no "security" service registered when an analytics query needed one/,
     );
     // …and it is emphatically not the degradation this case is about.
     expect(warnings[0]).not.toMatch(/is unavailable/);

packages/services/service-analytics/src/plugin.ts

@@ -693,7 +693,9 @@ export class AnalyticsServicePlugin implements Plugin {
     //              `/data`, because that gate IS this plugin's absent
     //              middleware. The two doors still agree, which is the
     //              equivalence property the card asks for, so this ADMITS and
-    //              is reported loudly at init below.
+    //              is reported loudly, once, by the first query that finds it
+    //              (below) — not at init, where the service is usually just
+    //              not registered YET.
     //   UNUSABLE — a security service exists but cannot answer: resolving it
     //              THREW, or the object it returned carries neither
     //              `canReadObject` nor `explain`. This is a wired-but-broken
@@ -751,11 +753,40 @@ export class AnalyticsServicePlugin implements Plugin {
         }
         return { kind: 'usable', svc };
       };
+      // [#22154] Absence is judged where it is used, not where init starts
+      // (AGENTS.md "Startup registry reads"). At this plugin's init the
+      // "security" service is not registered yet on any composition that
+      // ships plugin-security: that plugin registers it in its own start(),
+      // after every init(). This bridge resolves per call, so plugin order is
+      // not significant. A WARN at init asserted a verdict the same boot
+      // contradicts; init reports the absence at `info` (below), and the WARN
+      // waits for a query that needs the gate and finds no service.
+      //
+      // Once per bridge, i.e. per plugin init: the state is the deployment's,
+      // every later query is admitted the same way, and repeating it per query
+      // buries it. Deliberately NOT a module binding — a second kernel in the
+      // same process (a test run, a `verify` harness) must get its own report.
+      // The flag records only that the report was made; it caches no verdict:
+      // every query still resolves the service afresh.
+      let admissionAbsenceReported = false;
       admitObjectRead = async (object, context) => {
         const resolved = trySecurityAdmission();
         // No security service resolved at call time → no object-level gate on
-        // this deployment, which is the state reported at init.
-        if (resolved.kind === 'absent') return true;
+        // this deployment: ADMIT, exactly as before, and say so once.
+        if (resolved.kind === 'absent') {
+          if (!admissionAbsenceReported) {
+            admissionAbsenceReported = true;
+            ctx.logger.warn(
+              '[Analytics] No admitObjectRead configured and no "security" service registered when an ' +
+              `analytics query needed one (first: "${object}") — analytics queries do NOT enforce the ` +
+              'OBJECT-LEVEL read grant. On a SQL driver that means any authenticated caller can post an ' +
+              'inline dataset and read counts and groupings for an object they hold no grant on. Supply ' +
+              'admitObjectRead or register a security service. Reported once; later queries are ' +
+              'admitted the same way.',
+            );
+          }
+          return true;
+        }
         if (resolved.kind === 'unusable') {
           ctx.logger.error(
             `[Analytics] object-level read admission could not be resolved for "${object}" — ` +
@@ -1446,12 +1477,14 @@ export class AnalyticsServicePlugin implements Plugin {
         'read grant the engine middleware asks, ahead of the strategy chain.',
       );
     } else if (autoBridgedReadAdmission) {
-      ctx.logger.warn(
-        '[Analytics] No admitObjectRead configured and no "security" service registered at init — ' +
-        'the bridge resolves per query, but if no security service ever appears, analytics ' +
-        'queries will NOT enforce the OBJECT-LEVEL read grant. On a SQL driver that means any ' +
-        'authenticated caller can post an inline dataset and read counts and groupings for an ' +
-        'object they hold no grant on. Supply admitObjectRead or register a security service.',
+      // [#22154] A heads-up, not a verdict — the same situation the read-scope
+      // sibling above logs at `info`. The bridge resolves per query, and
+      // plugin-security registers the service in its start(), after this
+      // init; a query that needs the gate and finds no service WARNs then,
+      // once (see the bridge).
+      ctx.logger.info(
+        '[Analytics] admitObjectRead bridged to the "security" service; that service is not ' +
+        'registered yet at init and will be resolved per query (plugin order is not significant).',
       );
     }