Skip to content

Commit 361e5f3

Browse files
test(metadata-fs): external-write-resync drives the sweep at its seam, 24 s to 3.3 s (#23182 row 4) (#23262)
Part of #23182 (row 4) Clause-②: no This PR covers row 4 of #23182 only: `@objectstack/metadata-fs`, `test/external-write-resync.test.ts`, 24.3 s in run `38217670691`. It changes one test file and no production file. #23182 stays open for rows 1, 3, 5 and 6. ## Where the 24 s went Per case at BASE `6f4c518b01` (vitest, ms): create/update/delete 6042–6169, exactly-once 6082–6124, unreadable directory 7030–7048, ENOENT 5012–5018, close 6. All of it was idle waiting, on two things: - **The sweep's 2 s cadence.** The first case waited for three sweeps in a row: create, then update, then delete. The cadence is `RESYNC_INTERVAL_MS`, a private constant in `src/repository.ts` that no option sets. Making it injectable would widen `FileSystemRepositoryOptions`, a published production surface, so I did not take that route. - **Three fixed 5 s quiet windows** (`QUIET_WINDOW_MS`), in the exactly-once, unreadable-directory and ENOENT cases. ## What changed (test only) - **One recovery still waits for the clock.** In the first case, the scheduled sweep recovers the lost create with nobody calling anything. The deadline is `RECOVERY_WAIT_MS` (15 s, unchanged). The case now also requires the chain to re-arm after that sweep: `resyncTimer` must be set again. This keeps the half of the pin that says the backstop runs by itself and keeps running. - **Every other sweep is called directly.** The update and delete recoveries, and every quiet window, `await` the private `resync()`, the same body the timer runs. A quiet window is now `QUIET_SWEEPS = 3` sweeps, where the old window was sized at "comfortably more than two sweeps". `self-write-suppression.test.ts` and `external-delete-requires-absence.test.ts` already test this package this way. The watcher stays blinded exactly as before, so a recovered event can only come from a sweep. - **Two cases are stricter.** In the unreadable-directory case, the first sweep that meets the fault must report it. In the ENOENT case, every driven sweep must hit the injected ENOENT (`enoentServed`). Before this change, the ENOENT case passed even if no sweep ran. - The fixed 200 ms sleep after `put()` in the unreadable-directory case is gone. `put()` is awaited and sets the head in the same continuation. - `RECOVERY_WAIT_MS` and `CASE_TIMEOUT_MS` are unchanged. No case was deleted, skipped or moved. ## Wall time Vitest module line, in ms, on a shared 4-core box under `os-verify-lock`: | | BASE `6f4c518b01` | AFTER `43fef097df` | |:--|:--|:--| | file alone | 24228 / 24364 (a verbose run: tests 24.18 s) | 3331 / 3303 / 3356 | | package suite, `--maxWorkers=2` | 24226 / 24229 | 3387 / 3330 | | package suite, `--maxWorkers=8` (2x oversubscribed) | NOT MEASURED | 3348 | - **Per case AFTER:** about 2055 ms for create/update/delete (the one scheduled sweep), about 1150 ms for exactly-once (the live watcher's 1 s poll), and under 110 ms for each of the other three. - **Package suite:** 11 files and 74 tests pass, before and after. The suite's summed test time fell from 34.6 s to 13.8 s. - **CI after this change:** NOT MEASURED here. This PR's own Test Core log will carry the module line. - `origin/main` (`afbf960c26`, which touches nothing in this package) was merged before the AFTER readings. ## Ablation: every case can still fail Each leg changed `src/repository.ts` through `scripts/ablation-replace.mjs`: the anchor count went from 1 to 0, and the marker was on disk. Each leg then ran the new file and a temporary copy of the BASE file in one vitest run. Afterwards, the file was restored to the HEAD blob `f76f6dee4f48`, with `git diff HEAD` empty. The test imports `../src/index.js`, so no dist is involved. | leg | mutation | red cases, this PR | red cases, BASE | |:--|:--|:--|:--| | A1 | `resync()` returns at once | 1, 3, 4 | 1, 3 | | A2 | `scheduleResync()` never arms | 1 | 1, 3 | | A3 | the chain never re-arms | 1 (re-arm assertion) | 1 (update) | | A4 | the sweep forgets `heads` before each file | 1, 2 | 1, 2 | | A5 | the fault latch is removed | 3 (3 reports) | 3 (3 reports) | | A6 | an unreadable type is not recorded | none | none | | A8 | A6, plus the delete pass's `existsSync` re-check removed | 3 (2 deletes) | 3 (2 deletes) | | A7 | ENOENT is reported as a fault | 4 | 4 | - **A2 is the one place where this PR reds fewer cases.** At BASE, the unreadable-directory case also needed the scheduler. Now only case 1 does, so the scheduler half of the pin rests on case 1's scheduled create and its re-arm assertion. - **A6 stays green on both trees.** The delete pass re-checks the disk under the per-key lock, which is a second guard. A8 removes both guards and turns case 3 red on both trees. - **A1 reds case 4 here but not at BASE,** because the old ENOENT case passed without any sweep. ## Gates, lint and typecheck (at `43fef097df`) - **Gates:** `dispatch-gates --commands --repo objectstack-ai/objectstack` gives 49 commands, identical to the dispatch list. All 49 ran. `--ran` with exit codes reads "49 derived, 49 run, 0 NOT-MEASURED, 0 UNRUN". - `check:dual-build-cjs-loads` and `check:lean-entry-closure` first exited 3 (PREREQUISITE NOT MET, no dist). Both were re-run green after `turbo run build` (75 tasks, 73 from cache). - `check:sourcemap-no-sources-content` was also re-run after the build: 70 packages, 554 maps. - **Typecheck:** `pnpm --filter @objectstack/metadata-fs typecheck` exits 0. `tsc --listFiles` on `tsconfig.test.json` names the test file once. - **Lint (narrowed to the one file):** `eslint --no-inline-config --format json` reports 1 file, 0 errors and 0 warnings. - `--print-config` returns a config for the file, so it is linted. - Its parserOptions are `ecmaVersion` and `sourceType` only. Without type-aware linting, the diff cannot change any other file's result. - **Bytes:** `check:nul-bytes` exits 0, and a control-byte scan of the file finds 0 lines. ## No changeset This diff changes only a test. I built the package with `pnpm --filter @objectstack/metadata-fs build` and searched its `files` (`dist`, `README.md` and `CHANGELOG.md`). The test-only names `QUIET_SWEEPS`, `reportedByFirstSweep`, `enoentServed` and `blindWatcher` have 0 hits. The production controls `RESYNC_INTERVAL_MS` and `reportResyncFault` hit 2 and 4 files. `skip-changeset` is labelled. ## Acceptance notes - This row's pin is the next refresh PR's list no longer naming this file. - Outside the module line: a single-file run of this package spends 12.5 to 15.2 s in vitest's import phase (the `import` figure in the summary line), and no module line reports it. This is an observation only and is not filed. Carrier: none. --- _Generated by [Claude Code](https://claude.ai/code/session_01P88ehrZ6hM19hBzdpsQTTo)_ Co-authored-by: Claude <noreply@anthropic.com>
1 parent 4f68ba1 commit 361e5f3

1 file changed

Lines changed: 83 additions & 11 deletions

File tree

‎packages/metadata-fs/test/external-write-resync.test.ts‎

Lines changed: 83 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -39,6 +39,35 @@
3939
*
4040
* ⛔ These cases are NOT a claim about the CI mechanism, which was never
4141
* identified. They pin the repository's guarantee, not chokidar's behaviour.
42+
*
43+
* ## Which case waits for the sweep's clock, and why only one does
44+
*
45+
* The sweep runs every 2s on a private constant. Waiting out that cadence for
46+
* every recovery and every "nothing more arrived" window made this file ~24s
47+
* of wall that was almost all idle: three sequential sweeps in the first case
48+
* and three 5s quiet windows. That is over the 10s per-file test budget
49+
* (AGENTS.md, Build & Test), and the time measured nothing the sweep does.
50+
*
51+
* So the guarantee is pinned in two halves:
52+
*
53+
* - **The sweep runs by itself.** Exactly one recovery, the lost create in
54+
* the first case, waits for the backstop's own timer with nobody calling
55+
* anything, and the case then requires the chain to have re-armed behind
56+
* it. A sweep that never starts, or one that runs once and never again,
57+
* fails there.
58+
* - **What a sweep does.** Every other recovery and every quiet window
59+
* drives `resync()` itself — the body the timer runs — at the seam
60+
* immediately below the clock. That is the discipline
61+
* `self-write-suppression.test.ts` and
62+
* `external-delete-requires-absence.test.ts` set for this package: assert
63+
* the contract, not the race. A driven sweep is awaited, so a quiet window
64+
* is a count of sweeps that really ran, not a span of time in which some
65+
* might have.
66+
*
67+
* The scheduled sweep keeps running beside the driven ones. A scheduled pass
68+
* that lands between two driven passes is one more sweep over the same disk
69+
* against the same content-keyed index: it can add a chance to fail an
70+
* exactly-once or a said-once assertion, never remove one.
4271
*/
4372

4473
import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest';
@@ -58,8 +87,8 @@ const sleep = (ms: number) => new Promise<void>((r) => setTimeout(r, ms));
5887
*/
5988
const RECOVERY_WAIT_MS = 15_000;
6089

61-
/** Comfortably more than two sweeps, for the "did NOT republish" cases. */
62-
const QUIET_WINDOW_MS = 5_000;
90+
/** More than two sweeps, for the "did NOT republish" and "said once" cases. */
91+
const QUIET_SWEEPS = 3;
6392

6493
const CASE_TIMEOUT_MS = 60_000;
6594

@@ -75,8 +104,24 @@ interface WatcherHandle {
75104
} | null;
76105
resyncTimer: unknown;
77106
resyncEnabled: boolean;
107+
resync(): Promise<void>;
78108
}
79109

110+
/**
111+
* Run ONE reconciliation sweep now: the body `scheduleResync`'s timer runs,
112+
* without waiting out the cadence for it. It is awaited, so whatever it
113+
* publishes has been published when it returns, or never will be.
114+
*/
115+
const sweep = (repo: FileSystemRepository): Promise<void> =>
116+
(repo as unknown as WatcherHandle).resync();
117+
118+
/**
119+
* Enough turns for whatever a driven sweep published to reach the subscriber.
120+
* It is not a race budget: the sweep was awaited, so this only lets the
121+
* broker's queue drain into the array.
122+
*/
123+
const settle = () => sleep(50);
124+
80125
const handleOf = (repo: FileSystemRepository) => {
81126
const w = (repo as unknown as WatcherHandle).watcher;
82127
if (!w) throw new Error('watcher not armed — the case cannot measure anything');
@@ -156,8 +201,12 @@ describe('FileSystemRepository — external writes survive a lost watcher event
156201
// From here on chokidar can observe whatever it likes; none of it reaches
157202
// the repository. This is the state all six one-shot gates leave behind.
158203
blindWatcher(repo!);
204+
const priv = repo as unknown as WatcherHandle;
159205

160-
// ── create ───────────────────────────────────────────────────────────
206+
// ── create, recovered by the SCHEDULED sweep ─────────────────────────
207+
// Nobody calls anything here. This is the one recovery in this file that
208+
// waits for the backstop's own timer, so it is what pins that the sweep is
209+
// armed with the watcher and runs by itself.
161210
const file = path.join(viewDir, 'late.json');
162211
await fs.writeFile(file, JSON.stringify({ label: 'late' }, null, 2));
163212
await waitFor(() => events.some((e) => e.ref.name === 'late'), RECOVERY_WAIT_MS);
@@ -171,16 +220,26 @@ describe('FileSystemRepository — external writes survive a lost watcher event
171220
expect(created[0]!.actor).toBeNull();
172221
expect(created[0]!.parentHash).toBeNull();
173222

174-
// ── update ───────────────────────────────────────────────────────────
223+
// The chain re-arms behind that sweep. The timer slot is emptied when a
224+
// scheduled sweep starts and refilled only once it has finished, so it is
225+
// empty at least from the publish above until the re-arm. A sweep that ran
226+
// once and never again would recover this create and lose every later
227+
// change, and it fails here.
228+
await waitFor(() => priv.resyncTimer !== null, RECOVERY_WAIT_MS);
229+
expect(priv.resyncTimer).not.toBeNull();
230+
231+
// ── update, recovered by a driven sweep ──────────────────────────────
175232
await fs.writeFile(file, JSON.stringify({ label: 'late, edited' }, null, 2));
233+
await sweep(repo!);
176234
await waitFor(() => events.some((e) => e.ref.name === 'late' && e.op === 'update'), RECOVERY_WAIT_MS);
177235

178236
const updated = events.filter((e) => e.ref.name === 'late' && e.op === 'update');
179237
expect(updated).toHaveLength(1);
180238
expect(updated[0]!.parentHash).toBe(created[0]!.hash);
181239

182-
// ── delete ───────────────────────────────────────────────────────────
240+
// ── delete, recovered by a driven sweep ──────────────────────────────
183241
await fs.rm(file);
242+
await sweep(repo!);
184243
await waitFor(() => events.some((e) => e.ref.name === 'late' && e.op === 'delete'), RECOVERY_WAIT_MS);
185244

186245
const deleted = events.filter((e) => e.ref.name === 'late' && e.op === 'delete');
@@ -203,10 +262,13 @@ describe('FileSystemRepository — external writes survive a lost watcher event
203262

204263
// Our own write. `put()` publishes its own event; the sweep reads the same
205264
// bytes back and must recognise them as ours by content, not by a clock.
265+
// (The watcher's face of that suppression is pinned at the handler seam by
266+
// `self-write-suppression.test.ts`.)
206267
await repo!.put(ref('mine'), { label: 'mine' }, { parentVersion: null, actor: 'tester' });
207268

208-
// Several sweeps' worth of quiet.
209-
await sleep(QUIET_WINDOW_MS);
269+
// Several sweeps over that same disk, each one awaited.
270+
for (let i = 0; i < QUIET_SWEEPS; i++) await sweep(repo!);
271+
await settle();
210272

211273
expect(events.filter((e) => e.ref.name === 'once')).toHaveLength(1);
212274

@@ -220,7 +282,6 @@ describe('FileSystemRepository — external writes survive a lost watcher event
220282
await start();
221283
// A tracked item, so the delete pass has something it could wrongly retire.
222284
await repo!.put(ref('kept'), { label: 'kept' }, { parentVersion: null, actor: 'tester' });
223-
await sleep(200);
224285

225286
const errors: string[] = [];
226287
const errSpy = vi.spyOn(console, 'error').mockImplementation((...args: unknown[]) => {
@@ -239,16 +300,21 @@ describe('FileSystemRepository — external writes survive a lost watcher event
239300
return (realReaddir as (a: unknown, b?: unknown) => Promise<unknown>)(p, opts);
240301
}) as typeof fs.readdir);
241302

303+
let reportedByFirstSweep: number;
242304
try {
243-
await waitFor(() => errors.length > 0, RECOVERY_WAIT_MS);
305+
// The first sweep that meets the fault reports it.
306+
await sweep(repo!);
307+
reportedByFirstSweep = errors.length;
244308
// Keep failing across several more sweeps: a standing fault must not
245309
// reprint every 2s for the life of the process.
246-
await sleep(QUIET_WINDOW_MS);
310+
for (let i = 1; i < QUIET_SWEEPS; i++) await sweep(repo!);
247311
} finally {
248312
readdirSpy.mockRestore();
249313
errSpy.mockRestore();
250314
}
315+
await settle();
251316

317+
expect(reportedByFirstSweep).toBe(1);
252318
expect(errors).toHaveLength(1);
253319
expect(errors[0]).toContain(viewDir);
254320
expect(errors[0]).toContain('EACCES');
@@ -265,9 +331,14 @@ describe('FileSystemRepository — external writes survive a lost watcher event
265331
const errSpy = vi.spyOn(console, 'error').mockImplementation((...args: unknown[]) => {
266332
errors.push(args.map(String).join(' '));
267333
});
334+
// How many sweep reads of the type directory met the injected ENOENT. A
335+
// silence nobody exercised is no evidence, so the case requires one per
336+
// driven sweep.
337+
let enoentServed = 0;
268338
const realReaddir = fs.readdir;
269339
const readdirSpy = vi.spyOn(fs, 'readdir').mockImplementation(((p: unknown, opts?: unknown) => {
270340
if (p === viewDir) {
341+
enoentServed++;
271342
const gone: NodeJS.ErrnoException = new Error(`ENOENT: no such file or directory, scandir '${viewDir}'`);
272343
gone.code = 'ENOENT';
273344
return Promise.reject(gone);
@@ -276,12 +347,13 @@ describe('FileSystemRepository — external writes survive a lost watcher event
276347
}) as typeof fs.readdir);
277348

278349
try {
279-
await sleep(QUIET_WINDOW_MS);
350+
for (let i = 0; i < QUIET_SWEEPS; i++) await sweep(repo!);
280351
} finally {
281352
readdirSpy.mockRestore();
282353
errSpy.mockRestore();
283354
}
284355

356+
expect(enoentServed).toBeGreaterThanOrEqual(QUIET_SWEEPS);
285357
expect(errors).toEqual([]);
286358
}, CASE_TIMEOUT_MS);
287359

0 commit comments

Comments
 (0)