fix(plugin-audit): report where the audit system tables were provisioned (#4887) (#5035)

`provisionSystemTables()` said nothing on success and returned silently when
the engine exposed no `syncObjectSchema`, so "provisioned three tables" and
"provisioned nothing" produced byte-identical logs. `syncObjectSchema()` itself
returns `void` with three silent exits of its own (object unregistered / no
driver / driver without `syncSchema`), none of which throw, so the per-object
`catch` could not observe them either.

#4887 is what that silence costs. `sys_audit_log` (`lifecycle.class: 'audit'`)
and `sys_activity` (`lifecycle.class: 'telemetry'`) were reported as never
provisioned because they were absent from the primary SQLite file. They were
provisioned: ADR-0057 §3.6 routes both to the dedicated `telemetry` datasource
whenever one is registered, and `os dev` registers one by default as a sibling
file (`dev.db` -> `dev.telemetry.db`). `sys_comment` carries no lifecycle class,
stays on the primary, and was the one that "existed". Nothing in the log
connected those facts.

Provisioning now reports itself:

- the wholesale skip is a `warn` naming the consequence (tables stay
  lazy-created on first WRITE; a read-first env logs "no such table");
- one `info` line per boot listing where each table landed, resolved through
  the engine's own `getDriverForObject`;
- a second `info` line when the ADR-0057 split is in effect, stating that those
  tables live in another store and that anything reading them without naming
  the object will report "no such table" even though provisioning succeeded;
- an object that resolves to no driver is a `warn` — `syncObjectSchema()`
  issues no DDL in that case and throws nothing, so from outside the engine
  this is the only place it can be observed.

Behaviour is otherwise unchanged: the same three objects are synced, per-object
failures stay isolated, and an engine without on-demand DDL still degrades
rather than failing `start()`.

Refs #4887


Claude-Session: https://claude.ai/code/session_015W6nhsDrz6zWQc8je12a1t

Co-authored-by: Claude <noreply@anthropic.com>

Author: os-zhuang

.changeset/audit-provisioning-datasource-audible.md

@@ -0,0 +1,50 @@
+---
+"@objectstack/plugin-audit": patch
+---
+
+fix(plugin-audit): say where the audit system tables were provisioned, and stop skipping provisioning silently (#4887)
+
+`AuditPlugin.provisionSystemTables()` created `sys_audit_log` / `sys_activity` /
+`sys_comment` at `kernel:ready` and then said **nothing** — not on success, and
+not when it skipped the work entirely (`typeof engine.syncObjectSchema !==
+'function'` returned silently). `syncObjectSchema()` itself returns `void` and
+has three silent exits of its own — the object is not in the registry, no driver
+resolves for it, or the resolved driver has no `syncSchema` — none of which
+throw. So "provisioned three tables" and "provisioned nothing at all" produced
+byte-identical logs, and the only way to tell them apart was to go looking in a
+database.
+
+#4887 is what that costs. `sys_audit_log` and `sys_activity` were reported as
+never provisioned because they were absent from the primary SQLite file, with
+the silent `typeof` bail named as the likely cause. Neither was true:
+`sys_audit_log` (`lifecycle.class: 'audit'`) and `sys_activity`
+(`lifecycle.class: 'telemetry'`) are routed by **ADR-0057 §3.6** to the
+dedicated `telemetry` datasource whenever one is registered, and `os dev`
+registers one by default as a *sibling file* (`dev.db` → `dev.telemetry.db`).
+Both tables had been created — in the other store. `sys_comment` carries no
+lifecycle class, stays on the primary, and was the one that "existed". Nothing
+in the log connected those three facts.
+
+Provisioning now reports itself:
+
+- **Wholesale skip is a `warn`, naming the consequence** — the tables stay
+  lazy-created on first WRITE, so an env that READS one first (the home page
+  activity feed queries `sys_activity` before any mutation) logs "no such
+  table" until something writes.
+- **One `info` line per boot listing where each table landed** —
+  `sys_audit_log→telemetry, sys_activity→telemetry, sys_comment→sqlite`,
+  resolved through the engine's own `getDriverForObject`, so the log states the
+  routing rather than leaving it to be inferred.
+- **A second `info` line when the ADR-0057 split is in effect**, saying
+  explicitly that those tables live in a different store — on SQLite, a
+  different *file* — and that anything reading them without naming the object
+  (raw SQL against the default datasource) will report "no such table" even
+  though provisioning succeeded.
+- **An object that resolves to no driver is a `warn`** — `syncObjectSchema()`
+  returns without issuing any DDL in that case and throws nothing, so the
+  per-object `catch` never fires; from outside the engine this is the only place
+  it can be observed.
+
+Behaviour is otherwise unchanged: the same three objects are synced, per-object
+failures stay isolated, and an engine without on-demand DDL still degrades
+instead of failing `start()`.

packages/plugins/plugin-audit/src/audit-plugin.test.ts

@@ -39,8 +39,14 @@ function makeCtx(engine: unknown) {
     ['manifest', { register() {} }],
   ]);
   const readyHooks: Array<() => Promise<void> | void> = [];
+  // #4887 — the log IS the deliverable for the provisioning path: its silence
+  // is what made a working-but-elsewhere table read as a never-created one.
+  // Capture info/warn so the tests can assert on what an operator would see.
+  const logs = { info: [] as string[], warn: [] as string[] };
   const logger = {
-    info() {}, warn() {}, error() {}, debug() {},
+    info(msg: string) { logs.info.push(String(msg)); },
+    warn(msg: string) { logs.warn.push(String(msg)); },
+    error() {}, debug() {},
     child() { return logger; },
   };
   const ctx = {
@@ -51,7 +57,7 @@ function makeCtx(engine: unknown) {
       if (event === 'kernel:ready') readyHooks.push(fn);
     },
   } as any;
-  return { ctx, fireReady: async () => { for (const fn of readyHooks) await fn(); } };
+  return { ctx, logs, fireReady: async () => { for (const fn of readyHooks) await fn(); } };
 }
 
 describe('AuditPlugin — system table provisioning', () => {
@@ -89,6 +95,146 @@ describe('AuditPlugin — system table provisioning', () => {
   });
 });
 
+/**
+ * #4887 — provisioning must SAY what it did.
+ *
+ * `syncObjectSchema` returns `void` and has three silent exits of its own
+ * (object not registered / no driver / driver without `syncSchema`), so a
+ * caller that only catches throws cannot distinguish "created the table" from
+ * "did nothing". Combined with a silent `typeof sync !== 'function'` bail on
+ * this side, a boot where provisioning was skipped WHOLESALE logged exactly
+ * the same thing as a boot where it worked: nothing.
+ *
+ * #4887 is what that costs. `sys_audit_log` / `sys_activity` were reported as
+ * "never provisioned" because they were absent from the primary SQLite file —
+ * but ADR-0057 §3.6 routes both (lifecycle classes `audit` / `telemetry`) to
+ * the `telemetry` datasource when one is registered, and `os dev` registers one
+ * by default as a sibling file. The tables existed; the log just never said
+ * where. These tests pin the three statements an operator now gets.
+ */
+describe('AuditPlugin — provisioning is audible (#4887)', () => {
+  /** Engine whose datasource routing mirrors ADR-0057 §3.6 in `os dev`. */
+  function makeRoutingEngine(routes: Record<string, string | undefined>, defaultName = 'sqlite') {
+    return {
+      async syncObjectSchema(_name: string) { /* DDL issued on the resolved driver */ },
+      getDriverForObject(name: string) {
+        const ds = routes[name];
+        return ds === undefined ? undefined : { name: ds };
+      },
+      getDefaultDriverName() { return defaultName; },
+    };
+  }
+
+  it('warns — instead of returning silently — when the engine has no syncObjectSchema', async () => {
+    const { ctx, logs, fireReady } = makeCtx({ async find() { return []; } });
+    const plugin = new AuditPlugin();
+    await plugin.init(ctx);
+    await plugin.start(ctx);
+    await fireReady();
+
+    const warned = logs.warn.find((m) => m.includes('no syncObjectSchema'));
+    expect(warned).toBeDefined();
+    // The warning must name the CONSEQUENCE, not just the missing method:
+    // nothing is provisioned and a read-first env logs "no such table".
+    expect(warned).toMatch(/sys_activity/);
+    expect(warned).toMatch(/no such table/);
+  });
+
+  it('reports the datasource each system table was provisioned into', async () => {
+    // The exact `os dev` shape: audit + activity split off to `telemetry`,
+    // comment stays on the primary.
+    const engine = makeRoutingEngine({
+      sys_audit_log: 'telemetry',
+      sys_activity: 'telemetry',
+      sys_comment: 'sqlite',
+    });
+    const { ctx, logs, fireReady } = makeCtx(engine);
+    const plugin = new AuditPlugin();
+    await plugin.init(ctx);
+    await plugin.start(ctx);
+    await fireReady();
+
+    const placement = logs.info.find((m) => m.includes('system tables provisioned'));
+    expect(placement).toBeDefined();
+    expect(placement).toContain('sys_audit_log→telemetry');
+    expect(placement).toContain('sys_activity→telemetry');
+    expect(placement).toContain('sys_comment→sqlite');
+
+    // …and the split itself is called out, because "absent from the database I
+    // am looking at" is not "never created".
+    const split = logs.info.find((m) => m.includes('NON-default datasource'));
+    expect(split).toBeDefined();
+    expect(split).toContain('ADR-0057');
+    expect(split).toContain('sys_audit_log→telemetry');
+    expect(split).toContain('sys_activity→telemetry');
+    // sys_comment is ON the default datasource — it must not be listed as split.
+    expect(split).not.toContain('sys_comment');
+  });
+
+  it('says nothing about a split when every table is on the default datasource', async () => {
+    const engine = makeRoutingEngine({
+      sys_audit_log: 'sqlite',
+      sys_activity: 'sqlite',
+      sys_comment: 'sqlite',
+    });
+    const { ctx, logs, fireReady } = makeCtx(engine);
+    const plugin = new AuditPlugin();
+    await plugin.init(ctx);
+    await plugin.start(ctx);
+    await fireReady();
+
+    expect(logs.info.find((m) => m.includes('system tables provisioned'))).toBeDefined();
+    expect(logs.info.some((m) => m.includes('NON-default datasource'))).toBe(false);
+    expect(logs.warn.some((m) => m.includes('NO datasource driver'))).toBe(false);
+  });
+
+  it("warns when an object resolves to no driver — syncObjectSchema's own silent exit", async () => {
+    // `syncObjectSchema` returns without issuing DDL when no driver backs the
+    // object. It throws nothing, so the per-object catch never fires: the only
+    // way this is ever visible is from the outside, here.
+    const engine = makeRoutingEngine({
+      sys_audit_log: undefined,
+      sys_activity: 'sqlite',
+      sys_comment: 'sqlite',
+    });
+    const { ctx, logs, fireReady } = makeCtx(engine);
+    const plugin = new AuditPlugin();
+    await plugin.init(ctx);
+    await plugin.start(ctx);
+    await fireReady();
+
+    const warned = logs.warn.find((m) => m.includes('NO datasource driver'));
+    expect(warned).toBeDefined();
+    expect(warned).toContain('sys_audit_log');
+    // The other two still provisioned — one unroutable object does not stop them.
+    const placement = logs.info.find((m) => m.includes('system tables provisioned'));
+    expect(placement).toContain('sys_activity→sqlite');
+    expect(placement).toContain('sys_comment→sqlite');
+    expect(placement).not.toContain('sys_audit_log');
+  });
+
+  it('keeps reporting placements when one object fails to sync', async () => {
+    const engine = {
+      async syncObjectSchema(name: string) {
+        if (name === 'sys_activity') throw new Error('disk I/O error');
+      },
+      getDriverForObject() { return { name: 'sqlite' }; },
+      getDefaultDriverName() { return 'sqlite'; },
+    };
+    const { ctx, logs, fireReady } = makeCtx(engine);
+    const plugin = new AuditPlugin();
+    await plugin.init(ctx);
+    await plugin.start(ctx);
+    await fireReady();
+
+    expect(logs.warn.some((m) => m.includes('could not provision sys_activity'))).toBe(true);
+    const placement = logs.info.find((m) => m.includes('system tables provisioned'));
+    expect(placement).toContain('sys_audit_log→sqlite');
+    expect(placement).toContain('sys_comment→sqlite');
+    expect(placement).not.toContain('sys_activity');
+  });
+});
+
 /**
  * #4630 — the sys_comment record-level gates are only worth as much as their
  * MOUNTING: `comment-access-hooks.test.ts` proves what the hooks decide, this

packages/plugins/plugin-audit/src/audit-plugin.ts

@@ -181,19 +181,96 @@ export class AuditPlugin implements Plugin {
    * it is absent (and alters to add columns) — so this is safe on every boot,
    * and a no-op for objects whose table already exists. Per-object failures are
    * isolated so one bad object can't block the rest.
+   *
+   * ## Why this method reports where each table landed (#4887)
+   *
+   * `syncObjectSchema` returns `void` and exits SILENTLY on three conditions
+   * the plugin cannot see from the outside: the object is not in the registry,
+   * no driver resolves for it, or the resolved driver has no `syncSchema`. A
+   * caller that only catches throws therefore cannot tell "created" from "did
+   * nothing" — and neither could a reader of the log, because this method said
+   * nothing at all on success.
+   *
+   * That silence cost a whole misdiagnosis. #4887 reported these tables as
+   * "never provisioned" because they were absent from the primary SQLite file,
+   * and concluded the guard below had bailed out. It had not: `sys_audit_log`
+   * (`lifecycle.class: 'audit'`) and `sys_activity` (`lifecycle.class:
+   * 'telemetry'`) are routed by ADR-0057 §3.6 to the dedicated `telemetry`
+   * datasource whenever one is registered — which `os dev` provisions by
+   * default as a SIBLING FILE (`dev.db` → `dev.telemetry.db`). Their tables
+   * were created, in that other store. `sys_comment` carries no lifecycle
+   * class, stays on the primary, and was the one the reporter found. So the
+   * provisioning loop reports the resolved datasource per object, and calls out
+   * the split explicitly when it is in effect: a table that is "missing" from
+   * the database you are looking at, and a table that was never created, are
+   * different problems, and the log now distinguishes them.
    */
   private async provisionSystemTables(engine: IDataEngine, ctx: PluginContext): Promise<void> {
     // `syncObjectSchema` lives on the concrete ObjectQL engine, not the
     // IDataEngine contract; engines/drivers without on-demand DDL (e.g. an
     // in-memory test double) simply skip provisioning.
     const sync = (engine as unknown as { syncObjectSchema?: (name: string) => Promise<void> }).syncObjectSchema;
-    if (typeof sync !== 'function') return;
+    if (typeof sync !== 'function') {
+      // #4887 — this return used to be silent, so "provisioning was skipped
+      // wholesale" and "provisioning ran fine" produced identical logs. Name
+      // the consequence, not just the condition.
+      ctx.logger.warn(
+        'AuditPlugin: this engine exposes no syncObjectSchema() — sys_audit_log / sys_activity / sys_comment were NOT ' +
+          'provisioned up-front and stay lazy-created on first WRITE. An env that READS one first (the home page ' +
+          'activity feed queries sys_activity before any mutation) will log "no such table" until something writes to it.',
+      );
+      return;
+    }
+    // Same optional-probe posture as `syncObjectSchema` above: `getDriverForObject`
+    // is public on the concrete ObjectQL engine but not part of IDataEngine, so
+    // engines that lack it simply report no datasource — never an error.
+    const resolveDriver = (engine as unknown as {
+      getDriverForObject?: (name: string) => { name?: string } | undefined;
+    }).getDriverForObject;
+    // Declared on IDataEngine (optional — engines with no named-driver registry
+    // omit it), so no cast is needed here.
+    const defaultDatasource = engine.getDefaultDriverName?.();
+
+    const placements: string[] = [];
+    const offDefault: string[] = [];
     for (const obj of [SysAuditLog, SysActivity, SysComment]) {
       try {
         await sync.call(engine, obj.name);
       } catch (err) {
         ctx.logger.warn(`AuditPlugin: could not provision ${obj.name} storage — ${(err as Error)?.message ?? err}`);
+        continue;
       }
+      if (typeof resolveDriver !== 'function') continue;
+      let datasource: string | undefined;
+      try {
+        datasource = resolveDriver.call(engine, obj.name)?.name;
+      } catch {
+        datasource = undefined;
+      }
+      if (!datasource) {
+        // The second of the two silent exits #4887 asked to make audible: the
+        // call above resolved without throwing, but no driver backs this object,
+        // so `syncObjectSchema` returned having issued no DDL at all.
+        ctx.logger.warn(
+          `AuditPlugin: ${obj.name} resolves to NO datasource driver — syncObjectSchema() returned without creating its ` +
+            'storage. Reads and writes against it will fail with "no such table" until a driver backs its datasource.',
+        );
+        continue;
+      }
+      placements.push(`${obj.name}→${datasource}`);
+      if (defaultDatasource !== undefined && datasource !== defaultDatasource) offDefault.push(`${obj.name}→${datasource}`);
+    }
+
+    if (placements.length > 0) {
+      ctx.logger.info(`AuditPlugin: system tables provisioned — ${placements.join(', ')}`);
+    }
+    if (offDefault.length > 0) {
+      ctx.logger.info(
+        `AuditPlugin: ${offDefault.join(', ')} live on a NON-default datasource (ADR-0057 §3.6 lifecycle-class ` +
+          `separation), not on '${defaultDatasource}'. Their tables exist in that store — on SQLite, a different FILE. ` +
+          'Anything that reads them without naming the object (raw SQL on the default datasource) will report ' +
+          '"no such table" even though provisioning succeeded.',
+      );
     }
   }
 }