Compare commits

...
2 Commits
Author SHA1 Message Date
Masa d941e9f918 fix(search): disclose the telemetry coverage gap in search stats/tune (#4079)
* fix(search): disclose telemetry coverage gap in search stats/tune

`gbrain search stats` / `gbrain search tune` read from an in-memory,
best-effort telemetry buffer that flushes on a 60s timer or 100-call
threshold (by design — see the module header in
src/core/search/telemetry.ts). Short-lived CLI invocations typically
exit before either trigger fires, so their search calls are silently
dropped; only long-lived processes (serve, MCP stdio/HTTP, jobs work)
are reliably counted. `search stats`/`search tune` printed totals and
"data-driven recommendations" with no hint of this scope, so a CLI-first
user could be tuned against a sample that never included their own
searches.

This is a display-only accuracy fix: no telemetry/flush behavior
changes. Adds a `coverage` disclosure (JSON, additive) and a one-line
human-readable caveat to both subcommands, backed by a single exported
note in telemetry.ts so the two callers stay in sync.

* fix(search): correct coverage wording after review + document KEY_FILES

Codex review of the coverage-disclosure commit found real issues, not
just nits:

- "long-lived processes only" overclaimed — a CLI run that itself
  crosses the 100-call flush threshold before exiting IS captured.
  Reworded to "coverage favors long-lived processes ... a lone
  short-lived CLI search call is typically not recorded."
- The pre-existing "Run a few `gbrain query` calls and re-check"
  advice on a 0-count `search stats`/`search tune` now directly
  contradicts the new disclosure (a single CLI call is exactly what
  tends not to survive the flush). Replaced with guidance that matches
  the caveat (use `gbrain serve` / an MCP session for reliable counts).
- The human-readable caveats were hand-paraphrased at each call site,
  which is how the above wording drifted in the first place. Added
  `TELEMETRY_COVERAGE_CAVEAT` (short form, telemetry.ts) as the single
  literal string every human-output call site now reuses.
- Test assertions were too loose to catch inaccurate wording (only
  checked for the word "coverage" / a non-empty reason string).
  Strengthened to pin the exact caveat string / key phrases.
- Added the KEY_FILES.md entry for this behavior per repo convention,
  regenerated llms.txt/llms-full.txt (no diff — content already
  matched).

* fix(search): address round-2 Codex nits (honest wording + wording pins)

- Soften "captures counts reliably over time" (best-effort telemetry can
  still silently drop a flush) to "is more likely to record counts over
  time (telemetry stays best-effort either way)".
- Add wording-accuracy pin tests that hardcode the expected substance
  independently of the TELEMETRY_COVERAGE_NOTE/CAVEAT imports — importing
  the same constant into both production code and its own test assertion
  cannot catch an inaccurate edit to that constant (exactly how the
  round-1 "long-lived processes only" / missing "jobs work" bug slipped
  through). New tests assert gbrain serve / MCP / jobs work / short-lived
  CLI / the typically-not-never hedge directly, for both the --json
  reason string and the human caveat.
2026-08-14 05:02:42 -07:00
Javier Aldapeandgbrain-contrib 26578a2478 fix(patterns): accept completed child outcome (#4101)
Co-authored-by: gbrain-contrib <gbrain-contrib@example.com>
2026-08-14 04:53:32 -07:00
7 changed files with 255 additions and 10 deletions
File diff suppressed because one or more lines are too long
+12 -3
View File
@@ -38,7 +38,7 @@ import {
type SearchMode,
type ModeBundle,
} from '../core/search/mode.ts';
import { readSearchStats } from '../core/search/telemetry.ts';
import { readSearchStats, telemetryCoverage, TELEMETRY_COVERAGE_CAVEAT } from '../core/search/telemetry.ts';
const KNOB_DESCRIPTIONS: Record<keyof ModeBundle, string> = {
cache_enabled: 'Semantic query cache on/off',
@@ -225,6 +225,7 @@ async function runStatsSubcommand(engine: BrainEngine, args: string[]): Promise<
console.log(JSON.stringify({
schema_version: 2,
...stats,
coverage: telemetryCoverage(),
graph_signals: gsSection,
_meta: {
metric_glossary: {
@@ -241,11 +242,15 @@ async function runStatsSubcommand(engine: BrainEngine, args: string[]): Promise<
}
console.log(`Search stats over the last ${stats.window_days} days:`);
console.log(` Coverage note: ${TELEMETRY_COVERAGE_CAVEAT}`);
console.log('');
console.log(` Total searches: ${stats.total_calls}`);
if (stats.total_calls === 0) {
console.log('');
console.log('No telemetry recorded yet. Run a few `gbrain query` calls and re-check.');
console.log('No telemetry recorded in this window. This can mean no search activity, or');
console.log('it can reflect the coverage gap above — a lone short-lived CLI call is often');
console.log('not enough to trigger a flush. `gbrain serve` / an MCP session is more likely');
console.log('to record counts over time (telemetry stays best-effort either way).');
// Still print the graph-signals section since failures are tracked
// independently of the search_telemetry table.
if (gsSection.enabled || gsSection.failures_count > 0) {
@@ -382,6 +387,7 @@ async function runTuneSubcommand(engine: BrainEngine, args: string[]): Promise<v
schema_version: 2,
status: 'insufficient_data',
total_calls: stats.total_calls,
coverage: telemetryCoverage(),
recommendations: [],
message: 'Not enough search activity in the last 7 days to tune. Run `gbrain search stats` after some real usage.',
}, null, 2));
@@ -389,7 +395,8 @@ async function runTuneSubcommand(engine: BrainEngine, args: string[]): Promise<v
}
console.log('Not enough search activity in the last 7 days to tune.');
console.log(`Total searches: ${stats.total_calls} (need >= 20 for confident recommendations).`);
console.log('Run a few `gbrain query` calls, then re-run `gbrain search tune`.');
console.log(`(${TELEMETRY_COVERAGE_CAVEAT} Low counts can reflect this gap, not just low usage.)`);
console.log('Use `gbrain serve` or an MCP session for a while, then re-run `gbrain search tune`.');
return;
}
@@ -448,6 +455,7 @@ async function runTuneSubcommand(engine: BrainEngine, args: string[]): Promise<v
total_calls: stats.total_calls,
cache_hit_rate: stats.cache_hit_rate,
active_mode: resolved.resolved_mode,
coverage: telemetryCoverage(),
recommendations: recs,
applied: apply ? recs.map(r => r.apply_command) : [],
_meta: {
@@ -466,6 +474,7 @@ async function runTuneSubcommand(engine: BrainEngine, args: string[]): Promise<v
}
console.log(`Search tune (last 7 days, active mode: ${resolved.resolved_mode}):`);
console.log(`(${TELEMETRY_COVERAGE_CAVEAT})`);
console.log('');
if (recs.length === 0) {
+3 -3
View File
@@ -25,7 +25,7 @@ import type { BrainEngine } from '../engine.ts';
import type { PhaseResult, PhaseError } from '../cycle.ts';
import { MinionQueue } from '../minions/queue.ts';
import { waitForCompletion, TimeoutError } from '../minions/wait-for-completion.ts';
import type { MinionJobInput, SubagentHandlerData } from '../minions/types.ts';
import type { MinionJobInput, MinionJobStatus, SubagentHandlerData } from '../minions/types.ts';
import { serializeMarkdown } from '../markdown.ts';
import type { Page, PageType } from '../types.ts';
// #2415: allow-list + output-root resolution shared with the synthesize
@@ -221,7 +221,7 @@ export async function runPhasePatterns(
// parent job otherwise deadlocks a fully-occupied worker (#2050).
await runSubagentsInline(engine, queue, childQueueName, opts.yieldDuringPhase);
let outcome: string;
let outcome: MinionJobStatus | 'timeout';
try {
const final = await waitForCompletion(queue, job.id, {
timeoutMs: budgets.waitTimeoutMs,
@@ -271,7 +271,7 @@ export async function runPhasePatterns(
// returned status:ok even when the subagent timed out (e.g. no
// subagent-capable worker slot free for the whole wait window) and zero
// pattern pages were written — a silent no-op for days.
if (outcome !== 'complete') {
if (outcome !== 'completed') {
if (writtenRefs.length === 0) {
return {
phase: 'patterns',
+44
View File
@@ -434,6 +434,50 @@ export async function readSearchStats(
}
}
/**
* Coverage disclosure for `readSearchStats()` consumers (`gbrain search
* stats` / `gbrain search tune`). This documents the buffering behavior
* from the module header above — it changes NO behavior, it only gives
* display layers a single source of truth for the caveat text instead of
* each caller re-describing (and risking drift on) the flush mechanics.
*
* Short-lived CLI invocations (a single `gbrain query "..."` call) usually
* exit before the 60s timer or the 100-call threshold fires, so their
* search is buffered in-memory and then lost with the process — never
* written to `search_telemetry`. Long-lived processes (`gbrain serve`,
* stdio/HTTP MCP, `gbrain jobs work`) survive long enough for the periodic
* flush and are captured reliably. A CLI run that itself issues 100+
* search calls before exiting (e.g. a bulk eval) CAN cross the threshold
* and flush — hence "typically", not "never".
*/
export const TELEMETRY_COVERAGE_NOTE =
'Counts are most complete for long-lived processes (gbrain serve, MCP stdio/HTTP, ' +
'gbrain jobs work). A single short-lived CLI invocation typically exits before the ' +
'telemetry buffer flushes (60s timer or 100-call threshold), so its search is ' +
'usually not recorded here — see search/telemetry.ts for the buffering design.';
/**
* Short, single-line form of {@link TELEMETRY_COVERAGE_NOTE} for human CLI
* output (the long form is better suited to `--json`'s `reason` field).
* Every human-facing caveat in `gbrain search stats`/`gbrain search tune`
* reuses this literal string instead of paraphrasing it, so the wording
* cannot drift between call sites.
*/
export const TELEMETRY_COVERAGE_CAVEAT =
'Coverage favors long-lived processes (gbrain serve, MCP, jobs work) — a lone ' +
'short-lived CLI search call is typically not recorded.';
export interface TelemetryCoverage {
/** Whether a lone short-lived CLI search call is reliably counted. */
cli_invocations: 'typically_not_recorded';
reason: string;
}
/** Machine-readable form of {@link TELEMETRY_COVERAGE_NOTE} for `--json` output. */
export function telemetryCoverage(): TelemetryCoverage {
return { cli_invocations: 'typically_not_recorded', reason: TELEMETRY_COVERAGE_NOTE };
}
function nowDate(): string {
return new Date().toISOString().slice(0, 10);
}
+115 -1
View File
@@ -8,7 +8,7 @@
import { afterAll, beforeAll, beforeEach, describe, expect, test } from 'bun:test';
import { PGLiteEngine } from '../src/core/pglite-engine.ts';
import { runSearch } from '../src/commands/search.ts';
import { recordSearchTelemetry, _resetTelemetryWriterForTest, getTelemetryWriter } from '../src/core/search/telemetry.ts';
import { recordSearchTelemetry, _resetTelemetryWriterForTest, getTelemetryWriter, TELEMETRY_COVERAGE_CAVEAT } from '../src/core/search/telemetry.ts';
import type { HybridSearchMeta } from '../src/core/types.ts';
let engine: PGLiteEngine;
@@ -165,6 +165,81 @@ describe('gbrain search stats', () => {
const outBig = await captureRun(() => runSearch(engine, ['stats', '--days', '9999', '--json']));
expect(JSON.parse(outBig).window_days).toBe(365);
});
// Coverage disclosure: short-lived CLI search calls typically don't
// survive the telemetry flush timer/threshold, so `search stats` must
// say so instead of presenting the (possibly CLI-blind) count as total.
test('--json includes a coverage disclosure (empty table)', async () => {
const out = await captureRun(() => runSearch(engine, ['stats', '--json']));
const stats = JSON.parse(out);
expect(stats.coverage).toBeDefined();
expect(stats.coverage.cli_invocations).toBe('typically_not_recorded');
// Pin the substance, not just presence — an inaccurate reason string
// (e.g. "long-lived processes only") must fail this test.
expect(stats.coverage.reason).toMatch(/short-lived CLI/i);
expect(stats.coverage.reason).toMatch(/typically.*not recorded|not.*typically recorded/i);
});
test('--json includes a coverage disclosure (non-empty table)', async () => {
const w = getTelemetryWriter();
w.setEngine(engine);
recordSearchTelemetry(engine, makeMeta({ cache: { status: 'hit' } }), { results_count: 5 });
await w.flush();
const out = await captureRun(() => runSearch(engine, ['stats', '--json']));
const stats = JSON.parse(out);
expect(stats.coverage.cli_invocations).toBe('typically_not_recorded');
});
// Wording-accuracy pin, independent of the TELEMETRY_COVERAGE_NOTE import:
// importing the same constant into production code and the assertion
// would let an inaccurate edit to the constant sail through unnoticed
// (round-1 review caught exactly this class of bug — "long-lived
// processes only" overclaimed and dropped `jobs work`). Hardcode the
// substance here instead of comparing production output to itself.
test('--json coverage.reason names all three long-lived process kinds + the threshold exception', async () => {
const out = await captureRun(() => runSearch(engine, ['stats', '--json']));
const reason: string = JSON.parse(out).coverage.reason;
expect(reason).toMatch(/gbrain serve/i);
expect(reason).toMatch(/mcp/i);
expect(reason).toMatch(/jobs work/i);
expect(reason).toMatch(/short-lived CLI/i);
// Must not claim CLI calls are NEVER recorded — a bulk CLI run that
// itself crosses the 100-call flush threshold before exiting IS
// captured, so the wording must hedge ("typically"/"usually"), not
// assert absolute exclusivity ("only"/"never").
expect(reason).toMatch(/typically|usually/i);
expect(reason).not.toMatch(/\bonly\b/i);
expect(reason).not.toMatch(/\bnever\b/i);
});
test('human output surfaces the exact coverage caveat (empty table)', async () => {
const out = await captureRun(() => runSearch(engine, ['stats']));
// Pin the literal shared constant — proves the display layer isn't
// paraphrasing (and risking drift on) the buffering caveat.
expect(out).toContain(TELEMETRY_COVERAGE_CAVEAT);
expect(out.toLowerCase()).toContain('coverage gap above');
});
// Same independent-wording-pin rationale as the --json test above,
// applied to the short human caveat.
test('human coverage caveat names long-lived processes + jobs work + the hedge word, independent of the import', async () => {
const out = await captureRun(() => runSearch(engine, ['stats']));
expect(out).toMatch(/favors long-lived processes/i);
expect(out).toMatch(/jobs work/i);
expect(out).toMatch(/typically not recorded/i);
expect(out).not.toMatch(/only long-lived processes/i);
});
test('human output surfaces the exact coverage caveat (non-empty table)', async () => {
const w = getTelemetryWriter();
w.setEngine(engine);
recordSearchTelemetry(engine, makeMeta({ cache: { status: 'hit' } }), { results_count: 5 });
await w.flush();
const out = await captureRun(() => runSearch(engine, ['stats']));
expect(out).toContain(TELEMETRY_COVERAGE_CAVEAT);
});
});
describe('gbrain search tune (recommendations)', () => {
@@ -175,6 +250,26 @@ describe('gbrain search tune (recommendations)', () => {
expect(r.recommendations).toEqual([]);
});
// Coverage disclosure: `tune`'s recommendations are only as complete as
// the telemetry they're read from — same caveat as `search stats`.
test('insufficient data → --json includes coverage disclosure', async () => {
const out = await captureRun(() => runSearch(engine, ['tune', '--json']));
const r = JSON.parse(out);
expect(r.coverage).toBeDefined();
expect(r.coverage.cli_invocations).toBe('typically_not_recorded');
expect(r.coverage.reason).toMatch(/short-lived CLI/i);
});
test('insufficient data → human output notes the exact coverage caveat', async () => {
const out = await captureRun(() => runSearch(engine, ['tune']));
expect(out).toContain(TELEMETRY_COVERAGE_CAVEAT);
// The old copy told the user to "run a few `gbrain query` calls" to fix
// a zero count — that's misleading advice given the caveat (a single
// CLI call is exactly what tends NOT to be recorded). Pin the corrected
// suggestion instead.
expect(out).toMatch(/gbrain serve.*or an MCP session/i);
});
test('conservative + high budget drop rate → recommends balanced', async () => {
await engine.setConfig('search.mode', 'conservative');
const w = getTelemetryWriter();
@@ -194,6 +289,25 @@ describe('gbrain search tune (recommendations)', () => {
const modeRec = r.recommendations.find((x: { knob: string }) => x.knob === 'search.mode');
expect(modeRec).toBeDefined();
expect(modeRec.suggested).toBe('balanced');
// Coverage disclosure travels with real recommendations too, not just
// the insufficient-data early-return path.
expect(r.coverage.cli_invocations).toBe('typically_not_recorded');
});
test('has_recommendations → human output notes the exact coverage caveat', async () => {
await engine.setConfig('search.mode', 'conservative');
const w = getTelemetryWriter();
w.setEngine(engine);
for (let i = 0; i < 30; i++) {
recordSearchTelemetry(engine, makeMeta({
mode: 'conservative',
token_budget: { budget: 4000, used: 4000, kept: 5, dropped: 5 },
}), { results_count: 5 });
}
await w.flush();
const out = await captureRun(() => runSearch(engine, ['tune']));
expect(out).toContain(TELEMETRY_COVERAGE_CAVEAT);
});
test('tokenmax + Haiku subagent → recommends balanced', async () => {
+1 -1
View File
@@ -12,7 +12,7 @@
* the real Anthropic call fails immediately, exhausting max_attempts and
* landing the job in 'dead' (not 'timeout' — nothing ever times out, the
* failure is immediate). The #2782 status-reflects-outcome contract this
* test exists to pin is unchanged: any non-'complete' outcome with zero
* test exists to pin is unchanged: any non-'completed' outcome with zero
* writes must still surface as status 'fail', just under the outcome that
* actually occurs now that the job is drained instead of left stuck in
* 'waiting' for the full wait window.
@@ -0,0 +1,78 @@
import { afterAll, beforeAll, beforeEach, describe, expect, mock, test } from 'bun:test';
import { mkdtempSync, rmSync } from 'node:fs';
import { tmpdir } from 'node:os';
import { join } from 'node:path';
import { PGLiteEngine } from '../src/core/pglite-engine.ts';
import { resetPgliteState } from './helpers/reset-pglite.ts';
mock.module('../src/core/ai/gateway.ts', () => ({
probeChatModel: () => ({ ok: true }),
}));
mock.module('../src/core/cycle/synthesize.ts', () => ({
loadAllowedSlugPrefixes: async () => ['wiki/personal/patterns/*'],
loadOutputRoot: async () => 'wiki',
runSubagentsInline: async () => undefined,
}));
mock.module('../src/core/minions/wait-for-completion.ts', () => ({
TimeoutError: class TimeoutError extends Error {},
waitForCompletion: async (_queue: unknown, jobId: number) => ({
id: jobId,
status: 'completed',
}),
}));
const { runPhasePatterns } = await import('../src/core/cycle/patterns.ts');
let engine: PGLiteEngine;
let schemaVersion: string;
beforeAll(async () => {
engine = new PGLiteEngine();
await engine.connect({ database_url: '' });
await engine.initSchema();
schemaVersion = (await engine.getConfig('version')) ?? '7';
}, 60_000);
afterAll(async () => {
await engine.disconnect();
});
beforeEach(async () => {
await resetPgliteState(engine);
await engine.setConfig('version', schemaVersion);
await engine.setConfig('models.dream.patterns', 'anthropic:claude-sonnet-4-6');
});
async function seedReflections(): Promise<void> {
for (let i = 0; i < 3; i++) {
await engine.executeRaw(
`INSERT INTO pages (slug, type, title, compiled_truth)
VALUES ($1, 'note', $2, $3)`,
[
`wiki/personal/reflections/2026-08-0${i + 1}-reflection`,
`Reflection ${i + 1}`,
`Recurring theme fixture number ${i + 1}.`,
],
);
}
}
describe('runPhasePatterns completed child outcome (#4026)', () => {
test('completed child with zero writes is an ok no-op, not PATTERNS_CHILD_COMPLETED', async () => {
const brainDir = mkdtempSync(join(tmpdir(), 'gbrain-patterns-completed-'));
try {
await seedReflections();
const result = await runPhasePatterns(engine, { brainDir, dryRun: false });
expect(result.status).toBe('ok');
expect(result.details.child_outcome).toBe('completed');
expect(result.details.patterns_written).toBe(0);
expect(result.error?.code).not.toBe('PATTERNS_CHILD_COMPLETED');
} finally {
rmSync(brainDir, { recursive: true, force: true });
}
});
});