diff --git a/src/core/migrate.ts b/src/core/migrate.ts index 7b95a5767..1e42a958f 100644 --- a/src/core/migrate.ts +++ b/src/core/migrate.ts @@ -135,7 +135,10 @@ export const MIGRATIONS: Migration[] = [ } } } - if (renamed > 0) console.log(` Renamed ${renamed} slugs`); + // Migration progress goes to stderr — stdout must stay clean for + // callers parsing JSON (e.g. `gbrain doctor --json | jq`); migrations + // can run lazily inside ANY command's first DB connect. + if (renamed > 0) process.stderr.write(` Renamed ${renamed} slugs\n`); }, }, { @@ -5572,7 +5575,10 @@ export const MIGRATIONS: Migration[] = [ await engine.executeRaw(recreateChunksFn); if (lang === 'english') { - console.log(` v123: trigger functions recreated with language='english' (default — no backfill needed)`); + // stderr, NOT stdout: migrations run lazily inside any command's + // first DB connect — a console.log here polluted `doctor --json` + // stdout and broke jq consumers (heavy-tests fm_wallclock). + process.stderr.write(` v123: trigger functions recreated with language='english' (default — no backfill needed)\n`); return; } @@ -5593,7 +5599,7 @@ export const MIGRATIONS: Migration[] = [ WHERE search_vector IS NOT NULL; `); - console.log(` v123: trigger functions recreated with language='${lang}' + backfilled existing rows`); + process.stderr.write(` v123: trigger functions recreated with language='${lang}' + backfilled existing rows\n`); }, }, ]; diff --git a/test/migrate-stdout-clean.test.ts b/test/migrate-stdout-clean.test.ts new file mode 100644 index 000000000..f33e194b0 --- /dev/null +++ b/test/migrate-stdout-clean.test.ts @@ -0,0 +1,68 @@ +/** + * Migrations must never write to stdout — regression for the heavy-tests + * fm_wallclock failure (run 29731426470). + * + * Migrations run lazily inside ANY command's first DB connect (initSchema → + * runMigrations), including JSON-emitting commands like `gbrain doctor --json`. + * The v123 FTS migration (#2941) printed its completion notice via + * `console.log`, which landed as the first line of `doctor --json` stdout and + * broke every jq consumer ("Invalid numeric literal at line 1, column 7"). + * runMigrations' own contract (see the comment above its progress writes) + * routes ALL migration noise to stderr. + */ + +import { describe, test, expect, beforeAll, afterAll } from 'bun:test'; +import { readFileSync } from 'node:fs'; +import { join } from 'node:path'; +import { PGLiteEngine } from '../src/core/pglite-engine.ts'; +import { runMigrations } from '../src/core/migrate.ts'; + +describe('migration output stays off stdout', () => { + let engine: PGLiteEngine; + + beforeAll(async () => { + engine = new PGLiteEngine(); + await engine.connect({}); + await engine.initSchema(); + }); + + afterAll(async () => { + await engine.disconnect(); + }); + + test('re-running pending migrations (v122 → latest) writes nothing to stdout', async () => { + // Rewind the version stamp so the v123 handler actually re-executes — + // the exact state a CI Postgres/older brain is in when doctor connects. + await engine.setConfig('version', '122'); + + const stdoutWrites: string[] = []; + const origWrite = process.stdout.write.bind(process.stdout); + const origLog = console.log; + process.stdout.write = ((chunk: unknown, ...rest: unknown[]) => { + stdoutWrites.push(String(chunk)); + return (origWrite as (...a: unknown[]) => boolean)(chunk, ...rest); + }) as typeof process.stdout.write; + console.log = (...args: unknown[]) => { stdoutWrites.push(args.map(String).join(' ')); }; + + try { + const res = await runMigrations(engine); + // Load-bearing: the migration must have actually run for the stdout + // assertion to prove anything. + expect(res.applied).toBeGreaterThanOrEqual(1); + } finally { + process.stdout.write = origWrite; + console.log = origLog; + } + + expect(stdoutWrites).toEqual([]); + }, 60000); + + test('migrate.ts contains no console.log (all migration noise goes to stderr)', () => { + const src = readFileSync(join(import.meta.dir, '../src/core/migrate.ts'), 'utf8'); + const offenders = src + .split('\n') + .map((line, i) => ({ line, n: i + 1 })) + .filter(({ line }) => line.includes('console.log(')); + expect(offenders).toEqual([]); + }); +}); diff --git a/tests/heavy/frontmatter_scan_wallclock.sh b/tests/heavy/frontmatter_scan_wallclock.sh index b3b952069..162e4d129 100755 --- a/tests/heavy/frontmatter_scan_wallclock.sh +++ b/tests/heavy/frontmatter_scan_wallclock.sh @@ -92,11 +92,22 @@ timeout 120s bun run src/cli.ts init --pglite --yes --no-embedding >> "$LOG" 2>& # Register the brain dir as a source. Use raw SQL since `gbrain sources add` # might not exist in this version-window; the schema is what doctor reads. +# NOTE: must be `bun -e`, not `bun run -e` — `bun run` treats -e as an +# unknown script name and dumps its usage/script listing with exit 0, so the +# INSERT silently never ran and doctor scanned zero sources (vacuous pass). +# Resolve the engine the same way the CLI does (config + env), so the source +# lands in the DB doctor actually reads (Postgres when CI sets DATABASE_URL, +# the PGLite brain otherwise) — a hardcoded `connect({})` is in-memory and +# the INSERT would vanish. echo "[fm_wallclock] register source..." | tee -a "$LOG" -bun run -e " -import { PGLiteEngine } from './src/core/pglite-engine.ts'; -const e = new PGLiteEngine(); -await e.connect({}); +bun -e " +import { loadConfig, toEngineConfig } from './src/core/config.ts'; +import { createEngine } from './src/core/engine-factory.ts'; +const cfg = loadConfig(); +if (!cfg) throw new Error('no gbrain config — init failed?'); +const engineConfig = toEngineConfig(cfg); +const e = await createEngine(engineConfig); +await e.connect(engineConfig); await e.initSchema(); await e.executeRaw( \"INSERT INTO sources (id, name, local_path) VALUES ('fm-wallclock', 'Frontmatter wallclock test', \\\$1)\",