fix(metadata-fs): suppress self-writes by observed content, not by a 200ms clock (#7335)

.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.

packages/metadata-fs/src/repository.ts

@@ -94,8 +94,6 @@ export class FileSystemRepository implements MetadataRepository {
   private readonly heads = new Map<string, string>();
   /** 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<string>();
   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<void> {
-    if (this.selfWrites.has(absPath)) return; // Suppress our own writes.
     const parsed = parseItemPath(this.layout, absPath);
     if (!parsed) return;
     const ref: MetaRef = {

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<void> =>
+  (repo as unknown as {
+    handleFsChange(p: string, k: Kind): Promise<void>;
+  }).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<string, unknown> | 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<Kind>;
+}
+
+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<MetadataEvent[]> {
+  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);
+}