diff --git a/docs/cli.md b/docs/cli.md index 64dbd24b..6b190363 100644 --- a/docs/cli.md +++ b/docs/cli.md @@ -266,6 +266,41 @@ Services with `pull_policy: always` still pull again in the start phase because Compose applies that policy on every `up`; such pulls count against the start budget. +Native authored projects with persistent storage also prove their storage with +short-lived helper containers. Each helper proof (one storage carrier: dependency +check, target observation, helper create, policy, start, response and cleanup) has +its own budget, separate from the start budget: + +| Budget | Default | Variable | Range (ms) | +| --- | --- | --- | --- | +| One native storage carrier | 90 seconds | `HACK_NATIVE_STORAGE_TIMEOUT_MS` | 1,000–600,000 | + +`HACK_COMPOSE_STARTUP_TIMEOUT_MS` neither shortens nor lengthens a storage proof: +carriers follow only `HACK_NATIVE_STORAGE_TIMEOUT_MS`. Storage +proofs that run while a native `up` or `restart` builds and starts workloads do not +consume the start budget: their elapsed time extends the start deadline, and each +proof stays bounded by its own carrier budget. Each Docker command inside a carrier +keeps its fixed 10–15 second cap. + +The two variables bound different things: + +- Per proof: each storage carrier ends within `HACK_NATIVE_STORAGE_TIMEOUT_MS` (S). +- Per start phase: the storage time excluded from one `up` or `restart` start + deadline may total at most 16 × S or 1 hour, whichever is smaller (24 minutes at + the 90-second default; 1 hour from S = 225,000 up). The start deadline moves + later by at most that cap. A proof that would start after the cap is spent is + refused before it runs, and a proof that ends past the cap refuses the phase. +- Whole phase: the workload phase therefore ends within + `HACK_COMPOSE_STARTUP_TIMEOUT_MS`, plus the cap, plus at most one in-flight + guard proof. Raising S raises both the per-proof bound and the cap; raising the + start budget never changes either. + +When a carrier budget or the whole-phase cap runs out, the command reports the +closed effect reason `storage-budget` in `error.detail.native_compose_effect_refusal`, +and the human summary names `HACK_NATIVE_STORAGE_TIMEOUT_MS`. Exhaustion leaves the +same retained, uncertain state as any other storage refusal; inspect saved state +before retrying. + To share dependency data only across worktrees with the same lockfile/runtime fingerprint, label the bootstrap service with a logical top-level Compose volume: diff --git a/docs/reference/native-compose-commands.md b/docs/reference/native-compose-commands.md index d4e952db..59eeddbf 100644 --- a/docs/reference/native-compose-commands.md +++ b/docs/reference/native-compose-commands.md @@ -35,7 +35,17 @@ fallback. The first command slice supports whole-project detached `up`, `restart`, `run`, `down`, `ps`, plain `logs`, and `exec`. Startup uses the existing configurable -Compose startup budget. Compose owns dependency startup, restart, and exec +Compose startup budget (`HACK_COMPOSE_STARTUP_TIMEOUT_MS`) for builds, container +start, readiness and route verification. Storage preparation, enrollment and +every storage proof use the separate per-carrier storage budget +(`HACK_NATIVE_STORAGE_TIMEOUT_MS`, default 90 seconds); proofs in the build and +pre-spawn guards extend the start deadline by their own elapsed time instead of +consuming it. That excluded time is capped per start phase at 16 × the storage +budget or 1 hour, whichever is smaller: the deadline moves at most that far, a +guard proof that would start after the cap is refused before it runs, and one +that ends past it refuses the phase as `storage-budget`. The phase thus ends +within the start budget, plus the cap, plus at most one in-flight guard proof. +Compose owns dependency startup, restart, and exec health checks. Hack checks the exact proposed generation: each service must be running, healthy when it declares a health check, and each initializer job must have exited successfully. An older healthy container does not satisfy a new @@ -337,8 +347,12 @@ expectation admission/write, journal, enrollment read, provision, root discovery seed, verification, closing root proof, completion write and publication. Carrier transport additionally distinguishes target, create, policy, start, response and cleanup; policy reasons identify shape, command, labels, host policy, mount -cardinality, program/storage mounts and policy stability. Unknown errors remain -`unclassified`. Diagnostics contain no paths, resource names, helper replies, +cardinality, program/storage mounts and policy stability. A refusal that finds +its carrier's storage budget exhausted, and not cancelled, reports +`storage-budget`, which names `HACK_NATIVE_STORAGE_TIMEOUT_MS`; a start phase +that spends its whole-phase storage cap reports the same reason at +`guard-storage`. Unknown errors +remain `unclassified`. Diagnostics contain no paths, resource names, helper replies, error messages or causes. They add no observation, retry, repair or cleanup and do not change pending-state, deadline or effect admission rules. A stage names the first captured boundary; it does not establish the cause of older failures diff --git a/docs/reference/native-compose-storage-xattr-carrier.md b/docs/reference/native-compose-storage-xattr-carrier.md index 9aeb0876..280a2982 100644 --- a/docs/reference/native-compose-storage-xattr-carrier.md +++ b/docs/reference/native-compose-storage-xattr-carrier.md @@ -402,6 +402,33 @@ leaves durable uncertainty that only explicit recovery can report. Earlier one-second identity reads and a three-second settlement budget refused healthy commands that way on loaded hosts. +Budgets are layered and all finite: + +- Each carrier (one helper proof session) has an absolute deadline from the + named storage budget `HACK_NATIVE_STORAGE_TIMEOUT_MS` (default 90 seconds, + 1,000–600,000 ms). It is never derived from `HACK_COMPOSE_STARTUP_TIMEOUT_MS`, + so a short start budget cannot starve a helper proof and a long one does not + lengthen it. +- In a native `up` or `restart` start phase, guard proof time is excluded from + the start deadline but capped in total at 16 × the storage budget or 1 hour, + whichever is smaller. A guard proof that would start after the cap is spent is + refused before it runs, and one that ends past it refuses as `storage-budget`. +- Inside a carrier every Docker probe and command keeps a fixed cap, clipped to + the carrier's remaining budget: 15 seconds for reads, target observation and + helper create/start, and 10 seconds for helper removal and cleanup reads, which + are not clipped. 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 + 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`. + +A refusal that finds its carrier's own deadline passed (and the carrier not +cancelled) reports the closed effect reason `storage-budget`; a probe clipped to +the remaining budget times out exactly at that end. 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 failure or deadline permanently invalidates that writer and retains its private files/descriptors. A rename or sync may finish after refusal, so a serialized diff --git a/src/lib/compose-startup-budget.ts b/src/lib/compose-startup-budget.ts index a811968e..98bca8d6 100644 --- a/src/lib/compose-startup-budget.ts +++ b/src/lib/compose-startup-budget.ts @@ -4,11 +4,20 @@ import { CliUsageError } from "../cli/command.ts"; export const DEFAULT_COMPOSE_STARTUP_TIMEOUT_MS = 90_000; /** Default budget for image build/pull and container creation before start. */ export const DEFAULT_COMPOSE_IMAGE_TIMEOUT_MS = 1_800_000; +/** + * Default budget of one native storage carrier: its dependency check, target + * observation, helper create/policy/start/response/cleanup and closing proof. + * It equals the earlier shared start default, so an unset host keeps the same + * per-carrier bound. + */ +export const DEFAULT_NATIVE_STORAGE_TIMEOUT_MS = 90_000; export const COMPOSE_STARTUP_TIMEOUT_ENV = "HACK_COMPOSE_STARTUP_TIMEOUT_MS"; export const COMPOSE_IMAGE_TIMEOUT_ENV = "HACK_COMPOSE_IMAGE_TIMEOUT_MS"; +export const NATIVE_STORAGE_TIMEOUT_ENV = "HACK_NATIVE_STORAGE_TIMEOUT_MS"; const MIN_TIMEOUT_MS = 1000; const MAX_STARTUP_TIMEOUT_MS = 3_600_000; const MAX_IMAGE_TIMEOUT_MS = 14_400_000; +const MAX_NATIVE_STORAGE_TIMEOUT_MS = 600_000; const INTEGER_TEXT = /^[0-9]+$/; /** @@ -66,6 +75,137 @@ export function resolveComposeImageTimeoutMs( }); } +/** + * Budget of one native storage carrier (one fresh helper proof session), from + * `HACK_NATIVE_STORAGE_TIMEOUT_MS`. It is separate from the start budget: + * storage preparation, enrollment and every storage proof use it, never + * `HACK_COMPOSE_STARTUP_TIMEOUT_MS`. Each Docker probe inside a carrier keeps its + * own fixed 10-15 s cap, and an exhausted carrier refuses with the closed + * `storage-budget` effect reason. It grants nothing and relaxes no check. + */ +export function resolveNativeStorageTimeoutMs( + opts: { + readonly storageTimeoutMs?: number; + readonly env?: Readonly>; + } = {} +): number { + return resolveBudget({ + explicit: opts.storageTimeoutMs, + configured: (opts.env ?? process.env)[NATIVE_STORAGE_TIMEOUT_ENV], + fallback: DEFAULT_NATIVE_STORAGE_TIMEOUT_MS, + max: MAX_NATIVE_STORAGE_TIMEOUT_MS, + invalid: () => + new CliUsageError( + `Native storage timeout must be an integer from ${MIN_TIMEOUT_MS} to ${MAX_NATIVE_STORAGE_TIMEOUT_MS} milliseconds (${NATIVE_STORAGE_TIMEOUT_ENV})` + ), + }); +} + +/** + * Whole-phase cap on storage time excluded from one `up`/`restart` start + * deadline. Each guard storage proof is bounded per carrier by + * `HACK_NATIVE_STORAGE_TIMEOUT_MS` (S), but a phase runs up to (5B+3) guard + * proofs for B builds, each over every enrolled volume, so the sum alone is + * unbounded in practice. The excluded total may therefore not exceed + * {@link NATIVE_STORAGE_EXCLUSION_MULTIPLE} x S or + * {@link MAX_NATIVE_STORAGE_EXCLUSION_MS}, whichever is smaller: 24 minutes at + * the 90 s default and 1 hour from S = 225 s up. Ordinary proofs take a small + * fraction of S, so the cap only stops a phase whose proofs keep running near + * their per-proof budget. + */ +export const NATIVE_STORAGE_EXCLUSION_MULTIPLE = 16; +/** Absolute ceiling of excluded storage time in one start phase (1 hour). */ +export const MAX_NATIVE_STORAGE_EXCLUSION_MS = 3_600_000; + +/** Excluded storage time one start phase may use for a per-carrier budget S. */ +export function nativeComposeStorageExclusionCapMs( + storageTimeoutMs: number +): number { + return Math.min( + NATIVE_STORAGE_EXCLUSION_MULTIPLE * storageTimeoutMs, + MAX_NATIVE_STORAGE_EXCLUSION_MS + ); +} + +/** + * Closed, value-free refusal once a start phase has spent its whole-phase + * storage exclusion cap. Its effect reason is `storage-budget`; it grants + * nothing and relaxes no check. + */ +export class NativeStorageTotalBudgetError extends Error { + constructor() { + super( + "Native storage proofs exhausted the whole-phase storage budget; values omitted." + ); + this.name = "NativeStorageTotalBudgetError"; + } +} + +/** + * Start deadline of a native `up`/`restart` workload phase (image builds, + * container start, readiness and route verification), bounded by + * `HACK_COMPOSE_STARTUP_TIMEOUT_MS`. Storage proofs that pre-spawn guards run + * inside this phase are bounded by their own `HACK_NATIVE_STORAGE_TIMEOUT_MS` + * carriers instead: their monotonic elapsed time extends this deadline rather + * than consuming it. Overlapping exclusions count once, a rejected proof still + * counts as excluded time, and the deadline never moves earlier. + * + * The excluded total is capped by + * {@link nativeComposeStorageExclusionCapMs}: the deadline moves at most that + * far, a proof that would start at or past the cap is refused before it runs, + * and a proof that ends past it refuses the phase with + * {@link NativeStorageTotalBudgetError} (a failed proof keeps its own error). + * The phase therefore ends within the start budget, plus the cap, plus at + * most one in-flight guard proof, which is itself bounded per carrier. + */ +export function createNativeComposeStartDeadline(opts: { + readonly timeoutMs: number; + /** Per-carrier storage budget S, from {@link resolveNativeStorageTimeoutMs}. */ + readonly storageTimeoutMs: number; + /** Wall clock that callers compare the deadline with; defaults to `Date.now`. */ + readonly wallNow?: () => number; + /** Monotonic clock that measures excluded storage time. */ + readonly monotonicNow?: () => number; +}): { + readonly deadline: () => number; + readonly excludeStorage: (work: () => Promise) => Promise; +} { + const wallNow = opts.wallNow ?? Date.now; + const monotonicNow = opts.monotonicNow ?? (() => performance.now()); + const capMs = nativeComposeStorageExclusionCapMs(opts.storageTimeoutMs); + const base = wallNow() + opts.timeoutMs; + let excluded = 0; + let active = 0; + let since = 0; + const spent = () => + excluded + (active > 0 ? Math.max(0, monotonicNow() - since) : 0); + return { + deadline: () => base + Math.min(capMs, spent()), + excludeStorage: async (work) => { + if (spent() >= capMs) { + throw new NativeStorageTotalBudgetError(); + } + if (active === 0) { + since = monotonicNow(); + } + active += 1; + let value: Awaited>; + try { + value = await work(); + } finally { + active -= 1; + if (active === 0) { + excluded += Math.max(0, monotonicNow() - since); + } + } + if (spent() > capMs) { + throw new NativeStorageTotalBudgetError(); + } + return value; + }, + }; +} + function resolveBudget(opts: { readonly explicit: number | undefined; readonly configured: string | undefined; diff --git a/src/lib/native-compose-build.ts b/src/lib/native-compose-build.ts index 6d370b99..123fcdff 100644 --- a/src/lib/native-compose-build.ts +++ b/src/lib/native-compose-build.ts @@ -326,7 +326,11 @@ async function image( export async function buildNativeComposeImages(opts: { readonly intents: readonly NativeComposeBuildIntent[]; readonly projectRoot: string; - readonly deadline?: number; + /** + * Start-phase wall deadline, read at every check: storage proof time that + * `assertOwned` excludes from the start budget extends it while builds run. + */ + readonly deadline?: () => number; readonly signal: AbortSignal; readonly env: Record | undefined; readonly json: boolean; @@ -334,9 +338,10 @@ export async function buildNativeComposeImages(opts: { readonly assertOwned: () => Promise; readonly io?: BuildIo; }): Promise { + const deadline = opts.deadline; + const within = () => deadline === undefined || Date.now() < deadline(); const probe = (args: readonly string[]) => { - const remaining = - opts.deadline === undefined ? 15_000 : opts.deadline - Date.now(); + const remaining = deadline === undefined ? 15_000 : deadline() - Date.now(); requireValue(remaining > 0); return createNativeComposeProbe({ signal: opts.signal, @@ -366,10 +371,7 @@ export async function buildNativeComposeImages(opts: { }; let engine: string | null = null; const fresh = async () => { - requireValue( - !opts.signal.aborted && - (opts.deadline === undefined || Date.now() < opts.deadline) - ); + requireValue(!opts.signal.aborted && within()); await opts.assertFresh(); await opts.assertOwned(); const observed = await io.engine(); @@ -379,10 +381,7 @@ export async function buildNativeComposeImages(opts: { (engine === null || engine === observed) ); engine = observed; - requireValue( - !opts.signal.aborted && - (opts.deadline === undefined || Date.now() < opts.deadline) - ); + requireValue(!opts.signal.aborted && within()); }; const admitted: { intent: NativeComposeBuildIntent; id: string }[] = []; // Admit every selected cached tag before any builder is invoked. @@ -402,7 +401,7 @@ export async function buildNativeComposeImages(opts: { // Recheck after it, then admit spawn synchronously with the remaining budget. await fresh(); const timeoutMs = - opts.deadline === undefined ? undefined : opts.deadline - Date.now(); + deadline === undefined ? undefined : deadline() - Date.now(); requireValue( !opts.signal.aborted && (timeoutMs === undefined || timeoutMs > 0) ); diff --git a/src/lib/native-compose-command-storage.ts b/src/lib/native-compose-command-storage.ts index ddcd7abc..21e8635e 100644 --- a/src/lib/native-compose-command-storage.ts +++ b/src/lib/native-compose-command-storage.ts @@ -1,5 +1,5 @@ import { HackCliError } from "./cli-result.ts"; -import { resolveComposeStartupTimeoutMs } from "./compose-startup-budget.ts"; +import { resolveNativeStorageTimeoutMs } from "./compose-startup-budget.ts"; import { isRecord } from "./guards.ts"; import { type NativeComposeEffectRefusal, @@ -186,13 +186,15 @@ export async function prepareNativeComposeCommandStorage(opts: { return refuse(); } const engineId = await engine({ signal }); + // Each fresh carrier gets the named storage budget, never the start budget: + // a short HACK_COMPOSE_STARTUP_TIMEOUT_MS must not starve helper proofs. const carrier = (): Promise => createCarrier({ store, authority: mutation.materialAuthority, engineId, signal, - deadline: Date.now() + resolveComposeStartupTimeoutMs(), + deadline: Date.now() + resolveNativeStorageTimeoutMs(), originalCommandRecords: true, }); // Check the explicit dependency before any authored hook, intent or volume effect. @@ -383,7 +385,7 @@ export async function reconcileNativeComposeCommandStorage(opts: { const engineId = await observeNativeComposeFileEngine({ signal: opts.signal, }); - const deadline = Date.now() + resolveComposeStartupTimeoutMs(); + const deadline = Date.now() + resolveNativeStorageTimeoutMs(); for (const state of candidates) { if (state.state !== "enrolled" || state.reference.version !== 3) { continue; diff --git a/src/lib/native-compose-command.ts b/src/lib/native-compose-command.ts index fd69115c..9df273d7 100644 --- a/src/lib/native-compose-command.ts +++ b/src/lib/native-compose-command.ts @@ -9,7 +9,11 @@ import { HackCliError, okResult, } from "./cli-result.ts"; -import { resolveComposeStartupTimeoutMs } from "./compose-startup-budget.ts"; +import { + createNativeComposeStartDeadline, + resolveComposeStartupTimeoutMs, + resolveNativeStorageTimeoutMs, +} from "./compose-startup-budget.ts"; import { isRecord } from "./guards.ts"; import { tryNativeAuthoredCommand } from "./native-authored-command.ts"; import { nativeComposeRuntimeMetadataSelection } from "./native-authored-runtime-metadata.ts"; @@ -801,6 +805,8 @@ async function savedCommand(opts: { >; } = { files: null }; try { + const stopDeadline = + Date.now() + resolveComposeStartupTimeoutMs(); const code = await runNativeComposeOwnedFileChild({ command: [ ...composeArgs(generation), @@ -808,7 +814,7 @@ async function savedCommand(opts: { "--remove-orphans", ], signal, - deadline: Date.now() + resolveComposeStartupTimeoutMs(), + deadline: () => stopDeadline, arm: async () => { stopping.files = await prepareNativeComposeSavedFileStop({ mutation, @@ -1300,7 +1306,8 @@ async function startNativeComposeWorkloads(opts: { readonly signal: AbortSignal; readonly assertOwned: () => Promise; readonly builds: readonly NativeComposeBuildIntent[]; - readonly deadline: number; + /** Start-phase deadline; storage proofs in the pre-spawn guard extend it. */ + readonly deadline: () => number; readonly observeStorage: ( observed: NativeComposeOwnershipObservation ) => void; @@ -1317,7 +1324,7 @@ async function startNativeComposeWorkloads(opts: { assertOwned, deadline, } = opts; - if (deadline <= Date.now()) { + if (deadline() <= Date.now()) { return { value: 1, outcome: "uncertain" as const }; } let stage: NativeComposeEffectRefusal["stage"] = "compose-child"; @@ -1352,7 +1359,7 @@ async function startNativeComposeWorkloads(opts: { ? await waitReady({ document, ownership: selection, - deadline, + deadline: deadline(), generation, observeStorage: opts.observeStorage, }) @@ -1361,7 +1368,7 @@ async function startNativeComposeWorkloads(opts: { stage = "compose-file-readiness"; await files?.assertReady(selection, generation); stage = "compose-routing-readiness"; - await routing?.verifyTransition({ deadline }); + await routing?.verifyTransition({ deadline: deadline() }); } return { value: observed ? 0 : code || 1, @@ -1393,11 +1400,11 @@ async function executePreparedNativeWorkloads(opts: { readonly observeStorage: ( observed: NativeComposeOwnershipObservation ) => void; + /** Start budget whose deadline excludes guard storage proof time. */ + readonly start: ReturnType; }) { const deadline = - opts.options.operation === "run" - ? undefined - : Date.now() + resolveComposeStartupTimeoutMs(); + opts.options.operation === "run" ? undefined : opts.start.deadline; if (opts.builds.length > 0) { const code = await buildNativeComposeImages({ intents: opts.builds, @@ -1420,7 +1427,7 @@ async function executePreparedNativeWorkloads(opts: { } return await startNativeComposeWorkloads({ ...opts, - deadline: deadline ?? Date.now() + resolveComposeStartupTimeoutMs(), + deadline: opts.start.deadline, }); } @@ -1690,6 +1697,13 @@ async function executePreparedGeneration(opts: { storage?.enroll(generation, document) ); stage = "workload-execution"; + // The start budget begins after enrollment. Guard storage proofs are + // bounded by their own storage carriers and do not consume it; their + // excluded total is capped by a multiple of the storage budget. + const start = createNativeComposeStartDeadline({ + timeoutMs: resolveComposeStartupTimeoutMs(), + storageTimeoutMs: resolveNativeStorageTimeoutMs(), + }); return await executePreparedNativeWorkloads({ options, generation, @@ -1703,6 +1717,7 @@ async function executePreparedGeneration(opts: { projectRoot, signal, assertFresh, + start, observeStorage: ownership.observeStorage, assertOwned: () => assertNativeComposeEffectOwned({ @@ -1712,9 +1727,11 @@ async function executePreparedGeneration(opts: { ? () => { const adjacentProof = adjacentGuardProof; adjacentGuardProof = false; - return storage.verify( - generation, - adjacentProof ? { adjacentProof } : {} + return start.excludeStorage(() => + storage.verify( + generation, + adjacentProof ? { adjacentProof } : {} + ) ); } : undefined, diff --git a/src/lib/native-compose-effect-diagnostics.ts b/src/lib/native-compose-effect-diagnostics.ts index 7e4a5a84..e0db5868 100644 --- a/src/lib/native-compose-effect-diagnostics.ts +++ b/src/lib/native-compose-effect-diagnostics.ts @@ -1,4 +1,8 @@ import { createClosedRefusalRegistry } from "./closed-refusal-registry.ts"; +import { + NATIVE_STORAGE_TIMEOUT_ENV, + NativeStorageTotalBudgetError, +} from "./compose-startup-budget.ts"; import { NativeComposeOwnershipError, nativeComposeProbeFailure, @@ -71,6 +75,7 @@ export type NativeComposeEffectRefusal = { | "probe-timeout" | "probe-cancel" | "probe-budget" + | "storage-budget" | "probe-capture" | "probe-decode" | "probe-unclassified" @@ -152,6 +157,7 @@ const reasons: readonly NativeComposeEffectRefusal["reason"][] = [ "probe-timeout", "probe-cancel", "probe-budget", + "storage-budget", "probe-capture", "probe-decode", "probe-unclassified", @@ -202,11 +208,39 @@ export function retainNativeComposeEffectRefusal( registry.retain(error, diagnostic); } +/** + * Refusals issued because a native storage carrier exhausted its named budget. + * A start phase that spends its whole-phase storage exclusion cap refuses with + * `NativeStorageTotalBudgetError`, which maps to the same reason. + */ +const storageBudgetRefusals = new WeakSet(); + +/** + * Mark a refusal whose cause is an exhausted native storage carrier budget + * (`HACK_NATIVE_STORAGE_TIMEOUT_MS`), so its effect reason names that budget. + * It grants nothing and changes no check, deadline or retention. + */ +export function markNativeComposeStorageBudgetRefusal(error: object): void { + storageBudgetRefusals.add(error); +} + +function storageBudgetRefusal(error: unknown): boolean { + return ( + error instanceof NativeStorageTotalBudgetError || + (typeof error === "object" && + error !== null && + storageBudgetRefusals.has(error)) + ); +} + /** Classify only a trusted error class's own closed data property; never invoke error getters. */ export function nativeComposeEffectReason( error: unknown ): NativeComposeEffectRefusal["reason"] { try { + if (storageBudgetRefusal(error)) { + return "storage-budget"; + } const code = typeof error === "object" && error !== null ? Object.getOwnPropertyDescriptor(error, "code") @@ -279,9 +313,12 @@ export function nativeComposeEffectRefusalSummary( const reason = reasons.find( (value) => value === ownData(refusal, "reason") ); - return stage && reason - ? `Refusal boundary: ${stage} (${reason}); values omitted.` - : null; + if (!(stage && reason)) { + return null; + } + return reason === "storage-budget" + ? `Refusal boundary: ${stage} (${reason}); the native storage budget ${NATIVE_STORAGE_TIMEOUT_ENV} was exhausted; values omitted.` + : `Refusal boundary: ${stage} (${reason}); values omitted.`; } catch { return null; } diff --git a/src/lib/native-compose-file-command.ts b/src/lib/native-compose-file-command.ts index 042d2e1d..a42f4152 100644 --- a/src/lib/native-compose-file-command.ts +++ b/src/lib/native-compose-file-command.ts @@ -60,7 +60,12 @@ export async function runNativeComposeOwnedFileChild(opts: { readonly assertOwned: () => Promise; readonly command: readonly string[]; readonly signal: AbortSignal; - readonly deadline: number; + /** + * Wall deadline, read at each admission check and once for the child's + * remaining budget after the final guard. A start-phase deadline moves later + * only by storage proof time that the guard excludes from the start budget. + */ + readonly deadline: () => number; readonly options: Omit< RunOptions, "timeoutMs" | "beforeSpawn" | "onSpawn" | "onExit" @@ -78,7 +83,7 @@ export async function runNativeComposeOwnedFileChild(opts: { } const hooks = opts.hooks; const requireAdmission = () => { - if (signal.aborted || Date.now() >= deadline) { + if (signal.aborted || Date.now() >= deadline()) { throw new NativeComposeGenerationError("E_NATIVE_COMPOSE_UNCERTAIN"); } }; @@ -90,7 +95,7 @@ export async function runNativeComposeOwnedFileChild(opts: { return await run(command, { ...options, ...hooks?.(), - timeoutMs: deadline - Date.now(), + timeoutMs: deadline() - Date.now(), beforeSpawn: requireAdmission, }); } diff --git a/src/lib/native-compose-storage-witness-docker.ts b/src/lib/native-compose-storage-witness-docker.ts index edfe267f..67c61e8a 100644 --- a/src/lib/native-compose-storage-witness-docker.ts +++ b/src/lib/native-compose-storage-witness-docker.ts @@ -13,6 +13,7 @@ import { join } from "node:path"; import { isRecord } from "./guards.ts"; import { copyNativeComposeEffectRefusal, + markNativeComposeStorageBudgetRefusal, type NativeComposeEffectRefusal, nativeComposeEffectReason, retainNativeComposeEffectRefusal, @@ -143,9 +144,17 @@ function same(left: unknown, right: unknown): boolean { return JSON.stringify(left) === JSON.stringify(right); } function lifetime(context: Context): void { - if (context.signal.aborted || Date.now() >= context.deadline) { + if (context.signal.aborted) { refuse(); } + if (Date.now() >= context.deadline) { + // Same refusal; only its effect reason names the exhausted storage budget. + const error = new Error( + "Native storage xattr proof refused; values omitted." + ); + markNativeComposeStorageBudgetRefusal(error); + throw error; + } } async function current( context: Context, @@ -799,6 +808,14 @@ export async function reconcileNativeComposeStorageDockerCarrierRecovery( return refuse(); } } +/** + * Post-exit group-absence budget of an unrecorded command (an identity read or + * a legacy root/seed command). A recorded command shares its settlement budget + * 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. */ async function groupAbsent( pid: number, monotonicDeadline?: number @@ -806,9 +823,8 @@ async function groupAbsent( if (!(Number.isInteger(pid) && pid > 1)) { return refuse(); } - const now = - monotonicDeadline === undefined ? Date.now : () => performance.now(); - const deadline = monotonicDeadline ?? Date.now() + 3000; + const deadline = + monotonicDeadline ?? performance.now() + UNRECORDED_GROUP_BUDGET_MS; while (true) { try { process.kill(-pid, 0); @@ -818,7 +834,7 @@ async function groupAbsent( } return refuse(); } - if (now() >= deadline) { + if (performance.now() >= deadline) { return refuseCommand("probe-budget"); } await new Promise((resolve) => setTimeout(resolve, 20)); @@ -947,6 +963,26 @@ export function nativeComposeStorageCarrierReason( ): NativeComposeEffectRefusal["reason"] { return storageCommandRefusal(error) ?? nativeComposeEffectReason(error); } +/** + * Effect reason at a carrier boundary of one storage carrier. When its own + * deadline, the named `HACK_NATIVE_STORAGE_TIMEOUT_MS` storage budget, is + * exhausted and the carrier was not cancelled, the refusal names that budget: + * every probe and command inside it is clipped to the remaining budget, so its + * timeout or budget refusal fires exactly at that end. Otherwise it keeps the + * classified command cause. Diagnostics only: no check, deadline or retention changes. + */ +export function nativeComposeStorageCarrierBudgetReason(opts: { + readonly error: unknown; + readonly signal: AbortSignal; + readonly deadline: number; + readonly now?: () => number; +}): NativeComposeEffectRefusal["reason"] { + const now = opts.now ?? Date.now; + if (!opts.signal.aborted && now() >= opts.deadline) { + return "storage-budget"; + } + return nativeComposeStorageCarrierReason(opts.error); +} export async function runNativeComposeStorageDockerCommand(supplied: { readonly context: Pick; @@ -1313,6 +1349,12 @@ export async function createNativeComposeDockerStorageXattrCarrier( opts: Context ): Promise { const context: Context = Object.freeze({ ...opts }); + const carrierReason = (error: unknown) => + nativeComposeStorageCarrierBudgetReason({ + error, + signal: context.signal, + deadline: context.deadline, + }); const docker = findExecutableInPath("docker") ?? refuse(); const selectors = [ "DOCKER_HOST", @@ -1370,7 +1412,7 @@ export async function createNativeComposeDockerStorageXattrCarrier( copyNativeComposeEffectRefusal(error, normalized); retainNativeComposeEffectRefusal(normalized, { stage: "storage-dependency", - reason: nativeComposeEffectReason(error), + reason: carrierReason(error), }); throw normalized; } @@ -1395,7 +1437,7 @@ export async function createNativeComposeDockerStorageXattrCarrier( } catch (error) { retainNativeComposeEffectRefusal(error, { stage, - reason: nativeComposeStorageCarrierReason(error), + reason: carrierReason(error), }); throw error; } @@ -1436,7 +1478,7 @@ export async function createNativeComposeDockerStorageXattrCarrier( } catch (error) { retainNativeComposeEffectRefusal(error, { stage: "storage-target", - reason: nativeComposeStorageCarrierReason(error), + reason: carrierReason(error), }); throw error; } @@ -1596,7 +1638,7 @@ export async function createNativeComposeDockerStorageXattrCarrier( } catch (error) { retainNativeComposeEffectRefusal(error, { stage, - reason: nativeComposeStorageCarrierReason(error), + reason: carrierReason(error), }); throw error; } @@ -1750,7 +1792,7 @@ export async function createNativeComposeDockerStorageXattrCarrier( } catch (error) { retainNativeComposeEffectRefusal(error, { stage: "storage-helper-policy", - reason: nativeComposeStorageCarrierReason(error), + reason: carrierReason(error), }); throw error; } @@ -2087,7 +2129,7 @@ export async function createNativeComposeDockerStorageXattrCarrier( } catch (error) { retainNativeComposeEffectRefusal(error, { stage, - reason: nativeComposeStorageCarrierReason(error), + reason: carrierReason(error), }); throw error; } diff --git a/src/lib/native-compose-storage-witness-xattr-carrier.ts b/src/lib/native-compose-storage-witness-xattr-carrier.ts index b229444a..83a2b36e 100644 --- a/src/lib/native-compose-storage-witness-xattr-carrier.ts +++ b/src/lib/native-compose-storage-witness-xattr-carrier.ts @@ -1,5 +1,6 @@ import { createHash } from "node:crypto"; import { isRecord } from "./guards.ts"; +import { markNativeComposeStorageBudgetRefusal } from "./native-compose-effect-diagnostics.ts"; import type { NativeComposeMaterialBinding } from "./native-compose-generation.ts"; import { keys } from "./native-compose-private-state.ts"; import { @@ -205,9 +206,17 @@ export function checkNativeComposeStorageXattrCarrierLifetime( handle: NativeComposeStorageXattrCarrier ): void { const { signal, deadline } = parts(handle); - if (signal.aborted || deadline <= Date.now()) { + if (signal.aborted) { refuse(); } + if (deadline <= Date.now()) { + // Same refusal; only its effect reason names the exhausted storage budget. + const error = new Error( + "Native storage xattr proof refused; values omitted." + ); + markNativeComposeStorageBudgetRefusal(error); + throw error; + } } export function checkNativeComposeStorageXattrTarget(opts: { readonly value: unknown; diff --git a/tests/compose-startup-budget.test.ts b/tests/compose-startup-budget.test.ts index 20964cb7..ce7a753c 100644 --- a/tests/compose-startup-budget.test.ts +++ b/tests/compose-startup-budget.test.ts @@ -1,10 +1,21 @@ import { expect, test } from "bun:test"; import { + createNativeComposeStartDeadline, DEFAULT_COMPOSE_IMAGE_TIMEOUT_MS, DEFAULT_COMPOSE_STARTUP_TIMEOUT_MS, + DEFAULT_NATIVE_STORAGE_TIMEOUT_MS, + NativeStorageTotalBudgetError, + nativeComposeStorageExclusionCapMs, resolveComposeImageTimeoutMs, resolveComposeStartupTimeoutMs, + resolveNativeStorageTimeoutMs, } from "../src/lib/compose-startup-budget.ts"; +import { + nativeComposeEffectReason, + nativeComposeEffectRefusal, + nativeComposeEffectRefusalSummary, + retainNativeComposeEffectRefusal, +} from "../src/lib/native-compose-effect-diagnostics.ts"; test("startup budget defaults and explicit numeric precedence", () => { expect(resolveComposeStartupTimeoutMs({ env: {} })).toBe( @@ -90,3 +101,224 @@ test("image build/pull budget is separate, defaults to 30 minutes and allows up ).toThrow("HACK_COMPOSE_IMAGE_TIMEOUT_MS"); } }); + +test("native storage budget is named, finite and independent of the start budget", () => { + expect(DEFAULT_NATIVE_STORAGE_TIMEOUT_MS).toBe(90_000); + expect(resolveNativeStorageTimeoutMs({ env: {} })).toBe( + DEFAULT_NATIVE_STORAGE_TIMEOUT_MS + ); + // A short start budget never shortens storage carriers, and vice versa. + expect( + resolveNativeStorageTimeoutMs({ + env: { HACK_COMPOSE_STARTUP_TIMEOUT_MS: "15000" }, + }) + ).toBe(DEFAULT_NATIVE_STORAGE_TIMEOUT_MS); + expect( + resolveComposeStartupTimeoutMs({ + env: { HACK_NATIVE_STORAGE_TIMEOUT_MS: "600000" }, + }) + ).toBe(DEFAULT_COMPOSE_STARTUP_TIMEOUT_MS); + for (const value of ["1000", "600000"]) { + expect( + resolveNativeStorageTimeoutMs({ + env: { HACK_NATIVE_STORAGE_TIMEOUT_MS: value }, + }) + ).toBe(Number(value)); + } + expect( + resolveNativeStorageTimeoutMs({ + storageTimeoutMs: 120_000, + env: { HACK_NATIVE_STORAGE_TIMEOUT_MS: "invalid" }, + }) + ).toBe(120_000); + for (const value of ["", "999", "600001", "1e5", "+1000", "private-input"]) { + expect(() => + resolveNativeStorageTimeoutMs({ + env: { HACK_NATIVE_STORAGE_TIMEOUT_MS: value }, + }) + ).toThrow( + "integer from 1000 to 600000 milliseconds (HACK_NATIVE_STORAGE_TIMEOUT_MS)" + ); + } + for (const value of [0, 999, 600_001, 1000.5, Number.POSITIVE_INFINITY]) { + expect(() => + resolveNativeStorageTimeoutMs({ storageTimeoutMs: value }) + ).toThrow(); + } +}); + +function fakeClocks() { + const clock = { wall: 1_000_000, monotonic: 50 }; + return { + clock, + advance(ms: number) { + clock.wall += ms; + clock.monotonic += ms; + }, + options: { + wallNow: () => clock.wall, + monotonicNow: () => clock.monotonic, + }, + }; +} + +test("start deadline is consumed by start work but not by excluded storage proofs", async () => { + const { advance, options } = fakeClocks(); + const start = createNativeComposeStartDeadline({ + timeoutMs: 15_000, + storageTimeoutMs: 90_000, + ...options, + }); + expect(start.deadline()).toBe(1_015_000); + // Ordinary start work consumes the budget: the deadline does not move. + advance(4000); + expect(start.deadline()).toBe(1_015_000); + // A 40 s storage proof extends the deadline by exactly its own duration. + const value = await start.excludeStorage(async () => { + advance(10_000); + // While the proof runs, its elapsed time already extends the deadline. + expect(start.deadline()).toBe(1_025_000); + advance(30_000); + return "proved"; + }); + expect(value).toBe("proved"); + expect(start.deadline()).toBe(1_055_000); + advance(1000); + expect(start.deadline()).toBe(1_055_000); +}); + +test("rejected and overlapping storage proofs are excluded once and the deadline never moves earlier", async () => { + const { advance, options } = fakeClocks(); + const start = createNativeComposeStartDeadline({ + timeoutMs: 15_000, + storageTimeoutMs: 90_000, + ...options, + }); + const failure = new Error("synthetic storage refusal"); + await expect( + start.excludeStorage(async () => { + advance(5000); + throw failure; + }) + ).rejects.toBe(failure); + expect(start.deadline()).toBe(1_020_000); + let release: () => void = () => undefined; + const gate = new Promise((resolve) => { + release = resolve; + }); + const seen: number[] = []; + const outer = start.excludeStorage(async () => { + advance(2000); + seen.push(start.deadline()); + await start.excludeStorage(async () => { + advance(3000); + seen.push(start.deadline()); + }); + seen.push(start.deadline()); + await gate; + advance(1000); + }); + release(); + await outer; + seen.push(start.deadline()); + // Nested proofs overlap: 6 s of wall time is excluded once, not 9 s. + expect(seen).toEqual([1_022_000, 1_025_000, 1_025_000, 1_026_000]); +}); + +test("monotonic exclusion ignores wall-clock steps during a storage proof", async () => { + const { clock, options } = fakeClocks(); + const start = createNativeComposeStartDeadline({ + timeoutMs: 15_000, + storageTimeoutMs: 90_000, + ...options, + }); + await start.excludeStorage(async () => { + // The wall clock steps back a minute while 7 s of monotonic time passes. + clock.wall -= 60_000; + clock.monotonic += 7000; + }); + expect(start.deadline()).toBe(1_022_000); +}); + +test("the whole-phase storage exclusion cap is the smaller of 16 x S and one hour", () => { + expect(nativeComposeStorageExclusionCapMs(1000)).toBe(16_000); + expect( + nativeComposeStorageExclusionCapMs(DEFAULT_NATIVE_STORAGE_TIMEOUT_MS) + ).toBe(1_440_000); + expect(nativeComposeStorageExclusionCapMs(225_000)).toBe(3_600_000); + expect(nativeComposeStorageExclusionCapMs(600_000)).toBe(3_600_000); +}); + +test("excluded storage time past the whole-phase cap refuses as storage-budget and stops extending the deadline", async () => { + const { advance, options } = fakeClocks(); + // S = 1 s, so the phase may exclude at most 16 s of storage proofs. + const start = createNativeComposeStartDeadline({ + timeoutMs: 15_000, + storageTimeoutMs: 1000, + ...options, + }); + expect( + await start.excludeStorage(async () => { + advance(10_000); + return "proved"; + }) + ).toBe("proved"); + expect(start.deadline()).toBe(1_025_000); + // A proof that ends past the cap refuses even though it succeeded, and the + // deadline moves only up to the cap while it runs. + const seen: number[] = []; + const caught = await start + .excludeStorage(async () => { + advance(7000); + seen.push(start.deadline()); + return "proved"; + }) + .catch((error: unknown) => error); + expect(seen).toEqual([1_031_000]); + expect(caught).toBeInstanceOf(NativeStorageTotalBudgetError); + expect((caught as Error).message).toBe( + "Native storage proofs exhausted the whole-phase storage budget; values omitted." + ); + expect(nativeComposeEffectReason(caught)).toBe("storage-budget"); + retainNativeComposeEffectRefusal(caught, { + stage: "guard-storage", + reason: nativeComposeEffectReason(caught), + }); + expect( + nativeComposeEffectRefusalSummary({ + native_compose_effect_refusal: nativeComposeEffectRefusal(caught), + }) + ).toBe( + "Refusal boundary: guard-storage (storage-budget); the native storage budget HACK_NATIVE_STORAGE_TIMEOUT_MS was exhausted; values omitted." + ); + expect(start.deadline()).toBe(1_031_000); + // Once the cap is spent, a further proof is refused before it runs. + let ran = false; + await expect( + start.excludeStorage(async () => { + ran = true; + }) + ).rejects.toBeInstanceOf(NativeStorageTotalBudgetError); + expect(ran).toBe(false); + expect(start.deadline()).toBe(1_031_000); +}); + +test("a storage proof that fails past the whole-phase cap keeps its own error", async () => { + const { advance, options } = fakeClocks(); + const start = createNativeComposeStartDeadline({ + timeoutMs: 15_000, + storageTimeoutMs: 1000, + ...options, + }); + const failure = new Error("synthetic storage refusal"); + await expect( + start.excludeStorage(async () => { + advance(20_000); + throw failure; + }) + ).rejects.toBe(failure); + expect(start.deadline()).toBe(1_031_000); + await expect( + start.excludeStorage(async () => undefined) + ).rejects.toBeInstanceOf(NativeStorageTotalBudgetError); +}); diff --git a/tests/e2e/native-compose-phase-summary.ts b/tests/e2e/native-compose-phase-summary.ts new file mode 100644 index 00000000..02bb327a --- /dev/null +++ b/tests/e2e/native-compose-phase-summary.ts @@ -0,0 +1,76 @@ +import { isRecord } from "../../src/lib/guards.ts"; + +/** Storage phases whose durations size the native storage budget (HACK-1324). */ +const STORAGE_PHASES = new Set([ + "storage.proof", + "storage.enroll", + "guard.storage", + "finalize.witnesses", +]); +const PHASE_LINE = /^\{"diagnostic":"native-compose-phase",[^\n]*\}$/; + +export type NativeComposeStorageTimings = { + /** Completed or failed `storage.proof` spans, one per storage carrier proof. */ + readonly proofs: number; + readonly proofMaxMs: number; + readonly proofTotalMs: number; + /** Longest span per storage phase that ended in this command. */ + readonly longestMs: Readonly>; +}; + +/** + * Summarize the passive `HACK_NATIVE_COMPOSE_PHASE_TRACE=1` lines of one CLI + * stderr. Only the fixed diagnostic fields are read: phase names come from the + * closed set above and durations are integers, so the summary carries no + * value, path or resource name. Malformed or unknown lines are ignored. + */ +export function summarizeNativeComposeStorageTimings( + stderr: string +): NativeComposeStorageTimings { + let proofs = 0; + let proofMaxMs = 0; + let proofTotalMs = 0; + const longestMs: Record = {}; + for (const line of stderr.split("\n")) { + if (!PHASE_LINE.test(line)) { + continue; + } + let value: unknown; + try { + value = JSON.parse(line); + } catch { + continue; + } + if ( + !( + isRecord(value) && + typeof value.phase === "string" && + STORAGE_PHASES.has(value.phase) && + (value.boundary === "end" || value.boundary === "fail") && + Number.isSafeInteger(value.durationMs) && + (value.durationMs as number) >= 0 + ) + ) { + continue; + } + const duration = value.durationMs as number; + longestMs[value.phase] = Math.max(longestMs[value.phase] ?? 0, duration); + if (value.phase === "storage.proof") { + proofs += 1; + proofMaxMs = Math.max(proofMaxMs, duration); + proofTotalMs += duration; + } + } + return { proofs, proofMaxMs, proofTotalMs, longestMs }; +} + +/** One fixed log line for a command's storage timings. */ +export function describeNativeComposeStorageTimings( + timings: NativeComposeStorageTimings +): string { + const longest = [...STORAGE_PHASES] + .filter((phase) => Object.hasOwn(timings.longestMs, phase)) + .map((phase) => `${phase}=${timings.longestMs[phase]}ms`) + .join(" "); + return `storage proofs=${timings.proofs} max=${timings.proofMaxMs}ms total=${timings.proofTotalMs}ms${longest ? ` longest ${longest}` : ""}`; +} diff --git a/tests/e2e/native-config-networks-acceptance.ts b/tests/e2e/native-config-networks-acceptance.ts index 1b23d104..db1273d8 100644 --- a/tests/e2e/native-config-networks-acceptance.ts +++ b/tests/e2e/native-config-networks-acceptance.ts @@ -45,9 +45,39 @@ const OUTPUT_LIMIT = 2 * 1024 * 1024; const COMMAND_TIMEOUT = 180_000; // Witness-bearing exec/up verification runs three fresh helper carriers per proof; on the // hosted Linux engine a storage exec (two proofs) takes ~10 s and a warm up (six or seven) -// ~30 s across three checkouts, about 38 minutes for this scenario. -const SCENARIO_TIMEOUT = 60 * 60_000; +// ~30 s across three checkouts. 44 hosted passes (Blacksmith 4 vCPU, +// 2026-10-19..21) took 2113-3494 s, median ~2650 s; the slowest used 97% of +// the former 60-minute budget. The named 90-minute budget keeps 1.55x that +// slowest pass; with cleanup and two command bounds it stays inside the +// 150-minute shard job. +export const NATIVE_NETWORK_FIXTURE_SCENARIO_TIMEOUT = 90 * 60_000; +const SCENARIO_TIMEOUT = NATIVE_NETWORK_FIXTURE_SCENARIO_TIMEOUT; const CLEANUP_TIMEOUT = 3 * 60_000; +/** + * Whole-run and cleanup budgets gate only the start of a fixture command. A + * started command keeps its full own `COMMAND_TIMEOUT`, so the hard bound is + * `SCENARIO_TIMEOUT + CLEANUP_TIMEOUT + 2 * COMMAND_TIMEOUT`. Clipping a started + * command to the remaining whole-run budget killed an in-flight storage carrier + * command (run 39431629301): its created helper is retained evidence that saved + * `down --recover` correctly refuses to repair, so cleanup could not recover. + */ +export function nativeNetworkFixtureCommandTimeout(opts: { + readonly started: number; + readonly cleanupStarted: number | null; + readonly now: number; +}): number { + const remaining = + opts.cleanupStarted === null + ? SCENARIO_TIMEOUT - (opts.now - opts.started) + : CLEANUP_TIMEOUT - (opts.now - opts.cleanupStarted); + requireValue( + remaining > 0, + opts.cleanupStarted === null + ? "Network scenario exceeded its whole-run budget" + : "Network scenario exceeded its cleanup budget" + ); + return COMMAND_TIMEOUT; +} const BUN_TAG = "oven/bun:1.4.2-slim"; const CADDY_TAG = "lucaslorentz/caddy-docker-proxy:2.10.0-alpine"; const ROOT_CA = "/data/caddy/pki/authorities/local/root.crt"; @@ -1590,14 +1620,11 @@ export const nativeConfigNetworksScenario: Scenario = { cwd = ctx.tempRoot, extra: Readonly> = {} ): Promise => { - const remaining = - cleanupStarted === null - ? SCENARIO_TIMEOUT - (Date.now() - started) - : CLEANUP_TIMEOUT - (Date.now() - cleanupStarted); - requireValue( - remaining > 0, - "Network scenario exceeded its whole-run budget" - ); + const timeoutMs = nativeNetworkFixtureCommandTimeout({ + started, + cleanupStarted, + now: Date.now(), + }); sequence += 1; const command = { step: nativeNetworkFixtureStep(argv, stepExecutables), @@ -1612,7 +1639,7 @@ export const nativeConfigNetworksScenario: Scenario = { cwd, env: { ...env, ...extra }, captures, - timeoutMs: Math.min(COMMAND_TIMEOUT, remaining), + timeoutMs, }); } catch (error: unknown) { // A killed or unreturned command has no result for ok(); name it here. diff --git a/tests/e2e/scenarios/native-config-build.ts b/tests/e2e/scenarios/native-config-build.ts index ef16cf21..6b5fe784 100644 --- a/tests/e2e/scenarios/native-config-build.ts +++ b/tests/e2e/scenarios/native-config-build.ts @@ -13,10 +13,37 @@ import { runCommand, type Scenario, } from "../harness.ts"; +import { + describeNativeComposeStorageTimings, + summarizeNativeComposeStorageTimings, +} from "../native-compose-phase-summary.ts"; import { prepareNativeEngineTripwire } from "../native-engine-tripwire.ts"; import { proxyHasNoPublishedPorts } from "./native-routing-fixture-ingress.ts"; const TIMEOUT = 120_000; +/** + * One hack command. A storage-backed `up` with two builds runs about a dozen + * storage proofs in its build and spawn guards; each is bounded by its own + * storage carrier budget and no longer consumes the 90 s start budget. The + * hosted failure reached the start deadline about 110 s into `up` (HACK-1324), + * so a 120 s command bound would kill a proof that now continues. 300 s keeps + * a measured margin; each command's duration is logged as evidence. + */ +const CLI_TIMEOUT = 300_000; +const LOGGED_VERBS: ReadonlySet = new Set([ + "up", + "down", + "restart", + "run", + "exec", + "ps", + "logs", + "config", +]); +/** The first argv entry that is a closed lifecycle verb, or a fixed placeholder; never a value. */ +function nativeBuildCommandVerb(args: readonly string[]): string { + return args.find((arg) => LOGGED_VERBS.has(arg)) ?? "command"; +} const IMAGE_ID = /^sha256:[a-f0-9]{64}$/; const RESOURCE_ID = /^[a-f0-9]{64}$/; const TOKEN = /^[a-f0-9]{32}$/; @@ -573,21 +600,29 @@ export const nativeConfigBuildScenario: Scenario = { "Native-only build and source Dockerfile fences must be intact", }); }; - const raw = ( + const raw = async ( args: readonly string[], env: Readonly> = {} - ): Promise => - ctx.cli({ + ): Promise => { + const result = await ctx.cli({ args, cwd: root, - timeoutMs: TIMEOUT, + timeoutMs: CLI_TIMEOUT, env: { HACK_RUNTIME_BACKEND: "compose", HACK_DAEMON_DISABLE_DOCKER_EVENTS: "1", NC03_BUILD_AMBIENT: PUBLIC_AMBIENT, + HACK_NATIVE_COMPOSE_PHASE_TRACE: "1", ...env, }, }); + // Fixed verb, exit, duration and closed storage phase timings only: + // measured budget evidence without values. + ctx.log( + `hack ${nativeBuildCommandVerb(args)} ${result.timedOut ? "timeout" : `exit ${result.exitCode}`} in ${Math.round(result.durationMs)}ms; ${describeNativeComposeStorageTimings(summarizeNativeComposeStorageTimings(result.stderr))}` + ); + return result; + }; const cli = async (args: readonly string[]): Promise => { const result = await raw(args); expectExit({ diff --git a/tests/e2e/scenarios/native-config-down-hooks.ts b/tests/e2e/scenarios/native-config-down-hooks.ts index 5882cfcf..2ae8bbdf 100644 --- a/tests/e2e/scenarios/native-config-down-hooks.ts +++ b/tests/e2e/scenarios/native-config-down-hooks.ts @@ -23,8 +23,21 @@ import { pinNativeComposeFixtureVolume, runWithOwnedCleanup, } from "../native-compose-owned-fixture.ts"; +import { + describeNativeComposeStorageTimings, + summarizeNativeComposeStorageTimings, +} from "../native-compose-phase-summary.ts"; -const TIMEOUT = 90_000; +/** + * One hack command. The 15 s start budget below bounds container start and + * readiness only; each storage proof of an `up` (preparation, entry, + * enrollment, guard and finalization carriers) has its own default 90 s storage + * carrier budget (HACK-1324). A 90 s command bound could kill a slow but + * healthy proof and leave uncertain storage; 240 s keeps margin over several + * slow carriers. Each command's duration is logged as evidence. + */ +const TIMEOUT = 240_000; +const LOGGED_VERBS: ReadonlySet = new Set(["up", "down", "exec", "ps"]); const HOST_VALUE = "synthetic-down-host-$literal"; function data(result: CliResult): Record { const value: unknown = JSON.parse(result.stdout); @@ -171,9 +184,15 @@ if((await Bun.file("mode").text())===phase+"17")process.exit(17); HACK_RUNTIME_BACKEND: "compose", HACK_COMPOSE_STARTUP_TIMEOUT_MS: "15000", HACK_DAEMON_DISABLE_DOCKER_EVENTS: "1", + HACK_NATIVE_COMPOSE_PHASE_TRACE: "1", }, }); noValues(result); + // Fixed verb, exit, duration and closed storage phase timings only: + // measured budget evidence without values. + ctx.log( + `hack ${LOGGED_VERBS.has(args[0] ?? "") ? args[0] : "command"}${args.includes("--recover") ? " --recover" : ""} ${result.timedOut ? "timeout" : `exit ${result.exitCode}`} in ${Math.round(result.durationMs)}ms; ${describeNativeComposeStorageTimings(summarizeNativeComposeStorageTimings(result.stderr))}` + ); if (result.timedOut) { ctx.retainFixtures( "CLI timeout leaves unverified finite down effects; inspect saved owner before cleanup" diff --git a/tests/helpers/native-compose-command.ts b/tests/helpers/native-compose-command.ts index 5fb8e696..3bbbcdd9 100644 --- a/tests/helpers/native-compose-command.ts +++ b/tests/helpers/native-compose-command.ts @@ -247,7 +247,14 @@ export async function invoke( * Without one, the command uses an isolated client config that selects no * real engine. */ - extraEnv: Readonly> = {} + extraEnv: Readonly> = {}, + capture: { + /** + * Write the CLI's stderr straight to this file instead of a pipe, so the + * Docker stand-in can read diagnostics the CLI has already written. + */ + readonly stderrFile?: string; + } = {} ) { const child = Bun.spawn( [ @@ -278,16 +285,21 @@ export async function invoke( }), stdin: "ignore", stdout: "pipe", - stderr: "pipe", + stderr: capture.stderrFile ? Bun.file(capture.stderrFile) : "pipe", } ); const timer = setTimeout(() => child.kill("SIGKILL"), commandTimeoutMs); try { - const [code, stdout, stderr] = await Promise.all([ + const [code, stdout, piped] = await Promise.all([ child.exited, new Response(child.stdout).text(), - new Response(child.stderr).text(), + typeof child.stderr === "number" || child.stderr === undefined + ? "" + : new Response(child.stderr).text(), ]); + const stderr = capture.stderrFile + ? await Bun.file(capture.stderrFile).text() + : piped; return { code, stdout, stderr }; } finally { clearTimeout(timer); diff --git a/tests/native-compose-build.test.ts b/tests/native-compose-build.test.ts index f3312c97..88522726 100644 --- a/tests/native-compose-build.test.ts +++ b/tests/native-compose-build.test.ts @@ -471,7 +471,7 @@ test.each([ } try { await expect( - buildNativeComposeImages({ ...state.options, deadline }) + buildNativeComposeImages({ ...state.options, deadline: () => deadline }) ).rejects.toBeInstanceOf(NativeComposeBuildError); expect(reads).toBe(3); expect(state.executed()).toBe(0); @@ -535,21 +535,64 @@ test("run builds keep the existing unbounded command budget; startup budgets rem timeout = value; return await builder(args, value); }; + const limit = Date.now() + 30_000; expect( await buildNativeComposeImages({ ...startup.options, - deadline: Date.now() + 30_000, + deadline: () => limit, }) ).toBe(0); expect(timeout).toBeGreaterThan(0); expect(timeout).toBeLessThanOrEqual(30_000); + const past = Date.now() - 1; const expired = harness(); await expect( - buildNativeComposeImages({ ...expired.options, deadline: Date.now() - 1 }) + buildNativeComposeImages({ ...expired.options, deadline: () => past }) ).rejects.toBeInstanceOf(NativeComposeBuildError); expect(expired.executed()).toBe(0); }); +test("guard storage time that extends the start deadline is re-read at every build check", async () => { + // Fake wall clock: each owned guard spends 20 s of storage proof time that + // the start budget excludes, so the live deadline moves by the same amount. + let now = 1_000_000; + let deadline = now + 30_000; + const clock = spyOn(Date, "now").mockImplementation(() => now); + try { + const state = harness(); + let timeout: number | undefined; + const execute = state.options.io.execute; + state.options.io.execute = async (args, value) => { + timeout = value; + return await execute(args, value); + }; + state.options.assertOwned = async () => { + now += 20_000; + deadline += 20_000; + }; + expect( + await buildNativeComposeImages({ + ...state.options, + deadline: () => deadline, + }) + ).toBe(0); + expect(state.executed()).toBe(1); + // Every guard was excluded: the builder still receives the full budget. + expect(timeout).toBe(30_000); + const fixed = harness(); + fixed.options.assertOwned = async () => { + now += 20_000; + }; + const frozen = now + 30_000; + await expect( + buildNativeComposeImages({ ...fixed.options, deadline: () => frozen }) + ).rejects.toBeInstanceOf(NativeComposeBuildError); + expect(fixed.executed()).toBe(0); + } finally { + clock.mockRestore(); + } +}); + test("malformed or replaced daemon identity refuses before builder effects", async () => { const malformed = harness(); malformed.options.io.engine = async () => "private-canary\ninvalid"; diff --git a/tests/native-compose-effect-diagnostics.test.ts b/tests/native-compose-effect-diagnostics.test.ts index b3afdb0d..a4fb252b 100644 --- a/tests/native-compose-effect-diagnostics.test.ts +++ b/tests/native-compose-effect-diagnostics.test.ts @@ -10,6 +10,7 @@ import { import { attachNativeComposeEffectRefusal, copyNativeComposeEffectRefusal, + markNativeComposeStorageBudgetRefusal, nativeComposeEffectReason, nativeComposeEffectRefusal, nativeComposeEffectRefusalSummary, @@ -329,6 +330,33 @@ test("the human boundary summary names only a known stage and reason pair", () = } }); +test("an exhausted storage carrier budget is a closed reason that names its variable", () => { + const exhausted = new Error( + "Native storage xattr proof refused; values omitted." + ); + expect(nativeComposeEffectReason(exhausted)).toBe("unclassified"); + markNativeComposeStorageBudgetRefusal(exhausted); + expect(nativeComposeEffectReason(exhausted)).toBe("storage-budget"); + // Marking one refusal never reclassifies another. + expect(nativeComposeEffectReason(new Error("other"))).toBe("unclassified"); + retainNativeComposeEffectRefusal(exhausted, { + stage: "storage-helper-start", + reason: nativeComposeEffectReason(exhausted), + }); + const diagnostic = nativeComposeEffectRefusal(exhausted); + expect(diagnostic).toEqual({ + stage: "storage-helper-start", + reason: "storage-budget", + }); + expect( + nativeComposeEffectRefusalSummary({ + native_compose_effect_refusal: diagnostic, + }) + ).toBe( + "Refusal boundary: storage-helper-start (storage-budget); the native storage budget HACK_NATIVE_STORAGE_TIMEOUT_MS was exhausted; values omitted." + ); +}); + test.each([ "guard-fresh-before", "guard-ownership", diff --git a/tests/native-compose-file-owner.test.ts b/tests/native-compose-file-owner.test.ts index f783a8da..487df49c 100644 --- a/tests/native-compose-file-owner.test.ts +++ b/tests/native-compose-file-owner.test.ts @@ -299,6 +299,7 @@ for (const operation of ["up", "down"] as const) { const owner = initial ? ownerFor(mutation) : selected.owner; const controller = new AbortController(); const marker = join(parent, "unexpected-child"); + const admittedUntil = Date.now() + 10_000; await expect( mutation.runEffect({ generation: selected.generation, @@ -313,7 +314,7 @@ for (const operation of ["up", "down"] as const) { `await Bun.write(${JSON.stringify(marker)}, "effect")`, ], signal: controller.signal, - deadline: Date.now() + 10_000, + deadline: () => admittedUntil, options: { stdin: "ignore" as const, stdout: "ignore" as const, @@ -334,7 +335,7 @@ for (const operation of ["up", "down"] as const) { controller.abort(); Object.assign(input, { signal: new AbortController().signal, - deadline: Date.now() + 60_000, + deadline: () => admittedUntil + 50_000, }); }, }; diff --git a/tests/native-compose-phase-summary.test.ts b/tests/native-compose-phase-summary.test.ts new file mode 100644 index 00000000..203fc7c0 --- /dev/null +++ b/tests/native-compose-phase-summary.test.ts @@ -0,0 +1,55 @@ +import { expect, test } from "bun:test"; +import { + describeNativeComposeStorageTimings, + summarizeNativeComposeStorageTimings, +} from "./e2e/native-compose-phase-summary.ts"; + +function line(fields: Record): string { + return JSON.stringify({ + diagnostic: "native-compose-phase", + version: 1, + sequence: 1, + span: 1, + elapsedMs: 0, + ...fields, + }); +} + +test("storage timing evidence reads only closed phase trace fields", () => { + const canary = "private-storage-canary"; + const stderr = [ + "#1 building with docker driver", + line({ phase: "storage.proof", boundary: "begin", durationMs: null }), + line({ phase: "storage.proof", boundary: "end", durationMs: 6200 }), + line({ phase: "storage.proof", boundary: "fail", durationMs: 14_900 }), + line({ phase: "storage.enroll", boundary: "end", durationMs: 21_000 }), + line({ phase: "guard.storage", boundary: "end", durationMs: 7000 }), + line({ phase: "guard.ownership", boundary: "end", durationMs: 90_000 }), + line({ phase: canary, boundary: "end", durationMs: 1 }), + line({ phase: "storage.proof", boundary: "end", durationMs: -1 }), + line({ phase: "storage.proof", boundary: "end", durationMs: 1.5 }), + `${line({ phase: "storage.proof", boundary: "end", durationMs: 5 })} ${canary}`, + "{not json", + ].join("\n"); + const timings = summarizeNativeComposeStorageTimings(stderr); + expect(timings).toEqual({ + proofs: 2, + proofMaxMs: 14_900, + proofTotalMs: 21_100, + longestMs: { + "storage.proof": 14_900, + "storage.enroll": 21_000, + "guard.storage": 7000, + }, + }); + const text = describeNativeComposeStorageTimings(timings); + expect(text).toBe( + "storage proofs=2 max=14900ms total=21100ms longest storage.proof=14900ms storage.enroll=21000ms guard.storage=7000ms" + ); + expect(text).not.toContain(canary); + expect( + describeNativeComposeStorageTimings( + summarizeNativeComposeStorageTimings("") + ) + ).toBe("storage proofs=0 max=0ms total=0ms"); +}); diff --git a/tests/native-compose-start-storage-exclusion.test.ts b/tests/native-compose-start-storage-exclusion.test.ts new file mode 100644 index 00000000..71787001 --- /dev/null +++ b/tests/native-compose-start-storage-exclusion.test.ts @@ -0,0 +1,84 @@ +import { expect, test } from "bun:test"; +import { readFile, writeFile } from "node:fs/promises"; +import { join } from "node:path"; +import { fixture, invoke } from "./helpers/native-compose-command.ts"; + +const START_BUDGET_MS = 3000; +// Longer than the whole start budget, far below the per-carrier storage budget. +const GUARD_CARRIER_DELAY_MS = 4000; + +function phaseRows(text: string) { + return text + .split("\n") + .filter((line) => line.startsWith('{"diagnostic":"native-compose-phase",')) + .map( + (line) => + JSON.parse(line) as { + readonly phase: string; + readonly boundary: string; + readonly durationMs: number | null; + } + ); +} + +// Failure injection on the real source CLI: only the pre-spawn guard's storage +// carrier is slowed. The stand-in reads the CLI's own phase trace (written +// synchronously to its stderr file before the carrier spawns Docker) and delays +// a carrier dependency check (helper `image inspect`) only while a +// `guard.storage` span is open. Enrollment and finalization proofs are not +// delayed. Without the start deadline's storage exclusion, the guard alone +// would spend the start budget and the workload would never be admitted. +test("a pre-spawn guard storage proof longer than the start budget does not consume it", async () => { + const root = await fixture("", false, { + noHooks: true, + storage: { data: { kind: "persistent", scope: "worktree" } }, + }); + const stderrFile = join(root, "cli-stderr"); + const docker = join(root, "docker"); + const source = await readFile(docker, "utf8"); + const anchor = "const args=process.argv.slice(2);"; + expect(source.includes(anchor)).toBe(true); + await writeFile( + docker, + source.replace( + anchor, + `${anchor} +if(args[0]==="image"&&args[1]==="inspect"&&await Bun.file(${JSON.stringify(stderrFile)}).exists()){ + const open=new Map(); + for(const line of (await Bun.file(${JSON.stringify(stderrFile)}).text()).split("\\n")){ + if(!line.startsWith('{"diagnostic":"native-compose-phase",'))continue; + const row=JSON.parse(line);if(row.boundary==="begin")open.set(row.span,row.phase);else open.delete(row.span); + } + if([...open.values()].includes("guard.storage")){await appendFile(root+"/guard-carrier-delays","1\\n");await Bun.sleep(${GUARD_CARRIER_DELAY_MS});} +}` + ) + ); + const result = await invoke( + root, + ["up", "--detach", "--json"], + START_BUDGET_MS, + 240_000, + { HACK_NATIVE_COMPOSE_PHASE_TRACE: "1" }, + { stderrFile } + ); + const delays = ( + await readFile(join(root, "guard-carrier-delays"), "utf8").catch(() => "") + ) + .split("\n") + .filter(Boolean).length; + expect(delays).toBeGreaterThanOrEqual(1); + // The delayed guard storage proof outlasted the whole start budget. + const guard = phaseRows(result.stderr).filter( + (row) => row.phase === "guard.storage" && row.boundary === "end" + ); + expect(guard.length).toBeGreaterThanOrEqual(1); + expect(guard[0]?.durationMs ?? 0).toBeGreaterThan(START_BUDGET_MS); + // The workload was still admitted and started within its own start budget. + expect(result.code).toBe(0); + expect(JSON.parse(result.stdout)).toMatchObject({ + data: { status: "ready" }, + }); + expect( + (await readFile(join(root, "storage-events"), "utf8")).split("\n") + ).toContain("workload"); +}, 300_000); diff --git a/tests/native-compose-storage-command-record.test.ts b/tests/native-compose-storage-command-record.test.ts index 7a306e54..f4846113 100644 --- a/tests/native-compose-storage-command-record.test.ts +++ b/tests/native-compose-storage-command-record.test.ts @@ -703,6 +703,65 @@ test( }), 30_000 ); +test( + "an unrecorded command whose group never becomes absent refuses as probe-budget on monotonic time", + ownedCase(async () => { + const f = await fixture(), + marker = join(f.root, "effect"), + kill = process.kill, + monotonic = performance.now.bind(performance), + wall = Date.now(); + let elapsed = 0, + polls = 0; + // Fake clocks: the wall clock is frozen, so only a monotonic deadline can + // expire. Each post-exit poll still sees the exited group and 4 s pass. + const frozen = spyOn(Date, "now").mockImplementation(() => wall); + const clock = spyOn(performance, "now").mockImplementation( + () => monotonic() + elapsed + ); + const observer = spyOn(process, "kill").mockImplementation( + (pid, signal) => { + if ( + signal === 0 && + typeof pid === "number" && + pid < 0 && + existsSync(marker) + ) { + polls += 1; + elapsed += 4000; + return true; + } + return kill(pid, signal); + } + ); + try { + const caught = await runNativeComposeStorageDockerCommand({ + context: { + signal: new AbortController().signal, + deadline: wall + 3000, + }, + files: f.files, + args: ["/bin/sh", "-c", 'printf complete > "$1"', "owned", marker], + timeoutMs: 3000, + beforeSpawn: () => {}, + assertAdmitted: async () => {}, + }).catch((error: unknown) => error); + expect(caught).toBeInstanceOf(Error); + expect((caught as Error).message).toContain("values omitted"); + expect(nativeComposeStorageCarrierReason(caught)).toBe("probe-budget"); + expect(polls).toBe(1); + expect(await readFile(marker, "utf8")).toBe("complete"); + retained.add(f.root); + } finally { + if (confirmedTestLifetime()) { + frozen.mockRestore(); + clock.mockRestore(); + observer.mockRestore(); + } + } + }), + 30_000 +); test( "a recorded child that outlives its command budget refuses as probe-timeout", ownedCase(async () => { diff --git a/tests/native-compose-storage-witness-docker.test.ts b/tests/native-compose-storage-witness-docker.test.ts index 455fa8c8..c5c3aa30 100644 --- a/tests/native-compose-storage-witness-docker.test.ts +++ b/tests/native-compose-storage-witness-docker.test.ts @@ -1,9 +1,10 @@ -import { afterEach, expect, test } from "bun:test"; +import { afterEach, expect, spyOn, test } from "bun:test"; import { createHash } from "node:crypto"; import { mkdir, mkdtemp, realpath, rm } from "node:fs/promises"; import { tmpdir } from "node:os"; import { join } from "node:path"; import { + nativeComposeEffectReason, nativeComposeEffectRefusal, retainNativeComposeEffectRefusal, } from "../src/lib/native-compose-effect-diagnostics.ts"; @@ -13,7 +14,11 @@ import { type NativeComposeMaterialBinding, openNativeComposeGenerationStore, } from "../src/lib/native-compose-generation.ts"; -import { assertNativeComposeStorageDockerImage } from "../src/lib/native-compose-storage-witness-docker.ts"; +import { NativeComposeOwnershipError } from "../src/lib/native-compose-ownership.ts"; +import { + assertNativeComposeStorageDockerImage, + nativeComposeStorageCarrierBudgetReason, +} from "../src/lib/native-compose-storage-witness-docker.ts"; import { NATIVE_STORAGE_DOCKER_ARTIFACT, nativeComposeStorageDockerHelper, @@ -31,7 +36,13 @@ import { nativeComposeStorageDockerCarrierPolicy, nativeComposeStorageDockerCreateArgs, } from "../src/lib/native-compose-storage-witness-docker-policy.ts"; -import type { NativeComposeStorageXattrInvocation } from "../src/lib/native-compose-storage-witness-xattr-carrier.ts"; +import { + captureNativeComposeStorageXattrCarrier, + checkNativeComposeStorageXattrCarrierLifetime, + type NativeComposeStorageXattrArtifact, + type NativeComposeStorageXattrInvocation, +} from "../src/lib/native-compose-storage-witness-xattr-carrier.ts"; +import { refuseNativeComposeStorageXattr } from "../src/lib/native-compose-storage-witness-xattr-codec.ts"; const roots: string[] = [], stores: NativeComposeGenerationStore[] = []; @@ -1098,3 +1109,100 @@ test("policy comparison preserves all physical fields/duplicates and closes only fake.value.host.OomKillDisable = true; expect(() => nativeComposeStorageDockerCarrierPolicy(checked())).toThrow(); }); + +test("a carrier boundary names its exhausted storage budget, never a cancellation", () => { + // Fake clock: the carrier deadline is the named storage budget's end. + let now = 5_000_000; + const deadline = now + 90_000; + const timedOut = new NativeComposeOwnershipError( + "E_NATIVE_COMPOSE_PROBE_TIMEOUT" + ); + const reason = (signal: AbortSignal) => + nativeComposeStorageCarrierBudgetReason({ + error: timedOut, + signal, + deadline, + now: () => now, + }); + const live = new AbortController(); + // Inside the budget a probe timeout keeps its own closed cause. + now = deadline - 1; + expect(reason(live.signal)).toBe("probe-timeout"); + // A probe clipped to the remaining budget times out exactly at its end. + now = deadline; + expect(reason(live.signal)).toBe("storage-budget"); + now = deadline + 30_000; + expect(reason(live.signal)).toBe("storage-budget"); + // Cancellation is never reported as budget exhaustion. + const cancelled = new AbortController(); + cancelled.abort(); + expect( + nativeComposeStorageCarrierBudgetReason({ + error: new NativeComposeOwnershipError( + "E_NATIVE_COMPOSE_PROBE_CANCELLED" + ), + signal: cancelled.signal, + deadline, + now: () => now, + }) + ).toBe("probe-cancel"); +}); + +test("an exhausted xattr carrier lifetime refuses with the storage budget reason", () => { + const artifact: NativeComposeStorageXattrArtifact = { + version: 1, + imageId: `sha256:${"a".repeat(64)}`, + platform: "linux/arm64", + bunVersion: "1.4.2", + bunHash: "b".repeat(64), + libcHash: "c".repeat(64), + helperHash: "e".repeat(64), + kernelAbi: 1, + }; + const ports = { + inspect: async () => refuseNativeComposeStorageXattr(), + invoke: async () => refuseNativeComposeStorageXattr(), + }; + const start = Date.now(); + const deadline = start + 1000; + const live = new AbortController(); + const carrier = captureNativeComposeStorageXattrCarrier({ + artifact, + ports, + signal: live.signal, + deadline, + }); + const cancelled = new AbortController(); + const aborted = captureNativeComposeStorageXattrCarrier({ + artifact, + ports, + signal: cancelled.signal, + deadline, + }); + cancelled.abort(); + const clock = spyOn(Date, "now").mockImplementation(() => deadline); + try { + const caught = (() => { + try { + checkNativeComposeStorageXattrCarrierLifetime(carrier); + } catch (error: unknown) { + return error; + } + })(); + expect((caught as Error).message).toBe( + "Native storage xattr proof refused; values omitted." + ); + expect(nativeComposeEffectReason(caught)).toBe("storage-budget"); + const stopped = (() => { + try { + checkNativeComposeStorageXattrCarrierLifetime(aborted); + } catch (error: unknown) { + return error; + } + })(); + expect(stopped).toBeInstanceOf(Error); + expect(nativeComposeEffectReason(stopped)).toBe("unclassified"); + } finally { + clock.mockRestore(); + } +}); diff --git a/tests/native-compose-storage-witness-xattr-owner.test.ts b/tests/native-compose-storage-witness-xattr-owner.test.ts index 8c1dd21f..2073dd0e 100644 --- a/tests/native-compose-storage-witness-xattr-owner.test.ts +++ b/tests/native-compose-storage-witness-xattr-owner.test.ts @@ -56,6 +56,7 @@ import { } from "../src/lib/native-compose-storage-witness-xattr-carrier.ts"; import { encodeNativeComposeStorageXattrResponse } from "../src/lib/native-compose-storage-witness-xattr-codec.ts"; import { runNativeComposeStorageXattrHelper } from "../src/lib/native-compose-storage-witness-xattr-helper.ts"; +import { restoreEnv } from "./helpers/env.ts"; import { commandReaderFixture } from "./helpers/native-compose-storage-command-fixture.ts"; const engineId = "d".repeat(64); @@ -660,6 +661,54 @@ test("completion publication refusal retains its first boundary after complete h expect(saved.storageWitnesses?.[0]?.state).toBe("expected"); }); +test.each([ + ["unset", undefined, 90_000], + ["configured", "240000", 240_000], +] as const)("command storage carriers use the %s named storage budget, never a short start budget", async (_label, configured, expected) => { + const { store, transport } = await rememberedActive(); + const command = commandPorts(transport); + const deadlines: { readonly deadline: number; readonly from: number }[] = []; + const carrier = command.ports.carrier; + const ports = { + ...command.ports, + carrier: async (opts: { + readonly signal: AbortSignal; + readonly deadline: number; + }) => { + deadlines.push({ deadline: opts.deadline, from: Date.now() }); + return await carrier(opts); + }, + }; + const oldStartup = process.env.HACK_COMPOSE_STARTUP_TIMEOUT_MS; + const oldStorage = process.env.HACK_NATIVE_STORAGE_TIMEOUT_MS; + restoreEnv("HACK_COMPOSE_STARTUP_TIMEOUT_MS", "15000"); + restoreEnv("HACK_NATIVE_STORAGE_TIMEOUT_MS", configured); + try { + await store.withMutation(async (mutation) => { + const before = Date.now(); + const storage = await prepareNativeComposeCommandStorage({ + store, + mutation, + operation: "up", + selected: [selection], + signal: transport.controller.signal, + ports, + }); + expect(storage).not.toBeNull(); + expect(deadlines.length).toBeGreaterThanOrEqual(2); + for (const { deadline, from } of deadlines) { + // Each carrier deadline is taken when it is created, from the storage + // budget alone: never the 15 s start budget the command was given. + expect(deadline).toBeGreaterThanOrEqual(before + expected); + expect(deadline).toBeLessThanOrEqual(from + expected); + } + }); + } finally { + restoreEnv("HACK_COMPOSE_STARTUP_TIMEOUT_MS", oldStartup); + restoreEnv("HACK_NATIVE_STORAGE_TIMEOUT_MS", oldStorage); + } +}); + test.each([ "up", "restart", diff --git a/tests/native-networks-fixture.test.ts b/tests/native-networks-fixture.test.ts index b831b34d..62bf795c 100644 --- a/tests/native-networks-fixture.test.ts +++ b/tests/native-networks-fixture.test.ts @@ -18,10 +18,12 @@ import { dirname, join } from "node:path"; import { humanBoundary, humanClosedCode, + NATIVE_NETWORK_FIXTURE_SCENARIO_TIMEOUT, NATIVE_NETWORK_PROBE_EXIT, nativeNetworkFixtureAttachmentMatches, nativeNetworkFixtureCensus, nativeNetworkFixtureCommandDiagnostic, + nativeNetworkFixtureCommandTimeout, nativeNetworkFixtureCreateArgs, nativeNetworkFixtureFailureLabel, nativeNetworkFixtureHasNoPublication, @@ -45,6 +47,42 @@ import { runNativeNetworkFixtureCommand, } from "./e2e/native-config-networks-acceptance.ts"; +test("whole-run and cleanup budgets gate command starts and never clip an in-flight command", () => { + const started = 1_000_000; + const budget = NATIVE_NETWORK_FIXTURE_SCENARIO_TIMEOUT; + // Measured hosted passes reach 3494 s; the named budget keeps margin above it. + expect(budget).toBe(90 * 60_000); + expect(budget).toBeGreaterThanOrEqual(1.5 * 3_494_000); + for (const now of [started, started + 3_494_000, started + budget - 1]) { + // A command started one millisecond before the budget still gets its full + // own timeout instead of being killed when the whole-run budget expires. + expect( + nativeNetworkFixtureCommandTimeout({ started, cleanupStarted: null, now }) + ).toBe(180_000); + } + for (const now of [started + budget, started + budget + 1]) { + expect(() => + nativeNetworkFixtureCommandTimeout({ started, cleanupStarted: null, now }) + ).toThrow("Network scenario exceeded its whole-run budget"); + } + // Cleanup keeps its own start gate after the whole-run budget is spent. + const cleanupStarted = started + budget + 60_000; + expect( + nativeNetworkFixtureCommandTimeout({ + started, + cleanupStarted, + now: cleanupStarted + 3 * 60_000 - 1, + }) + ).toBe(180_000); + expect(() => + nativeNetworkFixtureCommandTimeout({ + started, + cleanupStarted, + now: cleanupStarted + 3 * 60_000, + }) + ).toThrow("Network scenario exceeded its cleanup budget"); +}); + test("preserved user container comparison permits only mount ordering", () => { const mount = { Type: "bind",