diff --git a/.changeset/26615-dev-upgrade-names-its-stop.md b/.changeset/26615-dev-upgrade-names-its-stop.md new file mode 100644 index 00000000000..3bb597188c8 --- /dev/null +++ b/.changeset/26615-dev-upgrade-names-its-stop.md @@ -0,0 +1,22 @@ +--- +'@objectstack/cli': patch +--- + +fix(cli): `os dev`'s in-place organization-ownership upgrade names what stopped it, and the exact command that carries on + +Clause-②: no +Metadata-protocol: none + +When the organization-ownership boot guard refuses a development database, `os dev` copies it and runs the ceremony on it in place. When that upgrade did not finish, it could exit with 「The upgrade did not run to a report」 and no cause. + +What changes: + +- The ceremony's own refusal is printed in its own words, also when the terminal forces colour (`FORCE_COLOR`): the refusal lines are read with colour stripped, and the `✗` glyph is no longer printed twice. +- An apply that stopped with no refusal of its own (an uncaught error, a crash, a signal) says how it ended and prints the end of its log, without the kernel's boot narration. +- A report file still holding the apply's reservation text, or one that does not parse, is read as "no report", with the cause, never as "a blocker (above)" with nothing above. A blocked report that names no blocker prints the log's cause too. +- A stale `organization_id` the plan gives the column-drop fate is upgraded as before, but no longer silently: before the apply runs, `os dev` prints per table how many stamped values the drop discards, and names the copy that keeps them. +- Each failed upgrade ends on the exact command that carries on: `os migrate organization-ownership --dev --database-url URL --apply --plan-file PLAN --backup-taken`, with the database and the plan the upgrade wrote. + +The copy taken before the upgrade is kept, as before. A development database with a stale `organization_id` column on `sys_flow_credential` and `sys_secret` (objects that no longer declare it) is upgraded and starts under `os dev`, now pinned by a test. The production ceremony is unchanged. + +What to do: nothing. diff --git a/packages/cli/src/commands/dev.ts b/packages/cli/src/commands/dev.ts index 45d1cece20d..477808cca43 100644 --- a/packages/cli/src/commands/dev.ts +++ b/packages/cli/src/commands/dev.ts @@ -941,6 +941,7 @@ export default class Dev extends Command { sqliteFile, env: localEnv, cwd: process.cwd(), + announce: (line) => console.log(chalk.yellow(` ⚠ ${line}`)), }); }, }); diff --git a/packages/cli/src/utils/dev-organization-ownership-upgrade.test.ts b/packages/cli/src/utils/dev-organization-ownership-upgrade.test.ts index 932c82412a4..a1433c77111 100644 --- a/packages/cli/src/utils/dev-organization-ownership-upgrade.test.ts +++ b/packages/cli/src/utils/dev-organization-ownership-upgrade.test.ts @@ -18,6 +18,7 @@ import { isOrganizationOwnershipRequiredMessage, ORGANIZATION_OWNERSHIP_REQUIRED_MESSAGE, upgradeDevelopmentDatabase, + type CeremonyRunEnd, type DevelopmentUpgradeInput, } from './dev-organization-ownership-upgrade.js'; @@ -29,20 +30,37 @@ const NOW = new Date('2026-10-16T10:00:00.000Z'); const BACKUP = (): string => join(dir, 'backups', 'organization-ownership-2026-10-16T10-00-00-000Z'); /** A fake CLI: answers `planCode`, and writes the files a real run writes. */ -function fakeRun(opts: { planCode?: number; report?: Record | null }): DevelopmentUpgradeInput['run'] { +function fakeRun(opts: { + planCode?: number; + report?: Record | null; + /** What the apply prints to its log, verbatim. */ + applyLog?: string; + /** How the apply ends, when not by its report's verdict. */ + applyEnd?: CeremonyRunEnd; + /** What the apply leaves at its `--out` path instead of a report. */ + applyFile?: string; + /** The plan file the plan run writes. */ + plan?: Record; +}): DevelopmentUpgradeInput['run'] { return (args, logFile) => { calls.push([...args]); const out = args[args.indexOf('--out') + 1]!; if (!args.includes('--apply')) { writeFileSync(logFile, opts.planCode ? ' ✗ Refused (sys_mystery): sys_mystery carries organization_id …\n' : 'planned\n', { flag: 'a' }); - if (!opts.planCode) writeFileSync(out, '{}'); - return opts.planCode ?? 0; + if (!opts.planCode) writeFileSync(out, JSON.stringify(opts.plan ?? {})); + return { status: opts.planCode ?? 0 }; } + if (opts.applyLog) writeFileSync(logFile, opts.applyLog, { flag: 'a' }); if (opts.report) writeFileSync(out, JSON.stringify(opts.report)); - return opts.report?.complete ? 0 : 1; + if (opts.applyFile !== undefined) writeFileSync(out, opts.applyFile); + return opts.applyEnd ?? { status: opts.report?.complete ? 0 : 1 }; }; } +/** The exact command every failed apply ends on: the plan this upgrade wrote, the database it opened. */ +const AGAIN = (): string => + `os migrate organization-ownership --dev --database-url file:${primary} --apply --plan-file ${join(BACKUP(), 'plan.json')} --backup-taken`; + const input = (run: DevelopmentUpgradeInput['run'], over: Partial = {}): DevelopmentUpgradeInput => ({ binPath: '/cli/bin/run.js', databaseUrl: `file:${primary}`, @@ -83,7 +101,8 @@ describe('os dev — the in-place upgrade of a v17-shape development database', const result = upgradeDevelopmentDatabase(input(fakeRun({ planCode: 1 }))); expect(result.ok).toBe(false); expect(calls).toHaveLength(1); - expect(result.lines[0]).toContain('✗ Refused (sys_mystery)'); + // The ceremony's own words; the `✗` glyph is the printer's, never doubled. + expect(result.lines[0]).toBe('Refused (sys_mystery): sys_mystery carries organization_id …'); expect(result.lines.at(-1)).toContain('nothing was changed'); expect(result.lines.at(-1)).toContain(BACKUP()); // The ceremony is open (18.x step 6): the way on is running it by hand. @@ -97,7 +116,7 @@ describe('os dev — the in-place upgrade of a v17-shape development database', }))); expect(result.ok).toBe(false); expect(result.lines[0]).toBe('authored-conversion: The authored permission x differs …'); - expect(result.lines.at(-1)).toContain(`--apply --plan-file ${join(BACKUP(), 'plan.json')} --backup-taken`); + expect(result.lines.at(-1)).toContain(AGAIN()); }); it('every step finished but the post-check holds an unattributable row: boots nothing, names the table, count and remedy', () => { @@ -130,6 +149,96 @@ describe('os dev — the in-place upgrade of a v17-shape development database', expect(result.lines[0]).not.toContain('17.x'); }); + it('⭐ a column drop that discards stamped values is said, per table, before the apply runs, and the upgrade completes', () => { + const announced: Array<{ line: string; callsSoFar: number }> = []; + const stamps = (rowsLosingTheirStamp: number) => ({ columnPresent: true, rowsLosingTheirStamp, rowsWithNullOrganization: 0 }); + const result = upgradeDevelopmentDatabase(input( + fakeRun({ + plan: { + tables: [ + { object: 'sys_flow_credential', fate: 'column-drop', fateCounts: stamps(0) }, + { object: 'sys_secret', fate: 'column-drop', fateCounts: stamps(3) }, + // Attribution keeps every stamp: nothing is discarded there. + { object: 'sys_job', fate: 'attribution', fateCounts: stamps(9) }, + ], + }, + report: { complete: true, blocking: 0, warnings: [], steps: [] }, + }), + { announce: (line) => announced.push({ line, callsSoFar: calls.length }) }, + )); + expect(result.ok).toBe(true); + expect(announced.map((a) => a.line)).toEqual([ + `sys_secret: the plan drops its retired organization_id column, discarding 3 stamped value(s); the copy in ${BACKUP()} keeps them.`, + ]); + // Said after the plan and before the apply. + expect(announced[0]!.callsSoFar).toBe(1); + expect(calls).toHaveLength(2); + }); + + describe('an apply that writes no report still names its cause, and the exact command that carries on', () => { + // A `FORCE_COLOR` terminal: chalk colours the refusal even into the log file. + const COLOURED = '\u001b[31m ✗ Refused: The plan file … was computed for the database A, and this run opened B.\u001b[39m\n'; + + it('⭐ a refusal printed in colour is read in the ceremony\'s own words', () => { + const result = upgradeDevelopmentDatabase(input(fakeRun({ applyLog: COLOURED, applyEnd: { status: 1 } }))); + expect(result.ok).toBe(false); + expect(result.lines[0]).toBe('Refused: The plan file … was computed for the database A, and this run opened B.'); + expect(result.lines.at(-1)).toContain('The upgrade did not run to a report.'); + expect(result.lines.at(-1)).toContain(AGAIN()); + expect(result.lines.at(-1)).toContain(BACKUP()); + }); + + it('an apply that stopped with no refusal of its own (an uncaught error) names how it ended and the end of its log', () => { + const log = + '2026-10-27T10:08:09.000Z INFO Bootstrap complete\n' + + ' → step column-drops…\n' + + '2026-10-27T10:08:10.000Z INFO Graceful shutdown started\n' + + ' Error: SQLITE_ERROR: error in index idx_sys_secret_organization_id after drop column\n'; + const result = upgradeDevelopmentDatabase(input(fakeRun({ applyLog: log, applyEnd: { status: 1 } }))); + expect(result.ok).toBe(false); + expect(result.lines[0]).toContain('exited with code 1 without a refusal of its own'); + expect(result.lines).toContain(' Error: SQLITE_ERROR: error in index idx_sys_secret_organization_id after drop column'); + expect(result.lines).toContain(' → step column-drops…'); + // The kernel's INFO narration is not the cause. + expect(result.lines.some((l) => l.includes('Bootstrap complete'))).toBe(false); + expect(result.lines.at(-1)).toContain(AGAIN()); + }); + + it('an apply ended by a signal says so', () => { + const result = upgradeDevelopmentDatabase(input(fakeRun({ applyEnd: { status: null, signal: 'SIGKILL' } }))); + expect(result.lines[0]).toContain('was ended by SIGKILL without a refusal of its own, and its log'); + expect(result.lines.at(-1)).toContain('The upgrade did not run to a report.'); + }); + + it('a report file still holding the apply\'s reservation text is no report: the cause is printed, not "a blocker (above)"', () => { + const reservation = JSON.stringify({ kind: 'organization-ownership-apply-reservation', reservedAt: '2026-10-27T10:08:09.000Z', note: '…' }); + const result = upgradeDevelopmentDatabase(input(fakeRun({ + applyLog: ' Error: the stack shut down mid-step\n', + applyEnd: { status: 1 }, + applyFile: reservation, + }))); + expect(result.ok).toBe(false); + expect(result.lines).toContain(' Error: the stack shut down mid-step'); + expect(result.lines.at(-1)).toContain('The upgrade did not run to a report.'); + expect(result.lines.join('\n')).not.toContain('a blocker (above)'); + }); + + it('a report file that does not parse is named, never thrown', () => { + const result = upgradeDevelopmentDatabase(input(fakeRun({ applyEnd: { status: 1 }, applyFile: '{"kind":"organization-own' }))); + expect(result.ok).toBe(false); + expect(result.lines.some((l) => l.startsWith(`Its report file ${join(BACKUP(), 'apply.json')} could not be read`))).toBe(true); + }); + + it('a blocked report that names no blocker prints the log\'s cause instead of an empty "above"', () => { + const result = upgradeDevelopmentDatabase(input(fakeRun({ + report: { complete: false, warnings: [], steps: [{ step: 'column-drops', status: 'blocked', blockers: [] }] }, + applyLog: ' ✗ The ceremony stopped at a blocker (above). Resolve it and re-run --apply; finished steps are not repeated. Report: …\n', + }))); + expect(result.lines[0]).toContain('The ceremony stopped at a blocker'); + expect(result.lines.at(-1)).toContain(AGAIN()); + }); + }); + it('the IPC message is recognised by its type alone', () => { expect(isOrganizationOwnershipRequiredMessage({ type: ORGANIZATION_OWNERSHIP_REQUIRED_MESSAGE, tables: ['sys_job'] })).toBe(true); expect(isOrganizationOwnershipRequiredMessage({ type: 'objectstack:listening', port: 3000 })).toBe(false); diff --git a/packages/cli/src/utils/dev-organization-ownership-upgrade.ts b/packages/cli/src/utils/dev-organization-ownership-upgrade.ts index c9f652245df..5815b103eae 100644 --- a/packages/cli/src/utils/dev-organization-ownership-upgrade.ts +++ b/packages/cli/src/utils/dev-organization-ownership-upgrade.ts @@ -1,8 +1,9 @@ // Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. import { spawnSync } from 'node:child_process'; -import { closeSync, copyFileSync, existsSync, mkdirSync, openSync, readFileSync } from 'node:fs'; +import { closeSync, copyFileSync, existsSync, mkdirSync, openSync, readFileSync, statSync } from 'node:fs'; import { basename, dirname, join } from 'node:path'; +import { stripVTControlCharacters } from 'node:util'; import { resolveTelemetryDbPath } from './telemetry-datasource.js'; /** @@ -38,8 +39,21 @@ import { resolveTelemetryDbPath } from './telemetry-datasource.js'; * step is printed, and so is each table the post-check holds (a row whose * owner cannot be derived among them, with its remedy), with where the copy * and the report are; nothing is guessed around it. + * - **Never a stop without its cause.** An upgrade that does not finish prints + * what stopped it: the ceremony's own refusal (its `✗` line, read with any + * colour stripped, so a `FORCE_COLOR` terminal reads the same words), each + * blocker of a blocked step, or — when the ceremony ended with no refusal of + * its own (an uncaught error, a crash, a signal) — how it ended and the end + * of its log. Then the exact command that carries on from the plan it wrote. * - **Once per session.** A boot refused again after a finished upgrade ends * `os dev`, naming the refusal; it never loops. + * - **No silent drop.** A stale `organization_id` the plan gives the + * column-drop fate is a column it accounts for (the object retired it, and + * the plan says its values go), so the upgrade proceeds; before the apply + * runs, it says per table how many stamped values the drop discards (the + * plan's `fateCounts.rowsLosingTheirStamp`), beside the copy that keeps + * them. A column the plan accounts for no fate of refuses the plan, which + * names the command (seat ruling 6446501014). * - **The warnings.** What the ceremony decided on the developer's behalf * (the plan's warnings) is printed, as the production ceremony prints it. */ @@ -71,8 +85,18 @@ export interface DevelopmentUpgradeInput { env: NodeJS.ProcessEnv; cwd: string; now?: Date; - /** Run one CLI invocation, its output appended to `logFile`; answers the exit code. Injected by tests. */ - run?: (args: readonly string[], logFile: string) => number; + /** Prints one line before the apply runs (what the plan's column drops discard). */ + announce?: (line: string) => void; + /** Run one CLI invocation, its output appended to `logFile`; answers how it ended. Injected by tests. */ + run?: (args: readonly string[], logFile: string) => CeremonyRunEnd; +} + +/** How one ceremony run ended: its exit code, or the signal that ended it, or why it never started. */ +export interface CeremonyRunEnd { + status: number | null; + signal?: string | null; + /** The spawn itself failed (`spawnSync`'s `error`): the run never started. */ + error?: string; } export interface DevelopmentUpgradeResult { @@ -87,7 +111,7 @@ export interface DevelopmentUpgradeResult { const CEREMONY = ['migrate', 'organization-ownership', '--dev'] as const; -function runCli(input: DevelopmentUpgradeInput): (args: readonly string[], logFile: string) => number { +function runCli(input: DevelopmentUpgradeInput): (args: readonly string[], logFile: string) => CeremonyRunEnd { return (args, logFile) => { const fd = openSync(logFile, 'a'); try { @@ -96,21 +120,105 @@ function runCli(input: DevelopmentUpgradeInput): (args: readonly string[], logFi env: input.env, stdio: ['ignore', fd, fd], }); - return result.status ?? 1; + return { + status: result.status, + signal: result.signal, + ...(result.error ? { error: result.error.message } : {}), + }; } finally { closeSync(fd); } }; } -/** The `✗` lines the ceremony printed: its refusal, in its own words. */ -function refusalLines(logFile: string): string[] { +/** Where the next run's output starts in the shared log. */ +function logOffset(logFile: string): number { + return existsSync(logFile) ? statSync(logFile).size : 0; +} + +/** One run's part of the ceremony's log, line by line, colour stripped and trimmed; empty lines dropped. */ +function logLines(logFile: string, from: number): string[] { if (!existsSync(logFile)) return []; - return readFileSync(logFile, 'utf8') + return readFileSync(logFile).subarray(from).toString('utf8') .split('\n') - .map((line) => line.trim()) - .filter((line) => line.startsWith('✗')) - .slice(-5); + .map((line) => stripVTControlCharacters(line).trim()) + .filter((line) => line.length > 0); +} + +/** The kernel's own timestamped log lines below a warning: boot narration, never the cause of a stop. */ +const NARRATION = /^\d{4}-\d{2}-\d{2}T[\d:.]+Z (?:TRACE|DEBUG|INFO) /; +const TAIL_LINES = 8; + +function describeEnd(end: CeremonyRunEnd): string { + if (end.error) return `could not be started (${end.error})`; + if (end.signal) return `was ended by ${end.signal}`; + return `exited with code ${end.status ?? 'unknown'}`; +} + +/** + * What stopped a ceremony run, in its own words: the `✗` lines it printed (its + * refusal; the glyph is the printer's), else how it ended and the end of its + * log — an uncaught error or a crash prints no `✗` line of the ceremony's own. + */ +function stopCause(logFile: string, from: number, command: string, end: CeremonyRunEnd): string[] { + const lines = logLines(logFile, from); + const refusals = lines.filter((line) => line.startsWith('✗')).map((line) => line.slice(1).trim()); + if (refusals.length > 0) return refusals.slice(-5); + const tail = lines.filter((line) => !NARRATION.test(line)).slice(-TAIL_LINES); + return [ + `\`${command}\` ${describeEnd(end)} without a refusal of its own${tail.length ? '; the end of its log:' : ', and its log is empty.'}`, + ...tail.map((line) => ` ${line}`), + ]; +} + +/** The apply's `--out` file, as the dev upgrade reads it. */ +type ApplyOutcome = + | { kind: 'report'; report: ApplyReport } + /** The file the apply reserves before its boot, still holding its reservation text: the run stopped before its report. */ + | { kind: 'reserved' } + | { kind: 'absent' } + | { kind: 'unreadable'; detail: string }; + +interface ApplyReport { + kind?: string; + complete?: boolean; + blocking?: number; + warnings?: string[]; + steps?: Array<{ step: string; status: string; blockers?: string[] }>; + tables?: Array<{ object: string; remaining?: number; held?: { rows: number; remedy: string } }>; +} + +function readApplyOutcome(applyFile: string): ApplyOutcome { + if (!existsSync(applyFile)) return { kind: 'absent' }; + let parsed: ApplyReport; + try { + parsed = JSON.parse(readFileSync(applyFile, 'utf8')) as ApplyReport; + } catch (error) { + return { kind: 'unreadable', detail: (error as Error).message }; + } + if (parsed?.kind === 'organization-ownership-apply-reservation') return { kind: 'reserved' }; + return { kind: 'report', report: parsed }; +} + +/** + * What each column drop of the plan discards: a table given the column-drop + * fate whose stale organization column still holds stamped values. Read from + * the plan file the ceremony wrote; a plan it cannot read names nothing here + * (the apply reads the same file and refuses it in its own words). + */ +function discardedStamps(planFile: string): Array<{ object: string; rows: number }> { + let plan: { tables?: Array<{ object?: unknown; fate?: unknown; fateCounts?: { rowsLosingTheirStamp?: unknown } }> }; + try { + plan = JSON.parse(readFileSync(planFile, 'utf8')) as typeof plan; + } catch { + return []; + } + return (plan.tables ?? []).flatMap((t) => { + const rows = t.fateCounts?.rowsLosingTheirStamp; + return t.fate === 'column-drop' && typeof t.object === 'string' && typeof rows === 'number' && rows > 0 + ? [{ object: t.object, rows }] + : []; + }); } /** @@ -145,33 +253,44 @@ export function upgradeDevelopmentDatabase(input: DevelopmentUpgradeInput): Deve const applyFile = join(backupDir, 'apply.json'); const kept = `The database as it was before the upgrade is copied to ${backupDir}, beside the ceremony's log.`; - const planned = run([...CEREMONY, '--database-url', input.databaseUrl, '--out', planFile], log); - if (planned !== 0 || !existsSync(planFile)) { + const planArgs = [...CEREMONY, '--database-url', input.databaseUrl, '--out', planFile]; + const planned = run(planArgs, log); + const applyFrom = logOffset(log); + if (planned.status !== 0 || !existsSync(planFile)) { return { ok: false, backupDir, warnings: [], - lines: [...refusalLines(log), `The upgrade plan was refused, and nothing was changed. ${kept} ${manual}`], + lines: [...stopCause(log, 0, `os ${planArgs.slice(0, 3).join(' ')}`, planned), `The upgrade plan was refused, and nothing was changed. ${kept} ${manual}`], }; } - run([...CEREMONY, '--database-url', input.databaseUrl, '--apply', '--plan-file', planFile, '--backup-taken', '--out', applyFile], log); - if (!existsSync(applyFile)) { + // The exact command that carries on from the plan this upgrade wrote: the + // apply resumes from its checkpoint, and finished steps are not repeated. + const again = + `\`os migrate organization-ownership --dev --database-url ${input.databaseUrl} --apply --plan-file ${planFile} --backup-taken\``; + for (const { object, rows } of discardedStamps(planFile)) { + input.announce?.( + `${object}: the plan drops its retired organization_id column, discarding ${rows} stamped value(s); ` + + `the copy in ${backupDir} keeps them.`, + ); + } + const applied = run([...CEREMONY, '--database-url', input.databaseUrl, '--apply', '--plan-file', planFile, '--backup-taken', '--out', applyFile], log); + const outcome = readApplyOutcome(applyFile); + if (outcome.kind !== 'report') { return { ok: false, backupDir, warnings: [], - lines: [...refusalLines(log), `The upgrade did not run to a report. ${kept} ${manual}`], + lines: [ + ...stopCause(log, applyFrom, 'os migrate organization-ownership --dev --apply', applied), + ...(outcome.kind === 'unreadable' ? [`Its report file ${applyFile} could not be read: ${outcome.detail}.`] : []), + `The upgrade did not run to a report. ${kept} Run ${again} to see the ceremony stop on this terminal, ` + + 'resolve what it names, and start os dev again — or restore the copy.', + ], }; } - const report = JSON.parse(readFileSync(applyFile, 'utf8')) as { - complete?: boolean; - blocking?: number; - warnings?: string[]; - steps?: Array<{ step: string; status: string; blockers?: string[] }>; - tables?: Array<{ object: string; remaining?: number; held?: { rows: number; remedy: string } }>; - }; + const { report } = outcome; const warnings = report.warnings ?? []; - const again = `\`os migrate organization-ownership --dev --apply --plan-file ${planFile} --backup-taken\``; if (report.complete && report.blocking !== 0) { // Every step finished and the post-check still holds rows: the marker is // not verified, so the guard would refuse the boot again. @@ -199,13 +318,16 @@ export function upgradeDevelopmentDatabase(input: DevelopmentUpgradeInput): Deve lines: [`Upgraded the development database to the v18 organization ownership. ${kept} The plan and the report are there too.`], }; } - const blocked = (report.steps ?? []).filter((s) => s.status === 'blocked'); + const blockers = (report.steps ?? []) + .filter((s) => s.status === 'blocked') + .flatMap((s) => (s.blockers ?? []).map((b) => `${s.step}: ${b}`)); return { ok: false, backupDir, warnings, lines: [ - ...blocked.flatMap((s) => (s.blockers ?? []).map((b) => `${s.step}: ${b}`)), + // A report that names no blocker still had a cause: the ceremony's log says it. + ...(blockers.length > 0 ? blockers : stopCause(log, applyFrom, 'os migrate organization-ownership --dev --apply', applied)), `The upgrade stopped at a blocker (above); every finished step is checkpointed. ${kept} Resolve it, then run ` + `${again} — or restore the copy.`, ], diff --git a/packages/cli/test/dev-organization-ownership-stale-column.integration.test.ts b/packages/cli/test/dev-organization-ownership-stale-column.integration.test.ts new file mode 100644 index 00000000000..86f868cfef1 --- /dev/null +++ b/packages/cli/test/dev-organization-ownership-stale-column.integration.test.ts @@ -0,0 +1,282 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * #26615 — the card's third target, run against the BUILT CLI: a development + * database with a stale physical `organization_id` column on an object that no + * longer declares one starts under a plain `os dev`, after the automatic + * in-place upgrade (ADR-0131 D10, development exception). + * + * ## The fixture + * + * The shape an 18.0 pre-release left a development database in: the two + * objects the card names, `sys_flow_credential` (`service-automation`, composed + * by `requires: ['automation']`) and `sys_secret`, each with the + * `organization_id` column and the `idx__organization_id` index the + * tenant-column injection gave every table before both declared + * `systemFields: { tenant: false }`; a `sys_secret` row still stamped with the + * Default Organization (a 17.x write) and a `sys_flow_credential` row with no + * stamp; and no organization-ownership marker in `sys_migration` (those + * releases wrote none). It is staged on a database a fresh `os dev` of this tree created, so + * every other table is the shape this release expects — the guard refuses for + * the two columns and the absent marker alone. + * + * ## What it pins + * + * - the refused boot is upgraded in place and the server starts on it: the + * verdict line, then the server's own start line; + * - the stamped value the `sys_secret` drop discards is said before the apply + * runs, with its count, and the unstamped table is not named (seat ruling + * 6446501014: the plan's column-drop fate accounts for the column, so the + * upgrade proceeds, loudly); + * - the two columns are gone, and the marker the guard reads is verified; + * - the copy taken before the upgrade is kept, with the columns still in it. + * + * The card's reported stop (「The upgrade did not run to a report」 with no + * cause) did not reproduce on this fixture, nor on an authentic HotCRM + * database of 2026-10-16 under the published 18.2.0; what that path prints now + * — the ceremony's own refusal, else how it ended and the end of its log — is + * `src/utils/dev-organization-ownership-upgrade.test.ts`'s subject. + * + * ## Spawn shape + * + * `bin/run.js` with `NODE_ENV` unset, as `dev-standalone-self-heal` does — the + * shipped entry, resolving commands from `dist/` (`requireBuiltCli`); `os dev` + * runs the ceremony through the same entry (`process.argv[1]`). One process + * group per boot. Every boot runs in `beforeAll` and every `it` reads what it + * recorded. + */ + +import { describe, it, expect, beforeAll, afterAll } from 'vitest'; +import { spawn, type ChildProcess } from 'node:child_process'; +import { existsSync, mkdtempSync, readdirSync, rmSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join, resolve } from 'node:path'; +import { fileURLToPath } from 'node:url'; +import Database from 'better-sqlite3'; +import { + childEnv, + E2E_SECRET_KEY, + KERNEL_ASSIGNED_PORT, + readKernelAssignedPort, + requireBuiltCli, + RUN_JS_RESOLVES_FROM_DIST, +} from './helpers/serve-process.js'; +import { writeDefineStackConfig } from './helpers/define-stack-fixture.js'; + +const HERE = resolve(fileURLToPath(import.meta.url), '..'); +/** `bin/run.js` — the SHIPPED entrypoint. */ +const CLI = resolve(HERE, '../bin/run.js'); + +/** The banner's tail — every row above it has printed. */ +const READY = /Press Ctrl\+C to stop/; +/** The parent's line once the first child after the upgrade is listening. */ +const UPGRADED_READY = /server started on the upgraded database/; +const BOOT_TIMEOUT_MS = 180_000; +const ALL_BOOTS_TIMEOUT_MS = 2 * (BOOT_TIMEOUT_MS + 30_000); + +const STALE = ['sys_flow_credential', 'sys_secret'] as const; +const MARKER = 'adr-0131-organization-ownership'; + +/** One object, and the automation service whose plugin declares `sys_flow_credential`. */ +const SCAFFOLD = { + manifest: { id: 'com.example.stale-org', namespace: 'stale', version: '1.0.0', type: 'app', name: 'stale' }, + requires: ['automation'], + objects: [{ + name: 'stale_item', + label: 'Item', + sharingModel: 'private', + fields: { title: { type: 'text', label: 'Title' } }, + }], +}; + +const groups: ChildProcess[] = []; +let dir: string; +let db: string; +let staged = false; +let upgradeOutput: string | Error = new Error('the upgrade boot was never run'); + +function hasOrganizationColumn(file: string, table: string): boolean { + const handle = new Database(file, { readonly: true }); + try { + return (handle.prepare(`PRAGMA table_info("${table}")`).all() as Array<{ name: string }>).some((c) => c.name === 'organization_id'); + } finally { + handle.close(); + } +} + +/** The pre-release shape: the injected column and its index on both objects, one stamped row, no marker. */ +function stagePreReleaseShape(): void { + const handle = new Database(db); + try { + for (const table of STALE) { + handle.exec(`ALTER TABLE "${table}" ADD COLUMN "organization_id" varchar(255)`); + handle.exec(`CREATE INDEX "idx_${table}_organization_id" ON "${table}" ("organization_id")`); + } + const organization = handle.prepare('SELECT id FROM sys_organization ORDER BY id LIMIT 1').get() as { id: string } | undefined; + if (!organization) throw new Error('the fresh boot created no Default Organization to stamp the stale row with'); + handle + .prepare('INSERT INTO sys_secret (id, namespace, key, ciphertext, organization_id) VALUES (?, ?, ?, ?, ?)') + .run('sec_stale', 'setting', 'stale.key', 'x', organization.id); + handle + .prepare('INSERT INTO sys_flow_credential (id, flow_name, state, node_id, credential_key, position, value) VALUES (?, ?, ?, ?, ?, ?, ?)') + .run('fc_stale', 'stale_flow', 'active', 'n1', 'token', 'p1', 'secret:sec_stale'); + handle.prepare('DELETE FROM sys_migration WHERE id = ?').run(MARKER); + } finally { + handle.close(); + } +} + +/** + * Boot `os dev` until `ready` matches, then stop the whole group and return what it printed. + * `-p KERNEL_ASSIGNED_PORT` (#24295); nothing here talks to the port. + */ +function bootUntil(ready: RegExp): Promise { + return new Promise((resolveBoot, rejectBoot) => { + const child = spawn(process.execPath, [CLI, 'dev', '--no-watch', '-d', 'file:A.db', '-p', KERNEL_ASSIGNED_PORT], { + cwd: dir, + // `childEnv`, never a bare `...process.env` — see its header. `NODE_ENV` + // unset, so the built entry resolves its commands from `dist/`. + env: childEnv({ + NO_COLOR: '1', + OS_CLOUD_URL: 'off', + OS_DISABLE_CONSOLE: '1', + OS_SECRET_KEY: E2E_SECRET_KEY, + OS_TELEMETRY_DB: '0', + OS_DATABASE_URL: undefined, + OS_ARTIFACT_URL: undefined, + OS_ARTIFACT_PATH: undefined, + OS_MODE: undefined, + NODE_ENV: undefined, + }), + stdio: ['ignore', 'pipe', 'pipe'], + // Own process group: `dev` supervises a `serve` grandchild. + detached: true, + }); + groups.push(child); + let out = ''; + let settled = false; + const finish = (err: Error | null) => { + if (settled) return; + settled = true; + clearTimeout(timer); + if (err) { + stopGroup(child).then(() => rejectBoot(err), () => rejectBoot(err)); + return; + } + // Stop BEFORE the file is read: the boot's own writes are flushed on exit. + stopGroup(child).then(() => resolveBoot(out), rejectBoot); + }; + const timer = setTimeout( + () => finish(new Error(`os dev never printed ${ready}\n--- output ---\n${out.slice(-6000)}`)), + BOOT_TIMEOUT_MS, + ); + const onData = (d: unknown) => { + out += String(d); + if (!ready.test(out) || !READY.test(out)) return; + const bound = readKernelAssignedPort(out, 'os dev'); + finish(bound instanceof Error ? bound : null); + }; + child.stdout?.on('data', onData); + child.stderr?.on('data', onData); + child.on('exit', (code) => + finish(new Error(`os dev exited ${String(code)} before ${ready}\n--- output ---\n${out.slice(-6000)}`)), + ); + }); +} + +async function stopGroup(child: ChildProcess): Promise { + if (child.pid === undefined || child.exitCode !== null || child.signalCode !== null) return; + await new Promise((done) => { + const give = setTimeout(() => { + try { process.kill(-child.pid!, 'SIGKILL'); } catch { /* group already gone */ } + done(); + }, 15_000); + child.once('exit', () => { clearTimeout(give); done(); }); + try { process.kill(-child.pid!, 'SIGTERM'); } catch { clearTimeout(give); done(); } + }); +} + +function upgraded(): string { + if (upgradeOutput instanceof Error) throw upgradeOutput; + return upgradeOutput; +} + +/** The copy the upgrade kept: `backups/organization-ownership-/` beside the database. */ +function backupDir(): string { + const root = join(dir, 'backups'); + const dirs = existsSync(root) ? readdirSync(root).filter((d) => d.startsWith('organization-ownership-')) : []; + expect(dirs, `backups: ${dirs.join(', ')}`).toHaveLength(1); + return join(root, dirs[0]!); +} + +beforeAll(async () => { + requireBuiltCli(RUN_JS_RESOLVES_FROM_DIST); + dir = mkdtempSync(join(tmpdir(), 'os-26615-dev-')); + writeDefineStackConfig(dir, SCAFFOLD); + db = join(dir, 'A.db'); + + // Boot 1: a fresh `os dev` creates every table this release declares. + await bootUntil(READY); + if (!existsSync(db)) return; + stagePreReleaseShape(); + staged = true; + + // Boot 2: the developer's `os dev` after pulling main — refused, upgraded, started. + try { + upgradeOutput = await bootUntil(UPGRADED_READY); + } catch (error) { + upgradeOutput = error instanceof Error ? error : new Error(String(error)); + } +}, ALL_BOOTS_TIMEOUT_MS); + +afterAll(async () => { + for (const child of groups) await stopGroup(child); + try { rmSync(dir, { recursive: true, force: true }); } catch { /* ignore */ } +}); + +describe('#26615 — `os dev` starts a development database with a stale organization_id on objects that retired it', () => { + it('the fixture is the pre-release shape: both columns staged', () => { + expect(staged, 'the fresh boot created no A.db').toBe(true); + }); + + it('⭐ the refused boot is upgraded in place and the server starts on it', () => { + const output = upgraded(); + expect(output).toContain('organization-ownership boot guard refused this development database'); + expect(output).toContain('Upgraded the development database to the v18 organization ownership.'); + expect(output).not.toContain('The upgrade did not run to a report'); + expect(output).toMatch(UPGRADED_READY); + }); + + it('the stamped value the drop discards is said, with its count, before the apply runs', () => { + const output = upgraded(); + const said = output.indexOf('sys_secret: the plan drops its retired organization_id column, discarding 1 stamped value(s)'); + expect(said, output.slice(-4000)).toBeGreaterThan(-1); + expect(said).toBeLessThan(output.indexOf('Upgraded the development database')); + // The unstamped table discards nothing, so it is not named. + expect(output).not.toContain('sys_flow_credential: the plan drops'); + }); + + it('both stale columns are dropped, and the marker the guard reads is verified', () => { + upgraded(); + for (const table of STALE) expect(hasOrganizationColumn(db, table), table).toBe(false); + const handle = new Database(db, { readonly: true }); + try { + const marker = handle.prepare('SELECT verified_at FROM sys_migration WHERE id = ?').get(MARKER) as + | { verified_at: string | null } + | undefined; + expect(marker?.verified_at, 'no verified organization-ownership marker').toBeTruthy(); + // The rows themselves are kept: only the column the objects retired went. + expect(handle.prepare('SELECT id FROM sys_secret WHERE id = ?').get('sec_stale')).toBeTruthy(); + expect(handle.prepare('SELECT id FROM sys_flow_credential WHERE id = ?').get('fc_stale')).toBeTruthy(); + } finally { + handle.close(); + } + }); + + it('the copy taken before the upgrade is kept, with the stale columns still in it', () => { + upgraded(); + const copy = backupDir(); + expect(readdirSync(copy)).toEqual(expect.arrayContaining(['A.db', 'plan.json', 'apply.json', 'ceremony.log'])); + for (const table of STALE) expect(hasOrganizationColumn(join(copy, 'A.db'), table), table).toBe(true); + }); +}); diff --git a/scripts/check-cli-test-child-env.mjs b/scripts/check-cli-test-child-env.mjs index e10633d0aee..be1ba8da4ad 100644 --- a/scripts/check-cli-test-child-env.mjs +++ b/scripts/check-cli-test-child-env.mjs @@ -2635,13 +2635,19 @@ export function selfTest() { .filter((abs) => builtEntrypointSpawns(abs, readFileSync(abs, 'utf8')).spawns > 0) .map((abs) => relative(REPO_ROOT, abs).split(sep).join('/')) .sort(); - t('the built-entrypoint population is exactly the seventeen files that spawn bin/run.js', + t('the built-entrypoint population is exactly the eighteen files that spawn bin/run.js', JSON.stringify(builtFiles) === JSON.stringify([ // [#26130] Joined the population deliberately: its subject is a plain // `os dev` boot that compiles before it serves, measured on the BUILT // packages the way `dev-standalone-self-heal` measures its `os dev` // boots. Its spawn hands the child `NODE_ENV: undefined`. 'packages/cli/test/dev-connector-env-parity.integration.test.ts', + // [#26615] Joined the population deliberately, beside + // `dev-standalone-self-heal`: its subject is a plain `os dev` whose + // refused boot runs the organization-ownership ceremony through the + // SAME entry (`process.argv[1]`), measured on the BUILT packages. Its + // spawn hands the child `NODE_ENV: undefined`. + 'packages/cli/test/dev-organization-ownership-stale-column.integration.test.ts', // [#21733] Joined the population deliberately: the card's acceptance is // a plain `os dev` restart on the BUILT packages, and its production leg // (`os serve` with `NODE_ENV` unset must NOT auto-migrate) is only