From 968251a6925d272892a66c8f923af42a559606c2 Mon Sep 17 00:00:00 2001 From: Claude Date: Sun, 6 Sep 2026 04:16:34 +0000 Subject: [PATCH 1/2] fix(metadata): a failing history cleanup run is no longer silent at either start() trigger MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Every inner catch on `runCleanup()`'s delete path is a bare `catch {`, so the error object is discarded; the only `console.error` in the method sits in its OUTER catch, which those inner catches prevent execution from reaching; and `start()` invoked the run as `void this.runCleanup()` at BOTH call sites — the immediate run and every interval tick — discarding the `{ deleted, errors }` the run returns. A driver whose deletes failed on every scheduled run produced zero output and no reachable error count. Read the envelope rather than replace it. `runCleanup()`'s contract, its inner catches and its counting are untouched: handing a failure to the CALLER is the third answer AGENTS.md "Degradation log levels" allows a durability seam, and that section names a log per failed write as the mirror-image failure. What was missing was a reader, and `start()` is where the chain ends — it returns void and an interval tick has no caller. Both call sites now go through one private pass that reads the counts and prints a single `error` line, naming the consequence and the fix, when a run lost deletes. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ --- ...story-cleanup-failing-run-is-not-silent.md | 9 + .../history-cleanup-failure-signal.test.ts | 195 ++++++++++++++++++ .../metadata/src/utils/history-cleanup.ts | 62 +++++- 3 files changed, 263 insertions(+), 3 deletions(-) create mode 100644 .changeset/history-cleanup-failing-run-is-not-silent.md create mode 100644 packages/metadata/src/utils/history-cleanup-failure-signal.test.ts diff --git a/.changeset/history-cleanup-failing-run-is-not-silent.md b/.changeset/history-cleanup-failing-run-is-not-silent.md new file mode 100644 index 0000000000..62580014a3 --- /dev/null +++ b/.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 private 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. diff --git a/packages/metadata/src/utils/history-cleanup-failure-signal.test.ts b/packages/metadata/src/utils/history-cleanup-failure-signal.test.ts new file mode 100644 index 0000000000..a90522a9ac --- /dev/null +++ b/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): number { + expect(table).toBe(TABLE); + log.deleteManyCalls++; + if (mode === 'refuses') { + throw new Error('driver refused the delete'); + } + return 0; + }, + find(): Record[] { + 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 }); + }); +}); diff --git a/packages/metadata/src/utils/history-cleanup.ts b/packages/metadata/src/utils/history-cleanup.ts index c064158a6e..a53cdb2637 100644 --- a/packages/metadata/src/utils/history-cleanup.ts +++ b/packages/metadata/src/utils/history-cleanup.ts @@ -51,15 +51,71 @@ 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 this.runCleanupAndReport(); // Schedule periodic cleanup this.cleanupTimer = setInterval(() => { - void this.runCleanup(); + void this.runCleanupAndReport(); }, intervalMs); } + /** + * Run one cleanup pass for `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. + * + * Resolves rather than rejects on every path, so `void` at the call sites + * cannot turn a cleanup failure into an unhandled rejection. + */ + private async runCleanupAndReport(): Promise { + let outcome: { deleted: number; errors: number }; + + try { + outcome = await this.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.', + ); + } + } + /** * Stop automatic cleanup. */ From f826cfaafa5ea936863aaa53fba9999f59c94fff Mon Sep 17 00:00:00 2001 From: Claude Date: Sun, 6 Sep 2026 04:26:21 +0000 Subject: [PATCH 2/2] refactor(metadata): lift the cleanup reporter out of the class so the published declaration does not move MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `private` members are emitted into the published `dist/*.d.ts` and join the class's nominal identity, so a private method would have made an observability repair change `@objectstack/metadata`'s declaration surface. As a module-level function — the idiom this file already uses for `executionPinnedTypes()` — it changes none of it. Behaviour, call sites and the pin are unchanged. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01ARYe3yQTQCUFm5qPYNgKaJ --- ...story-cleanup-failing-run-is-not-silent.md | 2 +- .../metadata/src/utils/history-cleanup.ts | 121 +++++++++--------- 2 files changed, 65 insertions(+), 58 deletions(-) diff --git a/.changeset/history-cleanup-failing-run-is-not-silent.md b/.changeset/history-cleanup-failing-run-is-not-silent.md index 62580014a3..15d38ecd95 100644 --- a/.changeset/history-cleanup-failing-run-is-not-silent.md +++ b/.changeset/history-cleanup-failing-run-is-not-silent.md @@ -6,4 +6,4 @@ fix(metadata): a `HistoryCleanupManager` run that loses deletes now says so, at 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 private 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. +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. diff --git a/packages/metadata/src/utils/history-cleanup.ts b/packages/metadata/src/utils/history-cleanup.ts index a53cdb2637..e0351a8bb9 100644 --- a/packages/metadata/src/utils/history-cleanup.ts +++ b/packages/metadata/src/utils/history-cleanup.ts @@ -53,69 +53,14 @@ export class HistoryCleanupManager { // Run cleanup immediately on start. Both call sites go through // `runCleanupAndReport()`, never `runCleanup()` — see its docblock. - void this.runCleanupAndReport(); + void runCleanupAndReport(this); // Schedule periodic cleanup this.cleanupTimer = setInterval(() => { - void this.runCleanupAndReport(); + void runCleanupAndReport(this); }, intervalMs); } - /** - * Run one cleanup pass for `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. - * - * Resolves rather than rejects on every path, so `void` at the call sites - * cannot turn a cleanup failure into an unhandled rejection. - */ - private async runCleanupAndReport(): Promise { - let outcome: { deleted: number; errors: number }; - - try { - outcome = await this.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.', - ); - } - } - /** * Stop automatic cleanup. */ @@ -371,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 { + 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.', + ); + } +}