From 298cb6dacaac9ef80db65a723d65cbd53c15d23e Mon Sep 17 00:00:00 2001 From: David Snelling Date: Mon, 31 Aug 2026 09:07:18 -0700 Subject: [PATCH] fix(recovery): a torn generation-log tail is a terminal verdict, never a wait MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two halves of one defect, found by a seeded-SIGKILL crash lane. THE FALSE POSITIVE. stampEntityTree() recorded generationStore.generation() — the ALLOCATED counter, a number a write in flight has claimed and may never commit — while the JSDoc beside it already said the source is the committed generation. Every crash inside a write window therefore produced a spurious verdict at the next open: either 'sourceGeneration N is ahead of the log head N-1' (the allocated generation died with the process) or 'rollup invariant nounCount: stamped X, observed Y' (the recovery fold folded facts the stamp's counts predate). Both told the operator to run repairIndex() — a whole-store recount — for a store that was coherent. Measured before this commit: 4 of 11 SIGKILL cycles on a healthy store raised one of the two. The stamp and the open now both read committedGeneration(), which is what every other open-time watermark in the class already reasons about. THE TERMINAL VERDICT. A stamp still ahead of committed truth after the recovery fold witnesses a generation that is not in the log — the stamp's fsync outlived the tail's, and there is nothing to arrive. That is its own verdict state now ('torn'), never folded in with 'incoherent': the two have opposite cures. A writer open demotes it — the unusable stamped surface is re-derived at the committed generation from the live counters, O(1), straight-line, no loop and no await on external progress, narrated with both count sets, the stamp's path and its committedAt. A read-only open cannot re-stamp, so it says so and names the cure instead of guessing, and still serves. Neither branch waits, and neither locks an owner out of a canonical tree the stamp only describes. Pins: the verifier returns the torn verdict with both generations; a fabricated head-behind-source store narrates precisely, demotes inside a bounded open, serves its rows, and is quiet at the next open (the demotion converges); a read-only open narrates the same verdict and leaves the bytes untouched. --- src/brainy.ts | 121 +++++++++++++++++++- src/db/familyStamp.ts | 32 ++++-- tests/integration/entity-tree-stamp.test.ts | 104 ++++++++++++++++- 3 files changed, 241 insertions(+), 16 deletions(-) diff --git a/src/brainy.ts b/src/brainy.ts index 70d46973..da04577e 100644 --- a/src/brainy.ts +++ b/src/brainy.ts @@ -12497,6 +12497,18 @@ export class Brainy implements BrainyInterface { * healed by `repairIndex()`, whose unconditional recount rebuilds the * rollups from a canonical walk and re-stamps. Best-effort: a stamp-write * fault warns loudly but never fails the flush that carried real data. + * + * THE SOURCE IS `committedGeneration()`, NEVER `generation()`. The latter is + * the ALLOCATED counter — a number a write in flight has claimed and may + * never commit. Stamping it made the stamp's generation label a claim about + * counts it was not taken at, and every crash inside a write window then + * produced a spurious verdict at the next open: either `sourceGeneration N + * is ahead of the log head N-1` (the allocated generation died with the + * process) or `rollup invariant 'nounCount': stamped X, observed Y` (the + * recovery fold folded facts the stamp's counts predate). MEASURED on the + * crash-consistency lane before this line changed: 4 of 11 SIGKILL cycles on + * a coherent store raised one of those two verdicts, each of them naming + * `repairIndex()` — a whole-store recount — as the cure for nothing. */ private async stampEntityTree(): Promise { if (this.isReadOnly) return @@ -12507,7 +12519,7 @@ export class Brainy implements BrainyInterface { ]) await writeFamilyStamp(this.storage, ENTITY_TREE_STAMP_PATH, { family: 'entity-tree', - sourceGeneration: this.generationStore.generation(), + sourceGeneration: this.generationStore.committedGeneration(), members: { mode: 'rollup', invariants: { nounCount, verbCount } } }) } catch (error) { @@ -12520,16 +12532,24 @@ export class Brainy implements BrainyInterface { /** * @description Open-time coherence check for the entity tree's family stamp: - * compare `sourceGeneration` against the log head and the stamped rollup - * invariants against the live counters. Verdicts: + * compare `sourceGeneration` against the store's COMMITTED generation and + * the stamped rollup invariants against the live counters. Verdicts: * - `coherent` / `absent` (legacy store; first flush stamps) → silent. * - `behind` → benign for the tree (it is written BY the commit; only the * stamp is stale — a crash landed between commit and flush). Refreshed at * the next flush. + * - `torn` → a TORN GENERATION-LOG TAIL, handled by + * {@link demoteTornEntityTreeStamp}: terminal, never a wait. * - `incoherent` → LOUD: the tree or its counters diverged from what was * stamped — `repairIndex()` recounts from canonical and re-stamps. * Never blocks open; a fault reading the stamp is surfaced as unverifiable, * never conflated with absence. + * + * THE COMPARISON IS AGAINST `committedGeneration()`, matching what + * {@link stampEntityTree} writes and what every other open-time watermark in + * this class already reasons about (the fact-scan capability, the metadata / + * graph / HNSW watermark verdicts). Comparing against the allocated counter + * was the one place that disagreed, and disagreeing was the whole defect. */ private async verifyEntityTreeStamp(): Promise { let stamp: FamilyStamp | null @@ -12546,11 +12566,16 @@ export class Brainy implements BrainyInterface { this.storage.getNounCount(), this.storage.getVerbCount() ]) - const verdict = verifyFamilyStamp(stamp, this.generationStore.generation(), { + const verdict = verifyFamilyStamp(stamp, this.generationStore.committedGeneration(), { nounCount, verbCount }) - if (verdict.state === 'incoherent') { + if (verdict.state === 'torn') { + await this.demoteTornEntityTreeStamp(stamp as FamilyStamp, verdict.stampSource, verdict.head, { + nounCount, + verbCount + }) + } else if (verdict.state === 'incoherent') { prodLog.warn( `[Brainy] entity-tree stamp INCOHERENT at open: ${verdict.failures.join('; ')}. ` + `The canonical tree or its counters diverged from the stamped state — run ` + @@ -12564,6 +12589,92 @@ export class Brainy implements BrainyInterface { } } + /** + * @description THE TERMINAL VERDICT for a torn generation-log tail. + * + * A stamp whose `sourceGeneration` sits ABOVE the store's committed + * watermark witnesses a generation that is not in the log: the stamp's fsync + * outlived the tail's. By the time this runs, log-authority recovery has + * already folded every intact fact above the manifest and advanced the + * watermark to cover them — so if the stamp is STILL ahead, the generation + * it names is not merely late, it is GONE. There is nothing to wait for. + * + * That is the whole point of this method. A field report of this class + * (single-process store, abrupt termination mid-fold) described a reopen + * that narrated the tear and then held 100% CPU with zero log growth for + * eight minutes before an operator wiped the directory. A recovery that + * cannot say what it is waiting for has no business spinning; the honest + * answer here is a verdict, taken now, at O(1) cost. + * + * WHAT THE VERDICT DOES — the stamped surface is UNUSABLE, so it is + * discarded rather than believed: the stamped counts describe a generation + * that never became durable, and comparing them against live counters can + * only produce noise. The tree itself is not in question (it IS canonical — + * every commit writes it, and the fold re-applied every after-image the log + * still holds), so the demotion is a re-derivation of this family's verified + * surface at the generation the store can actually show: + * + * - WRITER open → re-stamp at `committedGeneration()` from the live + * counters — exactly what the next flush would write, taken now so the + * tear cannot re-narrate on every subsequent open. Both count sets are + * logged so an operator can see whether anything really moved. + * - READER open → a reader cannot re-stamp. Narrate the same terminal + * verdict with the named cure and carry on serving; a read-only inspector + * is never locked out of a store, and never left waiting either. + * + * BOUNDEDNESS: straight-line code. No loop, no retry, no await on any + * external progress signal — the two counter reads and one stamp write are + * the entire cost, and none of them scales with the store. + */ + private async demoteTornEntityTreeStamp( + stamp: FamilyStamp, + stampSource: number, + head: number, + observed: { nounCount: number; verbCount: number } + ): Promise { + const stamped = stamp.members.mode === 'rollup' ? stamp.members.invariants : {} + const detail = + `[Brainy] TORN GENERATION-LOG TAIL at open: ${ENTITY_TREE_STAMP_PATH} witnesses source ` + + `generation ${stampSource} (stamped ${stamp.committedAt}), but the store's committed ` + + `generation is ${head} after crash recovery — the stamp's fsync outlived the log tail's, ` + + `and generation ${stampSource} is not in the log to arrive. Stamped rollups ` + + `${JSON.stringify(stamped)}; observed ${JSON.stringify(observed)}.` + + if (this.isReadOnly) { + prodLog.warn( + `${detail} This open is READ-ONLY, so the stamp cannot be re-derived: the entity-tree ` + + `family stays UNVERIFIED for this session (reads are unaffected — the canonical tree ` + + `is the truth this stamp only describes). Cure: open the store with a writer, or run ` + + `brain.repairIndex() there, to recount from canonical and re-stamp.` + ) + return + } + + const startedAt = Date.now() + try { + await writeFamilyStamp(this.storage, ENTITY_TREE_STAMP_PATH, { + family: 'entity-tree', + sourceGeneration: head, + members: { + mode: 'rollup', + invariants: { nounCount: observed.nounCount, verbCount: observed.verbCount } + } + }) + prodLog.warn( + `${detail} DEMOTED: the unusable stamp was re-derived at committed generation ${head} ` + + `from the live counters in ${Date.now() - startedAt}ms — terminal, not a wait. If the ` + + `observed counts above look wrong for your data, run brain.repairIndex() to recount ` + + `from canonical.` + ) + } catch (error) { + prodLog.warn( + `${detail} The demotion's re-stamp FAILED (${(error as Error).message}) — the tear will ` + + `narrate again at the next open, which is the honest outcome; the store still serves ` + + `from canonical. Cure: run brain.repairIndex() to recount from canonical and re-stamp.` + ) + } + } + /** * Ask the writer process serving this data directory to flush its in-memory * indexes to disk, so a read-only inspector can observe fresh state. diff --git a/src/db/familyStamp.ts b/src/db/familyStamp.ts index 98342884..2f01e935 100644 --- a/src/db/familyStamp.ts +++ b/src/db/familyStamp.ts @@ -12,9 +12,11 @@ * the verified surface is a small set of rollup invariants (entity/ * relationship counts) plus `sourceGeneration`. * - * `sourceGeneration` is the generation of the source-of-truth log this - * projection reflects — open-time coherence becomes a COMPARISON (stamp vs - * log head), not a walk: + * `sourceGeneration` is the COMMITTED generation of the source-of-truth log + * this projection reflects — never the allocated counter, which names a + * generation that may never commit (see {@link StampVerdict.torn}) — so + * open-time coherence becomes a COMPARISON (stamp vs committed head), not a + * walk: * * - equal + invariants hold → coherent, serve. * - behind → the projection missed the tail (crash between commit and stamp); @@ -24,6 +26,9 @@ * - invariants FAIL at equal generation → genuine incoherence: loud, and the * repair ritual (`repairIndex()`, whose recount rebuilds the rollups from a * canonical walk) heals it. + * - AHEAD → a torn generation-log tail: the stamp's fsync outlived the log + * tail's. TERMINAL, never a wait — the generation the stamp names does not + * exist to arrive. * * Stamps are JSON on purpose — every incident gets debugged by reading a * stamp in a terminal. @@ -70,6 +75,12 @@ export type StampVerdict = | { state: 'coherent' } | { state: 'absent' } // legacy store — first stamp writes at the next flush | { state: 'behind'; stampSource: number; head: number } + /** + * TORN GENERATION-LOG TAIL: the stamp witnesses a source generation the + * store's committed watermark can no longer show. TERMINAL — there is no + * generation to wait for, so the open demotes (or refuses) and never spins. + */ + | { state: 'torn'; stampSource: number; head: number } | { state: 'incoherent'; failures: string[] } | { state: 'unverifiable'; reason: string } // a FAULT reading the stamp — never conflated with absence @@ -118,12 +129,15 @@ export function verifyFamilyStamp( ): StampVerdict { if (stamp === null) return { state: 'absent' } if (stamp.sourceGeneration > head) { - // A stamp AHEAD of the log claims state that never committed — the - // projection was stamped against truth that a crash rolled back. - return { - state: 'incoherent', - failures: [`sourceGeneration ${stamp.sourceGeneration} is ahead of the log head ${head}`] - } + // A stamp AHEAD of committed truth witnesses a generation the store can no + // longer show: the stamp's fsync survived a crash that the log tail did + // not. This is the TORN GENERATION-LOG TAIL — its own class, never folded + // in with `incoherent` (a count that drifted at a generation both sides + // agree on), because the two have opposite cures: incoherence is recounted, + // a tear is DEMOTED. It is also terminal by construction — there is no + // generation the open can wait for, because the one the stamp names is + // gone. + return { state: 'torn', stampSource: stamp.sourceGeneration, head } } if (stamp.sourceGeneration < head) { return { state: 'behind', stampSource: stamp.sourceGeneration, head } diff --git a/tests/integration/entity-tree-stamp.test.ts b/tests/integration/entity-tree-stamp.test.ts index deefc5e6..23cc0a15 100644 --- a/tests/integration/entity-tree-stamp.test.ts +++ b/tests/integration/entity-tree-stamp.test.ts @@ -57,7 +57,11 @@ describe('entity-tree family stamp', () => { const invariants = (stamp.members as any).invariants expect(invariants.nounCount).toBe(await brain.storage.getNounCount()) expect(invariants.verbCount).toBe(await brain.storage.getVerbCount()) - expect(stamp.sourceGeneration).toBe(brain.generation()) + // THE SOURCE IS COMMITTED TRUTH, never the allocated counter. Stamping the + // counter labelled the stamp with a generation a write in flight had merely + // claimed, so every crash inside a write window produced a spurious verdict + // at the next open (see the torn-tail pins below). + expect(stamp.sourceGeneration).toBe(brain.generationStore.committedGeneration()) expect(stamp.generation).toBeGreaterThanOrEqual(1) }) @@ -112,6 +116,96 @@ describe('entity-tree family stamp', () => { expect(stillIncoherent).toEqual([]) }) + /** + * Rewrite the on-disk stamp so its `sourceGeneration` sits ABOVE the store's + * committed watermark — the durable shape a torn generation-log tail leaves + * behind (the stamp's fsync outlived the tail's). Fabricated rather than + * crash-produced so the pin is deterministic; the seeded-SIGKILL lane + * (`scripts/crash-consistency.mjs` in the engine repo) produces the same + * shape from a real abrupt termination. + */ + const fabricateTear = (ahead: number): FamilyStamp => { + const file = path.join(dir, `${ENTITY_TREE_STAMP_PATH}.gz`) + const zlib = require('node:zlib') + const raw = JSON.parse(zlib.gunzipSync(fs.readFileSync(file)).toString('utf-8')) as FamilyStamp + const torn: FamilyStamp = { ...raw, sourceGeneration: raw.sourceGeneration + ahead } + fs.writeFileSync(file, zlib.gzipSync(JSON.stringify(torn))) + return torn + } + + it('a torn generation-log tail is a TERMINAL VERDICT at open: narrated, demoted, never a wait', async () => { + for (let i = 0; i < 3; i++) + await brain.add({ data: `torn${i}`, type: 'document', metadata: { i } }) + await brain.close() + const torn = fabricateTear(5) + + const warn = vi.spyOn(prodLog, 'warn') + const startedAt = Date.now() + brain = await open() + const openMs = Date.now() - startedAt + + const tearLines = warn.mock.calls.filter((c) => String(c[0]).includes('TORN GENERATION-LOG TAIL')) + expect(tearLines.length).toBe(1) + const said = String(tearLines[0][0]) + // Narrated PRECISELY: both generations, the file, and the named cure. + expect(said).toContain(`source generation ${torn.sourceGeneration}`) + expect(said).toContain(`committed generation ${brain.generationStore.committedGeneration()}`) + expect(said).toContain(ENTITY_TREE_STAMP_PATH) + expect(said).toContain('DEMOTED') + expect(said).toMatch(/repairIndex\(\)/) + // Terminal, not a wait: the demotion is O(1) straight-line work, so a tear + // cannot turn an open into the 8-minute spin this class was reported as. + expect(openMs).toBeLessThan(30_000) + + // The store SERVES — a tear in a stamp never locks an owner out of the + // canonical tree the stamp merely describes. + expect((await brain.find({ type: 'document', limit: 100 })).length).toBe(3) + + // The demotion CONVERGED: the stamp now names committed truth, and the + // next open is quiet. A verdict that re-narrates every open is a wait + // wearing a different hat. + const restamped = (await readFamilyStamp(brain.storage, ENTITY_TREE_STAMP_PATH)) as FamilyStamp + expect(restamped.sourceGeneration).toBe(brain.generationStore.committedGeneration()) + await brain.close() + const warn2 = vi.spyOn(prodLog, 'warn') + brain = await open() + expect(warn2.mock.calls.filter((c) => String(c[0]).includes('TORN'))).toEqual([]) + }) + + it('a READ-ONLY open on a torn tail refuses to guess: terminal verdict + named cure, no re-stamp', async () => { + await brain.add({ data: 'ro', type: 'document', metadata: {} }) + await brain.close() + const torn = fabricateTear(3) + + const warn = vi.spyOn(prodLog, 'warn') + const reader: any = await Brainy.openReadOnly({ + requireSubtype: false, + storage: { type: 'filesystem', path: dir }, + silent: true, + dimensions: 384 + }) + const tearLines = warn.mock.calls.filter((c) => String(c[0]).includes('TORN GENERATION-LOG TAIL')) + expect(tearLines.length).toBe(1) + const said = String(tearLines[0][0]) + expect(said).toContain('READ-ONLY') + expect(said).toContain('UNVERIFIED') + expect(said).toMatch(/repairIndex\(\)/) + await reader.close() + + // A reader never rewrites the store: read the bytes back off disk (not + // through a writer open, which would demote them) — the torn stamp is + // exactly as it was found. + const onDisk = JSON.parse( + require('node:zlib') + .gunzipSync(fs.readFileSync(path.join(dir, `${ENTITY_TREE_STAMP_PATH}.gz`))) + .toString('utf-8') + ) as FamilyStamp + expect(onDisk.sourceGeneration).toBe(torn.sourceGeneration) + expect(onDisk.generation).toBe(torn.generation) + + brain = await open() + }) + it('the one verifier handles both member modes', () => { const rollup: FamilyStamp = { family: 'x', @@ -127,7 +221,13 @@ describe('entity-tree family stamp', () => { stampSource: 5, head: 9 }) - expect(verifyFamilyStamp(rollup, 3, { nounCount: 10 }).state).toBe('incoherent') // ahead of head + // AHEAD is its own class — a torn generation-log tail, never folded in + // with `incoherent`: the two have opposite cures (recount vs demote). + expect(verifyFamilyStamp(rollup, 3, { nounCount: 10 })).toEqual({ + state: 'torn', + stampSource: 5, + head: 3 + }) expect(verifyFamilyStamp(null, 5, {})).toEqual({ state: 'absent' }) const enumerated: FamilyStamp = {