diff --git a/.changeset/serve-unlinked-database-file-watch.md b/.changeset/serve-unlinked-database-file-watch.md new file mode 100644 index 0000000000..7a85c645f2 --- /dev/null +++ b/.changeset/serve-unlinked-database-file-watch.md @@ -0,0 +1,11 @@ +--- +"@objectstack/cli": patch +--- + +`os serve` now says so when the SQLite file it is serving is no longer the file at its configured path. + +Deleting the data directory under a running server — `rm -rf .objectstack/data`, which is what a `demo:reset` script does and what a fresh-database repro starts with — unlinks the inode without touching the process. SQLite keeps reading and writing the now-invisible file, health keeps answering `200`, and a later boot creates a brand-new database at the same path. From that moment every filesystem inspection of that path describes a *different* database than the running server answers from, and nothing anywhere says so: a row edited there has no observable effect on the live server, and a user who authenticates against the live server is not in that file. Both readings are true, both look like a broken write path, and one investigation that reported them as evidence cost a full P0 cycle. + +A boot that serves an on-disk SQLite file now records that file's identity once the boot is complete and re-checks it on a 30-second interval. When the file is gone, or the path holds a different file, it reports **once** at `error` — naming the path, the consequence (every external observation of this deployment is now false, and it will keep looking healthy) and the fix (restart the server so it opens the file that is at that path now). + +It refuses nothing and retries nothing: the running server is still correct, merely invisible, and breaking a working dev loop to fix a reporting gap would trade a bad hour for a worse one. Nothing is added to any payload, endpoint or state file. Silence from the check is not a claim that the file is intact — every uncertainty in it resolves toward staying quiet, because a false report would send an operator to restart a server whose database is fine. diff --git a/packages/cli/src/commands/serve-driver-banner.test.ts b/packages/cli/src/commands/serve-driver-banner.test.ts index a5bb48621a..47a455e959 100644 --- a/packages/cli/src/commands/serve-driver-banner.test.ts +++ b/packages/cli/src/commands/serve-driver-banner.test.ts @@ -49,7 +49,7 @@ describe('describeRegisteredDriver', () => { expect(describeRegisteredDriver(fakeKernel({ 'driver.sql': { config: { client: 'better-sqlite3', connection: { filename: './data.db' } } }, - }))).toEqual({ label: 'SqlDriver(better-sqlite3)', url: './data.db' }); + }))).toEqual({ label: 'SqlDriver(better-sqlite3)', url: './data.db', sqliteFile: './data.db' }); expect(describeRegisteredDriver(fakeKernel({ 'driver.sql': { config: { client: 'pg', connection: { host: 'db.example.com', port: 5432, database: 'app' } } }, @@ -133,10 +133,42 @@ describe('describeRegisteredDriver', () => { expect(describeRegisteredDriver(kernel)).toEqual({ label: 'SqliteWasmDriver', url: './app.wasm.db', + sqliteFile: './app.wasm.db', }); }); it('returns null when no known driver is registered', () => { expect(describeRegisteredDriver(fakeKernel({}))).toBeNull(); }); + + // `sqliteFile` is the SAME probe read a second time asking a different + // question: not "what do I print" but "which file on this filesystem", so + // the boot can `stat` it and notice later that the file it opened is no + // longer the file at that path. It is the plumbing between the driver and + // that watch, and nothing else pins it — a probe that stopped answering it + // would leave the watch silently un-armed on every boot, which is + // byte-identical to a deployment where nothing ever went wrong. + describe('sqliteFile — the on-disk file the boot is serving', () => { + it('answers the sqlite connection filename', () => { + expect(describeRegisteredDriver(fakeKernel({ + 'driver.com.objectstack.driver.sql': { + config: { client: 'better-sqlite3', connection: { filename: '/app/.objectstack/data/objectstack.db' } }, + }, + }))?.sqliteFile).toBe('/app/.objectstack/data/objectstack.db'); + }); + + it('is absent for every driver that serves no file on disk', () => { + expect(describeRegisteredDriver(fakeKernel({ + 'driver.sql': { config: { client: 'better-sqlite3', connection: { filename: ':memory:' } } }, + }))?.sqliteFile).toBeUndefined(); + + expect(describeRegisteredDriver(fakeKernel({ + 'driver.sql': { config: { client: 'pg', connection: { host: 'db.example.com', port: 5432, database: 'app' } } }, + }))?.sqliteFile).toBeUndefined(); + + expect(describeRegisteredDriver(fakeKernel({ + 'driver.memory': { constructor: { name: 'InMemoryDriver' }, config: {} }, + }))?.sqliteFile).toBeUndefined(); + }); + }); }); diff --git a/packages/cli/src/commands/serve.ts b/packages/cli/src/commands/serve.ts index b3ab2e3674..a2b9b26cba 100644 --- a/packages/cli/src/commands/serve.ts +++ b/packages/cli/src/commands/serve.ts @@ -74,7 +74,8 @@ import { stackDeclaresMetadata, bundleDeclaresTranslations, } from '../utils/stack-collections.js'; -import { redactConnectionUrl, describeDriverConnection } from '../utils/connection-display.js'; +import { redactConnectionUrl, describeDriverConnection, describeDriverSqliteFile } from '../utils/connection-display.js'; +import { captureServedDatabaseFile, watchServedDatabaseFile } from '../utils/served-database-file.js'; // The posture prose `os serve` and `os doctor` BOTH print, declared once // (#12492) — and, since #12579, the multi-org runtime SPELLING those two // commands put in front of the same operator, declared once with it. @@ -2099,6 +2100,11 @@ export default class Serve extends Command { // is idempotent, so the second pass over an already-clean URL is a no-op. let resolvedDriverLabel: string | undefined; let resolvedDatabaseUrl: string | undefined; + // The on-disk SQLite file this boot serves, when it serves one. Kept apart + // from `resolvedDatabaseUrl` on purpose: that value is a string for a + // human and may be redacted or labelled, while this one is handed to + // `stat` — see `describeDriverSqliteFile`. + let servedSqliteFilePath: string | undefined; // Resolve the kernel logger level up front. It decides more than the // logger's own threshold: it decides whether the boot-quiet window below @@ -2718,6 +2724,7 @@ export default class Serve extends Command { trackPlugin(resolution.trackName); resolvedDriverLabel = resolution.label; resolvedDatabaseUrl = resolution.displayUrl; + servedSqliteFilePath = resolution.sqliteFilePath; // ADR-0057 §3.6 (#2834 ②): provision the dedicated `telemetry` // datasource — a sibling SQLite file the engine routes every @@ -4588,6 +4595,7 @@ export default class Serve extends Command { if (probe) { resolvedDriverLabel = probe.label; resolvedDatabaseUrl = probe.url; + servedSqliteFilePath = probe.sqliteFile; } } catch { // best-effort only @@ -4756,6 +4764,35 @@ export default class Serve extends Command { // old order lost, and the reason the repair is not reader-side polling. publishBoundPort(boundPort, runtimeBoundPortChannels(printBanner)); + // ── Watch the served database file's identity ────────────────── + // Deleting the data directory under a running server (`rm -rf + // .objectstack/data`, what `demo:reset` does) unlinks the inode without + // touching this process: SQLite keeps serving the now-invisible file, + // health keeps answering 200, and a later boot creates a brand-new + // database at the same path. From then on every filesystem inspection of + // that path describes a DIFFERENT file than this server answers from — + // which is how "the row I edited had no effect" and "the user who just + // authenticated is not in the database" become simultaneously true + // readings of a healthy deployment. + // + // Started only once the boot is otherwise complete, so a failure here + // can never be mistaken for a boot problem, and only when an on-disk + // SQLite file is actually being served. It refuses nothing and reports + // once — see `served-database-file.ts` for why both. + if (servedSqliteFilePath) { + const openedDatabaseFile = captureServedDatabaseFile(servedSqliteFilePath); + if (openedDatabaseFile) { + watchServedDatabaseFile({ + opened: openedDatabaseFile, + // `error`, and to stderr: by the degradation-log-level rule this is + // the durability/consistency class — the system keeps looking + // normal while what it claims is persisted is not at the path it + // names. + onDiverged: (message) => { console.error(chalk.red(message)); }, + }); + } + } + // Kernel already registers SIGINT/SIGTERM handlers during bootstrap. // No duplicate handler needed here — just keep the process alive. @@ -6121,7 +6158,9 @@ function emitMultiNodeCapTelemetry( * arrives in, so a DSN-declared datasource no longer falls through to * `(unknown)`, and no shape prints credentials. */ -export function describeRegisteredDriver(kernel: any): { label: string; url: string } | null { +export function describeRegisteredDriver( + kernel: any, +): { label: string; url: string; sqliteFile?: string } | null { const candidates = [ 'driver.com.objectstack.driver.sql', 'driver.com.objectstack.driver.mongodb', @@ -6153,7 +6192,16 @@ export function describeRegisteredDriver(kernel: any): { label: string; url: str // A memory driver has no address to show — say so, rather than // `(unknown)`, which reads as "we looked for one and failed". - return { label, url: url ?? (name.endsWith('.memory') ? '(in-memory)' : '(unknown)') }; + // + // `sqliteFile` is the same config read a second time asking a DIFFERENT + // question: not "what do I print" but "which file on this filesystem", so + // a caller can `stat` it. Absent for every driver that serves no on-disk + // SQLite file, which is the majority of them. + return { + label, + url: url ?? (name.endsWith('.memory') ? '(in-memory)' : '(unknown)'), + sqliteFile: describeDriverSqliteFile(cfg), + }; } return null; } diff --git a/packages/cli/src/utils/connection-display.test.ts b/packages/cli/src/utils/connection-display.test.ts index 0014848d8e..020dde4d0d 100644 --- a/packages/cli/src/utils/connection-display.test.ts +++ b/packages/cli/src/utils/connection-display.test.ts @@ -12,7 +12,7 @@ // shape leaks the credentials the DSN carries. import { describe, it, expect } from 'vitest'; -import { redactConnectionUrl, describeDriverConnection } from './connection-display.js'; +import { redactConnectionUrl, describeDriverConnection, describeDriverSqliteFile } from './connection-display.js'; describe('redactConnectionUrl', () => { it('drops the userinfo segment from a DSN', () => { @@ -124,3 +124,36 @@ describe('describeDriverConnection', () => { expect(describeDriverConnection({ client: 'pg', connection: () => ({ host: 'h' }) })).toBeUndefined(); }); }); + +describe('describeDriverSqliteFile', () => { + // A SECOND question over the same config shapes: not "what do I print" but + // "which file on this filesystem", so the answer can be handed to `stat`. + it('reads the knex sqlite connection filename', () => { + expect(describeDriverSqliteFile({ + client: 'better-sqlite3', + connection: { filename: '/app/.objectstack/data/objectstack.db' }, + })).toBe('/app/.objectstack/data/objectstack.db'); + }); + + it('reads a filename kept at the top level', () => { + expect(describeDriverSqliteFile({ filename: '/app/data.db' })).toBe('/app/data.db'); + }); + + it('refuses the in-memory database, which is not a file on disk', () => { + expect(describeDriverSqliteFile({ connection: { filename: ':memory:' } })).toBeUndefined(); + }); + + it('refuses the empty name, SQLite\'s private temporary database', () => { + expect(describeDriverSqliteFile({ connection: { filename: ' ' } })).toBeUndefined(); + }); + + it('answers undefined for a driver that serves no file', () => { + expect(describeDriverSqliteFile({ url: 'mongodb://db.example.com/app' })).toBeUndefined(); + expect(describeDriverSqliteFile({ + client: 'pg', + connection: { host: 'db.example.com', port: 5432, database: 'app' }, + })).toBeUndefined(); + expect(describeDriverSqliteFile(undefined)).toBeUndefined(); + expect(describeDriverSqliteFile('postgres://db.example.com/app')).toBeUndefined(); + }); +}); diff --git a/packages/cli/src/utils/connection-display.ts b/packages/cli/src/utils/connection-display.ts index 523d43726e..66ca3a885e 100644 --- a/packages/cli/src/utils/connection-display.ts +++ b/packages/cli/src/utils/connection-display.ts @@ -98,3 +98,30 @@ export function describeDriverConnection(config: unknown): string | undefined { return readTarget(conn && typeof conn === 'object' ? conn as Record : undefined) ?? readTarget(cfg); } + +/** + * The on-disk SQLite file a driver config names, or `undefined` when it names + * none. + * + * A SECOND question over the same shapes {@link describeDriverConnection} + * already knows — and deliberately not a re-read of that function's output. + * That one renders a string for a human and is free to redact, abbreviate or + * label (`(in-memory)`, `(unknown)`); this one answers "which file on this + * filesystem", which is an identity, and an identity parsed back out of a + * display string is one redaction rule away from being wrong. + * + * `:memory:` and the empty name (SQLite's private temporary database) are not + * files on disk and are refused here, so a caller can hand the result straight + * to `stat` without re-deciding. + */ +export function describeDriverSqliteFile(config: unknown): string | undefined { + if (!config || typeof config !== 'object') return undefined; + const cfg = config as Record; + const conn = cfg.connection; + const bag = conn && typeof conn === 'object' ? conn as Record : cfg; + const filename = bag.filename ?? cfg.filename; + if (typeof filename !== 'string') return undefined; + const trimmed = filename.trim(); + if (!trimmed || trimmed === ':memory:') return undefined; + return trimmed; +} diff --git a/packages/cli/src/utils/served-database-file.test.ts b/packages/cli/src/utils/served-database-file.test.ts new file mode 100644 index 0000000000..ef5edd23af --- /dev/null +++ b/packages/cli/src/utils/served-database-file.test.ts @@ -0,0 +1,264 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. +// +// The condition these pin was reproduced end to end against a live +// `objectstack serve` before any of this was written: the data directory was +// deleted under a running server, the process kept three `(deleted)` +// descriptors open, `GET /api/v1/health` kept answering 200 with every seeded +// row, a second boot created a brand-new database at the same path, and an +// edit written into THAT file with its own server stopped had no observable +// effect on the first server — while the user id the first server was +// authenticating did not exist in it. Nothing anywhere said so. +// +// The tests below drive the same two transitions against the real filesystem +// (unlink, and unlink-then-recreate), because the whole question is whether a +// path still names the same file and a mocked `stat` cannot be wrong about +// that in the way a real filesystem can. + +import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; +import { mkdtempSync, rmSync, writeFileSync, statSync, mkdirSync, renameSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import type { Stats } from 'node:fs'; +import { + captureServedDatabaseFile, + checkServedDatabaseFile, + describeServedDatabaseFileDivergence, + watchServedDatabaseFile, + SERVED_DATABASE_FILE_CHECK_INTERVAL_MS, + type ServedDatabaseFile, +} from './served-database-file.js'; + +let dir: string; +let dbPath: string; + +beforeEach(() => { + dir = mkdtempSync(join(tmpdir(), 'os-served-db-')); + mkdirSync(join(dir, 'data'), { recursive: true }); + dbPath = join(dir, 'data', 'objectstack.db'); + writeFileSync(dbPath, 'first-boot'); +}); + +afterEach(() => { + rmSync(dir, { recursive: true, force: true }); +}); + +/** + * A `stat` stub that reports one identity, or throws one errno. + * + * `birthtimeMs`/`ctimeMs` default to two different values, which is what arms + * the second rung — the same thing a real database file does once it has been + * written to since it was created. + */ +const statStub = ( + result: { dev: number; ino: number; birthtimeMs?: number; ctimeMs?: number } | { code: string }, +) => + ((): Stats => { + if ('code' in result) { + const err = new Error(result.code) as NodeJS.ErrnoException; + err.code = result.code; + throw err; + } + return { birthtimeMs: 1_000, ctimeMs: 2_000, ...result } as unknown as Stats; + }); + +describe('captureServedDatabaseFile', () => { + it('records the device and inode of the file at the path', () => { + const captured = captureServedDatabaseFile(dbPath); + const real = statSync(dbPath); + expect(captured?.path).toBe(dbPath); + expect(captured?.dev).toBe(Number(real.dev)); + expect(captured?.ino).toBe(Number(real.ino)); + }); + + it('arms the birth-time rung only when this filesystem keeps birth and change times apart', () => { + // Armed: the two differ, so birth time cannot be a copy of `ctime`. + expect(captureServedDatabaseFile(dbPath, { + stat: statStub({ dev: 1, ino: 2, birthtimeMs: 100, ctimeMs: 500 }), + })).toEqual({ path: dbPath, dev: 1, ino: 2, birthtimeMs: 100 }); + + // Disarmed: indistinguishable from the documented `ctime` fallback, under + // which every write to a healthy database would read as a replacement. + expect(captureServedDatabaseFile(dbPath, { + stat: statStub({ dev: 1, ino: 2, birthtimeMs: 500, ctimeMs: 500 }), + })).toEqual({ path: dbPath, dev: 1, ino: 2, birthtimeMs: undefined }); + }); + + it('answers undefined when nothing is at the path', () => { + expect(captureServedDatabaseFile(join(dir, 'data', 'absent.db'))).toBeUndefined(); + }); + + it('answers undefined when the filesystem reports no usable inode', () => { + // Some Windows volumes report `ino: 0`. A watch seeded from that identity + // would call every later look a divergence — the one failure it must not + // have — so there is nothing to watch. + expect(captureServedDatabaseFile(dbPath, { stat: statStub({ dev: 1, ino: 0 }) })).toBeUndefined(); + }); +}); + +describe('checkServedDatabaseFile — against the real filesystem', () => { + it('is unchanged while the file is the same file', () => { + const opened = captureServedDatabaseFile(dbPath)!; + // Writing THROUGH the same inode is not a change of identity — this is + // what a healthy serving process does all day. + writeFileSync(dbPath, 'more pages'); + expect(checkServedDatabaseFile(opened)).toEqual({ kind: 'unchanged' }); + }); + + it('reports missing after the data directory is deleted under it', () => { + const opened = captureServedDatabaseFile(dbPath)!; + rmSync(join(dir, 'data'), { recursive: true, force: true }); // `demo:reset` + expect(checkServedDatabaseFile(opened)).toEqual({ kind: 'missing' }); + }); + + it('reports replaced once a later boot puts a different database at the same path', () => { + const opened = captureServedDatabaseFile(dbPath)!; + // The replacement is created while the original still exists, so the two + // inodes are necessarily distinct — otherwise this test is at the mercy of + // inode RECYCLING, which is real: measured here, deleting the file and + // recreating one at the same path in the same millisecond handed back the + // same inode. That case is covered on the birth-time rung below. + const incoming = join(dir, 'data', 'incoming.db'); + writeFileSync(incoming, 'second boot'); + rmSync(dbPath); + renameSync(incoming, dbPath); + + const verdict = checkServedDatabaseFile(opened); + expect(verdict).toEqual({ + kind: 'replaced', + onDisk: { dev: Number(statSync(dbPath).dev), ino: Number(statSync(dbPath).ino) }, + inodeReused: false, + }); + expect(Number(statSync(dbPath).ino)).not.toBe(opened.ino); + }); +}); + +describe('checkServedDatabaseFile — a read that failed is never a divergence', () => { + const opened: ServedDatabaseFile = { path: '/some/objectstack.db', dev: 10, ino: 20 }; + + it('reports unreadable, not missing, when the path cannot be read', () => { + const verdict = checkServedDatabaseFile(opened, { stat: statStub({ code: 'EACCES' }) }); + expect(verdict).toEqual({ kind: 'unreadable', reason: 'EACCES' }); + expect(describeServedDatabaseFileDivergence(opened, verdict)).toBeUndefined(); + }); + + it('reports unreadable when the later look has no usable inode either', () => { + const verdict = checkServedDatabaseFile(opened, { stat: statStub({ dev: 10, ino: 0 }) }); + expect(verdict.kind).toBe('unreadable'); + expect(describeServedDatabaseFileDivergence(opened, verdict)).toBeUndefined(); + }); + + it('treats a device change as a divergence even at the same inode number', () => { + // Inode numbers are only unique per filesystem, so a remount or a bind + // mount can hand back the same number for a different file. + const verdict = checkServedDatabaseFile(opened, { stat: statStub({ dev: 11, ino: 20 }) }); + expect(verdict).toEqual({ kind: 'replaced', onDisk: { dev: 11, ino: 20 }, inodeReused: false }); + }); +}); + +describe('checkServedDatabaseFile — the recycled inode', () => { + // The case a dev+inode comparison alone cannot see, and the one the card's + // own second half describes: the data directory is deleted and a later boot + // creates a brand-new database at the same path, onto the freed inode. + const armed: ServedDatabaseFile = { path: '/app/objectstack.db', dev: 10, ino: 20, birthtimeMs: 1_000 }; + + it('reports replaced when the same inode carries a newer birth time', () => { + const verdict = checkServedDatabaseFile(armed, { + stat: statStub({ dev: 10, ino: 20, birthtimeMs: 9_000, ctimeMs: 9_500 }), + }); + expect(verdict).toEqual({ kind: 'replaced', onDisk: { dev: 10, ino: 20 }, inodeReused: true }); + expect(describeServedDatabaseFileDivergence(armed, verdict)).toContain('recycled inode 20'); + }); + + it('stays silent for an ordinary write, which moves change time and not birth time', () => { + expect(checkServedDatabaseFile(armed, { + stat: statStub({ dev: 10, ino: 20, birthtimeMs: 1_000, ctimeMs: 8_000 }), + })).toEqual({ kind: 'unchanged' }); + }); + + it('cannot report on the second rung when it was never armed', () => { + // No `birthtimeMs` on the captured identity — a filesystem whose birth + // time is a copy of `ctime`, where trusting it would call every write a + // replacement. One rung is the conservative answer, never a wrong one. + const disarmed: ServedDatabaseFile = { path: '/app/objectstack.db', dev: 10, ino: 20 }; + expect(checkServedDatabaseFile(disarmed, { + stat: statStub({ dev: 10, ino: 20, birthtimeMs: 9_000, ctimeMs: 9_000 }), + })).toEqual({ kind: 'unchanged' }); + }); +}); + +describe('describeServedDatabaseFileDivergence', () => { + const opened: ServedDatabaseFile = { path: '/app/.objectstack/data/objectstack.db', dev: 10, ino: 20 }; + + it('says nothing when there is nothing to say', () => { + expect(describeServedDatabaseFileDivergence(opened, { kind: 'unchanged' })).toBeUndefined(); + }); + + it('owes a consequence and a fix, and pays both', () => { + const message = describeServedDatabaseFileDivergence(opened, { kind: 'missing' })!; + expect(message).toContain(opened.path); + // (1) the consequence, concretely — including that it keeps looking healthy + expect(message).toContain('no observable effect'); + expect(message).toContain('keeps answering 200'); + // (2) the fix + expect(message).toContain('restart this server'); + expect(message).toContain('rm -rf .objectstack/data'); + }); + + it('names both identities when the file was replaced', () => { + const message = describeServedDatabaseFileDivergence(opened, { + kind: 'replaced', + onDisk: { dev: 10, ino: 77 }, + inodeReused: false, + })!; + expect(message).toContain('10/20'); + expect(message).toContain('10/77'); + }); +}); + +describe('watchServedDatabaseFile', () => { + beforeEach(() => { vi.useFakeTimers(); }); + afterEach(() => { vi.useRealTimers(); }); + + it('stays silent while the file is unchanged', () => { + const opened = captureServedDatabaseFile(dbPath)!; + const onDiverged = vi.fn(); + const watch = watchServedDatabaseFile({ opened, onDiverged, intervalMs: 1_000 })!; + vi.advanceTimersByTime(10_000); + expect(onDiverged).not.toHaveBeenCalled(); + watch.stop(); + }); + + it('reports ONCE and stops watching', () => { + const opened = captureServedDatabaseFile(dbPath)!; + const onDiverged = vi.fn(); + watchServedDatabaseFile({ opened, onDiverged, intervalMs: 1_000 }); + + rmSync(join(dir, 'data'), { recursive: true, force: true }); + vi.advanceTimersByTime(1_000); + expect(onDiverged).toHaveBeenCalledTimes(1); + expect(onDiverged.mock.calls[0][0]).toContain(dbPath); + expect(onDiverged.mock.calls[0][1]).toEqual({ kind: 'missing' }); + + // The condition is permanent until a restart; repeating it every interval + // would make it unreadable, which is what made the founding incident's + // warning unreadable in the first place. + vi.advanceTimersByTime(60_000); + expect(onDiverged).toHaveBeenCalledTimes(1); + }); + + it('has nothing to run on a non-positive interval', () => { + const opened = captureServedDatabaseFile(dbPath)!; + expect(watchServedDatabaseFile({ opened, onDiverged: vi.fn(), intervalMs: 0 })).toBeUndefined(); + }); + + it('stop() is idempotent and silences the watch', () => { + const opened = captureServedDatabaseFile(dbPath)!; + const onDiverged = vi.fn(); + const watch = watchServedDatabaseFile({ opened, onDiverged })!; + watch.stop(); + watch.stop(); + rmSync(join(dir, 'data'), { recursive: true, force: true }); + vi.advanceTimersByTime(SERVED_DATABASE_FILE_CHECK_INTERVAL_MS * 3); + expect(onDiverged).not.toHaveBeenCalled(); + }); +}); diff --git a/packages/cli/src/utils/served-database-file.ts b/packages/cli/src/utils/served-database-file.ts new file mode 100644 index 0000000000..9cc19ca13e --- /dev/null +++ b/packages/cli/src/utils/served-database-file.ts @@ -0,0 +1,277 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * "Is the SQLite file I opened still the file at my path?" — the one question + * a live boot cannot answer for itself, and the one whose wrong answer costs a + * whole investigation. + * + * ## The measured state + * + * The documented dev loop deletes the database directory (`rm -rf + * .objectstack/data` — it is in hotcrm's own `demo:reset` script and in the + * repro block of the card this module was written for). Running it while a + * server still holds the database unlinks the inode without touching the + * process: SQLite keeps reading and writing the now-invisible file, the + * process keeps three `(deleted)` descriptors open (`objectstack.db`, `-wal`, + * `-shm`), and `GET /api/v1/health` keeps answering `200`. A later boot then + * creates a brand-new `objectstack.db` at the same path. + * + * From that moment the two halves of any investigation describe DIFFERENT + * files, with nothing saying so — reproduced end to end while writing this: + * + * ```text + * live server GET /api/v1/data/crm_account -> ["Acme Corp","Globex Ltd","Initech"] + * file at the same path (server stopped) -> ["EDITED_WITH_SERVER_STOPPED", ...] + * live server session user id -> d7ZOOTvRfxl8exw2f8TGvX7J8iincNRb + * that id in the file at the same path -> 0 rows + * ``` + * + * So "a row edit made with the server stopped has no observable effect" and "a + * user that authenticates against the live server is not in the database" are + * both TRUE readings of one healthy deployment — and both were reported as + * evidence of a broken write path in a card that then burned a full P0 cycle. + * Nothing in the product is wrong at that point; the deployment simply has no + * way to notice. + * + * ## Why the check is periodic and not on-error + * + * There is no error to hang it on. Measured: after the unlink every read and + * write still succeeds, health still answers `200`, and no exception is thrown + * anywhere — that is the whole defect. A condition that never produces a + * failure can only be found by asking, so the watch below asks on a timer. + * + * ## Why it reports and refuses nothing + * + * The running server is still CORRECT — it is merely invisible. Refusing to + * serve, or restarting, would break a working dev loop to fix a reporting gap. + * The level is `error` by the AGENTS.md degradation rule ("after the + * degradation, does the system still look normal from the outside, while + * something it claims is persisted has not actually landed?" — yes: every + * external observation of this deployment is now false), and it is said ONCE, + * at the first divergence, per that same rule. + * + * ## What is compared, and the direction it fails in + * + * The identity captured at boot is `stat(path)` taken right after the driver + * connected — the device+inode pair of the file at the configured path, plus + * its birth time where that field is trustworthy ({@link captureServedDatabaseFile} + * says what arms the second rung, and why inodes alone are not enough) — not + * the inode behind the driver's own descriptor, which no portable Node API + * exposes. If a swap happened in the window between the driver's `open()` and + * that first `stat()`, the capture records the NEW file and the watch never + * fires. That direction is deliberate, and it is the direction every + * uncertainty here is resolved in: a missed report costs what today already + * costs, while a false report would send an operator to restart a server whose + * database is fine. Silence from this watch is therefore never a claim that + * the file is intact — it is only the absence of a claim that it is not. + */ + +import { statSync, type Stats } from 'node:fs'; + +/** The identity of the database file this boot is serving. */ +export interface ServedDatabaseFile { + /** Absolute on-disk path the driver was pointed at. */ + path: string; + /** `stat.dev` at capture time. */ + dev: number; + /** `stat.ino` at capture time. */ + ino: number; + /** + * `stat.birthtimeMs` at capture time — the SECOND rung, present only when + * this filesystem's birth time is trustworthy here. See + * {@link captureServedDatabaseFile} for what arms it and why. + */ + birthtimeMs?: number; +} + +/** + * What a later look at the same path found. + * + * `unreadable` is deliberately its own verdict rather than folded into + * `unchanged`: "I could not judge" and "I judged, and it is fine" are + * different facts, and only the second one licenses silence as an answer. + */ +export type ServedDatabaseFileVerdict = + | { kind: 'unchanged' } + | { kind: 'missing' } + | { kind: 'replaced'; onDisk: { dev: number; ino: number }; inodeReused: boolean } + | { kind: 'unreadable'; reason: string }; + +/** Seam for tests — the real `statSync` by default. */ +export interface ServedDatabaseFileDeps { + stat?: (path: string) => Stats; +} + +/** + * How often the watch asks. A `stat` of one path is far below the noise floor + * of a serving process, and the watch stops itself at the first divergence, so + * the cost is bounded by the time the deployment spends healthy. + */ +export const SERVED_DATABASE_FILE_CHECK_INTERVAL_MS = 30_000; + +/** + * Capture the identity of the file at `path`, or `undefined` when this + * platform cannot answer. + * + * `undefined` means the watch must not run at all: an unreadable path, or a + * filesystem that reports no usable inode (`ino === 0`, seen on some Windows + * volumes). A watch seeded from an unjudgeable identity would report every + * later look as a divergence, which is the one failure this must not have. + */ +export function captureServedDatabaseFile( + path: string, + deps: ServedDatabaseFileDeps = {}, +): ServedDatabaseFile | undefined { + const stat = deps.stat ?? statSync; + try { + const s = stat(path); + if (!Number.isFinite(s.ino) || s.ino === 0) return undefined; + return { path, dev: Number(s.dev), ino: Number(s.ino), birthtimeMs: armBirthtime(s) }; + } catch { + return undefined; + } +} + +/** + * The birth time, when it can be trusted here — otherwise `undefined`. + * + * ⚠️ Inode numbers are RECYCLED, and the recycling is not exotic: measured on + * this repo's own CI-shaped filesystem, deleting a file and recreating one at + * the same path in the same millisecond handed back the SAME inode. So "a + * later boot created a brand-new database at this path" — the card's own + * second half — can be invisible to a dev+inode comparison alone. Birth time + * separates them: the same measurement showed it moving on the recreate + * (…634434.566 to …634438.940) while staying put across an ordinary write to + * a live inode, which is exactly the discrimination wanted. + * + * The hazard is that `birthtimeMs` is not universally real. Node documents + * two fallbacks for filesystems that do not store it: the epoch, or a copy of + * `ctime`. The epoch one is harmless (a constant compares equal forever); the + * `ctime` one is NOT — `ctime` moves on every write, so a healthy serving + * database would report itself replaced every interval. + * + * So the rung ARMS ITSELF on evidence, and only on evidence: if birth time is + * a copy of `ctime` it equals `ctime` by construction, and the two being + * different at capture proves this filesystem keeps them apart. A file whose + * `ctime` has not yet moved past its birth time is simply left on one rung — + * conservative, never wrong. The whole design is one-directional: it can only + * ever add detections, never a false one. + */ +function armBirthtime(s: Stats): number | undefined { + const birth = Number(s.birthtimeMs); + if (!Number.isFinite(birth)) return undefined; + if (birth === Number(s.ctimeMs)) return undefined; + return birth; +} + +/** Ask whether the file at `opened.path` is still the file `opened` names. */ +export function checkServedDatabaseFile( + opened: ServedDatabaseFile, + deps: ServedDatabaseFileDeps = {}, +): ServedDatabaseFileVerdict { + const stat = deps.stat ?? statSync; + let s: Stats; + try { + s = stat(opened.path); + } catch (err) { + const code = (err as NodeJS.ErrnoException | undefined)?.code; + // Nothing at the path is the headline case — the unlink itself. + if (code === 'ENOENT') return { kind: 'missing' }; + // Anything else (a permission change, a vanished mount) is a failure to + // MEASURE, never a measurement. Reporting divergence off it would be + // inventing an answer the read never produced. + return { kind: 'unreadable', reason: code ?? String((err as Error | undefined)?.message ?? err) }; + } + const dev = Number(s.dev); + const ino = Number(s.ino); + if (!Number.isFinite(ino) || ino === 0) { + return { kind: 'unreadable', reason: 'filesystem reports no usable inode' }; + } + if (dev !== opened.dev || ino !== opened.ino) { + return { kind: 'replaced', onDisk: { dev, ino }, inodeReused: false }; + } + // Same dev+inode — which is NOT the same as the same file. Second rung. + if (opened.birthtimeMs !== undefined) { + const birth = Number(s.birthtimeMs); + if (Number.isFinite(birth) && birth !== opened.birthtimeMs) { + return { kind: 'replaced', onDisk: { dev, ino }, inodeReused: true }; + } + } + return { kind: 'unchanged' }; +} + +/** + * The line an operator reads, or `undefined` when there is nothing to say. + * + * It owes two things and carries both, per the degradation-log-level rule: + * the CONSEQUENCE (concretely: every external observation of this deployment + * is now false, and it will keep looking healthy) and the FIX. + */ +export function describeServedDatabaseFileDivergence( + opened: ServedDatabaseFile, + verdict: ServedDatabaseFileVerdict, +): string | undefined { + const what = + verdict.kind === 'missing' + ? `nothing exists at ${opened.path} any more` + : verdict.kind === 'replaced' + ? (verdict.inodeReused + ? `${opened.path} is now a DIFFERENT file created since boot (the filesystem recycled inode ${opened.ino}, so only its creation time tells them apart)` + : `${opened.path} is now a DIFFERENT file (opened dev/inode ${opened.dev}/${opened.ino}, on disk now ${verdict.onDisk.dev}/${verdict.onDisk.ino})`) + : undefined; + if (!what) return undefined; + return [ + `Database file identity lost: this server is still serving the SQLite file it opened at boot, but ${what}.`, + ` Consequence: every filesystem inspection of that path — sqlite3, a table scan, a row edit, a hash transplant —`, + ` now describes a different database than this process serves, so an edit made there has no observable effect here`, + ` and a user authenticated here is not in that file. This server keeps answering 200 and nothing else will say so.`, + ` Fix: restart this server so it opens the file that is at that path now. Deleting the data directory`, + ` (rm -rf .objectstack/data, as demo:reset does) while a server is running is what produces this state.`, + ].join('\n'); +} + +/** A running watch. `stop()` is idempotent. */ +export interface ServedDatabaseFileWatch { + stop: () => void; +} + +/** + * Watch `opened` until it diverges, report once, and stop. + * + * Returns `undefined` when there is nothing to watch, so a caller can wire it + * unconditionally. The timer is `unref`'d: this must never be the reason a + * process stays alive. + */ +export function watchServedDatabaseFile(opts: { + opened: ServedDatabaseFile; + onDiverged: (message: string, verdict: ServedDatabaseFileVerdict) => void; + intervalMs?: number; + deps?: ServedDatabaseFileDeps; +}): ServedDatabaseFileWatch | undefined { + const intervalMs = opts.intervalMs ?? SERVED_DATABASE_FILE_CHECK_INTERVAL_MS; + if (!Number.isFinite(intervalMs) || intervalMs <= 0) return undefined; + + let stopped = false; + const timer = setInterval(() => { + if (stopped) return; + const verdict = checkServedDatabaseFile(opts.opened, opts.deps); + const message = describeServedDatabaseFileDivergence(opts.opened, verdict); + if (!message) return; + // Said ONCE, at the first divergence — the condition is permanent until a + // restart, so a repeat every interval would be the same fact re-logged + // until it is unreadable. + stop(); + opts.onDiverged(message, verdict); + }, intervalMs); + if (typeof (timer as { unref?: () => void }).unref === 'function') { + (timer as { unref: () => void }).unref(); + } + + function stop(): void { + if (stopped) return; + stopped = true; + clearInterval(timer); + } + + return { stop }; +}