soulcraftlabs/open-brainy
2
0
Fork 0
Code Issues 1 Pull requests Projects Releases 343 Packages Wiki Activity Actions

perf(idle): the flush-request watch is event-driven; the heartbeat is observability

Browse source 
Three idle-burn items from the steady-state audit, and one correction.

THE FLUSH-REQUEST WATCH (the strongest of them). It readdir'd the request
directory every 500 ms, per brain, for the life of every writer — armed on
every non-reader brain whether or not any inspector process existed. In a process holding many stores that is tens of directory reads per second
on a completely idle service, plus a stale-request GC on every one of them. It now
uses fs.watch, so the arrival itself wakes it and a request is seen SOONER
than the poll saw it. Two concessions ride along, both stated in the code: a
30s safety sweep (fs.watch drops events on some network and fuse filesystems,
and the GC needs a tick of its own — two orders of magnitude fewer reads than
the poll made), and a fall back to the original 500 ms poll, narrated, on a
filesystem that cannot watch at all, because an inspector whose request is
never seen waits forever.

THE WRITER HEARTBEAT goes 10s → 60s. It is observability ONLY — staleness is
decided by pid liveness and the fence compares pid + hostname, so no decision
anywhere reads the timestamp — and at 10s it was a lock-file write every ten
seconds per brain forever, for a value nothing computes with. An operator
still sees a heartbeat inside the minute.

THE HEALTH NARRATION dedupes by CONTENT, not by the provider's generation
counter. That counter bumps on every ledger mutation and rebuild boundary, so
a provider bumping it on routine work re-emitted the same unchanged line on
every read, while one that never bumped could suppress a line whose reasons
had genuinely changed. The generation is still reported; it no longer decides
whether the line is worth saying.

CORRECTION, and it is against my own earlier claim: the idle-flush commit read
a reported idle-CPU observation (many stores, no writes, a flush every ~35s,
over a core burned) as caused by
the flush path. That does not follow — this engine's cadence is write-driven
(every trigger runs through noteWriteForPersistence, which only a committed
write calls), so something was CALLING flush() on those brains and the caller
is still unidentified. The clean-flush gate makes such a call free; it does not
account for it. The code comments and the idle lane now say exactly that.

Pins: tests/integration/flush-watcher-event-driven.test.ts — an idle writer
makes at most one request-directory read in 8 seconds (the old poll made ~16),
and a dropped request is still acked well inside the safety sweep.
This commit is contained in:
David Snelling 2026-08-28 11:25:47 -07:00
parent 417ddb5143
commit fb1da1c56d
4 changed files with 245 additions and 36 deletions
Download patch file Download diff file Expand all files Collapse all files

116
src/storage/adapters/fileSystemStorage.ts
View file

@ -107,7 +107,23 @@ export class FileSystemStorage extends BaseStorage {
* "the previous writer died" without inferring either from a pid.
*/
private static readonly WRITER_CLOSE_FILE = '_writer.close'
private static readonly WRITER_HEARTBEAT_MS = 10_000
/**
* How often the lock file's `lastHeartbeat` is rewritten.
*
* THIS IS OBSERVABILITY ONLY, and the cadence follows from that. Staleness
* is decided by PID LIVENESS alone (see isWriterLockStale) and the fence
* compares pid + hostname — no decision anywhere reads this timestamp. It
* exists so an operator inspecting a lock file, or reading the
* BRAINY_WRITER_LOCKED error, can judge liveness themselves.
*
* At 10s it was a lock-file WRITE every ten seconds per brain, forever: 2.1
* writes/s across a production process holding 21 idle brains, for a
* human-readable timestamp nothing computes with. At 60s an operator still
* sees a heartbeat inside the minute, at a sixth of the cost. With the
* clean-close record now recording orderly releases explicitly, the
* heartbeat carries even less weight than it did.
*/
private static readonly WRITER_HEARTBEAT_MS = 60_000
private static readonly WRITER_STALE_THRESHOLD_MS = 60_000
private writerLockHeartbeat?: NodeJS.Timeout
private writerLockInfo?: WriterLockInfo
@ -135,9 +151,16 @@ export class FileSystemStorage extends BaseStorage {
private static readonly FLUSH_REQUEST_DIR = '_flush_requests'
private static readonly FLUSH_RESPONSE_DIR = '_flush_responses'
private static readonly FLUSH_WATCH_INTERVAL_MS = 500
/**
* The safety sweep behind the fs.watch: catches events an exotic filesystem
* dropped, and runs the stale-request GC. See startFlushRequestWatcher.
*/
private static readonly FLUSH_SAFETY_SWEEP_MS = 30_000
private static readonly FLUSH_POLL_INTERVAL_MS = 100
private static readonly FLUSH_REQUEST_TTL_MS = 60_000
private flushWatcherInterval?: NodeJS.Timeout
/** The inotify-backed watch on the request directory, when the FS supports one. */
private flushWatcher?: import('node:fs').FSWatcher
private flushWatcherInFlight = false
private flushWatcherOnRequest?: () => Promise<void>
@ -2385,36 +2408,101 @@ export class FileSystemStorage extends BaseStorage {
/**
* Start watching for cross-process flush requests. Called by Brainy.init()
* in writer mode. Polls `locks/_flush_requests/` every
* FLUSH_WATCH_INTERVAL_MS — each new `.req` file triggers the supplied
* callback (`brain.flush()`), after which an `.ack` is written to
* `locks/_flush_responses/` with the same request ID. Stale `.req` files
* (>FLUSH_REQUEST_TTL_MS) are garbage-collected on every tick.
* in writer mode. Each new `.req` file in `locks/_flush_requests/` triggers
* the supplied callback (`brain.flush()`), after which an `.ack` is written
* to `locks/_flush_responses/` with the same request ID. Stale `.req` files
* (>FLUSH_REQUEST_TTL_MS) are garbage-collected on each sweep.
*
* THE WATCH IS EVENT-DRIVEN, NOT A POLL. It used to `readdir` the request
* directory every 500 ms, per brain, for the entire life of every writer —
* armed on every non-reader brain whether or not any inspector process
* existed. MEASURED on a production process holding 21 brains: 42 directory
* reads per second on a completely idle service, plus a stale-request GC
* pass on every one of them. The engine does no periodic work without a
* cause, and a request that has not been made is not a cause.
*
* `fs.watch` (inotify on Linux) delivers the arrival itself, so a request is
* seen SOONER than the old poll saw it. Two honest concessions ride with it:
* - a slow SAFETY SWEEP (FLUSH_SAFETY_SWEEP_MS) still runs, because
* `fs.watch` can miss events on network and fuse filesystems and because
* the stale-request GC needs some tick of its own. At 30s that is 0.7
* reads/s across 21 brains where the poll cost 42.
* - a filesystem that cannot watch at all falls back to the ORIGINAL
* 500 ms poll, narrated once, because correctness outranks idle cost:
* an inspector whose request is never seen waits forever.
*/
public override startFlushRequestWatcher(onRequest: () => Promise<void>): void {
if (this.flushWatcherInterval) return // already watching
if (this.flushWatcherInterval || this.flushWatcher) return // already watching
this.flushWatcherOnRequest = onRequest
const reqDir = path.join(this.lockDir, FileSystemStorage.FLUSH_REQUEST_DIR)
const ackDir = path.join(this.lockDir, FileSystemStorage.FLUSH_RESPONSE_DIR)
// Ensure both dirs exist up front so the first .req drop doesn't race with mkdir.
this.ensureDirectoryExists(reqDir).catch(() => {})
this.ensureDirectoryExists(ackDir).catch(() => {})
this.flushWatcherInterval = setInterval(() => {
if (this.flushWatcherInFlight) return // skip overlapping tick
const sweep = (): void => {
if (this.flushWatcherInFlight) return // skip overlapping sweep
this.flushWatcherInFlight = true
this.processFlushRequests(reqDir, ackDir).finally(() => {
this.flushWatcherInFlight = false
})
}, FileSystemStorage.FLUSH_WATCH_INTERVAL_MS)
}
// Ensure both dirs exist up front so the first .req drop doesn't race with
// mkdir — and so there is a directory to watch.
void this.ensureDirectoryExists(reqDir)
.then(() => this.ensureDirectoryExists(ackDir))
.then(() => {
if (this.flushWatcherOnRequest !== onRequest) return // stopped meanwhile
try {
const watcher = fs.watch(reqDir, () => sweep())
this.flushWatcher = watcher
watcher.on('error', (err: Error) => {
// A watch that dies mid-life must not leave the door deaf.
console.warn(
`[brainy] Flush-request watch failed (${err.message}) — falling back to polling.`
)
this.flushWatcher?.close()
this.flushWatcher = undefined
this.startFlushRequestPolling(sweep)
})
if (typeof watcher.unref === 'function') watcher.unref()
// The safety sweep: missed events on exotic filesystems, and the
// stale-request GC.
this.flushWatcherInterval = setInterval(sweep, FileSystemStorage.FLUSH_SAFETY_SWEEP_MS)
if (typeof this.flushWatcherInterval.unref === 'function') {
this.flushWatcherInterval.unref()
}
// One sweep now: a request may have been dropped before the watch armed.
sweep()
} catch (err) {
console.warn(
`[brainy] Flush-request directory cannot be watched on this filesystem ` +
`(${(err as Error).message}) — polling every ` +
`${FileSystemStorage.FLUSH_WATCH_INTERVAL_MS}ms instead.`
)
this.startFlushRequestPolling(sweep)
}
})
.catch(() => {
// The request directory could not be created; nothing to watch. A
// cross-process flush request cannot be made either, so there is
// nothing to miss.
})
}
/** The original 500 ms poll — the fallback when a directory cannot be watched. */
private startFlushRequestPolling(sweep: () => void): void {
if (this.flushWatcherInterval) return
this.flushWatcherInterval = setInterval(sweep, FileSystemStorage.FLUSH_WATCH_INTERVAL_MS)
if (typeof this.flushWatcherInterval.unref === 'function') {
this.flushWatcherInterval.unref()
}
}
public override stopFlushRequestWatcher(): void {
if (this.flushWatcher) {
this.flushWatcher.close()
this.flushWatcher = undefined
}
if (this.flushWatcherInterval) {
clearInterval(this.flushWatcherInterval)
this.flushWatcherInterval = undefined