From dadfa61b5fd5baed5a6fcec100dcf54ef3f6dc3e Mon Sep 17 00:00:00 2001
From: David Snelling <david@soulcraft.com>
Date: Wed, 2 Sep 2026 16:17:55 -0700
Subject: [PATCH] =?UTF-8?q?test(idle):=20capture=20the=20stack=20behind=20?=
 =?UTF-8?q?each=20flush=20narration=20=E2=80=94=20the=20line=20alone=20can?=
 =?UTF-8?q?not=20name=20its=20brain?=
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

The self-diagnosis from the last round worked: the box says this brain's own
providers were NOT called, so the flush pairs inside the 90 s window belong to
another brain in the same process. It could not say WHICH, and the advice it
gave — read the 'stdout | <file> > <test>' prefix — cannot work here: vitest
tags a stdout block with the test that is RUNNING, and these lines are captured
by this test's own console hook anyway. Teeing them through would only ever
print this test's name.

The call stack does name the driver, so it is captured beside each line and the
first one is reported: `kickBackgroundFlush('idle')` under `armIdleFlushTimer`
is some brain's cadence timer, the deferred-embed worker's commit path is a
brain still landing vectors, and a bare `flush()` is an explicit caller.

Why that distinction settles it. A flush only narrates PAST the dirty gate, and
`_dirtySinceLastFlush` is set in exactly three places — `noteWriteForPersistence()`
(both commit paths, and the deferred-embed worker lands its vectors through the
single-op one), `clear()`, and `repairIndex()`. So a narrating flush is a flush
whose brain really did commit a write; "0 ms" is the flush being cheap, not the
flush being empty. That reading rules OUT the re-arming-follow-up theory: the
queued follow-up is armed only by a concurrent flush() caller, cleared before
promotion, and a promoted run over a clean brain returns at the dirty gate
without touching a provider or printing a line.

Context the message now carries: the suite runs every file in ONE process, and
a create-versus-close scan puts 67 test files above the line — more brains made
than closed. This assertion is downstream of that, and the next red arrives with
the stack that names which one.
---
 tests/integration/idle-costs-nothing.test.ts | 26 ++++++++++++++++----
 1 file changed, 21 insertions(+), 5 deletions(-)

diff --git a/tests/integration/idle-costs-nothing.test.ts b/tests/integration/idle-costs-nothing.test.ts
index 2374627e..7e664a28 100644
--- a/tests/integration/idle-costs-nothing.test.ts
+++ b/tests/integration/idle-costs-nothing.test.ts
@@ -70,8 +70,22 @@ describe('an idle brain costs nothing', () => {
     await brain.flush()
 
     const logged: string[] = []
+    // The STACK behind each narration, kept beside the line it belongs to.
+    // vitest tags a stdout block with the test that is RUNNING, not the brain
+    // that wrote it, so teeing these lines through would only ever name this
+    // test. The call stack does name the driver: `kickBackgroundFlush('idle')`
+    // under `armIdleFlushTimer` is a cadence flush on some brain, the deferred-
+    // embed worker's commit path is a brain still landing vectors, and a bare
+    // `flush()` is an explicit caller. That distinction is the whole question.
+    const stacks: string[] = []
     const origLog = console.log
-    console.log = ((...a: unknown[]) => { logged.push(a.map(String).join(' ')) }) as typeof console.log
+    console.log = ((...a: unknown[]) => {
+      const line = a.map(String).join(' ')
+      logged.push(line)
+      if (/All indexes flushed to disk|Flushing Brainy indexes/.test(line)) {
+        stacks.push(new Error('flush narration').stack ?? '(no stack)')
+      }
+    }) as typeof console.log
 
     // Watch the providers directly: a flush that runs calls all of them.
     const storage = (brain as unknown as { storage: { flushCounts: () => Promise<void> } }).storage
@@ -113,10 +127,12 @@ describe('an idle brain costs nothing', () => {
     )
     expect(
       flushChatter,
-      `a flush narrated during the ${IDLE_WATCH_MS}ms idle window. This brain's own ` +
-        `providers were NOT called (asserted above), so the lines below were printed by ` +
-        `another brain alive in this process — find it by the 'stdout | <file> > <test>' ` +
-        `prefix in the run log:\n${flushChatter.join('\n')}`
+      `${flushChatter.length} flush line(s) narrated during the ${IDLE_WATCH_MS}ms idle ` +
+        `window. This brain's own providers were NOT called (asserted above), so another ` +
+        `brain alive in this process printed them — the suite runs every file in ONE ` +
+        `process and 67 test files create more brains than they close.\n` +
+        `${flushChatter.join('\n')}\n\n` +
+        `The stack behind the first one names the driver:\n${stacks[0] ?? '(none captured)'}`
     ).toEqual([])
   }, 180_000)