diff --git a/.changeset/plain-pandas-battle.md b/.changeset/plain-pandas-battle.md new file mode 100644 index 0000000000..00792affe1 --- /dev/null +++ b/.changeset/plain-pandas-battle.md @@ -0,0 +1,19 @@ +--- +"@objectstack/driver-sql": patch +"@objectstack/cli": patch +--- + +`os migrate plan` / `apply` examine the object set the composed host DECLARED, and report the boundary when they cannot + +A composed host stack (#12938) registers its plugins for their DECLARATIONS: `init()` runs, `start()` is suppressed. The pass that hands every registered object to its driver — the one that fills the `managedObjectFields` map `detectManagedDrift()` diffs — lives in `ObjectQLPlugin.start()`, and a host that brings its own `ObjectQLPlugin` (under the framework's own plugin name, so the CLI's capability injector de-dups against it) DISPLACES the standalone one, since duplicate registration overwrites by name. The result was a boot where no `ObjectQLPlugin.start()` ran at all: every host plugin declared its objects, and not one reached a driver. + +Measured on ObjectStack Cloud's staging control plane: 36 host plugins composed, ~80 `sys_*` tables declared, **8** examined — all eight belonging to the single service that provisions its own tables from a `kernel:ready` hook rather than relying on that pass. Every consumer-visible signal was green, and `Physical schema is in sync with metadata` was one composed plugin away from printing over seventy unexamined tables. + +Two changes: + +- **The composed boot now drives that pass itself**, over the deferral it already armed: `engine.syncObjectSchema(name)` per declared object, which reaches `SqlDriver.initObjects` exactly as the suppressed `start()` would have. A plan still writes nothing — the deferral records the create-table work instead of running it. +- **`plan` / `apply` report what they could NOT examine.** `--json` payloads gain `composition.coverage` (`registeredObjects`, `examinedObjects`, `unexaminedObjects`, and per-reason counts: federated, unbound, on another datasource, on a driver without schema registration, refused). When `unexaminedObjects > 0`, the human output refuses the unqualified "in sync" line and says the plan is PARTIAL instead. A consumer gate asserting coverage should read `composition.coverage.unexaminedObjects` — `managedTables` alone cannot tell a small deployment apart from a mostly unexamined one. + +`@objectstack/driver-sql`: `initObjects` no longer calls `ensureDatabaseExists()` while DDL is deferred. It is the one line there that can write — `mkdir -p` for a sqlite parent directory, and on Postgres/MySQL a `SELECT 1` that CREATEs the database on `3D000` / `ER_BAD_DB_ERROR` — and under the deferral there is no DDL for a database to exist for. `flushDeferredSchemaDdl` clears the flag before re-entering, so the confirmed `os migrate apply` still ensures the database ahead of the first `CREATE TABLE`. + +A project with neither an `objectstack.config.*` nor a compiled artifact is unchanged: it composes nothing, carries no `composition` key, and diffs the same five data-stack tables it always did. diff --git a/.changeset/silver-eagles-shout.md b/.changeset/silver-eagles-shout.md new file mode 100644 index 0000000000..d67d8c1097 --- /dev/null +++ b/.changeset/silver-eagles-shout.md @@ -0,0 +1,13 @@ +--- +"@objectstack/cli": patch +--- + +`os migrate plan` / `os migrate apply` exit when their work is done + +Measured on ObjectStack Cloud's staging control plane, inside `docker run --rm`: the CLI finished in 4.3 seconds and printed its own `Graceful shutdown complete`, and the run was cancelled by hand **78 minutes later** — the shell's next statement never ran, so it was still blocked on that one `docker run`. + +The composition these commands perform (#12938) registers a host's plugins for their DECLARATIONS: `init()` runs, `start()` is replaced with a no-op. Anything a host plugin arms during Phase 1 whose release would have been installed by Phase 2 — an interval, a pool, a watcher, a `kernel:ready` hook that starts a dispatcher — has no release path at all, so the event loop never drains while the kernel reports a clean shutdown. + +Both commands now end the process deliberately once their document is written, after the kernel teardown they already ran. Chasing the handle instead would mean auditing host code this repo cannot see, which is the same argument that made the composition declaration-only in the first place. `stdout` and `stderr` are drained before the exit, so a `--json` payload on a pipe is not truncated — and the drain itself is bounded, so a pipe whose reader has gone away cannot become a second way for the command not to return. + +Failure paths are unchanged: `this.exit(n)` throws an oclif `ExitError` that oclif's own handler already turns into a `process.exit`. diff --git a/packages/cli/src/commands/migrate/apply.ts b/packages/cli/src/commands/migrate/apply.ts index 50f0e419da..3974e00d57 100644 --- a/packages/cli/src/commands/migrate/apply.ts +++ b/packages/cli/src/commands/migrate/apply.ts @@ -21,6 +21,7 @@ import { summarizePendingSchemaWork, groupByCategory, } from '../../utils/schema-migrate.js'; +import { exitOneShotCommand } from '../../utils/one-shot-exit.js'; import { OCCUPANCY_HINT, probeMigrationTarget } from '../../utils/migrate-occupancy-gate.js'; import { describeOccupancy } from '../../utils/sqlite-occupancy.js'; @@ -81,7 +82,18 @@ export default class MigrateApply extends Command { json: Flags.boolean({ description: 'Output as JSON (implies non-interactive; requires --yes to mutate)' }), }; + /** + * #13027 — the process must end when the apply does. + * + * See `migrate/plan.ts`'s twin for the measurement, and for why the failure + * paths deliberately stay on oclif's own exit. + */ async run(): Promise { + await this.apply(); + await exitOneShotCommand(typeof process.exitCode === 'number' ? process.exitCode : 0); + } + + private async apply(): Promise { const { flags } = await this.parse(MigrateApply); const timer = createTimer(); const allowDestructive = flags['allow-destructive']; @@ -167,8 +179,40 @@ export default class MigrateApply extends Command { // target database, so it belongs in the plan and behind the prompt. const pending = stack.pendingSchemaWork; + // [#13028] The boundary of what was reconciled, carried on every payload + // that can be read as "this deployment is migrated". A consumer gate + // needs `unexaminedObjects` — `applied: []` alone cannot tell "nothing to + // do" apart from "most of it was never looked at". + const compositionPayload = stack.composition.notes.length > 0 + ? { + composition: { + hostConfig: stack.composition.hostConfigPath, + hostConfigLoaded: stack.composition.hostConfigLoaded, + ...(stack.composition.coverage ? { coverage: stack.composition.coverage } : {}), + notes: stack.composition.notes, + }, + } + : {}; + const unexamined = stack.composition.coverage?.unexaminedObjects ?? 0; + if (drift.length === 0 && pending.length === 0) { - if (flags.json) { await emitJson({ applied: [], skipped: [], created: [], message: 'in_sync' }, 0, { compact: true }); return; } + if (flags.json) { + await emitJson( + { applied: [], skipped: [], created: [], message: unexamined > 0 ? 'in_sync_partial' : 'in_sync', ...compositionPayload }, + 0, + { compact: true }, + ); + return; + } + if (unexamined > 0) { + const c = stack.composition.coverage!; + printWarning( + `Nothing to apply over the ${c.examinedObjects} object(s) this run examined — but ` + + `${c.unexaminedObjects} of ${c.registeredObjects} declared object(s) were NOT examined (see above). ` + + 'This is a PARTIAL reconcile: it is not evidence that the deployment is in sync.', + ); + return; + } printSuccess('Physical schema is already in sync with metadata — nothing to apply.'); return; } @@ -223,6 +267,7 @@ export default class MigrateApply extends Command { created, applied, skipped, + ...compositionPayload, duration: timer.elapsed(), }); return; diff --git a/packages/cli/src/commands/migrate/plan.ts b/packages/cli/src/commands/migrate/plan.ts index 26ab06e01e..ae9e5e25c1 100644 --- a/packages/cli/src/commands/migrate/plan.ts +++ b/packages/cli/src/commands/migrate/plan.ts @@ -19,6 +19,7 @@ import { summarize, summarizePendingSchemaWork, } from '../../utils/schema-migrate.js'; +import { exitOneShotCommand } from '../../utils/one-shot-exit.js'; import { probeMigrationTarget } from '../../utils/migrate-occupancy-gate.js'; import { describeOccupancy } from '../../utils/sqlite-occupancy.js'; import { @@ -69,7 +70,26 @@ export default class MigratePlan extends Command { json: Flags.boolean({ description: 'Output as JSON' }), }; + /** + * #13027 — the process must end when the plan does. + * + * The body is {@link plan}; this wrapper exists so every one of its early + * `return`s funnels through one deliberate exit. A composed host stack can + * leave the event loop alive — its `start()` was suppressed, so anything it + * armed during `init()` has no release path — and this command has measurably + * outlived its own "Graceful shutdown complete" by 78 minutes. + * + * ⛔ The FAILURE paths are deliberately NOT routed here: `this.exit(n)` throws + * an `ExitError` that oclif's `handle()` turns into a `process.exit` of its + * own, so they already terminate — and catching them here to exit "tidily" + * would swallow the report with them. + */ async run(): Promise { + await this.plan(); + await exitOneShotCommand(typeof process.exitCode === 'number' ? process.exitCode : 0); + } + + private async plan(): Promise { const { flags } = await this.parse(MigratePlan); const timer = createTimer(); @@ -168,6 +188,11 @@ export default class MigratePlan extends Command { composition: { hostConfig: stack.composition.hostConfigPath, hostConfigLoaded: stack.composition.hostConfigLoaded, + // [#13028] The plan's own boundary, so a consumer gate can + // refuse a PARTIAL plan instead of reading `managedTables` + // as coverage. `unexaminedObjects > 0` is the discriminator; + // `reasons` says which kind of partial it is. + ...(stack.composition.coverage ? { coverage: stack.composition.coverage } : {}), notes: stack.composition.notes, }, } @@ -201,7 +226,22 @@ export default class MigratePlan extends Command { console.log(''); if (drift.length === 0 && pending.length === 0) { - printSuccess('Physical schema is in sync with metadata — nothing to migrate.'); + // [#13028] "In sync" is a claim about the objects this plan EXAMINED. + // On a composed host that examined a strict subset — a control plane + // declaring ~80 tables of which 8 reached the diffed driver — printing + // the unqualified sentence tells an operator the deployment is + // migrated when most of it was never looked at. Say which it is. + const partial = (stack.composition.coverage?.unexaminedObjects ?? 0) > 0; + if (partial) { + const c = stack.composition.coverage!; + printWarning( + `No drift over the ${c.examinedObjects} object(s) this plan examined — but ` + + `${c.unexaminedObjects} of ${c.registeredObjects} declared object(s) were NOT examined (see above). ` + + 'This is a PARTIAL plan: it is not evidence that the deployment is in sync.', + ); + } else { + printSuccess('Physical schema is in sync with metadata — nothing to migrate.'); + } console.log(''); return; } diff --git a/packages/cli/src/utils/one-shot-exit.test.ts b/packages/cli/src/utils/one-shot-exit.test.ts new file mode 100644 index 0000000000..9e77d91b8c --- /dev/null +++ b/packages/cli/src/utils/one-shot-exit.test.ts @@ -0,0 +1,85 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * #13027 — the exit primitive, pinned where the e2e cannot look. + * + * `test/migrate-plan-exits.e2e.test.ts` owns the end-to-end fact (a real child + * returns). This file owns the two properties that make that safe and which a + * child process cannot show you: the streams are DRAINED before the exit — the + * pipe-truncation `emitJson` exists to prevent, re-introduced one statement + * later would be invisible from outside — and the drain cannot itself hang. + */ + +import { describe, it, expect, vi } from 'vitest'; +import { exitOneShotCommand } from './one-shot-exit.js'; + +/** A stream whose no-op write callback fires, in order, when told to. */ +function drainableStream() { + const pending: Array<() => void> = []; + return { + writes: 0, + write(_chunk: string, cb?: () => void) { + this.writes++; + if (cb) pending.push(cb); + return true; + }, + flush() { for (const cb of pending.splice(0)) cb(); }, + }; +} + +describe('exitOneShotCommand (#13027)', () => { + it('drains every stream before it exits', async () => { + const out = drainableStream(); + const err = drainableStream(); + const order: string[] = []; + const exit = vi.fn((code: number) => { order.push(`exit:${code}`); return undefined as never; }); + + const promise = exitOneShotCommand(0, { streams: [out, err], exit }); + + // Not yet: the streams have been asked to drain and have not answered. + await Promise.resolve(); + expect(exit).not.toHaveBeenCalled(); + expect(out.writes).toBe(1); + expect(err.writes).toBe(1); + + out.flush(); + err.flush(); + await promise; + expect(order).toEqual(['exit:0']); + }); + + it('carries the exit code through', async () => { + const exit = vi.fn(() => undefined as never); + await exitOneShotCommand(1, { streams: [], exit }); + expect(exit).toHaveBeenCalledWith(1); + }); + + it('exits anyway when a stream never drains', async () => { + // A pipe whose reader has gone away never drains. This function's whole + // job is to stop a command from failing to return, so it must not become a + // second way to do exactly that. + const stuck = { write: () => true }; // callback never invoked + const exit = vi.fn(() => undefined as never); + const timers: Array<() => void> = []; + const setTimeoutFn = ((fn: () => void) => { + timers.push(fn); + return { unref() { /* noop */ } }; + }) as unknown as typeof setTimeout; + + const promise = exitOneShotCommand(0, { streams: [stuck], exit, setTimeoutFn }); + await Promise.resolve(); + expect(exit).not.toHaveBeenCalled(); + + // The budget expires. + for (const fire of timers) fire(); + await promise; + expect(exit).toHaveBeenCalledWith(0); + }); + + it('tolerates a stream that throws on write, and one that is absent', async () => { + const exit = vi.fn(() => undefined as never); + const throwing = { write() { throw new Error('EPIPE'); } }; + await exitOneShotCommand(0, { streams: [throwing, undefined], exit }); + expect(exit).toHaveBeenCalledWith(0); + }); +}); diff --git a/packages/cli/src/utils/one-shot-exit.ts b/packages/cli/src/utils/one-shot-exit.ts new file mode 100644 index 0000000000..1177e09916 --- /dev/null +++ b/packages/cli/src/utils/one-shot-exit.ts @@ -0,0 +1,117 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * End a one-shot command's PROCESS once its work is done (#13027). + * + * ## The measurement + * + * `os migrate plan`, ObjectStack Cloud's staging control plane, `apply=false`, + * inside `docker run --rm`. The command finished and said so: + * + * ``` + * 15:03:52.522 17 change(s): 0 safe, 0 needs-confirm, 17 destructive + * 15:03:52.517 INFO Graceful shutdown started + * 15:03:52.555 INFO OK Graceful shutdown complete + * ``` + * + * Elapsed inside the CLI: 4.3 seconds. The next line in the log is the run + * being cancelled by hand **78 minutes later**. The shell's very next statement + * was an `echo` that never printed, so the shell was still blocked on that one + * `docker run`: the process printed its own graceful-shutdown line and then did + * not exit. + * + * ## Why the fix is "exit deliberately" and not "find the handle" + * + * The composition `os migrate plan` performs (#12938) registers a host's + * plugins for their DECLARATIONS: `init()` runs, `start()` is replaced with a + * no-op. A host plugin that acquires something live during Phase 1 — an + * interval, a pool, a watcher, a `kernel:ready` hook that starts a dispatcher — + * and releases it from a path the suppressed `start()` (or a `destroy` the + * host's own wrapper never forwards) would have installed now has no release + * path at all. The event loop stays alive; the kernel has already reported a + * clean shutdown, so nothing looks wrong. + * + * Chasing the handle means auditing host code this repo cannot see — the same + * argument that made the composition declaration-only in the first place. A + * one-shot command that has written its document owes the operator an exit, and + * that is true whatever the host left running. ⛔ This is NOT a licence to skip + * teardown: the caller still runs `stack.shutdown()` first, and this is the + * last statement after it. + * + * ## Why it cannot simply be `process.exit(code)` + * + * `process.exit` tears the process down with an unflushed stdout **pipe** + * buffer — the exact truncation `emitJson` exists to prevent, re-introduced one + * statement later. `emitJson`/`emitText` already await their own write, but the + * human-readable path is `console.log`, which does not. So this drains both + * streams first, and refuses to hang while doing it: a stream that will not + * drain must not become a second way for this command to never return. + */ + +/** Injection seam — production values, replaced wholesale in unit tests. */ +export interface OneShotExitDeps { + /** Streams to drain before exiting. */ + streams?: Array<{ write(chunk: string, cb?: () => void): unknown } | undefined>; + /** The exit call itself. */ + exit?: (code: number) => never; + /** Upper bound on waiting for a drain, in ms. */ + drainTimeoutMs?: number; + /** Timer factory, so a test does not have to wait in real time. */ + setTimeoutFn?: typeof setTimeout; +} + +/** + * Wait for everything already queued on `stream` to reach the OS. + * + * A no-op write's callback fires once every write queued **before** it has been + * flushed, which is the documented way to ask this question. The timeout is not + * belt-and-braces: a pipe whose reader has gone away never drains, and this + * function's whole job is to stop a command from hanging. + */ +function drain( + stream: { write(chunk: string, cb?: () => void): unknown } | undefined, + timeoutMs: number, + setTimeoutFn: typeof setTimeout, +): Promise { + return new Promise((resolve) => { + if (!stream || typeof stream.write !== 'function') { + resolve(); + return; + } + let settled = false; + const done = (): void => { + if (settled) return; + settled = true; + resolve(); + }; + const timer = setTimeoutFn(done, timeoutMs); + (timer as { unref?: () => void })?.unref?.(); + try { + stream.write('', done); + } catch { + done(); + } + }); +} + +/** + * Flush stdout/stderr, then end the process with `code`. + * + * Returns `Promise` in production. In a test the injected `exit` may + * return normally, and then so does this — that is deliberate, so a unit test + * can assert the code without killing its own runner. + */ +export async function exitOneShotCommand( + code = 0, + deps: OneShotExitDeps = {}, +): Promise { + const { + streams = [process.stdout, process.stderr], + exit = process.exit.bind(process) as (c: number) => never, + drainTimeoutMs = 2_000, + setTimeoutFn = setTimeout, + } = deps; + + await Promise.all(streams.map((s) => drain(s, drainTimeoutMs, setTimeoutFn))); + return exit(code); +} diff --git a/packages/cli/src/utils/schema-migrate.host-composition.integration.test.ts b/packages/cli/src/utils/schema-migrate.host-composition.integration.test.ts index 3daa8c389f..a892908a22 100644 --- a/packages/cli/src/utils/schema-migrate.host-composition.integration.test.ts +++ b/packages/cli/src/utils/schema-migrate.host-composition.integration.test.ts @@ -340,3 +340,157 @@ describe('an artifact-less, config-less project is unchanged (#12938 baseline pi } }, 60_000); }); + +/** + * #13028 — the shape that measured 8 tables out of ~80, reproduced. + * + * ## What the earlier fixture could not see + * + * The `SecurityPlugin`-only fixture above composes a host plugin next to the + * standalone stack's OWN `ObjectQLPlugin`, and that plugin's `start()` runs + * normally — so the pass that hands registered objects to their driver + * (`installRegisteredSchemas` → `registerObjectMetadata`, the one thing that + * fills the `managedObjectFields` map `detectManagedDrift()` diffs) happens by + * itself, and the composition looks complete. + * + * A real control plane does not have that shape. ObjectStack Cloud's config + * brings its own `ObjectQLPlugin`, behind a lazy wrapper, under the FRAMEWORK'S + * OWN plugin name — deliberately, so the CLI's capability injector de-dups + * against it. Duplicate registration OVERWRITES by name + * (`packages/core/src/plugin-registration.ts`), so the host's wrapper DISPLACES + * the standalone plugin, and `composeForDeclarations` then suppresses the + * wrapper's `start()`. The result is a boot in which NO `ObjectQLPlugin.start()` + * runs at all: every host plugin's `init()` declared its objects, and not one + * of them was ever handed to a driver. + * + * Measured consequence, staging control plane, framework `15d55fb2430f`: + * 36 plugins composed, ~80 `sys_*` tables declared, **8** examined — and all + * eight belonged to `service-messaging`, the one service that provisions its + * own tables from a `kernel:ready` hook instead of relying on that pass. + * + * ⚠️ The plugin NAMES in the fixture below are load-bearing, not decoration. + * Rename `com.objectstack.engine.objectql` to anything else and the two + * plugins coexist, both `init()`s run, and the boot dies on + * `Service 'objectql' already registered` — a different defect, and the + * fixture would stop reproducing this one. + */ +describe('a host that brings its OWN ObjectQL engine (#13028 — cloud\'s measured shape)', () => { + let dir: string; + const savedEnv: Record = {}; + + beforeAll(() => { + dir = mkdtempSync(join(tmpdir(), 'os-13028-')); + mkdirSync(join(dir, 'node_modules', '@objectstack'), { recursive: true }); + symlinkSync( + securityPackageRoot(), + join(dir, 'node_modules', '@objectstack', 'plugin-security'), + 'dir', + ); + symlinkSync( + resolve(dirname(require_.resolve('@objectstack/objectql')), '..'), + join(dir, 'node_modules', '@objectstack', 'objectql'), + 'dir', + ); + + writeFileSync( + join(dir, 'objectstack.config.ts'), + [ + "import { ObjectQLPlugin } from '@objectstack/objectql';", + "import { SecurityPlugin } from '@objectstack/plugin-security';", + '', + '// `lazyPlugin` from ObjectStack Cloud\'s control-plane preset, in shape:', + '// construction deferred to init(), start()/stop() forwarded, and NO', + '// `destroy` — which is the other half of this seam (#13027).', + 'function lazyPlugin(name: string, factory: () => Promise): any {', + ' let impl: any = null;', + ' return {', + ' name,', + ' async init(ctx: any) { impl = await factory(); if (impl?.init) await impl.init(ctx); },', + ' async start(ctx: any) { if (impl?.start) await impl.start(ctx); },', + ' async stop(ctx: any) { if (impl?.stop) await impl.stop(ctx); },', + ' };', + '}', + '', + 'export default {', + ' plugins: [', + " lazyPlugin('com.objectstack.engine.objectql', async () => new ObjectQLPlugin({ registerProtocol: false })),", + " lazyPlugin('com.objectstack.security', async () => new SecurityPlugin()),", + ' ],', + '};', + '', + ].join('\n'), + ); + + savedEnv.NODE_ENV = process.env.NODE_ENV; + savedEnv.OS_ARTIFACT_PATH = process.env.OS_ARTIFACT_PATH; + process.env.NODE_ENV = 'production'; + process.env.OS_ARTIFACT_PATH = join(dir, 'dist', 'objectstack.json'); + }); + + afterAll(() => { + if (savedEnv.NODE_ENV === undefined) delete process.env.NODE_ENV; + else process.env.NODE_ENV = savedEnv.NODE_ENV; + if (savedEnv.OS_ARTIFACT_PATH === undefined) delete process.env.OS_ARTIFACT_PATH; + else process.env.OS_ARTIFACT_PATH = savedEnv.OS_ARTIFACT_PATH; + try { rmSync(dir, { recursive: true, force: true }); } catch { /* ignore */ } + }); + + it('examines the objects its host DECLARED, and says so in the coverage payload', async () => { + const stack = await bootSchemaStack({ + jsonOutput: false, + databaseUrl: `file:${join(dir, 'own-engine.db')}`, + deferSchemaDdl: true, + composeHostStack: true, + projectRoot: dir, + }); + try { + expect(stack.composition.hostConfigLoaded).toBe(true); + + const coverage = stack.composition.coverage; + expect(coverage, 'a composed boot must report its own boundary').not.toBeNull(); + // The declared set is real — the security family plus the platform floor + // plus the data stack — and every one of them is in the diffed set. + expect(coverage!.registeredObjects).toBeGreaterThan(ARTIFACTLESS_BASELINE_TABLES.length); + expect(coverage!.examinedObjects).toBe(coverage!.registeredObjects); + expect(coverage!.unexaminedObjects).toBe(0); + + // …and the count the consumer gate reads agrees with it, rather than + // being a second, differently-derived number. + expect(stack.managedTableCount).toBe(coverage!.examinedObjects); + + // The two tables #12938 named by hand as the proof the five-table set was + // wrong. Pre-#13028 this shape reached NEITHER. + const pending = stack.pendingSchemaWork.map((p) => p.table); + expect(pending).toContain('sys_position'); + expect(pending).toContain('sys_permission_set'); + + // Full coverage means SILENCE about coverage: the honesty note exists to + // mark a shortfall, and one that printed anyway would train readers to + // skip the line that matters. + expect(stack.composition.notes.join(' ')).not.toContain('PARTIAL'); + } finally { + await stack.shutdown(); + } + }, 60_000); + + it('still writes NOTHING — the declaration-phase suppression is intact', async () => { + const stack = await bootSchemaStack({ + jsonOutput: false, + databaseUrl: `file:${join(dir, 'own-engine-writes.db')}`, + deferSchemaDdl: true, + composeHostStack: true, + projectRoot: dir, + }); + try { + await stack.driver!.detectManagedDrift(); + // The binding this card adds is `registerObjectMetadata` — in-memory + // assignment on the driver. If it had reached `initObjects` instead, the + // table would exist here. + const k = (stack.driver as any).knex; + const exists = await k.schema.hasTable('sys_permission_set'); + expect(exists, 'a plan must not create a table on its way to a coverage number').toBe(false); + } finally { + await stack.shutdown(); + } + }, 60_000); +}); diff --git a/packages/cli/src/utils/schema-migrate.ts b/packages/cli/src/utils/schema-migrate.ts index 878ac9202b..82c0fc22e3 100644 --- a/packages/cli/src/utils/schema-migrate.ts +++ b/packages/cli/src/utils/schema-migrate.ts @@ -24,6 +24,7 @@ import { describeDriverConnection } from './connection-display.js'; import { reserveStdoutForJson } from './json-stdout.js'; import { buildSchemaMigrationPlugins, + measureComposedCoverage, type SchemaMigrationComposition, } from './schema-migration-plugins.js'; @@ -337,7 +338,7 @@ export async function bootSchemaStack( cwd: opts.projectRoot ?? process.cwd(), skipSeedData: defer, }) - : { plugins: [], hostConfigPath: null, hostConfigLoaded: false, notes: [] } satisfies SchemaMigrationComposition; + : { plugins: [], hostConfigPath: null, hostConfigLoaded: false, notes: [], coverage: null } satisfies SchemaMigrationComposition; for (const plugin of composition.plugins) { await kernel.use(plugin as any); } @@ -347,6 +348,22 @@ export async function bootSchemaStack( await runtime.start(); const driver = findSqlDriver(kernel); + + // #13028 — the composed host declared its objects in `init()`; the pass that + // hands them to their driver lives in `ObjectQLPlugin.start()`, which the + // declaration-phase composition suppressed (and which a host bringing its + // OWN engine plugin displaces outright, since duplicate registration + // overwrites by name). Drive that pass here, over the deferral this boot + // already armed, and record what it could NOT reach — so a partial plan says + // so instead of reading as coverage. Runs only when this boot actually + // composed a host; every other caller is untouched. + if (opts.composeHostStack === true && composition.notes.length > 0) { + const measured = await measureComposedCoverage(kernel, driver, defer); + composition.coverage = measured.coverage; + composition.notes.push(...measured.notes); + } + + // Read AFTER the pass above — that is the step which fills both of them. const managedTableCount = driver ? (driver as any).managedObjectFields?.size ?? 0 : 0; const pendingSchemaWork = defer && driver?.previewDeferredSchemaWork ? await driver.previewDeferredSchemaWork() diff --git a/packages/cli/src/utils/schema-migration-plugins.test.ts b/packages/cli/src/utils/schema-migration-plugins.test.ts index c02e2824cc..ce3de458e9 100644 --- a/packages/cli/src/utils/schema-migration-plugins.test.ts +++ b/packages/cli/src/utils/schema-migration-plugins.test.ts @@ -8,6 +8,7 @@ import { findHostConfig, composeForDeclarations, buildSchemaMigrationPlugins, + measureComposedCoverage, } from './schema-migration-plugins.js'; /** @@ -195,3 +196,159 @@ describe('buildSchemaMigrationPlugins', () => { expect(said).toContain('UNMEASURED'); }); }); + +/** + * #13028 — the plan reports its own BOUNDARY. + * + * The card's measurement: 36 host plugins composed on ObjectStack Cloud's + * staging control plane, ~80 `sys_*` tables declared, **8** examined, and every + * consumer-visible signal green — the config loaded, the composition printed a + * healthy note, the plan named real tables. A coverage gate reading + * `managedTables` passed over a plan that had not looked at most of the + * deployment. + * + * These cases pin the discriminator that gate needed. They use engine doubles + * rather than a boot: the integration file owns "does a real composed boot now + * reach the driver", and what is isolated here is the REPORT — which is the + * half that has to stay honest even when the coverage does not. + */ +describe('measureComposedCoverage (#13028)', () => { + /** + * A driver double. `syncSchema` is the method `engine.syncObjectSchema()` + * requires and `SqlDriver` implements — its presence is what separates a SQL + * driver from one that cannot register a managed schema at all. + */ + const driverDouble = (name: string) => ({ name, syncSchema: async () => undefined }); + + /** An engine double: a registry, driver resolution, and the sync entry point. */ + const engineDouble = (opts: { + objects: Array<{ name: string; external?: unknown }>; + driverFor: (name: string) => unknown; + sync?: (name: string) => Promise; + }) => ({ + registry: { getAllObjects: () => opts.objects }, + getDriverForObject: opts.driverFor, + syncObjectSchema: opts.sync ?? (async () => undefined), + }); + + const kernelWith = (engine: unknown) => ({ + getService: (slot: string) => (slot === 'objectql' ? engine : undefined), + }); + + it('reports full coverage when every declared object lands on the diffed driver', async () => { + const driver = driverDouble('control'); + const synced: string[] = []; + const engine = engineDouble({ + objects: [{ name: 'sys_position' }, { name: 'sys_permission_set' }], + driverFor: () => driver, + sync: async (n) => { synced.push(n); }, + }); + + const out = await measureComposedCoverage(kernelWith(engine), driver, true); + + expect(synced).toEqual(['sys_position', 'sys_permission_set']); + expect(out.coverage).toMatchObject({ + registeredObjects: 2, + examinedObjects: 2, + unexaminedObjects: 0, + }); + // Silence is the point: a plan that examined everything must render + // byte-identically to one from before this existed. + expect(out.notes).toEqual([]); + }); + + it('names the shortfall — and its reason — when objects sit on ANOTHER driver', async () => { + // The measured cloud shape: a composed host brings its own engine/driver + // pair, `findSqlDriver()` resolves one driver, and part of the declared set + // is bound somewhere the plan will never diff. + const planned = driverDouble('control'); + const elsewhere = driverDouble('tenant'); + const engine = engineDouble({ + objects: [{ name: 'sys_notification' }, { name: 'sys_position' }, { name: 'sys_user' }], + driverFor: (n) => (n === 'sys_notification' ? planned : elsewhere), + }); + + const out = await measureComposedCoverage(kernelWith(engine), planned, true); + + expect(out.coverage).toMatchObject({ + registeredObjects: 3, + examinedObjects: 1, + unexaminedObjects: 2, + }); + expect(out.coverage.reasons.otherDriver).toBe(2); + const said = out.notes.join(' '); + expect(said).toContain('1 of 3 declared object(s) are in the diffed set'); + expect(said).toContain('2 bound to a different datasource'); + // The sentence a consumer gate and an operator both need: an empty result + // over the rest is not a pass. + expect(said).toContain('PARTIAL'); + expect(said).toContain('UNMEASURED'); + }); + + it('counts federated, unbound and unsupported objects apart from one another', async () => { + const planned = driverDouble('control'); + const engine = engineDouble({ + objects: [ + { name: 'sys_position' }, + { name: 'remote_customer', external: { remoteName: 'customers' } }, + { name: 'orphan' }, + ], + driverFor: (n) => (n === 'sys_position' ? planned : undefined), + }); + + const out = await measureComposedCoverage(kernelWith(engine), planned, true); + + expect(out.coverage.reasons).toMatchObject({ federated: 1, unbound: 1, otherDriver: 0 }); + const said = out.notes.join(' '); + expect(said).toContain('1 federated (no managed table)'); + expect(said).toContain('1 bound to no driver'); + }); + + it('reports a REFUSING driver as a shortfall, quoting it', async () => { + const planned = driverDouble('control'); + const engine = engineDouble({ + objects: [{ name: 'sys_position' }], + driverFor: () => planned, + sync: async () => { throw new Error('pool is closed'); }, + }); + + const out = await measureComposedCoverage(kernelWith(engine), planned, true); + + expect(out.coverage.examinedObjects).toBe(0); + expect(out.coverage.reasons.failed).toBe(1); + const said = out.notes.join(' '); + expect(said).toContain('REFUSED schema registration for 1 object(s)'); + expect(said).toContain('pool is closed'); + }); + + it('says the registry was UNREADABLE rather than answering "zero objects"', async () => { + // #9285's contract, one layer out: "the registry holds nothing" and "the + // registry could not be read" have opposite consequences, and only the + // first is a truthful reason to report full coverage over an empty set. + const out = await measureComposedCoverage(kernelWith({ registry: {} }), driverDouble('control'), true); + + expect(out.coverage.registeredObjects).toBe(0); + const said = out.notes.join(' '); + expect(said).toContain('no readable ObjectQL registry'); + expect(said).toContain('UNMEASURED coverage, not full coverage'); + }); + + it('REFUSES to bind on a boot that did not defer DDL — that call would create tables', async () => { + // The guard that keeps this pass from turning a dry run into a migration: + // `syncObjectSchema` takes the DDL path when the driver is not deferring, + // so a non-deferred boot reports UNMEASURED instead of syncing. + const planned = driverDouble('control'); + let synced = 0; + const engine = engineDouble({ + objects: [{ name: 'sys_position' }], + driverFor: () => planned, + sync: async () => { synced++; }, + }); + + const out = await measureComposedCoverage(kernelWith(engine), planned, false); + + expect(synced).toBe(0); + expect(out.notes.join(' ')).toContain('did not defer schema DDL'); + expect(out.notes.join(' ')).toContain('UNMEASURED'); + }); +}); diff --git a/packages/cli/src/utils/schema-migration-plugins.ts b/packages/cli/src/utils/schema-migration-plugins.ts index 5ab0525900..08978511f8 100644 --- a/packages/cli/src/utils/schema-migration-plugins.ts +++ b/packages/cli/src/utils/schema-migration-plugins.ts @@ -167,6 +167,48 @@ function hasPlatformObjects(plugins: readonly unknown[]): boolean { ); } +/** + * What the composed boot could and could NOT examine (#13028). + * + * `managedTables` alone cannot answer that. The count is read off ONE driver — + * the one `findSqlDriver()` resolves — and a composed host brings its own + * engine/driver pair, so a plan can report a healthy-looking number while most + * of the deployment's objects sit on an engine nobody diffed, or on no driver + * at all. Measured on ObjectStack Cloud's staging control plane before this + * card: 36 host plugins composed, ~80 `sys_*` tables declared, **8** examined, + * every signal green. + * + * So the plan reports its own boundary. Every field here is a count of objects, + * not of plugins: which plugin an object came from is not observable at this + * seam (a manifest registration carries a package id, not a plugin instance), + * and inventing that attribution would be a second thing that reads like + * coverage. + */ +export interface SchemaMigrationCoverage { + /** Objects the composed boot's engine registry holds — the deployment's declared set. */ + registeredObjects: number; + /** Of those, the ones now bound to the driver this plan diffs. */ + examinedObjects: number; + /** + * `registeredObjects - examinedObjects` — declared, and NOT covered by the + * plan below. Non-zero means the plan is PARTIAL, whatever its findings say. + */ + unexaminedObjects: number; + /** Why each unexamined object is unexamined, so the number is actionable. */ + reasons: { + /** Federated (external) objects — no managed table, correctly out of scope. */ + federated: number; + /** No driver claims them: `getDriverForObject()` answered nothing. */ + unbound: number; + /** Their driver cannot register object metadata (a non-SQL driver). */ + unsupported: number; + /** Bound to a DIFFERENT driver than the one this plan diffs. */ + otherDriver: number; + /** Their driver REFUSED the registration — the loud one; see `notes`. */ + failed: number; + }; +} + export interface SchemaMigrationComposition { /** Plugins to register after the data stack, in order. */ plugins: unknown[]; @@ -188,6 +230,13 @@ export interface SchemaMigrationComposition { * nor an artifact produces byte-identical output to before this existed. */ notes: string[]; + /** + * The boundary of what this plan examined (#13028) — `null` until the boot + * has started and {@link measureComposedCoverage} has run, and `null` + * forever on a boot that composed nothing, so an artifact-less, config-less + * run renders byte-identically to before any of this existed. + */ + coverage: SchemaMigrationCoverage | null; } const NOTHING_COMPOSED: SchemaMigrationComposition = Object.freeze({ @@ -195,6 +244,7 @@ const NOTHING_COMPOSED: SchemaMigrationComposition = Object.freeze({ hostConfigPath: null, hostConfigLoaded: false, notes: [], + coverage: null, }) as SchemaMigrationComposition; /** @@ -288,5 +338,158 @@ export async function buildSchemaMigrationPlugins(opts: { notes.push('Composed PlatformObjectsPlugin (the platform floor `os serve` composes unconditionally).'); } - return { plugins, hostConfigPath, hostConfigLoaded, notes }; + return { plugins, hostConfigPath, hostConfigLoaded, notes, coverage: null }; +} + +/** + * Bind the composed boot's declared objects to their drivers, WITHOUT DDL, and + * report what the plan can therefore examine (#13028). + * + * ## Why this step exists at all + * + * What fills a SQL driver's `managedObjectFields` — the map + * `detectManagedDrift()` diffs the physical schema against — is + * `registerObjectMetadata()`, and the one pass that drives it for every + * registered object lives inside `ObjectQLPlugin.start()`. A declaration-phase + * composition suppresses `start()`; a host that brings its OWN `ObjectQLPlugin` + * (ObjectStack Cloud's control plane does, behind a lazy wrapper) therefore + * ends the boot with its objects declared in an engine whose driver was never + * told about one of them. + * + * Measured on that control plane: 36 host plugins composed, ~80 `sys_*` tables + * declared, **8** examined — and all eight belonged to the single service that + * provisions its own tables from a `kernel:ready` hook rather than relying on + * that pass. Every consumer-visible signal was green. + * + * ## Why running it here is safe — and why it is the framework's own pass + * + * Per object it calls `engine.syncObjectSchema(name)`: the SAME public + * `IDataEngine` entry point `service-messaging` already uses to provision its + * tables, reaching `SqlDriver.initObjects` exactly as `ObjectQLPlugin.start()` + * would have. This boot has DDL DEFERRED, so `initObjects` registers the + * metadata in memory, records the create-table work as PENDING and returns — + * no `CREATE TABLE`, no `ALTER TABLE`, and since #13028 not even the + * `ensureDatabaseExists()` probe (`sql-driver.ts` skips it while deferred, for + * this call site). A plan still writes nothing, and it costs no round-trips. + * + * ⛔ It is NOT the suppressed `start()` re-armed: no host code runs here at + * all. This is the framework driving its own registry→driver pass over the + * declarations the host's `init()` already made. + * + * ⛔ And it must NOT run on a boot that did not defer: the same call would then + * take the DDL path and a "plan" would create tables. The caller passes + * `deferred` rather than this function deducing it — a capability that appears + * because of a default nobody wrote down is invisible at every call site + * (AGENTS.md → Route & surface ownership §2). + * + * @param kernel the booted kernel. + * @param plannedDriver the driver whose managed set the plan will diff — the + * identity comparison that turns "bound somewhere" into "bound HERE". + * @param deferred whether this boot armed deferred DDL. `false` reports the + * coverage as UNMEASURED instead of syncing. + */ +export async function measureComposedCoverage( + kernel: unknown, + plannedDriver: unknown, + deferred: boolean, +): Promise<{ coverage: SchemaMigrationCoverage; notes: string[] }> { + const notes: string[] = []; + const empty: SchemaMigrationCoverage = { + registeredObjects: 0, + examinedObjects: 0, + unexaminedObjects: 0, + reasons: { federated: 0, unbound: 0, unsupported: 0, otherDriver: 0, failed: 0 }, + }; + + if (!deferred) { + notes.push( + 'This boot did not defer schema DDL, so the declared object set was NOT bound to the driver here — ' + + 'binding it would have run DDL. Coverage below is UNMEASURED, not full.', + ); + return { coverage: empty, notes }; + } + + const getService = (kernel as { getService?: (name: string) => unknown })?.getService; + let engine: any; + try { + engine = getService?.call(kernel, 'objectql'); + } catch { + engine = undefined; + } + const objects: unknown = engine?.registry?.getAllObjects?.(); + if ( + !Array.isArray(objects) + || typeof engine?.getDriverForObject !== 'function' + || typeof engine?.syncObjectSchema !== 'function' + ) { + // No engine, or one whose registry cannot be read. ⛔ NOT reported as + // "zero objects": that answer was never obtained, and the two have + // opposite consequences (a small deployment vs. a plan that measured + // nothing). The plan keeps whatever the driver already knew and says why + // it could not do better. + notes.push( + 'The composed boot exposes no readable ObjectQL registry, so the plan below covers only what ' + + 'already reached the driver by some other path. That is UNMEASURED coverage, not full coverage.', + ); + return { coverage: empty, notes }; + } + + let examined = 0; + let federated = 0; + let unbound = 0; + let unsupported = 0; + let otherDriver = 0; + let failed = 0; + const failures = new Map(); + + for (const obj of objects as Array<{ name: string; external?: unknown }>) { + // Federated objects have no managed table — `detectManagedDrift` could not + // diff one if it wanted to. Counted apart from a real gap rather than + // folded into it. + if (obj?.external != null) { federated++; continue; } + const driver = engine.getDriverForObject(obj.name); + if (!driver) { unbound++; continue; } + if (driver !== plannedDriver) { otherDriver++; continue; } + if (typeof (driver as { syncSchema?: unknown }).syncSchema !== 'function') { unsupported++; continue; } + try { + await engine.syncObjectSchema(obj.name); + examined++; + } catch (e: unknown) { + failed++; + const message = e instanceof Error ? e.message : String(e); + failures.set(message, (failures.get(message) ?? 0) + 1); + } + } + + for (const [message, count] of failures) { + notes.push( + `The driver REFUSED schema registration for ${count} object(s) (${message}); ` + + 'those objects are NOT in the plan below.', + ); + } + + const total = (objects as unknown[]).length; + const coverage: SchemaMigrationCoverage = { + registeredObjects: total, + examinedObjects: examined, + unexaminedObjects: total - examined, + reasons: { federated, unbound, unsupported, otherDriver, failed }, + }; + + if (coverage.unexaminedObjects > 0) { + const why = [ + coverage.reasons.federated > 0 ? `${coverage.reasons.federated} federated (no managed table)` : null, + coverage.reasons.otherDriver > 0 ? `${coverage.reasons.otherDriver} bound to a different datasource` : null, + coverage.reasons.unbound > 0 ? `${coverage.reasons.unbound} bound to no driver` : null, + coverage.reasons.unsupported > 0 ? `${coverage.reasons.unsupported} on a driver without schema registration` : null, + coverage.reasons.failed > 0 ? `${coverage.reasons.failed} refused by their driver` : null, + ].filter((s): s is string => s !== null); + notes.push( + `Coverage: ${coverage.examinedObjects} of ${coverage.registeredObjects} declared object(s) are in the diffed set; ` + + `${coverage.unexaminedObjects} are NOT (${why.join(', ')}). The plan below is PARTIAL — an empty result over ` + + 'those objects is UNMEASURED, not "in sync".', + ); + } + + return { coverage, notes }; } diff --git a/packages/cli/test/migrate-plan-exits.e2e.test.ts b/packages/cli/test/migrate-plan-exits.e2e.test.ts new file mode 100644 index 0000000000..0214396c72 --- /dev/null +++ b/packages/cli/test/migrate-plan-exits.e2e.test.ts @@ -0,0 +1,166 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * #13027 — `os migrate plan` ENDS ITS PROCESS once the plan is printed. + * + * ## The measurement this inverts + * + * ObjectStack Cloud's `migrate-control-db.yml`, staging control plane, + * `apply=false`, inside `docker run --rm`. The CLI finished in 4.3 seconds and + * said so — `17 change(s)`, `Graceful shutdown started`, `Graceful shutdown + * complete` — and then the log's next line is the run being cancelled by hand + * **78 minutes later**. The shell's very next statement was an `echo` that + * never printed, so the shell was still blocked on that one `docker run`: the + * process had printed its own graceful-shutdown line and had not exited. + * + * The cause is structural, not incidental. The host composition (#12938) + * registers a host's plugins for their DECLARATIONS: `init()` runs, `start()` + * is replaced with a no-op. Anything a plugin arms during Phase 1 whose release + * would have been installed by Phase 2 now has no release path at all, and the + * event loop never drains. + * + * ## Why this file spawns a real process + * + * The defect IS process exit. An in-process test cannot observe it: vitest's + * worker is alive either way, and the handle that keeps a real CLI alive would + * simply keep the worker alive too — which reads as a slow test, not a failure. + * Nothing short of a child whose exit is awaited can distinguish "returned" from + * "did not return", which is exactly why the CLI's own suite was blind to a + * command that hung for 78 minutes in production. + * + * ## The fixture is the defect's own shape, not a stand-in + * + * `objectstack.config.ts` brings one plugin that acquires a REF'd interval in + * `init()` and would clear it in `start()`. That is the composed shape verbatim: + * `init()` runs, `start()` is suppressed, the timer holds the loop open, and the + * kernel still reports a clean shutdown. No import, so the config bundles with + * nothing installed in the fixture directory. + * + * ⛔ The interval is deliberately NOT `unref()`ed. An unref'd timer lets the + * process exit on its own and the test would pass against the unfixed CLI — + * a pin that cannot fail is the failure mode this file exists to prevent. + */ + +import { describe, it, expect } from 'vitest'; +import { spawn } from 'node:child_process'; +import { mkdtempSync, rmSync, writeFileSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import { CLI, childEnv } from './helpers/serve-process.js'; + +/** + * How long the child is allowed to take, end to end. + * + * The measured plan itself took 4.3 seconds against a remote Postgres; this + * fixture is an in-memory SQLite with one plugin, so the work is far smaller + * and the budget is dominated by tsx compiling the CLI's command tree on a + * cold worker. Generous on purpose — the defect being pinned is UNBOUNDED + * (78 minutes and still running), so any finite bound separates the two states + * and a tight one would only add flake. + */ +const EXIT_BUDGET_MS = 90_000; + +interface ChildOutcome { + code: number | null; + signal: NodeJS.Signals | null; + stdout: string; + stderr: string; + /** `true` when the budget expired and the child had to be killed. */ + timedOut: boolean; + elapsedMs: number; +} + +function runMigratePlan(cwd: string): Promise { + return new Promise((resolve) => { + const started = Date.now(); + const child = spawn( + process.execPath, + [CLI, 'migrate', 'plan', '--json'], + { + cwd, + env: childEnv({ + // No compiled artifact: the host config is the only deployment here. + OS_ARTIFACT_PATH: join(cwd, 'dist', 'objectstack.json'), + OS_DATABASE_URL: `file:${join(cwd, 'plan.db')}`, + NODE_ENV: 'production', + }), + stdio: ['ignore', 'pipe', 'pipe'], + }, + ); + + let stdout = ''; + let stderr = ''; + child.stdout.on('data', (c) => { stdout += String(c); }); + child.stderr.on('data', (c) => { stderr += String(c); }); + + let timedOut = false; + const timer = setTimeout(() => { + timedOut = true; + // SIGKILL, not SIGTERM: the process under test is one that does not end + // when its own work does, and a handler-swallowed SIGTERM would leave the + // test hanging on the very condition it is measuring. + child.kill('SIGKILL'); + }, EXIT_BUDGET_MS); + + child.on('close', (code, signal) => { + clearTimeout(timer); + resolve({ code, signal, stdout, stderr, timedOut, elapsedMs: Date.now() - started }); + }); + }); +} + +describe('os migrate plan exits once the plan is written (#13027)', () => { + it('returns from a composed host stack that armed an unreleasable handle in init()', async () => { + const dir = mkdtempSync(join(tmpdir(), 'os-13027-')); + try { + writeFileSync( + join(dir, 'objectstack.config.ts'), + [ + '// A host plugin in the shape the composition cannot release: the', + '// handle is acquired in `init()` and the only path that would clear', + '// it lives in `start()`, which a declaration-phase composition', + '// replaces with a no-op.', + 'let held: any = null;', + 'export default {', + ' plugins: [', + ' {', + " name: 'com.example.holds-the-loop-open',", + ' async init() {', + ' // REF\'d on purpose — an unref\'d timer would let the process', + ' // exit on its own and this pin could never fail.', + ' held = setInterval(() => { /* holds the event loop */ }, 1000);', + ' },', + ' async start() {', + ' if (held) clearInterval(held);', + ' },', + ' },', + ' ],', + '};', + '', + ].join('\n'), + ); + + const outcome = await runMigratePlan(dir); + + expect( + outcome.timedOut, + `os migrate plan did not exit within ${EXIT_BUDGET_MS}ms.\n` + + `--- stdout ---\n${outcome.stdout}\n--- stderr ---\n${outcome.stderr}`, + ).toBe(false); + // The command SUCCEEDED and then exited — not "exited because it crashed". + // Both halves matter: a non-zero code would make the exit meaningless as + // evidence that the success path returns. + expect(outcome.code, `stderr:\n${outcome.stderr}`).toBe(0); + expect(outcome.signal).toBeNull(); + + // And the document survived the exit — `process.exit` on an undrained + // stdout pipe truncates, which is the one way this fix could break the + // consumer it exists to unblock. + const payload = JSON.parse(outcome.stdout); + expect(payload).toHaveProperty('managedTables'); + expect(payload).toHaveProperty('composition'); + } finally { + try { rmSync(dir, { recursive: true, force: true }); } catch { /* ignore */ } + } + }, EXIT_BUDGET_MS + 30_000); +}); diff --git a/packages/drivers/driver-sql/src/sql-driver-deferred-ddl.test.ts b/packages/drivers/driver-sql/src/sql-driver-deferred-ddl.test.ts index f6afbb67aa..60b7bf61c6 100644 --- a/packages/drivers/driver-sql/src/sql-driver-deferred-ddl.test.ts +++ b/packages/drivers/driver-sql/src/sql-driver-deferred-ddl.test.ts @@ -212,3 +212,75 @@ describe('SqlDriver deferred schema DDL (#3917)', () => { }); }); }); + +/** + * #13028 — a deferred `initObjects` does not ensure the database EXISTS either. + * + * `ensureDatabaseExists()` is the one line in `initObjects` that can write + * while nothing else does: it `mkdir -p`s a sqlite parent directory and, on + * Postgres/MySQL, issues `SELECT 1` and CREATEs the database when that comes + * back `3D000` / `ER_BAD_DB_ERROR`. Under the deferral every DDL branch is + * skipped in favour of recording the work, so there is no DDL for a database + * to exist for — and #6743's promise ("a plan must not bring a database into + * existence") was only being kept for sqlite, by the CLI, one layer up. + * + * The cost half is why it is measured rather than merely tidied: `os migrate + * plan` on a composed control plane registers ~80 objects one call at a time, + * and a `SELECT 1` per call is ~80 round-trips against a database the command + * is never going to touch. + */ +describe('deferred initObjects does not ensure the database exists (#13028)', () => { + let driver: SqlDriver; + + afterEach(async () => { + await driver.disconnect(); + }); + + it('skips the probe while deferred', async () => { + driver = makeDriver(); + const calls: string[] = []; + (driver as any).ensureDatabaseExists = async () => { calls.push('ensure'); }; + + driver.setDeferredDdl(true); + await driver.initObjects([WIDGET]); + + expect(calls).toEqual([]); + // …and the registration the deferral exists to preserve still happened. + expect((driver as any).managedObjectFields.has('widgets')).toBe(true); + expect(driver.deferredSchemaObjectCount).toBe(1); + }); + + it('still runs it on a NON-deferred sync — the guarantee for real DDL is unchanged', async () => { + driver = makeDriver(); + const calls: string[] = []; + const real = (driver as any).ensureDatabaseExists.bind(driver); + (driver as any).ensureDatabaseExists = async () => { calls.push('ensure'); await real(); }; + + await driver.initObjects([WIDGET]); + + expect(calls).toEqual(['ensure']); + expect(await (driver as any).knex.schema.hasTable('widgets')).toBe(true); + }); + + it('runs it on the FLUSH, before the first CREATE TABLE', async () => { + driver = makeDriver(); + driver.setDeferredDdl(true); + await driver.initObjects([WIDGET]); + + // Instrumented only now, so what it records is about the flush alone. + const order: string[] = []; + const realEnsure = (driver as any).ensureDatabaseExists.bind(driver); + (driver as any).ensureDatabaseExists = async () => { + // Recorded together with the state of the world at that moment: "before + // the first CREATE TABLE" is the claim, and the table's absence here is + // what proves it rather than call ORDER alone. + order.push(`ensure(table=${await (driver as any).knex.schema.hasTable('widgets')})`); + await realEnsure(); + }; + + await driver.flushDeferredSchemaDdl(); + + expect(order).toEqual(['ensure(table=false)']); + expect(await (driver as any).knex.schema.hasTable('widgets')).toBe(true); + }); +}); diff --git a/packages/drivers/driver-sql/src/sql-driver.ts b/packages/drivers/driver-sql/src/sql-driver.ts index 0a9f80a27e..56c5e8ed14 100644 --- a/packages/drivers/driver-sql/src/sql-driver.ts +++ b/packages/drivers/driver-sql/src/sql-driver.ts @@ -9363,7 +9363,26 @@ export class SqlDriver implements IDataDriver { // DDL gate (ADR-0015 §5.1): createTable/alterTable below mutate schema. // Also covers `syncSchema`, which delegates here. this.assertSchemaMutable('initObjects'); - await this.ensureDatabaseExists(); + + // [#13028] …and NOT while DDL is deferred. Under {@link deferredDdl} every + // branch below is skipped in favour of recording the work, so there is no + // DDL for a database to exist FOR — while `ensureDatabaseExists()` is the + // one line here that can WRITE: it `mkdir -p`s a sqlite parent directory + // and, on Postgres/MySQL, issues `SELECT 1` and CREATEs THE DATABASE when + // that comes back `3D000` / `ER_BAD_DB_ERROR`. + // + // That made a declared dry run able to create a database (#6743 closed the + // sqlite half by opening an absent file in memory; this is the same + // promise, kept at the source and for every dialect), and it charged one + // round-trip per object to do it — on a control plane at ~300ms RTT × ~80 + // objects, a `plan` that computes in seconds would have spent minutes + // asking a database it was never going to touch whether it existed. + // + // ⛔ NOT a relaxation of the guarantee for real DDL: `flushDeferredSchemaDdl` + // clears `deferredDdl` BEFORE re-entering this method with the deferred + // objects, so the confirmed `os migrate apply` still ensures the database + // ahead of the first `CREATE TABLE`. + if (!this.deferredDdl) await this.ensureDatabaseExists(); for (const obj of objects) { // Re-read what the registration above recorded, rather than recomputing: