fix(metadata): a failing history cleanup run is no longer silent, at both of start()’s triggers

.changeset/history-cleanup-failing-run-is-not-silent.md

@@ -0,0 +1,9 @@
+---
+'@objectstack/metadata': patch
+---
+
+fix(metadata): a `HistoryCleanupManager` run that loses deletes now says so, at both of `start()`'s triggers
+
+A failing history cleanup was completely silent. Three things composed: every inner `catch` on the delete path is a bare `catch {`, so the error object is discarded; the only `console.error` in `runCleanup()` sits in its OUTER catch, which those inner catches prevent execution from reaching; and `start()` invoked the run as `void this.runCleanup()`, throwing away the `{ deleted, errors }` the run returns — at BOTH call sites, the immediate run and every interval tick. A driver whose deletes failed on every scheduled run therefore produced zero output and no reachable error count, while the history table grew past its retention policy with nothing to find.
+
+The repair reads the envelope instead of replacing it. `runCleanup()`'s contract, its inner catches and its counting are unchanged: reporting a failure to the CALLER is the third answer AGENTS.md → "Degradation log levels" allows a durability seam, and that same section names a log per failed write as the mirror-image failure. What was missing was a reader — `start()` is where the chain ends, since it returns `void` and an interval tick has no caller at all. Both call sites now go through one shared pass that reads the returned counts and, when a run lost deletes, prints one `error` line naming the consequence (rows past the retention policy are still in the table, nothing retries them, and the system keeps reporting healthy) and where to look. A run that loses nothing stays quiet, and a direct caller of `runCleanup()` sees exactly the same `{ deleted, errors }` as before.

packages/metadata/src/utils/history-cleanup-failure-signal.test.ts

@@ -0,0 +1,195 @@
+// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
+
+/**
+ * #16061 — a cleanup run that loses deletes must SAY SO, at both triggers.
+ *
+ * ## The closed loop this file pins open
+ *
+ * Three things composed to make a failing cleanup completely silent:
+ *
+ *   1. every inner `catch` on the delete path is a bare `catch {` — unbound,
+ *      so the error object is gone;
+ *   2. the only `console.error` in `runCleanup()` sits in its OUTER catch,
+ *      which the inner catches prevent execution from reaching;
+ *   3. `start()` invoked the run as `void this.runCleanup()`, discarding the
+ *      `{ deleted, errors }` the run returns — at BOTH call sites.
+ *
+ * ⇒ A driver whose deletes fail on every scheduled run produced zero output
+ * and no reachable error count. The history table grew past its retention
+ * policy with nothing to find.
+ *
+ * ## What is asserted, and what is deliberately NOT
+ *
+ * The subject is the SIGNAL, not the cleanup. Adding a report here is not an
+ * enhancement — it turns an error path that already exists from unobservable
+ * into observable — so every case below asserts that a failing run produces
+ * something an operator can read, and none of them asserts that any row was
+ * deleted.
+ *
+ * ⛔ Not pinned: the wording of the report, beyond the two facts AGENTS.md →
+ * "Degradation log levels" says such a line owes — the consequence and the
+ * fix — plus the failure count, which is the only thing `runCleanup()`
+ * carries out of the swallowing catches. Pinning the prose would make every
+ * later clarification a test edit.
+ *
+ * ⛔ Not changed, and asserted unchanged: `runCleanup()`'s own contract. Its
+ * inner catches stay silent on purpose — the same AGENTS.md section names a
+ * log per failed write as the mirror-image failure and calls a failure handed
+ * to the CALLER the third legal answer. The defect was never that the seams
+ * report through the envelope; it was that nobody read the envelope.
+ *
+ * ## Why the two triggers are separate cases
+ *
+ * `start()` runs the pass twice over: once immediately, and once per interval
+ * tick. Both were `void this.runCleanup()`. Repairing only the immediate one
+ * leaves every SCHEDULED run silent — which is the defect, for the trigger
+ * that runs forever rather than the one that runs once. A single case that
+ * only counted reports could pass on a half-fix, so the immediate run and a
+ * tick are asserted separately.
+ */
+
+import { describe, it, expect, vi, afterEach } from 'vitest';
+import type { IDataDriver } from '@objectstack/spec/contracts';
+import type { MetadataHistoryRetentionPolicy } from '@objectstack/spec/system';
+import type { DatabaseLoader } from '../loaders/database-loader.js';
+import { HistoryCleanupManager } from './history-cleanup.js';
+
+const TABLE = 'sys_metadata_history';
+const HOUR_MS = 60 * 60 * 1000;
+
+/** Every delete the age branch attempts, and whether the driver refuses it. */
+interface DriverLog {
+  deleteManyCalls: number;
+}
+
+/**
+ * A manager over a driver whose bulk delete either refuses or succeeds.
+ *
+ * `HistoryCleanupManager` reads `driver`, `historyTableName` and
+ * `organizationId` off the loader by property, so a plain object is enough
+ * (the same stub shape `history-cleanup-dst.test.ts` uses).
+ */
+function managerFor(
+  mode: 'refuses' | 'succeeds',
+  log: DriverLog,
+  policy: MetadataHistoryRetentionPolicy,
+): HistoryCleanupManager {
+  const driver = {
+    deleteMany(table: string, _filter: Record<string, unknown>): number {
+      expect(table).toBe(TABLE);
+      log.deleteManyCalls++;
+      if (mode === 'refuses') {
+        throw new Error('driver refused the delete');
+      }
+      return 0;
+    },
+    find(): Record<string, unknown>[] {
+      throw new Error('the maxVersions branch must not run in these cases');
+    },
+  } as unknown as IDataDriver;
+
+  const loader = {
+    driver,
+    historyTableName: TABLE,
+    organizationId: undefined,
+  } as unknown as DatabaseLoader;
+
+  return new HistoryCleanupManager(policy, loader);
+}
+
+/** Join one `console.error` call's arguments into the text an operator reads. */
+function textOf(call: unknown[]): string {
+  return call.map((a) => (typeof a === 'string' ? a : String(a))).join(' ');
+}
+
+afterEach(() => {
+  vi.useRealTimers();
+  vi.restoreAllMocks();
+});
+
+describe('#16061 — a failing history cleanup is not silent', () => {
+  it('reports the IMMEDIATE run started by start()', async () => {
+    const log: DriverLog = { deleteManyCalls: 0 };
+    const errors = vi.spyOn(console, 'error').mockImplementation(() => {});
+    vi.useFakeTimers();
+
+    const manager = managerFor('refuses', log, {
+      autoCleanup: true,
+      maxAgeDays: 30,
+      cleanupIntervalHours: 1,
+    });
+
+    manager.start();
+    // Let the immediate run settle without advancing to the first tick.
+    await vi.advanceTimersByTimeAsync(0);
+    manager.stop();
+
+    // The run really ran and really lost a delete — without this the case
+    // could pass over a driver that was never asked.
+    expect(log.deleteManyCalls).toBe(1);
+
+    expect(errors).toHaveBeenCalledTimes(1);
+    const text = textOf(errors.mock.calls[0]);
+    expect(text).toMatch(/history cleanup/i);
+    // The count is the only thing carried out of the swallowing catches.
+    expect(text).toContain('1');
+    // The two things AGENTS.md says such a line owes.
+    expect(text).toMatch(/still in the table|grows past the retention policy/i);
+    expect(text).toMatch(/fix:/i);
+  });
+
+  it('reports EVERY SCHEDULED run, not only the first', async () => {
+    const log: DriverLog = { deleteManyCalls: 0 };
+    const errors = vi.spyOn(console, 'error').mockImplementation(() => {});
+    vi.useFakeTimers();
+
+    const manager = managerFor('refuses', log, {
+      autoCleanup: true,
+      maxAgeDays: 30,
+      cleanupIntervalHours: 1,
+    });
+
+    manager.start();
+    await vi.advanceTimersByTimeAsync(0);
+    expect(errors).toHaveBeenCalledTimes(1);
+
+    // One interval tick. This is the SECOND call site; a fix applied only to
+    // the immediate run leaves this one silent and this expectation red.
+    await vi.advanceTimersByTimeAsync(HOUR_MS);
+    manager.stop();
+
+    expect(log.deleteManyCalls).toBe(2);
+    expect(errors).toHaveBeenCalledTimes(2);
+    expect(textOf(errors.mock.calls[1])).toMatch(/history cleanup/i);
+  });
+
+  it('CONTROL — a run that loses nothing says nothing', async () => {
+    const log: DriverLog = { deleteManyCalls: 0 };
+    const errors = vi.spyOn(console, 'error').mockImplementation(() => {});
+    vi.useFakeTimers();
+
+    const manager = managerFor('succeeds', log, {
+      autoCleanup: true,
+      maxAgeDays: 30,
+      cleanupIntervalHours: 1,
+    });
+
+    manager.start();
+    await vi.advanceTimersByTimeAsync(0);
+    await vi.advanceTimersByTimeAsync(HOUR_MS);
+    manager.stop();
+
+    // Same code path, same two triggers, driver simply does not refuse.
+    expect(log.deleteManyCalls).toBe(2);
+    expect(errors).not.toHaveBeenCalled();
+  });
+
+  it('leaves runCleanup()\'s envelope exactly as it was', async () => {
+    const log: DriverLog = { deleteManyCalls: 0 };
+    const manager = managerFor('refuses', log, { maxAgeDays: 30 });
+
+    // A DIRECT caller still gets the counts, unchanged: the repair reads the
+    // envelope, it does not replace it.
+    await expect(manager.runCleanup()).resolves.toEqual({ deleted: 0, errors: 1 });
+  });
+});

packages/metadata/src/utils/history-cleanup.ts

@@ -51,12 +51,13 @@ export class HistoryCleanupManager {
 
     const intervalMs = (this.policy.cleanupIntervalHours ?? 24) * 60 * 60 * 1000;
 
-    // Run cleanup immediately on start
-    void this.runCleanup();
+    // Run cleanup immediately on start. Both call sites go through
+    // `runCleanupAndReport()`, never `runCleanup()` — see its docblock.
+    void runCleanupAndReport(this);
 
     // Schedule periodic cleanup
     this.cleanupTimer = setInterval(() => {
-      void this.runCleanup();
+      void runCleanupAndReport(this);
     }, intervalMs);
   }
 
@@ -315,3 +316,65 @@ export class HistoryCleanupManager {
     };
   }
 }
+
+/**
+ * Run one cleanup pass for {@link HistoryCleanupManager.start} and report a
+ * run that lost deletes.
+ *
+ * `runCleanup()` reports its failures to the CALLER, in the `errors` field of
+ * the `{ deleted, errors }` envelope it returns. That is the third answer
+ * AGENTS.md → "Degradation log levels" allows a durability seam, and it is why
+ * that method's inner `catch` clauses are deliberately silent: the same
+ * section names a log per failed write as the mirror-image failure, and asks
+ * for one report, at the first degradation, naming the consequence and the
+ * fix.
+ *
+ * A failure handed to the caller is only reported while somebody READS it, and
+ * `start()` is where that chain ends — it returns `void`, and the interval tick
+ * has no caller at all. Both call sites used to spell the run
+ * `void this.runCleanup()`, so a driver whose deletes failed produced no output
+ * and no reachable count: the history table grew past its retention policy and
+ * nothing said so.
+ *
+ * So the envelope is read HERE, once per run. Restoring
+ * `void this.runCleanup()` at EITHER call site re-opens the defect for that
+ * trigger alone — a startup-only report leaves every scheduled run silent —
+ * which is why the pin asserts the immediate run and an interval tick
+ * separately.
+ *
+ * Module-level, and NOT a private method, on purpose: TypeScript emits
+ * `private` members into the published `dist/*.d.ts` and they join the class's
+ * nominal identity, so a private method would have made an observability
+ * repair move the published declaration. As a free function it changes none of
+ * it — measured, all 10 published declaration files byte-identical.
+ *
+ * Resolves rather than rejects on every path, so `void` at the call sites
+ * cannot turn a cleanup failure into an unhandled rejection.
+ */
+async function runCleanupAndReport(manager: HistoryCleanupManager): Promise<void> {
+  let outcome: { deleted: number; errors: number };
+
+  try {
+    outcome = await manager.runCleanup();
+  } catch (error) {
+    console.error(
+      'History cleanup: the run did not complete, so no history row past the retention '
+      + 'policy was deleted and the table keeps growing while the system reports healthy. '
+      + 'Fix: the cause below comes from the configured data driver, not from the retention '
+      + 'policy; call `runCleanup()` directly to reproduce it. Cause:',
+      error,
+    );
+    return;
+  }
+
+  if (outcome.errors > 0) {
+    console.error(
+      `History cleanup: ${outcome.errors} delete operation(s) failed and `
+      + `${outcome.deleted} row(s) were deleted. The history rows those deletes were meant `
+      + 'to remove are still in the table, nothing retries them, and the table grows past '
+      + 'the retention policy while the system keeps reporting healthy. Fix: check the data '
+      + 'driver delete path for the metadata history table. The per-failure causes are not '
+      + 'carried out of `runCleanup()`, so reproduce them against the driver directly.',
+    );
+  }
+}