objectstack-ai
diff --git a/‎.changeset/auth-event-audit-cause-keyed-report.md‎
Lines changed: 13 additions & 0 deletions b/‎.changeset/auth-event-audit-cause-keyed-report.md‎
Lines changed: 13 additions & 0 deletions
diff --git a/‎packages/plugins/plugin-audit/src/audit-writers.ts‎
Lines changed: 14 additions & 2 deletions b/‎packages/plugins/plugin-audit/src/audit-writers.ts‎
Lines changed: 14 additions & 2 deletions
diff --git a/‎packages/plugins/plugin-audit/src/auth-event-audit.test.ts‎
Lines changed: 200 additions & 0 deletions b/‎packages/plugins/plugin-audit/src/auth-event-audit.test.ts‎
Lines changed: 200 additions & 0 deletions
@@ -0,0 +1,13 @@
+---
+"@objectstack/plugin-audit": patch
+---
+
+A lost auth-event row is reported once per failure CAUSE, not once per process, and the first line names the cause instead of a fixed remedy.
+
+`auth-event-audit.ts` — the writer behind the `login` / `logout` rows in `sys_audit_log` — carried its own, independent copy of both defects the record-level audit writer was fixed for. `reportAuthEventWriteFailure` deduped on a single process-wide boolean, so after the first failure of any cause, every later failure of every *other* cause degraded to `debug` for the life of the process: a long-running server could keep losing sign-in and sign-out rows for hours to a second, unrelated fault, with one `error` line at the top of the log describing the first. `persistAuthEventAuditRow` is registered in the durability-degradation vocabulary precisely because a lost audit row must be reported at `error`.
+
+The dedupe key is now the failure's identity — the error `code` (or its absence) together with the object the rows are about. A repeat of an already-reported cause still degrades to `debug`, exactly as before; a new cause reports at `error`, once. The key is built from the `code` and **never** the message: a driver names the offending row in its message, so a message-keyed dedupe would grow one `error` line per lost row. Keyed on the code, the reported-cause set is bounded by the driver's code vocabulary and does not grow with traffic — measured at one `error` line for 200 failed sign-ins carrying 200 distinct messages under one code, and the same one line for 200 carrying no code at all.
+
+The first `error` line now leads with the underlying code and message, which were already computed at the call site and passed only into the `debug` payload. The ADR-0057 §3.6 telemetry-datasource guidance is kept — it is the correct remedy for the "no such table" cause it was written for — but is now printed only for that cause, decided by the shared `isMissingTableError` predicate for the one table this writer writes. Previously it was printed unconditionally, so an organization refusal was answered with "check the datasource", sending the operator to inspect something that was working.
+
+The cause-key helpers are imported from the record-level writer in this same package rather than re-spelled here: a second copy of that key is how these defects reached this file, so a third spelling would repeat the mistake. No published export is added or changed.
@@ -726,8 +726,17 @@ function renderMilestoneSummary(
  * A code that is absent, or is not a scalar, collapses to ONE bucket rather
  * than growing one: an uncoded fault is "the uncoded fault on this object", and
  * a thousand of them is still one `error` line.
+ *
+ * ⚠️ [#17452] EXPORTED, for `auth-event-audit.ts`. That file carried a second,
+ * independent copy of the process-wide boolean this key replaced, and it now
+ * imports this one instead of re-spelling it — a second copy of the key is
+ * precisely how the defect reached that file, so a third spelling would be the
+ * same mistake again. Same seam as its `createFieldPresenceProbe` import.
+ * ⛔ Deliberately NOT re-exported from the package barrel: the sharing is
+ * internal to `@objectstack/plugin-audit` and the published surface is
+ * unchanged by it.
  */
-function auditFailureCauseKey(object: string, err: unknown): string {
+export function auditFailureCauseKey(object: string, err: unknown): string {
   const code = (err as { code?: unknown } | null | undefined)?.code;
   const bounded = typeof code === 'string' || typeof code === 'number' ? String(code) : '(no code)';
   // JSON rather than a separator character: an object name and a driver code
@@ -743,8 +752,11 @@ function auditFailureCauseKey(object: string, err: unknown): string {
  * the line printed a fixed remedy and never looked at `err`. The code is what
  * makes two failures the same failure (see {@link auditFailureCauseKey}), so it
  * leads; the message is what makes this one legible.
+ *
+ * ⚠️ [#17452] Exported alongside {@link auditFailureCauseKey} and for the same
+ * reason — the two are one shape, and the auth-event sink needs both halves.
  */
-function auditFailureCauseSummary(err: unknown, detail: string): string {
+export function auditFailureCauseSummary(err: unknown, detail: string): string {
   const code = (err as { code?: unknown } | null | undefined)?.code;
   return typeof code === 'string' || typeof code === 'number' ? `${String(code)}: ${detail}` : detail;
 }
 
@@ -350,3 +350,203 @@ describe('[#8144] createAuthEventAuditSink writes a login row that names its act
     expect(meta).toMatchObject({ action: 'login' });
   });
 });
+
+/**
+ * [#17452] The dedupe key is the failure's CAUSE, not the process.
+ *
+ * The block above pins that a lost auth-event row is reported at `error`, and
+ * that it is reported ONCE rather than once per failed sign-in. Both still
+ * hold. What this block pins is the COUNTING UNIT of that "once", and the two
+ * defects the process-wide version had — the SECOND, independent copy of the
+ * pair `audit-writers.ts` carried before #15166:
+ *
+ *  1. after the first failure of ANY cause, every later failure of every OTHER
+ *     cause degraded to `debug` for the life of the process — a server could
+ *     keep losing sign-in rows for hours to a second fault with one `error`
+ *     line at the top of the log describing the first;
+ *  2. that one line named the ADR-0057 §3.6 telemetry-datasource remedy
+ *     unconditionally, so a refusal that had nothing to do with datasource
+ *     routing sent its operator to check something that was not broken.
+ *
+ * ⚠️ The anti-noise choice these must not undo is AGENTS.md's, and #4420 is
+ * what it was invented against: an unbounded per-event line nobody could read.
+ * `keys on the error CODE, never its message` below is the pin that keeps
+ * "once per cause" from decaying into it — ⛔ do not relax it to a message.
+ *
+ * The helpers are `audit-writers.ts`'s, imported rather than re-spelled: a
+ * second copy of this key is how the defect got here in the first place.
+ */
+describe('auth-event audit — reported once per CAUSE, not once per process (#17452)', () => {
+  interface LogLine {
+    level: string;
+    message: string;
+    meta?: Record<string, any>;
+  }
+
+  /** A sink whose ledger insert fails with a caller-chosen error each time. */
+  function makeCauseSink(nextError: (n: number) => unknown) {
+    const logs: LogLine[] = [];
+    let n = 0;
+    const broken: any = {
+      getSchema: () => null,
+      insert: async () => {
+        throw nextError(n++);
+      },
+    };
+    const logger = {
+      error(message: string, _err?: Error, meta?: Record<string, any>) {
+        logs.push({ level: 'error', message, meta });
+      },
+      warn(message: string, meta?: Record<string, any>) {
+        logs.push({ level: 'warn', message, meta });
+      },
+      debug(message: string, meta?: Record<string, any>) {
+        logs.push({ level: 'debug', message, meta });
+      },
+    };
+    const sink = createAuthEventAuditSink({ getEngine: () => broken, logger });
+    const signIn = (id: string) => sink.recordAuthEvent({ action: 'login', userId: id, sessionId: id });
+    const at = (level: string) => logs.filter((l) => l.level === level);
+    return { sink, signIn, at, logs };
+  }
+
+  const driverError = (message: string, code?: string): Error => {
+    const e = new Error(message) as Error & { code?: string };
+    if (code !== undefined) e.code = code;
+    return e;
+  };
+
+  const NO_SUCH_TABLE = () => driverError('no such table: sys_audit_log', 'SQLITE_ERROR');
+  const ORG_REQUIRED = () =>
+    driverError('system write requires an organization', 'ERR_SYSTEM_WRITE_ORGANIZATION_REQUIRED');
+
+  it('reports a SECOND, DIFFERENT cause at error — a new cause is a new degradation', async () => {
+    // THE DEFECT. On the process-wide boolean this was one `error` (the first
+    // cause) and one `debug`; the organization refusal — a completely
+    // different fault, with a different remedy — was never reported at all.
+    let phase = 0;
+    const { signIn, at } = makeCauseSink(() => (phase === 0 ? NO_SUCH_TABLE() : ORG_REQUIRED()));
+
+    await signIn('usr_1');
+    phase = 1;
+    await signIn('usr_2');
+
+    const errors = at('error');
+    expect(errors).toHaveLength(2);
+    expect(errors[0].message).toMatch(/no such table: sys_audit_log/);
+    expect(errors[1].message).toMatch(/ERR_SYSTEM_WRITE_ORGANIZATION_REQUIRED/);
+    expect(at('debug')).toHaveLength(0);
+    expect(at('warn')).toEqual([]);
+  });
+
+  it('still degrades a REPEAT of an already-reported cause to debug', async () => {
+    // ⚠️ THE DISCRIMINATING CONTROL. Deleting the boolean outright would also
+    // make the test above pass, and would be the falsifier AGENTS.md names
+    // ("log every failure at `error`"). This is the half that must NOT change:
+    // the same cause on the same object still says it once.
+    const { signIn, at } = makeCauseSink(() => NO_SUCH_TABLE());
+
+    for (const id of ['usr_1', 'usr_2', 'usr_3', 'usr_4', 'usr_5']) await signIn(id);
+
+    expect(at('error')).toHaveLength(1);
+    expect(at('debug')).toHaveLength(4);
+    // The repeats name the cause they were folded into, so a `debug` sweep can
+    // tell "the same fault, 4 more times" from "four different faults".
+    expect(at('debug')[0].meta?.cause).toBe(at('debug')[3].meta?.cause);
+  });
+
+  it('keys on the error CODE, never its message, so a per-row fault cannot flood `error`', async () => {
+    // ⚠️ THE ANTI-NOISE PIN (AGENTS.md; #4420). A driver names the offending
+    // ROW in its message, so a message-keyed dedupe would grow one `error`
+    // line per lost sign-in row — #4420 again, wearing the word "cause". 200
+    // sign-ins, 200 distinct messages, ONE code ⇒ one line.
+    const EVENTS = 200;
+    const { signIn, at } = makeCauseSink((i) =>
+      driverError(`UNIQUE constraint failed: sys_audit_log.id (row aud_${i})`, 'SQLITE_CONSTRAINT_UNIQUE'),
+    );
+
+    for (let i = 0; i < EVENTS; i += 1) await signIn(`usr_${i}`);
+
+    expect(at('error')).toHaveLength(1);
+    expect(at('debug')).toHaveLength(EVENTS - 1);
+  });
+
+  it('folds a fault carrying NO code into ONE bucket rather than growing one', async () => {
+    // The other half of the bound: "the code, or its ABSENCE" is a single key
+    // value, so an uncoded driver — the shape with nothing bounded to key on —
+    // still says it once instead of once per sign-in.
+    const EVENTS = 200;
+    const { signIn, at } = makeCauseSink((i) => driverError(`insert failed for record aud_${i}`));
+
+    for (let i = 0; i < EVENTS; i += 1) await signIn(`usr_${i}`);
+
+    expect(at('error')).toHaveLength(1);
+    expect(at('debug')).toHaveLength(EVENTS - 1);
+  });
+
+  it('carries the underlying code and message in the first line it prints', async () => {
+    // The information was computed one line above the branch and dropped on the
+    // floor: the `error` path built a fixed string and never read `err`.
+    const { signIn, at } = makeCauseSink(() => ORG_REQUIRED());
+
+    await signIn('usr_1');
+
+    const msg = at('error')[0].message;
+    expect(msg).toMatch(/ERR_SYSTEM_WRITE_ORGANIZATION_REQUIRED/);
+    expect(msg).toMatch(/system write requires an organization/);
+    // The consequence half is unchanged — it is still owed, and still first.
+    expect(msg).toMatch(/compliance trail is now INCOMPLETE/);
+  });
+
+  it('prints the datasource remedy for the cause it is the remedy FOR, and not for others', async () => {
+    // ⛔ Not a deletion: the ADR-0057 §3.6 routing text is genuinely correct for
+    // the "no such table" cause it was written for, so it must still print
+    // there. What is fixed is that it used to print for EVERY cause.
+    const missing = makeCauseSink(() => NO_SUCH_TABLE());
+    await missing.signIn('usr_1');
+    const forMissingTable = missing.at('error')[0].message;
+    expect(forMissingTable).toMatch(/telemetry/);
+    expect(forMissingTable).toMatch(/OS_TELEMETRY_DB=0/);
+
+    // The misdirection: the cause is an organization refusal and the text said
+    // "datasource".
+    const refused = makeCauseSink(() => ORG_REQUIRED());
+    await refused.signIn('usr_1');
+    const forRefusal = refused.at('error')[0].message;
+    expect(forRefusal).not.toMatch(/OS_TELEMETRY_DB/);
+    expect(forRefusal).not.toMatch(/telemetry/i);
+    // It still owes a fix — it just owes the RIGHT one.
+    expect(forRefusal).toMatch(/Fix:/);
+  });
+
+  it('[#9657] the `warn` fallback is per-cause too — a sink with no `error` hears the second fault', async () => {
+    // `AuthEventAuditLogger.error` is OPTIONAL, so the degrade path is the only
+    // channel a host without one ever gets. Fixing the dedupe on the `error`
+    // branch alone would leave that host exactly where it started.
+    const logs: Array<{ level: string; message: string }> = [];
+    let phase = 0;
+    const broken: any = {
+      getSchema: () => null,
+      insert: async () => {
+        throw phase === 0 ? NO_SUCH_TABLE() : ORG_REQUIRED();
+      },
+    };
+    const logger = {
+      warn(message: string) {
+        logs.push({ level: 'warn', message });
+      },
+      debug(message: string) {
+        logs.push({ level: 'debug', message });
+      },
+    };
+    const sink = createAuthEventAuditSink({ getEngine: () => broken, logger });
+
+    await sink.recordAuthEvent({ action: 'login', userId: 'usr_1' });
+    phase = 1;
+    await sink.recordAuthEvent({ action: 'logout', userId: 'usr_1' });
+
+    const warns = logs.filter((l) => l.level === 'warn');
+    expect(warns).toHaveLength(2);
+    expect(warns[1].message).toMatch(/ERR_SYSTEM_WRITE_ORGANIZATION_REQUIRED/);
+  });
+});