fix(cli): keep doctor --json stdout clean — v123 migration handler printed to stdout

The v123 configurable-FTS migration (#2941) logged its completion notice
via console.log. Migrations run lazily inside any command's first DB
connect, so on the nightly heavy run (fresh Postgres service DB) the
line landed as the first line of `gbrain doctor --json` stdout and broke
the fm_wallclock jq parse ("Invalid numeric literal at line 1, column 7",
run 29731426470). runMigrations' contract routes all migration noise to
stderr; move the v123 prints (and the pre-existing v2 slug-rename print)
there.

Also un-vacuous the fm_wallclock harness: its register-source step used
`bun run -e` (bun dumps usage with exit 0 instead of running the code)
and `connect({})` (in-memory), so the source was never registered and
doctor scanned nothing. It now resolves the engine the way the CLI does
and registers the source in the DB doctor actually reads.

Regression test: test/migrate-stdout-clean.test.ts re-runs migrations
from v122 asserting zero stdout writes, plus a source-level guard that
migrate.ts contains no console.log.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Garry Tan
2026-07-20 10:25:07 -07:00
co-authored by Claude Fable 5
parent f72de97943
commit 57330c8fd1
3 changed files with 92 additions and 7 deletions
+9 -3
View File
@@ -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`);
},
},
];
+68
View File
@@ -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([]);
});
});
+15 -4
View File
@@ -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)\",