diff --git a/.changeset/metadata-fs-selfwrites-content-keyed.md b/.changeset/metadata-fs-selfwrites-content-keyed.md new file mode 100644 index 0000000000..e6429e55ea --- /dev/null +++ b/.changeset/metadata-fs-selfwrites-content-keyed.md @@ -0,0 +1,62 @@ +--- +"@objectstack/metadata-fs": patch +--- + +fix(metadata-fs): stop suppressing self-writes on a wall clock, so a poll tick can no longer swallow an external edit (#7335) + +`FileSystemRepository` suppressed the watcher event its own `put()`/`delete()` +was about to produce by adding the path to a `selfWrites` Set and clearing it on +a fixed `setTimeout(…, 200)`. `handleFsChange` then dropped **any** event for a +path in that Set, without ever reading what the watcher had observed. + +Under `usePolling: true, interval: 1000` chokidar compares state once per tick, +so our own write and an external edit landing between two ticks are delivered as +a **single** event carrying the *external* content. Dropping that on a timer +destroyed the only notification the external edit would ever produce — the edit +was silently lost, and nothing later recovered it. The realistic trigger is a +`git checkout` or an editor save arriving while the process writes the same item: +the dev-mode authoring loop. + +**Measured.** The filing recorded 0/360 instrumented iterations reaching the +window and called it derived rather than observed. That was a sampling artefact: +the delivery lag of a self-write event is +`(interval - (writeTime mod interval)) + awaitWriteFinish`, so a *fixed* +pre-edit sleep phase-locks the poll and pins the lag outside the window +(measured: 519–585 ms across 25 runs). Randomising the sleep so the lag samples +`[0, interval)` uniformly, 40 runs: + +| delivery lag | runs | external edit | +|--------------|------|---------------| +| < 200 ms | 7 | **swallowed** | +| > 200 ms | 33 | delivered | + +A perfect split on the wall-clock boundary — the mechanism, observed. + +**The fix removes the pre-check rather than re-keying it**, because the +content-keyed suppression it was shadowing already existed one step further +down and needs no timer: + +- `add`/`change` — `currentHead === hash` drops the event when the bytes on disk + are the bytes we last published. `put()` sets that head in the same + continuation as its `rename`, and `awaitWriteFinish` holds any event for a + further `stabilityThreshold`, so the index is never late. +- `unlink` — `!currentHead` drops the event when the index already agrees the + item is gone. + +`delete()` additionally now retires the head **before** it unlinks rather than +after. `awaitWriteFinish` debounces only `add`/`change`, so that face gets no +stability cushion between the disk mutation and the event it produces; ordering +the index update first makes the downstream check a total suppression rather +than a race against the poll callback. A failed `unlink` restores the head +before rethrowing, so the error path is unchanged. + +No API or configuration change; the repository publishes strictly more of the +external edits it was always meant to report. + +One pre-existing limit is now documented rather than altered: identity is judged +on what round-trips through the file, so a spec whose in-memory form does not +(a `Date`, which canonicalises to `{}` in memory but to an ISO string once +written and re-read) is republished as an external `update`. Such a spec already +fails `put().version === get().hash` independently of the watcher, and the +200 ms window never covered it either — it expired some 360 ms before the event +it would have had to catch. diff --git a/packages/metadata-fs/src/repository.ts b/packages/metadata-fs/src/repository.ts index 1fa4f23636..003adb0e5a 100644 --- a/packages/metadata-fs/src/repository.ts +++ b/packages/metadata-fs/src/repository.ts @@ -94,8 +94,6 @@ export class FileSystemRepository implements MetadataRepository { private readonly heads = new Map(); /** Next seq counter, hydrated from the log on `start()`. */ private nextSeq = 1; - /** Paths we wrote ourselves; suppress the resulting chokidar event. */ - private readonly selfWrites = new Set(); private watcher: FSWatcher | null = null; private started = false; @@ -297,17 +295,15 @@ export class FileSystemRepository implements MetadataRepository { // First write of the process materializes the root (#7000). await this.ensureRoot(); await fs.mkdir(typeDir(this.layout, ref.type), { recursive: true }); - this.selfWrites.add(file); - try { - await writeJsonAtomic(file, spec); - } finally { - // Hold the suppression until chokidar has had a chance to emit; - // we keep it in selfWrites for one debounce tick. - setTimeout(() => this.selfWrites.delete(file), 200); - } + await writeJsonAtomic(file, spec); // The watcher must not depend on its own directory scan to notice a // path we created ourselves (#7282). See `trackWrittenPath`. this.trackWrittenPath(file); + // Publishing the new head here is what suppresses the watcher event this + // write is about to produce — see `handleFsChange` (#7335). It runs in + // the same continuation as the `rename` above, and `awaitWriteFinish` + // holds any event for a further `stabilityThreshold`, so the index is + // always current by the time an event for this path can be delivered. this.heads.set(key, hash); const evt: MetadataEvent = { @@ -352,13 +348,24 @@ export class FileSystemRepository implements MetadataRepository { const file = itemPath(this.layout, ref.type, ref.name); // A delete appends a tombstone to the change log, so it is a write too. await this.ensureRoot(); - this.selfWrites.add(file); + // Retire the head BEFORE touching the disk, not after (#7335). + // + // `awaitWriteFinish` only debounces `add`/`change`; chokidar emits + // `unlink` with no stability delay at all, so — unlike `put()` — this + // face has no cushion between the disk mutation and the event it + // produces. Clearing the index first makes `handleFsChange`'s + // `if (!currentHead) return` a total suppression for our own removal + // rather than a race against the poll callback. + this.heads.delete(key); try { if (existsSync(file)) await fs.unlink(file); - } finally { - setTimeout(() => this.selfWrites.delete(file), 200); + } catch (err) { + // The disk still holds the item, so the index must too — otherwise a + // failed delete would leave the repository claiming a file it can + // still read. Restores exactly the pre-call state before rethrowing. + if (currentHead !== null) this.heads.set(key, currentHead); + throw err; } - this.heads.delete(key); const seq = this.nextSeq++; const ts = this.now().toISOString(); const evt: MetadataEvent = { @@ -506,8 +513,55 @@ export class FileSystemRepository implements MetadataRepository { this.watcher = w; } + /** + * Translate a watcher event into a `MetadataEvent`, or drop it. + * + * ## Self-writes are suppressed by content identity, never by a clock (#7335) + * + * This used to open with `if (this.selfWrites.has(absPath)) return;` — a + * `Set` that `put()`/`delete()` added the path to and a `setTimeout(…, 200)` + * cleared. That check discarded **every** event for a recently-written path + * without ever looking at what the watcher had actually observed, which is + * the whole defect: with `usePolling`, chokidar compares state once per + * `interval`, so our write and an external edit landing between two ticks + * are delivered as **one** event carrying the *external* content. Dropping + * it on a wall clock destroyed the only notification that edit would ever + * produce. + * + * Measured on `origin/main` @ `69fde55`, 40 iterations, poll phase + * randomised so the delivery lag samples `[0, interval)` uniformly: + * + * delivery lag < 200ms → 7 runs → external edit SWALLOWED, every time + * delivery lag > 200ms → 33 runs → external edit delivered, every time + * + * A perfect split on the wall-clock boundary, and the reason earlier + * instrumentation saw 0/360: a *fixed* pre-edit sleep phase-locks the poll, + * pinning the lag (measured: 519–585ms across 25 runs) safely outside the + * window. Nothing about the window was rare — it was unsampled. + * + * What remains is the check that was already doing the real work one step + * down, and it needs no timer because it compares the content the watcher + * **read** against the index: + * + * - `add`/`change` — `currentHead === hash` drops the event when the bytes + * on disk are the bytes we last published. `put()` sets that head in the + * same continuation as its `rename`, and `awaitWriteFinish` holds the + * event for a further `stabilityThreshold`, so it is never late. + * - `unlink` — `!currentHead` drops the event when the index already + * agrees the item is gone. `delete()` retires the head *before* it + * unlinks, precisely because this face gets no `awaitWriteFinish` delay. + * + * Both faces are pinned together in `test/self-write-suppression.test.ts`. + * + * Note the deliberate limit: identity is judged on what round-trips through + * the file, so a spec whose in-memory form does not (a `Date`, which + * canonicalises to `{}` in memory but to an ISO string once written and + * re-read) is republished as an external `update`. That predates this change + * and is independent of it — such a spec already fails `put().version === + * get().hash`, and the 200ms window never covered it either, expiring some + * 360ms before the event it would have had to catch. + */ private async handleFsChange(absPath: string, kind: 'add' | 'change' | 'unlink'): Promise { - if (this.selfWrites.has(absPath)) return; // Suppress our own writes. const parsed = parseItemPath(this.layout, absPath); if (!parsed) return; const ref: MetaRef = { diff --git a/packages/metadata-fs/test/self-write-suppression.test.ts b/packages/metadata-fs/test/self-write-suppression.test.ts new file mode 100644 index 0000000000..c500d9e421 --- /dev/null +++ b/packages/metadata-fs/test/self-write-suppression.test.ts @@ -0,0 +1,201 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * #7335 — self-write suppression is a **content-identity** property, and it + * holds identically on both faces that write to disk: `put()` and `delete()`. + * + * ## The defect + * + * `handleFsChange` used to open with a wall-clock pre-check: `put()`/`delete()` + * added the path to a `selfWrites` Set and a `setTimeout(…, 200)` cleared it, + * and any event arriving in between was discarded **without reading what the + * watcher had observed**. Under `usePolling: true, interval: 1000` chokidar + * compares state once per tick, so our own write and an external edit landing + * between two ticks arrive as ONE event carrying the *external* content. Drop + * that on a timer and the external edit is gone — it was the only event it was + * ever going to produce. + * + * ## Why the window looked unreachable, and how it was reached + * + * The filing measured 0/360 and called the window derived rather than + * observed. That was a sampling artefact, not luck: the delivery lag of a + * self-write event is `(interval - (writeTime mod interval)) + + * awaitWriteFinish`, so a **fixed** pre-edit sleep phase-locks the poll and + * pins the lag. Measured on the pre-fix tree, fixed 1500ms sleep, 25 runs: + * lag 519–585ms — never once inside a 200ms window, exactly as filed. + * + * Randomising the sleep so the lag samples `[0, interval)` uniformly, 40 runs + * on `origin/main` @ `69fde55`: + * + * | delivery lag | runs | external edit | + * |--------------|------|---------------| + * | < 200ms | 7 | SWALLOWED | + * | > 200ms | 33 | delivered | + * + * A perfect split on the wall-clock boundary — the mechanism, observed. + * + * ## Why these cases assert at the handler seam + * + * That end-to-end reproduction is ~17% per iteration and costs seconds a run, + * because the thing being sampled IS a poll phase. Pinning it would buy a + * probabilistic test for a property that can be stated exactly, and this + * package has been ejected from the merge queue twice already by wall-clock + * watcher assertions (#7208, #7255). + * + * So the cases drive `handleFsChange` directly — the seam immediately below + * chokidar, entered with exactly the arguments a sub-200ms delivery produces — + * and assert the contract rather than the race: + * + * **an event whose observed content differs from the index must be + * published, no matter how recently we wrote that path.** + * + * Entering at lag ≈ 0 is the worst case for the old code and deterministic for + * the new: on the pre-fix tree both cases below fail (the path is in + * `selfWrites`, so nothing is published); after the fix both pass. The + * complementary direction — a genuine self-write must NOT be republished — is + * asserted alongside, so a fix that simply published everything would fail too. + * + * The two faces share one table because they implement one contract by two + * different mechanisms (`currentHead === hash` for writes, `!currentHead` for + * removals) and are the likeliest place for a future change to fix one and + * silently regress the other. + */ + +import { describe, it, expect, beforeEach, afterEach } from 'vitest'; +import fs from 'node:fs/promises'; +import path from 'node:path'; +import os from 'node:os'; +import { hashSpec } from '@objectstack/metadata-core'; +import type { MetaRef, MetadataEvent } from '@objectstack/metadata-core'; +import { FileSystemRepository } from '../src/index.js'; + +const ref = (name: string): MetaRef => ({ org: 'system', type: 'view', name }); + +/** Enter the watcher handler exactly as chokidar would. */ +type Kind = 'add' | 'change' | 'unlink'; +const deliver = (repo: FileSystemRepository, file: string, kind: Kind): Promise => + (repo as unknown as { + handleFsChange(p: string, k: Kind): Promise; + }).handleFsChange(file, kind); + +interface Face { + /** Which write face of the repository is under test. */ + readonly name: 'put' | 'delete'; + /** + * Perform our own write, then have an external actor change the same path + * underneath us, and report the event chokidar would coalesce the pair into. + */ + run(repo: FileSystemRepository, file: string, r: MetaRef): Promise<{ + kind: Kind; + /** What the external actor left on disk. */ + externalSpec: Record | null; + /** The op the resulting MetadataEvent must carry. */ + expectedOp: MetadataEvent['op']; + }>; + /** + * Perform our own write with NO external interference, and report the event + * chokidar would deliver for it. Nothing may be published for this one. + */ + selfOnly(repo: FileSystemRepository, file: string, r: MetaRef): Promise; +} + +const FACES: readonly Face[] = [ + { + name: 'put', + async run(repo, file, r) { + // Our write, then an external edit landing before the next poll tick. + // chokidar coalesces both into a single `change` carrying the LATTER. + await repo.put(r, { label: 'ours' }, { parentVersion: null, actor: 't' }); + const externalSpec = { label: 'theirs' }; + await fs.writeFile(file, JSON.stringify(externalSpec, null, 2) + '\n', 'utf8'); + return { kind: 'change', externalSpec, expectedOp: 'update' }; + }, + async selfOnly(repo, _file, r) { + await repo.put(r, { label: 'ours' }, { parentVersion: null, actor: 't' }); + return 'change'; + }, + }, + { + name: 'delete', + async run(repo, file, r) { + // Our removal, then an external actor recreating the path before the + // next tick — coalesced into a single `add` carrying THEIR content. + const a = await repo.put(r, { label: 'ours' }, { parentVersion: null, actor: 't' }); + await repo.delete(r, { parentVersion: a.version, actor: 't' }); + const externalSpec = { label: 'restored by hand' }; + await fs.mkdir(path.dirname(file), { recursive: true }); + await fs.writeFile(file, JSON.stringify(externalSpec, null, 2) + '\n', 'utf8'); + return { kind: 'add', externalSpec, expectedOp: 'create' }; + }, + async selfOnly(repo, _file, r) { + const a = await repo.put(r, { label: 'ours' }, { parentVersion: null, actor: 't' }); + await repo.delete(r, { parentVersion: a.version, actor: 't' }); + return 'unlink'; + }, + }, +]; + +describe('#7335 self-write suppression is keyed on observed content, not on a clock', () => { + let root: string; + let repo: FileSystemRepository | null = null; + + beforeEach(async () => { + root = await fs.mkdtemp(path.join(os.tmpdir(), 'os-selfwrite-')); + }); + + afterEach(async () => { + if (repo) await repo.close(); + repo = null; + await fs.rm(root, { recursive: true, force: true }); + }); + + for (const face of FACES) { + it(`${face.name}(): an external change coalesced into our own write is NOT swallowed`, async () => { + // The watcher is disabled: these cases supply the event themselves, at + // the lag that matters. Leaving a real poller running would race them. + repo = new FileSystemRepository({ root, org: 'system', disableWatch: true }); + await repo.start(); + const r = ref('coalesced'); + const file = path.join(root, 'view', 'coalesced.json'); + + const { kind, externalSpec, expectedOp } = await face.run(repo, file, r); + const before = await readLog(root); + + // Deliver at lag ≈ 0 — the instant the old wall-clock window was widest. + await deliver(repo, file, kind); + + // Assert on the durable change log: a swallow erases the record itself, + // not merely a live subscriber's copy of it. + const added = (await readLog(root)).slice(before.length); + expect(added).toHaveLength(1); + expect(added[0]!.op).toBe(expectedOp); + expect(added[0]!.source).toBe('fs'); + expect(added[0]!.actor).toBe('fs'); + expect(added[0]!.hash).toBe(hashSpec(externalSpec)); + }); + + it(`${face.name}(): our own write, undisturbed, is still not republished`, async () => { + repo = new FileSystemRepository({ root, org: 'system', disableWatch: true }); + await repo.start(); + const r = ref('undisturbed'); + const file = path.join(root, 'view', 'undisturbed.json'); + + const kind = await face.selfOnly(repo, file, r); + const before = await readLog(root); + + // Same lag ≈ 0 delivery, but nothing external happened: the content the + // watcher can observe is exactly what we published, so this must be a + // no-op WITHOUT any help from a timer. + await deliver(repo, file, kind); + + expect(await readLog(root)).toEqual(before); + }); + } +}); + +/** The durable change log — the record a swallow erases. */ +async function readLog(root: string): Promise { + const file = path.join(root, '.objectstack', '.log', 'main.jsonl'); + const text = (await fs.readFile(file, 'utf8').catch(() => '')).trim(); + return text === '' ? [] : text.split('\n').map((l) => JSON.parse(l) as MetadataEvent); +}