Skip to content

Commit fb2a0fe

Browse files
committed
fix(tests): handle filesystem races in JSON crash checker
1 parent 62c7cd9 commit fb2a0fe

3 files changed

Lines changed: 97 additions & 10 deletions

File tree

‎docs/architecture/task-lifecycle-model.md‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -346,6 +346,12 @@ Successful cold initialization must report a healthy store.
346346

347347
A successful rename can publish a new value before the write promise resolves.
348348
The checker treats that value as committed.
349+
A native rename can also finish after the last JavaScript snapshot but before SIGKILL.
350+
The checker reads committed files after child exit to set exact follow-up expectations.
351+
That final state must preserve the newest value already observed.
352+
An observer also retries a complete snapshot if a rename races its directory listing and file reads.
353+
Three failed attempts exhaust the snapshot budget and fail the check.
354+
Deterministic regressions cover both orderings without waiting for scheduling races.
349355
Deletion follow-ups run without injected faults.
350356
The best-effort delete API can resolve after an I/O failure; this check does not strengthen that contract.
351357

‎scripts/check-json-replacement.test.ts‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -31,3 +31,16 @@ for (const workers of ["0", "9", "1.5", "invalid"]) {
3131
assert.match(result.stderr, /JSON_REPLACEMENT_WORKERS must be an integer from 1 to 8/)
3232
})
3333
}
34+
35+
for (const regression of ["rename-in-flight", "snapshot-race"]) {
36+
test(`accepts the deterministic ${regression} schedule`, () => {
37+
const result = spawnSync(
38+
process.execPath,
39+
["--import", "tsx", "scripts/check-json-replacement.ts", `--regression=${regression}`],
40+
{ encoding: "utf8", timeout: 30_000 },
41+
)
42+
assert.ifError(result.error)
43+
assert.equal(result.status, 0, result.stderr)
44+
assert.match(result.stdout, new RegExp(`${regression} regression passed`))
45+
})
46+
}

‎scripts/check-json-replacement.ts‎

Lines changed: 78 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -19,17 +19,30 @@ type Result = { op: string; ok: boolean; code?: string; value?: string; repairRu
1919
const CHILD = String.raw`
2020
const fs = require("fs"), fsp = require("fs/promises"), path = require("path")
2121
const native = { ...fsp }, emit = (data) => fs.writeSync(1, JSON.stringify(data) + "\n")
22-
let root = process.env.CHECK_ROOT, fault = JSON.parse(process.env.CHECK_FAULT || "null"), count = 0, forced = false, rolledBack = false, observing = true, pending = 0
22+
let root = process.env.CHECK_ROOT, fault = JSON.parse(process.env.CHECK_FAULT || "null"), count = 0, forced = false, rolledBack = false, observing = true, pending = 0, pendingClose, pendingCommit, pendingSnapshotMove
2323
const canonical = () => path.join(root, "tasks", "child", "history_item.json")
2424
const normalize = (p) => typeof p === "string" ? path.relative(root, p).replace(/\\/g, "/").replace(/\.(new|bak)_[^.]+\.tmp/g, ".$1.tmp") : ""
2525
function copies() {
2626
const dir = path.dirname(canonical())
27-
return fs.readdirSync(dir).filter((name) => name === "history_item.json" || (name.startsWith(".history_item.json.bak_") && name.endsWith(".tmp"))).map((name) => fs.readFileSync(path.join(dir, name), "utf8"))
27+
// Native namespace changes can race this synchronous list/read observer.
28+
// Retry the whole snapshot; never drop a missing entry from a stale list.
29+
for (let attempt = 0; attempt < 3; attempt++) {
30+
try {
31+
const names = fs.readdirSync(dir).filter((name) => name === "history_item.json" || (name.startsWith(".history_item.json.bak_") && name.endsWith(".tmp")))
32+
if (pendingSnapshotMove) { const move = pendingSnapshotMove; pendingSnapshotMove = undefined; move() }
33+
return names.map((name) => fs.readFileSync(path.join(dir, name), "utf8"))
34+
} catch (error) { if (error.code !== "ENOENT") throw error }
35+
}
36+
throw new Error("Committed-copy snapshot retry budget exhausted")
2837
}
2938
console.error = console.warn = console.log = () => {}
3039
Math.random = () => 0.5
3140
function cut(n, phase) {
3241
if (fault && fault.step === n && fault.kind === phase) {
42+
if (process.env.CHECK_SCHEDULE === "late-rename") {
43+
if (!pendingCommit) throw new Error("Regression schedule did not reach the in-flight rename")
44+
pendingCommit()
45+
}
3346
emit({ crash: true }); process.kill(process.pid, "SIGKILL")
3447
}
3548
}
@@ -54,7 +67,22 @@ function after(n, call, error) {
5467
for (const name of ["mkdir", "access", "readdir", "stat", "readFile", "rename", "unlink"]) {
5568
fsp[name] = async (...args) => {
5669
const { n, error } = before(name, args)
57-
try { if (error) throw error; const value = await native[name](...args); after(n, name); return value }
70+
try {
71+
if (error) throw error
72+
if (name === "rename" && process.env.CHECK_SCHEDULE === "move-during-snapshot" && args[0] === canonical()) {
73+
pendingSnapshotMove = () => fs.renameSync(...args)
74+
if (pendingClose) pendingClose()
75+
return await new Promise(() => {})
76+
}
77+
if (name === "rename" && process.env.CHECK_SCHEDULE === "late-rename") {
78+
// Hold the real rename until the close snapshot has been emitted. Its
79+
// filesystem effect then lands before SIGKILL, without a JS completion event.
80+
pendingCommit = () => fs.renameSync(...args)
81+
if (pendingClose) pendingClose()
82+
return await new Promise(() => {})
83+
}
84+
const value = await native[name](...args); after(n, name); return value
85+
}
5886
catch (error) { after(n, name, error); throw error }
5987
}
6088
}
@@ -64,7 +92,13 @@ function callbacks(names, prefix) {
6492
const callback = args.pop(), { n, error } = before(prefix + name, args)
6593
if (error) { after(n, prefix + name, error); return callback(error) }
6694
pending++
67-
return fs[name](...args, (error, ...values) => { pending--; after(n, prefix + name, error); callback(error, ...values) })
95+
return fs[name](...args, (error, ...values) => {
96+
const finish = () => { pending--; after(n, prefix + name, error); callback(error, ...values) }
97+
if (prefix === "stream." && name === "close" && process.env.CHECK_SCHEDULE) {
98+
pendingClose = finish
99+
if (pendingCommit || pendingSnapshotMove) finish()
100+
} else finish()
101+
})
68102
}
69103
return result
70104
}
@@ -173,7 +207,13 @@ function committed(root: string): string[] {
173207
)
174208
.map((name) => fs.readFileSync(path.join(dir, name), "utf8"))
175209
}
176-
async function runtime(bundle: string, root: string, mode: string, fault?: Fault) {
210+
async function runtime(
211+
bundle: string,
212+
root: string,
213+
mode: string,
214+
fault?: Fault,
215+
schedule?: "late-rename" | "move-during-snapshot",
216+
) {
177217
const child = await new Promise<{ status: number | null; stdout: string; stderr: string }>((resolve, reject) => {
178218
execFile(
179219
process.execPath,
@@ -190,6 +230,7 @@ async function runtime(bundle: string, root: string, mode: string, fault?: Fault
190230
CHECK_MODE: mode,
191231
CHECK_INCOMING: encoded[2],
192232
CHECK_FAULT: JSON.stringify(fault ?? null),
233+
CHECK_SCHEDULE: schedule,
193234
},
194235
encoding: "utf8",
195236
timeout: 20_000,
@@ -296,13 +337,19 @@ function violation(invariant: number, context: string, events: Event[]): never {
296337
.join("\n"),
297338
)
298339
}
299-
async function runCase(bundle: string, dir: string, mode: Mode, fault?: Fault) {
340+
async function runCase(
341+
bundle: string,
342+
dir: string,
343+
mode: Mode,
344+
fault?: Fault,
345+
schedule?: "late-rename" | "move-during-snapshot",
346+
) {
300347
const root = path.join(dir, "storage")
301348
seed(root, mode)
302349
const beforeCanonical = fs.existsSync(path.join(root, relativeCanonical))
303350
? fs.readFileSync(path.join(root, relativeCanonical), "utf8")
304351
: undefined
305-
const run = await runtime(bundle, root, mode, fault)
352+
const run = await runtime(bundle, root, mode, fault, schedule)
306353
const context = `${mode} ${JSON.stringify(fault ?? "no fault")}`
307354
let latest = mode === "newer" ? 1 : 0
308355
for (const [index, event] of run.events.entries()) {
@@ -316,8 +363,12 @@ async function runCase(bundle: string, dir: string, mode: Mode, fault?: Fault) {
316363
run.events.some((event) => event.n === fault.step),
317364
"Fault cutpoint was not reached",
318365
)
319-
if (!committed(root).some((data) => encoded.some((entry) => entry === data)))
320-
violation(2, context + " lost the only committed copy", run.events)
366+
// Native renames can finish after the last JS snapshot but before SIGKILL.
367+
// Once the child exits, its actual disk state owns follow-up expectations.
368+
const diskVersion = Math.max(-1, ...committed(root).map((data) => encoded.findIndex((entry) => entry === data)))
369+
if (diskVersion < latest)
370+
violation(2, context + " lost the latest committed copy after the last snapshot", run.events)
371+
latest = diskVersion
321372
const result = run.results[0]
322373
if (
323374
result?.ok &&
@@ -342,7 +393,12 @@ async function runCase(bundle: string, dir: string, mode: Mode, fault?: Fault) {
342393
if (followup.op === "delete" && followup.value !== undefined)
343394
violation(4, context + " deleted file returned after recovery", run.events)
344395
if (followup.op !== "delete" && followup.value !== encoded[followup.op === "write" ? 2 : latest])
345-
violation(3, context + " invalid follow-up value", run.events)
396+
violation(
397+
3,
398+
context +
399+
` follow-up ${followup.op} returned an invalid value (expected version ${followup.op === "write" ? 2 : latest})`,
400+
run.events,
401+
)
346402
if (followup.op === "cold" && !followup.healthy)
347403
violation(5, context + " cold-start snapshot unavailable", run.events)
348404
}
@@ -354,6 +410,18 @@ async function main() {
354410
const mutation = process.argv.find((arg) => arg.startsWith("--mutation="))?.split("=")[1]
355411
const bundle = path.join(work, "production.cjs")
356412
await bundleAt(bundle, mutation)
413+
const regression = process.argv.find((arg) => arg.startsWith("--regression="))?.split("=")[1]
414+
if (regression === "rename-in-flight" || regression === "snapshot-race") {
415+
const mode = regression === "rename-in-flight" ? "write" : "fallback"
416+
const schedule = regression === "rename-in-flight" ? "late-rename" : "move-during-snapshot"
417+
const trace = await runCase(bundle, path.join(work, "baseline"), mode)
418+
const close = trace.find((event) => event.phase === "before" && event.call === "stream.close")
419+
assert(close, "Regression requires the real stream-close boundary")
420+
await runCase(bundle, path.join(work, schedule), mode, { step: close.n, kind: "after" }, schedule)
421+
console.log(`${regression} regression passed`)
422+
return
423+
}
424+
assert(!regression, "Unknown regression")
357425
if (mutation === "restore-backup-loss") {
358426
const baseline = path.join(work, "baseline")
359427
const events = await runCase(bundle, baseline, "restore")

0 commit comments

Comments
 (0)