Compare commits

..
Author SHA1 Message Date
ddb000b0e2 fix(dream): keep dream --dry-run --json stdout clean of embed summaries (#394)
The cycle's embed phase called runEmbedCore with no output suppression, so
the '[dry-run] Would embed ...' / 'Embedded N chunks ...' slog summaries
landed on stdout ahead of the JSON CycleReport, breaking the documented
stdout-clean-for-JSON contract (docs/progress-events.md).

Adds EmbedOpts.quiet gating the human stdout summary slog sites in
embed.ts (embedPage, embedAll, embedAllStale); the cycle's runPhaseEmbed
sets quiet: true since it reports counts via its own PhaseResult. Errors
and warnings still go to stderr regardless.

Takeover of #854 (same approach, reimplemented on current master — the
original patch predates the slog migration and the widened
embedAll/embedAllStale signatures). Regression test ported from #854.

Co-authored-by: Kage18 <Kage18@users.noreply.github.com>
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-21 14:31:13 -07:00
5 changed files with 84 additions and 75 deletions
+33 -15
View File
@@ -107,6 +107,14 @@ export interface EmbedOpts {
* runs lock every source in sorted order. dryRun skips it.
*/
singleFlight?: boolean;
/**
* #394: suppress human stdout summaries (the `[dry-run] Would embed ...` /
* `Embedded N chunks ...` slog lines). Set by structured-output callers —
* the cycle's embed phase (dream --json must keep stdout JSON-clean per
* docs/progress-events.md) reports counts via its own PhaseResult instead.
* Errors/warnings still go to stderr regardless.
*/
quiet?: boolean;
}
/**
@@ -253,7 +261,7 @@ export async function runEmbedCore(engine: BrainEngine, opts: EmbedOpts): Promis
for (const s of opts.slugs) {
if (isAborted(opts.signal)) break; // #1737: stop the per-slug loop on abort
try {
await embedPage(engine, s, !!opts.dryRun, result, opts.sourceId, opts.signal);
await embedPage(engine, s, !!opts.dryRun, result, opts.sourceId, opts.signal, opts.quiet);
} catch (e: unknown) {
serr(` Error embedding ${s}: ${e instanceof Error ? e.message : e}`);
}
@@ -347,6 +355,7 @@ export async function runEmbedCore(engine: BrainEngine, opts: EmbedOpts): Promis
catchUp: opts.catchUp,
pacer,
paceMaxConcurrency,
quiet: opts.quiet,
}, opts.signal);
} finally {
// E1: surface pacing telemetry (human + structured) when pacing was on.
@@ -376,7 +385,7 @@ export async function runEmbedCore(engine: BrainEngine, opts: EmbedOpts): Promis
return result;
}
if (opts.slug) {
await embedPage(engine, opts.slug, !!opts.dryRun, result, opts.sourceId, opts.signal);
await embedPage(engine, opts.slug, !!opts.dryRun, result, opts.sourceId, opts.signal, opts.quiet);
return result;
}
throw new Error('No embed target specified. Pass { slug }, { slugs }, { all }, or { stale }.');
@@ -521,6 +530,7 @@ async function embedPage(
result: EmbedResult,
sourceId?: string,
signal?: AbortSignal,
quiet?: boolean,
) {
const opts = sourceId ? { sourceId } : undefined;
const page = await engine.getPage(slug, opts);
@@ -565,7 +575,7 @@ async function embedPage(
result.skipped += chunks.length - toEmbed.length;
if (toEmbed.length === 0) {
slog(`${slug}: all ${chunks.length} chunks already embedded`);
if (!quiet) slog(`${slug}: all ${chunks.length} chunks already embedded`);
result.pages_processed++;
return;
}
@@ -602,7 +612,7 @@ async function embedPage(
}
result.embedded += toEmbed.length;
result.pages_processed++;
slog(`${slug}: embedded ${toEmbed.length} chunks`);
if (!quiet) slog(`${slug}: embedded ${toEmbed.length} chunks`);
}
async function embedAll(
@@ -620,6 +630,8 @@ async function embedAll(
pacer?: DbPacer;
/** Resolved concurrency cap (E-1: the worker count, no separate permit). */
paceMaxConcurrency?: number;
/** #394: suppress human stdout summaries (structured-output callers). */
quiet?: boolean;
},
signal?: AbortSignal,
) {
@@ -763,10 +775,12 @@ async function embedAll(
});
// Stdout summary preserved for scripts/tests that grep for counts.
if (dryRun) {
slog(`[dry-run] Would embed ${result.would_embed} chunks across ${pages.length} pages`);
} else {
slog(`Embedded ${result.embedded} chunks across ${pages.length} pages`);
if (!staleOpts?.quiet) {
if (dryRun) {
slog(`[dry-run] Would embed ${result.would_embed} chunks across ${pages.length} pages`);
} else {
slog(`Embedded ${result.embedded} chunks across ${pages.length} pages`);
}
}
}
@@ -802,6 +816,8 @@ async function embedAllStale(
pacer?: DbPacer;
/** Resolved concurrency cap (E-1: the worker count, no separate permit). */
paceMaxConcurrency?: number;
/** #394: suppress human stdout summaries (structured-output callers). */
quiet?: boolean;
},
signature?: string,
externalSignal?: AbortSignal,
@@ -819,7 +835,7 @@ async function embedAllStale(
signature,
...(sourceId && { sourceId }),
});
if (invalidated > 0) {
if (invalidated > 0 && !staleOpts?.quiet) {
slog(`[embed] invalidated ${invalidated} chunk(s) embedded under a prior model signature`);
}
}
@@ -830,10 +846,12 @@ async function embedAllStale(
dryRun && signature ? { ...sourceOpt, signature } : sourceOpt,
);
if (staleCount === 0) {
if (dryRun) {
slog('[dry-run] Would embed 0 chunks (0 stale found)');
} else {
slog('Embedded 0 chunks (0 stale found)');
if (!staleOpts?.quiet) {
if (dryRun) {
slog('[dry-run] Would embed 0 chunks (0 stale found)');
} else {
slog('Embedded 0 chunks (0 stale found)');
}
}
return;
}
@@ -842,7 +860,7 @@ async function embedAllStale(
result.would_embed += staleCount;
result.total_chunks += staleCount;
if (onProgress) onProgress(1, 1, 0);
slog(`[dry-run] Would embed ${staleCount} stale chunks`);
if (!staleOpts?.quiet) slog(`[dry-run] Would embed ${staleCount} stale chunks`);
return;
}
@@ -1082,7 +1100,7 @@ async function embedAllStale(
if (budgetTimer) clearTimeout(budgetTimer);
}
slog(`Embedded ${result.embedded} chunks across ${totalProcessedPages} pages`);
if (!staleOpts?.quiet) slog(`Embedded ${result.embedded} chunks across ${totalProcessedPages} pages`);
// #1946 (OV2a): a catch-up pass that completed without being aborted but left
// chunks unembedded means those chunks are stuck (a non-transient embed
+3 -1
View File
@@ -1214,7 +1214,9 @@ async function runPhaseEmbed(engine: BrainEngine, dryRun: boolean, signal?: Abor
// 10-15 min one) bails within a batch instead of running to completion
// after the job was killed — which left gbrain_cycle_locks held and
// wedged every subsequent autopilot cycle.
const result = await runEmbedCore(engine, { stale: true, dryRun, signal });
// #394: quiet — the cycle reports embed counts via its own PhaseResult;
// raw `[dry-run] Would embed ...` stdout lines would corrupt `dream --json`.
const result = await runEmbedCore(engine, { stale: true, dryRun, signal, quiet: true });
const embeddedCount = dryRun ? result.would_embed : result.embedded;
return {
phase: 'embed',
+3 -11
View File
@@ -35,11 +35,10 @@
*
* The doctor renders both side by side.
*
* Drift contract: every check name that ships through doctor MUST appear in
* Drift contract: every check name that ships in doctor.ts MUST appear in
* exactly one set below. The drift-guard test in
* `test/doctor-categories.test.ts` enforces this by reading doctor check
* emitter sources via a tagged-string scan and asserting set membership
* exactly.
* `test/doctor-categories.test.ts` enforces this by reading doctor.ts source
* via a tagged-string scan and asserting set membership exactly.
*
* If you add a new doctor check, you MUST add its name to the appropriate
* set here. The categorize step in `src/commands/doctor.ts` falls through
@@ -68,15 +67,12 @@ export const BRAIN_CHECK_NAMES: ReadonlySet<string> = new Set([
'conversation_parser_probe_health',
'cross_modal_modality_backfill',
'cycle_freshness',
'dangling_aliases',
'effective_date_health',
'embed_staleness',
'embedding_column_registry',
'embedding_env_override',
'embedding_provider',
'embedding_width_consistency',
'embeddings',
'entity_link_coverage',
'eval_drift',
'extract_atoms_backlog',
'extract_health',
@@ -106,9 +102,7 @@ export const BRAIN_CHECK_NAMES: ReadonlySet<string> = new Set([
'stub_guard_24h',
'sync_failures',
'sync_freshness',
'takes_count',
'takes_weight_grid',
'timeline_coverage',
'unified_multimodal_coverage',
'voice_gate_health',
]);
@@ -176,14 +170,12 @@ export const META_CHECK_NAMES: ReadonlySet<string> = new Set([
'eval_capture',
'minions_migration',
'multi_source_drift',
'pack_upgrade_available',
'schema_pack_active',
'schema_pack_consistency',
'schema_pack_source_drift',
'schema_version',
'slug_fallback_audit',
'timeline_dedup_index',
'type_proliferation',
'upgrade_errors',
]);
+18 -48
View File
@@ -1,10 +1,10 @@
/**
* Drift guard for src/core/doctor-categories.ts.
*
* Reads doctor check emitter source via a literal-string scan, enumerates every
* `name: '<...>'` Check name, and asserts each appears in exactly ONE category
* set. The union of the four sets must equal the discovered names exactly —
* no orphans, no extras.
* Reads src/commands/doctor.ts source via a literal-string scan, enumerates
* every `name: '<...>'` Check name, and asserts each appears in exactly ONE
* category set. The union of the four sets must equal the discovered names
* exactly — no orphans, no extras.
*
* This is the structural failure the v0.41.19.0 plan-eng-review caught:
* doctor.ts grows new checks regularly; without this guard, the
@@ -25,30 +25,26 @@ import {
} from '../src/core/doctor-categories.ts';
const DOCTOR_TS_PATH = join(import.meta.dir, '..', 'src', 'commands', 'doctor.ts');
const ONBOARD_CHECKS_TS_PATH = join(import.meta.dir, '..', 'src', 'core', 'onboard', 'checks.ts');
const CHECK_SOURCE_PATHS = [DOCTOR_TS_PATH, ONBOARD_CHECKS_TS_PATH];
function enumerateCheckNames(): Set<string> {
const source = readFileSync(DOCTOR_TS_PATH, 'utf-8');
const names = new Set<string>();
for (const path of CHECK_SOURCE_PATHS) {
const source = readFileSync(path, 'utf-8');
// 1) Inline object-literal form: `{ name: 'foo', ... }`.
for (const m of source.matchAll(/name:\s*['"]([a-z][a-z0-9_]+)['"]/g)) {
names.add(m[1]);
}
// 2) Helper-function form: `const name = 'foo';` inside a check helper.
// Catches checks like `nightly_quality_probe_health` and
// `conversation_facts_backlog` that build the Check from a captured
// name constant.
for (const m of source.matchAll(/const\s+name\s*=\s*['"]([a-z][a-z0-9_]+)['"]/g)) {
names.add(m[1]);
}
// 1) Inline object-literal form: `{ name: 'foo', ... }`.
for (const m of source.matchAll(/name:\s*['"]([a-z][a-z0-9_]+)['"]/g)) {
names.add(m[1]);
}
// 2) Helper-function form: `const name = 'foo';` inside a check helper.
// Catches checks like `nightly_quality_probe_health` and
// `conversation_facts_backlog` that build the Check from a captured
// name constant.
for (const m of source.matchAll(/const\s+name\s*=\s*['"]([a-z][a-z0-9_]+)['"]/g)) {
names.add(m[1]);
}
return names;
}
describe('doctor-categories drift guard', () => {
test('every doctor-emitted check name belongs to exactly one category set', () => {
test('every check name in doctor.ts source belongs to exactly one category set', () => {
const discovered = enumerateCheckNames();
const allCategorized = new Set<string>([
...BRAIN_CHECK_NAMES,
@@ -63,7 +59,7 @@ describe('doctor-categories drift guard', () => {
}
if (missing.length > 0) {
throw new Error(
`These check names appear in doctor check emitters but are not categorized in ` +
`These check names appear in doctor.ts but are not categorized in ` +
`src/core/doctor-categories.ts: ${missing.sort().join(', ')}. ` +
`Add each to BRAIN/SKILL/OPS/META_CHECK_NAMES.`,
);
@@ -90,7 +86,7 @@ describe('doctor-categories drift guard', () => {
expect(dupes).toEqual([]);
});
test('every categorized name is currently used in doctor check emitters (no stale entries)', () => {
test('every categorized name is currently used in doctor.ts source (no stale entries)', () => {
const discovered = enumerateCheckNames();
const allCategorized = new Set<string>([
...BRAIN_CHECK_NAMES,
@@ -128,14 +124,6 @@ describe('categorizeCheck', () => {
expect(categorizeCheck('sync_freshness')).toBe('brain');
});
test('returns the right category for onboard data-quality check names', () => {
expect(categorizeCheck('embed_staleness')).toBe('brain');
expect(categorizeCheck('entity_link_coverage')).toBe('brain');
expect(categorizeCheck('timeline_coverage')).toBe('brain');
expect(categorizeCheck('takes_count')).toBe('brain');
expect(categorizeCheck('dangling_aliases')).toBe('brain');
});
test('returns the right category for a known skill name', () => {
expect(categorizeCheck('resolver_health')).toBe('skill');
expect(categorizeCheck('skill_conformance')).toBe('skill');
@@ -152,24 +140,6 @@ describe('categorizeCheck', () => {
expect(categorizeCheck('upgrade_errors')).toBe('meta');
});
test('returns the right category for onboard schema-pack check names without warning', () => {
const originalWrite = process.stderr.write.bind(process.stderr);
const captured: string[] = [];
(process.stderr as { write: typeof process.stderr.write }).write = ((
chunk: string | Uint8Array,
) => {
captured.push(typeof chunk === 'string' ? chunk : Buffer.from(chunk).toString());
return true;
}) as typeof process.stderr.write;
try {
expect(categorizeCheck('pack_upgrade_available')).toBe('meta');
expect(categorizeCheck('type_proliferation')).toBe('meta');
expect(captured.filter((c) => c.includes('[doctor-categories]'))).toEqual([]);
} finally {
(process.stderr as { write: typeof process.stderr.write }).write = originalWrite;
}
});
test('unknown check name falls through to meta with a stderr warn (once per process)', () => {
const originalWrite = process.stderr.write.bind(process.stderr);
const captured: string[] = [];
+27
View File
@@ -292,6 +292,33 @@ describe('runDream — output format', () => {
expect(parsed).toHaveProperty('totals');
});
// #394 / takeover of #854: the embed phase's `[dry-run] Would embed ...`
// summary must not leak onto stdout ahead of the JSON CycleReport.
test('--dry-run --json emits only JSON even when embed has stale chunks', async () => {
await engine.putPage('concepts/testing', {
type: 'concept',
title: 'Testing',
compiled_truth: 'Testing keeps JSON contracts honest.',
timeline: '',
});
await engine.upsertChunks('concepts/testing', [
{ chunk_index: 0, chunk_text: 'Testing keeps JSON contracts honest.', chunk_source: 'compiled_truth' },
]);
const lines: string[] = [];
const logSpy = spyOn(console, 'log').mockImplementation((msg: string) => { lines.push(String(msg)); });
await runDream(engine, ['--dir', repo, '--phase', 'embed', '--dry-run', '--json']);
logSpy.mockRestore();
const output = lines.join('\n');
expect(output.trimStart().startsWith('{')).toBe(true);
const parsed = JSON.parse(output);
expect(parsed.schema_version).toBe('1');
expect(parsed.phases[0].phase).toBe('embed');
// The stale chunk was still counted in the structured report.
expect(parsed.phases[0].details.would_embed).toBe(1);
});
test('human output for clean status mentions "Brain is healthy"', async () => {
const lines: string[] = [];
const logSpy = spyOn(console, 'log').mockImplementation((msg: string) => { lines.push(String(msg)); });