diff --git a/src/commands/doctor.ts b/src/commands/doctor.ts index 73dc89721..120999c0c 100644 --- a/src/commands/doctor.ts +++ b/src/commands/doctor.ts @@ -1623,7 +1623,7 @@ export async function computeWedgedQueueCheck(engine: BrainEngine): Promise = []; for (const r of rows) { const activeHealthy = Number(r.active_healthy ?? 0); const waiting = Number(r.waiting ?? 0); @@ -1631,21 +1631,59 @@ export async function computeWedgedQueueCheck(engine: BrainEngine): Promise 0 && mins !== null && mins > thresholdMin) { - wedged.push(`'${r.queue}' (${waiting} waiting, 0 active, ${Math.round(mins)}m since last completion)`); + wedged.push({ + queue: r.queue, + label: `'${r.queue}' (${waiting} waiting, 0 active, ${Math.round(mins)}m since last completion)`, + }); } } if (wedged.length === 0) { return { name: 'wedged_queue', status: 'ok', message: 'No wedged queues' }; } - return { - name: 'wedged_queue', - status: 'fail', - message: - `Wedged queue(s) — worker alive but not claiming work: ${wedged.join('; ')}. ` + + // #3063: split the diagnosis on worker liveness. The wedged-pool message + // ("worker alive but not claiming work → restart to rebuild the DB pool") + // only applies when a supervisor actually holds a live singleton lock. + // With no live holder the worker is simply not running — telling the + // operator to blame the DB pool sends them down the wrong path. + const alive: string[] = []; + const noWorker: string[] = []; + for (const w of wedged) { + let hasLiveWorker = false; + try { + const { supervisorLockId } = await import('../core/minions/supervisor.ts'); + const lockRows = await engine.executeRaw<{ live: boolean }>( + `SELECT (ttl_expires_at > now()) AS live FROM gbrain_cycle_locks WHERE id = $1`, + [supervisorLockId(w.queue)], + ); + hasLiveWorker = lockRows.length > 0 && lockRows[0].live === true; + } catch { + // Lock table unreadable → can't prove absence; keep the + // conservative wedged-pool message. + hasLiveWorker = true; + } + (hasLiveWorker ? alive : noWorker).push(w.label); + } + const parts: string[] = []; + if (noWorker.length > 0) { + parts.push( + `Queue(s) with waiting jobs and no worker running: ${noWorker.join('; ')}. ` + + `Start the worker: \`gbrain jobs supervisor start\` ` + + `(or restart the autopilot unit if installed).`, + ); + } + if (alive.length > 0) { + parts.push( + `Wedged queue(s) — worker alive but not claiming work: ${alive.join('; ')}. ` + `Restart the worker so it rebuilds a fresh DB pool: ` + `\`gbrain jobs supervisor stop && gbrain jobs supervisor start\`, ` + `then \`gbrain jobs retry \` on any dead-lettered jobs.`, - details: { wedged_queues: wedged.length, threshold_minutes: thresholdMin }, + ); + } + return { + name: 'wedged_queue', + status: 'fail', + message: parts.join(' '), + details: { wedged_queues: wedged.length, no_worker_queues: noWorker.length, threshold_minutes: thresholdMin }, }; } catch (e) { // Pre-migration brains / transient errors: advisory check stays ok. diff --git a/src/core/cycle/nightly-quality-probe.ts b/src/core/cycle/nightly-quality-probe.ts index caf7a1f53..e1bd58d2b 100644 --- a/src/core/cycle/nightly-quality-probe.ts +++ b/src/core/cycle/nightly-quality-probe.ts @@ -101,21 +101,20 @@ export async function runNightlyQualityProbe(deps: NightlyProbeDeps): Promise e.outcome !== 'rate_limited')); if (!decision.run) { - logQualityProbeEvent({ - outcome: 'rate_limited', - exit_code: 0, - pass_count: 0, - fail_count: 0, - inconclusive_count: 0, - error_count: 0, - est_cost_usd: 0, - detail: 'already ran within 24h window', - }); + // #3064: do NOT log an audit row here. Autopilot ticks every ~5 min, so + // the skip fires ~288x/day between real runs — logging each one spammed + // the audit JSONL and permanently tripped doctor's + // nightly_quality_probe_health warn (rate_limited counts as non-PASS). return { outcome: 'rate_limited', exit_code: 0, detail: 'already ran within 24h' }; } diff --git a/src/core/facts/fence-write.ts b/src/core/facts/fence-write.ts index ae35769fb..52ea23a3c 100644 --- a/src/core/facts/fence-write.ts +++ b/src/core/facts/fence-write.ts @@ -34,7 +34,7 @@ */ import { existsSync, mkdirSync, readFileSync, writeFileSync, renameSync, appendFileSync } from 'node:fs'; -import { dirname } from 'node:path'; +import { dirname, join } from 'node:path'; import type { BrainEngine, NewFact, FactVisibility } from '../engine.ts'; import { resolvePageFilePath } from '../markdown.ts'; @@ -172,17 +172,68 @@ export async function writeFactsToFence( // the put_page write-through and dream-cycle reverse-render compute. The // bare join wrote main-source fences to the repo ROOT (the default source's // tree), polluting ~/brain with stray root-level fence files. - const filePath = resolvePageFilePath(target.localPath, target.slug, target.sourceId); - const tmpPath = `${filePath}.tmp`; + let filePath = resolvePageFilePath(target.localPath, target.slug, target.sourceId); return withPageLock( target.slug, async () => { // 1. Read existing body or stub-create. - let body: string; + let body: string | null = null; if (existsSync(filePath)) { body = readFileSync(filePath, 'utf-8'); } else { + // #3069: the slug-derived path missed, but the page may still exist + // on disk under a different basename — vault files like + // `10-people/First Last.md` import with slug `10-people/first-last`, + // so `/.md` doesn't exist even though the page does. + // Stub-creating next to the real file (a) duplicates the page and + // (b) restarts fence row_num at 1 on the empty stub, colliding with + // the real page's existing DB rows on idx_facts_fence_key. Resolve + // via the page row (sync stamps source_path + import_filename) + // before concluding the page doesn't exist. + let pageRow: { source_path: string | null; import_filename: string | null } | null = null; + try { + const rows = await engine.executeRaw<{ source_path: string | null; import_filename: string | null }>( + `SELECT source_path, import_filename FROM pages WHERE slug = $1 AND source_id = $2 AND deleted_at IS NULL LIMIT 1`, + [target.slug, target.sourceId], + ); + pageRow = rows[0] ?? null; + } catch { + // Lookup failed (pre-migration schema, transient) — fall through + // to the pre-#3069 stub path rather than dropping the facts. + } + if (pageRow !== null) { + const candidates: string[] = []; + if (pageRow.source_path) { + candidates.push(join(target.localPath!, pageRow.source_path)); + } + if (pageRow.import_filename) { + const name = pageRow.import_filename.endsWith('.md') + ? pageRow.import_filename + : `${pageRow.import_filename}.md`; + candidates.push(join(dirname(filePath), name)); + } + const hit = candidates.find((c) => existsSync(c)); + if (hit !== undefined) { + filePath = hit; + body = readFileSync(filePath, 'utf-8'); + } else { + // A page row exists but its backing file can't be located. + // Refuse to stub-create (the empty stub's fence would restart + // row_num at 1 → unique violation against the row's existing + // facts, and a later sync would import the stub OVER the real + // page content). Route to the legacy DB-only path instead so + // the facts aren't dropped. + // eslint-disable-next-line no-console + console.warn( + `[facts] page row exists for slug=${target.slug} (source=${target.sourceId}) but its backing file was not found on disk — refusing to stub-create a duplicate page; routing to legacy DB-only path.`, + ); + return { inserted: 0, ids: [], stubGuardBlocked: true }; + } + } + } + if (body === null) { + // No page row for this slug — genuinely new entity page. // Stub-creation guard. Phantom entity pages at the brain root were // being spawned when resolveEntitySlug fell through to a bare // slugify because pg_trgm scored too low on short bare names. The @@ -238,6 +289,7 @@ export async function writeFactsToFence( } // 3. Atomic write: .tmp first, then parse-validate, then rename. + const tmpPath = `${filePath}.tmp`; writeFileSync(tmpPath, body, 'utf-8'); // 4. Parse-before-rename: re-read the .tmp content and verify the diff --git a/test/doctor-wedged-queue.test.ts b/test/doctor-wedged-queue.test.ts index c69932f1a..787ad91d2 100644 --- a/test/doctor-wedged-queue.test.ts +++ b/test/doctor-wedged-queue.test.ts @@ -97,6 +97,34 @@ describe('issue #1801 fix #3 — computeWedgedQueueCheck', () => { expect(check.message).not.toContain("'q-healthy'"); }); + it('#3063: wedged queue with NO live supervisor → "no worker running", not the DB-pool message', async () => { + await seed('default', 'cycle', 'waiting'); + await seed('default', 'cycle', 'completed', { updatedAtSql: "now() - interval '20 min'" }); + // No gbrain_cycle_locks row for gbrain-supervisor:default. + const check = await computeWedgedQueueCheck(pgLike); + expect(check.status).toBe('fail'); + expect(check.message).toContain('no worker running'); + expect(check.message).toContain('gbrain jobs supervisor start'); + expect(check.message).not.toContain('rebuilds a fresh DB pool'); + }); + + it('#3063: wedged queue WITH a live supervisor lock → keeps the wedged-pool message', async () => { + await seed('default', 'cycle', 'waiting'); + await seed('default', 'cycle', 'completed', { updatedAtSql: "now() - interval '20 min'" }); + await base.executeRaw( + `INSERT INTO gbrain_cycle_locks (id, holder_pid, holder_host, acquired_at, ttl_expires_at, last_refreshed_at) + VALUES ('gbrain-supervisor:default', 12345, 'test-host', now(), now() + interval '5 min', now())`, + ); + try { + const check = await computeWedgedQueueCheck(pgLike); + expect(check.status).toBe('fail'); + expect(check.message).toContain('worker alive but not claiming work'); + expect(check.message).toContain('rebuilds a fresh DB pool'); + } finally { + await base.executeRaw(`DELETE FROM gbrain_cycle_locks WHERE id = 'gbrain-supervisor:default'`); + } + }); + it('returns ok on PGLite (no multi-process worker surface)', async () => { const check = await computeWedgedQueueCheck(base as unknown as BrainEngine); expect(check.status).toBe('ok'); diff --git a/test/fence-write.test.ts b/test/fence-write.test.ts index 3bcb0c05b..9e7852ff6 100644 --- a/test/fence-write.test.ts +++ b/test/fence-write.test.ts @@ -273,6 +273,74 @@ describe('writeFactsToFence — stub guard (v0.34.5)', () => { }); }); +describe('writeFactsToFence — basename ≠ slug (#3069)', () => { + test('resolves the real file via the page row instead of stub-creating a duplicate', async () => { + // Vault file whose basename differs from its slug — the way sync imports + // `10-people/Joey Example.md` as slug `10-people/joey-example`. + mkdirSync(join(brainDir, '10-people'), { recursive: true }); + const realPath = join(brainDir, '10-people/Joey Example.md'); + writeFileSync( + realPath, + '---\ntype: person\ntitle: Joey Example\nslug: 10-people/joey-example\n---\n\n# Joey Example\n\n## Facts\n\n\n| # | claim | kind | confidence | visibility | notability | valid_from | valid_until | source | context |\n|---|-------|------|------------|------------|------------|------------|-------------|--------|---------|\n| 1 | Existing claim | fact | 1.0 | world | medium | 2024-01-01 | | import | |\n\n', + 'utf-8', + ); + await engine.putPage('10-people/joey-example', { + type: 'person', + title: 'Joey Example', + compiled_truth: '# Joey Example', + timeline: '', + frontmatter: {}, + content_hash: 'x', + source_path: '10-people/Joey Example.md', + import_filename: 'Joey Example', + }); + + const result = await writeFactsToFence( + engine, + { sourceId: 'default', localPath: brainDir, slug: '10-people/joey-example' }, + [baseInput({ fact: 'New claim after rename' })], + ); + + expect(result.inserted).toBe(1); + expect(result.stubGuardBlocked).toBeUndefined(); + // No duplicate stub next to the real page. + expect(existsSync(join(brainDir, '10-people/joey-example.md'))).toBe(false); + // The fact landed on the REAL file, continuing the fence's row_num + // sequence (a stub would have restarted at 1 → idx_facts_fence_key + // collision against the real page's DB rows). + const body = readFileSync(realPath, 'utf-8'); + expect(body).toContain('New claim after rename'); + // eslint-disable-next-line @typescript-eslint/no-explicit-any + const rows = await (engine as any).db.query( + `SELECT row_num FROM facts WHERE source_markdown_slug = '10-people/joey-example'`, + ); + expect(rows.rows[0].row_num).toBe(2); + }); + + test('page row exists but backing file is gone → stubGuardBlocked, no stub created', async () => { + await engine.putPage('10-people/ghost-page', { + type: 'person', + title: 'Ghost', + compiled_truth: '', + timeline: '', + frontmatter: {}, + content_hash: 'y', + source_path: '10-people/Ghost Page.md', // never written to disk + import_filename: 'Ghost Page', + }); + + const result = await writeFactsToFence( + engine, + { sourceId: 'default', localPath: brainDir, slug: '10-people/ghost-page' }, + [baseInput()], + ); + + expect(result.inserted).toBe(0); + expect(result.stubGuardBlocked).toBe(true); + expect(existsSync(join(brainDir, '10-people/ghost-page.md'))).toBe(false); + }); +}); + describe('lookupSourceLocalPath', () => { test('returns the configured local_path for an existing source', async () => { const got = await lookupSourceLocalPath(engine, 'default'); diff --git a/test/nightly-quality-probe.test.ts b/test/nightly-quality-probe.test.ts index 5f145e903..a6b123391 100644 --- a/test/nightly-quality-probe.test.ts +++ b/test/nightly-quality-probe.test.ts @@ -132,7 +132,7 @@ describe('runNightlyQualityProbe (DI stub harness)', () => { }); }); - test('enabled + recent run within 24h → outcome: rate_limited', async () => { + test('enabled + recent run within 24h → outcome: rate_limited (no audit row for the skip)', async () => { // Pre-seed a recent audit event by running the probe once first. await withEnv({ GBRAIN_AUDIT_DIR: auditTmp }, async () => { // First run succeeds. @@ -140,9 +140,28 @@ describe('runNightlyQualityProbe (DI stub harness)', () => { // Second run, same hour → rate_limited. const r2 = await runNightlyQualityProbe(makeDeps()); expect(r2.outcome).toBe('rate_limited'); + // #3064: the skip does NOT log an audit row — autopilot ticks every + // ~5 min, so skip rows would spam the JSONL and (pre-fix) re-arm the + // 24h window on every tick, muting the probe forever after one run. const events = await readEvents(); - expect(events.length).toBe(2); - expect(events[1].outcome).toBe('rate_limited'); + expect(events.length).toBe(1); + expect(events[0].outcome).toBe('pass'); + }); + }); + + test('#3064 regression: historical rate_limited skip rows do NOT re-arm the 24h window', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: auditTmp }, async () => { + const { logQualityProbeEvent } = await import('../src/core/audit-quality-probe.ts'); + const now = new Date(); + const zero = { exit_code: 0, pass_count: 0, fail_count: 0, inconclusive_count: 0, error_count: 0, est_cost_usd: 0 }; + // Real run 25h ago (outside the window)... + logQualityProbeEvent({ outcome: 'pass', ts: new Date(now.getTime() - 25 * 3600_000).toISOString(), ...zero }); + // ...plus skip rows a pre-fix brain logged on every autopilot tick. + logQualityProbeEvent({ outcome: 'rate_limited', ts: new Date(now.getTime() - 10 * 60_000).toISOString(), ...zero }); + logQualityProbeEvent({ outcome: 'rate_limited', ts: new Date(now.getTime() - 5 * 60_000).toISOString(), ...zero }); + + const r = await runNightlyQualityProbe(makeDeps({ now: () => now })); + expect(r.outcome).toBe('pass'); // pre-fix: 'rate_limited' forever }); });