agent-watcher/mcp-watcher/test/watcher.test.ts
bob-boat 95ff60ce94 mcp-watcher: safety-poll fallback for dropped inotify events
Adds a periodic timer (default 30s) that calls drain() unconditionally,
covering the case where chokidar/inotify silently drops an IN_MODIFY
event. Observed twice in production: ping appended to inbox, file mtime
updated, but no event delivered to the watcher; a sibling-file touch
unblocked it. Root cause is Linux inotify under brief idle gaps + atomic
writes — not consistently reliable on its own.

drain() is already idempotent (HWM comparison short-circuits when
nothing's new), so the steady-state overhead is one stat + JSON parse
per poll cycle. Event-driven path remains the primary; the poll just
masks the rare miss within the cycle interval.

- safetyPollMs option: default 30_000, set to 0 to disable
- stop() clears the interval before closing chokidar
- Two new tests: safety-poll delivers when fs-event never fires;
  safetyPollMs:0 truly disables the timer

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-05-23 12:54:26 -04:00

216 lines
7.5 KiB
TypeScript

import { describe, it, expect, beforeEach, afterEach } from "vitest";
import { mkdtempSync, writeFileSync, mkdirSync, appendFileSync, rmSync, readFileSync } from "node:fs";
import { tmpdir } from "node:os";
import { join } from "node:path";
import { makePaths } from "../src/paths.js";
import { InboxWatcher } from "../src/watcher.js";
import type { PingEvent } from "../src/inbox.js";
let dir: string;
beforeEach(() => {
dir = mkdtempSync(join(tmpdir(), "watcher-watch-"));
});
afterEach(() => {
rmSync(dir, { recursive: true, force: true });
});
const ev = (over: Partial<PingEvent>): PingEvent => ({
ts: "2026-05-06T10:00:00Z",
id: "ping-" + Math.random().toString(36).slice(2, 10),
from: "foreman",
to: "bob",
type: "INFO",
payload: "test",
...over,
});
const writeInbox = (path: string, events: PingEvent[]) => {
mkdirSync(join(path, "..").replace(/[^/]*\/?$/, ""), { recursive: true });
writeFileSync(path, events.map((e) => JSON.stringify(e)).join("\n") + "\n");
};
describe("InboxWatcher initial drain", () => {
it("emits all unread events on start, then advances HWM", async () => {
const paths = makePaths(dir);
mkdirSync(paths.pingsDir, { recursive: true });
writeInbox(paths.inbox("bob"), [
ev({ id: "a", ts: "2026-05-06T10:00:00Z" }),
ev({ id: "b", ts: "2026-05-06T11:00:00Z" }),
]);
const delivered: { event: PingEvent; warning?: string }[] = [];
const w = new InboxWatcher({
paths,
agent: "bob",
notify: async (event, warning) => {
delivered.push({ event, warning });
},
// No-op chokidar substitute
startWatcher: () => ({ async close() {} }),
});
await w.start();
await w.stop();
expect(delivered.map((d) => d.event.id)).toEqual(["a", "b"]);
const hwm = JSON.parse(readFileSync(paths.hwm("bob"), "utf8"));
expect(hwm.last_delivered_ts).toBe("2026-05-06T11:00:00Z");
});
it("orders urgent before normal regardless of timestamp", async () => {
const paths = makePaths(dir);
mkdirSync(paths.pingsDir, { recursive: true });
writeInbox(paths.inbox("bob"), [
ev({ id: "older-normal", ts: "2026-05-06T10:00:00Z", priority: "normal" }),
ev({ id: "newer-urgent", ts: "2026-05-06T11:00:00Z", priority: "urgent" }),
]);
const delivered: PingEvent[] = [];
const w = new InboxWatcher({
paths, agent: "bob",
notify: async (e) => { delivered.push(e); },
startWatcher: () => ({ async close() {} }),
});
await w.start();
await w.stop();
expect(delivered.map((d) => d.id)).toEqual(["newer-urgent", "older-normal"]);
});
it("defers a sentinel-missing ping and re-attempts on next drain", async () => {
const paths = makePaths(dir);
mkdirSync(paths.pingsDir, { recursive: true });
writeInbox(paths.inbox("bob"), [ev({ id: "a", sentinel: "/nope" })]);
const delivered: PingEvent[] = [];
let triggerChange: () => void = () => {};
const w = new InboxWatcher({
paths, agent: "bob",
notify: async (e) => { delivered.push(e); },
sentinelExists: () => false,
startWatcher: (_path, onChange) => {
triggerChange = onChange;
return { async close() {} };
},
});
await w.start();
expect(delivered).toEqual([]);
// hwm has pending_attempts.a = 1 but ts not advanced
let hwm = JSON.parse(readFileSync(paths.hwm("bob"), "utf8"));
expect(hwm.pending_attempts).toEqual({ a: 1 });
expect(hwm.last_delivered_ts).toBe("");
// Two more triggers — third delivery emits with warning
triggerChange();
await new Promise((r) => setTimeout(r, 10));
triggerChange();
await new Promise((r) => setTimeout(r, 10));
expect(delivered.map((d) => d.id)).toEqual(["a"]);
hwm = JSON.parse(readFileSync(paths.hwm("bob"), "utf8"));
expect(hwm.pending_attempts).toEqual({});
expect(hwm.last_delivered_ts).toBe("2026-05-06T10:00:00Z");
await w.stop();
});
it("populates recentEvents map for tools to look up sender", async () => {
const paths = makePaths(dir);
mkdirSync(paths.pingsDir, { recursive: true });
writeInbox(paths.inbox("bob"), [
ev({ id: "ping-x", from: "mom" }),
ev({ id: "ping-y", from: "foreman" }),
]);
const w = new InboxWatcher({
paths, agent: "bob",
notify: async () => {},
startWatcher: () => ({ async close() {} }),
});
await w.start();
expect(w.recentEvents().get("ping-x")?.from).toBe("mom");
expect(w.recentEvents().get("ping-y")?.from).toBe("foreman");
await w.stop();
});
it("safety-poll delivers pings appended while no fs-event fires", async () => {
// Simulates the dropped-inotify-event case: chokidar mock never fires
// onChange. A ping is appended after start(); only the safety-poll
// timer can catch it. Asserts the watcher recovers within one poll cycle.
const paths = makePaths(dir);
mkdirSync(paths.pingsDir, { recursive: true });
writeInbox(paths.inbox("bob"), [ev({ id: "before-start", ts: "2026-05-06T10:00:00Z" })]);
const delivered: PingEvent[] = [];
const w = new InboxWatcher({
paths,
agent: "bob",
notify: async (e) => { delivered.push(e); },
// Chokidar mock that NEVER fires onChange — simulates a dropped event.
startWatcher: () => ({ async close() {} }),
safetyPollMs: 20,
});
await w.start();
expect(delivered.map((d) => d.id)).toEqual(["before-start"]);
// Append a new ping post-start, without notifying chokidar.
appendFileSync(
paths.inbox("bob"),
JSON.stringify(ev({ id: "after-start", ts: "2026-05-06T12:00:00Z" })) + "\n",
);
// Wait long enough for at least one safety-poll cycle.
await new Promise((r) => setTimeout(r, 80));
await w.stop();
expect(delivered.map((d) => d.id)).toEqual(["before-start", "after-start"]);
const hwm = JSON.parse(readFileSync(paths.hwm("bob"), "utf8"));
expect(hwm.last_delivered_ts).toBe("2026-05-06T12:00:00Z");
});
it("safetyPollMs: 0 disables the safety-poll timer", async () => {
const paths = makePaths(dir);
mkdirSync(paths.pingsDir, { recursive: true });
writeInbox(paths.inbox("bob"), [ev({ id: "a", ts: "2026-05-06T10:00:00Z" })]);
const delivered: PingEvent[] = [];
const w = new InboxWatcher({
paths,
agent: "bob",
notify: async (e) => { delivered.push(e); },
startWatcher: () => ({ async close() {} }),
safetyPollMs: 0,
});
await w.start();
// Append a ping; with no fs-event AND no safety-poll, it must NOT be delivered.
appendFileSync(
paths.inbox("bob"),
JSON.stringify(ev({ id: "missed", ts: "2026-05-06T11:00:00Z" })) + "\n",
);
await new Promise((r) => setTimeout(r, 50));
await w.stop();
expect(delivered.map((d) => d.id)).toEqual(["a"]); // only the initial-drain ping
});
it("skips pings already covered by HWM on restart", async () => {
const paths = makePaths(dir);
mkdirSync(paths.pingsDir, { recursive: true });
writeInbox(paths.inbox("bob"), [
ev({ id: "a", ts: "2026-05-06T10:00:00Z" }),
ev({ id: "b", ts: "2026-05-06T11:00:00Z" }),
]);
writeFileSync(
paths.hwm("bob"),
JSON.stringify({ last_delivered_ts: "2026-05-06T10:00:00Z", pending_attempts: {} }),
);
const delivered: PingEvent[] = [];
const w = new InboxWatcher({
paths, agent: "bob",
notify: async (e) => { delivered.push(e); },
startWatcher: () => ({ async close() {} }),
});
await w.start();
await w.stop();
expect(delivered.map((d) => d.id)).toEqual(["b"]);
});
});