From 88e79729d39744e35c188bca22ce0786946973d6 Mon Sep 17 00:00:00 2001 From: David Snelling Date: Tue, 1 Sep 2026 12:17:55 -0700 Subject: [PATCH] perf(open): pending-embed recovery is bounded by a low-water mark and runs behind the doors MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The recovery fold scanned the generation log from generation 1 at every open, on the open's foreground — O(whole history) on long-lived brains (measured at two minutes of a large brain's open). Now an advisory mark records the log's head whenever the pending set drains to empty (and at clean close when empty); recovery scans from the mark + 1. The mark is advisory and monotone-safe: stale-low costs a longer scan, never a marker. The fold itself moves behind the doors as a latched background task — the embed worker starts when it settles, and awaitPendingEmbeds() and close() wait on the latch first, so no caller can observe a half-recovered set. A pending embed's outcome was always eventual; moving its recovery off the foreground changes when the worker starts, never whether a marker is honored. Pinned in tests/integration/pending-embed-low-water.test.ts: the drain writes the mark and the next open scans from mark + 1; a pending embed enqueued after the mark survives an unclean stop; open arms the fold as a background latch the barrier waits on; a clean close writes the mark even without a drain. --- src/brainy.ts | 131 ++++++++++++---- .../pending-embed-low-water.test.ts | 145 ++++++++++++++++++ 2 files changed, 249 insertions(+), 27 deletions(-) create mode 100644 tests/integration/pending-embed-low-water.test.ts diff --git a/src/brainy.ts b/src/brainy.ts index 06c947c2..c9f24873 100644 --- a/src/brainy.ts +++ b/src/brainy.ts @@ -1820,31 +1820,31 @@ export class Brainy implements BrainyInterface { // a deferred write's ack and its background embed DELAYED a vector; // this is where it lands. if (!this.isReadOnly) { - try { - await step( - 'bridge-pending-embed-sidecars', - 'migrating any pre-log deferred-embed marker files into the generation log', - () => this.bridgeLegacyPendingEmbedSidecars() - ) - await step( - 'recover-pending-embeds', - 'folding the generation log\'s deferred-embed markers back into the pending set', - () => this.recoverPendingEmbedsFromLog() - ) - if (this._pendingEmbedIds.size > 0) { - prodLog.info( - `[Brainy] ${this._pendingEmbedIds.size} deferred embed(s) pending from a previous ` + - `session — resuming in the background` + // BEHIND THE DOORS (the open pays nothing here): the bridge + the + // recovery fold run as one latched background task; the embed worker + // starts when it settles. A pending embed's outcome was always + // eventual — moving its recovery off the open's foreground changes + // when the worker starts, never whether a marker is honored. + // awaitPendingEmbeds() and close() wait on the latch first. + this._pendingEmbedRecovery = (async () => { + try { + await this.bridgeLegacyPendingEmbedSidecars() + await this.recoverPendingEmbedsFromLog() + if (this._pendingEmbedIds.size > 0) { + prodLog.info( + `[Brainy] ${this._pendingEmbedIds.size} deferred embed(s) pending from a previous ` + + `session — resuming in the background` + ) + const t = setTimeout(() => this.kickEmbedWorker(), 0) + ;(t as { unref?: () => void }).unref?.() + } + } catch (err) { + prodLog.warn( + `[Brainy] pending-embed recovery failed: ${(err as Error).message} — ` + + `the log's markers remain durable; recovery retries next open` ) - const t = setTimeout(() => this.kickEmbedWorker(), 0) - ;(t as { unref?: () => void }).unref?.() } - } catch (err) { - prodLog.warn( - `[Brainy] pending-embed recovery failed: ${(err as Error).message} — ` + - `the log's markers remain durable; recovery retries next open` - ) - } + })() } // PHASE 4 of 5 — "VFS bootstrap": shutdown-hook registration, blob @@ -2408,6 +2408,19 @@ export class Brainy implements BrainyInterface { */ private static readonly PENDING_EMBED_PREFIX = '_system/pending_embeds/' + /** + * Storage-root-relative path of the ADVISORY pending-embed low-water mark: + * `{ generation, writtenAt }`, written whenever the pending set drains to + * empty (and at clean close when empty). Every marker in facts at or below + * `generation` is consumed, so recovery scans from `generation + 1`. The + * mark is advisory and monotone-safe: stale-low costs a longer scan, never + * a lost marker; it is never required for correctness. + */ + private static readonly PENDING_EMBED_LOWWATER_PATH = '_system/pending_embeds_lowwater.json' + + /** Resolves when the background pending-embed recovery fold has settled (open arms it). */ + private _pendingEmbedRecovery: Promise | null = null + /** * @description Mark a deferred embed pending (MT5): the id joins the * in-memory fast-path set and the returned `embed.pending` record is @@ -2435,6 +2448,40 @@ export class Brainy implements BrainyInterface { */ private clearPendingEmbed(id: string): void { this._pendingEmbedIds.delete(id) + if (this._pendingEmbedIds.size === 0) this.maybeWriteEmbedLowWater() + } + + /** + * @description Advance the advisory low-water mark: called at drain-to-empty + * (and at clean close when empty), it records the fact log's CURRENT head — + * with the set empty, every marker at or below the head has been consumed, + * so the next open's recovery fold scans only what comes after. Fire-and- + * forget at the drain (close() awaits the core); loud on failure: a missed + * write costs the next open a longer scan, never a marker. No-op without a + * fact log (no durable markers exist there) and on read-only opens. + */ + private maybeWriteEmbedLowWater(): void { + void this.writeEmbedLowWater() + } + + /** The awaitable core of {@link maybeWriteEmbedLowWater} — close() awaits it. */ + private async writeEmbedLowWater(): Promise { + if (this.isReadOnly) return + const log = this.generationStore ? this.generationStore.getFactLog() : null + if (!log) return + const generation = log.headGeneration() + if (!(generation > 0)) return + try { + await this.storage.writeRawObject(Brainy.PENDING_EMBED_LOWWATER_PATH, { + generation, + writtenAt: Date.now() + }) + } catch (err) { + prodLog.warn( + `[Brainy] pending-embed low-water write failed at generation ${generation}: ` + + `${(err as Error).message} — the next open scans from the previous mark` + ) + } } /** @@ -2445,9 +2492,14 @@ export class Brainy implements BrainyInterface { * survives the fold is exactly the set of acknowledged deferred writes * whose vectors have not landed. * - * BOUND (honest): no durable low-water mark exists for the earliest - * unconsumed pending, so the fold scans the log's committed facts from - * generation 1 — a sequential read of the log at open, O(log bytes). + * BOUND: the scan starts at the advisory low-water mark + * ({@link Brainy.PENDING_EMBED_LOWWATER_PATH}) — the log head at which the + * pending set last drained to empty — so a settled brain reads only the + * facts since then, not its whole history. Without a mark (first open + * after upgrade) it scans from generation 1, once; a stale-low mark costs + * a longer scan, never a marker. The fold runs BEHIND the doors (open + * arms it as a background task and the embed worker starts when it + * settles); {@link awaitPendingEmbeds} and close() wait for it first. * It is SKIPPED WHOLESALE when the log has never had a v2 tail * ({@link FactLog.hasV2History} — v1 facts cannot carry marker records), * so pre-cutover brains pay nothing; on a mixed log the scan still reads @@ -2460,7 +2512,18 @@ export class Brainy implements BrainyInterface { private async recoverPendingEmbedsFromLog(): Promise { const log = this.generationStore.getFactLog() if (!log || !log.hasV2History()) return - const scan = log.scanFacts({ fromGeneration: 1 }) + let fromGeneration = 1 + try { + const mark = (await this.storage.readRawObject(Brainy.PENDING_EMBED_LOWWATER_PATH)) as { + generation?: number + } | null + if (mark && typeof mark.generation === 'number' && mark.generation > 0) { + fromGeneration = mark.generation + 1 + } + } catch { + // No mark (or unreadable): scan from 1 — correctness over cost. + } + const scan = log.scanFacts({ fromGeneration }) for await (const batch of scan.batches()) { for (const fact of batch.facts) { for (const record of fact.records ?? []) { @@ -2647,6 +2710,7 @@ export class Brainy implements BrainyInterface { * before I proceed" callers use this; nothing else ever needs to wait. */ public async awaitPendingEmbeds(): Promise { + if (this._pendingEmbedRecovery) await this._pendingEmbedRecovery while (this._pendingEmbedIds.size > 0 || this._embedWorkerFlight) { this.kickEmbedWorker() await (this._embedWorkerFlight ?? Promise.resolve()) @@ -19443,6 +19507,19 @@ export class Brainy implements BrainyInterface { * terminal releases have run. */ async close(): Promise { + if (this._pendingEmbedRecovery) { + // Settle the background marker fold before the durable steps — its scan + // is bounded by the low-water mark (a full scan happens at most once, + // on the first open after upgrade). + const settleStart = Date.now() + await this._pendingEmbedRecovery + const settleMs = Date.now() - settleStart + if (settleMs >= 1000) { + prodLog.info(`[Brainy] close: pending-embed recovery settled in ${settleMs}ms`) + } + this._pendingEmbedRecovery = null + } + if (this._pendingEmbedIds.size === 0) await this.writeEmbedLowWater() let closeFailure: unknown = null try { await this.closeDurableSteps() diff --git a/tests/integration/pending-embed-low-water.test.ts b/tests/integration/pending-embed-low-water.test.ts new file mode 100644 index 00000000..ff01b349 --- /dev/null +++ b/tests/integration/pending-embed-low-water.test.ts @@ -0,0 +1,145 @@ +/** + * @module tests/integration/pending-embed-low-water + * @description The pending-embed recovery fold is bounded and background (10.4.9). + * + * The fold used to scan the generation log from generation 1 at EVERY open, + * on the open's foreground — O(whole history) per open on long-lived brains. + * Now: an advisory low-water mark (`_system/pending_embeds_lowwater.json`) + * records the committed generation whenever the pending set drains to empty, + * recovery scans from `mark + 1`, and the fold runs behind the doors as a + * latched background task the worker, `awaitPendingEmbeds()` and `close()` + * wait on. The mark is advisory: stale-low costs a longer scan, never a + * marker — a pending embed enqueued before a crash is still recovered. + */ +import { describe, it, expect, afterEach, vi } from 'vitest' +import { mkdtempSync, rmSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { Brainy } from '../../src/brainy' +import { NounType } from '../../src/types/graphTypes' + +const LOWWATER_PATH = '_system/pending_embeds_lowwater.json' + +describe('pending-embed recovery: bounded by the low-water mark, behind the doors', () => { + const roots: string[] = [] + const dir = (): string => { + const d = mkdtempSync(join(tmpdir(), 'brainy-lowwater-')) + roots.push(d) + return d + } + const open = async (root: string): Promise> => { + const brain = new Brainy({ + requireSubtype: false, + storage: { type: 'filesystem', path: root } + }) + await brain.init() + return brain + } + + afterEach(() => { + for (const d of roots.splice(0)) rmSync(d, { recursive: true, force: true }) + }) + + it('drain-to-empty writes the mark, and the next open scans from mark + 1', async () => { + const root = dir() + const brain = await open(root) + // Hold the worker so the pending state is observable, then release it. + const realKick = (brain as any).kickEmbedWorker.bind(brain) + ;(brain as any).kickEmbedWorker = () => {} + await brain.add({ + id: 'row-1', + data: 'the first deferred row', + type: NounType.Thing, + deferEmbedding: true + }) + expect(brain.pendingEmbedCount()).toBeGreaterThan(0) + ;(brain as any).kickEmbedWorker = realKick + await brain.awaitPendingEmbeds() + // The drain wrote the advisory mark (fire-and-forget: settle the microtask). + await new Promise((r) => setTimeout(r, 50)) + const mark = (await (brain as any).storage.readRawObject(LOWWATER_PATH)) as { + generation: number + } | null + expect(mark).not.toBeNull() + expect(mark!.generation).toBeGreaterThan(0) + await brain.close() + + const brain2 = await open(root) + const log = (brain2 as any).generationStore.getFactLog() + const scanSpy = vi.spyOn(log, 'scanFacts') + try { + await (brain2 as any).recoverPendingEmbedsFromLog() + expect(scanSpy).toHaveBeenCalledTimes(1) + const opts = scanSpy.mock.calls[0][0] as { fromGeneration?: number } + expect(opts.fromGeneration).toBeGreaterThanOrEqual(mark!.generation + 1) + } finally { + scanSpy.mockRestore() + await brain2.close() + } + }) + + it('a pending embed enqueued after the mark survives an unclean stop', async () => { + const root = dir() + const brain = await open(root) + await brain.add({ id: 'settled', data: 'lands before the mark', type: NounType.Thing }) + await brain.awaitPendingEmbeds() + await new Promise((r) => setTimeout(r, 50)) + + // A deferred write whose embed never lands: block the worker, then drop + // the instance without close() — the unclean-stop shape. + ;(brain as any).kickEmbedWorker = () => {} + await brain.add({ + id: 'orphan', + data: 'enqueued then abandoned', + type: NounType.Thing, + deferEmbedding: true + }) + expect(brain.pendingEmbedCount()).toBeGreaterThan(0) + // No close(): simulate the crash by releasing only the writer lock so the + // next open can proceed. + await (brain as any).storage.releaseWriterLock() + + const brain2 = await open(root) + await (brain2 as any)._pendingEmbedRecovery + expect(brain2.pendingEmbedCount()).toBeGreaterThan(0) + await brain2.awaitPendingEmbeds() + expect(brain2.pendingEmbedCount()).toBe(0) + await brain2.close() + // Reap the crashed instance: its fence is gone, so close() fails loudly — + // swallow that here; the point is clearing its watchers and registry entry. + await brain.close().catch(() => undefined) + }) + + it('open arms the fold as a background latch; awaitPendingEmbeds waits on it', async () => { + const root = dir() + const brain = await open(root) + await brain.add({ id: 'a-row', data: 'some data', type: NounType.Thing }) + await brain.awaitPendingEmbeds() + await brain.close() + + const brain2 = await open(root) + // The latch exists the moment init() returns (writable filesystem brain)… + expect((brain2 as any)._pendingEmbedRecovery).not.toBeNull() + // …and the barrier settles it before answering. + await brain2.awaitPendingEmbeds() + expect(brain2.pendingEmbedCount()).toBe(0) + await brain2.close() + }) + + it('a clean close with an empty set writes the mark even if no drain happened', async () => { + const root = dir() + const brain = await open(root) + await brain.add({ id: 'r1', data: 'row one', type: NounType.Thing }) + await brain.awaitPendingEmbeds() + await brain.close() + // Read the mark back through the storage door (the adapter owns the + // on-disk encoding), on a fresh instance. + const brain2 = await open(root) + const mark = (await (brain2 as any).storage.readRawObject(LOWWATER_PATH)) as { + generation: number + } | null + expect(mark).not.toBeNull() + expect(mark!.generation).toBeGreaterThan(0) + await brain2.close() + }) +})