diff --git a/docs/reference/native-compose-commands.md b/docs/reference/native-compose-commands.md index bd051489..6d0d5b02 100644 --- a/docs/reference/native-compose-commands.md +++ b/docs/reference/native-compose-commands.md @@ -366,7 +366,8 @@ cardinality, program/storage mounts and policy stability. A re-inspected carrier whose creation time, policy or stopped state changed reports `helper-policy-stability`, and a saved material binding that changed during a carrier step, or before a verification's deferred evidence retirement, reports -`private-state`. A policy or state refusal keeps its reason even when it is +`private-state`, as does an original command owner vetoed before that +retirement. A policy or state refusal keeps its reason even when it is caught after the carrier's deadline. A timeout, budget or otherwise unclassified refusal that finds its carrier's storage budget exhausted, and not cancelled, reports `storage-budget`, which names diff --git a/docs/reference/native-compose-storage-xattr-carrier.md b/docs/reference/native-compose-storage-xattr-carrier.md index 4e2a571d..8ea4af98 100644 --- a/docs/reference/native-compose-storage-xattr-carrier.md +++ b/docs/reference/native-compose-storage-xattr-carrier.md @@ -392,8 +392,11 @@ original completion state. It does not acquire a PID from the durable record. The carrier uses held regular capture files, not pipes. Version 2 therefore names its capture evidence `held-files-quiescent`, never EOF. The original exit callback, strict ESRCH group absence, held file/path identity, both synchronized bounded -captures and their hashes precede settlement publication. EPERM/EIO and unknown -exit or capture disposition refuse. Settlement publication shares one finite +captures and their hashes precede settlement publication. Only ESRCH proves group +absence: a group probe answering EPERM (which macOS can return just after the +group's last member exits) is not absence, so observation continues to the same +budget and refuses there if ESRCH never follows. EIO and unknown exit or capture +disposition refuse. Settlement publication shares one finite 15-second post-command budget with group observation and its identity reads; timeout/cancellation remain refused results and cannot grant a subsequent daemon command. These budgets must outlast an ordinary multi-second host stall: a stalled @@ -437,7 +440,8 @@ Budgets are layered and all finite: it reports `storage-budget`. A recorded command's 15-second settlement budget follows its exit. - An unrecorded command (an identity read or a legacy root/seed command) waits - at most three seconds for its process group to become absent after exit. Like + at most three seconds for its process group to become absent after exit, + including while the group probe answers EPERM (HACK-1463). Like the handshake and settlement budgets, this deadline is monotonic (`performance.now`), so a wall-clock step cannot shorten or extend it. Exhaustion refuses as `probe-budget`. @@ -451,7 +455,8 @@ record replaces it with a fixed refusal. Such reasons include a helper policy refusal, `helper-policy-stability` for a re-inspected carrier whose creation time, policy or stopped state changed, and `private-state` for a saved material binding that changed during a carrier step or before a verification's deferred -evidence retirement. Cancellation +evidence retirement, or for an original command owner vetoed before that +retirement. Cancellation keeps `probe-cancel`. The reason changes no check, retention or recovery rule. Only the original in-memory writer can advance its exact sequence. Publication diff --git a/src/lib/native-compose-storage-witness-docker.ts b/src/lib/native-compose-storage-witness-docker.ts index 70c15ff7..c44d6654 100644 --- a/src/lib/native-compose-storage-witness-docker.ts +++ b/src/lib/native-compose-storage-witness-docker.ts @@ -927,8 +927,16 @@ export async function reconcileNativeComposeStorageDockerCarrierRecovery( * instead. Fixed and finite; exhaustion refuses as `probe-budget`. */ const UNRECORDED_GROUP_BUDGET_MS = 3000; -/** Every deadline here is monotonic (`performance.now`), like the handshake and - * settlement budgets: a wall-clock step cannot shorten or extend the wait. */ +/** + * Waits until the exited command's process group is proven absent: only `ESRCH` + * proves it. `EPERM` means the group still has a member this process cannot + * signal. macOS can answer it just after the last member exited (seen once in + * 400 exits on a loaded host), so it is not absence: the wait continues to the + * same deadline (HACK-1463). Refusing it at once refused healthy commands as + * `unclassified` on a loaded host. Every deadline here is monotonic + * (`performance.now`), like the handshake and settlement budgets: a wall-clock + * step cannot shorten or extend the wait. + */ async function groupAbsent( pid: number, monotonicDeadline?: number @@ -945,7 +953,9 @@ async function groupAbsent( if (isRecord(error) && error.code === "ESRCH") { return; } - return refuse(); + if (!(isRecord(error) && error.code === "EPERM")) { + return refuse(); + } } if (performance.now() >= deadline) { return refuseCommand("probe-budget"); @@ -2191,8 +2201,16 @@ export async function createNativeComposeDockerStorageXattrCarrier( const check = async () => { await checkCompletion(); tool(); + // The live owner veto guards this invocation's saved command + // record. Every command settled before this finalizer was set, so + // no deadline can invalidate the owner now: a vetoed owner reports + // `private-state` at the carrier's own cleanup stage. Untagged, it + // would read `storage-budget` once caught past the deadline. if (!nativeComposeStorageCommandOwnerConfirmed(owner)) { - return refuse(); + return refuseObserved( + "storage-helper-cleanup", + "private-state" + ); } // Deferred retirement is the carrier's own cleanup: a binding // changed since the invocation began reports `private-state`. diff --git a/tests/native-compose-storage-binding-call-sites.test.ts b/tests/native-compose-storage-binding-call-sites.test.ts index e320da94..a4c7a1dc 100644 --- a/tests/native-compose-storage-binding-call-sites.test.ts +++ b/tests/native-compose-storage-binding-call-sites.test.ts @@ -10,6 +10,7 @@ import { beginNativeComposeStorageCarrierIntent, initializeNativeComposeStorageCarrierJournal, } from "../src/lib/native-compose-storage-carrier-journal.ts"; +import * as commandRecord from "../src/lib/native-compose-storage-command-record.ts"; import { createNativeComposeDockerStorageXattrCarrier, nativeComposeStorageCarrierBudgetReason, @@ -257,6 +258,9 @@ function outcomeOf(error: unknown, deadline: number) { async function verifyOnce(opts: { readonly perturb: number; readonly fault?: { readonly name: Fault; readonly inspection: number }; + /** Invalidate the real original command owner once the invoke returned, + * before its deferred finish, as a live owner veto would. */ + readonly vetoOwner?: true; }) { const f = await fixture({ volume: true }); if (opts.fault) { @@ -266,6 +270,17 @@ async function verifyOnce(opts: { ); } return await withCarrierEnvironment(f, opts.perturb, async (reads) => { + // The real owner, captured as it is created; nothing else changes. + const owners: commandRecord.NativeComposeStorageCommandOwner[] = []; + const createOwner = commandRecord.createNativeComposeStorageCommandOwner; + const ownerCreation = spyOn( + commandRecord, + "createNativeComposeStorageCommandOwner" + ).mockImplementation(async (owner) => { + const created = await createOwner(owner); + owners.push(created); + return created; + }); const { deadline, handle } = await carrier(f); const ports = nativeComposeStorageXattrCarrierPorts(handle); const journalPath = join(f.root, "journal"); @@ -324,10 +339,17 @@ async function verifyOnce(opts: { if (!finish) { throw new Error("Expected an original deferred finish"); } + if (opts.vetoOwner) { + expect(owners).toHaveLength(1); + for (const owner of owners) { + commandRecord.invalidateNativeComposeStorageCommandOwner(owner); + } + } await finish({ input, completion }); } catch (error: unknown) { caught = error; } finally { + ownerCreation.mockRestore(); await directory.file.close(); } return { @@ -443,6 +465,13 @@ test.each([ // once more (7) and at each of its remove command's three admissions (8-10). // The chosen inspection shows another stopped state under the same creation // time and policy. +// +// The reported refusal is asserted first: it is the property, and a carrier +// that refused before the fault (for example a host identity read refused +// under load, HACK-1463) then fails with its own stage and reason instead of a +// bare inspection count. Only the fault reports `helper-policy-stability`, and +// it refuses at once, so given that refusal the count pins which inspection +// reached the tagged call site. test.each([ ["on its repeated stopped inspection", 7], ["at its remove command's first admission", 8], @@ -454,11 +483,6 @@ test.each([ perturb: 0, fault: { name: "fault-carrier-state-changed", inspection }, }); - expect( - Number( - await Bun.file(join(verified.root, "carrier-state-inspects")).text() - ) - ).toBe(inspection); expect(verified.outcome).toEqual({ refusal: { stage: "storage-helper-policy", @@ -466,8 +490,33 @@ test.each([ }, late: "helper-policy-stability", }); + expect( + Number( + await Bun.file(join(verified.root, "carrier-state-inspects")).text() + ) + ).toBe(inspection); // The helper ran once; nothing proved or retired the witness afterwards. expect(await helperOperations(verified.root)).toEqual(["verify"]); }, CASE_BUDGET_MS ); + +// The deferred finish checks the live original command owner before its +// binding read (read 49). An owner vetoed after every command settled is the +// invocation's saved private state, so the finish refuses as `private-state` at +// the carrier's own cleanup stage; untagged, it would report `unclassified`, +// and `storage-budget` once caught after the carrier deadline. +test( + "a verify whose original command owner was vetoed before its deferred finish refuses as private-state at storage-helper-cleanup, even after its deadline", + async () => { + const verified = await verifyOnce({ perturb: 0, vetoOwner: true }); + expect(verified.outcome).toEqual({ + refusal: { stage: "storage-helper-cleanup", reason: "private-state" }, + late: "private-state", + }); + // It refused before the finish's binding read and evidence retirement. + expect(verified.reads).toBe(48); + expect(await helperOperations(verified.root)).toEqual(["verify"]); + }, + CASE_BUDGET_MS +); diff --git a/tests/native-compose-storage-command-record.test.ts b/tests/native-compose-storage-command-record.test.ts index d6c436b6..1fb39738 100644 --- a/tests/native-compose-storage-command-record.test.ts +++ b/tests/native-compose-storage-command-record.test.ts @@ -1067,6 +1067,13 @@ test.each(["stdout", "stderr"] as const)( })(), 30_000 ); +/** + * Case budget for the group-absence probe refusals. `EPERM` is retried until + * the transport's 15 s settlement budget (`SETTLEMENT_BUDGET_MS` in + * native-compose-storage-witness-docker.ts) runs out before it refuses + * (HACK-1463), so the case needs that wait plus room for a loaded host. + */ +const GROUP_PROBE_REFUSAL_CASE_BUDGET_MS = 60_000; test.each(["EPERM", "EIO"] as const)( "%s is never group absence or settlement", (code) => @@ -1098,7 +1105,7 @@ test.each(["EPERM", "EIO"] as const)( } } })(), - 30_000 + GROUP_PROBE_REFUSAL_CASE_BUDGET_MS ); test.each([false, true])( "a delayed PID receipt write is bounded and permanently withholds continuation (backward wall clock: %s)", diff --git a/tests/native-compose-storage-probe-budget.test.ts b/tests/native-compose-storage-probe-budget.test.ts index 08f76dd1..2ba6f53c 100644 --- a/tests/native-compose-storage-probe-budget.test.ts +++ b/tests/native-compose-storage-probe-budget.test.ts @@ -74,6 +74,17 @@ const carrierId = "e".repeat(64); const invocationId = "a".repeat(32); /** Virtual helper start duration: above the former fixed 15 s start cap. */ const SLOW_START_MS = 20_000; +/** + * Bun budget of the recorded (original-command) slow-start proof. Its helper + * start is virtual (`Date.now` is advanced by the engine, not by waiting), so + * {@link SLOW_START_MS} costs no wall time. The real cost is the recorded + * branch's host work: three published commands, each with stopped-child + * identity reads (`/bin/ps`, `sysctl`), private-state publications and + * settlement, plus `finish()` retirement. A hosted run takes a few seconds; a + * host at load average 120-140 took over 30 s (HACK-1463), so this is a hang + * guard with a clear margin, not a speed assertion. + */ +const RECORDED_PROOF_CASE_BUDGET_MS = 120_000; const roots: string[] = []; const stores: NativeComposeGenerationStore[] = []; const heldJournals: HeldDirectory[] = []; @@ -681,57 +692,63 @@ test("a helper start slower than the former 15 s cap completes within the defaul // helper command through the recorded original-command branch (publication, // boundary deadline and settlement). That branch computes its own child bound, // so it needs its own slow-start proof. -test("a recorded exec/up verify proof completes a helper start slower than the former 15 s cap", async () => { - const budgetMs = resolveNativeStorageTimeoutMs({ env: {} }); - expect(budgetMs).toBe(90_000); - const { engine, result, error, record, retired } = await proveWithSlowStart({ - budgetMs, - recorded: true, - }); - expect(nativeComposeEffectRefusal(error)).toBeUndefined(); - expect(error).toBeNull(); - expect(result).toMatchObject({ - outcome: "complete", - exitCode: 0, - carrierId, - containersAfterCleanup: [], - }); - expect(engine.commands.map(({ verb }) => verb)).toEqual([ - "create", - "start", - "rm", - ]); - const [create, start, remove] = engine.commands; - // The recorded child bound is the remaining carrier budget, never more. - for (const command of [create, start]) { - expect(command?.timeoutMs).toBeGreaterThan(SLOW_START_MS); - expect(command?.timeoutMs).toBeLessThanOrEqual(budgetMs); - } - expect(remove?.timeoutMs).toBeGreaterThan(0); - expect(remove?.timeoutMs).toBeLessThanOrEqual( - NATIVE_STORAGE_PROBE_CEILING_MS - ); - // Every helper command was published and settled as an original command. - expect(record).not.toBeNull(); - const { commands } = parseNativeComposeStorageCommandRecord(record ?? ""); - expect(commands.map(({ kind }) => kind)).toEqual([ - "create", - "start", - "remove", - ]); - for (const command of commands) { - expect(command.child).not.toBeNull(); - expect(command.settlement).toMatchObject({ +test( + "a recorded exec/up verify proof completes a helper start slower than the former 15 s cap", + async () => { + const budgetMs = resolveNativeStorageTimeoutMs({ env: {} }); + expect(budgetMs).toBe(90_000); + const { engine, result, error, record, retired } = await proveWithSlowStart( + { + budgetMs, + recorded: true, + } + ); + expect(nativeComposeEffectRefusal(error)).toBeUndefined(); + expect(error).toBeNull(); + expect(result).toMatchObject({ + outcome: "complete", exitCode: 0, - timedOut: false, - cancelled: false, + carrierId, + containersAfterCleanup: [], }); - } - // The journal's completion retired the invocation files through finish(). - expect(retired).toBe(true); - expect(engine.elapsed).toBe(SLOW_START_MS); - expect(existsSync(tripwire)).toBe(false); -}, 30_000); + expect(engine.commands.map(({ verb }) => verb)).toEqual([ + "create", + "start", + "rm", + ]); + const [create, start, remove] = engine.commands; + // The recorded child bound is the remaining carrier budget, never more. + for (const command of [create, start]) { + expect(command?.timeoutMs).toBeGreaterThan(SLOW_START_MS); + expect(command?.timeoutMs).toBeLessThanOrEqual(budgetMs); + } + expect(remove?.timeoutMs).toBeGreaterThan(0); + expect(remove?.timeoutMs).toBeLessThanOrEqual( + NATIVE_STORAGE_PROBE_CEILING_MS + ); + // Every helper command was published and settled as an original command. + expect(record).not.toBeNull(); + const { commands } = parseNativeComposeStorageCommandRecord(record ?? ""); + expect(commands.map(({ kind }) => kind)).toEqual([ + "create", + "start", + "remove", + ]); + for (const command of commands) { + expect(command.child).not.toBeNull(); + expect(command.settlement).toMatchObject({ + exitCode: 0, + timedOut: false, + cancelled: false, + }); + } + // The journal's completion retired the invocation files through finish(). + expect(retired).toBe(true); + expect(engine.elapsed).toBe(SLOW_START_MS); + expect(existsSync(tripwire)).toBe(false); + }, + RECORDED_PROOF_CASE_BUDGET_MS +); test("a helper start that outlasts the whole storage budget still refuses at the budget's end", async () => { const budgetMs = 12_000; diff --git a/tests/native-compose-storage-witness-docker-io.test.ts b/tests/native-compose-storage-witness-docker-io.test.ts index d7da3cd2..60515757 100644 --- a/tests/native-compose-storage-witness-docker-io.test.ts +++ b/tests/native-compose-storage-witness-docker-io.test.ts @@ -1,4 +1,4 @@ -import { afterEach, expect, test } from "bun:test"; +import { afterEach, expect, spyOn, test } from "bun:test"; import { fstatSync } from "node:fs"; import { link, @@ -16,7 +16,10 @@ import { holdDirectory, writeExclusive, } from "../src/lib/native-compose-private-state.ts"; -import { runNativeComposeStorageDockerCommand } from "../src/lib/native-compose-storage-witness-docker.ts"; +import { + nativeComposeStorageCarrierReason, + runNativeComposeStorageDockerCommand, +} from "../src/lib/native-compose-storage-witness-docker.ts"; import { createNativeComposeStorageDockerEmptyLeaf, holdNativeComposeStorageDockerIo, @@ -242,3 +245,68 @@ test("fixed wrapper quota bounds capture growth and oversized output cannot be a await f.directory.file.close(); } }); + +/** + * Runs one unrecorded command (the path of every identity read) while its + * exited group answers `EPERM` to `kill(-group, 0)` for the first `eperm` + * probes, as macOS can just after the group's last member exits (HACK-1463). + * Every other signal and probe reaches the real `process.kill`. + */ +async function withGroupProbeEperm(eperm: number) { + const f = await fixture(); + const files = { + held: [f.directory], + path: f.root, + input: f.input, + inputInfo: f.inputInfo, + requestText: f.text, + captures: [] as { path: string; info: typeof f.inputInfo }[], + }; + const kill = process.kill.bind(process); + let answered = 0; + const probe = spyOn(process, "kill").mockImplementation((( + pid: number, + signal?: string | number + ) => { + if (pid < 0 && signal === 0 && answered < eperm) { + answered += 1; + throw Object.assign(new Error("synthetic EPERM"), { code: "EPERM" }); + } + return kill(pid, signal); + }) as typeof process.kill); + try { + const outcome = await runNativeComposeStorageDockerCommand({ + files, + context: { + signal: new AbortController().signal, + deadline: Date.now() + 10_000, + }, + args: ["/bin/echo", "synthetic"], + timeoutMs: 10_000, + beforeSpawn: () => undefined, + assertAdmitted: async () => undefined, + }).then( + (result) => ({ result, error: null as unknown }), + (error: unknown) => ({ result: null, error }) + ); + return { ...outcome, answered }; + } finally { + probe.mockRestore(); + await f.io.close(); + await f.directory.file.close(); + } +} +test("an exited command whose group briefly answers EPERM is awaited until it is absent", async () => { + const outcome = await withGroupProbeEperm(3); + expect(outcome.error).toBeNull(); + expect(outcome.answered).toBe(3); + expect(outcome.result).toEqual({ exitCode: 0, stdout: "synthetic\n" }); +}); +test("a group that keeps answering EPERM is never taken as absent and refuses at its budget", async () => { + const outcome = await withGroupProbeEperm(Number.POSITIVE_INFINITY); + expect(outcome.result).toBeNull(); + expect((outcome.error as Error).message).toContain("values omitted"); + expect(nativeComposeStorageCarrierReason(outcome.error)).toBe("probe-budget"); + // Probed every 20 ms across the fixed 3 s unrecorded group budget. + expect(outcome.answered).toBeGreaterThan(1); +});