From debcc2c96affaa8face3e2139a2146d1e2ee3a4e Mon Sep 17 00:00:00 2001 From: Claude Date: Tue, 27 Oct 2026 15:03:42 +0000 Subject: [PATCH 1/2] fix(cli): os dev's in-place organization-ownership upgrade names what stopped it When the boot guard refuses a development database, os dev copies it and runs the ceremony in place. An apply that wrote no report ended on "The upgrade did not run to a report" with no cause whenever the ceremony's refusal was coloured (FORCE_COLOR), or the apply stopped with no refusal of its own (an uncaught error, a crash, a signal), or it left its reservation text in the report file. The upgrade now reads the ceremony's log with colour stripped, from where each run started, and prints the refusal in the ceremony's own words, or how the run ended and the end of its log. Every failed upgrade ends on the exact command that carries on from the plan it wrote. A real os dev test pins a database with a stale organization_id on sys_flow_credential and sys_secret starting after the automatic upgrade. Co-authored-by: Claude Claude-Session: https://claude.ai/code/session_01FEkQ5pVM4YkXVkL6VgUUhP --- .../26615-dev-upgrade-names-its-stop.md | 21 ++ ...dev-organization-ownership-upgrade.test.ts | 91 +++++- .../dev-organization-ownership-upgrade.ts | 140 ++++++++-- ...ownership-stale-column.integration.test.ts | 264 ++++++++++++++++++ scripts/check-cli-test-child-env.mjs | 8 +- 5 files changed, 491 insertions(+), 33 deletions(-) create mode 100644 .changeset/26615-dev-upgrade-names-its-stop.md create mode 100644 packages/cli/test/dev-organization-ownership-stale-column.integration.test.ts 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..4a960e93b99 --- /dev/null +++ b/.changeset/26615-dev-upgrade-names-its-stop.md @@ -0,0 +1,21 @@ +--- +'@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. +- 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/utils/dev-organization-ownership-upgrade.test.ts b/packages/cli/src/utils/dev-organization-ownership-upgrade.test.ts index 932c82412a4..7ec5a24bc19 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,35 @@ 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; +}): 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; + 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 +99,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 +114,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 +147,70 @@ describe('os dev — the in-place upgrade of a v17-shape development database', expect(result.lines[0]).not.toContain('17.x'); }); + 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..b81529a6a8e 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,6 +39,12 @@ 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. * - **The warnings.** What the ceremony decided on the developer's behalf @@ -71,8 +78,16 @@ 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; + /** 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 +102,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 +111,84 @@ 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 }; } /** @@ -145,33 +223,38 @@ 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\``; + 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 +282,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..384b7685ca5 --- /dev/null +++ b/packages/cli/test/dev-organization-ownership-stale-column.integration.test.ts @@ -0,0 +1,264 @@ +// 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 }`, holding rows written 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 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, unstamped rows, 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")`); + } + handle.prepare('INSERT INTO sys_secret (id, namespace, key, ciphertext) VALUES (?, ?, ?, ?)').run('sec_stale', 'setting', 'stale.key', 'x'); + 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('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 From 74e75e381c7f4f1d82ad9cbd941f1951f0840561 Mon Sep 17 00:00:00 2001 From: Claude Date: Tue, 27 Oct 2026 15:48:02 +0000 Subject: [PATCH 2/2] fix(cli): os dev says what each column drop of the upgrade discards before it runs Seat ruling 6446501014 (option C): a stale organization_id the plan gives the column-drop fate is a column the plan accounts for, so the dev upgrade proceeds, but never silently. After the plan and before the apply, os dev prints per table how many stamped values the drop discards (the plan's fateCounts.rowsLosingTheirStamp) and names the copy that keeps them. Pinned by a unit case and by the real os dev fixture, whose sys_secret row is now stamped. Co-authored-by: Claude Claude-Session: https://claude.ai/code/session_01FEkQ5pVM4YkXVkL6VgUUhP --- .../26615-dev-upgrade-names-its-stop.md | 1 + packages/cli/src/commands/dev.ts | 1 + ...dev-organization-ownership-upgrade.test.ts | 30 +++++++++++++++- .../dev-organization-ownership-upgrade.ts | 36 +++++++++++++++++++ ...ownership-stale-column.integration.test.ts | 28 ++++++++++++--- 5 files changed, 90 insertions(+), 6 deletions(-) diff --git a/.changeset/26615-dev-upgrade-names-its-stop.md b/.changeset/26615-dev-upgrade-names-its-stop.md index 4a960e93b99..3bb597188c8 100644 --- a/.changeset/26615-dev-upgrade-names-its-stop.md +++ b/.changeset/26615-dev-upgrade-names-its-stop.md @@ -14,6 +14,7 @@ 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. 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 7ec5a24bc19..a1433c77111 100644 --- a/packages/cli/src/utils/dev-organization-ownership-upgrade.test.ts +++ b/packages/cli/src/utils/dev-organization-ownership-upgrade.test.ts @@ -39,13 +39,15 @@ function fakeRun(opts: { 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, '{}'); + if (!opts.planCode) writeFileSync(out, JSON.stringify(opts.plan ?? {})); return { status: opts.planCode ?? 0 }; } if (opts.applyLog) writeFileSync(logFile, opts.applyLog, { flag: 'a' }); @@ -147,6 +149,32 @@ 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'; diff --git a/packages/cli/src/utils/dev-organization-ownership-upgrade.ts b/packages/cli/src/utils/dev-organization-ownership-upgrade.ts index b81529a6a8e..5815b103eae 100644 --- a/packages/cli/src/utils/dev-organization-ownership-upgrade.ts +++ b/packages/cli/src/utils/dev-organization-ownership-upgrade.ts @@ -47,6 +47,13 @@ import { resolveTelemetryDbPath } from './telemetry-datasource.js'; * 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. */ @@ -78,6 +85,8 @@ export interface DevelopmentUpgradeInput { env: NodeJS.ProcessEnv; cwd: string; now?: Date; + /** 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; } @@ -191,6 +200,27 @@ function readApplyOutcome(applyFile: string): ApplyOutcome { 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 }] + : []; + }); +} + /** * Upgrade the development database in place: copy it, plan, apply the plan. * Synchronous on purpose — nothing else may open the files while it runs. @@ -238,6 +268,12 @@ export function upgradeDevelopmentDatabase(input: DevelopmentUpgradeInput): Deve // 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') { 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 index 384b7685ca5..86f868cfef1 100644 --- a/packages/cli/test/dev-organization-ownership-stale-column.integration.test.ts +++ b/packages/cli/test/dev-organization-ownership-stale-column.integration.test.ts @@ -13,9 +13,10 @@ * 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 }`, holding rows written 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 + * `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. * @@ -23,6 +24,10 @@ * * - 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. * @@ -99,7 +104,7 @@ function hasOrganizationColumn(file: string, table: string): boolean { } } -/** The pre-release shape: the injected column and its index on both objects, unstamped rows, no marker. */ +/** 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 { @@ -107,7 +112,11 @@ function stagePreReleaseShape(): void { handle.exec(`ALTER TABLE "${table}" ADD COLUMN "organization_id" varchar(255)`); handle.exec(`CREATE INDEX "idx_${table}_organization_id" ON "${table}" ("organization_id")`); } - handle.prepare('INSERT INTO sys_secret (id, namespace, key, ciphertext) VALUES (?, ?, ?, ?)').run('sec_stale', 'setting', 'stale.key', 'x'); + 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'); @@ -238,6 +247,15 @@ describe('#26615 — `os dev` starts a development database with a stale organiz 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);