diff --git a/.changeset/20768-first-boot-migration-gate-read.md b/.changeset/20768-first-boot-migration-gate-read.md new file mode 100644 index 00000000000..e8a3888cbb8 --- /dev/null +++ b/.changeset/20768-first-boot-migration-gate-read.md @@ -0,0 +1,22 @@ +--- +'@objectstack/driver-sql': patch +--- + +fix(driver-sql): the first boot of a new database no longer prints a `DATABASE_ERROR` for `sys_migration` (#20768) + +On the first boot of a new database, the SQL driver printed this line once, on its warn channel (stderr by default): + +```text +[sql-driver] DATABASE_ERROR — the backend refused a read on 'sys_migration' (SQLITE_ERROR) ... no such table: sys_migration +``` + +Nothing was wrong. At the start of its first schema sync, before it creates any table, the driver asks whether this deployment's file columns have moved (the ADR-0104 media-arm resolver). The resolver the engine supplies answers by reading `sys_migration`. On a new database that table does not exist yet, so the read is refused and the answer is "not moved", which is correct for an empty store. + +The driver now asks that question inside an async scope. Inside it, a read refused because its own target table does not exist goes to the logger's `debug` channel instead of `warn`. The default logger has no `debug`, so the line is not printed. The logger shape gains an optional `debug`. The refusal is still thrown to the resolver, and the resolver's answer is the same as before. + +What still warns: + +- every other refusal inside that scope, such as a malformed statement on a table that exists, or a missing table named by another relation (a view over a dropped table); +- a missing table read anywhere else, as before. + +The missing-table check is the shared `isMissingTableError` from `@objectstack/types`, which `@objectstack/metadata/errors` re-exports. There is nothing to migrate. diff --git a/packages/drivers/driver-sql/src/sql-driver-20768-pre-ddl-question-missing-table.test.ts b/packages/drivers/driver-sql/src/sql-driver-20768-pre-ddl-question-missing-table.test.ts new file mode 100644 index 00000000000..288d97c4210 --- /dev/null +++ b/packages/drivers/driver-sql/src/sql-driver-20768-pre-ddl-question-missing-table.test.ts @@ -0,0 +1,287 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * [#20768] A missing table read by a driver's own PRE-DDL question leaves the + * warn channel. Nothing else does. + * + * ## The measured defect + * + * `objectstack dev --database file:NEW.sqlite` on `examples/app-crm` printed + * one line on the first boot of a new database, on the driver's warn channel + * (stderr): + * + * ```text + * [sql-driver] DATABASE_ERROR — the backend refused a read on 'sys_migration' (SQLITE_ERROR) ... + * select * from `sys_migration` where `id` = 'adr-0104-file-references' limit 1 - no such table: sys_migration + * ``` + * + * The read is the engine's migration-gate read. The ADR-0104 media-arm + * resolver reaches it, and this driver asks that resolver at the start of its + * first `initObjects`, before its schema pass has created any table. On a new + * database the ledger is not there yet, the resolver answers "not moved", and + * that answer is right. Only the log line was wrong. + * + * ## What this file pins, from the driver's side + * + * The engine-driven boot is pinned in `@objectstack/runtime` + * (`first-boot-migration-gate-read.integration.test.ts`). Here the resolver is + * a stand-in that reads the ledger the way the engine does: one row by id, + * with a failed read answered as "not moved". + * + * ① first boot: the question's read of a table that does not exist yet goes + * to `debug`, not `warn`. The resolver still gets the refusal envelope, and + * the arm is the one it always was. + * ② the same holds when the ledger is served by ANOTHER driver instance: the + * scope follows the async chain, not the instance. + * ③ second boot: the table exists, the read succeeds, nothing is logged, and + * the answer comes from the ledger row. + * + * Controls, each a refusal that must still warn: + * + * ④ a malformed read on an EXISTING table, inside the question; + * ⑤ a missing table named by some OTHER relation (a view over a dropped + * table), inside the question; + * ⑥ a missing table read OUTSIDE the question. + */ + +import { describe, it, expect, afterEach } from 'vitest'; +import { mkdtempSync, rmSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import type { DriverQuery } from '@objectstack/spec/contracts'; +import { SqlDriver } from './sql-driver.js'; +import type { SqlDriverConfig } from './sql-driver.js'; + +const LEDGER = 'sys_migration'; +const MIGRATION_ID = 'adr-0104-file-references'; +/** The ledger's columns the engine's gate read looks at, as a stand-in object. */ +const LEDGER_OBJECT = { + name: LEDGER, + fields: { + last_run_at: { type: 'text' }, + verified_at: { type: 'text' }, + columns_moved_at: { type: 'text' }, + blocking: { type: 'number' }, + }, +}; +/** An app object with a media column: the column the arm decides the encoding of. */ +const MEDIA_OBJECT = { name: 'os20768_doc', fields: { cover: { type: 'image' }, title: { type: 'text' } } }; + +type Line = { level: 'warn' | 'debug' | 'info' | 'error'; message: string }; + +/** Reads the arm the way every writer and every DDL branch reads it. */ +class ArmProbe extends SqlDriver { + readonly lines: Line[] = []; + + constructor(config: SqlDriverConfig) { + super(config); + // Arrow closures on purpose: this sink records, it is not the receiver test + // (`logger-receiver-detach.test.ts` owns that). + (this as unknown as { logger: Record void> }).logger = { + warn: (m) => this.lines.push({ level: 'warn', message: String(m) }), + debug: (m) => this.lines.push({ level: 'debug', message: String(m) }), + info: (m) => this.lines.push({ level: 'info', message: String(m) }), + error: (m) => this.lines.push({ level: 'error', message: String(m) }), + }; + } + + get arm(): boolean { + return (this as unknown as { fileColumnsMoved: boolean }).fileColumnsMoved; + } + + databaseErrors(level: Line['level'], object: string): string[] { + return this.lines + .filter((l) => l.level === level && l.message.includes(`'${object}'`)) + .map((l) => l.message); + } +} + +const open: ArmProbe[] = []; +const dirs: string[] = []; + +function newDatabaseFile(): string { + const dir = mkdtempSync(join(tmpdir(), 'os-20768-')); + dirs.push(dir); + // Named but not created: the first driver to connect creates it, as a new + // deployment's first boot does. + return join(dir, 'new.sqlite'); +} + +function driver(filename: string): ArmProbe { + const d = new ArmProbe({ + client: 'better-sqlite3', + connection: { filename }, + useNullAsDefault: true, + } as SqlDriverConfig); + open.push(d); + return d; +} + +/** A resolver shaped like the engine's: read one ledger row, a failure is "not moved". */ +function ledgerResolver(ledger: SqlDriver, observed: { error?: any; row?: any; asked: number }) { + return async (): Promise => { + observed.asked += 1; + try { + observed.row = await ledger.findOne(LEDGER, { where: { id: MIGRATION_ID } }); + return observed.row?.verified_at != null && observed.row?.columns_moved_at != null; + } catch (e) { + observed.error = e; + return false; + } + }; +} + +afterEach(async () => { + while (open.length) await open.pop()?.disconnect().catch(() => {}); + while (dirs.length) rmSync(dirs.pop()!, { recursive: true, force: true }); +}); + +describe('[#20768] a missing table read by the pre-DDL question is not a DATABASE_ERROR', () => { + it('① first boot: the ledger read goes to debug; the resolver hears the refusal; the arm is unchanged', async () => { + const d = driver(newDatabaseFile()); + const observed: { error?: any; row?: any; asked: number } = { asked: 0 }; + expect(d.setFileColumnsMovedResolver(ledgerResolver(d, observed))).toBe(true); + + await d.initObjects([LEDGER_OBJECT, MEDIA_OBJECT] as any); + + // The question was asked, and its read really was refused, with the envelope. + expect(observed.asked).toBe(1); + expect(observed.error?.code).toBe('DATABASE_ERROR'); + expect(observed.error?.status).toBe(500); + // No warn line for the ledger ... + expect(d.databaseErrors('warn', LEDGER)).toEqual([]); + // ... and the demoted line exists: demoted, not deleted. + const demoted = d.databaseErrors('debug', LEDGER); + expect(demoted).toHaveLength(1); + expect(demoted[0]).toContain('no such table'); + // The arm the resolver's answer set: "not moved", as before. + expect(d.arm).toBe(false); + // The schema pass went on to create the ledger. + expect(await d.find(LEDGER, {})).toEqual([]); + }); + + it('② the scope follows the async chain: a ledger served by another driver instance is demoted too', async () => { + const asker = driver(newDatabaseFile()); + const ledger = driver(newDatabaseFile()); + const observed: { error?: any; row?: any; asked: number } = { asked: 0 }; + asker.setFileColumnsMovedResolver(ledgerResolver(ledger, observed)); + + await asker.initObjects([MEDIA_OBJECT] as any); + + expect(observed.error?.code).toBe('DATABASE_ERROR'); + expect(ledger.databaseErrors('warn', LEDGER)).toEqual([]); + expect(ledger.databaseErrors('debug', LEDGER)).toHaveLength(1); + expect(asker.arm).toBe(false); + }); + + it('③ second boot: the read succeeds, nothing is logged, and the answer comes from the ledger row', async () => { + const file = newDatabaseFile(); + const first = driver(file); + first.setFileColumnsMovedResolver(ledgerResolver(first, { asked: 0 })); + await first.initObjects([LEDGER_OBJECT, MEDIA_OBJECT] as any); + // Between boots, the column move is recorded, so the second boot's answer + // can only be "moved" if its read reached the row. + const now = new Date().toISOString(); + await first.create( + LEDGER, + { id: MIGRATION_ID, last_run_at: now, verified_at: now, columns_moved_at: now, blocking: 0 }, + { bypassTenantAudit: true }, + ); + await first.disconnect(); + + const second = driver(file); + const observed: { error?: any; row?: any; asked: number } = { asked: 0 }; + second.setFileColumnsMovedResolver(ledgerResolver(second, observed)); + await second.initObjects([LEDGER_OBJECT, MEDIA_OBJECT] as any); + + expect(observed.error).toBeUndefined(); + expect(observed.row?.id).toBe(MIGRATION_ID); + expect(second.arm).toBe(true); + expect(second.lines.filter((l) => l.message.includes('DATABASE_ERROR'))).toEqual([]); + expect(second.databaseErrors('debug', LEDGER)).toEqual([]); + }); +}); + +describe('[#20768] CONTROLS — every other refusal still warns', () => { + it('④ a malformed read on an EXISTING table, inside the question, still warns', async () => { + const file = newDatabaseFile(); + const first = driver(file); + await first.initObjects([LEDGER_OBJECT] as any); + await first.disconnect(); + + const d = driver(file); + const observed: { error?: any; row?: any; asked: number } = { asked: 0 }; + // More bound variables than SQLite accepts in one statement: the backend + // refuses the statement, and the table is there. + const tooMany: NonNullable = { + id: { $in: Array.from({ length: 40_000 }, (_, i) => `k${i}`) }, + }; + d.setFileColumnsMovedResolver(async () => { + observed.asked += 1; + try { + await d.find(LEDGER, { where: tooMany }); + } catch (e) { + observed.error = e; + } + return false; + }); + + await d.initObjects([MEDIA_OBJECT] as any); + + expect(observed.asked).toBe(1); + expect(observed.error?.code).toBe('DATABASE_ERROR'); + expect(observed.error?.status).toBe(500); + const warned = d.databaseErrors('warn', LEDGER); + expect(warned).toHaveLength(1); + expect(warned[0]).toContain('DATABASE_ERROR'); + expect(d.databaseErrors('debug', LEDGER)).toEqual([]); + }); + + it('⑤ a missing table named by ANOTHER relation (a view over a dropped table), inside the question, still warns', async () => { + const file = newDatabaseFile(); + const first = driver(file); + await first.initObjects([LEDGER_OBJECT] as any); + await first.execute('create table os20768_gone (id text primary key)'); + await first.execute('create view os20768_view as select * from os20768_gone'); + await first.execute('drop table os20768_gone'); + await first.disconnect(); + + const d = driver(file); + const observed: { error?: any; asked: number } = { asked: 0 }; + d.setFileColumnsMovedResolver(async () => { + observed.asked += 1; + try { + await d.find('os20768_view', {}); + } catch (e) { + observed.error = e; + } + return false; + }); + + await d.initObjects([MEDIA_OBJECT] as any); + + expect(observed.error?.code).toBe('DATABASE_ERROR'); + expect(observed.error?.status).toBe(500); + expect(d.databaseErrors('warn', 'os20768_view')).toHaveLength(1); + expect(d.databaseErrors('debug', 'os20768_view')).toEqual([]); + }); + + it('⑥ a missing table read OUTSIDE the question still warns', async () => { + const d = driver(newDatabaseFile()); + d.setFileColumnsMovedResolver(ledgerResolver(d, { asked: 0 })); + await d.initObjects([LEDGER_OBJECT] as any); + // The question has been asked and answered; the scope is closed. + let refusal: any; + try { + await d.find('os20768_never_created', {}); + } catch (e) { + refusal = e; + } + expect(refusal?.code).toBe('DATABASE_ERROR'); + expect(refusal?.status).toBe(500); + const warned = d.databaseErrors('warn', 'os20768_never_created'); + expect(warned).toHaveLength(1); + expect(warned[0]).toContain('no such table'); + expect(d.databaseErrors('debug', 'os20768_never_created')).toEqual([]); + }); +}); diff --git a/packages/drivers/driver-sql/src/sql-driver.ts b/packages/drivers/driver-sql/src/sql-driver.ts index 47d5046ccd5..824a3fb801c 100644 --- a/packages/drivers/driver-sql/src/sql-driver.ts +++ b/packages/drivers/driver-sql/src/sql-driver.ts @@ -88,6 +88,7 @@ import { uniqueViolationColumn, resolveTenancyPosture, declareTargetedTable, + isMissingTableError, } from '@objectstack/types'; import { postureEnforcesWall } from '@objectstack/spec/security'; import { @@ -147,10 +148,34 @@ import { import { recoverUnencodedJsonText } from './unencoded-json-text.js'; import knex, { Knex } from 'knex'; import { nanoid } from 'nanoid'; +import { AsyncLocalStorage } from 'node:async_hooks'; import { createHash } from 'node:crypto'; import { existsSync } from 'node:fs'; import { currentPerfTiming, perfNow, type PerfTiming } from '@objectstack/observability'; +/** + * [#20768] The async scope of a driver's own PRE-DDL question: the ADR-0104 + * media-arm resolver that {@link SqlDriver.resolveFileColumnsMoved} asks at the + * start of the first `initObjects`, before this driver has created any table. + * + * The resolver the engine supplies answers by reading `sys_migration`. On the + * first boot of a new database that table does not exist yet, because this + * very schema pass is what creates it. The backend refuses the read, and the + * resolver answers "not moved", which is the correct answer for a store with + * no columns. So the refusal is the ordinary state of a new database, and not + * a `DATABASE_ERROR` to put in front of an operator. + * + * Only one question reads through this scope, and only + * {@link SqlDriver.backendStatementFault} consults it. ⛔ It demotes one class, + * a missing table, recognised by the shared `isMissingTableError`. Any other + * refusal inside the scope still warns, and so does a missing table outside it. + * + * Module-level rather than per instance: the read the question issues goes to + * whichever driver serves the ledger. On a multi-datasource composition that + * can be another instance of this class, and it is in the same async chain. + */ +const PRE_DDL_QUESTION_SCOPE = new AsyncLocalStorage(); + /** * Default ID length for auto-generated IDs. */ @@ -6113,6 +6138,13 @@ export class SqlDriver implements IDataDriver { protected logger: { warn: (msg: string, meta?: any) => void; info?: (msg: string, meta?: any) => void; + /** + * [#20768] Below-warn channel for a refusal that is the ordinary state of + * the store, not a fault (see {@link SqlDriver.backendStatementFault}). + * The default sink has none, so such a line is dropped unless a host + * injects a logger that keeps `debug`. + */ + debug?: (msg: string, meta?: any) => void; /** * Durability-degradation channel (see AGENTS.md §Degradation log levels): * used when a constraint the metadata claims is enforced is NOT — e.g. a @@ -10010,20 +10042,45 @@ export class SqlDriver implements IDataDriver { const detail = (error as { message?: unknown } | null | undefined)?.message; const code = (error as { code?: unknown } | null | undefined)?.code; - this.logger.warn( - `[sql-driver] DATABASE_ERROR — the backend refused a read on '${object}'` + - (typeof code === 'string' && code.length > 0 ? ` (${code})` : '') + - '. The dialect message below is kept server-side: it carries the compiled statement, ' + - 'and on the dialects that inline them the bound literals too: ' + - `${typeof detail === 'string' ? detail : String(error)}`, - ); + const dialectText = typeof detail === 'string' ? detail : String(error); // [#13438] The table the statement was compiled against, resolved the way // {@link SqlDriver.getBuilder} resolves it — a federated object's // `external.remoteName`, otherwise the object's own name — because every // read exit that reaches here built its statement through `getBuilder`. // Declared on the envelope for `isMissingTableError`; never in the message. const targetedTable = this.physicalTableByObject[object] ?? object; - return backendStatementFaultError(object, error, targetedTable); + const envelope = backendStatementFaultError(object, error, targetedTable); + + // [#20768] One class leaves the warn channel, and only inside one scope: a + // table that does not exist yet, read while a driver asks its pre-DDL + // question (the ADR-0104 media-arm resolver, asked before the schema pass + // creates any table). On the first boot of a new database that read is + // `sys_migration`, and its refusal is the ordinary state of the store. The + // resolver hears the refusal and answers "not moved", as it always did. + // + // ⛔ Demoted, not deleted: the same dialect text goes to `debug`, which the + // default sink does not have. ⛔ Asked through the one shared predicate, + // over the envelope's DECLARED target, so a missing table named by some + // other relation (a view over a dropped table) is not this class. Every + // other refusal in the scope, and a missing table outside it, warns below. + if (PRE_DDL_QUESTION_SCOPE.getStore() === true && isMissingTableError(envelope, object)) { + this.logger.debug?.( + `[sql-driver] '${object}' does not exist yet: it was read while this driver asked its ` + + 'pre-DDL question (the ADR-0104 media-arm resolver), before its schema pass created ' + + 'any table. The refusal goes back to the resolver, which answers from it: ' + + dialectText, + ); + return envelope; + } + + this.logger.warn( + `[sql-driver] DATABASE_ERROR — the backend refused a read on '${object}'` + + (typeof code === 'string' && code.length > 0 ? ` (${code})` : '') + + '. The dialect message below is kept server-side: it carries the compiled statement, ' + + 'and on the dialects that inline them the bound literals too: ' + + dialectText, + ); + return envelope; } async count(object: string, query?: DriverQuery, options?: DriverOptions): Promise { @@ -19847,7 +19904,10 @@ export class SqlDriver implements IDataDriver { this.fileColumnsMovedAsked = true; this.fileColumnsMovedResolver = undefined; try { - this.fileColumnsMoved = (await resolver()) === true; + // [#20768] Asked inside the pre-DDL scope. On a new database the ledger + // the resolver reads does not exist yet, and that refusal is not a + // fault. The answer is unchanged — see {@link PRE_DDL_QUESTION_SCOPE}. + this.fileColumnsMoved = (await PRE_DDL_QUESTION_SCOPE.run(true, resolver)) === true; } catch { this.fileColumnsMoved = false; } diff --git a/packages/runtime/src/first-boot-migration-gate-read.integration.test.ts b/packages/runtime/src/first-boot-migration-gate-read.integration.test.ts new file mode 100644 index 00000000000..3c7537173ea --- /dev/null +++ b/packages/runtime/src/first-boot-migration-gate-read.integration.test.ts @@ -0,0 +1,163 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * #20768 — the first and second boot of a new SQLite database print no + * `sys_migration` `DATABASE_ERROR`, and a real refusal still warns. + * + * ## The measured defect + * + * `objectstack dev --database file:NEW.sqlite` on `examples/app-crm` printed + * one line on the FIRST boot of a new database, on the SQL driver's warn + * channel (stderr), and nothing on the second boot: + * + * ```text + * [sql-driver] DATABASE_ERROR — the backend refused a read on 'sys_migration' (SQLITE_ERROR) ... + * select * from `sys_migration` where `id` = 'adr-0104-file-references' limit 1 - no such table: sys_migration + * ``` + * + * A stack captured at the read named its caller: `ObjectQL.haveFileColumnsMoved`, + * called by the resolver the engine hands the driver at `registerDriver`, which + * `SqlDriver.initObjects` asks before its schema pass has created any table. + * Nothing was wrong. The table did not exist yet, the gate answered "not + * verified" and "not moved", and that is the right answer for a new store. + * + * ## The construction + * + * The boot's own chain, without a kernel: a real `ObjectQL` engine and a real + * `SqlDriver` over a SQLite file that does not exist yet, `sys_migration` + * registered, and the engine's schema pass (`syncSchemas`), which reaches the + * same `driver.syncSchema` → `initObjects` → resolver → gate read. The driver's + * log is captured on every channel, so a line that moved to `debug` is still + * counted: the fix demotes the line, it does not delete it. + * + * The gate answers are asserted on both boots, so the change is to a log level + * and to nothing a gate decides. + */ + +import { describe, it, expect, afterEach } from 'vitest'; +import { existsSync, mkdtempSync, rmSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import { ObjectQL } from '@objectstack/objectql'; +import { SqlDriver } from '@objectstack/driver-sql'; +import { SysMigration } from '@objectstack/platform-objects/system'; +import { FILE_REFERENCES_MIGRATION_ID } from '@objectstack/spec/system'; + +type Level = 'warn' | 'debug' | 'info' | 'error'; +type Line = { level: Level; message: string }; + +const openDrivers: SqlDriver[] = []; +const tempDirs: string[] = []; + +afterEach(async () => { + while (openDrivers.length) { + try { + await openDrivers.pop()?.disconnect(); + } catch { + /* already disconnected */ + } + } + while (tempDirs.length) rmSync(tempDirs.pop()!, { recursive: true, force: true }); +}); + +/** One boot of the engine over `file`, up to and including the schema pass. */ +async function boot(file: string): Promise<{ driver: SqlDriver; engine: ObjectQL; lines: Line[] }> { + const driver = new SqlDriver({ client: 'better-sqlite3', connection: { filename: file }, useNullAsDefault: true }); + openDrivers.push(driver); + const lines: Line[] = []; + const sink = (level: Level) => (message: string) => { + lines.push({ level, message: String(message) }); + }; + (driver as unknown as { logger: Record void> }).logger = { + warn: sink('warn'), + debug: sink('debug'), + info: sink('info'), + error: sink('error'), + }; + const engine = new ObjectQL(); + engine.registerDriver(driver as never, true); + await engine.init(); + engine.registry.registerObject(SysMigration as never, '#20768'); + await engine.syncSchemas(); + return { driver, engine, lines }; +} + +/** Every captured line on `level` that names `object` as the read's target. */ +function linesAbout(lines: Line[], level: Level, object: string): string[] { + return lines.filter((l) => l.level === level && l.message.includes(`'${object}'`)).map((l) => l.message); +} + +function newDatabaseFile(): string { + const dir = mkdtempSync(join(tmpdir(), 'os-20768-')); + tempDirs.push(dir); + return join(dir, 'new.sqlite'); +} + +describe('#20768 — the first boot of a new SQLite database reads the migration gate without a DATABASE_ERROR', () => { + it('first and second boot: no sys_migration DATABASE_ERROR on the warn channel; the gate answers are unchanged', async () => { + const file = newDatabaseFile(); + expect(existsSync(file)).toBe(false); + + // ── boot 1: the database does not exist when the gate is read. + const first = await boot(file); + expect(linesAbout(first.lines, 'warn', 'sys_migration')).toEqual([]); + expect(first.lines.filter((l) => l.level === 'warn' && l.message.includes('DATABASE_ERROR'))).toEqual([]); + // Lit: the gate WAS read before the table existed, and the refusal is + // still on record one level down. + const demoted = linesAbout(first.lines, 'debug', 'sys_migration'); + expect(demoted).toHaveLength(1); + expect(demoted[0]).toContain('no such table'); + // The answers, unchanged: not moved (the JSON arm), not verified. + expect((first.driver as unknown as { mediaColumnIsJson(): boolean }).mediaColumnIsJson()).toBe(true); + expect(await first.engine.haveFileColumnsMoved()).toBe(false); + expect(await first.engine.isFileReferencesMigrationVerified()).toBe(false); + expect(existsSync(file)).toBe(true); + + // The ledger records a verified migration between the boots, so the second + // boot can only answer "verified" if its gate read reached the row. + const now = new Date().toISOString(); + await first.driver.create( + 'sys_migration', + { id: FILE_REFERENCES_MIGRATION_ID, last_run_at: now, verified_at: now, applied_at: now, blocking: 0, advisory: 0 }, + { bypassTenantAudit: true }, + ); + await first.driver.disconnect(); + + // ── boot 2: the same file. + const second = await boot(file); + expect(second.lines.filter((l) => l.message.includes('DATABASE_ERROR'))).toEqual([]); + expect(linesAbout(second.lines, 'debug', 'sys_migration')).toEqual([]); + expect(await second.engine.isFileReferencesMigrationVerified()).toBe(true); + expect(await second.engine.haveFileColumnsMoved()).toBe(false); + }); + + it('CONTROL a malformed read on an existing table still warns, and so does a missing table read after boot', async () => { + const { driver, lines } = await boot(newDatabaseFile()); + // Count only what the reads below log. The boot's own lines are the first + // test's subject, and this control must not move with them. + lines.length = 0; + + // More bound variables than SQLite takes in one statement, on a table that + // exists: the backend refuses it, and that is a real refusal. + const tooMany = Array.from({ length: 40_000 }, (_, i) => `k${i}`); + const malformed = await driver.find('sys_migration', { where: { id: { $in: tooMany } } }).then( + () => expect.fail('expected the backend to refuse the statement'), + (e: { code?: string; status?: number }) => e, + ); + expect(malformed.code).toBe('DATABASE_ERROR'); + expect(malformed.status).toBe(500); + const warned = linesAbout(lines, 'warn', 'sys_migration'); + expect(warned).toHaveLength(1); + expect(warned[0]).toContain('DATABASE_ERROR'); + + // A table nobody created, read once the boot is done: still a warn. + const missing = await driver.find('os20768_never_provisioned', {}).then( + () => expect.fail('expected the read of a table that was never created to fail'), + (e: { code?: string; status?: number }) => e, + ); + expect(missing.code).toBe('DATABASE_ERROR'); + expect(missing.status).toBe(500); + expect(linesAbout(lines, 'warn', 'os20768_never_provisioned')).toHaveLength(1); + expect(linesAbout(lines, 'debug', 'os20768_never_provisioned')).toEqual([]); + }); +});