feat(open): the open names the STEP that cost the time, not just the phase
A phase that costs a minute and names only itself tells an operator where to look but not what to look at. MEASURED on a real 14,056-noun / 72,679-verb store, the warm reopen's generation-store phase cost 55,538 ms with nothing inside it named — the fold was skipped (the close was clean), so the cost was somewhere else entirely and the breakdown could not say where. Six steps inside the open now report their own wall with their own cause when they exceed the phase threshold: the generation store's open (manifest, committed ranges, fact log, packed tier, crash replay), the entity-tree stamp verification, the brain-format read, the pre-upgrade backup, the derived-index gate, and the VFS init. Silent under the threshold, so a fast open says nothing extra. Same always-visible channel as the phase lines.
This commit is contained in:
parent
4a67aa0fb9
commit
5a091ccad9
1 changed files with 48 additions and 8 deletions
|
|
@ -1163,6 +1163,23 @@ export class Brainy<T = any> implements BrainyInterface<T> {
|
||||||
)
|
)
|
||||||
}, OPEN_HEARTBEAT_MS)
|
}, OPEN_HEARTBEAT_MS)
|
||||||
if (typeof openHeartbeat.unref === 'function') openHeartbeat.unref()
|
if (typeof openHeartbeat.unref === 'function') openHeartbeat.unref()
|
||||||
|
/**
|
||||||
|
* Narrate one STEP inside a phase when it turns out to be expensive.
|
||||||
|
* A phase that costs a minute and names only itself tells an operator
|
||||||
|
* where to look but not what to look at; this names the step. Silent
|
||||||
|
* under OPEN_PHASE_NARRATE_MS, so a fast open says nothing extra.
|
||||||
|
*/
|
||||||
|
const step = async <T>(name: string, cause: string, run: () => Promise<T>): Promise<T> => {
|
||||||
|
const startedAt = Date.now()
|
||||||
|
try {
|
||||||
|
return await run()
|
||||||
|
} finally {
|
||||||
|
const elapsed = Date.now() - startedAt
|
||||||
|
if (elapsed >= OPEN_PHASE_NARRATE_MS) {
|
||||||
|
prodLog.narrate(`[Brainy] open: step "${name}" took ${elapsed}ms — ${cause}`)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
const markPhase = (name: string): void => {
|
const markPhase = (name: string): void => {
|
||||||
const now = Date.now()
|
const now = Date.now()
|
||||||
const elapsed = now - lastPhaseCheckpoint
|
const elapsed = now - lastPhaseCheckpoint
|
||||||
|
|
@ -1263,9 +1280,12 @@ export class Brainy<T = any> implements BrainyInterface<T> {
|
||||||
// instances skip recovery (readers never write; the next writer
|
// instances skip recovery (readers never write; the next writer
|
||||||
// repairs).
|
// repairs).
|
||||||
this.generationStore = new GenerationStore(this.storage)
|
this.generationStore = new GenerationStore(this.storage)
|
||||||
const generationOpenResult = await this.generationStore.open({
|
const generationOpenResult = await step(
|
||||||
readOnly: this.config.mode === 'reader'
|
'generation-store.open',
|
||||||
})
|
'reading the generation manifest and committed ranges, opening the fact log and the ' +
|
||||||
|
'packed segment tier, and folding any crash-recovery replay',
|
||||||
|
() => this.generationStore.open({ readOnly: this.config.mode === 'reader' })
|
||||||
|
)
|
||||||
|
|
||||||
// The generation fact log is CANONICAL state, not a derived index — no
|
// The generation fact log is CANONICAL state, not a derived index — no
|
||||||
// sweeper, GC, or blob-lifecycle path may ever delete under it. Declare
|
// sweeper, GC, or blob-lifecycle path may ever delete under it. Declare
|
||||||
|
|
@ -1303,7 +1323,11 @@ export class Brainy<T = any> implements BrainyInterface<T> {
|
||||||
// rollup invariants against the log head + live counters. Loud on
|
// rollup invariants against the log head + live counters. Loud on
|
||||||
// genuine incoherence (repairIndex heals), silent on absent/coherent,
|
// genuine incoherence (repairIndex heals), silent on absent/coherent,
|
||||||
// benign-behind refreshes at the next flush. Never blocks open.
|
// benign-behind refreshes at the next flush. Never blocks open.
|
||||||
await this.verifyEntityTreeStamp()
|
await step(
|
||||||
|
'verify-entity-tree-stamp',
|
||||||
|
'comparing the entity tree\'s stamped generation and rollups against the store',
|
||||||
|
() => this.verifyEntityTreeStamp()
|
||||||
|
)
|
||||||
|
|
||||||
// 8.0 ⇄ native-provider version handshake: load the on-disk brain-format
|
// 8.0 ⇄ native-provider version handshake: load the on-disk brain-format
|
||||||
// marker (`_system/brain-format.json`) into an in-memory field NOW —
|
// marker (`_system/brain-format.json`) into an in-memory field NOW —
|
||||||
|
|
@ -1315,7 +1339,11 @@ export class Brainy<T = any> implements BrainyInterface<T> {
|
||||||
// them from the canonical records and then re-stamps the marker AFTER the
|
// them from the canonical records and then re-stamps the marker AFTER the
|
||||||
// rebuild verifies (non-destructive: a crash mid-rebuild leaves the old /
|
// rebuild verifies (non-destructive: a crash mid-rebuild leaves the old /
|
||||||
// absent marker, so the next open idempotently re-rebuilds).
|
// absent marker, so the next open idempotently re-rebuilds).
|
||||||
this._brainFormat = await readBrainFormat(this.storage)
|
this._brainFormat = await step(
|
||||||
|
'read-brain-format',
|
||||||
|
'reading the on-disk format marker that decides whether the derived indexes are stale',
|
||||||
|
() => readBrainFormat(this.storage)
|
||||||
|
)
|
||||||
this._indexEpochStale =
|
this._indexEpochStale =
|
||||||
this._brainFormat === null || this._brainFormat.indexEpoch !== EXPECTED_INDEX_EPOCH
|
this._brainFormat === null || this._brainFormat.indexEpoch !== EXPECTED_INDEX_EPOCH
|
||||||
|
|
||||||
|
|
@ -1326,7 +1354,11 @@ export class Brainy<T = any> implements BrainyInterface<T> {
|
||||||
// upgrade verifies + stamps; retained on failure. No-op for a reader, for
|
// upgrade verifies + stamps; retained on failure. No-op for a reader, for
|
||||||
// non-filesystem storage, or for a brain with no persisted data.
|
// non-filesystem storage, or for a brain with no persisted data.
|
||||||
if (this._indexEpochStale && this.config.migrationBackup && !this.isReadOnly) {
|
if (this._indexEpochStale && this.config.migrationBackup && !this.isReadOnly) {
|
||||||
await this.createMigrationBackupIfNeeded()
|
await step(
|
||||||
|
'pre-upgrade-backup',
|
||||||
|
'snapshotting the brain directory before a one-time format rebuild (migrationBackup)',
|
||||||
|
() => this.createMigrationBackupIfNeeded()
|
||||||
|
)
|
||||||
}
|
}
|
||||||
|
|
||||||
// PHASE 2 of 5 — "generation-store open+fold": GenerationStore
|
// PHASE 2 of 5 — "generation-store open+fold": GenerationStore
|
||||||
|
|
@ -1606,7 +1638,11 @@ export class Brainy<T = any> implements BrainyInterface<T> {
|
||||||
// init() returns — there is no more first-query lazy path, so the flag
|
// init() returns — there is no more first-query lazy path, so the flag
|
||||||
// below (kept for getIndexStatus() API compatibility) simply flips true
|
// below (kept for getIndexStatus() API compatibility) simply flips true
|
||||||
// once this open-time step has run.
|
// once this open-time step has run.
|
||||||
await this.rebuildIndexesIfNeeded()
|
await step(
|
||||||
|
'rebuild-indexes-if-needed',
|
||||||
|
'the derived-index gate: each family\'s readiness verdict, and any build it asks for',
|
||||||
|
() => this.rebuildIndexesIfNeeded()
|
||||||
|
)
|
||||||
this.lazyRebuildCompleted = true
|
this.lazyRebuildCompleted = true
|
||||||
|
|
||||||
// Check for pending data migrations
|
// Check for pending data migrations
|
||||||
|
|
@ -1679,7 +1715,11 @@ export class Brainy<T = any> implements BrainyInterface<T> {
|
||||||
// Initialize VFS: Ensure VFS is ready when accessed as property
|
// Initialize VFS: Ensure VFS is ready when accessed as property
|
||||||
// This eliminates need for separate vfs.init() calls - zero additional complexity
|
// This eliminates need for separate vfs.init() calls - zero additional complexity
|
||||||
this._vfs = new VirtualFileSystem(this)
|
this._vfs = new VirtualFileSystem(this)
|
||||||
await this._vfs.init()
|
await step(
|
||||||
|
'vfs.init',
|
||||||
|
'creating or adopting the VFS root and wiring the path resolver',
|
||||||
|
() => this._vfs!.init()
|
||||||
|
)
|
||||||
this._vfsInitialized = true // Mark VFS as fully initialized
|
this._vfsInitialized = true // Mark VFS as fully initialized
|
||||||
|
|
||||||
// 8.0 MVCC: infrastructure bootstrap (VFS root, etc.) is now the
|
// 8.0 MVCC: infrastructure bootstrap (VFS root, etc.) is now the
|
||||||
|
|
|
||||||
Loading…
Add table
Add a link
Reference in a new issue