fix(metadata): 历史序号 event_seq 不再从一次失败的读里凭空发号 —— 只有「表还没建」可以从 1 开始 (#4825)

.changeset/next-event-seq-read-failure-loud.md

@@ -0,0 +1,43 @@
+---
+"@objectstack/metadata": patch
+---
+
+fix(metadata): 历史序号 `event_seq` 不再从一次失败的读里凭空发号 —— 只有「表还没建」可以从 1 开始 (#4825)
+
+`DatabaseLoader.nextEventSeq()` 过去把读 `sys_metadata_history` 的**全部**失败折成同一个答案:
+
+```ts
+} catch {
+  // Table not provisioned yet or driver error — start at 1.
+  return 1;
+}
+```
+
+注释同时点名了两种原因,然后用同一个 `return 1` 对待。这是 #4728 刚修掉的同一种形状,但危害是
+**更贵的那一半**:#4728 是「字节没落盘」,本条是「**落盘的字节是错的**」。历史表里已经有 N 行时,
+一次瞬时读失败(连接抖动、超时、权限)会让下一条历史拿到 `event_seq = 1`,与既有行**直接撞号**,
+而 insert **成功**、日志**一行没有**。`event_seq` 正是历史列表排序与 rollback 定位的依据,撞号之后
+版本顺序就永久不可信 —— 重试不修、重启也不修。
+
+现在按**错误类型**判别,复用 #4728 落地的那套判别机制(`packages/metadata/src/utils/schema-sync-errors.ts`
+里新增的 `isMissingTableError()` 与既有 `isSchemaAlreadyExistsError()` 共用同一个 code / errno /
+message + `cause` 链匹配器,而不是在同一个包里另起一套错误判别):
+
+- **良性的「表还没建」**(SQLite `no such table: …`、Postgres SQLSTATE `42P01` /
+  `relation "…" does not exist`、MySQL `ER_NO_SUCH_TABLE` / errno `1146`,并跟随 `cause` 链)——
+  没有行,就没有可撞的号,`1` 确实是下一个号,静默返回。
+- **其余一切读失败** —— `nextEventSeq()` 原样抛出。调用方 `createHistoryRecord()` 以
+  `console.error` 上报**后果**(该条历史记录未写入;元数据写入本身已成功,所以服务器仍报告健康,
+  而变更历史正在悄悄出现空洞,版本时间线与 rollback 目标将不完整)、**为什么是空洞而不是错号**
+  (从 1 发号会与既有行撞号,把「不完整」变成「顺序错误」,后者无人能发现)与**修复动作**,
+  然后**跳过这条历史记录**。
+- 判别的方向刻意保守:凡是没有被正面识别为「表不存在」的,一律当作真实失败。`does not exist`
+  本身不够 —— `role "…" does not exist`、`database "…" does not exist`、`column "…" does not exist`
+  都是真实失败,对着一张可能满是行的表返回 1 正是要避免的事,所以消息匹配要求 table/relation 与
+  该短语同现。
+
+两条边界保持不变:元数据写入本身**不**因此失败(记录已经落盘,把它报成失败是比原缺陷更糟的谎),
+以及本路径已知的并发撞号限制(非事务,canonical producer 仍是 `SysMetadataRepository`)——那是被
+记录过的限制,与「读失败静默重置到 1」是两回事。报告只说**一次**,恢复时补一条 `info`。
+
+无 API / schema 变更;新增内部工具 `isMissingTableError()`(未从包入口导出)。

packages/metadata/src/loaders/database-loader.test.ts

@@ -641,6 +641,201 @@ describe('DatabaseLoader schema-sync failure reporting (#4728)', () => {
   });
 });
 
+// ---------- event_seq is never invented from a read that failed ----------
+
+/**
+ * #4825 (same family as #4728, rule: #4632).
+ *
+ * `nextEventSeq()` used to `catch { return 1 }`, with a comment naming BOTH
+ * "table not provisioned yet" (benign) and "driver error" (not benign). With N
+ * rows already in `sys_metadata_history`, one flaky read therefore handed the
+ * next row `event_seq = 1` — colliding with an existing row while the insert
+ * SUCCEEDED and nothing was logged.
+ *
+ * That is why these tests assert on the VALUE that lands, not merely on whether
+ * a write happened: the damage here is not a missing row, it is a written row
+ * carrying a wrong number, which no retry and no restart repairs.
+ *
+ * Both directions are pinned, plus a same-call-site/opposite-verdict case — a
+ * suite proving only the loud half would pass on a `() => true` classifier,
+ * which is the bug, and one proving only the benign half would pass on the
+ * `catch { return 1 }` being replaced.
+ */
+describe('DatabaseLoader event_seq on a failed history read (#4825)', () => {
+  let errorSpy: ReturnType<typeof vi.spyOn>;
+  let infoSpy: ReturnType<typeof vi.spyOn>;
+
+  /** Benign: nothing has been provisioned, so there is no row to collide with. */
+  const noSuchTable = () =>
+    Object.assign(new Error('no such table: sys_metadata_history'), { code: 'SQLITE_ERROR' });
+
+  /** NOT benign: the rows are still there, this read just did not see them. */
+  const connectionReset = () =>
+    Object.assign(new Error('read ECONNRESET'), { code: 'ECONNRESET' });
+
+  /** Every `event_seq` this driver was asked to persist, in order. */
+  function historySeqsWritten(driver: IDataDriver): unknown[] {
+    const calls = (driver.create as ReturnType<typeof vi.fn>).mock.calls as unknown[][];
+    return calls
+      .filter((call: unknown[]) => call[0] === 'sys_metadata_history')
+      .map((call: unknown[]) => (call[1] as Record<string, unknown>).event_seq);
+  }
+
+  /** The mock driver's own `find`, still callable after we wrap it. */
+  type DriverFind = (table: string, query: unknown) => Promise<Record<string, unknown>[]>;
+
+  /**
+   * A driver whose reads of the HISTORY table fail while `broken` — writes and
+   * the `sys_metadata` table keep working throughout, which is exactly what
+   * makes the defect invisible in production.
+   */
+  function driverWithBreakableHistoryReads(makeError: () => unknown, startBroken = false) {
+    const driver = createMockDriver();
+    const realFind = driver.find as DriverFind;
+    let broken = startBroken;
+    driver.find = vi.fn().mockImplementation((table: string, query: unknown) => {
+      if (broken && table === 'sys_metadata_history') return Promise.reject(makeError());
+      return realFind(table, query);
+    });
+    return {
+      driver,
+      breakReads: () => {
+        broken = true;
+      },
+      healReads: () => {
+        broken = false;
+      },
+    };
+  }
+
+  beforeEach(() => {
+    errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {});
+    infoSpy = vi.spyOn(console, 'info').mockImplementation(() => {});
+  });
+
+  afterEach(() => {
+    errorSpy.mockRestore();
+    infoSpy.mockRestore();
+  });
+
+  describe('the benign case — the history table is not provisioned yet', () => {
+    it('numbers from 1 and stays silent', async () => {
+      const { driver } = driverWithBreakableHistoryReads(noSuchTable, true);
+      const loader = new DatabaseLoader({ driver });
+
+      await loader.save('object', 'account', { name: 'account' });
+
+      expect(historySeqsWritten(driver)).toEqual([1]);
+      expect(errorSpy).not.toHaveBeenCalled();
+      expect(infoSpy).not.toHaveBeenCalled();
+    });
+  });
+
+  describe('a REAL read failure against a table that already has rows', () => {
+    it('does NOT restart at 1 — no colliding row is written at all', async () => {
+      const { driver, breakReads } = driverWithBreakableHistoryReads(connectionReset);
+      const loader = new DatabaseLoader({ driver });
+
+      // Build real history first: two rows, event_seq 1 and 2.
+      await loader.save('object', 'account', { name: 'account' });
+      await loader.save('object', 'contact', { name: 'contact' });
+      expect(historySeqsWritten(driver)).toEqual([1, 2]);
+
+      breakReads();
+      await loader.save('object', 'lead', { name: 'lead' });
+
+      // Before #4825 this was [1, 2, 1] — a duplicate `event_seq` written
+      // successfully, silently, over the top of an existing row's number.
+      expect(historySeqsWritten(driver)).toEqual([1, 2]);
+    });
+
+    it('reports at error, naming the consequence, the deliberate skip, and the fix', async () => {
+      const { driver, breakReads } = driverWithBreakableHistoryReads(connectionReset);
+      const loader = new DatabaseLoader({ driver });
+
+      await loader.save('object', 'account', { name: 'account' });
+      breakReads();
+      await loader.save('object', 'lead', { name: 'lead' });
+
+      expect(errorSpy).toHaveBeenCalledTimes(1);
+      const [message, cause] = errorSpy.mock.calls[0] as [string, unknown];
+      expect(message).toContain('sys_metadata_history');
+      expect(message).toContain('event_seq');
+      // consequence: the row is gone AND the system keeps looking fine
+      expect(message).toMatch(/NOT written/);
+      expect(message).toMatch(/SUCCEEDED/);
+      expect(message).toMatch(/looking healthy/i);
+      // why a hole is preferable to a wrong number
+      expect(message).toMatch(/collide/i);
+      // fix
+      expect(message).toMatch(/fix the datasource\/driver error/i);
+      // and the driver error is carried, not discarded
+      expect((cause as Error).message).toBe('read ECONNRESET');
+    });
+
+    it('does not fail the metadata write it accompanies', async () => {
+      const { driver, breakReads } = driverWithBreakableHistoryReads(connectionReset);
+      const loader = new DatabaseLoader({ driver });
+
+      breakReads();
+      const result = await loader.save('object', 'account', { name: 'account' });
+
+      // The record write already happened; reporting it as failed would be a
+      // worse lie than the one being fixed. The history hole is what is loud.
+      expect(result.success).toBe(true);
+      expect((await loader.load('object', 'account')).data).toEqual({ name: 'account' });
+    });
+
+    it('says it once, not once per skipped entry, and reports recovery', async () => {
+      const { driver, breakReads, healReads } = driverWithBreakableHistoryReads(connectionReset);
+      const loader = new DatabaseLoader({ driver });
+
+      await loader.save('object', 'account', { name: 'account' });
+      breakReads();
+      await loader.save('object', 'contact', { name: 'contact' });
+      await loader.save('object', 'lead', { name: 'lead' });
+      expect(errorSpy).toHaveBeenCalledTimes(1);
+
+      healReads();
+      await loader.save('object', 'deal', { name: 'deal' });
+
+      expect(errorSpy).toHaveBeenCalledTimes(1);
+      expect(infoSpy).toHaveBeenCalledTimes(1);
+      expect((infoSpy.mock.calls[0] as [string])[0]).toMatch(/readable again/i);
+      // Numbering resumes after the surviving max (1), never from 1 again.
+      expect(historySeqsWritten(driver)).toEqual([1, 2]);
+    });
+  });
+
+  it('DISTINGUISHES the two: same call site, opposite verdicts', async () => {
+    const { driver: benignDriver } = driverWithBreakableHistoryReads(noSuchTable, true);
+    const { driver: realDriver } = driverWithBreakableHistoryReads(connectionReset, true);
+
+    await new DatabaseLoader({ driver: benignDriver }).save('object', 'account', { name: 'a' });
+    await new DatabaseLoader({ driver: realDriver }).save('object', 'account', { name: 'a' });
+
+    // Benign: numbered, written, silent. Real: not numbered, not written, loud.
+    expect(historySeqsWritten(benignDriver)).toEqual([1]);
+    expect(historySeqsWritten(realDriver)).toEqual([]);
+    expect(errorSpy).toHaveBeenCalledTimes(1);
+  });
+
+  it('applies to the rollback history path too, not just save()', async () => {
+    const { driver, breakReads } = driverWithBreakableHistoryReads(connectionReset);
+    const loader = new DatabaseLoader({ driver });
+
+    await loader.save('object', 'account', { name: 'account' });
+    await loader.save('object', 'account', { name: 'account', label: 'Account' });
+    expect(historySeqsWritten(driver)).toEqual([1, 2]);
+
+    breakReads();
+    await loader.registerRollback('object', 'account', { name: 'account' }, 1);
+
+    expect(historySeqsWritten(driver)).toEqual([1, 2]);
+    expect(errorSpy).toHaveBeenCalledTimes(1);
+  });
+});
+
 // ---------- DatabaseLoader read-through cache ----------
 
 describe('DatabaseLoader read-through cache', () => {

packages/metadata/src/loaders/database-loader.ts

@@ -26,7 +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 { isMissingTableError, 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';
 
@@ -131,6 +131,12 @@ export class DatabaseLoader implements MetadataLoader {
    */
   private schemaFailureReported = false;
   private historySchemaFailureReported = false;
+  /**
+   * Same once-only discipline for the #4825 seam: the history table is readable
+   * or it is not, and repeating the report per skipped write turns a real
+   * degradation into noise people learn to skim.
+   */
+  private historySeqFailureReported = false;
 
   /** (type, name) → metadata payload — primes `load()` */
   private readonly loadCache?: LRUCache<string, Record<string, unknown> | null>;
@@ -267,6 +273,24 @@ export class DatabaseLoader implements MetadataLoader {
    * Reads `MAX(event_seq) + 1` for the configured `organization_id`.
    * Legacy path — not transactional, so concurrent writes can collide.
    * The canonical (transactional) producer is `SysMetadataRepository`.
+   *
+   * #4825 (same shape as #4728, rule from #4632) — discriminate by error TYPE.
+   * This used to `catch { return 1 }`, with a comment that named BOTH reasons a
+   * read can fail and then answered both the same way. Exactly one of them is
+   * benign: the history table has not been provisioned, so there is no row to
+   * be inconsistent with and 1 genuinely IS the next number. Every other reason
+   * — connection drop, timeout, insufficient privileges — means the rows are
+   * still there and simply were not seen, and answering 1 against a table with
+   * N rows **collides with existing rows**: the insert succeeds, the log stays
+   * empty, and `event_seq` (the ordering key that history listing and rollback
+   * targeting both stand on) is silently wrong from then on. Note this is the
+   * costlier half of the #4728 family — not bytes that never landed, but bytes
+   * that landed *wrong*, which no retry and no restart repairs.
+   *
+   * @throws The underlying driver error, unchanged, for every non-benign read
+   *         failure. Deliberate: a sequence number this method cannot derive
+   *         from data it actually read is not a number it may invent. The
+   *         caller ({@link createHistoryRecord}) owns the consequence.
    */
   private async nextEventSeq(): Promise<number> {
     const where: Record<string, unknown> = this.organizationId
@@ -280,9 +304,11 @@ export class DatabaseLoader implements MetadataLoader {
         if (v > max) max = v;
       }
       return max + 1;
-    } catch {
-      // Table not provisioned yet or driver error — start at 1.
-      return 1;
+    } catch (error) {
+      // Benign — and ONLY benign: there is no table, therefore no row, so
+      // numbering from 1 cannot collide with anything.
+      if (isMissingTableError(error)) return 1;
+      throw error;
     }
   }
 
@@ -493,7 +519,41 @@ export class DatabaseLoader implements MetadataLoader {
     // transaction, so concurrent writers can collide. The SysMetadataRepository
     // path serializes this under engine.transaction(); DatabaseLoader is
     // deprecated for new writes and tolerates the race.
-    const eventSeq = await this.nextEventSeq();
+    //
+    // #4825: the concurrency race above is a KNOWN, recorded limitation of this
+    // path. A read failure is not the same thing and is not tolerated — if the
+    // sequence cannot be derived from rows we actually read, we write NO history
+    // row rather than one carrying a number we made up. A missing row is loud
+    // here and visibly absent later; a colliding row is silent now and corrupts
+    // the ordering that `queryHistory` and `rollback` both depend on, forever.
+    let eventSeq: number;
+    try {
+      eventSeq = await this.nextEventSeq();
+    } catch (error) {
+      if (!this.historySeqFailureReported) {
+        this.historySeqFailureReported = true;
+        console.error(
+          `[Metadata] Could not read \`${this.historyTableName}\` to determine the next \`event_seq\` — the history ` +
+            `entry for ${type}/${name} was NOT written, and further entries are being skipped while this persists. ` +
+            `The metadata write itself SUCCEEDED, so the server keeps looking healthy while its change history ` +
+            `silently develops holes: version timelines and rollback targets will be incomplete. The entry is skipped ` +
+            `deliberately — numbering it from 1 (what this code did before #4825) would collide with existing rows and ` +
+            `make \`event_seq\` ordering wrong rather than merely incomplete, which nothing detects and no restart ` +
+            `repairs. Fix the datasource/driver error below (connection, timeout, privileges); the next metadata write ` +
+            `retries and reports recovery.`,
+          error,
+        );
+      }
+      return;
+    }
+
+    if (this.historySeqFailureReported) {
+      this.historySeqFailureReported = false;
+      console.info(
+        `[Metadata] \`${this.historyTableName}\` is readable again — \`event_seq\` numbering recovered and change ` +
+          `history is being recorded again. Entries skipped during the outage are not backfilled.`,
+      );
+    }
 
     const historyRecord: Partial<MetadataHistoryRecord> = {
       id: historyId,