open-brainy/tests/integration/repair-narration.test.ts

/**
 * @module tests/integration/repair-narration
 * @description A REPAIR NARRATES ITSELF, AND ITS RECEIPT SAYS WHERE THE TIME
 * WENT.
 *
 * On a production store (14,647 nouns / 73,070 verbs) a `repairIndex()` ran
 * for more than thirty minutes at roughly a full core with ZERO log lines
 * between its start and its end, while the read doors kept serving. The
 * operator could tell it was alive only from `top`, and could not tell which
 * of its single-threaded walks it was inside. The law pinned here:
 *
 *   - every phase announces itself BEFORE it works, naming what it is about
 *     to walk;
 *   - a heartbeat names the phase still running, at a bounded cadence, for as
 *     long as it runs;
 *   - every phase reports its own wall, and that wall is carried in the typed
 *     receipt (`RepairFamilyReport.durationMs`) — not only in a log line.
 *
 * All of it on the narration channel, which production's log clamp cannot
 * silence (see tests/integration/open-narration.test.ts).
 */

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.js'
import { NounType } from '../../src/types/graphTypes.js'
import { FileSystemStorage } from '../../src/storage/adapters/fileSystemStorage.js'
import { prodLog, configureLogger, LogLevel } from '../../src/utils/logger.js'

describe('repairIndex narration', () => {
  const dirs: string[] = []
  const brains: Brainy[] = []

  afterEach(async () => {
    for (const b of brains.splice(0)) {
      try { await b.close() } catch { /* already closed */ }
    }
    for (const d of dirs.splice(0)) {
      try { rmSync(d, { recursive: true, force: true }) } catch { /* ignore */ }
    }
    configureLogger({ level: LogLevel.INFO })
  })

  async function seededBrain(): Promise<Brainy> {
    const dir = mkdtempSync(join(tmpdir(), 'brainy-repair-narration-'))
    dirs.push(dir)
    const brain = new Brainy({ requireSubtype: false, storage: { type: 'filesystem', path: dir } })
    brains.push(brain)
    await brain.init()
    for (let i = 0; i < 5; i++) {
      await brain.add({ data: `repair subject ${i}`, type: NounType.Concept })
    }
    await brain.flush()
    return brain
  }

  it('announces every phase, reports its wall, and carries that wall in the receipt', async () => {
    const brain = await seededBrain()
    const narrateSpy = vi.spyOn(prodLog, 'narrate')

    const report = await brain.repairIndex()

    const lines = narrateSpy.mock.calls.map(([m]) => String(m))

    // Every family that ran has BOTH a start line and a finish line naming it.
    for (const family of report.families) {
      const started = lines.filter((l) => l.includes(`"${family.family}" started —`))
      const finished = lines.filter((l) =>
        new RegExp(`"${family.family}" finished in \\d+ms`).test(l)
      )
      expect(finished.length, `no finish line for ${family.family}`).toBeGreaterThanOrEqual(1)
      // A skipped family may be recorded without a start line only if it never
      // began; every family that began must have announced itself.
      if (family.checked) {
        expect(started.length, `no start line for ${family.family}`).toBeGreaterThanOrEqual(1)
      }
      // THE RECEIPT CARRIES THE WALL — not only the log.
      expect(typeof family.durationMs, `${family.family} has no durationMs`).toBe('number')
      expect(family.durationMs).toBeGreaterThanOrEqual(0)
    }

    // The closing line accounts for the whole repair, per family.
    const closing = lines.filter((l) => /repairIndex complete in \d+ms/.test(l))
    expect(closing.length).toBe(1)
    expect(closing[0]).toMatch(/@\d+ms/)
  }, 180_000)

  it('heartbeats while a single phase is still walking', async () => {
    const brain = await seededBrain()

    // Make one phase long enough to cross the heartbeat cadence, exactly as a
    // multi-minute canonical walk does on a real store.
    const proto = FileSystemStorage.prototype as unknown as Record<
      string,
      (...args: unknown[]) => Promise<unknown>
    >
    const realPrune = proto.pruneOrphanedEntities
    proto.pruneOrphanedEntities = async function slow(this: unknown, ...args: unknown[]) {
      await new Promise((r) => setTimeout(r, 6_500))
      return realPrune.apply(this, args)
    }
    // Clamped as production clamps it: the narration must survive.
    configureLogger({ level: LogLevel.ERROR })
    const narrateSpy = vi.spyOn(prodLog, 'narrate')
    try {
      await brain.repairIndex()
    } finally {
      proto.pruneOrphanedEntities = realPrune
    }

    const beats = narrateSpy.mock.calls
      .map(([m]) => String(m))
      .filter((l) => /repairIndex: still in "orphaned-containers" after \d+s/.test(l))
    expect(beats.length).toBeGreaterThanOrEqual(1)
    expect(beats[0]).toMatch(/ghost\/scar containers/)
  }, 180_000)
})