fix(devx): durability log-level matcher reads the callee, and stops accepting a spelling that prints nothing (#9750)

* fix(devx): the durability log-level matcher reads the callee, and stops accepting a spelling that prints nothing

`loggerLevel()` required the callee to be a plain property access, so
`(logger.error ?? logger.warn)(...)` — a call on a parenthesized expression —
collected no levels and the catch was reported as `catch swallows the failure
with no log at all`, the harshest verdict in the file, on code that is loud at
runtime.

The dangerous half was the repair that report invited. The one fallback
spelling the matcher DID accept is `logger.error?.(...)`, which prints nothing
at all against a sink that has no `error` — and `error` is declared optional on
exactly the sinks that use the idiom. So the gate's cheapest satisfaction
converted a loud degradation into a silent one.

- resolve the callee structurally: parentheses, `??`/`||`, a ternary,
  `.call`/`.apply`/`.bind`, non-null assertions, `logger['error']`, and a
  same-file `const` holding a fallback are followed to whatever they end at.
- an optional CALL (`?.(`) no longer counts as loud: it is the author's own
  statement that the call may not print, and the sink it holds still has `warn`.
  Optionality on the RECEIVER (`logger?.error(...)`) is deliberately not judged.
- "I could not read this call" is its own verdict, `unreadable-report`, instead
  of being folded into `silent-swallow`.
- six seams the tightened rule found — plugin-audit x3, plugin-email,
  plugin-security x2, all on sinks whose `error` is declared optional — now
  reach for `error` and fall back to `warn` instead of to silence.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01XqDQYVU5smx29ts9pAErja

* test(plugins): pin that a sink without `error` still hears the durability report

One per repaired package. Each asserts the MESSAGE lands at `warn` — not merely
that nothing threw, which the silent `logger?.error?.(…)` version satisfied too.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01XqDQYVU5smx29ts9pAErja

* fix(plugin-audit): AuthEventAuditLogger declares the `warn` fallback its report needs

`error` is optional on this sink, so a durability report that reaches for it
needs somewhere to fall back to — and this interface declared no `warn` at all,
while its sibling `ReadAuditLogger` in the same package always has. The type,
not the call site, was the thing missing the channel.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01XqDQYVU5smx29ts9pAErja

* chore: changeset for the durability-report fallback, and re-measure the shape census

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01XqDQYVU5smx29ts9pAErja

---------

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

Author: os-steve

.changeset/durability-log-level-callee-shapes.md

@@ -0,0 +1,23 @@
+---
+"@objectstack/plugin-audit": patch
+"@objectstack/plugin-email": patch
+"@objectstack/plugin-security": patch
+---
+
+A durability failure reported to a logger without `error` is no longer lost
+
+Six degradation reports — a lost `sys_audit_log` row (CRUD, auth-event and
+read-audit writers), a stranded `sys_email` row, and the two permission-set
+metadata backfill failures — were spelled `logger?.error?.(…)`. `error` is
+declared OPTIONAL on those sinks, and an optional call emits nothing at all when
+the method is absent: a host injecting a `{ info, warn }` logger received no
+report whatsoever, on exactly the paths whose whole point is that nothing else
+looks broken afterwards.
+
+Each now reaches for `error` and falls back to `warn`, never to silence. The
+message, its consequence and its fix are identical on both channels; only the
+level degrades, and only when the sink cannot do better.
+
+`AuthEventAuditLogger` additionally declares the `warn?` method it needs for
+that fallback, matching `ReadAuditLogger`, which always had it. The addition is
+optional, so no existing sink stops satisfying the interface.

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

@@ -1068,7 +1068,7 @@ describe('audit writers — a lost audit row is reported at error (#5226)', () =
   interface LogLine { level: string; message: string; meta?: any }
 
   /** Engine whose `sys_audit_log` insert always fails, capturing every log line. */
-  function makeFailingEngine(failWith = 'no such table: sys_audit_log') {
+  function makeFailingEngine(failWith = 'no such table: sys_audit_log', omitError = false) {
     const hooks = new Map<string, Array<(ctx: any) => any>>();
     const logs: LogLine[] = [];
     const sudoApi = {
@@ -1095,7 +1095,12 @@ describe('audit writers — a lost audit row is reported at error (#5226)', () =
       },
       unregisterHooksByPackage() { /* no-op */ },
       logger: {
-        error(message: string, _err?: unknown, meta?: any) { logs.push({ level: 'error', message, meta }); },
+        // `omitError` reproduces the sink a host may legitimately inject: the
+        // kernel `Logger` requires `error`, but this reporter reaches its sink
+        // through `(engine as any).logger`, so nothing checks. #9657.
+        ...(omitError
+          ? {}
+          : { error(message: string, _err?: unknown, meta?: any) { logs.push({ level: 'error', message, meta }); } }),
         warn(message: string, meta?: any) { logs.push({ level: 'warn', message, meta }); },
         debug(message: string, meta?: any) { logs.push({ level: 'debug', message, meta }); },
         info() { /* unused */ },
@@ -1127,6 +1132,24 @@ describe('audit writers — a lost audit row is reported at error (#5226)', () =
     expect(errors[0].meta).toMatchObject({ object: 'crm_lead', action: 'create' });
   });
 
+  it('still reports the lost row when the sink has NO `error` — at warn, never in silence (#9657)', async () => {
+    // The regression this pins: the report used to be spelled
+    // `logger?.error?.(…)`, an optional call that emits NOTHING against a sink
+    // without `error`. The compliance trail was then incomplete AND unreported.
+    // ⛔ Asserting only "did not throw" would pass on the silent version too,
+    // so this asserts the MESSAGE lands, and that it is the same one.
+    const { engine, fire, logs } = makeFailingEngine('no such table: sys_audit_log', true);
+    installAuditWriters(engine as any);
+
+    await fire('afterInsert', aWrite('l-1'));
+
+    const warns = logs.filter((l) => l.level === 'warn');
+    expect(warns).toHaveLength(1);
+    expect(warns[0].message).toMatch(/compliance trail is now INCOMPLETE/);
+    expect(warns[0].message).toMatch(/OS_TELEMETRY_DB=0/);
+    expect(warns[0].meta).toMatchObject({ object: 'crm_lead', action: 'create' });
+  });
+
   it('names both the CONSEQUENCE and the FIX in the first line it prints', async () => {
     const { engine, fire, logs } = makeFailingEngine();
     installAuditWriters(engine as any);

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

@@ -881,7 +881,7 @@ export function installAuditWriters(
       auditFailureReported = true;
       // The two things an `error` here owes, both in the first line it prints:
       // the CONSEQUENCE, concretely, and the FIX.
-      logger?.error?.(
+      const message =
         'Audit write FAILED — the compliance trail is now INCOMPLETE. The audited write itself SUCCEEDED and is on ' +
           'disk, so the API returned success and nothing downstream looks broken; only the `sys_audit_log` row that ' +
           'records who did it never landed, and nothing retries it. Every subsequent audited write is likely losing ' +
@@ -890,10 +890,16 @@ export function installAuditWriters(
           "lifecycle class routes it to the dedicated `telemetry` datasource whenever one is registered (`os dev` " +
           'provisions one by default as a SIBLING SQLite file), so a "no such table" here usually means the write ' +
           'executed against a DIFFERENT datasource than the one the table was created in — see framework#5226. ' +
-          'Set `OS_TELEMETRY_DB=0` to keep every lifecycle-classed object on the primary datasource.',
-        err instanceof Error ? err : new Error(detail),
-        { object, action },
-      );
+          'Set `OS_TELEMETRY_DB=0` to keep every lifecycle-classed object on the primary datasource.';
+      // `error` is OPTIONAL on this sink, so `logger?.error?.(…)` printed
+      // NOTHING when the host injected one without it — the durability
+      // degradation this text describes would then be reported by nobody at
+      // all (#9657). Reach for `error`, fall back to `warn`, never to silence.
+      if (logger?.error) {
+        logger.error(message, err instanceof Error ? err : new Error(detail), { object, action });
+      } else {
+        logger?.warn?.(message, { object, action, err: detail });
+      }
     } catch {
       /* logging must never break the audited write */
     }

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

@@ -319,4 +319,27 @@ describe('[#8144] createAuthEventAuditSink writes a login row that names its act
     // on a systemic cause trains everyone to skim the channel.
     expect(logger.debug).toHaveBeenCalledTimes(1);
   });
+
+  it('[#9657] a sink with NO `error` still hears it — at warn, not in silence', async () => {
+    // `AuthEventAuditLogger.error` is OPTIONAL and the report used to be
+    // `logger?.error?.(…)`, an optional call that emits NOTHING when the method
+    // is absent. The sign-in still succeeds either way, which is exactly why
+    // the missing ledger row has to be somebody's problem out loud.
+    const broken: any = {
+      getSchema: () => null,
+      insert: async () => {
+        throw new Error('no such table: sys_audit_log');
+      },
+    };
+    const logger = { warn: vi.fn(), debug: vi.fn() };
+    const sink = createAuthEventAuditSink({ getEngine: () => broken, logger });
+
+    await expect(sink.recordAuthEvent({ action: 'login', userId: 'usr_1' })).resolves.toBeUndefined();
+
+    expect(logger.warn).toHaveBeenCalledTimes(1);
+    const [msg, meta] = logger.warn.mock.calls[0];
+    expect(String(msg)).toContain('INCOMPLETE');
+    expect(String(msg)).toContain('Fix:');
+    expect(meta).toMatchObject({ action: 'login' });
+  });
 });

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

@@ -105,6 +105,14 @@ export interface AuthSessionAuditEvent {
  */
 export interface AuthEventAuditLogger {
   error?(msg: string, err?: Error, meta?: Record<string, any>): void;
+  /**
+   * The fallback channel for the durability report below. `error` is optional
+   * here, so a sink that has none must still have somewhere to put a lost audit
+   * row — reaching for `error` and finding nothing must degrade to `warn`,
+   * never to silence (#9657). Signature and optionality mirror
+   * `ReadAuditLogger` in `read-audit.ts`, which already declared it.
+   */
+  warn?(msg: string, meta?: Record<string, any>): void;
   debug?(msg: string, meta?: Record<string, any>): void;
 }
 
@@ -172,7 +180,7 @@ export function createAuthEventAuditSink(opts: AuthEventAuditSinkOptions): AuthE
         return;
       }
       failureReported = true;
-      logger?.error?.(
+      const message =
         'Auth-event audit write FAILED — the compliance trail is now INCOMPLETE. The sign-in/sign-out itself ' +
           'SUCCEEDED and the user holds a valid session, so the API returned 200 and nothing downstream looks ' +
           `broken; only the \`sys_audit_log\` row recording the ${action} never landed, and nothing retries it. ` +
@@ -183,10 +191,16 @@ export function createAuthEventAuditSink(opts: AuthEventAuditSinkOptions): AuthE
           'lifecycle class routes it to the dedicated `telemetry` datasource whenever one is registered (`os dev` ' +
           'provisions one by default as a SIBLING SQLite file), so a "no such table" here usually means the write ' +
           'executed against a DIFFERENT datasource than the one the table was created in. Set `OS_TELEMETRY_DB=0` ' +
-          'to keep every lifecycle-classed object on the primary datasource.',
-        err instanceof Error ? err : new Error(detail),
-        { action },
-      );
+          'to keep every lifecycle-classed object on the primary datasource.';
+      // `error` is OPTIONAL on this sink, so `logger?.error?.(…)` printed
+      // NOTHING when the host injected one without it — the durability
+      // degradation this text describes would then be reported by nobody at
+      // all (#9657). Reach for `error`, fall back to `warn`, never to silence.
+      if (logger?.error) {
+        logger.error(message, err instanceof Error ? err : new Error(detail), { action });
+      } else {
+        logger?.warn?.(message, { action, err: detail });
+      }
     } catch {
       /* logging must never break the auth response */
     }

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

@@ -461,7 +461,7 @@ export function installReadAuditWriter(
         return;
       }
       failureReported = true;
-      logger?.error?.(
+      const message =
         `Read-audit write FAILED — ${count} record-view row(s) were LOST and the compliance trail is now ` +
           'INCOMPLETE. The reads themselves SUCCEEDED and returned 200, so the API, the screens and every ' +
           'counter read clean; only the `sys_audit_log` rows recording WHO opened those records never landed, ' +
@@ -473,10 +473,16 @@ export function installReadAuditWriter(
           'one is registered (`os dev` provisions one by default as a SIBLING SQLite file), so a "no such ' +
           'table" here usually means the write executed against a DIFFERENT datasource than the one the table ' +
           'was created in. Set `OS_TELEMETRY_DB=0` to keep every lifecycle-classed object on the primary ' +
-          'datasource.',
-        err instanceof Error ? err : new Error(detail),
-        { count },
-      );
+          'datasource.';
+      // `error` is OPTIONAL on this sink, so `logger?.error?.(…)` printed
+      // NOTHING when the host injected one without it — the durability
+      // degradation this text describes would then be reported by nobody at
+      // all (#9657). Reach for `error`, fall back to `warn`, never to silence.
+      if (logger?.error) {
+        logger.error(message, err instanceof Error ? err : new Error(detail), { count });
+      } else {
+        logger?.warn?.(message, { count, err: detail });
+      }
     } catch {
       /* logging must never break the read */
     }

packages/plugins/plugin-email/src/outbox-sweep.test.ts

@@ -270,6 +270,26 @@ describe('failures are loud, counted, and never stop the batch', () => {
     expect(perRow[0]).toMatch(/engine exploded/);
   });
 
+  it('[#9657] reports a stranded row to a sink with NO `error` — at warn, not in silence', async () => {
+    // `SweepLogger.error` is declared OPTIONAL, and the per-row report used to
+    // be `logger?.error?.(…)`: against a `{ info, warn }` sink it emitted
+    // NOTHING, so the message that stays `queued` forever was reported by
+    // nobody while the server kept looking healthy.
+    const engine = fakeEngine([{ id: 'row-bad', created_at: ago(min(30)) }]);
+    const service = fakeService({
+      deliver: () => { throw new Error('engine exploded'); },
+    });
+    const logger = { info: vi.fn(), warn: vi.fn() };
+
+    const res = await sweepStrandedOutbox({ engine, service, logger, now: () => NOW });
+
+    expect(res).toMatchObject({ scanned: 1, failed: 1 });
+    const warned = lines(logger.warn).filter((l) => l.includes('could not advance sys_email row'));
+    expect(warned).toHaveLength(1);
+    expect(warned[0]).toMatch(/row-bad/);
+    expect(warned[0]).toMatch(/engine exploded/);   // the cause survives the fallback
+  });
+
   it('propagates a failure of the query itself — the sweep did not happen', async () => {
     const engine = { find: vi.fn(async () => { throw new Error('no such table: sys_email'); }) };
     await expect(sweepStrandedOutbox({ engine, service: fakeService(), now: () => NOW }))

packages/plugins/plugin-email/src/outbox-sweep.ts

@@ -199,13 +199,17 @@ export async function sweepStrandedOutbox(
       result.failed++;
       if (!rowErrorReported) {
         rowErrorReported = true;
-        logger?.error?.(
+        const message =
           `EmailServicePlugin: outbox sweep could not advance sys_email row '${rowId}' — that message stays `
           + 'at `queued`, undelivered, and nothing will look at it again until the next restart, while the '
           + 'server keeps reporting healthy. Fix: the cause below comes from the datasource or the queue, '
           + 'not from the message itself (a message that cannot be sent is recorded as `failed` on its own '
-          + `row); restore that dependency and restart to re-sweep. Cause: ${err?.message ?? err}`,
-        );
+          + `row); restore that dependency and restart to re-sweep. Cause: ${err?.message ?? err}`;
+        // `SweepLogger.error` is OPTIONAL, so `logger?.error?.(…)` printed
+        // NOTHING against a sink that has only `warn` — the stranded row would
+        // then be reported by nobody (#9657). Fall back to `warn`, not silence.
+        if (logger?.error) logger.error(message);
+        else logger?.warn?.(message);
       }
     }
   }

packages/plugins/plugin-security/src/permission-set-projection.test.ts

@@ -1016,6 +1016,36 @@ describe('reconcilePermissionSetProjection', () => {
     expect(logs.some((l) => l.level === 'info' && /reconciled/.test(l.msg))).toBe(false);
   });
 
+  it('[#9657] a sink with NO `error` still hears the backfill failure — at warn, not in silence', async () => {
+    // `ProjectionLogger.error` is declared OPTIONAL, and the report used to be
+    // spelled `logger?.error?.(…)` — an optional call that emits NOTHING when
+    // the method is absent. A host injecting `{ info, warn }` therefore lost
+    // the whole durability report, on the one path that must never be quiet.
+    const ql = makeQl();
+    const protocol = makeProtocol(ql);
+    ql.permRows.push({
+      id: 'ps_bad', name: 'broken_set', managed_by: 'admin', active: true,
+      label: 'Broken Set', object_permissions: JSON.stringify({ ticket: { allowRead: 'yes-please' } }),
+    });
+    const logs: Array<{ level: string; msg: string; meta?: any }> = [];
+    const logger = {
+      info: (m: string, meta?: any) => logs.push({ level: 'info', msg: m, meta }),
+      warn: (m: string, meta?: any) => logs.push({ level: 'warn', msg: m, meta }),
+    };
+
+    const out = await reconcilePermissionSetProjection(protocol, { ql, logger });
+
+    expect(out.backfillFailed).toBe(1);
+    const firstFailure = logs.find((l) => /backfill into metadata FAILED/.test(l.msg));
+    expect(firstFailure).toBeDefined();
+    expect(firstFailure!.level).toBe('warn');
+    // The consequence and the fix survive the fallback — a downgraded level is
+    // a degradation of the CHANNEL, never of the message.
+    expect(firstFailure!.msg).toMatch(/Nothing will look broken/);
+    expect(firstFailure!.msg).toMatch(/Fix:/);
+    expect(firstFailure!.meta?.name).toBe('broken_set');
+  });
+
   it('heals a record that drifted from an EXISTING metadata definition (metadata wins)', async () => {
     const ql = makeQl();
     const declared = { member_default: envBody({ name: 'member_default', systemPermissions: ['declared.baseline'] }) };

packages/plugins/plugin-security/src/permission-set-projection.ts

@@ -800,14 +800,17 @@ export function createPermissionSetWriteThrough(
           // definition never returned to the metadata store — the stores
           // disagree silently until someone notices the set behaves like a
           // legacy data-door row.
-          logger?.error?.(
+          const message =
             '[security] restored permission set was NOT re-authored into metadata (ADR-0094 D3) — the record is ' +
             'back and looks healthy, but the metadata store has no definition for it, so a metadata-driven ' +
             're-provision will not recreate it. Fix: make the record body spec-valid (the error names the ' +
-            'offending key) and re-save the set through Setup, or re-run boot reconciliation.',
-            e as Error,
-            { name: row.name },
-          );
+            'offending key) and re-save the set through Setup, or re-run boot reconciliation.';
+          // `ProjectionLogger.error` is OPTIONAL, so `logger?.error?.(…)` printed
+          // NOTHING against a sink that has only `warn` — the durability
+          // degradation described above would then be reported by nobody at all
+          // (#9657). Reach for `error`, fall back to `warn`, never to silence.
+          if (logger?.error) logger.error(message, e as Error, { name: row.name });
+          else logger?.warn?.(message, { name: row.name, error: String((e as Error)?.message ?? e) });
         }
       }
       return;
@@ -1023,7 +1026,7 @@ export async function reconcilePermissionSetProjection(
         // the summary line below. #4669: this was a `warn` with no counter,
         // which is why a 100%-failing backfill sat green for a release.
         if (out.backfillFailed === 1) {
-          logger?.error?.(
+          const message =
             '[security] permission-set backfill into metadata FAILED (ADR-0094 D4) — this environment has ' +
             '`sys_permission_set` records with NO metadata definition backing them, and the one-time backfill ' +
             'did not write one. Nothing will look broken: the records still list in Setup and the evaluator ' +
@@ -1032,10 +1035,13 @@ export async function reconcilePermissionSetProjection(
             'of them, and every boot retries and fails identically. Fix: make the record body spec-valid — the ' +
             'error below names the offending key; `permissionSetBodyFromRow()` already drops storage columns ' +
             '(`active`, timestamps, provenance), so a rejection here means the stored facet JSON itself is ' +
-            'off-contract — then reboot to re-run reconciliation, or delete the orphan record.',
-            e as Error,
-            { name: row.name },
-          );
+            'off-contract — then reboot to re-run reconciliation, or delete the orphan record.';
+          // `ProjectionLogger.error` is OPTIONAL, so `logger?.error?.(…)` printed
+          // NOTHING against a sink that has only `warn` — the durability
+          // degradation described above would then be reported by nobody at all
+          // (#9657). Reach for `error`, fall back to `warn`, never to silence.
+          if (logger?.error) logger.error(message, e as Error, { name: row.name });
+          else logger?.warn?.(message, { name: row.name, error: String((e as Error)?.message ?? e) });
         }
       }
     } else if (recordDiffersFromBody(row, effective)) {