fix(vfs): the old-root sweep narrates only when it has something to say

The release gate's own output caught this: every test brain printed
"[VFS] old-root sweep complete in 1ms and recorded" — hundreds of lines — and
a consumer would get two of them on the first open of every store.

They were emitted on the always-visible channel, which a production log level
deliberately CANNOT silence. That channel exists so an operator can always
learn why a database is slow; a 0ms no-op on a fresh store is not that, and
announcing it there trains people to ignore the one channel built to be
impossible to ignore. It was also inconsistent with every other narration in
this work, all of which is silent under a threshold.

The sweep now speaks when it has something to say — duplicate roots removed, or
a wall over a second that a person watching a slow first open deserves
explained — and otherwise does its work, records its marker, and stays quiet.
cleanupOldRoots() reports what it removed so the decision rests on a fact
rather than on a guess.

Pin: a fresh store's sweep emits nothing on the channel and still records its
marker, so the silence can never be mistaken for the work being skipped.
This commit is contained in:
David Snelling 2026-08-28 12:30:30 -07:00
parent 42e2da259b
commit d49148e140
2 changed files with 56 additions and 11 deletions

View file

@ -20,6 +20,7 @@ import { join } from 'node:path'
import { Brainy } from '../../src/brainy.js'
import { NounType } from '../../src/types/graphTypes.js'
import { VirtualFileSystem } from '../../src/vfs/VirtualFileSystem.js'
import { prodLog } from '../../src/utils/logger.js'
describe('the VFS old-root sweep', () => {
const dirs: string[] = []
@ -80,6 +81,32 @@ describe('the VFS old-root sweep', () => {
expect(sweepSpy).not.toHaveBeenCalled()
}, 180_000)
it('a sweep that removes nothing on a fresh store says nothing', async () => {
const dir = mkdtempSync(join(tmpdir(), 'brainy-root-sweep-quiet-'))
dirs.push(dir)
// The always-visible channel cannot be silenced by a log level, so a line
// on it has to earn its place. A fresh store's sweep finds no duplicate
// roots and costs a millisecond — it must do its work, record its marker,
// and stay quiet, or it trains operators to ignore the one channel that
// exists to be impossible to ignore.
const narrated: string[] = []
const spy = vi.spyOn(prodLog, 'narrate').mockImplementation(((...args: unknown[]) => {
narrated.push(args.map((a) => String(a)).join(' '))
}) as typeof prodLog.narrate)
const brain = await open(dir)
await (brain.vfs as unknown as { whenRootSweepSettled: () => Promise<void> }).whenRootSweepSettled()
spy.mockRestore()
expect(narrated.filter((l) => /old-root sweep/i.test(l))).toEqual([])
// ...and it still did the work: the marker is recorded, so no future open sweeps.
expect(
existsSync(join(dir, '_system', 'vfs-root-sweep.json')) ||
existsSync(join(dir, '_system', 'vfs-root-sweep.json.gz'))
).toBe(true)
}, 180_000)
it('the open does not wait for the sweep', async () => {
const dir = mkdtempSync(join(tmpdir(), 'brainy-root-sweep-async-'))
dirs.push(dir)