From 30e71c9da4945d1ef7791510d7e08e82b69c5168 Mon Sep 17 00:00:00 2001 From: Dimitri Kennedy Date: Mon, 12 Oct 2026 13:52:39 -0400 Subject: [PATCH 1/3] perf(storage): reuse unchanged storage witness proofs across warm commands A warm, image-only, unrouted `up` or `restart` with no hooks now runs four directory-xattr storage proofs instead of six. Each proof is three fresh helper containers. - The warm enrollment tail (no new volume) reuses the effect-entry proof of the same generation under the same lease. It uses the existing adjacentProof record, which needs a byte-identical material binding, so any receipt write in between forces a full proof. - Finalization skips the second proof pass when there is no route, after hook, or new or saved file material. In that case the completion step only reads. Proof reuse stays within one command and one lease. Nothing is persisted, so every command still opens with a full proof. Each performed verification proof now emits a passive `storage.proof` phase-trace span. The hosted native-config-compose scenario uses it to assert four proofs on each of two consecutive warm ups. Refs: HACK-1123 Co-Authored-By: Claude Opus 5.5 --- docs/reference/native-compose-phase-trace.md | 7 +- .../native-compose-storage-witness.md | 35 ++++- src/lib/native-compose-command-storage.ts | 11 +- src/lib/native-compose-command.ts | 38 +++-- src/lib/native-compose-file-command.ts | 11 ++ src/lib/native-compose-phase-trace.ts | 1 + src/lib/native-compose-storage-witness.ts | 6 +- tests/e2e/scenarios/native-config-compose.ts | 62 ++++++++ tests/native-compose-phase-trace.test.ts | 10 +- ...compose-storage-activation-command.test.ts | 81 ++++++++-- .../native-compose-storage-fence-cost.test.ts | 11 +- ...ompose-storage-witness-xattr-owner.test.ts | 143 +++++++++++++++++- 12 files changed, 369 insertions(+), 47 deletions(-) diff --git a/docs/reference/native-compose-phase-trace.md b/docs/reference/native-compose-phase-trace.md index 7f1a68bdc..30a2850bf 100644 --- a/docs/reference/native-compose-phase-trace.md +++ b/docs/reference/native-compose-phase-trace.md @@ -33,7 +33,7 @@ environment values, subprocess output or exception text. The canonical call sites cover `oneoff.post-remove-owned`, `oneoff.post-remove-fresh`, `oneoff.post-remove-guard`, `storage.enroll`, -`guard.fresh-before`, `guard.ownership`, `guard.storage`, `guard.fresh-after`, +`storage.proof`, `guard.fresh-before`, `guard.ownership`, `guard.storage`, `guard.fresh-after`, `finish.pending`, `finish.witness-work`, and the finalization phases `finalize.fresh`, `finalize.generation`, `finalize.projection`, `finalize.owned`, `finalize.remember-storage`, `finalize.witnesses`, @@ -41,7 +41,10 @@ phases `finalize.fresh`, `finalize.generation`, `finalize.projection`, recheck repeats the phase with a new span. Conditional phases appear only when the existing command takes that path. `guard.storage` measures the ordinary storage verification await inside the workload ownership guard; `storage.enroll` measures -its preceding enrollment phase. Nested spans describe nested awaits, so their +its preceding enrollment phase. `storage.proof` measures one performed +directory-xattr verification kernel proof (three helper carriers) and nests inside +whichever phase requested it; a verification that reuses an adjacent proof under +the same lease emits no `storage.proof` span. Nested spans describe nested awaits, so their durations must not be added as independent CPU time. Output stops after 256 records or 64 KiB, or if the clock or sink fails. Diagnostic diff --git a/docs/reference/native-compose-storage-witness.md b/docs/reference/native-compose-storage-witness.md index 4476dc8c3..8146831af 100644 --- a/docs/reference/native-compose-storage-witness.md +++ b/docs/reference/native-compose-storage-witness.md @@ -103,15 +103,44 @@ projection, recovery or newly declared volume. A speculative ownership read can preview that merge but cannot publish it. A birth addition repeats the original fully fenced path. Each qualifying phase keeps a fresh closing kernel proof and exact source, generation and receipt-incarnation checks. No proof is reused across -pending publication or effects. Opening preparation, enrollment, pre-spawn and -both final receipt proofs remain separate. The one-volume offline counter is +pending publication or effects. The opening preparation proof and the +post-workload receipt proof remain separate. The one-volume offline counter is three full proofs before effect entry rather than five; it establishes call ordering and count, not CPU savings or atomic observation across the daemon and private filesystem. +Within one command and one mutation lease, a verification whose code since the +previous proof performed only reads may reuse that completed kernel proof. It +still runs every host check (anchors, expectation, completion and binding). It +skips the three helper carriers only when the engine, generation and reference +are the same and its opening material binding (receipt identity and hash, lease +token, checkout anchor and generation) is byte-identical to the binding that +opened and closed the recorded proof. A receipt publication in between, such as +pending intent, a storage birth or completion, changes that binding and forces a +full proof. A refused or failed verification clears the record. Nothing is +persisted: every later command or lease, including the first after an engine +restart, opens with a full proof. Callers claim adjacency from code structure, +never from timing: + +- the warm `up`/`restart` enrollment tail (no newly declared volume) reuses the + effect-entry proof of the same generation; a new volume seeds and proves in + full; +- the first pre-spawn guard of an `up`/`restart` without build, routing or file + material reuses the enrollment-tail record; +- saved `exec` reuses its opening proof before the process. Its closing proof + after the process stays fresh. + +Final receipt verification proves once after the workload when no route, after +hook, or new or saved file material needs a completion step. Otherwise it proves +again after that step. A warm image-only, unrouted `up` without hooks therefore +proves four times (opening, prepublication, effect-entry and post-workload) +rather than six. With `HACK_NATIVE_COMPOSE_PHASE_TRACE=1`, each performed +verification proof emits one `storage.proof` span; a reused proof emits none. +These counts establish call ordering and helper invocations, not wall time. + The one-off `run` path separately omits the enrollment-tail read that would immediately repeat its mandatory pre-spawn witness read. `up` and `restart` -keep that tail read. Cold enrollment still seeds once and verifies before +keep that tail read; when warm it is the adjacent reuse above. Cold enrollment still seeds once and verifies before publishing its enrolled reference. The one-volume cold-run control reaches the actual pre-spawn boundary after eleven helper calls rather than fourteen; it intercepts the workload there and does not qualify Docker execution or timing. diff --git a/src/lib/native-compose-command-storage.ts b/src/lib/native-compose-command-storage.ts index c9384e64c..ddcd7abc1 100644 --- a/src/lib/native-compose-command-storage.ts +++ b/src/lib/native-compose-command-storage.ts @@ -314,7 +314,16 @@ export async function prepareNativeComposeCommandStorage(opts: { // guard. Up and restart can arm other effects before that guard. if (operation !== "run") { stage = "storage-verify"; - await verify(generation); + // Warm enrollment (no new volume) performs only the read-only + // selection compare and cold-absence check above, after the + // effect-entry proof of this same generation under this lease. It + // may reuse that proof; a receipt write since then changes the + // material binding and forces a full proof. A new volume seeds and + // always proves in full. + await verify( + generation, + newVolumes.length === 0 ? { adjacentProof: true } : {} + ); } } catch (error) { retainNativeComposeEffectRefusal(error, { diff --git a/src/lib/native-compose-command.ts b/src/lib/native-compose-command.ts index 758d25dc9..02e674912 100644 --- a/src/lib/native-compose-command.ts +++ b/src/lib/native-compose-command.ts @@ -56,6 +56,7 @@ import { assertNativeComposeFileRunSupported, assertNativeComposeSavedFileEngines, type NativeComposeCommandFiles, + nativeComposeSavedFilesPresent, prepareNativeComposeCommandFiles, prepareNativeComposeSavedFileStop, retireNativeComposeSavedFiles, @@ -1653,21 +1654,30 @@ async function executePreparedGeneration(opts: { signal, }); }, - retireFiles: async () => { - await files?.assertReady(selection, generation); - await retireNativeComposeSavedFiles({ - mutation, - store, - saved: previous, - selection, - signal, - }); - }, + // Without new or saved file material the retirement only reads, so + // leaving it out lets finalization take its single proof pass when no + // route or after hook needs a completion step either. + ...(files !== null || nativeComposeSavedFilesPresent(previous) + ? { + retireFiles: async () => { + await files?.assertReady(selection, generation); + await retireNativeComposeSavedFiles({ + mutation, + store, + saved: previous, + selection, + signal, + }); + }, + } + : {}), }); - // Up/restart enrollment ends with a storage proof. With no build, routing or - // file material, the first pre-spawn guard follows it with only read-only - // source and ownership checks (arming is a no-op), so that guard may reuse the - // adjacent proof. Every later guard and finalization proof stays fresh. + // Up/restart enrollment ends with a storage proof (a warm enrollment reuses + // the effect-entry proof; a new volume proves in full). With no build, + // routing or file material, the first pre-spawn guard follows it with only + // read-only source and ownership checks (arming is a no-op), so that guard + // may reuse the adjacent proof. Every later guard and the post-workload + // finalization proof stay fresh. let adjacentGuardProof = (operation === "up" || operation === "restart") && builds.length === 0 && diff --git a/src/lib/native-compose-file-command.ts b/src/lib/native-compose-file-command.ts index 7368665a4..59e3c1b0d 100644 --- a/src/lib/native-compose-file-command.ts +++ b/src/lib/native-compose-file-command.ts @@ -463,6 +463,17 @@ export async function prepareNativeComposeCommandFiles(opts: { } } +/** Whether any saved generation carries file material that + * `retireNativeComposeSavedFiles` would retire. With none, that retirement + * performs only read-only document loads and no file or engine effect. */ +export function nativeComposeSavedFilesPresent( + saved: readonly Saved[] +): boolean { + return saved.some((selected) => + Object.hasOwn(selected.document, NATIVE_COMPOSE_FILES_EXTENSION) + ); +} + /** Saved cleanup acquires neither authored inputs nor credentials and never infers child reaping. */ export async function retireNativeComposeSavedFiles(opts: { readonly mutation: NativeComposeMutation; diff --git a/src/lib/native-compose-phase-trace.ts b/src/lib/native-compose-phase-trace.ts index 540f833b0..0bcebca28 100644 --- a/src/lib/native-compose-phase-trace.ts +++ b/src/lib/native-compose-phase-trace.ts @@ -7,6 +7,7 @@ const PHASES = [ "oneoff.post-remove-fresh", "oneoff.post-remove-guard", "storage.enroll", + "storage.proof", "guard.fresh-before", "guard.ownership", "guard.storage", diff --git a/src/lib/native-compose-storage-witness.ts b/src/lib/native-compose-storage-witness.ts index 7586eb73b..726307b07 100644 --- a/src/lib/native-compose-storage-witness.ts +++ b/src/lib/native-compose-storage-witness.ts @@ -18,6 +18,7 @@ import { publishNativeComposeStorageWitnessEnrollment, runNativeComposeMaterialAction, } from "./native-compose-generation.ts"; +import { measureNativeComposePhase } from "./native-compose-phase-trace.ts"; import { type HeldDirectory, holdDirectory, @@ -1274,10 +1275,11 @@ function takeLeaseProof(opts: { const recorded = proofs.get(key); proofs.delete(key); return { - /** Run the kernel proof unless an adjacent caller opens with the recorded binding. */ + /** Run the kernel proof unless an adjacent caller opens with the recorded + * binding. Only a performed proof emits the passive `storage.proof` span. */ async prove(opening: string, run: () => Promise): Promise { if (!(opts.adjacent && recorded === opening)) { - await run(); + await measureNativeComposePhase("storage.proof", run); } }, /** Record a completed proof only when its binding never moved. */ diff --git a/tests/e2e/scenarios/native-config-compose.ts b/tests/e2e/scenarios/native-config-compose.ts index e77445915..5c784551a 100644 --- a/tests/e2e/scenarios/native-config-compose.ts +++ b/tests/e2e/scenarios/native-config-compose.ts @@ -146,6 +146,36 @@ function object(text: string): Record { return value; } +/** + * Storage verification proof counts from one CLI's phase trace. Each performed + * kernel proof (three helper carriers) emits one `storage.proof` span; a proof + * reused within the command's lease emits none. + */ +function storageProofTrace(stderr: string): { + readonly proofs: number; + readonly unfinished: number; + readonly proofMs: number; + readonly finalizations: number; +} { + const rows = stderr + .split("\n") + .filter((line) => line.startsWith('{"diagnostic":"native-compose-phase",')) + .map((line) => object(line)); + const spans = (phase: string, boundary: string) => + rows.filter((row) => row.phase === phase && row.boundary === boundary); + const ended = spans("storage.proof", "end"); + return { + proofs: spans("storage.proof", "begin").length, + unfinished: spans("storage.proof", "begin").length - ended.length, + proofMs: ended.reduce( + (total, row) => + total + (typeof row.durationMs === "number" ? row.durationMs : 0), + 0 + ), + finalizations: spans("finalize.witnesses", "begin").length, + }; +} + function shellQuote(value: string): string { return `'${value.replaceAll("'", "'\\''")}'`; } @@ -1280,6 +1310,38 @@ export const nativeConfigComposeScenario: Scenario = { await checkSql(marker); await Bun.write(projectPath, projectText); await cli(["up", "--detach", "--json"]); + // HACK-1123: two consecutive unchanged warm ups each prove storage four + // times (opening, prepublication, effect-entry, post-workload); the + // enrollment tail and first guard reuse the effect-entry proof, and with + // no route, hook or file material finalization proves once. + const warmUps: (ReturnType & { + readonly totalMs: number; + })[] = []; + for (const attempt of [1, 2]) { + const warm = await raw(["up", "--detach", "--json"], { + HACK_NATIVE_COMPOSE_PHASE_TRACE: "1", + }); + expectExit({ + result: warm, + codes: [0], + message: `Traced unchanged warm up ${attempt} must succeed`, + }); + warmUps.push({ + ...storageProofTrace(warm.stderr), + totalMs: Math.round(warm.durationMs), + }); + } + ctx.log(`warm up storage proofs: ${JSON.stringify(warmUps)}`); + expect({ + that: warmUps.every( + (warm) => + warm.proofs === 4 && + warm.unfinished === 0 && + warm.finalizations === 1 + ), + message: + "Unchanged warm up must perform exactly four storage proofs and one finalization witness check", + }); const beforeRestart = await snapshot(); const beforeRestartBoot = await probe("exec", marker); stage("owned workload removal/rename and retained SQL data verified"); diff --git a/tests/native-compose-phase-trace.test.ts b/tests/native-compose-phase-trace.test.ts index a34785627..85dd53b73 100644 --- a/tests/native-compose-phase-trace.test.ts +++ b/tests/native-compose-phase-trace.test.ts @@ -339,14 +339,8 @@ test( "finalize.witnesses", "finalize.pending", "finalize.pending-check", - "finalize.before-complete", - "finalize.fresh", - "finalize.generation", - "finalize.owned", - "finalize.remember-storage", - "finalize.witnesses", - "finalize.pending", - "finalize.pending-check", + // No route, after hook or file material: no completion step, so no + // second finalization pass. "finalize.save", ]); expect(rows.every((row, index) => row.sequence === index + 1)).toBe(true); diff --git a/tests/native-compose-storage-activation-command.test.ts b/tests/native-compose-storage-activation-command.test.ts index e7c5fae6d..131162a95 100644 --- a/tests/native-compose-storage-activation-command.test.ts +++ b/tests/native-compose-storage-activation-command.test.ts @@ -382,11 +382,13 @@ test("public down recover completes only removed readonly original work and next }, 500_000); // One proof is root, verify and root-after through three fresh helper carriers. -// Warm up/restart keep the opening, both effect-phase, enrollment and both -// finalization proofs; only the first pre-spawn guard reuses the adjacent -// enrollment proof (no build, routing or file material). Saved exec keeps its -// opening proof, reuses it for the adjacent pre-spawn check and proves again -// after the process. A cold up seeds once and keeps every later proof. +// Warm up/restart keep the opening and both effect-phase proofs. The warm +// enrollment tail (no new volume) and then the first pre-spawn guard (no build, +// routing or file material) reuse the adjacent effect-entry proof. With no +// route, after hook or file material, finalization keeps one fresh +// post-workload proof. Saved exec keeps its opening proof, reuses it for the +// adjacent pre-spawn check and proves again after the process. A cold up seeds +// once and proves its new volume in full. Consecutive warm ups cost the same. test( "source CLI helper invocations per command keep every non-adjacent proof", async () => @@ -414,12 +416,17 @@ test( "seed", ...proofs(3), "workload", - ...proofs(2), + ...proofs(1), + ]); + expect(await counted(["up", "--detach", "--json"])).toEqual([ + ...proofs(3), + "workload", + ...proofs(1), ]); expect(await counted(["up", "--detach", "--json"])).toEqual([ - ...proofs(4), + ...proofs(3), "workload", - ...proofs(2), + ...proofs(1), ]); expect(await counted(["exec", "web", "--", "true"])).toEqual([ ...proofs(1), @@ -427,9 +434,9 @@ test( ...proofs(1), ]); expect(await counted(["restart", "--json"])).toEqual([ - ...proofs(4), + ...proofs(3), "workload", - ...proofs(2), + ...proofs(1), ]); expect( (await operations(root)).filter((op) => op === "seed") @@ -438,3 +445,57 @@ test( }), 390_000 ); + +// Negative control for the single finalization pass: an after hook is a host +// effect between readiness and the ready receipt, so its effect phases keep +// their proofs and finalization keeps its second fresh proof after the +// completion step. The eight post-workload proofs equal the count before +// proof reuse; only the warm enrollment tail drops (six to five before the +// workload). +test( + "source CLI warm up with an after hook keeps both finalization proofs", + async () => + await ownedColdCase(async (owner) => { + const root = await fixture("", false, { + storage, + hooks: { + up: { + after: [ + { + name: "after", + command: { exec: [process.execPath, "-e", "0"] }, + }, + ], + }, + }, + cleanupAllowed: owner.cleanupAllowed, + }); + const eventsFile = join(root, "storage-events"); + const events = async () => + (await Bun.file(eventsFile).exists()) + ? (await Bun.file(eventsFile).text()).trim().split("\n") + : []; + const counted = async (args: readonly string[]) => { + const before = (await events()).length; + const result = await owner.invoke(root, args); + expect(result.code, await disposition(root, result.code)).toBe(0); + return (await events()).slice(before); + }; + const proofs = (count: number) => + Array.from({ length: count }, () => ["root", "verify", "root"]).flat(); + expect(await counted(["up", "--detach", "--json"])).toEqual([ + "root", + "seed", + ...proofs(3), + "workload", + ...proofs(8), + ]); + expect(await counted(["up", "--detach", "--json"])).toEqual([ + ...proofs(5), + "workload", + ...proofs(8), + ]); + expect(await Bun.file(join(root, "carriers")).json()).toEqual([]); + }), + 390_000 +); diff --git a/tests/native-compose-storage-fence-cost.test.ts b/tests/native-compose-storage-fence-cost.test.ts index c0322ce87..7d641d7d4 100644 --- a/tests/native-compose-storage-fence-cost.test.ts +++ b/tests/native-compose-storage-fence-cost.test.ts @@ -152,11 +152,14 @@ test("storage fence count per command: every proof kept, exact duplicates gone, direct: 0, observations: 2 * PROOF_OBSERVATIONS, }); + // Warm up proves four times: opening, prepublication, effect-entry (reused + // by the enrollment tail and first guard) and one post-workload finalization. + // A reused proof makes no engine fence or target observation. expect(await counted(root, ["up", "--detach", "--json"])).toEqual({ code: 0, - cli: FILE_ENGINE_FENCES + 6 * PROOF_FENCES, + cli: FILE_ENGINE_FENCES + 4 * PROOF_FENCES, direct: 0, - observations: 6 * PROOF_OBSERVATIONS, + observations: 4 * PROOF_OBSERVATIONS, }); // Admitted Unix selection: the same fences, one fresh read each. Only the // first storage fence is a CLI read, checked against one extra direct read. @@ -170,8 +173,8 @@ test("storage fence count per command: every proof kept, exact duplicates gone, expect(await counted(root, ["up", "--detach", "--json"], selected)).toEqual({ code: 0, cli: FILE_ENGINE_FENCES + 1, - direct: 6 * PROOF_FENCES, - observations: 6 * PROOF_OBSERVATIONS, + direct: 4 * PROOF_FENCES, + observations: 4 * PROOF_OBSERVATIONS, }); // Admitted context selection (DOCKER_HOST unset; the client config's current // context names the socket): the same counts as an explicit Unix host. diff --git a/tests/native-compose-storage-witness-xattr-owner.test.ts b/tests/native-compose-storage-witness-xattr-owner.test.ts index 2cb45c0bc..8c1dd21f3 100644 --- a/tests/native-compose-storage-witness-xattr-owner.test.ts +++ b/tests/native-compose-storage-witness-xattr-owner.test.ts @@ -663,7 +663,7 @@ test("completion publication refusal retains its first boundary after complete h test.each([ "up", "restart", -] as const)("warm no-op %s keeps opening, two closing and all later witness proofs", async (operation) => { +] as const)("warm no-op %s reuses the effect-entry proof for enrollment and keeps every other proof", async (operation) => { const { store, transport } = await rememberedActive(); const command = commandPorts(transport); let finalizers = 0; @@ -697,7 +697,7 @@ test.each([ finalizers++; expect( transport.calls.filter((call) => call === "verify") - ).toHaveLength(6); + ).toHaveLength(5); }, effect: async () => { expect(owned).toBe(2); @@ -710,8 +710,17 @@ test.each([ expect((await store.loadCurrent()).pending?.generationId).toBe( generation.generationId ); + // Warm enrollment (no new volume) reuses the effect-entry proof of + // this generation: only read-only checks ran since it. await storage.enroll(generation, document); + expect( + transport.calls.filter((call) => call === "verify") + ).toHaveLength(3); + // An ordinary (non-adjacent) verification always proves in full. await storage.verify(generation); + expect( + transport.calls.filter((call) => call === "verify") + ).toHaveLength(4); transport.calls.push("workload"); return { value: 0, outcome: "complete" }; }, @@ -719,12 +728,140 @@ test.each([ expect(result).toEqual({ value: 0, outcome: "complete" }); }); expect(finalizers).toBe(1); - expect(transport.calls.filter((call) => call === "verify")).toHaveLength(7); + expect(transport.calls.filter((call) => call === "verify")).toHaveLength(6); expect(transport.calls).not.toContain("seed"); expect(transport.calls).not.toContain("provision"); expect((await store.loadCurrent()).pending).toBeNull(); }, 30_000); +test("warm enrollment proves in full when the material binding moved since the effect-entry proof", async () => { + const { store, transport } = await rememberedActive(); + const command = commandPorts(transport); + const original = generationOwner.assertNativeComposeMaterialAuthority; + let moved = false; + // Stand-in for a receipt publication (for example a storage birth) between + // the effect-entry proof and the enrollment tail: the next opening binding + // carries a different receipt hash than the one the lease recorded. + const authority = spyOn( + generationOwner, + "assertNativeComposeMaterialAuthority" + ).mockImplementation(async (input) => { + const binding = await original(input); + if (moved) { + moved = false; + return { + ...binding, + receipt: { ...binding.receipt, hash: "0".repeat(64) }, + }; + } + return binding; + }); + try { + await store.withMutation(async (mutation) => { + const storage = await prepareNativeComposeCommandStorage({ + store, + mutation, + operation: "up", + selected: [selection], + signal: transport.controller.signal, + ports: command.ports, + }); + if (!storage) { + throw new Error("Expected retained storage"); + } + const generation = await publish(mutation); + transport.state.generation = generation; + const document = await store.readGenerationDocument(generation); + await mutation.runEffect({ + generation, + operation: "up", + assertFresh: async () => {}, + assertOwned: async () => {}, + captureStorage: () => [volume], + storageWitnesses: storage.effectWitnesses, + effect: async () => { + expect(helperOperations(transport)).toHaveLength(9); + moved = true; + await storage.enroll(generation, document); + expect(moved).toBe(false); + expect(helperOperations(transport)).toHaveLength(12); + transport.calls.push("workload"); + return { value: 0, outcome: "complete" }; + }, + }); + }); + } finally { + authority.mockRestore(); + } + expect(transport.calls).toContain("workload"); + expect(transport.calls).not.toContain("seed"); +}, 30_000); + +test("an adjacent verification never reuses a proof across a receipt publication or a later lease", async () => { + const { store, transport, generation, reference } = await rememberedActive(); + const command = commandPorts(transport); + const proofs = () => + transport.calls.filter((call) => call === "verify").length; + await store.withMutation(async (mutation) => { + const storage = await prepareNativeComposeCommandStorage({ + store, + mutation, + operation: "up", + selected: [selection], + signal: transport.controller.signal, + ports: command.ports, + }); + if (!storage) { + throw new Error("Expected retained storage"); + } + expect(proofs()).toBe(1); + // Positive control: only reads since the opening proof. + await storage.verify(generation, { adjacentProof: true }); + expect(proofs()).toBe(1); + // The effect publishes pending and then the completed receipt. Its last + // recorded proof precedes that completion publication. + const result = await mutation.runEffect({ + generation, + operation: "up", + assertFresh: async () => {}, + assertOwned: async () => {}, + captureStorage: () => [volume], + storageWitnesses: storage.effectWitnesses, + effect: async () => ({ value: 0, outcome: "complete" }), + }); + expect(result.outcome).toBe("complete"); + const published = proofs(); + await storage.verify(generation, { adjacentProof: true }); + expect(proofs()).toBe(published + 1); + }); + // A later command holds a new lease (as after an engine restart): nothing + // recorded in the previous one is visible, so an adjacent claim still proves. + await store.withMutation(async (mutation) => { + const before = proofs(); + await verifyNativeComposeStorageXattrWitness({ + authority: mutation.materialAuthority, + generation, + engineId, + reference, + carrier: transport.carrier, + adjacentProof: true, + }); + expect(proofs()).toBe(before + 1); + // A different engine never matches the recorded proof or the binding. + await expect( + verifyNativeComposeStorageXattrWitness({ + authority: mutation.materialAuthority, + generation, + engineId: "e".repeat(64), + reference, + carrier: transport.carrier, + adjacentProof: true, + }) + ).rejects.toThrow(witnessRefusal); + expect(proofs()).toBe(before + 1); + }); +}, 30_000); + test.each( (["prepublication", "effect-entry"] as const).flatMap((phase) => (["ownership", "source-await"] as const).map((boundary) => ({ From 0853a134a369fc7c9cee24c35b368c0ae645bd86 Mon Sep 17 00:00:00 2001 From: Dimitri Kennedy Date: Mon, 12 Oct 2026 14:20:34 -0400 Subject: [PATCH 2/3] ci: keep the Bun crash loop inside its budget and default to the focused file The HACK-1211 experiment produced two iterations per Bun version: one focused pass and one full `bun test` that started on a 600 s estimate and overran the 30-minute budget, because the full suite takes 30-35 minutes on hosted macOS. - Never start an iteration whose estimate exceeds the remaining budget. The estimate is a conservative prior (focused 120 s, full 2400 s) until a run completes, then the longest completed run times 1.2. A command that does not fit is recorded once in summary.json `skippedForBudget` and leaves the rotation. Deadline stops remain a safety net (`overrun`). - Add `--mode=focused|full|alternate` (default focused: only tests/native-https-owner.test.ts) and `--role=baseline|candidate`. - The workflow gains a validated `mode` dispatch input; the label-triggered matched pair uses focused with baseline/candidate roles. Full mode needs a budget of at least 40 minutes. The job timeout stays budget + 15. - summary.json gains per-command counts (iterations, passes, crashes, other failures, overruns, skipped-for-budget) and a one-line verdict such as "baseline 0/97 focused crashes". - The shared classifier also treats exit 134 (SIGABRT) and 138 (SIGBUS) as crash exits. Co-Authored-By: Claude Opus 5.5 --- .ai/skills/hack-repo-verify/SKILL.md | 2 +- .github/workflows/bun-crash-experiment.yml | 58 ++- scripts/bun-crash-loop.ts | 429 +++++++++++++++----- scripts/lib/bun-crash-classify.ts | 9 +- tests/bun-crash-loop.test.ts | 449 +++++++++++++++++---- 5 files changed, 739 insertions(+), 208 deletions(-) diff --git a/.ai/skills/hack-repo-verify/SKILL.md b/.ai/skills/hack-repo-verify/SKILL.md index 39a1657d3..4b01408db 100644 --- a/.ai/skills/hack-repo-verify/SKILL.md +++ b/.ai/skills/hack-repo-verify/SKILL.md @@ -70,7 +70,7 @@ untracked candidate additions. Keep private artifacts excluded from the index. | Native authored command slices | `tests/native-authored-command.test.ts` (unsupported matrix), `tests/native-authored-command-dispatch.test.ts`, `tests/native-authored-project-{start,run,observe,logs,exec,recovery}.test.ts` and the [command contract](../../../docs/reference/native-authored-commands.md); the dispatch "source CLI" cases need the prepared compiler (`bun run build:config-compiler` or absolute `HACK_CONFIG_COMPILER_BINARY`) and fail without it; `native-authored-project-start` and `native-authored-project-exec` are nondeterministic on a local macOS host, so a single local pass or failure is not proof; live acceptance runs host-serialized on one prepared macOS provider slot | | Native VM/routing/reclamation | [candidate guide](../../../docs/guides/native-candidate.md), relevant acceptance gate and isolated host fixture; Linux checks cannot qualify macOS effects | | Resource/performance claims | [performance skill](../hack-repo-performance/SKILL.md), matched workload and measured boundaries | -| Bun runtime crashes | Read-only history: `bun run ci:bun-crash-census -- --since --until ` (failed `test` job logs; `--scan-passing` for all). Matched reproduction: the gated [experiment](../../../.github/workflows/bun-crash-experiment.yml), which spends hosted macOS minutes and needs an explicit go-ahead; never loop on a shared host. Both share [the classifier](../../../scripts/lib/bun-crash-classify.ts) | +| Bun runtime crashes | Read-only history: `bun run ci:bun-crash-census -- --since --until ` (failed `test` job logs; `--scan-passing` for all). Matched reproduction: the gated [experiment](../../../.github/workflows/bun-crash-experiment.yml), which spends hosted macOS minutes and needs an explicit go-ahead; never loop on a shared host. Its default `focused` mode loops `tests/native-https-owner.test.ts` (where both original segfaults happened); `full` needs a budget of at least 40 minutes because one full suite takes 30-35. A run never starts unless its estimate fits the remaining budget, so read `summary.json` for the verdict and per-mode crash, failure and skipped-for-budget counts. Both share [the classifier](../../../scripts/lib/bun-crash-classify.ts) | Read [CI](../../../.github/workflows/ci.yml) for current hosted gates. A local pass does not mean CI ran. Existing unsupported remote/gateway/native-app checks are diff --git a/.github/workflows/bun-crash-experiment.yml b/.github/workflows/bun-crash-experiment.yml index 170bd2e11..6802c92b4 100644 --- a/.github/workflows/bun-crash-experiment.yml +++ b/.github/workflows/bun-crash-experiment.yml @@ -8,8 +8,15 @@ name: Bun crash experiment # go-ahead. # # A labeled pull request runs the matched pair on the pull request's head: the -# 1.3.9 baseline and the 1.4.2 candidate pinned on next, with the same job and -# budget. A dispatch runs one Bun version at a chosen source revision. +# 1.3.9 baseline and the 1.4.2 candidate pinned on next, with the same job, +# budget and the default `focused` mode. A dispatch runs one Bun version at a +# chosen source revision and mode. +# +# Modes: `focused` loops tests/native-https-owner.test.ts, the file in which both +# original segfaults happened (about 16 s per run); `full` loops the full +# `bun test` (about 30-35 min per run on hosted macOS); `alternate` alternates +# the two. The loop never starts a run whose estimate exceeds the remaining +# budget; it records the command as skipped for budget instead. on: workflow_dispatch: inputs: @@ -22,9 +29,17 @@ on: type: string default: "" budget_minutes: - description: Loop budget in minutes (5-240); the job timeout is budget + 15 + description: Loop budget in minutes (5-240; full mode needs at least 40); the job timeout is budget + 15 type: number default: 30 + mode: + description: focused loops the owner test file, full loops the full suite, alternate alternates them + type: choice + options: + - focused + - full + - alternate + default: focused pull_request: types: [labeled] @@ -46,7 +61,8 @@ jobs: permissions: contents: read outputs: - bun_versions: ${{ steps.plan.outputs.bun_versions }} + runs: ${{ steps.plan.outputs.runs }} + mode: ${{ steps.plan.outputs.mode }} source_revision: ${{ steps.plan.outputs.source_revision }} budget_seconds: ${{ steps.plan.outputs.budget_seconds }} timeout_minutes: ${{ steps.plan.outputs.timeout_minutes }} @@ -58,6 +74,7 @@ jobs: INPUT_BUN_VERSION: ${{ inputs.bun_version }} INPUT_SOURCE_REVISION: ${{ inputs.source_revision }} INPUT_BUDGET_MINUTES: ${{ inputs.budget_minutes }} + INPUT_MODE: ${{ inputs.mode }} PR_HEAD_SHA: ${{ github.event.pull_request.head.sha }} EVENT_SHA: ${{ github.sha }} run: | @@ -67,13 +84,15 @@ jobs: echo "Invalid bun_version" exit 1 fi - versions="[\"$INPUT_BUN_VERSION\"]" + runs="[{\"bun_version\":\"$INPUT_BUN_VERSION\",\"role\":\"\"}]" revision="${INPUT_SOURCE_REVISION:-$EVENT_SHA}" budget="$INPUT_BUDGET_MINUTES" + mode="$INPUT_MODE" else - versions='["1.3.9","1.4.2"]' + runs='[{"bun_version":"1.3.9","role":"baseline"},{"bun_version":"1.4.2","role":"candidate"}]' revision="$PR_HEAD_SHA" budget=30 + mode=focused fi if ! [[ "$revision" =~ ^[0-9a-f]{40}$ ]]; then echo "Invalid source_revision" @@ -83,20 +102,35 @@ jobs: echo "Invalid budget_minutes" exit 1 fi + case "$mode" in + focused | full | alternate) ;; + *) + echo "Invalid mode" + exit 1 + ;; + esac + # The loop's full-suite prior is 40 minutes (DEFAULT_FULL_ESTIMATE_SECONDS + # in scripts/bun-crash-loop.ts); a smaller full-mode budget could never + # start a run and would only spend hosted macOS minutes on setup. + if [ "$mode" = "full" ] && [ "$budget" -lt 40 ]; then + echo "full mode needs budget_minutes of at least 40" + exit 1 + fi { - echo "bun_versions=$versions" + echo "runs=$runs" + echo "mode=$mode" echo "source_revision=$revision" echo "budget_seconds=$((budget * 60))" echo "timeout_minutes=$((budget + 15))" } >> "$GITHUB_OUTPUT" loop: - name: Bun crash loop (${{ matrix.bun_version }}) + name: Bun crash loop (${{ matrix.bun_version }}, ${{ needs.plan.outputs.mode }}) needs: plan strategy: fail-fast: false matrix: - bun_version: ${{ fromJSON(needs.plan.outputs.bun_versions) }} + include: ${{ fromJSON(needs.plan.outputs.runs) }} runs-on: blacksmith-6vcpu-macos-15 timeout-minutes: ${{ fromJSON(needs.plan.outputs.timeout_minutes) }} permissions: @@ -144,15 +178,19 @@ jobs: else echo "Source revision has no test preflight" fi - - name: Loop the owner test and the full suite within the budget + - name: Loop the selected tests within the budget env: BUN_ENABLE_CRASH_REPORTING: "0" EXPECTED_BUN_VERSION: ${{ matrix.bun_version }} SOURCE_REVISION: ${{ needs.plan.outputs.source_revision }} BUDGET_SECONDS: ${{ needs.plan.outputs.budget_seconds }} + LOOP_MODE: ${{ needs.plan.outputs.mode }} + LOOP_ROLE: ${{ matrix.role }} run: >- bun "$RUNNER_TEMP/bun-crash-instrument/scripts/bun-crash-loop.ts" --budget-seconds="$BUDGET_SECONDS" + --mode="$LOOP_MODE" + ${LOOP_ROLE:+"--role=$LOOP_ROLE"} --expect-bun-version="$EXPECTED_BUN_VERSION" --source-revision="$SOURCE_REVISION" --out-dir="$RUNNER_TEMP/bun-crash-loop" diff --git a/scripts/bun-crash-loop.ts b/scripts/bun-crash-loop.ts index 220aa1d21..a8e9a1581 100644 --- a/scripts/bun-crash-loop.ts +++ b/scripts/bun-crash-loop.ts @@ -2,14 +2,26 @@ /** * Fixed-budget Bun crash loop for the gated `bun-crash-experiment` workflow. * - * It alternates `bun test tests/native-https-owner.test.ts` with the full - * `bun test`, classifies every run with the shared classifier, keeps each run's - * log, and writes a closed, value-free summary. + * Modes: + * - `focused` (default) loops `bun test tests/native-https-owner.test.ts`, the file + * in which both original segfaults happened; + * - `full` loops the full `bun test`; + * - `alternate` alternates the two. + * Every run is classified with the shared classifier and keeps its own log, and + * the loop writes a closed, value-free summary with per-command counts and a + * one-line verdict. * - * Budget invariant: an iteration starts only when its estimated duration (the - * larger of its initial estimate and its longest observed run) ends at or before - * the deadline. An iteration that is still running at the deadline is stopped and - * recorded as `overrun`, never as a crash, unless its log carries the crash banner. + * Budget invariant: an iteration starts only when its estimated duration ends at + * or before the deadline. Until a command has completed a run, its estimate is a + * conservative prior; afterwards it is the longest completed run of that command + * times {@link ESTIMATE_HEADROOM}. A command whose estimate does not fit is + * recorded once as skipped for budget and leaves the rotation: its estimate cannot + * change without a run and the remaining budget only shrinks, so it could never + * fit again. The loop ends when every command has been skipped. + * + * A run still going at the deadline (an estimate that was too small) is stopped + * and recorded as `overrun`, never as a crash, unless its log carries the crash + * banner. With honest estimates this does not happen; the stop is a safety net. * * The loop never opens or fetches crash-report links. It sets * `BUN_ENABLE_CRASH_REPORTING=0` so Bun does not upload a report itself; the logs @@ -39,6 +51,19 @@ import { export type LoopCommandId = "focused" | "full"; +/** Which commands the loop runs: one file, the full suite, or both in turn. */ +export type LoopMode = "focused" | "full" | "alternate"; + +export const LOOP_MODES: readonly LoopMode[] = ["focused", "full", "alternate"]; +export const DEFAULT_LOOP_MODE: LoopMode = "focused"; + +/** Closed labels for the matched pair; a dispatched run has none. */ +export type LoopRole = "baseline" | "candidate"; +const LOOP_ROLES: readonly LoopRole[] = ["baseline", "candidate"]; + +/** The test file in which both original segfaults happened. */ +export const FOCUSED_TEST_FILE = "tests/native-https-owner.test.ts"; + export interface LoopCommand { readonly id: LoopCommandId; readonly argv: readonly string[]; @@ -66,15 +91,35 @@ export interface IterationRecord { readonly durationMs: number; } +/** A command the loop did not start because its estimate exceeded the remaining budget. */ +export interface SkippedForBudget { + readonly command: LoopCommandId; + readonly reason: "budget"; + /** Loop time at which the skip was decided. */ + readonly atMs: number; + readonly remainingMs: number; + readonly estimateMs: number; +} + export interface LoopResult { readonly budgetMs: number; readonly elapsedMs: number; + /** The configured commands, in rotation order. */ + readonly commands: readonly LoopCommandId[]; readonly iterations: readonly IterationRecord[]; - readonly estimatesMs: Readonly>; + readonly skippedForBudget: readonly SkippedForBudget[]; + /** The estimate each command had when the loop ended. */ + readonly estimatesMs: Readonly>>; } export const DEFAULT_FOCUSED_ESTIMATE_SECONDS = 120; -export const DEFAULT_FULL_ESTIMATE_SECONDS = 600; +/** + * The full CLI suite takes about 30 to 35 minutes on hosted macOS, so the prior + * is 40 minutes. The workflow's full-mode budget floor mirrors this value. + */ +export const DEFAULT_FULL_ESTIMATE_SECONDS = 2400; +/** Multiplier on the longest completed run, to absorb run-to-run variance. */ +export const ESTIMATE_HEADROOM = 1.2; const MIN_BUDGET_SECONDS = 60; const MAX_BUDGET_SECONDS = 6 * 60 * 60; const KILL_GRACE_MS = 10_000; @@ -85,50 +130,75 @@ export class LoopError extends Error {} export function loopCommands(opts: { readonly bunExecutable: string; + readonly mode: LoopMode; readonly focusedEstimateSeconds: number; readonly fullEstimateSeconds: number; }): readonly LoopCommand[] { - return [ - { - id: "focused", - argv: [opts.bunExecutable, "test", "tests/native-https-owner.test.ts"], - initialEstimateMs: opts.focusedEstimateSeconds * 1000, - }, - { - id: "full", - argv: [opts.bunExecutable, "test"], - initialEstimateMs: opts.fullEstimateSeconds * 1000, - }, - ]; + const focused: LoopCommand = { + id: "focused", + argv: [opts.bunExecutable, "test", FOCUSED_TEST_FILE], + initialEstimateMs: opts.focusedEstimateSeconds * 1000, + }; + const full: LoopCommand = { + id: "full", + argv: [opts.bunExecutable, "test"], + initialEstimateMs: opts.fullEstimateSeconds * 1000, + }; + switch (opts.mode) { + case "focused": + return [focused]; + case "full": + return [full]; + case "alternate": + return [focused, full]; + default: + throw new LoopError("Invalid mode"); + } +} + +/** + * The estimate for the next start of a command: its conservative prior until a + * run completes, then the longest completed run times {@link ESTIMATE_HEADROOM}. + */ +export function nextEstimateMs(opts: { + readonly priorMs: number; + readonly longestCompletedMs: number | null; +}): number { + return opts.longestCompletedMs === null + ? opts.priorMs + : Math.ceil(opts.longestCompletedMs * ESTIMATE_HEADROOM); } /** - * Picks the next command, or null when none can finish by the deadline. - * The command at `cursor` is preferred; when it does not fit, the next command in - * sequence order that fits runs instead. Equality with the deadline fits. + * Decides the next step for the active rotation: run the command at `cursor` + * when it ends at or before the deadline, otherwise skip it for budget. Equality + * with the deadline fits; nothing fits once the deadline is reached. + * Returns null when no command is left. */ -export function planNextCommand(opts: { +export function planNextIteration(opts: { readonly nowMs: number; readonly deadlineMs: number; - readonly commands: readonly LoopCommand[]; + readonly active: readonly LoopCommand[]; readonly cursor: number; - readonly estimatesMs: Readonly>; -}): { readonly command: LoopCommand; readonly cursor: number } | null { - const count = opts.commands.length; - if (count === 0 || opts.nowMs >= opts.deadlineMs) { + readonly estimatesMs: Readonly>>; +}): { + readonly action: "run" | "skip"; + readonly command: LoopCommand; + readonly position: number; +} | null { + const count = opts.active.length; + if (count === 0) { return null; } - const preferred = ((opts.cursor % count) + count) % count; - for (let offset = 0; offset < count; offset += 1) { - const command = opts.commands[(preferred + offset) % count]; - if ( - command !== undefined && - opts.nowMs + opts.estimatesMs[command.id] <= opts.deadlineMs - ) { - return { command, cursor: preferred + 1 }; - } + const position = ((opts.cursor % count) + count) % count; + const command = opts.active[position]; + if (command === undefined) { + return null; } - return null; + const estimate = opts.estimatesMs[command.id] ?? command.initialEstimateMs; + const fits = + opts.nowMs < opts.deadlineMs && opts.nowMs + estimate <= opts.deadlineMs; + return { action: fits ? "run" : "skip", command, position }; } function classifyIteration(run: ExecutedRun): { @@ -143,7 +213,7 @@ function classifyIteration(run: ExecutedRun): { return classifyBunRun(run); } -/** Runs commands until none can finish within the budget. */ +/** Runs commands until every command has been skipped for budget. */ export async function runBunCrashLoop(opts: { readonly budgetMs: number; readonly commands: readonly LoopCommand[]; @@ -153,36 +223,62 @@ export async function runBunCrashLoop(opts: { context: { readonly index: number; readonly deadlineMs: number } ) => Promise; readonly onIteration?: (record: IterationRecord) => void; + readonly onSkip?: (skip: SkippedForBudget) => void; }): Promise { const startMs = opts.now(); const deadlineMs = startMs + opts.budgetMs; - const estimatesMs = {} as Record; + const estimatesMs: Partial> = {}; + const longestCompletedMs: Partial> = {}; for (const command of opts.commands) { estimatesMs[command.id] = command.initialEstimateMs; } + const active = [...opts.commands]; const iterations: IterationRecord[] = []; + const skippedForBudget: SkippedForBudget[] = []; let cursor = 0; for (;;) { - const next = planNextCommand({ - nowMs: opts.now(), + const nowMs = opts.now(); + const next = planNextIteration({ + nowMs, deadlineMs, - commands: opts.commands, + active, cursor, estimatesMs, }); if (next === null) { break; } - cursor = next.cursor; + if (next.action === "skip") { + const skip: SkippedForBudget = { + command: next.command.id, + reason: "budget", + atMs: Math.max(0, nowMs - startMs), + remainingMs: Math.max(0, deadlineMs - nowMs), + estimateMs: estimatesMs[next.command.id] ?? 0, + }; + skippedForBudget.push(skip); + opts.onSkip?.(skip); + // The command after the skipped one moves into its position. + active.splice(next.position, 1); + cursor = next.position; + continue; + } + cursor = next.position + 1; const index = iterations.length + 1; - const started = opts.now(); const run = await opts.execute(next.command, { index, deadlineMs }); - const durationMs = Math.max(0, opts.now() - started); - estimatesMs[next.command.id] = Math.max( - estimatesMs[next.command.id], - durationMs - ); + const durationMs = Math.max(0, opts.now() - nowMs); const { outcome, reason } = classifyIteration(run); + if (!run.stoppedAtDeadline) { + const longest = Math.max( + longestCompletedMs[next.command.id] ?? 0, + durationMs + ); + longestCompletedMs[next.command.id] = longest; + estimatesMs[next.command.id] = nextEstimateMs({ + priorMs: next.command.initialEstimateMs, + longestCompletedMs: longest, + }); + } const record: IterationRecord = { index, command: next.command.id, @@ -201,32 +297,114 @@ export async function runBunCrashLoop(opts: { return { budgetMs: opts.budgetMs, elapsedMs: Math.max(0, opts.now() - startMs), + commands: opts.commands.map((command) => command.id), iterations, + skippedForBudget, estimatesMs, }; } -const OUTCOMES: readonly IterationOutcome[] = [ - "pass", - "failure", - "crash", - "overrun", -]; - -export function summarizeIterations( - iterations: readonly IterationRecord[] -): Record> { - const empty = (): Record => ({ - pass: 0, - failure: 0, - crash: 0, - overrun: 0, +/** Per-command counts. `failures` are non-crash failures. */ +export interface CommandCounts { + iterations: number; + passes: number; + crashes: number; + failures: number; + overruns: number; + skippedForBudget: number; +} + +/** Counts for each configured command, in rotation order. */ +export function countIterations( + result: Pick +): Partial> { + const counts: Partial> = {}; + for (const id of result.commands) { + counts[id] = { + iterations: 0, + passes: 0, + crashes: 0, + failures: 0, + overruns: 0, + skippedForBudget: 0, + }; + } + const outcomeField = { + pass: "passes", + crash: "crashes", + failure: "failures", + overrun: "overruns", + } as const satisfies Record; + for (const record of result.iterations) { + const row = counts[record.command]; + if (row !== undefined) { + row.iterations += 1; + row[outcomeField[record.outcome]] += 1; + } + } + for (const skip of result.skippedForBudget) { + const row = counts[skip.command]; + if (row !== undefined) { + row.skippedForBudget += 1; + } + } + return counts; +} + +/** + * One closed line, for example `baseline 0/97 focused crashes` or + * `Bun 1.4.2 0/40 focused crashes, 0/1 full crashes`. + */ +export function renderVerdict(opts: { + readonly result: Pick< + LoopResult, + "commands" | "iterations" | "skippedForBudget" + >; + readonly role: LoopRole | null; + readonly bunVersion: string | null; +}): string { + const counts = countIterations(opts.result); + const subject = opts.role ?? `Bun ${opts.bunVersion ?? "unknown"}`; + const parts = opts.result.commands.map((id) => { + const row = counts[id]; + return `${row?.crashes ?? 0}/${row?.iterations ?? 0} ${id} crashes`; }); - const totals = { focused: empty(), full: empty() }; - for (const record of iterations) { - totals[record.command][record.outcome] += 1; + const overruns = opts.result.commands.reduce( + (sum, id) => sum + (counts[id]?.overruns ?? 0), + 0 + ); + let verdict = `${subject} ${parts.join(", ")}`; + if (opts.result.iterations.length === 0) { + verdict += "; no iteration fit the budget"; + } else if (overruns > 0) { + verdict += `; ${overruns} overrun`; } - return totals; + return verdict; +} + +/** The closed, value-free `summary.json` document. */ +export function buildLoopSummary(opts: { + readonly result: LoopResult; + readonly mode: LoopMode; + readonly role: LoopRole | null; + readonly bunVersion: string | null; + readonly sourceRevision: string | null; + readonly diagnosticReports: number; +}) { + return { + verdict: renderVerdict(opts), + bunVersion: opts.bunVersion, + role: opts.role, + mode: opts.mode, + sourceRevision: opts.sourceRevision, + diagnosticReports: opts.diagnosticReports, + budgetMs: opts.result.budgetMs, + elapsedMs: opts.result.elapsedMs, + counts: countIterations(opts.result), + estimatesMs: opts.result.estimatesMs, + skippedForBudget: opts.result.skippedForBudget, + iterations: opts.result.iterations, + }; } const seconds = (ms: number): string => (ms / 1000).toFixed(1); @@ -234,31 +412,36 @@ const seconds = (ms: number): string => (ms / 1000).toFixed(1); /** Markdown for `$GITHUB_STEP_SUMMARY`. Only closed tokens, numbers and validated identifiers. */ export function renderLoopSummary(opts: { readonly result: LoopResult; + readonly mode: LoopMode; + readonly role: LoopRole | null; readonly bunVersion: string | null; readonly sourceRevision: string | null; readonly diagnosticReports: number; }): string { - const totals = summarizeIterations(opts.result.iterations); + const counts = countIterations(opts.result); const lines = [ "## Bun crash experiment", "", + `Verdict: ${renderVerdict(opts)}`, + "", "| Field | Value |", "| --- | --- |", `| Bun | ${opts.bunVersion ?? "unknown"} |`, + `| Role | ${opts.role ?? "-"} |`, + `| Mode | ${opts.mode} |`, `| Source revision | ${opts.sourceRevision ?? "unknown"} |`, `| Budget seconds | ${seconds(opts.result.budgetMs)} |`, `| Loop seconds | ${seconds(opts.result.elapsedMs)} |`, `| Iterations | ${opts.result.iterations.length} |`, `| Crash reports (bun*.ips) | ${opts.diagnosticReports} |`, "", - "| Command | Runs | Pass | Failure | Crash | Overrun | Estimate seconds |", - "| --- | --- | --- | --- | --- | --- | --- |", + "| Command | Runs | Pass | Crash | Other failure | Overrun | Skipped for budget | Estimate seconds |", + "| --- | --- | --- | --- | --- | --- | --- | --- |", ]; - for (const id of ["focused", "full"] as const) { - const row = totals[id]; - const runs = OUTCOMES.reduce((sum, outcome) => sum + row[outcome], 0); + for (const id of opts.result.commands) { + const row = counts[id]; lines.push( - `| ${id} | ${runs} | ${row.pass} | ${row.failure} | ${row.crash} | ${row.overrun} | ${seconds(opts.result.estimatesMs[id] ?? 0)} |` + `| ${id} | ${row?.iterations ?? 0} | ${row?.passes ?? 0} | ${row?.crashes ?? 0} | ${row?.failures ?? 0} | ${row?.overruns ?? 0} | ${row?.skippedForBudget ?? 0} | ${seconds(opts.result.estimatesMs[id] ?? 0)} |` ); } lines.push( @@ -271,6 +454,11 @@ export function renderLoopSummary(opts: { `| ${record.index} | ${record.command} | ${record.outcome} | ${record.reason} | ${record.exitCode ?? "-"} | ${record.signal ?? "-"} | ${seconds(record.durationMs)} |` ); } + for (const skip of opts.result.skippedForBudget) { + lines.push( + `| - | ${skip.command} | skipped | budget | - | - | ${seconds(skip.estimateMs)} estimated, ${seconds(skip.remainingMs)} left |` + ); + } lines.push( "", "Logs and crash reports are in the run artifact. Crash-report links are never opened.", @@ -366,6 +554,8 @@ export function executeWithLog(opts: { export interface LoopArguments { readonly budgetSeconds: number; readonly outDir: string; + readonly mode: LoopMode; + readonly role: LoopRole | null; readonly expectBunVersion: string | null; readonly sourceRevision: string | null; readonly focusedEstimateSeconds: number; @@ -383,28 +573,49 @@ function parseSeconds(name: string, value: string, min: number, max: number) { return parsed; } -export function parseLoopArguments(argv: readonly string[]): LoopArguments { +function parseClosed( + name: string, + value: string, + allowed: readonly T[] +): T { + const match = allowed.find((candidate) => candidate === value); + if (match === undefined) { + throw new LoopError(`Invalid ${name}`); + } + return match; +} + +const KNOWN_FLAGS: ReadonlySet = new Set([ + "budget-seconds", + "out-dir", + "mode", + "role", + "expect-bun-version", + "source-revision", + "focused-estimate-seconds", + "full-estimate-seconds", +]); + +/** `--name=value` flags; unknown, malformed or repeated flags are rejected. */ +function readFlags(argv: readonly string[]): ReadonlyMap { const values = new Map(); for (const arg of argv) { const match = /^--([a-z-]+)=(.*)$/.exec(arg); - if (!match?.[1] || match[2] === undefined || values.has(match[1])) { + if ( + !match?.[1] || + match[2] === undefined || + values.has(match[1]) || + !KNOWN_FLAGS.has(match[1]) + ) { throw new LoopError("Invalid argument"); } values.set(match[1], match[2]); } - const known = new Set([ - "budget-seconds", - "out-dir", - "expect-bun-version", - "source-revision", - "focused-estimate-seconds", - "full-estimate-seconds", - ]); - for (const key of values.keys()) { - if (!known.has(key)) { - throw new LoopError("Invalid argument"); - } - } + return values; +} + +export function parseLoopArguments(argv: readonly string[]): LoopArguments { + const values = readFlags(argv); const budget = values.get("budget-seconds"); if (budget === undefined) { throw new LoopError("Missing --budget-seconds"); @@ -421,6 +632,7 @@ export function parseLoopArguments(argv: readonly string[]): LoopArguments { if (outDir !== undefined && outDir.length === 0) { throw new LoopError("Invalid --out-dir"); } + const role = values.get("role"); return { budgetSeconds: parseSeconds( "--budget-seconds", @@ -429,6 +641,12 @@ export function parseLoopArguments(argv: readonly string[]): LoopArguments { MAX_BUDGET_SECONDS ), outDir: resolve(outDir ?? join(tmpdir(), "bun-crash-loop")), + mode: parseClosed( + "--mode", + values.get("mode") ?? DEFAULT_LOOP_MODE, + LOOP_MODES + ), + role: role === undefined ? null : parseClosed("--role", role, LOOP_ROLES), expectBunVersion: expect ?? null, sourceRevision: revision ?? null, focusedEstimateSeconds: parseSeconds( @@ -461,6 +679,7 @@ async function main(): Promise { budgetMs: args.budgetSeconds * 1000, commands: loopCommands({ bunExecutable: process.execPath, + mode: args.mode, focusedEstimateSeconds: args.focusedEstimateSeconds, fullEstimateSeconds: args.fullEstimateSeconds, }), @@ -471,37 +690,37 @@ async function main(): Promise { `iteration=${record.index} command=${record.command} outcome=${record.outcome} reason=${record.reason} seconds=${seconds(record.durationMs)}\n` ); }, + onSkip: (skip) => { + process.stdout.write( + `skipped command=${skip.command} reason=${skip.reason} estimate_seconds=${seconds(skip.estimateMs)} remaining_seconds=${seconds(skip.remainingMs)}\n` + ); + }, }); const diagnosticReports = await collectDiagnosticReports({ source: join(homedir(), "Library", "Logs", "DiagnosticReports"), destination: join(args.outDir, "diagnostic-reports"), sinceMs: loopStartMs, }); - const summary = renderLoopSummary({ + const report = { result, + mode: args.mode, + role: args.role, bunVersion, sourceRevision: args.sourceRevision, diagnosticReports, - }); + }; await Bun.write( join(args.outDir, "summary.json"), - `${JSON.stringify( - { - bunVersion, - sourceRevision: args.sourceRevision, - diagnosticReports, - ...result, - }, - null, - 2 - )}\n` + `${JSON.stringify(buildLoopSummary(report), null, 2)}\n` ); + const summary = renderLoopSummary(report); const stepSummary = process.env.GITHUB_STEP_SUMMARY; if (stepSummary) { await appendFile(stepSummary, summary); } else { process.stdout.write(summary); } + process.stdout.write(`verdict: ${renderVerdict(report)}\n`); if (result.iterations.length === 0) { throw new LoopError("No iteration fits the budget"); } diff --git a/scripts/lib/bun-crash-classify.ts b/scripts/lib/bun-crash-classify.ts index 443176811..0e4134fac 100644 --- a/scripts/lib/bun-crash-classify.ts +++ b/scripts/lib/bun-crash-classify.ts @@ -9,8 +9,11 @@ * crash-report links or values) is ever returned. */ -/** Exit statuses a shell reports for Bun's crash signals: SIGTRAP (133) and SIGSEGV (139). */ -export const BUN_CRASH_EXIT_CODES: readonly number[] = [133, 139]; +/** + * Exit statuses a shell reports for Bun's crash signals: SIGTRAP (133), SIGABRT + * (134), SIGBUS (138) and SIGSEGV (139). + */ +export const BUN_CRASH_EXIT_CODES: readonly number[] = [133, 134, 138, 139]; export type BunRunOutcome = "crash" | "failure" | "pass"; @@ -19,7 +22,7 @@ export type BunRunReason = | "banner" /** The process was ended by a signal it did not get from the harness. */ | "signal" - /** The exit status encodes a crash signal (133 or 139). */ + /** The exit status encodes a crash signal (133, 134, 138 or 139). */ | "signal_exit" /** Exit 0 and no crash banner. */ | "exit_zero" diff --git a/tests/bun-crash-loop.test.ts b/tests/bun-crash-loop.test.ts index e7a3ff683..ba3ef6ad3 100644 --- a/tests/bun-crash-loop.test.ts +++ b/tests/bun-crash-loop.test.ts @@ -3,14 +3,18 @@ import { mkdtemp, readdir, rm, utimes, writeFile } from "node:fs/promises"; import { homedir, tmpdir } from "node:os"; import { join } from "node:path"; import { + buildLoopSummary, collectDiagnosticReports, + countIterations, type ExecutedRun, executeWithLog, type LoopCommand, loopCommands, + nextEstimateMs, parseLoopArguments, - planNextCommand, + planNextIteration, renderLoopSummary, + renderVerdict, runBunCrashLoop, } from "../scripts/bun-crash-loop.ts"; import { @@ -51,8 +55,8 @@ describe("classifyBunRun", () => { ).toEqual({ outcome: "crash", reason: "banner" }); }); - test("exit 133 or 139 without a banner is a signal crash", () => { - for (const exitCode of [133, 139]) { + test("a trap, abort, bus-error or segfault exit status without a banner is a signal crash", () => { + for (const exitCode of [133, 134, 138, 139]) { expect(classifyBunRun({ exitCode, signal: null, output: "" })).toEqual({ outcome: "crash", reason: "signal_exit", @@ -148,78 +152,188 @@ const commands: readonly LoopCommand[] = [ { id: "full", argv: ["full"], initialEstimateMs: 300_000 }, ]; -describe("planNextCommand deadline arithmetic", () => { +const PASS: ExecutedRun = { + exitCode: 0, + signal: null, + output: " 3 pass\n 0 fail\n", + stoppedAtDeadline: false, +}; + +/** + * An injected executor on an injected clock. A run that would end past the + * deadline is stopped at the deadline, as the real executor does, so starting an + * iteration that cannot fit shows up as an overrun. + */ +function simulatedExecutor(opts: { + readonly clock: { now: number }; + readonly durationMs: (command: LoopCommand) => number; + readonly run?: (command: LoopCommand, index: number) => ExecutedRun; + readonly starts?: { id: string; at: number; argv: readonly string[] }[]; +}) { + return async ( + command: LoopCommand, + context: { readonly index: number; readonly deadlineMs: number } + ): Promise => { + opts.starts?.push({ + id: command.id, + at: opts.clock.now, + argv: command.argv, + }); + const end = opts.clock.now + opts.durationMs(command); + if (end > context.deadlineMs) { + opts.clock.now = context.deadlineMs; + return { + exitCode: null, + signal: "SIGTERM", + output: "", + stoppedAtDeadline: true, + }; + } + opts.clock.now = end; + return opts.run?.(command, context.index) ?? PASS; + }; +} + +describe("planNextIteration deadline arithmetic", () => { const estimatesMs = { focused: 100_000, full: 300_000 }; test("a command that ends exactly at the deadline may start", () => { expect( - planNextCommand({ + planNextIteration({ nowMs: 700_000, deadlineMs: 1_000_000, - commands, + active: commands, cursor: 1, estimatesMs, - })?.command.id - ).toBe("full"); - }); - - test("a command that would end past the deadline falls back to one that fits", () => { - const next = planNextCommand({ - nowMs: 700_001, - deadlineMs: 1_000_000, - commands, - cursor: 1, - estimatesMs, - }); - expect(next?.command.id).toBe("focused"); - expect(next?.cursor).toBe(2); + }) + ).toMatchObject({ action: "run", position: 1, command: { id: "full" } }); }); - test("nothing starts when no command fits or the deadline has passed", () => { + test("a command that would end past the deadline is skipped, not started", () => { expect( - planNextCommand({ - nowMs: 900_001, + planNextIteration({ + nowMs: 700_001, deadlineMs: 1_000_000, - commands, - cursor: 0, + active: commands, + cursor: 1, estimatesMs, }) - ).toBeNull(); + ).toMatchObject({ action: "skip", position: 1, command: { id: "full" } }); + }); + + test("nothing starts once the deadline is reached, and an empty rotation ends", () => { expect( - planNextCommand({ + planNextIteration({ nowMs: 1_000_000, deadlineMs: 1_000_000, - commands, + active: commands, cursor: 0, estimatesMs: { focused: 0, full: 0 }, + })?.action + ).toBe("skip"); + expect( + planNextIteration({ + nowMs: 0, + deadlineMs: 1_000_000, + active: [], + cursor: 0, + estimatesMs, }) ).toBeNull(); }); + + test("the estimate is the prior until a run completes, then the longest run with headroom", () => { + expect( + nextEstimateMs({ priorMs: 2_400_000, longestCompletedMs: null }) + ).toBe(2_400_000); + expect( + nextEstimateMs({ priorMs: 120_000, longestCompletedMs: 16_500 }) + ).toBe(19_800); + }); }); describe("runBunCrashLoop", () => { - test("no iteration starts past the budget and estimates grow to observed durations", async () => { - let clock = 0; - const durations = { focused: 90_000, full: 500_000 }; - const starts: { id: string; at: number }[] = []; + test("a 30-minute alternating budget never starts the 35-minute suite and records the skip", async () => { + // The hosted shape: focused ~16.5 s, full suite ~35 min, 30-minute budget. + const clock = { now: 0 }; + const starts: { id: string; at: number; argv: readonly string[] }[] = []; + const budgetMs = 1_800_000; + const result = await runBunCrashLoop({ + budgetMs, + commands: loopCommands({ + bunExecutable: "/bin/bun", + mode: "alternate", + focusedEstimateSeconds: 120, + fullEstimateSeconds: 2400, + }), + now: () => clock.now, + execute: simulatedExecutor({ + clock, + starts, + durationMs: (command) => (command.id === "full" ? 2_100_000 : 16_500), + }), + }); + expect(starts.some((start) => start.id === "full")).toBe(false); + expect(starts).toHaveLength(108); + for (const start of starts) { + expect(start.at + 16_500).toBeLessThanOrEqual(budgetMs); + } + expect(result.iterations.every((record) => record.outcome === "pass")).toBe( + true + ); + expect(result.skippedForBudget).toEqual([ + { + command: "full", + reason: "budget", + atMs: 16_500, + remainingMs: 1_783_500, + estimateMs: 2_400_000, + }, + { + command: "focused", + reason: "budget", + atMs: 1_782_000, + remainingMs: 18_000, + estimateMs: 19_800, + }, + ]); + expect(countIterations(result)).toEqual({ + focused: { + iterations: 108, + passes: 108, + crashes: 0, + failures: 0, + overruns: 0, + skippedForBudget: 1, + }, + full: { + iterations: 0, + passes: 0, + crashes: 0, + failures: 0, + overruns: 0, + skippedForBudget: 1, + }, + }); + }); + + test("estimates follow measured durations and no start overruns the deadline", async () => { + const clock = { now: 0 }; + const starts: { id: string; at: number; argv: readonly string[] }[] = []; const result = await runBunCrashLoop({ budgetMs: 1_000_000, commands, - now: () => clock, - execute: async (command) => { - starts.push({ id: command.id, at: clock }); - clock += durations[command.id]; - return { - exitCode: 0, - signal: null, - output: "", - stoppedAtDeadline: false, - }; - }, + now: () => clock.now, + execute: simulatedExecutor({ + clock, + starts, + durationMs: (command) => (command.id === "full" ? 500_000 : 90_000), + }), }); - // After the full suite takes 500 s, its estimate is 500 s and it no longer - // fits; focused runs (estimate 100 s) continue until 950 s + 100 s > 1000 s. - expect(starts).toEqual([ + // The full suite fits its 300 s prior once; measured at 500 s (600 s with + // headroom) it no longer fits at 680 s and leaves the rotation. Focused runs + // (108 s estimate after the first) continue until 950 s + 108 s > 1000 s. + expect(starts.map(({ id, at }) => ({ id, at }))).toEqual([ { id: "focused", at: 0 }, { id: "full", at: 90_000 }, { id: "focused", at: 590_000 }, @@ -227,16 +341,141 @@ describe("runBunCrashLoop", () => { { id: "focused", at: 770_000 }, { id: "focused", at: 860_000 }, ]); - for (const start of starts) { - const estimate = start.id === "full" ? 300_000 : 100_000; - expect(start.at + estimate).toBeLessThanOrEqual(1_000_000); - } - expect(result.estimatesMs).toEqual({ focused: 100_000, full: 500_000 }); + expect(result.estimatesMs).toEqual({ focused: 108_000, full: 600_000 }); + expect( + result.skippedForBudget.map(({ command, atMs }) => [command, atMs]) + ).toEqual([ + ["full", 680_000], + ["focused", 950_000], + ]); expect(result.iterations.map((record) => record.outcome)).toEqual( new Array(6).fill("pass") ); }); + test("focused mode only ever runs the owner test file", async () => { + const clock = { now: 0 }; + const starts: { id: string; at: number; argv: readonly string[] }[] = []; + const result = await runBunCrashLoop({ + budgetMs: 600_000, + commands: loopCommands({ + bunExecutable: "/bin/bun", + mode: "focused", + focusedEstimateSeconds: 120, + fullEstimateSeconds: 2400, + }), + now: () => clock.now, + execute: simulatedExecutor({ clock, starts, durationMs: () => 20_000 }), + }); + expect(starts.length).toBeGreaterThan(20); + for (const start of starts) { + expect(start.argv).toEqual([ + "/bin/bun", + "test", + "tests/native-https-owner.test.ts", + ]); + } + expect(result.commands).toEqual(["focused"]); + expect(Object.keys(countIterations(result))).toEqual(["focused"]); + expect(result.skippedForBudget.map((skip) => skip.command)).toEqual([ + "focused", + ]); + }); + + test("full mode with a budget below the prior starts nothing and says so", async () => { + const clock = { now: 0 }; + const starts: { id: string; at: number; argv: readonly string[] }[] = []; + const result = await runBunCrashLoop({ + budgetMs: 1_800_000, + commands: loopCommands({ + bunExecutable: "/bin/bun", + mode: "full", + focusedEstimateSeconds: 120, + fullEstimateSeconds: 2400, + }), + now: () => clock.now, + execute: simulatedExecutor({ clock, starts, durationMs: () => 1 }), + }); + expect(starts).toEqual([]); + expect(result.skippedForBudget).toHaveLength(1); + expect( + renderVerdict({ result, role: "candidate", bunVersion: "1.4.2" }) + ).toBe("candidate 0/0 full crashes; no iteration fit the budget"); + }); + + test("injected crashes count as crashes, other non-zero exits as other failures", async () => { + const clock = { now: 0 }; + const injected: ExecutedRun[] = [ + PASS, + // Bun's own banner, whatever the exit status. + { + exitCode: 0, + signal: null, + output: CRASH_TRANSCRIPT, + stoppedAtDeadline: false, + }, + // Signal deaths as Bun.spawn reports them; no real process gets a signal. + { + exitCode: null, + signal: "SIGSEGV", + output: "", + stoppedAtDeadline: false, + }, + { + exitCode: null, + signal: "SIGBUS", + output: "", + stoppedAtDeadline: false, + }, + // Shell-style abort exit status without a banner. + { exitCode: 134, signal: null, output: "", stoppedAtDeadline: false }, + { + exitCode: 1, + signal: null, + output: "(fail) owner starts [5.00ms]\n 3 pass\n 1 fail\n", + stoppedAtDeadline: false, + }, + { exitCode: 2, signal: null, output: "", stoppedAtDeadline: false }, + ]; + const result = await runBunCrashLoop({ + budgetMs: 200_000, + commands: [commands[0] as LoopCommand], + now: () => clock.now, + execute: simulatedExecutor({ + clock, + durationMs: () => 10_000, + run: (_command, index) => injected[index - 1] ?? PASS, + }), + }); + expect( + result.iterations + .slice(0, 7) + .map((record) => [record.outcome, record.reason]) + ).toEqual([ + ["pass", "exit_zero"], + ["crash", "banner"], + ["crash", "signal"], + ["crash", "signal"], + ["crash", "signal_exit"], + ["failure", "test_failure"], + ["failure", "exit_code"], + ]); + // 10 s runs, 12 s estimate after the first: starts at 0..180 s, then 190 s + 12 s > 200 s. + expect(countIterations(result)).toEqual({ + focused: { + iterations: 19, + passes: 13, + crashes: 4, + failures: 2, + overruns: 0, + skippedForBudget: 1, + }, + }); + expect( + renderVerdict({ result, role: "baseline", bunVersion: "1.3.9" }) + ).toBe("baseline 4/19 focused crashes"); + }); + test("a run stopped at the deadline is an overrun unless it printed the crash banner", async () => { let clock = 0; const runs: ExecutedRun[] = [ @@ -254,21 +493,15 @@ describe("runBunCrashLoop", () => { }, ]; const result = await runBunCrashLoop({ - budgetMs: 1_000_000, + budgetMs: 250_000, commands: [commands[0] as LoopCommand], now: () => clock, execute: async () => { clock += 100_000; - return ( - runs.shift() ?? { - exitCode: 0, - signal: null, - output: "", - stoppedAtDeadline: false, - } - ); + return runs.shift() ?? PASS; }, }); + expect(result.iterations).toHaveLength(2); expect(result.iterations[0]).toMatchObject({ outcome: "overrun", reason: "deadline", @@ -278,6 +511,12 @@ describe("runBunCrashLoop", () => { outcome: "crash", reason: "banner", }); + // A stopped run is not a measured duration, so the prior stays in force. + expect(result.estimatesMs.focused).toBe(100_000); + expect(countIterations(result).focused?.overruns).toBe(1); + expect(renderVerdict({ result, role: null, bunVersion: "1.3.9" })).toBe( + "Bun 1.3.9 1/2 focused crashes; 1 overrun" + ); }); test("a signal death from the executor is recorded as a crash with its closed signal name", async () => { @@ -303,19 +542,12 @@ describe("runBunCrashLoop", () => { }, ]; const result = await runBunCrashLoop({ - budgetMs: 300_000, + budgetMs: 400_000, commands: [commands[0] as LoopCommand], now: () => clock, execute: async () => { clock += 100_000; - return ( - runs.shift() ?? { - exitCode: 0, - signal: null, - output: "", - stoppedAtDeadline: false, - } - ); + return runs.shift() ?? PASS; }, }); expect( @@ -332,7 +564,7 @@ describe("runBunCrashLoop", () => { ]); }); - test("the summary is closed and value-free", async () => { + test("the summaries are closed and value-free", async () => { let clock = 0; const result = await runBunCrashLoop({ budgetMs: 250_000, @@ -348,17 +580,37 @@ describe("runBunCrashLoop", () => { }; }, }); - const summary = renderLoopSummary({ + const report = { result, + mode: "alternate" as const, + role: null, bunVersion: "1.3.9", sourceRevision: "2b8057c1ae6f4311150b6e139a9a919bbc7788d4", diagnosticReports: 1, - }); - expect(summary).toContain("| focused | 2 | 0 | 0 | 2 | 0 |"); + }; + const summary = renderLoopSummary(report); + expect(summary).toContain( + "Verdict: Bun 1.3.9 2/2 focused crashes, 0/0 full crashes" + ); + expect(summary).toContain("| focused | 2 | 0 | 2 | 0 | 0 | 1 | 120.0 |"); + expect(summary).toContain("| full | 0 | 0 | 0 | 0 | 0 | 1 | 300.0 |"); expect(summary).toContain("| 1 | focused | crash | banner | 133 | - |"); - expect(summary).not.toContain("do-not-print"); - expect(summary).not.toContain("bun.report"); - expect(summary).not.toContain("native-https-owner"); + expect(summary).toContain("| - | full | skipped | budget |"); + const json = JSON.stringify(buildLoopSummary(report)); + expect(JSON.parse(json)).toMatchObject({ + verdict: "Bun 1.3.9 2/2 focused crashes, 0/0 full crashes", + mode: "alternate", + role: null, + counts: { + focused: { iterations: 2, crashes: 2, skippedForBudget: 1 }, + full: { iterations: 0, skippedForBudget: 1 }, + }, + }); + for (const text of [summary, json]) { + expect(text).not.toContain("do-not-print"); + expect(text).not.toContain("bun.report"); + expect(text).not.toContain("native-https-owner"); + } }); }); @@ -434,21 +686,27 @@ describe("executeWithLog", () => { }); }); -test("loop commands run the focused owner test and then the full suite", () => { - expect( +test("each mode selects its commands, and focused is the owner test file alone", () => { + const ids = (mode: "focused" | "full" | "alternate") => loopCommands({ bunExecutable: "/bin/bun", + mode, focusedEstimateSeconds: 60, - fullEstimateSeconds: 600, - }).map((command) => [command.id, command.argv, command.initialEstimateMs]) - ).toEqual([ - [ - "focused", - ["/bin/bun", "test", "tests/native-https-owner.test.ts"], - 60_000, - ], - ["full", ["/bin/bun", "test"], 600_000], - ]); + fullEstimateSeconds: 2400, + }).map((command): unknown[] => [ + command.id, + command.argv, + command.initialEstimateMs, + ]); + const focused = [ + "focused", + ["/bin/bun", "test", "tests/native-https-owner.test.ts"], + 60_000, + ]; + const full = ["full", ["/bin/bun", "test"], 2_400_000]; + expect(ids("focused")).toEqual([focused]); + expect(ids("full")).toEqual([full]); + expect(ids("alternate")).toEqual([focused, full]); }); test("loop arguments are validated and closed", () => { @@ -462,10 +720,19 @@ test("loop arguments are validated and closed", () => { ).toMatchObject({ budgetSeconds: 1800, outDir: "/tmp/x", + mode: "focused", + role: null, expectBunVersion: "1.3.9", focusedEstimateSeconds: 120, - fullEstimateSeconds: 600, + fullEstimateSeconds: 2400, }); + expect( + parseLoopArguments([ + "--budget-seconds=1800", + "--mode=alternate", + "--role=baseline", + ]) + ).toMatchObject({ mode: "alternate", role: "baseline" }); for (const argv of [ [], ["--budget-seconds=10"], @@ -474,6 +741,10 @@ test("loop arguments are validated and closed", () => { ["--budget-seconds=1800", "--unknown=1"], ["--budget-seconds=1800", "--expect-bun-version=latest"], ["--budget-seconds=1800", "--source-revision=main"], + ["--budget-seconds=1800", "--mode=both"], + ["--budget-seconds=1800", "--mode="], + ["--budget-seconds=1800", "--role=dispatch"], + ["--budget-seconds=1800", "--role="], ]) { expect(() => parseLoopArguments(argv)).toThrow(); } From 255b7af12ff869f320d472514a7929ca56703100 Mon Sep 17 00:00:00 2001 From: Dimitri Kennedy Date: Mon, 12 Oct 2026 16:04:30 -0400 Subject: [PATCH 3/3] test(storage): pin first file up finalization and isolate harness HOME Add a source CLI regression for a first up with new file material and no saved file material: finalization keeps its completion step, the second finalize pass, and the post-completion file-mount readiness check. The test fails when the retirement condition keeps only the saved-files arm. Native-compose CLI harnesses now give the child a private HOME under the fixture root instead of the contributor's HOME. Co-Authored-By: Claude Opus 5.5 --- tests/helpers/native-compose-command.ts | 4 +- tests/helpers/native-compose-files.ts | 14 +++-- tests/native-compose-file-command.test.ts | 53 +++++++++++++++++++ ...compose-storage-activation-command.test.ts | 3 +- 4 files changed, 68 insertions(+), 6 deletions(-) diff --git a/tests/helpers/native-compose-command.ts b/tests/helpers/native-compose-command.ts index b928ec72e..2d5c39329 100644 --- a/tests/helpers/native-compose-command.ts +++ b/tests/helpers/native-compose-command.ts @@ -55,6 +55,8 @@ export async function fixture( cleanupGuards.set(root, opts.cleanupAllowed); } await mkdir(join(root, ".hack")); + // Private HOME for child CLIs; the contributor's home is never selected. + await mkdir(join(root, "user-home"), { mode: 0o700 }); await Bun.write( join(root, ".hack/hack.project.json"), JSON.stringify({ @@ -246,7 +248,7 @@ export async function invoke( { cwd: root, env: { - HOME: process.env.HOME, + HOME: join(root, "user-home"), LANG: "C", PATH: `${root}:/usr/bin:/bin`, HACK_HOME: join(root, "home"), diff --git a/tests/helpers/native-compose-files.ts b/tests/helpers/native-compose-files.ts index 76f015624..957b07662 100644 --- a/tests/helpers/native-compose-files.ts +++ b/tests/helpers/native-compose-files.ts @@ -70,6 +70,8 @@ export async function fileCommandFixture(source: unknown = FILE_SOURCE) { const root = join(parent, "checkout"); await mkdir(join(root, ".hack"), { recursive: true }); await mkdir(join(parent, "home"), { mode: 0o700 }); + // Private HOME for child CLIs; the contributor's home is never selected. + await mkdir(join(parent, "user-home"), { mode: 0o700 }); await Bun.write( join(root, ".hack/hack.project.json"), JSON.stringify(source) @@ -152,7 +154,9 @@ await fail(); } export function spawnFiles( fixture: { readonly parent: string; readonly root: string }, - args = ["up", "--detach", "--json"] + args = ["up", "--detach", "--json"], + /** Diagnostics only, such as the passive phase trace. */ + extraEnv: Readonly> = {} ) { const child = Bun.spawn( [ @@ -165,7 +169,7 @@ export function spawnFiles( { cwd: fixture.root, env: { - HOME: process.env.HOME, + HOME: join(fixture.parent, "user-home"), LANG: "C", PATH: `${fixture.parent}:/usr/bin:/bin`, HACK_HOME: join(fixture.parent, "home"), @@ -176,6 +180,7 @@ export function spawnFiles( HACK_COMPOSE_STARTUP_TIMEOUT_MS: "3000", CI: "1", HACK_EXECUTION_MODE: "non_interactive", + ...extraEnv, }, stdin: "ignore", stdout: "pipe", @@ -187,9 +192,10 @@ export function spawnFiles( } export async function invokeFiles( fixture: { readonly parent: string; readonly root: string }, - args = ["up", "--detach", "--json"] + args = ["up", "--detach", "--json"], + extraEnv: Readonly> = {} ) { - const child = spawnFiles(fixture, args); + const child = spawnFiles(fixture, args, extraEnv); const timer = setTimeout(() => child.kill("SIGKILL"), 45_000); try { const [code, stdout, stderr] = await Promise.all([ diff --git a/tests/native-compose-file-command.test.ts b/tests/native-compose-file-command.test.ts index 87057b2e5..9196a2356 100644 --- a/tests/native-compose-file-command.test.ts +++ b/tests/native-compose-file-command.test.ts @@ -166,6 +166,59 @@ test("source CLI delivers actual acquired binary, managed and empty files with e expect(await fileJournal(ready.document)).toContain('"phase":"retired"'); await assertFileTransport(fixture); }, 120_000); +// Finalization may take its single proof pass only when the file retirement +// step would merely read. A first up has new file material and no saved file +// material: its completion step must still run, so the post-completion +// ownership pass re-observes the exact file mounts (files.assertReady) and the +// second finalize witness pass follows it. +test("first file up without saved file material keeps the completion step, post-completion file check and second finalize pass", async () => { + const fixture = await fileCommandFixture(); + const up = await invokeFiles(fixture, undefined, { + HACK_NATIVE_COMPOSE_PHASE_TRACE: "1", + }); + expect(up.code).toBe(0); + const phases = up.stderr + .split("\n") + .filter((line) => line.startsWith('{"diagnostic":"native-compose-phase",')) + .map((line) => JSON.parse(line) as { phase: string; boundary: string }) + .filter((row) => row.boundary === "begin") + .map((row) => row.phase); + const pass = [ + "finalize.fresh", + "finalize.generation", + "finalize.owned", + "finalize.remember-storage", + "finalize.witnesses", + "finalize.pending", + "finalize.pending-check", + ]; + expect(phases.slice(phases.indexOf("finalize.fresh"))).toEqual([ + ...pass, + "finalize.before-complete", + ...pass, + "finalize.save", + ]); + // Exact file-mount observations after the engine start: workload readiness, + // the first finalize pass's unbound-root check, the completion step's + // readiness check and the post-completion ownership pass's readiness check. + // Without the completion step only the first two remain. + const requests = await assertFileTransport(fixture); + const started = requests.findIndex((args) => args[0] === "compose"); + expect(started).toBeGreaterThanOrEqual(0); + expect( + requests + .slice(started) + .filter( + (args) => + args[0] === "container" && + args[1] === "inspect" && + String(args[3]).includes('"mounts":{{json .Mounts}}') + ) + ).toHaveLength(4); + const ready = await fileCommandState(fixture.root); + expect(ready.pending).toBeNull(); + expect(ready.current.stopped).toBe(false); +}, 120_000); test("unchanged authored file up acquires new bytes and retires its prior snapshot instead of reusing a warm generation", async () => { const fixture = await fileCommandFixture(); expect((await invokeFiles(fixture)).code).toBe(0); diff --git a/tests/native-compose-storage-activation-command.test.ts b/tests/native-compose-storage-activation-command.test.ts index 131162a95..e44bc003c 100644 --- a/tests/native-compose-storage-activation-command.test.ts +++ b/tests/native-compose-storage-activation-command.test.ts @@ -71,7 +71,8 @@ async function ownedColdCase( ], cwd: root, env: { - HOME: process.env.HOME ?? root, + // A private HOME under the fixture, never the contributor's. + HOME: join(root, "user-home"), LANG: "C", PATH: `${root}:/usr/bin:/bin`, HACK_HOME: join(root, "home"),