From 8eee631dc343f7cb1bba82a1b8e9e53296ee8a29 Mon Sep 17 00:00:00 2001 From: Claude Date: Mon, 3 Aug 2026 08:40:09 +0000 Subject: [PATCH] =?UTF-8?q?fix(metadata):=20sys=5Fmetadata=20=E7=9A=84=20D?= =?UTF-8?q?DL=20=E5=A4=B1=E8=B4=A5=E5=BF=85=E9=A1=BB=E5=93=8D=E4=BA=AE,?= =?UTF-8?q?=E5=8F=AA=E9=9D=99=E9=BB=98=E3=80=8C=E8=A1=A8=E5=B7=B2=E5=AD=98?= =?UTF-8?q?=E5=9C=A8=E3=80=8D=E4=B8=80=E7=A7=8D=20(#4728)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `DatabaseLoader.ensureSchema()` 过去用一个空 `catch` 吞掉全部 DDL 失败,并且照样 把 `schemaReady` 置为 `true` —— 注释里的免责理由("e.g. table already exists") 只覆盖了最良性的一种原因,却为**所有**原因开脱。权限不足 / 数据源未连上 / 列类型 冲突之后,表或新列压根不存在,而进程状态与成功路径逐字节相同,日志里一行痕迹也 没有。这正是 #4420 的形态,#4632 已把它定成规则并落地了机械检查。 改为按错误类型判别: - 新增内部工具 `isSchemaAlreadyExistsError()`,按驱动错误码(Postgres SQLSTATE 42P07/42701/42710、MySQL ER_TABLE_EXISTS_ERROR/ER_DUP_FIELDNAME/ER_DUP_KEYNAME 及 errno、SQLite 只能靠消息)判别,并跟随 `cause` 链;凡是没有被正面识别为 「已存在」的,一律当作真实失败。 - 良性「已存在」:表确实已就绪,静默通过,并照常执行后续迁移与 ADR-0005 索引。 - 其余失败:`console.error` 上报后果(表/列未创建,后续元数据写入不持久,而服务器 仍报告健康)与修复动作(修掉驱动/数据源错误后重启),且只说一次。 - 真实失败后 `schemaReady` 不再置 `true`:启动依旧不被阻断(方法不抛),但 loader 不再声称它并不具备的就绪状态,下一次操作会重试,瞬时故障可自愈(恢复补一条 info)。 - `ensureHistorySchema()` 按同一规则对齐,两处不再一边过度静默、一边过度报错。 删除 `scripts/durability-degradation.baseline.json` 中指向本单的条目(shrink-only)。 Co-Authored-By: Claude Fable 5 Claude-Session: https://claude.ai/code/session_015Br2xsJsczFsTR9bvbh2Ny --- .../database-loader-ddl-failure-loud.md | 40 ++++ .../src/loaders/database-loader.test.ts | 210 +++++++++++++++++- .../metadata/src/loaders/database-loader.ts | 103 +++++++-- .../src/utils/schema-sync-errors.test.ts | 117 ++++++++++ .../metadata/src/utils/schema-sync-errors.ts | 102 +++++++++ scripts/durability-degradation.baseline.json | 10 +- 6 files changed, 555 insertions(+), 27 deletions(-) create mode 100644 .changeset/database-loader-ddl-failure-loud.md create mode 100644 packages/metadata/src/utils/schema-sync-errors.test.ts create mode 100644 packages/metadata/src/utils/schema-sync-errors.ts diff --git a/.changeset/database-loader-ddl-failure-loud.md b/.changeset/database-loader-ddl-failure-loud.md new file mode 100644 index 0000000000..0202e8e00d --- /dev/null +++ b/.changeset/database-loader-ddl-failure-loud.md @@ -0,0 +1,40 @@ +--- +"@objectstack/metadata": patch +--- + +fix(metadata): `sys_metadata` 的 DDL 失败不再被静默吞掉 —— 只有「表已存在」这一种原因可以静音 (#4728) + +`DatabaseLoader.ensureSchema()` 过去用一个空 `catch` 吞掉 **全部** DDL 失败,并且照样把 +`schemaReady` 置为 `true`: + +```ts +} catch { + // If syncSchema fails (e.g. table already exists), mark ready and continue + this.schemaReady = true; +} +``` + +注释里的免责理由只覆盖了失败原因中最良性的一种,却用它为**所有**原因开脱。真实的失败 +(权限不足、数据源根本没连上、列类型冲突)之后,表或新列压根不存在,而进程的状态与成功 +路径**逐字节相同**,启动日志里一行痕迹都没有 —— 这正是 #4420 的形态:声称已持久化、实 +际没落盘、系统看起来完全健康。#4632 把它定成规则(AGENTS.md → "Degradation log levels"), +机械检查 `pnpm check:durability-log-level` 已经能发现这一处。 + +现在按**错误类型**判别,而不是按注释里的乐观假设: + +- **良性的「已存在」**(SQLite 的 `table … already exists` / `duplicate column name`、 + Postgres 的 SQLSTATE `42P07`/`42701`/`42710`、MySQL 的 `ER_TABLE_EXISTS_ERROR` 等及其 + `errno`,并跟随 `cause` 链)—— 表确实已就绪,当作 no-op 静默通过,并照常执行后续的 + `project_id → environment_id` 迁移与 ADR-0005 索引。 +- **其余一切失败** —— 以 `console.error` 上报,文案同时说清**后果**(`sys_metadata` 的表/ + 列未创建,后续每一次元数据写入都会报错、或在宽松驱动上悄悄丢列,而服务器仍报告健康) + 与**修复动作**(修掉下面那条驱动/数据源错误后重启)。只说**一次**,不是每次写入都刷屏。 +- `schemaReady` **不再**在真实失败后置 `true`。启动依旧不被阻断(该方法不抛),但 loader + 不再声称一个它并不具备的就绪状态,下一次元数据操作会重试 —— 数据源只是还在连接这类瞬 + 时故障因此可以自愈,恢复时补一条 `info`。 + +`ensureHistorySchema()` 按同一规则对齐:良性「已存在」不再每次写入都打一条 `error`(过度 +使用 `error` 是镜像失败),真实失败则同样只响亮一次并保持重试。 + +无 API / schema 变更;新增内部工具 `isSchemaAlreadyExistsError()`(未从包入口导出)。 +`scripts/durability-degradation.baseline.json` 中指向本单的条目随之删除(该文件 shrink-only)。 diff --git a/packages/metadata/src/loaders/database-loader.test.ts b/packages/metadata/src/loaders/database-loader.test.ts index 0f30f8edcd..fde893870e 100644 --- a/packages/metadata/src/loaders/database-loader.test.ts +++ b/packages/metadata/src/loaders/database-loader.test.ts @@ -1,6 +1,6 @@ // Copyright (c) 2025 ObjectStack. Licensed under the Apache-2.0 license. -import { describe, it, expect, vi, beforeEach } from 'vitest'; +import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; import { DatabaseLoader, type DatabaseLoaderOptions } from './database-loader'; import type { IDataDriver } from '@objectstack/spec/contracts'; import { MetadataManager } from '../metadata-manager'; @@ -433,6 +433,214 @@ describe('DatabaseLoader', () => { }); }); +// ---------- DDL failure is loud, and only "already exists" is silent ---------- + +/** + * #4728 (rule: #4632, accident: #4420). + * + * `ensureSchema()` used to `catch {}` every DDL failure and set + * `schemaReady = true` regardless — a total durability failure was byte-for-byte + * indistinguishable from success, with no log line at all. The comment excused + * *all* failure reasons with the most benign one ("e.g. table already exists"). + * + * Both directions are pinned here on purpose: proving the real failure is loud + * is not enough, because "always log error" would pass that alone while making + * the benign case unreadable noise. The point is that the two are DISTINGUISHED. + */ +describe('DatabaseLoader schema-sync failure reporting (#4728)', () => { + let errorSpy: ReturnType; + let infoSpy: ReturnType; + + /** A real DDL failure: the table does NOT exist afterwards. */ + const permissionDenied = () => + Object.assign(new Error('permission denied for schema public'), { code: '42501' }); + + /** The one benign reason: the table IS already provisioned. */ + const alreadyExists = () => + Object.assign(new Error('table sys_metadata already exists'), { code: 'SQLITE_ERROR' }); + + beforeEach(() => { + errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + infoSpy = vi.spyOn(console, 'info').mockImplementation(() => {}); + }); + + afterEach(() => { + errorSpy.mockRestore(); + infoSpy.mockRestore(); + }); + + describe('a REAL DDL failure', () => { + it('reports at error, naming the consequence and the fix', async () => { + const driver = createMockDriver(); + driver.syncSchema = vi.fn().mockRejectedValue(permissionDenied()); + const loader = new DatabaseLoader({ driver }); + + await loader.list('object'); + + expect(errorSpy).toHaveBeenCalledTimes(1); + const [message, cause] = errorSpy.mock.calls[0] as [string, unknown]; + // consequence + expect(message).toContain('sys_metadata'); + expect(message).toContain('FAILED'); + expect(message).toContain('NOT created'); + // the system keeps looking healthy — that is the whole point of the level + expect(message).toMatch(/reporting healthy/i); + // fix + expect(message).toMatch(/fix it and restart/i); + // and the underlying driver error is carried, not discarded + expect((cause as Error).message).toBe('permission denied for schema public'); + }); + + it('does NOT mark the schema ready — the next operation retries the DDL', async () => { + const driver = createMockDriver(); + driver.syncSchema = vi.fn().mockRejectedValue(permissionDenied()); + const loader = new DatabaseLoader({ driver }); + + await loader.list('object'); + await loader.list('view'); + await loader.exists('object', 'account'); + + // Before #4728 this was 1: the failure set `schemaReady = true` and every + // later write proceeded against a table that was never created. + expect(driver.syncSchema).toHaveBeenCalledTimes(3); + }); + + it('says it once, not once per operation', async () => { + const driver = createMockDriver(); + driver.syncSchema = vi.fn().mockRejectedValue(permissionDenied()); + const loader = new DatabaseLoader({ driver }); + + await loader.list('object'); + await loader.list('view'); + await loader.list('flow'); + + expect(errorSpy).toHaveBeenCalledTimes(1); + }); + + it('recovers silently-loudly: a transient failure that heals reports the recovery', async () => { + const driver = createMockDriver(); + driver.syncSchema = vi + .fn() + .mockRejectedValueOnce( + Object.assign(new Error('connect ECONNREFUSED 127.0.0.1:5432'), { + code: 'ECONNREFUSED', + }), + ) + .mockResolvedValue(undefined); + const loader = new DatabaseLoader({ driver }); + + await loader.list('object'); // datasource still connecting → loud + await loader.list('view'); // retried → succeeds + + expect(errorSpy).toHaveBeenCalledTimes(1); + expect(infoSpy).toHaveBeenCalledTimes(1); + expect((infoSpy.mock.calls[0] as [string])[0]).toMatch(/succeeded on retry/i); + + // Ready now, so a third operation does not re-run the DDL. + await loader.list('flow'); + expect(driver.syncSchema).toHaveBeenCalledTimes(2); + }); + }); + + describe('the benign "already exists" failure', () => { + it('is silent — no error, no info', async () => { + const driver = createMockDriver(); + driver.syncSchema = vi.fn().mockRejectedValue(alreadyExists()); + const loader = new DatabaseLoader({ driver }); + + await loader.list('object'); + + expect(errorSpy).not.toHaveBeenCalled(); + expect(infoSpy).not.toHaveBeenCalled(); + }); + + it('marks the schema ready — the table is provisioned, so no retry', async () => { + const driver = createMockDriver(); + driver.syncSchema = vi.fn().mockRejectedValue(alreadyExists()); + const loader = new DatabaseLoader({ driver }); + + await loader.list('object'); + await loader.list('view'); + + expect(driver.syncSchema).toHaveBeenCalledTimes(1); + }); + + it('still runs the post-sync migrations (the table exists, so they apply)', async () => { + const driver = createMockDriver(); + driver.syncSchema = vi.fn().mockRejectedValue(alreadyExists()); + const raw = vi.fn().mockResolvedValue(undefined); + (driver as unknown as { raw: unknown }).raw = raw; + const loader = new DatabaseLoader({ driver }); + + await loader.list('object'); + + expect(raw).toHaveBeenCalled(); + expect(raw.mock.calls.some(([sql]) => String(sql).includes('idx_sys_metadata_overlay_active'))).toBe( + true, + ); + }); + }); + + it('DISTINGUISHES the two: same call site, opposite verdicts', async () => { + const benignDriver = createMockDriver(); + benignDriver.syncSchema = vi.fn().mockRejectedValue(alreadyExists()); + const realDriver = createMockDriver(); + realDriver.syncSchema = vi.fn().mockRejectedValue(permissionDenied()); + + await new DatabaseLoader({ driver: benignDriver }).list('object'); + const afterBenign = errorSpy.mock.calls.length; + + await new DatabaseLoader({ driver: realDriver }).list('object'); + const afterReal = errorSpy.mock.calls.length; + + expect(afterBenign).toBe(0); + expect(afterReal).toBe(1); + }); + + describe('the history table follows the same rule', () => { + /** sys_metadata syncs fine; only the history table's DDL fails. */ + function driverWithFailingHistoryDdl(error: unknown): IDataDriver { + const driver = createMockDriver(); + driver.syncSchema = vi.fn().mockImplementation((table: string) => { + if (table === 'sys_metadata_history') return Promise.reject(error); + return Promise.resolve(undefined); + }); + return driver; + } + + it('reports a real failure at error, naming the lost audit trail and the fix', async () => { + const driver = driverWithFailingHistoryDdl(permissionDenied()); + const loader = new DatabaseLoader({ driver }); + + await loader.save('object', 'account', { name: 'account' }); + + expect(errorSpy).toHaveBeenCalledTimes(1); + const message = (errorSpy.mock.calls[0] as [string])[0]; + expect(message).toContain('sys_metadata_history'); + expect(message).toMatch(/will NOT be persisted/); + expect(message).toMatch(/restart/i); + }); + + it('is silent on "already exists" and stops retrying', async () => { + const driver = driverWithFailingHistoryDdl( + Object.assign(new Error("Table 'sys_metadata_history' already exists"), { + code: 'ER_TABLE_EXISTS_ERROR', + }), + ); + const loader = new DatabaseLoader({ driver }); + + await loader.save('object', 'account', { name: 'account' }); + await loader.save('object', 'contact', { name: 'contact' }); + + expect(errorSpy).not.toHaveBeenCalled(); + const historySyncs = (driver.syncSchema as ReturnType).mock.calls.filter( + ([table]) => table === 'sys_metadata_history', + ); + expect(historySyncs).toHaveLength(1); + }); + }); +}); + // ---------- DatabaseLoader read-through cache ---------- describe('DatabaseLoader read-through cache', () => { diff --git a/packages/metadata/src/loaders/database-loader.ts b/packages/metadata/src/loaders/database-loader.ts index 91b7c7c894..0b98fdd835 100644 --- a/packages/metadata/src/loaders/database-loader.ts +++ b/packages/metadata/src/loaders/database-loader.ts @@ -26,6 +26,7 @@ import type { IDataDriver, IDataEngine } from '@objectstack/spec/contracts'; import type { MetadataLoader } from './loader-interface.js'; import { calculateChecksum } from '../utils/metadata-history-utils.js'; import { LRUCache } from '../utils/lru-cache.js'; +import { isSchemaAlreadyExistsError } from '../utils/schema-sync-errors.js'; import { addSysMetadataOverlayIndex } from '../migrations/add-sys-metadata-overlay-index.js'; import { migrateProjectIdToEnvironmentId } from '../migrations/migrate-project-id-to-environment-id.js'; @@ -123,6 +124,13 @@ export class DatabaseLoader implements MetadataLoader { private trackHistory: boolean; private schemaReady = false; private historySchemaReady = false; + /** + * Whether the loud "DDL failed" report has already been printed for the + * metadata table / history table respectively. AGENTS.md → "Degradation log + * levels": say it **once**, at the first degradation, not once per retry. + */ + private schemaFailureReported = false; + private historySchemaFailureReported = false; /** (type, name) → metadata payload — primes `load()` */ private readonly loadCache?: LRUCache | null>; @@ -321,22 +329,59 @@ export class DatabaseLoader implements MetadataLoader { ...SysMetadataObject, name: this.tableName, }); - this.schemaReady = true; - // v5.0 forward migration: project_id → environment_id (idempotent). - try { - await migrateProjectIdToEnvironmentId(this.driver!); - } catch { - // ignore — migration is best-effort on bootstrap - } - // Apply ADR-0005 partial UNIQUE INDEX (best-effort, idempotent) - try { - await addSysMetadataOverlayIndex(this.driver!); - } catch { - // ignore — index is optimization + } catch (error) { + // #4728 (rule: #4632, accident: #4420) — discriminate by error TYPE. + // Exactly ONE failure reason is benign here: the table/columns are + // already provisioned and a non-fully-idempotent driver reports that as + // an error. Every other reason (insufficient privileges, datasource never + // connected, incompatible column type) means the table or column does NOT + // exist — and the previous code marked `schemaReady = true` for all of + // them, making a total durability failure indistinguishable from success + // with not one line in the log. + if (!isSchemaAlreadyExistsError(error)) { + if (!this.schemaFailureReported) { + this.schemaFailureReported = true; + console.error( + `[Metadata] DDL for the metadata table \`${this.tableName}\` FAILED — its table/columns were NOT created or altered. ` + + `Every metadata write from here on (Studio saves, app installs, org overlays) targets storage that may not exist: ` + + `writes will error out, or silently drop columns on a lenient driver, while the server keeps reporting healthy. ` + + `This is NOT the benign "already exists" case — check the datasource/driver error below (insufficient privileges, ` + + `datasource not connected, incompatible column type), fix it and restart. Schema sync is retried on the next ` + + `metadata operation, so a transient cause recovers on its own.`, + error, + ); + } + // Deliberate, and the opposite of what this code did before: on a REAL + // DDL failure `schemaReady` stays FALSE. Startup is still not blocked + // (this method does not throw — callers proceed and fail loudly at the + // driver if the table is truly missing), but the loader never claims a + // readiness it does not have, and the next operation retries the sync + // so a datasource that was merely still connecting heals itself. Same + // shape as `ensureHistorySchema()` below. + return; } + // Benign — and ONLY benign: the table is already provisioned, so the DDL + // was a no-op rather than a failure. Fall through to the ready path. + } + + if (this.schemaFailureReported) { + this.schemaFailureReported = false; + console.info( + `[Metadata] DDL for the metadata table \`${this.tableName}\` succeeded on retry — metadata writes are durable again.`, + ); + } + this.schemaReady = true; + // v5.0 forward migration: project_id → environment_id (idempotent). + try { + await migrateProjectIdToEnvironmentId(this.driver!); } catch { - // If syncSchema fails (e.g. table already exists), mark ready and continue - this.schemaReady = true; + // ignore — migration is best-effort on bootstrap + } + // Apply ADR-0005 partial UNIQUE INDEX (best-effort, idempotent) + try { + await addSysMetadataOverlayIndex(this.driver!); + } catch { + // ignore — index is optimization } } @@ -358,11 +403,35 @@ export class DatabaseLoader implements MetadataLoader { ...SysMetadataHistoryObject, name: this.historyTableName, }); + if (this.historySchemaFailureReported) { + this.historySchemaFailureReported = false; + console.info( + `[Metadata] DDL for the metadata history table \`${this.historyTableName}\` succeeded on retry — change history is being recorded again.`, + ); + } this.historySchemaReady = true; } catch (error) { - // Log the error; historySchemaReady remains false so the next operation retries. - // If the error is a benign "already exists" the next attempt will also succeed. - console.error('Failed to ensure history schema, will retry on next operation:', error); + // Same discrimination as `ensureSchema()` above (#4728). A benign + // "already exists" means the history table IS provisioned — treat it as + // the no-op it is instead of re-reporting it (and re-running the DDL) on + // every single write, which is the mirror-image failure: an `error` line + // for a non-degradation trains everyone to skim `error`. + if (isSchemaAlreadyExistsError(error)) { + this.historySchemaReady = true; + return; + } + // Real failure: loud once, `historySchemaReady` stays false so the next + // operation retries. + if (!this.historySchemaFailureReported) { + this.historySchemaFailureReported = true; + console.error( + `[Metadata] DDL for the metadata history table \`${this.historyTableName}\` FAILED — its table/columns were NOT created. ` + + `Metadata change history (versions, diffs, rollback) will NOT be persisted while every metadata write keeps succeeding, ` + + `so the audit trail silently ends here. Fix the datasource/driver error below and restart; the sync is retried on the ` + + `next metadata operation.`, + error, + ); + } } } diff --git a/packages/metadata/src/utils/schema-sync-errors.test.ts b/packages/metadata/src/utils/schema-sync-errors.test.ts new file mode 100644 index 0000000000..04ea9fbde1 --- /dev/null +++ b/packages/metadata/src/utils/schema-sync-errors.test.ts @@ -0,0 +1,117 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * #4728 — the classification that decides whether a DDL failure may be silenced. + * + * Both directions are pinned deliberately. A test suite that only proves the + * benign case is recognised would pass just as happily on `() => true`, which is + * exactly the bug being fixed (one benign reason excusing every reason). + */ + +import { describe, it, expect } from 'vitest'; +import { isSchemaAlreadyExistsError } from './schema-sync-errors.js'; + +describe('isSchemaAlreadyExistsError', () => { + describe('benign — the table/column is already provisioned', () => { + it('recognises the SQLite message (code is the undifferentiated SQLITE_ERROR)', () => { + const err = Object.assign(new Error('table sys_metadata already exists'), { + code: 'SQLITE_ERROR', + }); + expect(isSchemaAlreadyExistsError(err)).toBe(true); + }); + + it('recognises the SQLite duplicate-column message', () => { + const err = Object.assign(new Error('duplicate column name: environment_id'), { + code: 'SQLITE_ERROR', + }); + expect(isSchemaAlreadyExistsError(err)).toBe(true); + }); + + it('recognises PostgreSQL duplicate_table by SQLSTATE', () => { + const err = Object.assign(new Error('relation "sys_metadata" already exists'), { + code: '42P07', + }); + expect(isSchemaAlreadyExistsError(err)).toBe(true); + }); + + it('recognises PostgreSQL duplicate_column by SQLSTATE even with an opaque message', () => { + const err = Object.assign(new Error('db error'), { code: '42701' }); + expect(isSchemaAlreadyExistsError(err)).toBe(true); + }); + + it('recognises MySQL ER_TABLE_EXISTS_ERROR by code and by errno', () => { + expect( + isSchemaAlreadyExistsError( + Object.assign(new Error("Table 'sys_metadata' already exists"), { + code: 'ER_TABLE_EXISTS_ERROR', + }), + ), + ).toBe(true); + expect( + isSchemaAlreadyExistsError(Object.assign(new Error('opaque'), { errno: 1050 })), + ).toBe(true); + }); + + it('follows an error wrapped as `cause`', () => { + const inner = Object.assign(new Error('relation "sys_metadata" already exists'), { + code: '42P07', + }); + const outer = Object.assign(new Error('syncSchema failed'), { cause: inner }); + expect(isSchemaAlreadyExistsError(outer)).toBe(true); + }); + + it('accepts a bare thrown string', () => { + expect(isSchemaAlreadyExistsError('table sys_metadata already exists')).toBe(true); + }); + }); + + describe('NOT benign — the table/column does not exist', () => { + it('rejects insufficient privileges', () => { + const err = Object.assign(new Error('permission denied for schema public'), { + code: '42501', + }); + expect(isSchemaAlreadyExistsError(err)).toBe(false); + }); + + it('rejects a datasource that never connected', () => { + const err = Object.assign(new Error('connect ECONNREFUSED 127.0.0.1:5432'), { + code: 'ECONNREFUSED', + errno: -111, + }); + expect(isSchemaAlreadyExistsError(err)).toBe(false); + }); + + it('rejects an incompatible column type', () => { + const err = Object.assign( + new Error('column "metadata" cannot be cast automatically to type jsonb'), + { code: '42804' }, + ); + expect(isSchemaAlreadyExistsError(err)).toBe(false); + }); + + it('rejects a read-only / disk-full driver failure', () => { + const err = Object.assign(new Error('attempt to write a readonly database'), { + code: 'SQLITE_READONLY', + }); + expect(isSchemaAlreadyExistsError(err)).toBe(false); + }); + + it('rejects values that carry no signal at all', () => { + expect(isSchemaAlreadyExistsError(undefined)).toBe(false); + expect(isSchemaAlreadyExistsError(null)).toBe(false); + expect(isSchemaAlreadyExistsError(new Error(''))).toBe(false); + expect(isSchemaAlreadyExistsError({})).toBe(false); + expect(isSchemaAlreadyExistsError(42)).toBe(false); + }); + + it('does not follow a cause chain forever', () => { + // Deeply nested benign cause beyond the cap is treated as NOT benign — + // erring toward loud, never toward silent. + let err: Error = new Error('table x already exists'); + for (let i = 0; i < 8; i++) { + err = Object.assign(new Error(`wrap ${i}`), { cause: err }); + } + expect(isSchemaAlreadyExistsError(err)).toBe(false); + }); + }); +}); diff --git a/packages/metadata/src/utils/schema-sync-errors.ts b/packages/metadata/src/utils/schema-sync-errors.ts new file mode 100644 index 0000000000..1df1c22305 --- /dev/null +++ b/packages/metadata/src/utils/schema-sync-errors.ts @@ -0,0 +1,102 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * DDL failure classification for metadata schema sync (#4728, rule from #4632). + * + * `IDataDriver.syncSchema()` is contractually **idempotent** ("creates tables if + * missing, adds columns, updates indexes"), so in principle a re-sync of an + * existing table should not throw at all. In practice a driver may surface the + * already-provisioned case as an error instead of a no-op — `CREATE TABLE` + * without `IF NOT EXISTS`, an `ALTER TABLE ADD COLUMN` for a column that is + * already there. That single failure reason is benign: the table and its columns + * exist, so the bytes will land. + * + * **Every other** DDL failure is not benign, and the difference is the whole + * point of this module. Insufficient privileges, a datasource that never + * connected, an incompatible column type — after those, the table or column does + * not exist, yet the process keeps looking healthy while everything it claims to + * persist has nowhere to land. That is the #4420 shape, and AGENTS.md → + * "Degradation log levels" requires it to be reported at `error`. + * + * The defect this replaces was a `catch` whose comment named the benign reason + * ("e.g. table already exists") and used it to excuse **all** of them. Callers + * must therefore ask the question by error *type*: + * + * ```ts + * catch (error) { + * if (!isSchemaAlreadyExistsError(error)) { + * console.error('… consequence … fix …', error); // loud, and stay not-ready + * return; + * } + * // benign only: the table is already provisioned, carry on + * } + * ``` + * + * Classification is deliberately conservative — anything not positively + * recognised as "already exists" is treated as a real failure, because the cost + * of a false "benign" (silent data loss) is far higher than the cost of a false + * "real" (one extra error line). + */ + +/** + * Driver/SQLSTATE codes that mean "the thing you asked me to create is already + * there". Postgres reports SQLSTATE on `code`; mysql2 reports its symbolic name. + */ +const ALREADY_EXISTS_CODES: ReadonlySet = new Set([ + // PostgreSQL SQLSTATE (class 42 — syntax error or access rule violation) + '42P07', // duplicate_table + '42701', // duplicate_column + '42710', // duplicate_object — index / constraint already exists + // MySQL / MariaDB (mysql2 puts the symbolic name on `code`) + 'ER_TABLE_EXISTS_ERROR', // 1050 + 'ER_DUP_FIELDNAME', // 1060 + 'ER_DUP_KEYNAME', // 1061 +]); + +/** MySQL/MariaDB numeric equivalents of the codes above (`errno`). */ +const ALREADY_EXISTS_ERRNOS: ReadonlySet = new Set([1050, 1060, 1061]); + +/** + * Message fallback for drivers that carry no machine-readable code — notably + * SQLite, whose `code` is the undifferentiated `SQLITE_ERROR` for every DDL + * failure, so the message is the only signal available: + * - `table sys_metadata already exists` + * - `duplicate column name: environment_id` + * - `index idx_x already exists` + * Postgres phrases its own as `relation "x" already exists` / + * `column "x" of relation "y" already exists`, which matches the same test. + */ +const ALREADY_EXISTS_MESSAGE = /already exists|duplicate column name|duplicate key name/i; + +/** How far to follow an `error.cause` chain — drivers wrap, but not deeply. */ +const MAX_CAUSE_DEPTH = 4; + +/** + * Is this DDL error the benign "already provisioned" case? + * + * @param error - The value thrown by `syncSchema()` (or any DDL call). + * @returns `true` only when the error positively identifies as + * table/column/index-already-exists. Anything else — including an + * unrecognised error, `undefined`, or a permission/connection failure — + * returns `false` and MUST be reported loudly by the caller. + */ +export function isSchemaAlreadyExistsError(error: unknown, depth = 0): boolean { + if (error === null || error === undefined || depth > MAX_CAUSE_DEPTH) return false; + + if (typeof error === 'string') return ALREADY_EXISTS_MESSAGE.test(error); + if (typeof error !== 'object') return false; + + const err = error as { + code?: unknown; + errno?: unknown; + message?: unknown; + cause?: unknown; + }; + + if (typeof err.code === 'string' && ALREADY_EXISTS_CODES.has(err.code)) return true; + if (typeof err.errno === 'number' && ALREADY_EXISTS_ERRNOS.has(err.errno)) return true; + if (typeof err.message === 'string' && ALREADY_EXISTS_MESSAGE.test(err.message)) return true; + + // Drivers commonly re-throw with the original attached as `cause`. + return isSchemaAlreadyExistsError(err.cause, depth + 1); +} diff --git a/scripts/durability-degradation.baseline.json b/scripts/durability-degradation.baseline.json index 939a64336a..d5095d3ecc 100644 --- a/scripts/durability-degradation.baseline.json +++ b/scripts/durability-degradation.baseline.json @@ -7,13 +7,5 @@ "'just run the update command', which is precisely how a gate stops meaning anything.", "Every entry names WHY it is still here and WHAT closes it." ], - "entries": [ - { - "file": "packages/metadata/src/loaders/database-loader.ts", - "callee": "syncSchema", - "reason": "ensureSchema() catches a failed sys_metadata DDL, sets `schemaReady = true` and continues — every subsequent metadata write targets a table that may not exist. Real durability finding, NOT an accepted design. Left baselined only because packages/metadata/** was frozen for this round (#4556 was rewriting its write path concurrently); fixing it here would have collided.", - "tracked_by": "#4728", - "closes_when": "#4728 raises the swallow to `error` (or rethrows) and deletes this entry." - } - ] + "entries": [] }