diff --git a/packages/agent-memory-sync/CHANGELOG.md b/packages/agent-memory-sync/CHANGELOG.md index d0fc265..c204542 100644 --- a/packages/agent-memory-sync/CHANGELOG.md +++ b/packages/agent-memory-sync/CHANGELOG.md @@ -14,3 +14,4 @@ is dated instead. The format is loosely based on - `withTickDeadline` (test helper) gained an inactivity mode: it resets its deadline on either the ready line or the new push-start line, so a per-tick test budget bounds the gap since the last observed signal instead of the tick's total duration. A second, independent absolute cap (2.5x the inactivity budget) still bounds a tick that keeps signaling forever, failing with a distinct message. - A pre-existing failure class under this package's documented load scenario stalls before either progress signal can fire: a chokidar filesystem-event delivery issue under CPU contention, present at the merge base too, at roughly a 30-40% failure rate under load on both. No timeout size fixes this; it is out of scope for this change and tracked as a follow-up. - New unit tests in `tests/unit/watch-process-inactivity.test.ts` pin the inactivity and absolute-cap semantics directly, without a real spawn. +- Root-caused (but did not fix, see below) the follow-up above (agent-tasks f876dff6). Isolated outside chokidar entirely (a standalone script, no test harness), a bare `fs.watch()` on macOS can permanently miss a write issued <1ms after the watch is reported armed — Node's own documented, currently-unfixed behavior (nodejs/node#52601), not a chokidar bug; chokidar 4.x (this package's version) uses neither `fsevents` nor polling by default, so neither of that follow-up's original "polling vs fsevents" or "atomic-write visibility" candidates were actually in play. A second candidate mechanism — the parent test-runner process's own delayed reading of the child's stderr pipe under load — was measured and ruled out: p99 9ms / max 11ms across 600 samples under load, far too small to account for missing a 90s budget. Against this package's own documented 10-worker load scenario, the historical 30-40% stall did not reproduce: a 2026-08-16/17 measurement ran the scenario 5/5 green on the merge base, both idle and under load. No retry/workaround code was added as a result — the failure this task originally investigated is not currently reproducible, and speculative retry logic tried in an earlier iteration of this task was found on review to add a deterministic regression for no measurable benefit, so it was removed again. The one behavior change kept: `spawnWatch` (test helper) now spawns its child with stdout `'ignore'` instead of an unread `'pipe'`, since nothing reads it and an unread pipe backs up once the child writes past the OS pipe buffer (64KB), which would otherwise look exactly like an unexplained stall. See `tests/helpers/watch-process.ts`'s header comment and `src/commands/watch.ts`'s ready-line comment for the full measurement notes. diff --git a/packages/agent-memory-sync/src/commands/watch.ts b/packages/agent-memory-sync/src/commands/watch.ts index b8cee12..f9ecfe5 100644 --- a/packages/agent-memory-sync/src/commands/watch.ts +++ b/packages/agent-memory-sync/src/commands/watch.ts @@ -287,11 +287,23 @@ function registerWatchCommand(program: import("commander").Command): void { // inotify-backed watcher (Linux) that scan is not instantaneous, and a // filesystem write issued before it completes can be silently missed — // chokidar has not finished wiring up inotify watch descriptors for - // every (possibly nested) watched path yet. A caller that treats this - // line as the "watch is now armed" signal (e.g. an integration test - // triggering an edit) is therefore safe on both fsevents (macOS) and - // inotify (Linux) once the line has actually printed, where a fixed - // sleep() before that point is not. + // every (possibly nested) watched path yet. This line is a large + // improvement over an unconditional sleep() before it, but is NOT a + // complete guarantee on macOS: this package's chokidar version (^4.0.3) + // depends on neither `fsevents` nor `usePolling` by default (v4 dropped + // the optional `fsevents` native dependency entirely and watches + // exclusively via Node's own fs.watch/fs.watchFile), and on macOS a + // freshly-created fs.watch() can still miss a write issued immediately + // after it returns — a currently-unfixed Node.js/libuv behavior + // (nodejs/node#52601, "Not possible to know when fs.watch has started + // on macOS"), independent of chokidar's own initial-scan/'ready' + // bookkeeping. Measured in isolation (agent-tasks f876dff6): a write + // issued 0ms after the watch is reported armed was lost 10/10 times, + // while a write issued >=1ms after was caught 10/10 times, both idle + // and under load. In practice this package's own waitForWatcherReady + // test helper (tests/helpers/watch-process.ts) polls at a 25ms + // cadence, which leaves comfortable margin above that threshold; see + // that file's header comment for the full measurement notes. watcher.on("ready", () => { writeInfo( `watching ${watchedPaths.length} path(s) under ${runConfig.rootDir} (debounce ${debounceMs}ms)`, diff --git a/packages/agent-memory-sync/tests/helpers/watch-process.ts b/packages/agent-memory-sync/tests/helpers/watch-process.ts index bbd9f2c..e3e55b9 100644 --- a/packages/agent-memory-sync/tests/helpers/watch-process.ts +++ b/packages/agent-memory-sync/tests/helpers/watch-process.ts @@ -24,6 +24,27 @@ const { spawn } = require("node:child_process"); const path = require("node:path"); +// ROOT CAUSE and follow-up findings (agent-tasks f876dff6): +// - Mechanism: on macOS, chokidar 4.x uses raw fs.watch() (no fsevents, no +// polling by default) and a freshly-armed fs.watch() can permanently miss +// a write issued <1ms after arming — a currently-unfixed Node.js/libuv +// behavior (nodejs/node#52601). Measured 0/10 caught at 0ms, 10/10 caught +// at >=1ms, both idle and under load. waitForWatcherReady's 25ms poll +// cadence leaves comfortable margin above that threshold. +// - Measured 2026-08-16/17: this file's documented 10-worker load scenario +// ran 5/5 green on the merge base, idle and under load; the historical +// 30-40% stall symptom did not reproduce. No retry/workaround is carried +// in this file as a result. +// - Ruled out: a parent-side delay reading the child's stderr +// pipe as a stall cause. Measured p99 9ms / max 11ms across 600 samples +// under load — cannot account for missing a 90s budget. +// - Ordering constraint for future changes to this file: any child.on( +// "exit", ...) listener MUST be registered before the first longer await +// after spawn() returns. Node does not replay a missed "exit" event to a +// listener attached after the fact (measured 0/15 caught at >=100ms +// delay), so a late listener can make an already-finished child look like +// a 90s stall. +// // Matches watch.ts's "watching N path(s) under ..." ready line. --verbose is // required for it to print at all: writeInfo (src/output.ts) is a no-op // unless verbose is set, which is why every watch invocation through this @@ -201,7 +222,12 @@ function spawnWatch(args: string[], env: NodeJS.ProcessEnv) { const child = spawn( path.resolve(process.cwd(), "node_modules", ".bin", "tsx"), ["src/main.ts", ...args], - { env, stdio: ["ignore", "pipe", "pipe"], detached: true } + // stdout is "ignore", not "pipe": nothing below ever reads child.stdout + // (only child.stderr is drained, see the "data" listener further down), + // and an unread "pipe" backs up once the child writes more than the OS + // pipe buffer (64KB) — which would block the child's own write() call + // and look exactly like an unexplained stall from the test's side. + { env, stdio: ["ignore", "ignore", "pipe"], detached: true } ); if (typeof child.pid === "number") { liveGroupPids.add(child.pid);