From 66f4cb6d82c8bcdcb4cbb85a69bedc3509541c4b Mon Sep 17 00:00:00 2001 From: Time Attakc <89218912+time-attack@users.noreply.github.com> Date: Thu, 23 Jul 2026 12:28:27 -0700 Subject: [PATCH] fix(dream): keep dream --dry-run --json stdout clean of embed summaries (#394) (#3109) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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: Garry Tan Co-authored-by: Kage18 Co-authored-by: Claude Fable 5 --- src/commands/embed.ts | 48 +++++++++++++++++++++++++++++-------------- src/core/cycle.ts | 4 +++- test/dream.test.ts | 27 ++++++++++++++++++++++++ 3 files changed, 63 insertions(+), 16 deletions(-) diff --git a/src/commands/embed.ts b/src/commands/embed.ts index 348d76812..85ae2c282 100644 --- a/src/commands/embed.ts +++ b/src/commands/embed.ts @@ -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`); } /** @@ -645,6 +655,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, ) { @@ -790,10 +802,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`); + } } } @@ -829,6 +843,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, @@ -846,7 +862,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`); } } @@ -857,10 +873,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; } @@ -869,7 +887,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; } @@ -1112,7 +1130,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 diff --git a/src/core/cycle.ts b/src/core/cycle.ts index a10b1ca80..757b4021b 100644 --- a/src/core/cycle.ts +++ b/src/core/cycle.ts @@ -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', diff --git a/test/dream.test.ts b/test/dream.test.ts index f4380eb14..ebff52620 100644 --- a/test/dream.test.ts +++ b/test/dream.test.ts @@ -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)); });