From 44496c28f778d0bc1ab38955c86ee00d54a74498 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Wed, 9 Sep 2026 14:04:15 +0200 Subject: [PATCH 1/9] fix(ios): budget cold toolchain probes for the first-exec signature stall xcodebuild/xcrun toolchain probes in cache-identity.ts and runner-cache-metadata.ts were budgeted for a warm toolchain (10s/5s), below the ~18-19s syspolicyd signature-verification stall on the first exec after a fresh macOS host boots. Share one 30s floor constant between both call sites and retry once after a timeout while the deadline allows, since the second exec is instant. Closes #2422 --- .../__tests__/runner-cache-metadata.test.ts | 54 +++++++++++++ .../src/runner/runner-cache-metadata.ts | 42 ++++++++-- .../snapshot-source/cache-identity.test.ts | 80 +++++++++++++++++++ .../src/snapshot-source/cache-identity.ts | 53 ++++++++++-- .../src/toolchain-probe-budget.ts | 16 ++++ 5 files changed, 234 insertions(+), 11 deletions(-) create mode 100644 packages/platform-apple/src/snapshot-source/cache-identity.test.ts create mode 100644 packages/platform-apple/src/toolchain-probe-budget.ts diff --git a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts index dbcba191fe..3314626255 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts @@ -240,6 +240,60 @@ test('a timed-out probe leaves the toolchain unavailable instead of a comparable assert.deepEqual(unavailableProbes(), [{ probe: 'xcodebuild -version', reason: 'probe_error' }]); }); +// Apple's syspolicyd signature scan blocks the first xcodebuild/xcrun exec +// after a fresh macOS host boots for roughly 18 to 19 seconds; the immediate +// next exec of the same tool is instant (#2422). These two cases exercise +// the resulting one-retry policy without waiting on a real cold-start stall. +// They use device fixtures untouched by the tests above so the toolchain +// fingerprint cache starts empty for each. + +test('a cold-start toolchain probe recovers on retry: the first call exceeds the budget, the second returns immediately', () => { + let xcodebuildAttempts = 0; + runCmdSync.mockImplementation((command: string, args: readonly string[]) => { + if (command === 'xcodebuild') { + xcodebuildAttempts += 1; + if (xcodebuildAttempts === 1) { + throw new AppError('COMMAND_FAILED', 'xcodebuild timed out after 30000ms', { + timeoutMs: 30_000, + }); + } + } + return appleToolchainProbeResult(command, args); + }); + runCmdSync.mockClear(); + + const metadata = resolveExpectedRunnerCacheMetadata(IOS_DEVICE); + + assert.equal(metadata.xcodeVersion, '26.2'); + assert.equal(metadata.xcodeBuildVersion, '17C52'); + expect(runCmdSync.mock.calls.filter(([command]) => command === 'xcodebuild')).toHaveLength(2); +}); + +test('a toolchain host that never returns still fails at the deadline with the same timeout error', () => { + runCmdSync.mockImplementation((command: string, args: readonly string[]) => { + if (command === 'xcodebuild') { + throw new AppError('COMMAND_FAILED', 'xcodebuild timed out after 30000ms', { + timeoutMs: 30_000, + }); + } + return appleToolchainProbeResult(command, args); + }); + runCmdSync.mockClear(); + + try { + resolveExpectedRunnerCacheMetadata(MACOS_DEVICE); + assert.fail('expected an always-timing-out toolchain probe to fail the cache decision'); + } catch (error) { + assert.ok(error instanceof AppError); + assert.equal(error.code, 'COMMAND_FAILED'); + assert.equal(error.details?.retriable, true); + expect(error.message).toContain('xcodebuild -version'); + expect(error.message).toContain('xcodebuild timed out after 30000ms'); + } + // Exactly one retry, not an unbounded loop: the original attempt plus one retry. + expect(runCmdSync.mock.calls.filter(([command]) => command === 'xcodebuild')).toHaveLength(2); +}); + test('a failing probe reports its exit status rather than a fabricated SDK version', () => { runCmdSync.mockImplementation((command: string, args: readonly string[]) => command === 'xcrun' diff --git a/packages/platform-apple/src/runner/runner-cache-metadata.ts b/packages/platform-apple/src/runner/runner-cache-metadata.ts index a0461ad244..31d34f9f43 100644 --- a/packages/platform-apple/src/runner/runner-cache-metadata.ts +++ b/packages/platform-apple/src/runner/runner-cache-metadata.ts @@ -18,13 +18,13 @@ import { resolveRunnerSdkName, } from './apple-runner-platform.ts'; import { computeRunnerSourceFingerprint } from './runner-source.ts'; +import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../toolchain-probe-budget.ts'; const DEFAULT_IOS_RUNNER_APP_BUNDLE_ID = 'com.callstack.agentdevice.runner'; const RUNNER_DERIVED_ROOT = path.join(os.homedir(), '.agent-device', 'apple-runner'); export const RUNNER_CACHE_METADATA_FILE = '.agent-device-runner-cache.json'; const RUNNER_CACHE_SCHEMA_VERSION = 2; const RUNNER_CACHE_METADATA_VALUE_MAX_LENGTH = 300; -const TOOLCHAIN_PROBE_TIMEOUT_MS = 5_000; const TOOLCHAIN_PROBE_MAX_BUFFER = 128 * 1024; const TOOLCHAIN_PROBE_DETAIL_MAX_LENGTH = 200; const TOOLCHAIN_PROBE_HINT = @@ -223,11 +223,7 @@ function runToolchainProbe(cmd: string, args: string[]): ProbeResult { const probe = [cmd, ...args].join(' '); let output: { exitCode: number; stdout: string; stderr: string }; try { - output = runCmdSync(cmd, args, { - allowFailure: true, - timeoutMs: TOOLCHAIN_PROBE_TIMEOUT_MS, - maxBuffer: TOOLCHAIN_PROBE_MAX_BUFFER, - }); + output = runToolchainProbeCommand(cmd, args); } catch (error) { return probeFailure(probe, 'probe_error', error instanceof Error ? error.message : `${error}`); } @@ -242,6 +238,40 @@ function runToolchainProbe(cmd: string, args: string[]): ProbeResult { return value ? { ok: true, value } : probeFailure(probe, 'empty_output', 'no output'); } +/** + * Runs one toolchain probe, retrying exactly once if the attempt times out. + * Apple's syspolicyd signature scan blocks the first `xcodebuild`/`xcrun` + * exec after a fresh host boots (see COLD_TOOLCHAIN_PROBE_TIMEOUT_MS); the + * immediate next exec of the same tool is instant, so the retry recovers + * without widening the per-call budget. + */ +function runToolchainProbeCommand( + cmd: string, + args: string[], +): { exitCode: number; stdout: string; stderr: string } { + try { + return execToolchainProbeCommand(cmd, args); + } catch (error) { + if (!isToolchainProbeTimeout(error)) throw error; + return execToolchainProbeCommand(cmd, args); + } +} + +function execToolchainProbeCommand( + cmd: string, + args: string[], +): { exitCode: number; stdout: string; stderr: string } { + return runCmdSync(cmd, args, { + allowFailure: true, + timeoutMs: COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, + maxBuffer: TOOLCHAIN_PROBE_MAX_BUFFER, + }); +} + +function isToolchainProbeTimeout(error: unknown): boolean { + return error instanceof Error && /timed out after \d+ms/.test(error.message); +} + function parseXcodeVersionOutput( output: ProbeResult, ): ProbeResult<{ version: string; buildVersion: string }> { diff --git a/packages/platform-apple/src/snapshot-source/cache-identity.test.ts b/packages/platform-apple/src/snapshot-source/cache-identity.test.ts new file mode 100644 index 0000000000..744be2a785 --- /dev/null +++ b/packages/platform-apple/src/snapshot-source/cache-identity.test.ts @@ -0,0 +1,80 @@ +import assert from 'node:assert/strict'; +import { test } from 'vitest'; +import { AppError } from '@agent-device/kernel/errors'; +import { createSnapshotSourceHost } from './host.ts'; +import { readSnapshotSourceToolchain } from './cache-identity.ts'; +import { createSnapshotSourceDeadline } from './deadline.ts'; +import type { SnapshotSourceHost } from './types.ts'; + +// Apple's syspolicyd signature scan blocks the first xcodebuild/xcrun exec +// after a fresh macOS host boots for roughly 18 to 19 seconds; the immediate +// next exec of the same tool is instant (#2422). These cases exercise the +// resulting one-retry policy without waiting on a real cold-start stall. + +test('a cold-start toolchain probe recovers on retry: the first call exceeds the budget, the second returns immediately', async () => { + let calls = 0; + const host = fakeToolchainHost((command, args) => { + calls += 1; + if (calls === 1) { + throw new AppError('COMMAND_FAILED', `${command} timed out after 30000ms`, { + timeoutMs: 30_000, + }); + } + return toolchainAnswer(command, args); + }); + + const identity = await readSnapshotSourceToolchain( + host, + 'iOS 26.2', + createSnapshotSourceDeadline(120_000, undefined), + ); + + assert.equal(identity.xcode, 'Xcode 26.2\nBuild version 17C52'); + assert.equal(identity.macosBuild, '24G90'); + assert.equal(identity.architecture, 'arm64'); + assert.equal(identity.simulatorSdk, '26.2'); + // 5 baseline probes (xcodebuild, sw_vers x2, uname, xcrun) plus the one + // retry that recovered the first, timed-out call. + assert.equal(calls, 6); +}); + +test('a toolchain host that never returns still fails at the deadline with the same timeout error', async () => { + const host = fakeToolchainHost((command) => { + throw new AppError('COMMAND_FAILED', `${command} timed out after 30000ms`, { + timeoutMs: 30_000, + }); + }); + + await assert.rejects( + readSnapshotSourceToolchain(host, 'iOS 26.2', createSnapshotSourceDeadline(120_000, undefined)), + (error: unknown) => + error instanceof AppError && error.message === 'xcodebuild timed out after 30000ms', + ); +}); + +function toolchainAnswer( + command: string, + args: string[], +): { stdout: string; stderr: string; exitCode: number } { + const stdout = + command === 'xcodebuild' + ? 'Xcode 26.2\nBuild version 17C52' + : command === 'sw_vers' + ? args.includes('-buildVersion') + ? '24G90' + : '15.6' + : command === 'uname' + ? 'arm64' + : '26.2'; + return { stdout, stderr: '', exitCode: 0 }; +} + +function fakeToolchainHost( + run: (command: string, args: string[]) => { stdout: string; stderr: string; exitCode: number }, +): SnapshotSourceHost { + const real = createSnapshotSourceHost(); + return { + ...real, + run: async (command, args) => run(command, args), + }; +} diff --git a/packages/platform-apple/src/snapshot-source/cache-identity.ts b/packages/platform-apple/src/snapshot-source/cache-identity.ts index 0d1fd09f89..797804c590 100644 --- a/packages/platform-apple/src/snapshot-source/cache-identity.ts +++ b/packages/platform-apple/src/snapshot-source/cache-identity.ts @@ -1,8 +1,10 @@ import { createHash } from 'node:crypto'; import path from 'node:path'; +import type { ExecResult } from '@agent-device/host-kit/command'; import { snapshotSourceError } from './errors.ts'; import { remainingSnapshotSourceMs, type SnapshotSourceDeadline } from './deadline.ts'; import type { SnapshotSourceHost } from './types.ts'; +import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../toolchain-probe-budget.ts'; export type SnapshotSourceToolchainIdentity = Readonly<{ xcode: string; @@ -84,11 +86,7 @@ async function toolOutput( args: string[], deadline: SnapshotSourceDeadline, ): Promise { - const result = await host.run(command, args, { - allowFailure: true, - signal: deadline.signal, - timeoutMs: Math.min(10_000, remainingSnapshotSourceMs(deadline, 'toolchain-probe-deadline')), - }); + const result = await runToolchainProbe(host, command, args, deadline); if (result.exitCode !== 0) { throw snapshotSourceError('unsupported', 'toolchain-probe-failed', { command, @@ -100,3 +98,48 @@ async function toolOutput( if (!output) throw snapshotSourceError('unsupported', 'toolchain-probe-empty', { command }); return output; } + +/** + * Runs one toolchain probe, retrying exactly once if the attempt times out + * and the deadline still has room. The retry absorbs the cold-start + * signature-verification stall named on COLD_TOOLCHAIN_PROBE_TIMEOUT_MS: the + * first exec of a tool on a fresh host can block for that long, but the + * immediate next exec of the same tool is instant. + */ +async function runToolchainProbe( + host: SnapshotSourceHost, + command: string, + args: string[], + deadline: SnapshotSourceDeadline, +): Promise { + try { + return await execToolchainProbe(host, command, args, deadline); + } catch (error) { + if (!isToolchainProbeTimeout(error) || !toolchainProbeDeadlineHasRoom(deadline)) throw error; + return await execToolchainProbe(host, command, args, deadline); + } +} + +function execToolchainProbe( + host: SnapshotSourceHost, + command: string, + args: string[], + deadline: SnapshotSourceDeadline, +): Promise { + return host.run(command, args, { + allowFailure: true, + signal: deadline.signal, + timeoutMs: Math.min( + COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, + remainingSnapshotSourceMs(deadline, 'toolchain-probe-deadline'), + ), + }); +} + +function toolchainProbeDeadlineHasRoom(deadline: SnapshotSourceDeadline): boolean { + return !deadline.signal?.aborted && deadline.clock.remainingMs() > 0; +} + +function isToolchainProbeTimeout(error: unknown): boolean { + return error instanceof Error && /timed out after \d+ms/.test(error.message); +} diff --git a/packages/platform-apple/src/toolchain-probe-budget.ts b/packages/platform-apple/src/toolchain-probe-budget.ts new file mode 100644 index 0000000000..c61d6f3fae --- /dev/null +++ b/packages/platform-apple/src/toolchain-probe-budget.ts @@ -0,0 +1,16 @@ +/** + * Per-call timeout for a toolchain identity probe (`xcodebuild -version`, + * `xcrun --show-sdk-version`, `sw_vers`, `uname`, …). On a fresh macOS host, + * Apple's syspolicyd signature scan blocks the very first `xcodebuild`/ + * `xcrun`/large-binary exec after boot for roughly 18 to 19 seconds at 0% + * CPU; the second exec of the same tool is instant. A budget sized for a + * warm toolchain (the old 10 s / 5 s split) trips on that cold-start stall + * and reports a bogus toolchain-probe timeout unrelated to the change under + * test (#2422). + * + * `snapshot-source/cache-identity.ts` and `runner/runner-cache-metadata.ts` + * both read this one constant for their per-call budget, and both retry + * once after a timeout while their deadline still allows it, so the two + * budgets cannot drift apart again. + */ +export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; From ab8130a5d4530f4152f93eb3cea7b0fa89aa93d0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Wed, 9 Sep 2026 14:24:03 +0200 Subject: [PATCH 2/9] fix(apple): duplicate the cold-toolchain-probe budget instead of a shared module toolchain-probe-budget.ts sat outside every platform-apple facade's eager closure, but runner-cache-metadata.ts (imported from it) sits inside all seven -- so the new import added one module to each, tripping the eager-closure-budgets no-growth gate (#2422). Delete the shared module. cache-identity.ts keeps the canonical constant inline (it was already outside the gated closures); runner-cache-metadata.ts declares its own copy, guarded by a new unit test that asserts the two stay equal. --- .../__tests__/runner-cache-metadata.test.ts | 11 ++++++++++ .../src/runner/runner-cache-metadata.ts | 16 +++++++++++++- .../src/snapshot-source/cache-identity.ts | 22 ++++++++++++++++++- .../src/toolchain-probe-budget.ts | 16 -------------- 4 files changed, 47 insertions(+), 18 deletions(-) delete mode 100644 packages/platform-apple/src/toolchain-probe-budget.ts diff --git a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts index 3314626255..93cd16befa 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts @@ -3,6 +3,7 @@ import assert from 'node:assert/strict'; import { AppError } from '@agent-device/kernel/errors'; import { IOS_DEVICE, IOS_SIMULATOR, MACOS_DEVICE } from './device-fixtures.ts'; import { + COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, diffComparableRunnerCacheMetadata, resolveRunnerBundleBuildSettings, resolveRunnerMaxConcurrentDestinationsFlag, @@ -11,10 +12,20 @@ import { resolveRunnerSandboxBuildArgs, resolveExpectedRunnerCacheMetadata, } from '../runner-cache-metadata.ts'; +import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS as SNAPSHOT_SOURCE_COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../../snapshot-source/cache-identity.ts'; import { appleToolchainProbeResult, stubAppleToolchainProbes } from './apple-toolchain-fixtures.ts'; const runCmdSync = stubAppleToolchainProbes(); +// This file's COLD_TOOLCHAIN_PROBE_TIMEOUT_MS is a deliberate local copy of +// snapshot-source/cache-identity.ts's constant of the same name, not an +// import of it -- see the doc comment on the export in +// runner-cache-metadata.ts for why. This test is what keeps the two values +// from drifting apart (#2422). +test('COLD_TOOLCHAIN_PROBE_TIMEOUT_MS matches the copy in snapshot-source/cache-identity.ts', () => { + assert.equal(COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, SNAPSHOT_SOURCE_COLD_TOOLCHAIN_PROBE_TIMEOUT_MS); +}); + test('resolveRunnerMaxConcurrentDestinationsFlag uses simulator flag for simulators', () => { assert.equal( resolveRunnerMaxConcurrentDestinationsFlag(IOS_SIMULATOR), diff --git a/packages/platform-apple/src/runner/runner-cache-metadata.ts b/packages/platform-apple/src/runner/runner-cache-metadata.ts index 31d34f9f43..e1707558d5 100644 --- a/packages/platform-apple/src/runner/runner-cache-metadata.ts +++ b/packages/platform-apple/src/runner/runner-cache-metadata.ts @@ -18,13 +18,27 @@ import { resolveRunnerSdkName, } from './apple-runner-platform.ts'; import { computeRunnerSourceFingerprint } from './runner-source.ts'; -import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../toolchain-probe-budget.ts'; const DEFAULT_IOS_RUNNER_APP_BUNDLE_ID = 'com.callstack.agentdevice.runner'; const RUNNER_DERIVED_ROOT = path.join(os.homedir(), '.agent-device', 'apple-runner'); export const RUNNER_CACHE_METADATA_FILE = '.agent-device-runner-cache.json'; const RUNNER_CACHE_SCHEMA_VERSION = 2; const RUNNER_CACHE_METADATA_VALUE_MAX_LENGTH = 300; + +/** + * Per-call timeout for a toolchain identity probe (`xcodebuild -version`, + * `xcrun --show-sdk-version`, …). Must equal `COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` + * in `../snapshot-source/cache-identity.ts` -- both absorb the same ~18 to + * 19 second syspolicyd signature-scan stall on the first `xcodebuild`/ + * `xcrun` exec after a fresh macOS host boots (#2422). It is declared here + * rather than imported from that module because this file sits in every + * platform-apple façade's eager closure and `snapshot-source/*` does not + * (`scripts/__tests__/eager-closure-budgets.ts`); a unit test + * (`__tests__/runner-cache-metadata.test.ts`) asserts the two constants stay + * equal so they cannot drift apart. + */ +export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; + const TOOLCHAIN_PROBE_MAX_BUFFER = 128 * 1024; const TOOLCHAIN_PROBE_DETAIL_MAX_LENGTH = 200; const TOOLCHAIN_PROBE_HINT = diff --git a/packages/platform-apple/src/snapshot-source/cache-identity.ts b/packages/platform-apple/src/snapshot-source/cache-identity.ts index 797804c590..3e05fcbb8b 100644 --- a/packages/platform-apple/src/snapshot-source/cache-identity.ts +++ b/packages/platform-apple/src/snapshot-source/cache-identity.ts @@ -4,7 +4,27 @@ import type { ExecResult } from '@agent-device/host-kit/command'; import { snapshotSourceError } from './errors.ts'; import { remainingSnapshotSourceMs, type SnapshotSourceDeadline } from './deadline.ts'; import type { SnapshotSourceHost } from './types.ts'; -import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../toolchain-probe-budget.ts'; + +/** + * Per-call timeout for a toolchain identity probe (`xcodebuild -version`, + * `xcrun --show-sdk-version`, `sw_vers`, `uname`, …). On a fresh macOS host, + * Apple's syspolicyd signature scan blocks the very first `xcodebuild`/ + * `xcrun`/large-binary exec after boot for roughly 18 to 19 seconds at 0% + * CPU; the second exec of the same tool is instant. A budget sized for a + * warm toolchain (the old 10 s / 5 s split) trips on that cold-start stall + * and reports a bogus toolchain-probe timeout unrelated to the change under + * test (#2422). + * + * `runner/runner-cache-metadata.ts` needs this same budget but cannot import + * it from here: this module is outside every platform-apple façade's eager + * closure today, and importing it from `runner-cache-metadata.ts` would pull + * `snapshot-source/*` into all of them (`scripts/__tests__/eager-closure- + * budgets.ts`). It instead declares its own copy of this constant, checked + * against this one for equality by a unit test + * (`runner/__tests__/runner-cache-metadata.test.ts`) so the two cannot drift + * apart. + */ +export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; export type SnapshotSourceToolchainIdentity = Readonly<{ xcode: string; diff --git a/packages/platform-apple/src/toolchain-probe-budget.ts b/packages/platform-apple/src/toolchain-probe-budget.ts deleted file mode 100644 index c61d6f3fae..0000000000 --- a/packages/platform-apple/src/toolchain-probe-budget.ts +++ /dev/null @@ -1,16 +0,0 @@ -/** - * Per-call timeout for a toolchain identity probe (`xcodebuild -version`, - * `xcrun --show-sdk-version`, `sw_vers`, `uname`, …). On a fresh macOS host, - * Apple's syspolicyd signature scan blocks the very first `xcodebuild`/ - * `xcrun`/large-binary exec after boot for roughly 18 to 19 seconds at 0% - * CPU; the second exec of the same tool is instant. A budget sized for a - * warm toolchain (the old 10 s / 5 s split) trips on that cold-start stall - * and reports a bogus toolchain-probe timeout unrelated to the change under - * test (#2422). - * - * `snapshot-source/cache-identity.ts` and `runner/runner-cache-metadata.ts` - * both read this one constant for their per-call budget, and both retry - * once after a timeout while their deadline still allows it, so the two - * budgets cannot drift apart again. - */ -export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; From 4372274a038768e1224612e3506afc711f9f6b41 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Wed, 9 Sep 2026 16:56:31 +0200 Subject: [PATCH 3/9] fix(apple): bound the cold toolchain probes by the owning request budget Three synchronous probes could each retry once at 30 s, so a wedged toolchain host blocked a request for ~180 s with no deadline and no cancellation check. The runner cache decision now takes the owning request's budget (remaining ms + abort signal) and builds one clock per fingerprint read: every attempt runs at min(per-call ceiling, remaining), the retry is skipped once the budget is spent, an exhausted budget fails the decision without starting another probe, and an aborted signal surfaces the cancellation instead of retrying. `ensureXctestrunArtifact` passes the build budget and signal, session reuse passes the startup budget and the request signal, and lease adoption passes the startup budget; a caller with neither is still capped at 45 s total, so the worst case falls from ~180 s to 45 s. Error codes, texts, and the probe hint are unchanged. Both retry classifiers now read the exec layer's structured timeout detail instead of matching "timed out after Nms" in the message. The predicate is exported once from host-kit's command surface and reaches `runner-cache-metadata.ts` through the Apple runner host port, so the file's eager closure is unchanged. Tests use a fake clock that only advances when a probe actually blocks for the timeout it was given, so the exhausted-budget and cancellation cases have to spend the budget to pass; both consumers also pin that an error saying "timed out after 10ms" without the structured detail is not retried. Refs #2422 --- packages/host-kit/src/command.ts | 1 + packages/host-kit/src/internal/exec.test.ts | 35 +++ packages/host-kit/src/internal/exec.ts | 16 ++ .../platform-apple/src/core/runner-host.ts | 2 + .../__tests__/runner-cache-metadata.test.ts | 217 ++++++++++++++---- packages/platform-apple/src/runner/host.ts | 8 + .../src/runner/runner-adoption.ts | 15 +- .../src/runner/runner-artifact.ts | 8 +- .../src/runner/runner-cache-metadata.ts | 144 +++++++++--- .../src/runner/runner-session.ts | 9 +- .../src/runner/runner-xctestrun.ts | 1 + .../snapshot-source/cache-identity.test.ts | 22 ++ .../src/snapshot-source/cache-identity.ts | 14 +- 13 files changed, 405 insertions(+), 87 deletions(-) diff --git a/packages/host-kit/src/command.ts b/packages/host-kit/src/command.ts index 8c56f2d0ed..95e68a8f5a 100644 --- a/packages/host-kit/src/command.ts +++ b/packages/host-kit/src/command.ts @@ -7,6 +7,7 @@ export { execFailureDetails, type ExecOptions, type ExecResult, + isCommandTimeoutError, isExecutablePath, requireExecSuccess, resolveExecutableOverridePath, diff --git a/packages/host-kit/src/internal/exec.test.ts b/packages/host-kit/src/internal/exec.test.ts index dfd8dc0af4..6273a3c457 100644 --- a/packages/host-kit/src/internal/exec.test.ts +++ b/packages/host-kit/src/internal/exec.test.ts @@ -5,6 +5,7 @@ import path from 'node:path'; import { flushDiagnosticsToSessionFile, withDiagnosticsScope } from './diagnostics.ts'; import { coerceExecResult, + isCommandTimeoutError, requireExecSuccess, runCmd, runCmdBackground, @@ -424,3 +425,37 @@ test('coerceExecResult repairs loosely-typed provider results and keeps typed on } as unknown as ExecResult); assert.deepEqual(loose, { stdout: '', stderr: '42', exitCode: 1 }); }); + +test('isCommandTimeoutError reads the structured timeout, not the message text', async () => { + const killedAtTimeout = await runCmd(process.execPath, ['-e', 'setTimeout(() => {}, 10_000)'], { + timeoutMs: 50, + }).then( + () => null, + (error: unknown) => error, + ); + assert.ok(isCommandTimeoutError(killedAtTimeout)); + + assert.ok( + isCommandTimeoutError( + (() => { + try { + runCmdSync(process.execPath, ['-e', 'setTimeout(() => {}, 10_000)'], { timeoutMs: 50 }); + return null; + } catch (error) { + return error; + } + })(), + ), + ); + + // A tool that failed on its own and said "timed out" in its output: same + // code, same wording, no timeout we imposed. + assert.equal( + isCommandTimeoutError( + new AppError('COMMAND_FAILED', 'xcodebuild timed out after 10ms', { cmd: 'xcodebuild' }), + ), + false, + ); + assert.equal(isCommandTimeoutError(new Error('timed out after 10ms')), false); + assert.equal(isCommandTimeoutError(undefined), false); +}); diff --git a/packages/host-kit/src/internal/exec.ts b/packages/host-kit/src/internal/exec.ts index 0e71f66f1a..b31187c8fc 100644 --- a/packages/host-kit/src/internal/exec.ts +++ b/packages/host-kit/src/internal/exec.ts @@ -592,6 +592,22 @@ function createTimeoutError( }); } +/** + * True only for the COMMAND_FAILED error this module raises when it kills a + * command at its own `timeoutMs` — the structured signal both timeout sites + * above stamp on `details.timeoutMs`. Callers that retry a timed-out command + * classify with this instead of matching the message text, so a command whose + * own output happens to say "timed out after 10ms" is not mistaken for a + * timeout the exec layer imposed. + */ +export function isCommandTimeoutError(error: unknown): boolean { + return ( + error instanceof AppError && + error.code === 'COMMAND_FAILED' && + typeof error.details?.timeoutMs === 'number' + ); +} + function createExitError( executable: string, cmd: string, diff --git a/packages/platform-apple/src/core/runner-host.ts b/packages/platform-apple/src/core/runner-host.ts index d09e13b1fb..6ef48432c9 100644 --- a/packages/platform-apple/src/core/runner-host.ts +++ b/packages/platform-apple/src/core/runner-host.ts @@ -3,6 +3,7 @@ import { publishFileSync, acquireProcessLock } from '@agent-device/host-kit/file import { resolveIosSimulatorDeviceSetPath } from '@agent-device/kernel/device-isolation'; import { + isCommandTimeoutError, requireExecSuccess, runCmdBackground, runCmdStreaming, @@ -55,6 +56,7 @@ export const appleRunnerHost: AppleRunnerHost = { runCmdSync, runCmdBackground, requireExecSuccess, + isCommandTimeoutError, emitDiagnostic, withDiagnosticTimer, retryWithPolicy, diff --git a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts index 93cd16befa..4074351e4b 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts @@ -1,7 +1,10 @@ -import { expect, test } from 'vitest'; +import { beforeEach, describe, expect, test } from 'vitest'; import assert from 'node:assert/strict'; -import { AppError } from '@agent-device/kernel/errors'; +import { AppError, isRequestCanceledError } from '@agent-device/kernel/errors'; +import { resetAllProcessMemosForTests } from '@agent-device/kernel/ttl-memo'; import { IOS_DEVICE, IOS_SIMULATOR, MACOS_DEVICE } from './device-fixtures.ts'; +import { appleRunnerTestHost } from '../test-host.ts'; +import type { ExecOptions } from '../host.ts'; import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, diffComparableRunnerCacheMetadata, @@ -253,58 +256,182 @@ test('a timed-out probe leaves the toolchain unavailable instead of a comparable // Apple's syspolicyd signature scan blocks the first xcodebuild/xcrun exec // after a fresh macOS host boots for roughly 18 to 19 seconds; the immediate -// next exec of the same tool is instant (#2422). These two cases exercise -// the resulting one-retry policy without waiting on a real cold-start stall. -// They use device fixtures untouched by the tests above so the toolchain -// fingerprint cache starts empty for each. +// next exec of the same tool is instant (#2422). These cases exercise the +// resulting one-retry policy, and the budget that bounds it, without waiting +// on a real cold-start stall: the fake clock only moves when a probe actually +// blocks for the timeout it was given, so a case that claims the budget was +// spent had to spend it. +describe('toolchain probe budget', () => { + // Failures are never memoized, but the recovery case below succeeds; each + // case starts from an empty toolchain fingerprint cache so none of them + // reads another's answer. + beforeEach(resetAllProcessMemosForTests); + + test('a cold-start probe recovers on retry, and the stall it survived is charged to the budget', () => { + const clock = installFakeToolchainClock(); + const xcodebuildTimeouts: number[] = []; + runCmdSync.mockImplementation((command: string, args: string[], options: ExecOptions) => { + if (command !== 'xcodebuild') return appleToolchainProbeResult(command, args); + xcodebuildTimeouts.push(options.timeoutMs ?? 0); + if (xcodebuildTimeouts.length > 1) return appleToolchainProbeResult(command, args); + throw blockForWholeTimeout(clock, command, args, options); + }); + runCmdSync.mockClear(); + + const metadata = resolveExpectedRunnerCacheMetadata(IOS_DEVICE); + + assert.equal(metadata.xcodeVersion, '26.2'); + assert.equal(metadata.xcodeBuildVersion, '17C52'); + // The retry runs on what the shared budget has left, not on a fresh + // per-call ceiling: 45 s total minus the 30 s the first attempt burned. + assert.deepEqual(xcodebuildTimeouts, [COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, 15_000]); + }); -test('a cold-start toolchain probe recovers on retry: the first call exceeds the budget, the second returns immediately', () => { - let xcodebuildAttempts = 0; - runCmdSync.mockImplementation((command: string, args: readonly string[]) => { - if (command === 'xcodebuild') { - xcodebuildAttempts += 1; - if (xcodebuildAttempts === 1) { - throw new AppError('COMMAND_FAILED', 'xcodebuild timed out after 30000ms', { - timeoutMs: 30_000, - }); - } - } - return appleToolchainProbeResult(command, args); + test('a toolchain host that never returns stops at the shared budget instead of once per probe', () => { + const clock = installFakeToolchainClock(); + runCmdSync.mockImplementation((command: string, args: string[], options: ExecOptions) => { + throw blockForWholeTimeout(clock, command, args, options); + }); + runCmdSync.mockClear(); + + assert.throws( + () => resolveExpectedRunnerCacheMetadata(MACOS_DEVICE), + (error: unknown) => { + assert.ok(error instanceof AppError); + assert.equal(error.code, 'COMMAND_FAILED'); + assert.equal(error.details?.reason, 'apple_toolchain_probe_unavailable'); + assert.equal(error.details?.retriable, true); + expect(error.details?.hint).toContain('xcode-select -p'); + expect(error.message).toContain('xcodebuild -version'); + // The reported failure is the last attempt: 30 s, then the 15 s the + // budget still had. + expect(error.message).toContain('xcodebuild timed out after 15000ms'); + expect(error.message).toContain('request budget'); + return true; + }, + ); + // 30 s + a 15 s retry spends the whole budget on the first probe; the two + // xcrun probes then fail on the budget instead of blocking for 30 s each. + assert.equal(runCmdSync.mock.calls.length, 2); + assert.equal(clock.nowMs, 45_000); }); - runCmdSync.mockClear(); - const metadata = resolveExpectedRunnerCacheMetadata(IOS_DEVICE); + test('an owning request with 4 s left gets one 4 s attempt and no retry', () => { + const clock = installFakeToolchainClock(); + runCmdSync.mockImplementation((command: string, args: string[], options: ExecOptions) => { + throw blockForWholeTimeout(clock, command, args, options); + }); + runCmdSync.mockClear(); + + assert.throws( + () => resolveExpectedRunnerCacheMetadata(IOS_SIMULATOR, undefined, { timeoutMs: 4_000 }), + (error: unknown) => { + assert.ok(error instanceof AppError); + assert.equal(error.details?.reason, 'apple_toolchain_probe_unavailable'); + expect(error.message).toContain('xcodebuild timed out after 4000ms'); + expect(error.message).toContain('request budget'); + return true; + }, + ); + assert.equal(runCmdSync.mock.calls.length, 1); + assert.equal(clock.nowMs, 4_000); + }); - assert.equal(metadata.xcodeVersion, '26.2'); - assert.equal(metadata.xcodeBuildVersion, '17C52'); - expect(runCmdSync.mock.calls.filter(([command]) => command === 'xcodebuild')).toHaveLength(2); -}); + test('a request canceled while a probe blocked surfaces the cancellation instead of retrying', () => { + const clock = installFakeToolchainClock(); + const request = new AbortController(); + runCmdSync.mockImplementation((command: string, args: string[], options: ExecOptions) => { + const timeout = blockForWholeTimeout(clock, command, args, options); + request.abort(); + throw timeout; + }); + runCmdSync.mockClear(); + + assert.throws( + () => + resolveExpectedRunnerCacheMetadata(IOS_SIMULATOR, undefined, { signal: request.signal }), + (error: unknown) => isRequestCanceledError(error), + ); + assert.equal(runCmdSync.mock.calls.length, 1); + }); -test('a toolchain host that never returns still fails at the deadline with the same timeout error', () => { - runCmdSync.mockImplementation((command: string, args: readonly string[]) => { - if (command === 'xcodebuild') { - throw new AppError('COMMAND_FAILED', 'xcodebuild timed out after 30000ms', { - timeoutMs: 30_000, - }); - } - return appleToolchainProbeResult(command, args); + test('an already-canceled request runs no toolchain probe at all', () => { + installFakeToolchainClock(); + runCmdSync.mockClear(); + + assert.throws( + () => + resolveExpectedRunnerCacheMetadata(IOS_SIMULATOR, undefined, { + signal: AbortSignal.abort(), + }), + (error: unknown) => isRequestCanceledError(error), + ); + assert.equal(runCmdSync.mock.calls.length, 0); }); - runCmdSync.mockClear(); - try { - resolveExpectedRunnerCacheMetadata(MACOS_DEVICE); - assert.fail('expected an always-timing-out toolchain probe to fail the cache decision'); - } catch (error) { - assert.ok(error instanceof AppError); - assert.equal(error.code, 'COMMAND_FAILED'); - assert.equal(error.details?.retriable, true); - expect(error.message).toContain('xcodebuild -version'); - expect(error.message).toContain('xcodebuild timed out after 30000ms'); - } - // Exactly one retry, not an unbounded loop: the original attempt plus one retry. - expect(runCmdSync.mock.calls.filter(([command]) => command === 'xcodebuild')).toHaveLength(2); + test('a probe that failed on its own and merely says "timed out" in its message is not retried', () => { + installFakeToolchainClock(); + runCmdSync.mockImplementation((command: string, args: string[]) => { + if (command !== 'xcodebuild') return appleToolchainProbeResult(command, args); + // No `timeoutMs` detail: this is the tool reporting its own failure, not + // the exec layer killing it at a timeout we asked for. + throw new AppError('COMMAND_FAILED', 'xcodebuild timed out after 10ms', { + cmd: command, + args, + }); + }); + runCmdSync.mockClear(); + + assert.throws( + () => resolveExpectedRunnerCacheMetadata(IOS_SIMULATOR), + (error: unknown) => { + assert.ok(error instanceof AppError); + expect(error.message).toContain('xcodebuild timed out after 10ms'); + return true; + }, + ); + expect(runCmdSync.mock.calls.filter(([command]) => command === 'xcodebuild')).toHaveLength(1); + }); }); +/** + * A clock the probes' own budget reads, advanced only by + * {@link blockForWholeTimeout}. Without it a mock that throws immediately + * proves nothing about a deadline: no time passes, so every budget looks + * untouched however many attempts run. + */ +function installFakeToolchainClock(): { nowMs: number } { + const clock = { nowMs: 0 }; + appleRunnerTestHost.update({ + deadlineFromTimeoutMs: (timeoutMs: number) => { + const startedAtMs = clock.nowMs; + const expiresAtMs = startedAtMs + Math.max(0, timeoutMs); + return { + remainingMs: () => Math.max(0, expiresAtMs - clock.nowMs), + elapsedMs: () => Math.max(0, clock.nowMs - startedAtMs), + isExpired: () => expiresAtMs - clock.nowMs <= 0, + }; + }, + }); + return clock; +} + +/** A probe that blocked for its whole timeout and was then killed, as the exec layer reports it. */ +function blockForWholeTimeout( + clock: { nowMs: number }, + command: string, + args: string[], + options: ExecOptions, +): AppError { + const timeoutMs = options.timeoutMs ?? 0; + clock.nowMs += timeoutMs; + return new AppError('COMMAND_FAILED', `${command} timed out after ${timeoutMs}ms`, { + cmd: command, + args, + timeoutMs, + }); +} + test('a failing probe reports its exit status rather than a fabricated SDK version', () => { runCmdSync.mockImplementation((command: string, args: readonly string[]) => command === 'xcrun' diff --git a/packages/platform-apple/src/runner/host.ts b/packages/platform-apple/src/runner/host.ts index 66ddb41f45..11e318d113 100644 --- a/packages/platform-apple/src/runner/host.ts +++ b/packages/platform-apple/src/runner/host.ts @@ -149,6 +149,12 @@ export type AppleRunnerHost = { message: string, extra?: Record | ((result: ExecResult) => Record), ): ExecResult; + /** + * True only for the error the exec layer raises when it killed a command at + * the `timeoutMs` the caller asked for, read from the structured detail it + * stamps rather than from the message text. + */ + isCommandTimeoutError(error: unknown): boolean; // Diagnostics (@agent-device/host-kit/diagnostics) emitDiagnostic(event: DiagnosticEventInput): void; withDiagnosticTimer( @@ -277,6 +283,8 @@ export const runCmdBackground: AppleRunnerHost['runCmdBackground'] = (cmd, args, requireHost().runCmdBackground(cmd, args, options); export const requireExecSuccess: AppleRunnerHost['requireExecSuccess'] = (result, message, extra) => requireHost().requireExecSuccess(result, message, extra); +export const isCommandTimeoutError: AppleRunnerHost['isCommandTimeoutError'] = (error) => + requireHost().isCommandTimeoutError(error); export const emitDiagnostic: AppleRunnerHost['emitDiagnostic'] = (event) => requireHost().emitDiagnostic(event); export const withDiagnosticTimer = ( diff --git a/packages/platform-apple/src/runner/runner-adoption.ts b/packages/platform-apple/src/runner/runner-adoption.ts index d82bd1a09d..f67073162d 100644 --- a/packages/platform-apple/src/runner/runner-adoption.ts +++ b/packages/platform-apple/src/runner/runner-adoption.ts @@ -19,6 +19,7 @@ import { import { resolveExpectedRunnerCacheMetadata, resolveRunnerDerivedPath, + type RunnerCacheProbeBudget, type RunnerXctestrunArtifact, } from './runner-xctestrun.ts'; import { @@ -86,7 +87,9 @@ export async function tryAdoptRunnerSessionFromLease( if (!verifyLeaseRunnerPidIdentity(lease, runnerPid)) { return skip('runner_pid_recycled'); } - const expectedDerived = resolveExpectedDerivedPath(device); + const expectedDerived = resolveExpectedDerivedPath(device, { + timeoutMs: options.startupTimeoutMs, + }); if (!expectedDerived) return skip('expected_derived_unresolved'); if (!lease.xctestrunPath.startsWith(`${expectedDerived}${path.sep}`)) { return skip('artifact_fingerprint_mismatch'); @@ -134,9 +137,15 @@ async function probeRunnerAnswersUptime(device: DeviceInfo, port: number): Promi } } -function resolveExpectedDerivedPath(device: DeviceInfo): string | null { +function resolveExpectedDerivedPath( + device: DeviceInfo, + budget: RunnerCacheProbeBudget, +): string | null { try { - return resolveRunnerDerivedPath(device, resolveExpectedRunnerCacheMetadata(device)); + return resolveRunnerDerivedPath( + device, + resolveExpectedRunnerCacheMetadata(device, undefined, budget), + ); } catch { return null; } diff --git a/packages/platform-apple/src/runner/runner-artifact.ts b/packages/platform-apple/src/runner/runner-artifact.ts index b80182ed52..084e6050b9 100644 --- a/packages/platform-apple/src/runner/runner-artifact.ts +++ b/packages/platform-apple/src/runner/runner-artifact.ts @@ -83,7 +83,13 @@ export async function ensureXctestrunArtifact( if (external) return external; const projectRoot = findProjectRoot(); - const expectedCacheMetadata = resolveExpectedRunnerCacheMetadata(device, projectRoot); + // The cache decision runs blocking toolchain probes before any build starts, + // so it spends this request's build budget and must answer to it: the same + // deadline and abort signal the build itself would get (#2422). + const expectedCacheMetadata = resolveExpectedRunnerCacheMetadata(device, projectRoot, { + timeoutMs: options.buildTimeoutMs, + signal: options.signal, + }); const derived = resolveRunnerDerivedPath(device, expectedCacheMetadata); return await withKeyedLock(runnerXctestrunBuildLocks, derived, async () => { const releaseCacheLock = await acquireRunnerXctestrunCacheLock(derived); diff --git a/packages/platform-apple/src/runner/runner-cache-metadata.ts b/packages/platform-apple/src/runner/runner-cache-metadata.ts index e1707558d5..826dafa4b6 100644 --- a/packages/platform-apple/src/runner/runner-cache-metadata.ts +++ b/packages/platform-apple/src/runner/runner-cache-metadata.ts @@ -2,9 +2,11 @@ import crypto from 'node:crypto'; import os from 'node:os'; import path from 'node:path'; import { isMacOs, type DeviceInfo } from '@agent-device/kernel/device'; -import { AppError } from '@agent-device/kernel/errors'; +import { AppError, createRequestCanceledError } from '@agent-device/kernel/errors'; import { createTtlMemo, + Deadline, + isCommandTimeoutError, isEnvTruthy, findProjectRoot, readVersion, @@ -26,8 +28,9 @@ const RUNNER_CACHE_SCHEMA_VERSION = 2; const RUNNER_CACHE_METADATA_VALUE_MAX_LENGTH = 300; /** - * Per-call timeout for a toolchain identity probe (`xcodebuild -version`, - * `xcrun --show-sdk-version`, …). Must equal `COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` + * Ceiling on one toolchain identity probe attempt (`xcodebuild -version`, + * `xcrun --show-sdk-version`, …); the owning request's remaining budget can + * cap an attempt lower. Must equal `COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` * in `../snapshot-source/cache-identity.ts` -- both absorb the same ~18 to * 19 second syspolicyd signature-scan stall on the first `xcodebuild`/ * `xcrun` exec after a fresh macOS host boots (#2422). It is declared here @@ -39,6 +42,19 @@ const RUNNER_CACHE_METADATA_VALUE_MAX_LENGTH = 300; */ export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; +/** + * Ceiling on the wall clock the whole toolchain fingerprint may spend, across + * all three probes and their retries, when the owning request carries no + * shorter budget. Sized for the one cold-start stall the retry exists for -- + * a single stalled probe (up to {@link COLD_TOOLCHAIN_PROBE_TIMEOUT_MS}) plus + * its now-warm retry and the two remaining probes -- not for three + * independently stalling tools, which is why the per-call timeout alone is not + * the bound (#2422). + */ +const TOOLCHAIN_FINGERPRINT_BUDGET_MS = 45_000; + +const TOOLCHAIN_PROBE_BUDGET_EXHAUSTED_DETAIL = + 'the request budget for reading the toolchain was exhausted before this probe could run'; const TOOLCHAIN_PROBE_MAX_BUFFER = 128 * 1024; const TOOLCHAIN_PROBE_DETAIL_MAX_LENGTH = 200; const TOOLCHAIN_PROBE_HINT = @@ -67,6 +83,59 @@ type ToolchainProbeFailure = { detail: string; }; +/** + * What the request that wants a runner cache decision has left to spend on it. + * The decision blocks the calling request on up to three synchronous `spawnSync` + * probes, so the request's own deadline and cancellation must reach them: an + * exhausted budget fails the decision instead of starting another 30 second + * probe, and a canceled request surfaces the cancellation rather than + * retrying (#2422). A caller with neither still gets + * {@link TOOLCHAIN_FINGERPRINT_BUDGET_MS} as the ceiling. + * + * `spawnSync` cannot be interrupted once it has started, so cancellation is + * observed between attempts; the per-attempt cap is what bounds how long that + * takes. + */ +export type RunnerCacheProbeBudget = { + /** Milliseconds the owning request has left, if it carries a deadline. */ + timeoutMs?: number; + /** The owning request's cancellation signal, if it carries one. */ + signal?: AbortSignal; +}; + +/** + * The remaining-time and cancellation view the probes consult. One is created + * per fingerprint read, so the three probes and their retries share -- and + * together cannot exceed -- a single budget. + */ +type ToolchainProbeClock = { + /** Milliseconds the next attempt may block for; 0 once the budget is spent. */ + attemptTimeoutMs(): number; + /** Throws the owning request's cancellation error once it has aborted. */ + throwIfCanceled(): void; +}; + +function createToolchainProbeClock( + budget: RunnerCacheProbeBudget | undefined, +): ToolchainProbeClock { + const ownerRemainingMs = + budget?.timeoutMs !== undefined && Number.isFinite(budget.timeoutMs) + ? Math.max(0, budget.timeoutMs) + : Number.POSITIVE_INFINITY; + const deadline = Deadline.fromTimeoutMs( + Math.min(TOOLCHAIN_FINGERPRINT_BUDGET_MS, ownerRemainingMs), + ); + return { + attemptTimeoutMs: () => + Math.min(COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, Math.floor(deadline.remainingMs())), + throwIfCanceled: () => { + if (budget?.signal?.aborted) { + throw createRequestCanceledError({ phase: 'apple_toolchain_probe' }); + } + }, + }; +} + type ProbeResult = | { ok: true; value: Value } | { ok: false; failure: ToolchainProbeFailure }; @@ -139,13 +208,14 @@ export const IOS_RUNNER_CONTAINER_BUNDLE_IDS: string[] = resolveRunnerContainerB export function resolveExpectedRunnerCacheMetadata( device: DeviceInfo, projectRoot: string = findProjectRoot(), + budget?: RunnerCacheProbeBudget, ): RunnerXctestrunCacheMetadata { const platformName = resolveRunnerPlatformName(device); return { schemaVersion: RUNNER_CACHE_SCHEMA_VERSION, packageVersion: readVersion(projectRoot), runnerSourceFingerprint: computeRunnerSourceFingerprint(projectRoot), - ...requireRunnerToolchainFingerprint(resolveRunnerSdkName(platformName, device.kind)), + ...requireRunnerToolchainFingerprint(resolveRunnerSdkName(platformName, device.kind), budget), platformName, deviceKind: device.kind, target: device.target ?? 'mobile', @@ -177,10 +247,13 @@ function toolchainFingerprintCache(): TtlMemo { +function runToolchainProbe( + cmd: string, + args: string[], + clock: ToolchainProbeClock, +): ProbeResult { const probe = [cmd, ...args].join(' '); + // Both checks are outside the try: a canceled request is the caller's own + // error to see, and an exhausted budget must not start another blocking + // spawnSync just to time out again. + clock.throwIfCanceled(); + if (clock.attemptTimeoutMs() <= 0) { + return probeFailure(probe, 'probe_error', TOOLCHAIN_PROBE_BUDGET_EXHAUSTED_DETAIL); + } let output: { exitCode: number; stdout: string; stderr: string }; try { - output = runToolchainProbeCommand(cmd, args); + output = runToolchainProbeCommand(cmd, args, clock); } catch (error) { + clock.throwIfCanceled(); return probeFailure(probe, 'probe_error', error instanceof Error ? error.message : `${error}`); } if (output.exitCode !== 0) { @@ -253,39 +339,41 @@ function runToolchainProbe(cmd: string, args: string[]): ProbeResult { } /** - * Runs one toolchain probe, retrying exactly once if the attempt times out. - * Apple's syspolicyd signature scan blocks the first `xcodebuild`/`xcrun` - * exec after a fresh host boots (see COLD_TOOLCHAIN_PROBE_TIMEOUT_MS); the - * immediate next exec of the same tool is instant, so the retry recovers - * without widening the per-call budget. + * Runs one toolchain probe, retrying exactly once if the attempt timed out and + * the shared budget still has room. Apple's syspolicyd signature scan blocks + * the first `xcodebuild`/`xcrun` exec after a fresh host boots (see + * COLD_TOOLCHAIN_PROBE_TIMEOUT_MS); the immediate next exec of the same tool is + * instant, so the retry recovers without widening the per-call budget. Only the + * exec layer's structured timeout is retried -- a tool that failed on its own + * and merely said "timed out" in its output is not this stall. */ function runToolchainProbeCommand( cmd: string, args: string[], + clock: ToolchainProbeClock, ): { exitCode: number; stdout: string; stderr: string } { try { - return execToolchainProbeCommand(cmd, args); + return execToolchainProbeCommand(cmd, args, clock); } catch (error) { - if (!isToolchainProbeTimeout(error)) throw error; - return execToolchainProbeCommand(cmd, args); + if (!isCommandTimeoutError(error)) throw error; + clock.throwIfCanceled(); + if (clock.attemptTimeoutMs() <= 0) throw error; + return execToolchainProbeCommand(cmd, args, clock); } } function execToolchainProbeCommand( cmd: string, args: string[], + clock: ToolchainProbeClock, ): { exitCode: number; stdout: string; stderr: string } { return runCmdSync(cmd, args, { allowFailure: true, - timeoutMs: COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, + timeoutMs: clock.attemptTimeoutMs(), maxBuffer: TOOLCHAIN_PROBE_MAX_BUFFER, }); } -function isToolchainProbeTimeout(error: unknown): boolean { - return error instanceof Error && /timed out after \d+ms/.test(error.message); -} - function parseXcodeVersionOutput( output: ProbeResult, ): ProbeResult<{ version: string; buildVersion: string }> { diff --git a/packages/platform-apple/src/runner/runner-session.ts b/packages/platform-apple/src/runner/runner-session.ts index 15864c0798..46923ec6f5 100644 --- a/packages/platform-apple/src/runner/runner-session.ts +++ b/packages/platform-apple/src/runner/runner-session.ts @@ -24,6 +24,7 @@ import { prepareXctestrunWithEnv, resolveExpectedRunnerCacheMetadata, resolveRunnerDerivedPath, + type RunnerCacheProbeBudget, } from './runner-xctestrun.ts'; import { resolveRunnerRequestSignal, @@ -112,7 +113,10 @@ export async function ensureRunnerSession( const existing = runnerSessions.get(device.id); if (existing) { assertExpectedRunnerSession(existing, options.expectedRunnerSessionId); - const reusable = await resolveReusableRunnerSession(device, existing); + const reusable = await resolveReusableRunnerSession(device, existing, { + timeoutMs: options.startupTimeoutMs, + signal: resolveRunnerRequestSignal(options), + }); if (reusable) return reusable; } @@ -307,6 +311,7 @@ function runnerSessionOwnershipChanged(): AppError { async function resolveReusableRunnerSession( device: DeviceInfo, existing: RunnerSession, + cacheProbeBudget: RunnerCacheProbeBudget, ): Promise { if (!isRunnerProcessAlive(existing.child.pid)) { await measureRunnerStartupStep({}, 'stop_stale_session', async () => { @@ -336,7 +341,7 @@ async function resolveReusableRunnerSession( const expectedDerived = resolveRunnerDerivedPath( device, - resolveExpectedRunnerCacheMetadata(device), + resolveExpectedRunnerCacheMetadata(device, undefined, cacheProbeBudget), ); if (existingArtifact?.derived !== expectedDerived) { emitDiagnostic({ diff --git a/packages/platform-apple/src/runner/runner-xctestrun.ts b/packages/platform-apple/src/runner/runner-xctestrun.ts index 7d19f11b29..eae7fcbe0e 100644 --- a/packages/platform-apple/src/runner/runner-xctestrun.ts +++ b/packages/platform-apple/src/runner/runner-xctestrun.ts @@ -16,5 +16,6 @@ export { resolveExpectedRunnerCacheMetadata, resolveRunnerAppBundleId, resolveRunnerDerivedPath, + type RunnerCacheProbeBudget, } from './runner-cache-metadata.ts'; export { acquireXcodebuildSimulatorSetRedirect } from './runner-device-set.ts'; diff --git a/packages/platform-apple/src/snapshot-source/cache-identity.test.ts b/packages/platform-apple/src/snapshot-source/cache-identity.test.ts index 744be2a785..c9a15b7605 100644 --- a/packages/platform-apple/src/snapshot-source/cache-identity.test.ts +++ b/packages/platform-apple/src/snapshot-source/cache-identity.test.ts @@ -39,7 +39,9 @@ test('a cold-start toolchain probe recovers on retry: the first call exceeds the }); test('a toolchain host that never returns still fails at the deadline with the same timeout error', async () => { + let calls = 0; const host = fakeToolchainHost((command) => { + calls += 1; throw new AppError('COMMAND_FAILED', `${command} timed out after 30000ms`, { timeoutMs: 30_000, }); @@ -50,6 +52,26 @@ test('a toolchain host that never returns still fails at the deadline with the s (error: unknown) => error instanceof AppError && error.message === 'xcodebuild timed out after 30000ms', ); + // Exactly one retry, not an unbounded loop. + assert.equal(calls, 2); +}); + +test('a probe that failed on its own and merely says "timed out" in its message is not retried', async () => { + let calls = 0; + const host = fakeToolchainHost((command) => { + calls += 1; + // No `timeoutMs` detail: the tool reported its own failure, the exec layer + // did not kill it at a timeout we asked for. Retrying that just doubles a + // failure the retry cannot fix. + throw new AppError('COMMAND_FAILED', `${command} timed out after 10ms`, { cmd: command }); + }); + + await assert.rejects( + readSnapshotSourceToolchain(host, 'iOS 26.2', createSnapshotSourceDeadline(120_000, undefined)), + (error: unknown) => + error instanceof AppError && error.message === 'xcodebuild timed out after 10ms', + ); + assert.equal(calls, 1); }); function toolchainAnswer( diff --git a/packages/platform-apple/src/snapshot-source/cache-identity.ts b/packages/platform-apple/src/snapshot-source/cache-identity.ts index 3e05fcbb8b..dca3907520 100644 --- a/packages/platform-apple/src/snapshot-source/cache-identity.ts +++ b/packages/platform-apple/src/snapshot-source/cache-identity.ts @@ -1,6 +1,6 @@ import { createHash } from 'node:crypto'; import path from 'node:path'; -import type { ExecResult } from '@agent-device/host-kit/command'; +import { isCommandTimeoutError, type ExecResult } from '@agent-device/host-kit/command'; import { snapshotSourceError } from './errors.ts'; import { remainingSnapshotSourceMs, type SnapshotSourceDeadline } from './deadline.ts'; import type { SnapshotSourceHost } from './types.ts'; @@ -120,11 +120,13 @@ async function toolOutput( } /** - * Runs one toolchain probe, retrying exactly once if the attempt times out + * Runs one toolchain probe, retrying exactly once if the attempt timed out * and the deadline still has room. The retry absorbs the cold-start * signature-verification stall named on COLD_TOOLCHAIN_PROBE_TIMEOUT_MS: the * first exec of a tool on a fresh host can block for that long, but the - * immediate next exec of the same tool is instant. + * immediate next exec of the same tool is instant. Only the exec layer's own + * structured timeout counts -- a tool that failed by itself and merely said + * "timed out" in its output is not this stall and is not retried. */ async function runToolchainProbe( host: SnapshotSourceHost, @@ -135,7 +137,7 @@ async function runToolchainProbe( try { return await execToolchainProbe(host, command, args, deadline); } catch (error) { - if (!isToolchainProbeTimeout(error) || !toolchainProbeDeadlineHasRoom(deadline)) throw error; + if (!isCommandTimeoutError(error) || !toolchainProbeDeadlineHasRoom(deadline)) throw error; return await execToolchainProbe(host, command, args, deadline); } } @@ -159,7 +161,3 @@ function execToolchainProbe( function toolchainProbeDeadlineHasRoom(deadline: SnapshotSourceDeadline): boolean { return !deadline.signal?.aborted && deadline.clock.remainingMs() > 0; } - -function isToolchainProbeTimeout(error: unknown): boolean { - return error instanceof Error && /timed out after \d+ms/.test(error.message); -} From 0a258ee1875adaadf8cec5b517bfb5878e4928d7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Wed, 9 Sep 2026 22:23:39 +0200 Subject: [PATCH 4/9] fix(apple): spend one deadline across the toolchain probes and the step they precede The Apple runner cache decision runs up to three blocking toolchain probes before the step that needs the decision. Those probes were handed the phase's timeout and the step was then handed the same number again, so a cold-start probe stall added its 30 to 45 seconds on top of the phase budget instead of coming out of it. RunnerCacheProbeBudget now carries the phase's deadline rather than a timeout number, and each caller creates exactly one: - ensureXctestrunArtifact: the probes and xcodebuild read the same clock, and a phase with nothing left fails before the spawn. - ensureRunnerSession: the reuse probe spends from the startup clock, and the new session gets what it left. - tryAdoptRunnerSessionFromLease: the fingerprint probe spends from the caller's clock, and the adopted session gets the remainder. COLD_TOOLCHAIN_PROBE_TIMEOUT_MS now has one owner, core/config.ts. Snapshot source imports it; runner-cache-metadata reads it through the Apple runner host port, because core/config.ts is missing from one of the seven eager closures that evaluate that file and a direct import would grow it. createSnapshotSourceDeadline takes an injectable clock so a test can prove that a probe which blocked for its whole timeout leaves the retry only the remainder. --- packages/platform-apple/src/core/config.ts | 17 ++ .../platform-apple/src/core/runner-host.ts | 2 + .../runner-artifact-phase-budget.test.ts | 145 ++++++++++++++++++ .../__tests__/runner-cache-metadata.test.ts | 21 +-- .../runner/__tests__/runner-client.test.ts | 2 +- packages/platform-apple/src/runner/host.ts | 11 ++ .../src/runner/runner-adoption.ts | 26 +++- .../src/runner/runner-artifact.ts | 82 ++++++---- .../src/runner/runner-cache-metadata.ts | 103 +++++++++---- .../platform-apple/src/runner/runner-cache.ts | 3 + .../src/runner/runner-session.ts | 25 ++- .../src/runner/runner-xctestrun.ts | 3 + .../snapshot-source/cache-identity.test.ts | 90 ++++++++--- .../src/snapshot-source/cache-identity.ts | 34 ++-- .../src/snapshot-source/deadline.ts | 12 +- 15 files changed, 435 insertions(+), 141 deletions(-) create mode 100644 packages/platform-apple/src/runner/__tests__/runner-artifact-phase-budget.test.ts diff --git a/packages/platform-apple/src/core/config.ts b/packages/platform-apple/src/core/config.ts index 47e87c1718..177e0d69d7 100644 --- a/packages/platform-apple/src/core/config.ts +++ b/packages/platform-apple/src/core/config.ts @@ -23,3 +23,20 @@ export const IOS_RUNNER_SCREENSHOT_COPY_TIMEOUT_MS = 20_000; export const IOS_SIMULATOR_SCREENSHOT_RETRY_MAX_ATTEMPTS = 5; export const IOS_SIMULATOR_SCREENSHOT_RETRY_BASE_DELAY_MS = 1_000; export const IOS_SIMULATOR_SCREENSHOT_RETRY_MAX_DELAY_MS = 5_000; + +/** + * Ceiling on one Apple toolchain identity probe attempt (`xcodebuild -version`, + * `xcrun --show-sdk-version`, `sw_vers`, `uname`, …). On a fresh macOS host, + * Apple's syspolicyd signature scan blocks the very first `xcodebuild`/`xcrun`/ + * large-binary exec after boot for roughly 18 to 19 seconds at 0% CPU; the + * second exec of the same tool is instant. A budget sized for a warm toolchain + * (the old 10 s / 5 s split) trips on that cold-start stall and reports a bogus + * toolchain-probe timeout unrelated to the change under test (#2422). + * + * Both toolchain probers read this one value. `snapshot-source/cache-identity.ts` + * imports it from here; `runner/runner-cache-metadata.ts` reads it through the + * Apple runner host port instead, because that file sits in every Apple façade's + * eager import closure and may not add a module to it + * (`scripts/__tests__/eager-closure-budgets.test.ts`). + */ +export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; diff --git a/packages/platform-apple/src/core/runner-host.ts b/packages/platform-apple/src/core/runner-host.ts index 6ef48432c9..3b12313e2f 100644 --- a/packages/platform-apple/src/core/runner-host.ts +++ b/packages/platform-apple/src/core/runner-host.ts @@ -35,6 +35,7 @@ import { } from '@agent-device/host-kit/request'; import { bootFailureHint, classifyBootFailure } from '@agent-device/provision-kit/boot-diagnostics'; +import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from './config.ts'; import { resolveIosPhysicalDeviceControl } from './physical-device-control.ts'; import { visitXmlPlistEntries } from './plist-xml.ts'; import { @@ -57,6 +58,7 @@ export const appleRunnerHost: AppleRunnerHost = { runCmdBackground, requireExecSuccess, isCommandTimeoutError, + coldToolchainProbeTimeoutMs: () => COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, emitDiagnostic, withDiagnosticTimer, retryWithPolicy, diff --git a/packages/platform-apple/src/runner/__tests__/runner-artifact-phase-budget.test.ts b/packages/platform-apple/src/runner/__tests__/runner-artifact-phase-budget.test.ts new file mode 100644 index 0000000000..f641aa4814 --- /dev/null +++ b/packages/platform-apple/src/runner/__tests__/runner-artifact-phase-budget.test.ts @@ -0,0 +1,145 @@ +import assert from 'node:assert/strict'; +import fs from 'node:fs'; +import path from 'node:path'; +import { afterEach, beforeEach, test, vi } from 'vitest'; +import { AppError } from '@agent-device/kernel/errors'; +import { resetAllProcessMemosForTests } from '@agent-device/kernel/ttl-memo'; +import { appleRunnerTestHost } from '../test-host.ts'; +import type { ExecOptions, ExecResult, ExecStreamOptions } from '../host.ts'; +import { ensureXctestrunArtifact } from '../runner-xctestrun.ts'; +import { appleToolchainProbeResult } from './apple-toolchain-fixtures.ts'; +import { MACOS_DEVICE } from './device-fixtures.ts'; +import { mkdtempForTestSync } from './tmp-dir.ts'; + +/** + * The build phase spends one budget, not two (#2422). + * + * `ensureXctestrunArtifact` runs the cache decision's blocking toolchain probes + * before it starts `xcodebuild`. Those probes used to be handed + * `buildTimeoutMs` and the build was then handed the same number again, so a + * cold-start probe stall added its 30 to 45 seconds on top of the phase budget + * instead of coming out of it. These cases pin the shared deadline: the clock + * moves only when a probe actually blocks for the timeout it was handed, so a + * case that claims the budget was spent had to spend it. + */ + +const clock = { nowMs: 0 }; +const runCmdSync = vi.fn(); +const runCmdStreaming = vi.fn(); +let projectRoot: string; + +beforeEach(() => { + resetAllProcessMemosForTests(); + clock.nowMs = 0; + projectRoot = mkdtempForTestSync('agent-device-runner-phase-root-'); + // `buildXctestrunArtifact` refuses to start a build without the runner project. + fs.mkdirSync( + path.join(projectRoot, 'apple', 'runner', 'AgentDeviceRunner', 'AgentDeviceRunner.xcodeproj'), + { recursive: true }, + ); + process.env.AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH = mkdtempForTestSync( + 'agent-device-runner-phase-derived-', + ); + runCmdSync.mockReset().mockImplementation(appleToolchainProbeResult); + runCmdStreaming + .mockReset() + .mockImplementation(async (): Promise => ({ exitCode: 0, stdout: '', stderr: '' })); + appleRunnerTestHost.update({ + runCmdSync, + runCmdStreaming, + findProjectRoot: () => projectRoot, + readVersion: () => '0.0.0-test', + deadlineFromTimeoutMs: (timeoutMs: number) => { + const startedAtMs = clock.nowMs; + const expiresAtMs = startedAtMs + Math.max(0, timeoutMs); + return { + remainingMs: () => Math.max(0, expiresAtMs - clock.nowMs), + elapsedMs: () => Math.max(0, clock.nowMs - startedAtMs), + isExpired: () => expiresAtMs - clock.nowMs <= 0, + }; + }, + }); +}); + +afterEach(() => { + delete process.env.AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH; +}); + +test('a warm toolchain leaves the build the whole phase budget', async () => { + await assert.rejects( + ensureXctestrunArtifact(MACOS_DEVICE, { buildTimeoutMs: 120_000 }), + missingXctestrun, + ); + + assert.equal(clock.nowMs, 0); + assert.equal(buildTimeoutMsGiven(), 120_000); +}); + +test('a cold-start probe stall comes out of the build budget instead of being added to it', async () => { + let xcodebuildProbes = 0; + runCmdSync.mockImplementation((command: string, args: string[], options: ExecOptions) => { + // The syspolicyd stall: the first `xcodebuild` exec blocks for the whole + // timeout it was handed, the immediate next one answers at once. + xcodebuildProbes += command === 'xcodebuild' ? 1 : 0; + if (xcodebuildProbes === 1 && command === 'xcodebuild') { + throw blockForWholeTimeout(command, options); + } + return appleToolchainProbeResult(command, args); + }); + + await assert.rejects( + ensureXctestrunArtifact(MACOS_DEVICE, { buildTimeoutMs: 120_000 }), + missingXctestrun, + ); + + // 30 s of stall, absorbed by the retry -- and charged to the phase, so the + // build is given 90 s rather than a second full 120 s. + assert.equal(clock.nowMs, 30_000); + assert.equal(buildTimeoutMsGiven(), 90_000); +}); + +test('a probe that spends the whole phase fails before xcodebuild is spawned', async () => { + runCmdSync.mockImplementation((command: string, args: string[], options: ExecOptions) => { + // The last of the three probes answers, but only after blocking for + // everything the phase had left. + if (args.includes('--show-sdk-build-version')) clock.nowMs += options.timeoutMs ?? 0; + return appleToolchainProbeResult(command, args); + }); + + await assert.rejects( + ensureXctestrunArtifact(MACOS_DEVICE, { buildTimeoutMs: 30_000 }), + (error: unknown) => + error instanceof AppError && + error.details?.reason === 'runner_phase_budget_exhausted' && + error.details?.phase === 'runner_xctestrun_build', + ); + + assert.equal(clock.nowMs, 30_000); + assert.equal(runCmdStreaming.mock.calls.length, 0); +}); + +/** The fake build writes no `.xctestrun`; the budget it was handed is what these cases read. */ +function missingXctestrun(error: unknown): boolean { + return error instanceof AppError && error.message === 'Failed to locate .xctestrun after build'; +} + +function buildTimeoutMsGiven(): number | undefined { + assert.equal(runCmdStreaming.mock.calls.length, 1); + const [command, , options] = runCmdStreaming.mock.calls[0] as [ + string, + string[], + ExecStreamOptions, + ]; + assert.equal(command, 'xcodebuild'); + return options.timeoutMs; +} + +/** A probe that blocked for its whole timeout and was then killed, as the exec layer reports it. */ +function blockForWholeTimeout(command: string, options: ExecOptions): AppError { + const timeoutMs = options.timeoutMs ?? 0; + clock.nowMs += timeoutMs; + return new AppError('COMMAND_FAILED', `${command} timed out after ${timeoutMs}ms`, { + cmd: command, + timeoutMs, + }); +} diff --git a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts index 4074351e4b..f317c57428 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts @@ -6,7 +6,7 @@ import { IOS_DEVICE, IOS_SIMULATOR, MACOS_DEVICE } from './device-fixtures.ts'; import { appleRunnerTestHost } from '../test-host.ts'; import type { ExecOptions } from '../host.ts'; import { - COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, + createRunnerPhaseDeadline, diffComparableRunnerCacheMetadata, resolveRunnerBundleBuildSettings, resolveRunnerMaxConcurrentDestinationsFlag, @@ -15,20 +15,13 @@ import { resolveRunnerSandboxBuildArgs, resolveExpectedRunnerCacheMetadata, } from '../runner-cache-metadata.ts'; -import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS as SNAPSHOT_SOURCE_COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../../snapshot-source/cache-identity.ts'; +// The one owning module for the probe budget: this file's probes reach it +// through the runner host port, snapshot-source imports it directly (#2422). +import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../../core/config.ts'; import { appleToolchainProbeResult, stubAppleToolchainProbes } from './apple-toolchain-fixtures.ts'; const runCmdSync = stubAppleToolchainProbes(); -// This file's COLD_TOOLCHAIN_PROBE_TIMEOUT_MS is a deliberate local copy of -// snapshot-source/cache-identity.ts's constant of the same name, not an -// import of it -- see the doc comment on the export in -// runner-cache-metadata.ts for why. This test is what keeps the two values -// from drifting apart (#2422). -test('COLD_TOOLCHAIN_PROBE_TIMEOUT_MS matches the copy in snapshot-source/cache-identity.ts', () => { - assert.equal(COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, SNAPSHOT_SOURCE_COLD_TOOLCHAIN_PROBE_TIMEOUT_MS); -}); - test('resolveRunnerMaxConcurrentDestinationsFlag uses simulator flag for simulators', () => { assert.equal( resolveRunnerMaxConcurrentDestinationsFlag(IOS_SIMULATOR), @@ -316,15 +309,17 @@ describe('toolchain probe budget', () => { assert.equal(clock.nowMs, 45_000); }); - test('an owning request with 4 s left gets one 4 s attempt and no retry', () => { + test('an owning phase with 4 s left gets one 4 s attempt and no retry', () => { const clock = installFakeToolchainClock(); + const phaseDeadline = createRunnerPhaseDeadline(4_000); runCmdSync.mockImplementation((command: string, args: string[], options: ExecOptions) => { throw blockForWholeTimeout(clock, command, args, options); }); runCmdSync.mockClear(); assert.throws( - () => resolveExpectedRunnerCacheMetadata(IOS_SIMULATOR, undefined, { timeoutMs: 4_000 }), + () => + resolveExpectedRunnerCacheMetadata(IOS_SIMULATOR, undefined, { deadline: phaseDeadline }), (error: unknown) => { assert.ok(error instanceof AppError); assert.equal(error.details?.reason, 'apple_toolchain_probe_unavailable'); diff --git a/packages/platform-apple/src/runner/__tests__/runner-client.test.ts b/packages/platform-apple/src/runner/__tests__/runner-client.test.ts index 2589a940f1..ba9be5f861 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-client.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-client.test.ts @@ -1416,7 +1416,7 @@ test('ensureXctestrunArtifact stress-recovers after a bad restored artifact', as assert.equal(rebuilt.artifact, 'rebuilt'); assert.equal(rebuilt.reason, 'missing_xctestrun'); assert.equal(mockRunCmdStreaming.mock.calls.length, 1); - assert.equal(mockRunCmdStreaming.mock.calls[0]?.[2]?.timeoutMs, 300_000); + assert.equal(Math.ceil(Number(mockRunCmdStreaming.mock.calls[0]?.[2]?.timeoutMs) / 1e3), 300); // phase remainder (#2422) }); test('ensureXctestrunArtifact rethrows unexpected cached macOS runner repair errors', async () => { diff --git a/packages/platform-apple/src/runner/host.ts b/packages/platform-apple/src/runner/host.ts index 11e318d113..4088131653 100644 --- a/packages/platform-apple/src/runner/host.ts +++ b/packages/platform-apple/src/runner/host.ts @@ -155,6 +155,15 @@ export type AppleRunnerHost = { * stamps rather than from the message text. */ isCommandTimeoutError(error: unknown): boolean; + /** + * Ceiling on one toolchain identity probe attempt, in milliseconds + * (`COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` in + * `packages/platform-apple/src/core/config.ts`, which owns it for both + * toolchain probers). It arrives through the port rather than by import so + * the runner's cache-metadata module, which every Apple façade evaluates, + * does not grow its eager import closure to read one number. + */ + coldToolchainProbeTimeoutMs(): number; // Diagnostics (@agent-device/host-kit/diagnostics) emitDiagnostic(event: DiagnosticEventInput): void; withDiagnosticTimer( @@ -285,6 +294,8 @@ export const requireExecSuccess: AppleRunnerHost['requireExecSuccess'] = (result requireHost().requireExecSuccess(result, message, extra); export const isCommandTimeoutError: AppleRunnerHost['isCommandTimeoutError'] = (error) => requireHost().isCommandTimeoutError(error); +export const coldToolchainProbeTimeoutMs: AppleRunnerHost['coldToolchainProbeTimeoutMs'] = () => + requireHost().coldToolchainProbeTimeoutMs(); export const emitDiagnostic: AppleRunnerHost['emitDiagnostic'] = (event) => requireHost().emitDiagnostic(event); export const withDiagnosticTimer = ( diff --git a/packages/platform-apple/src/runner/runner-adoption.ts b/packages/platform-apple/src/runner/runner-adoption.ts index f67073162d..b608c19df0 100644 --- a/packages/platform-apple/src/runner/runner-adoption.ts +++ b/packages/platform-apple/src/runner/runner-adoption.ts @@ -17,9 +17,11 @@ import { type RunnerLease, } from './runner-lease.ts'; import { + requireRunnerPhaseRemainingMs, resolveExpectedRunnerCacheMetadata, resolveRunnerDerivedPath, type RunnerCacheProbeBudget, + type RunnerPhaseDeadline, type RunnerXctestrunArtifact, } from './runner-xctestrun.ts'; import { @@ -50,7 +52,17 @@ export function isIosRunnerDetachEnabled(env: NodeJS.ProcessEnv = process.env): // lock, like the rest of session startup. export async function tryAdoptRunnerSessionFromLease( device: DeviceInfo, - options: { startupTimeoutMs?: number; expectedRunnerSessionId?: string }, + options: { + startupTimeoutMs?: number; + /** + * The startup phase's clock, shared with the caller. The fingerprint check + * below runs the same blocking toolchain probes a fresh startup would, so + * the adopted session must be given what those probes left rather than a + * fresh `startupTimeoutMs` (#2422). + */ + phaseDeadline?: RunnerPhaseDeadline; + expectedRunnerSessionId?: string; + }, ): Promise { if (device.kind !== 'simulator' || !isIosRunnerDetachEnabled()) return null; // Custom simulator sets run behind the XCTestDevices redirect, whose @@ -88,7 +100,7 @@ export async function tryAdoptRunnerSessionFromLease( return skip('runner_pid_recycled'); } const expectedDerived = resolveExpectedDerivedPath(device, { - timeoutMs: options.startupTimeoutMs, + deadline: options.phaseDeadline, }); if (!expectedDerived) return skip('expected_derived_unresolved'); if (!lease.xctestrunPath.startsWith(`${expectedDerived}${path.sep}`)) { @@ -156,7 +168,7 @@ function buildAdoptedRunnerSession( lease: RunnerLease, runnerPid: number, expectedDerived: string, - options: { startupTimeoutMs?: number }, + options: { startupTimeoutMs?: number; phaseDeadline?: RunnerPhaseDeadline }, ): RunnerSession & { lease: RunnerLease } { const sessionId = lease.sessionId; const artifact: RunnerXctestrunArtifact = { @@ -181,7 +193,13 @@ function buildAdoptedRunnerSession( child, // The probe already proved the runner answers commands. ready: true, - startupTimeoutMs: normalizeRunnerStartupTimeoutMs(options.startupTimeoutMs), + startupTimeoutMs: normalizeRunnerStartupTimeoutMs( + requireRunnerPhaseRemainingMs( + options.phaseDeadline, + options.startupTimeoutMs, + 'runner_session_adoption', + ), + ), lease: buildRunnerLease({ deviceId: device.id, sessionId, diff --git a/packages/platform-apple/src/runner/runner-artifact.ts b/packages/platform-apple/src/runner/runner-artifact.ts index 084e6050b9..558426618d 100644 --- a/packages/platform-apple/src/runner/runner-artifact.ts +++ b/packages/platform-apple/src/runner/runner-artifact.ts @@ -19,9 +19,11 @@ import { assertSafeDerivedCleanup, cleanRunnerDerivedArtifacts, cleanRunnerDerivedBeforeEvaluation, + createRunnerPhaseDeadline, emitRunnerXctestrunDecision, emitRunnerXctestrunRebuildDecision, evaluateExistingXctestrun, + requireRunnerPhaseRemainingMs, resolveExpectedRunnerCacheMetadata, resolveRunnerBundleBuildSettings, resolveRunnerDerivedPath, @@ -31,6 +33,7 @@ import { resolveRunnerSigningBuildSettings, writeRunnerCacheMetadataForArtifacts, type ExistingXctestrunState, + type RunnerPhaseDeadline, type RunnerXctestrunCacheKind, type RunnerXctestrunCacheMetadata, } from './runner-cache.ts'; @@ -68,26 +71,33 @@ export type ExternalXctestRunnerOptions = { iosXctestEnvDir?: string; }; +/** What the build phase reads: its budget, where it logs, and how it is canceled. */ +type RunnerXctestrunBuildOptions = { + verbose?: boolean; + logPath?: string; + traceLogPath?: string; + buildTimeoutMs?: number; + signal?: AbortSignal; +}; + export async function ensureXctestrunArtifact( device: DeviceInfo, - options: { - verbose?: boolean; - logPath?: string; - traceLogPath?: string; - buildTimeoutMs?: number; + options: RunnerXctestrunBuildOptions & { forceRunnerXctestrunRebuild?: boolean; - signal?: AbortSignal; } & ExternalXctestRunnerOptions, ): Promise { const external = resolveExternalXctestrunArtifact(options); if (external) return external; const projectRoot = findProjectRoot(); - // The cache decision runs blocking toolchain probes before any build starts, - // so it spends this request's build budget and must answer to it: the same - // deadline and abort signal the build itself would get (#2422). + // One clock for the whole build phase. The cache decision runs blocking + // toolchain probes before any build starts, so a cold probe's stall is time + // the build no longer has: both read this deadline rather than each starting + // from a fresh copy of `buildTimeoutMs` (#2422). The cache lock, the reuse + // evaluation, and the cleanup between them are on it too. + const phaseDeadline = createRunnerPhaseDeadline(options.buildTimeoutMs); const expectedCacheMetadata = resolveExpectedRunnerCacheMetadata(device, projectRoot, { - timeoutMs: options.buildTimeoutMs, + deadline: phaseDeadline, signal: options.signal, }); const derived = resolveRunnerDerivedPath(device, expectedCacheMetadata); @@ -97,6 +107,7 @@ export async function ensureXctestrunArtifact( return await ensureXctestrunUnderCacheLock({ device, options, + phaseDeadline, projectRoot, expectedCacheMetadata, derived, @@ -153,19 +164,14 @@ function resolveExternalXctestDerivedDataPath(xctestrunPath: string): string { async function ensureXctestrunUnderCacheLock(params: { device: DeviceInfo; - options: { - verbose?: boolean; - logPath?: string; - traceLogPath?: string; - buildTimeoutMs?: number; - signal?: AbortSignal; - }; + options: RunnerXctestrunBuildOptions; + phaseDeadline: RunnerPhaseDeadline | undefined; projectRoot: string; expectedCacheMetadata: RunnerXctestrunCacheMetadata; derived: string; forceRebuild: boolean; }): Promise { - const { device, options, projectRoot, expectedCacheMetadata, derived } = params; + const { device, options, phaseDeadline, projectRoot, expectedCacheMetadata, derived } = params; cleanRunnerDerivedBeforeEvaluation(derived, params.forceRebuild); const existing = await evaluateExistingXctestrunForDevice({ device, @@ -193,6 +199,7 @@ async function ensureXctestrunUnderCacheLock(params: { return await buildXctestrunArtifact({ device, options, + phaseDeadline, projectRoot, expectedCacheMetadata, derived, @@ -229,33 +236,46 @@ async function resolveReusableXctestrunArtifact(params: { async function buildXctestrunArtifact(params: { device: DeviceInfo; - options: { - verbose?: boolean; - logPath?: string; - traceLogPath?: string; - buildTimeoutMs?: number; - signal?: AbortSignal; - }; + options: RunnerXctestrunBuildOptions; + phaseDeadline: RunnerPhaseDeadline | undefined; projectRoot: string; expectedCacheMetadata: RunnerXctestrunCacheMetadata; derived: string; cache: RunnerXctestrunArtifact['cache']; reason: ExistingXctestrunState['reason']; }): Promise { - const { device, options, projectRoot, expectedCacheMetadata, derived, cache, reason } = params; + const { + device, + options, + phaseDeadline, + projectRoot, + expectedCacheMetadata, + derived, + cache, + reason, + } = params; const projectPath = resolveAppleRunnerProjectPath(projectRoot); if (!fs.existsSync(projectPath)) { throw new AppError('COMMAND_FAILED', 'iOS runner project not found', { projectPath }); } + // What the phase has left after the toolchain probes, the cache lock, and the + // reuse evaluation -- computed before the build announces itself, so a phase + // already spent fails here instead of starting an xcodebuild it would have to + // kill at once (#2422). + const buildTimeoutMs = requireRunnerPhaseRemainingMs( + phaseDeadline, + options.buildTimeoutMs, + 'runner_xctestrun_build', + ); const buildStartedAt = Date.now(); emitRequestProgress({ type: 'command', status: 'progress', message: 'Building Apple runner...', }); - await buildRunnerXctestrun(device, projectPath, derived, options); + await buildRunnerXctestrun(device, projectPath, derived, { ...options, buildTimeoutMs }); const buildMs = Math.max(0, Date.now() - buildStartedAt); const built = findXctestrun(derived, device); @@ -461,13 +481,7 @@ async function buildRunnerXctestrun( device: DeviceInfo, projectPath: string, derived: string, - options: { - verbose?: boolean; - logPath?: string; - traceLogPath?: string; - buildTimeoutMs?: number; - signal?: AbortSignal; - }, + options: RunnerXctestrunBuildOptions, ): Promise { const runnerBundleBuildSettings = resolveRunnerBundleBuildSettings(process.env); const signingBuildSettings = resolveRunnerSigningBuildSettings( diff --git a/packages/platform-apple/src/runner/runner-cache-metadata.ts b/packages/platform-apple/src/runner/runner-cache-metadata.ts index 826dafa4b6..a381b0a284 100644 --- a/packages/platform-apple/src/runner/runner-cache-metadata.ts +++ b/packages/platform-apple/src/runner/runner-cache-metadata.ts @@ -4,6 +4,7 @@ import path from 'node:path'; import { isMacOs, type DeviceInfo } from '@agent-device/kernel/device'; import { AppError, createRequestCanceledError } from '@agent-device/kernel/errors'; import { + coldToolchainProbeTimeoutMs, createTtlMemo, Deadline, isCommandTimeoutError, @@ -27,29 +28,14 @@ export const RUNNER_CACHE_METADATA_FILE = '.agent-device-runner-cache.json'; const RUNNER_CACHE_SCHEMA_VERSION = 2; const RUNNER_CACHE_METADATA_VALUE_MAX_LENGTH = 300; -/** - * Ceiling on one toolchain identity probe attempt (`xcodebuild -version`, - * `xcrun --show-sdk-version`, …); the owning request's remaining budget can - * cap an attempt lower. Must equal `COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` - * in `../snapshot-source/cache-identity.ts` -- both absorb the same ~18 to - * 19 second syspolicyd signature-scan stall on the first `xcodebuild`/ - * `xcrun` exec after a fresh macOS host boots (#2422). It is declared here - * rather than imported from that module because this file sits in every - * platform-apple façade's eager closure and `snapshot-source/*` does not - * (`scripts/__tests__/eager-closure-budgets.ts`); a unit test - * (`__tests__/runner-cache-metadata.test.ts`) asserts the two constants stay - * equal so they cannot drift apart. - */ -export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; - /** * Ceiling on the wall clock the whole toolchain fingerprint may spend, across - * all three probes and their retries, when the owning request carries no - * shorter budget. Sized for the one cold-start stall the retry exists for -- - * a single stalled probe (up to {@link COLD_TOOLCHAIN_PROBE_TIMEOUT_MS}) plus - * its now-warm retry and the two remaining probes -- not for three - * independently stalling tools, which is why the per-call timeout alone is not - * the bound (#2422). + * all three probes and their retries, when the owning phase carries no shorter + * budget. Sized for the one cold-start stall the retry exists for -- a single + * stalled probe (up to the host's `coldToolchainProbeTimeoutMs()`) plus its + * now-warm retry and the two remaining probes -- not for three independently + * stalling tools, which is why the per-call timeout alone is not the bound + * (#2422). */ const TOOLCHAIN_FINGERPRINT_BUDGET_MS = 45_000; @@ -84,9 +70,54 @@ type ToolchainProbeFailure = { }; /** - * What the request that wants a runner cache decision has left to spend on it. + * The one clock a runner phase spends: the cache decision's blocking toolchain + * probes and the step the phase exists for (an `xcodebuild` build, a runner + * startup) both read it, so what the probes spend is time the step no longer + * has. Create it once per phase with {@link createRunnerPhaseDeadline} and read + * the rest with {@link requireRunnerPhaseRemainingMs}; a step that hands the + * probes a timeout and then hands itself the same number again spends the + * phase's budget twice (#2422). + */ +export type RunnerPhaseDeadline = Deadline; + +/** + * The phase clock for a step whose budget is `timeoutMs`, or `undefined` for a + * caller that carries no budget at all (background and preflight surfaces). + */ +export function createRunnerPhaseDeadline( + timeoutMs: number | undefined, +): RunnerPhaseDeadline | undefined { + if (timeoutMs === undefined || !Number.isFinite(timeoutMs)) return undefined; + return Deadline.fromTimeoutMs(Math.max(0, timeoutMs)); +} + +/** + * What the phase has left for its next step, or `fallbackTimeoutMs` when it + * carries no deadline. Throws instead of returning zero: a step reached with + * nothing left must fail before it spawns anything, not start a process it + * would have to kill immediately. + */ +export function requireRunnerPhaseRemainingMs( + deadline: RunnerPhaseDeadline | undefined, + fallbackTimeoutMs: number | undefined, + phase: string, +): number | undefined { + if (!deadline) return fallbackTimeoutMs; + const remainingMs = Math.floor(deadline.remainingMs()); + if (remainingMs <= 0) { + throw new AppError('COMMAND_FAILED', 'The Apple runner budget ran out before this step began', { + phase, + reason: 'runner_phase_budget_exhausted', + retriable: true, + }); + } + return remainingMs; +} + +/** + * What the phase that wants a runner cache decision has left to spend on it. * The decision blocks the calling request on up to three synchronous `spawnSync` - * probes, so the request's own deadline and cancellation must reach them: an + * probes, so the phase's own deadline and cancellation must reach them: an * exhausted budget fails the decision instead of starting another 30 second * probe, and a canceled request surfaces the cancellation rather than * retrying (#2422). A caller with neither still gets @@ -97,8 +128,8 @@ type ToolchainProbeFailure = { * takes. */ export type RunnerCacheProbeBudget = { - /** Milliseconds the owning request has left, if it carries a deadline. */ - timeoutMs?: number; + /** The owning phase's clock, shared with whatever the phase does next. */ + deadline?: RunnerPhaseDeadline; /** The owning request's cancellation signal, if it carries one. */ signal?: AbortSignal; }; @@ -118,16 +149,19 @@ type ToolchainProbeClock = { function createToolchainProbeClock( budget: RunnerCacheProbeBudget | undefined, ): ToolchainProbeClock { - const ownerRemainingMs = - budget?.timeoutMs !== undefined && Number.isFinite(budget.timeoutMs) - ? Math.max(0, budget.timeoutMs) - : Number.POSITIVE_INFINITY; - const deadline = Deadline.fromTimeoutMs( - Math.min(TOOLCHAIN_FINGERPRINT_BUDGET_MS, ownerRemainingMs), - ); + // Two clocks, because they bound different things: the phase's, which the + // build or startup after these probes will read the remainder of, and the + // fingerprint's own ceiling, which stops a caller with a generous phase + // budget from spending minutes on three stalled tools. + const phaseDeadline = budget?.deadline; + const fingerprintDeadline = Deadline.fromTimeoutMs(TOOLCHAIN_FINGERPRINT_BUDGET_MS); return { attemptTimeoutMs: () => - Math.min(COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, Math.floor(deadline.remainingMs())), + Math.min( + coldToolchainProbeTimeoutMs(), + Math.floor(fingerprintDeadline.remainingMs()), + phaseDeadline ? Math.floor(phaseDeadline.remainingMs()) : Number.POSITIVE_INFINITY, + ), throwIfCanceled: () => { if (budget?.signal?.aborted) { throw createRequestCanceledError({ phase: 'apple_toolchain_probe' }); @@ -342,7 +376,8 @@ function runToolchainProbe( * Runs one toolchain probe, retrying exactly once if the attempt timed out and * the shared budget still has room. Apple's syspolicyd signature scan blocks * the first `xcodebuild`/`xcrun` exec after a fresh host boots (see - * COLD_TOOLCHAIN_PROBE_TIMEOUT_MS); the immediate next exec of the same tool is + * `COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` in `../core/config.ts`, which reaches this + * file through the host port); the immediate next exec of the same tool is * instant, so the retry recovers without widening the per-call budget. Only the * exec layer's structured timeout is retried -- a tool that failed on its own * and merely said "timed out" in its output is not this stall. diff --git a/packages/platform-apple/src/runner/runner-cache.ts b/packages/platform-apple/src/runner/runner-cache.ts index 94f0431f50..252896e10f 100644 --- a/packages/platform-apple/src/runner/runner-cache.ts +++ b/packages/platform-apple/src/runner/runner-cache.ts @@ -20,6 +20,8 @@ import { type RunnerXctestrunCacheProductArtifact, } from './runner-cache-metadata.ts'; export { + createRunnerPhaseDeadline, + requireRunnerPhaseRemainingMs, resolveExpectedRunnerCacheMetadata, resolveRunnerBundleBuildSettings, resolveRunnerDerivedPath, @@ -27,6 +29,7 @@ export { resolveRunnerPerformanceBuildSettings, resolveRunnerSandboxBuildArgs, resolveRunnerSigningBuildSettings, + type RunnerPhaseDeadline, type RunnerXctestrunCacheMetadata, } from './runner-cache-metadata.ts'; diff --git a/packages/platform-apple/src/runner/runner-session.ts b/packages/platform-apple/src/runner/runner-session.ts index 46923ec6f5..89b88e1d9b 100644 --- a/packages/platform-apple/src/runner/runner-session.ts +++ b/packages/platform-apple/src/runner/runner-session.ts @@ -19,12 +19,15 @@ import { waitForRunner, RUNNER_STARTUP_TIMEOUT_MS } from './runner-startup-trans import { sendRunnerCommandOnce } from './runner-transport.ts'; import { acquireXcodebuildSimulatorSetRedirect, + createRunnerPhaseDeadline, ensureXctestrunArtifact, IOS_RUNNER_CONTAINER_BUNDLE_IDS, prepareXctestrunWithEnv, + requireRunnerPhaseRemainingMs, resolveExpectedRunnerCacheMetadata, resolveRunnerDerivedPath, type RunnerCacheProbeBudget, + type RunnerPhaseDeadline, } from './runner-xctestrun.ts'; import { resolveRunnerRequestSignal, @@ -110,11 +113,16 @@ export async function ensureRunnerSession( // from a retained-after-close runner no longer applies. cancelIosRunnerIdleStop(device.id); return await withRunnerSessionLock(device.id, async () => { + // One clock for the whole startup phase. The reuse check runs the same + // blocking toolchain probes the startup after it would, so a cold probe's + // stall is time the startup no longer has: everything below reads what this + // deadline has left rather than `startupTimeoutMs` again (#2422). + const phaseDeadline = createRunnerPhaseDeadline(options.startupTimeoutMs); const existing = runnerSessions.get(device.id); if (existing) { assertExpectedRunnerSession(existing, options.expectedRunnerSessionId); const reusable = await resolveReusableRunnerSession(device, existing, { - timeoutMs: options.startupTimeoutMs, + deadline: phaseDeadline, signal: resolveRunnerRequestSignal(options), }); if (reusable) return reusable; @@ -122,7 +130,7 @@ export async function ensureRunnerSession( return await withRunnerLeaseLock( device.id, - async () => await startRunnerSessionWithLease(device, options), + async () => await startRunnerSessionWithLease(device, options, phaseDeadline), ); }); } @@ -130,6 +138,7 @@ export async function ensureRunnerSession( async function startRunnerSessionWithLease( device: DeviceInfo, options: RunnerSessionOptions, + phaseDeadline: RunnerPhaseDeadline | undefined, ): Promise { const startupTimings: Record = {}; // The owning request's abort signal so a client disconnect kills the blocking @@ -155,6 +164,7 @@ async function startRunnerSessionWithLease( async () => await tryAdoptRunnerSessionFromLease(device, { startupTimeoutMs: options.startupTimeoutMs, + phaseDeadline, expectedRunnerSessionId: options.expectedRunnerSessionId, }), ); @@ -185,6 +195,15 @@ async function startRunnerSessionWithLease( phase: 'ios_runner_startup_cleanup_stale_bundles_skipped', }); } + // What the startup phase has left after the reuse probe, the adoption attempt + // and the pre-build cleanup. Read before the build rather than after it: the + // build answers to its own `buildTimeoutMs` deadline, so charging it to the + // startup budget as well would spend that budget twice over (#2422). + const startupTimeoutMs = requireRunnerPhaseRemainingMs( + phaseDeadline, + options.startupTimeoutMs, + 'runner_session_startup', + ); const xctestrunArtifact = await measureRunnerStartupStep( startupTimings, 'ensure_xctestrun', @@ -258,7 +277,7 @@ async function startRunnerSessionWithLease( child: runnerProcess.child, ready: false, startupRetryWake: runnerProcess.startupRetryWake, - startupTimeoutMs: normalizeRunnerStartupTimeoutMs(options.startupTimeoutMs), + startupTimeoutMs: normalizeRunnerStartupTimeoutMs(startupTimeoutMs), startupTimings, logicalLeaseContext, simulatorSetRedirect: simulatorSetRedirect ?? undefined, diff --git a/packages/platform-apple/src/runner/runner-xctestrun.ts b/packages/platform-apple/src/runner/runner-xctestrun.ts index eae7fcbe0e..66f1cf4f38 100644 --- a/packages/platform-apple/src/runner/runner-xctestrun.ts +++ b/packages/platform-apple/src/runner/runner-xctestrun.ts @@ -12,10 +12,13 @@ export { type RunnerXctestrunCacheKind, } from './runner-cache.ts'; export { + createRunnerPhaseDeadline, IOS_RUNNER_CONTAINER_BUNDLE_IDS, + requireRunnerPhaseRemainingMs, resolveExpectedRunnerCacheMetadata, resolveRunnerAppBundleId, resolveRunnerDerivedPath, type RunnerCacheProbeBudget, + type RunnerPhaseDeadline, } from './runner-cache-metadata.ts'; export { acquireXcodebuildSimulatorSetRedirect } from './runner-device-set.ts'; diff --git a/packages/platform-apple/src/snapshot-source/cache-identity.test.ts b/packages/platform-apple/src/snapshot-source/cache-identity.test.ts index c9a15b7605..af417da7bd 100644 --- a/packages/platform-apple/src/snapshot-source/cache-identity.test.ts +++ b/packages/platform-apple/src/snapshot-source/cache-identity.test.ts @@ -3,60 +3,87 @@ import { test } from 'vitest'; import { AppError } from '@agent-device/kernel/errors'; import { createSnapshotSourceHost } from './host.ts'; import { readSnapshotSourceToolchain } from './cache-identity.ts'; -import { createSnapshotSourceDeadline } from './deadline.ts'; +import { createSnapshotSourceDeadline, type SnapshotSourceDeadline } from './deadline.ts'; +import type { ExecOptions, ExecResult } from '@agent-device/host-kit/command'; import type { SnapshotSourceHost } from './types.ts'; // Apple's syspolicyd signature scan blocks the first xcodebuild/xcrun exec // after a fresh macOS host boots for roughly 18 to 19 seconds; the immediate // next exec of the same tool is instant (#2422). These cases exercise the -// resulting one-retry policy without waiting on a real cold-start stall. +// resulting one-retry policy, and the deadline that bounds it, without waiting +// on a real cold-start stall: the fake clock only moves when a probe actually +// blocks for the timeout it was handed, so a case that claims the budget was +// spent had to spend it. -test('a cold-start toolchain probe recovers on retry: the first call exceeds the budget, the second returns immediately', async () => { +test('a cold-start toolchain probe recovers on retry, and the retry gets only what the stall left', async () => { + const clock = { nowMs: 0 }; + const timeouts: number[] = []; let calls = 0; - const host = fakeToolchainHost((command, args) => { + const host = fakeToolchainHost((command, args, options) => { calls += 1; - if (calls === 1) { - throw new AppError('COMMAND_FAILED', `${command} timed out after 30000ms`, { - timeoutMs: 30_000, - }); - } + timeouts.push(options.timeoutMs ?? 0); + if (calls === 1) throw blockForWholeTimeout(clock, command, options); return toolchainAnswer(command, args); }); const identity = await readSnapshotSourceToolchain( host, 'iOS 26.2', - createSnapshotSourceDeadline(120_000, undefined), + fakeClockDeadline(40_000, clock), ); assert.equal(identity.xcode, 'Xcode 26.2\nBuild version 17C52'); assert.equal(identity.macosBuild, '24G90'); assert.equal(identity.architecture, 'arm64'); assert.equal(identity.simulatorSdk, '26.2'); + // The stalled first attempt is capped at the 30 s per-probe ceiling; the + // retry runs on the 10 s the shared deadline has left, not a second 30 s. + assert.deepEqual(timeouts.slice(0, 2), [30_000, 10_000]); + assert.equal(clock.nowMs, 30_000); // 5 baseline probes (xcodebuild, sw_vers x2, uname, xcrun) plus the one // retry that recovered the first, timed-out call. assert.equal(calls, 6); }); +test('a probe that spends the whole deadline is not retried', async () => { + const clock = { nowMs: 0 }; + const timeouts: number[] = []; + const host = fakeToolchainHost((command, _args, options) => { + timeouts.push(options.timeoutMs ?? 0); + throw blockForWholeTimeout(clock, command, options); + }); + + await assert.rejects( + readSnapshotSourceToolchain(host, 'iOS 26.2', fakeClockDeadline(30_000, clock)), + (error: unknown) => + error instanceof AppError && error.message === 'xcodebuild timed out after 30000ms', + ); + // Nothing left to retry on, so the original timeout propagates unchanged. + assert.deepEqual(timeouts, [30_000]); + assert.equal(clock.nowMs, 30_000); +}); + test('a toolchain host that never returns still fails at the deadline with the same timeout error', async () => { - let calls = 0; - const host = fakeToolchainHost((command) => { - calls += 1; - throw new AppError('COMMAND_FAILED', `${command} timed out after 30000ms`, { - timeoutMs: 30_000, - }); + const clock = { nowMs: 0 }; + const timeouts: number[] = []; + const host = fakeToolchainHost((command, _args, options) => { + timeouts.push(options.timeoutMs ?? 0); + throw blockForWholeTimeout(clock, command, options); }); await assert.rejects( - readSnapshotSourceToolchain(host, 'iOS 26.2', createSnapshotSourceDeadline(120_000, undefined)), + readSnapshotSourceToolchain(host, 'iOS 26.2', fakeClockDeadline(120_000, clock)), (error: unknown) => error instanceof AppError && error.message === 'xcodebuild timed out after 30000ms', ); - // Exactly one retry, not an unbounded loop. - assert.equal(calls, 2); + // Exactly one retry, not an unbounded loop, and the retry is charged the + // remainder rather than a fresh ceiling. + assert.deepEqual(timeouts, [30_000, 30_000]); + assert.equal(clock.nowMs, 60_000); }); test('a probe that failed on its own and merely says "timed out" in its message is not retried', async () => { + const clock = { nowMs: 0 }; let calls = 0; const host = fakeToolchainHost((command) => { calls += 1; @@ -67,17 +94,30 @@ test('a probe that failed on its own and merely says "timed out" in its message }); await assert.rejects( - readSnapshotSourceToolchain(host, 'iOS 26.2', createSnapshotSourceDeadline(120_000, undefined)), + readSnapshotSourceToolchain(host, 'iOS 26.2', fakeClockDeadline(120_000, clock)), (error: unknown) => error instanceof AppError && error.message === 'xcodebuild timed out after 10ms', ); assert.equal(calls, 1); }); -function toolchainAnswer( +/** A deadline read against a clock only {@link blockForWholeTimeout} advances. */ +function fakeClockDeadline(timeoutMs: number, clock: { nowMs: number }): SnapshotSourceDeadline { + return createSnapshotSourceDeadline(timeoutMs, undefined, () => clock.nowMs); +} + +/** A probe that blocked for its whole timeout and was then killed, as the exec layer reports it. */ +function blockForWholeTimeout( + clock: { nowMs: number }, command: string, - args: string[], -): { stdout: string; stderr: string; exitCode: number } { + options: ExecOptions, +): AppError { + const timeoutMs = options.timeoutMs ?? 0; + clock.nowMs += timeoutMs; + return new AppError('COMMAND_FAILED', `${command} timed out after ${timeoutMs}ms`, { timeoutMs }); +} + +function toolchainAnswer(command: string, args: string[]): ExecResult { const stdout = command === 'xcodebuild' ? 'Xcode 26.2\nBuild version 17C52' @@ -92,11 +132,11 @@ function toolchainAnswer( } function fakeToolchainHost( - run: (command: string, args: string[]) => { stdout: string; stderr: string; exitCode: number }, + run: (command: string, args: string[], options: ExecOptions) => ExecResult, ): SnapshotSourceHost { const real = createSnapshotSourceHost(); return { ...real, - run: async (command, args) => run(command, args), + run: async (command, args, options) => run(command, args, options ?? {}), }; } diff --git a/packages/platform-apple/src/snapshot-source/cache-identity.ts b/packages/platform-apple/src/snapshot-source/cache-identity.ts index dca3907520..5b7c057743 100644 --- a/packages/platform-apple/src/snapshot-source/cache-identity.ts +++ b/packages/platform-apple/src/snapshot-source/cache-identity.ts @@ -1,31 +1,13 @@ import { createHash } from 'node:crypto'; import path from 'node:path'; import { isCommandTimeoutError, type ExecResult } from '@agent-device/host-kit/command'; +// The per-attempt toolchain probe budget both Apple toolchain probers read; see +// its doc comment there for the cold-start stall it is sized for (#2422). +import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../core/config.ts'; import { snapshotSourceError } from './errors.ts'; import { remainingSnapshotSourceMs, type SnapshotSourceDeadline } from './deadline.ts'; import type { SnapshotSourceHost } from './types.ts'; -/** - * Per-call timeout for a toolchain identity probe (`xcodebuild -version`, - * `xcrun --show-sdk-version`, `sw_vers`, `uname`, …). On a fresh macOS host, - * Apple's syspolicyd signature scan blocks the very first `xcodebuild`/ - * `xcrun`/large-binary exec after boot for roughly 18 to 19 seconds at 0% - * CPU; the second exec of the same tool is instant. A budget sized for a - * warm toolchain (the old 10 s / 5 s split) trips on that cold-start stall - * and reports a bogus toolchain-probe timeout unrelated to the change under - * test (#2422). - * - * `runner/runner-cache-metadata.ts` needs this same budget but cannot import - * it from here: this module is outside every platform-apple façade's eager - * closure today, and importing it from `runner-cache-metadata.ts` would pull - * `snapshot-source/*` into all of them (`scripts/__tests__/eager-closure- - * budgets.ts`). It instead declares its own copy of this constant, checked - * against this one for equality by a unit test - * (`runner/__tests__/runner-cache-metadata.test.ts`) so the two cannot drift - * apart. - */ -export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; - export type SnapshotSourceToolchainIdentity = Readonly<{ xcode: string; macosProductVersion: string; @@ -124,9 +106,11 @@ async function toolOutput( * and the deadline still has room. The retry absorbs the cold-start * signature-verification stall named on COLD_TOOLCHAIN_PROBE_TIMEOUT_MS: the * first exec of a tool on a fresh host can block for that long, but the - * immediate next exec of the same tool is instant. Only the exec layer's own - * structured timeout counts -- a tool that failed by itself and merely said - * "timed out" in its output is not this stall and is not retried. + * immediate next exec of the same tool is instant. Both attempts read one + * deadline, so the retry gets what the stall left rather than a fresh ceiling. + * Only the exec layer's own structured timeout counts -- a tool that failed by + * itself and merely said "timed out" in its output is not this stall and is not + * retried. */ async function runToolchainProbe( host: SnapshotSourceHost, @@ -159,5 +143,5 @@ function execToolchainProbe( } function toolchainProbeDeadlineHasRoom(deadline: SnapshotSourceDeadline): boolean { - return !deadline.signal?.aborted && deadline.clock.remainingMs() > 0; + return !deadline.signal?.aborted && deadline.clock.remainingMs(deadline.now()) > 0; } diff --git a/packages/platform-apple/src/snapshot-source/deadline.ts b/packages/platform-apple/src/snapshot-source/deadline.ts index ca03e563e7..f0d5a2fe38 100644 --- a/packages/platform-apple/src/snapshot-source/deadline.ts +++ b/packages/platform-apple/src/snapshot-source/deadline.ts @@ -3,20 +3,28 @@ import { snapshotSourceError } from './errors.ts'; export type SnapshotSourceDeadline = Readonly<{ clock: Deadline; + /** + * The clock the deadline is read against. Injected so a test can prove that a + * step which blocked for the timeout it was handed leaves the next step only + * the remainder -- a fake that throws instantly moves no time and so cannot + * tell a shared budget from a fresh one (#2422). + */ + now: () => number; signal: AbortSignal | undefined; }>; export function createSnapshotSourceDeadline( timeoutMs: number, signal: AbortSignal | undefined, + now: () => number = Date.now, ): SnapshotSourceDeadline { if (signal?.aborted) throw snapshotSourceError('cancelled', 'abort-signal'); - return { clock: Deadline.fromTimeoutMs(timeoutMs), signal }; + return { clock: Deadline.fromTimeoutMs(timeoutMs, now()), now, signal }; } export function remainingSnapshotSourceMs(deadline: SnapshotSourceDeadline, code: string): number { if (deadline.signal?.aborted) throw snapshotSourceError('cancelled', 'abort-signal'); - const remainingMs = deadline.clock.remainingMs(); + const remainingMs = deadline.clock.remainingMs(deadline.now()); if (remainingMs <= 0) throw snapshotSourceError('timeout', code); return Math.max(1, Math.floor(remainingMs)); } From e823dca6b711564f862e25462a9bea5c63f71281 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Thu, 10 Sep 2026 10:52:09 +0200 Subject: [PATCH 5/9] fix(apple): keep cancellation typed after a probe timeout and simplify the probe budget --- packages/host-kit/src/command.ts | 1 + packages/host-kit/src/internal/exec.ts | 15 ++++ packages/platform-apple/src/core/config.ts | 17 ---- .../platform-apple/src/core/runner-host.ts | 2 +- .../runner/__tests__/runner-adoption.test.ts | 24 +++++ .../__tests__/runner-cache-metadata.test.ts | 45 +++++----- packages/platform-apple/src/runner/host.ts | 12 +-- .../src/runner/runner-adoption.ts | 17 +++- .../src/runner/runner-artifact.ts | 6 +- .../src/runner/runner-cache-metadata.ts | 90 +++++++++---------- .../platform-apple/src/runner/runner-cache.ts | 1 - .../src/runner/runner-session.ts | 4 +- .../src/runner/runner-xctestrun.ts | 1 - .../snapshot-source/cache-identity.test.ts | 33 +++++++ .../src/snapshot-source/cache-identity.ts | 21 +++-- 15 files changed, 177 insertions(+), 112 deletions(-) diff --git a/packages/host-kit/src/command.ts b/packages/host-kit/src/command.ts index 95e68a8f5a..6b32fb47b3 100644 --- a/packages/host-kit/src/command.ts +++ b/packages/host-kit/src/command.ts @@ -1,5 +1,6 @@ export { coerceExecResult, + COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, type CommandExecutorOverride, type ExecBackgroundOptions, type ExecBackgroundResult, diff --git a/packages/host-kit/src/internal/exec.ts b/packages/host-kit/src/internal/exec.ts index b31187c8fc..b9f2bb646a 100644 --- a/packages/host-kit/src/internal/exec.ts +++ b/packages/host-kit/src/internal/exec.ts @@ -608,6 +608,21 @@ export function isCommandTimeoutError(error: unknown): boolean { ); } +/** + * Ceiling on one Apple toolchain identity probe attempt (`xcodebuild -version`, + * `xcrun --show-sdk-version`, `sw_vers`, `uname`, …). On a fresh macOS host, + * Apple's syspolicyd signature scan blocks the very first `xcodebuild`/`xcrun`/ + * large-binary exec after boot for roughly 18 to 19 seconds at 0% CPU; the + * second exec of the same tool is instant. A budget sized for a warm toolchain + * (the old 10 s / 5 s split) trips on that cold-start stall and reports a bogus + * toolchain-probe timeout unrelated to the change under test (#2422). + * + * It sits beside {@link isCommandTimeoutError} because it is a property of + * exec'ing an Apple tool rather than of either prober: both Apple toolchain + * probers read this one value. + */ +export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; + function createExitError( executable: string, cmd: string, diff --git a/packages/platform-apple/src/core/config.ts b/packages/platform-apple/src/core/config.ts index 177e0d69d7..47e87c1718 100644 --- a/packages/platform-apple/src/core/config.ts +++ b/packages/platform-apple/src/core/config.ts @@ -23,20 +23,3 @@ export const IOS_RUNNER_SCREENSHOT_COPY_TIMEOUT_MS = 20_000; export const IOS_SIMULATOR_SCREENSHOT_RETRY_MAX_ATTEMPTS = 5; export const IOS_SIMULATOR_SCREENSHOT_RETRY_BASE_DELAY_MS = 1_000; export const IOS_SIMULATOR_SCREENSHOT_RETRY_MAX_DELAY_MS = 5_000; - -/** - * Ceiling on one Apple toolchain identity probe attempt (`xcodebuild -version`, - * `xcrun --show-sdk-version`, `sw_vers`, `uname`, …). On a fresh macOS host, - * Apple's syspolicyd signature scan blocks the very first `xcodebuild`/`xcrun`/ - * large-binary exec after boot for roughly 18 to 19 seconds at 0% CPU; the - * second exec of the same tool is instant. A budget sized for a warm toolchain - * (the old 10 s / 5 s split) trips on that cold-start stall and reports a bogus - * toolchain-probe timeout unrelated to the change under test (#2422). - * - * Both toolchain probers read this one value. `snapshot-source/cache-identity.ts` - * imports it from here; `runner/runner-cache-metadata.ts` reads it through the - * Apple runner host port instead, because that file sits in every Apple façade's - * eager import closure and may not add a module to it - * (`scripts/__tests__/eager-closure-budgets.test.ts`). - */ -export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; diff --git a/packages/platform-apple/src/core/runner-host.ts b/packages/platform-apple/src/core/runner-host.ts index 3b12313e2f..fbe331b209 100644 --- a/packages/platform-apple/src/core/runner-host.ts +++ b/packages/platform-apple/src/core/runner-host.ts @@ -3,6 +3,7 @@ import { publishFileSync, acquireProcessLock } from '@agent-device/host-kit/file import { resolveIosSimulatorDeviceSetPath } from '@agent-device/kernel/device-isolation'; import { + COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, isCommandTimeoutError, requireExecSuccess, runCmdBackground, @@ -35,7 +36,6 @@ import { } from '@agent-device/host-kit/request'; import { bootFailureHint, classifyBootFailure } from '@agent-device/provision-kit/boot-diagnostics'; -import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from './config.ts'; import { resolveIosPhysicalDeviceControl } from './physical-device-control.ts'; import { visitXmlPlistEntries } from './plist-xml.ts'; import { diff --git a/packages/platform-apple/src/runner/__tests__/runner-adoption.test.ts b/packages/platform-apple/src/runner/__tests__/runner-adoption.test.ts index 956ebaa495..53e5999ff3 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-adoption.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-adoption.test.ts @@ -2,6 +2,7 @@ import fs from 'node:fs'; import path from 'node:path'; import { afterEach, beforeEach, expect, test, vi } from 'vitest'; import type { DeviceInfo } from '@agent-device/kernel/device'; +import { createRequestCanceledError, isRequestCanceledError } from '@agent-device/kernel/errors'; import { buildDetachedRunnerLease, buildRunnerLease, @@ -11,6 +12,7 @@ import { } from '../runner-lease.ts'; import { isIosRunnerDetachEnabled, tryAdoptRunnerSessionFromLease } from '../runner-adoption.ts'; import { sendRunnerCommandOnce } from '../runner-transport.ts'; +import { resolveExpectedRunnerCacheMetadata } from '../runner-xctestrun.ts'; import { appleRunnerTestHost } from '../test-host.ts'; import { mkdtempForTestSync } from './tmp-dir.ts'; @@ -28,6 +30,7 @@ vi.mock('../runner-xctestrun.ts', async (importOriginal) => { }); const mockSendRunnerCommandOnce = vi.mocked(sendRunnerCommandOnce); +const mockResolveExpectedRunnerCacheMetadata = vi.mocked(resolveExpectedRunnerCacheMetadata); const mockIsProcessAlive = vi.fn((_pid: number) => false); const mockReadProcessCommand = vi.fn((_pid: number): string | null => null); const mockReadProcessStartTime = vi.fn((_pid: number): string | null => 'test-process-start'); @@ -140,6 +143,27 @@ test('adoption succeeds for a live, matching, probe-healthy runner', async () => expect(readStaleRunnerLease(simulator.id)).toBeNull(); }); +test('a request canceled during the fingerprint probe fails adoption instead of skipping it', async () => { + // The fingerprint check runs the same blocking toolchain probes a fresh + // startup would, and it is handed the request's signal. A cancellation from + // there is not an unresolvable derived path: swallowing it would let startup + // walk on past a client that is already gone (#2422). + writeStaleLease(); + mockIsProcessAlive.mockReturnValue(true); + const request = new AbortController(); + request.abort(); + mockResolveExpectedRunnerCacheMetadata.mockImplementationOnce((_device, _projectRoot, budget) => { + // The probe only cancels because the request's signal reached it. + expect(budget?.signal?.aborted).toBe(true); + throw createRequestCanceledError({ phase: 'apple_toolchain_probe' }); + }); + + await expect( + tryAdoptRunnerSessionFromLease(simulator, { signal: request.signal }), + ).rejects.toSatisfy(isRequestCanceledError); + expect(mockSendRunnerCommandOnce).not.toHaveBeenCalled(); +}); + test('adoption is skipped for a recycled runner pid (start time mismatch)', async () => { // The live process on the leased pid started at a different time than the // lease recorded — pid recycled since the owner died (#1596). Adopting it diff --git a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts index f317c57428..bb1c8fdd24 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts @@ -15,9 +15,10 @@ import { resolveRunnerSandboxBuildArgs, resolveExpectedRunnerCacheMetadata, } from '../runner-cache-metadata.ts'; -// The one owning module for the probe budget: this file's probes reach it -// through the runner host port, snapshot-source imports it directly (#2422). -import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../../core/config.ts'; +// The one owning module for the probe budget: host-kit's exec layer. The +// snapshot-source prober imports it from there directly; this file's probes read +// the same value through the runner host port (#2422). +import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '@agent-device/host-kit/command'; import { appleToolchainProbeResult, stubAppleToolchainProbes } from './apple-toolchain-fixtures.ts'; const runCmdSync = stubAppleToolchainProbes(); @@ -289,19 +290,10 @@ describe('toolchain probe budget', () => { assert.throws( () => resolveExpectedRunnerCacheMetadata(MACOS_DEVICE), - (error: unknown) => { - assert.ok(error instanceof AppError); - assert.equal(error.code, 'COMMAND_FAILED'); - assert.equal(error.details?.reason, 'apple_toolchain_probe_unavailable'); - assert.equal(error.details?.retriable, true); - expect(error.details?.hint).toContain('xcode-select -p'); - expect(error.message).toContain('xcodebuild -version'); - // The reported failure is the last attempt: 30 s, then the 15 s the - // budget still had. - expect(error.message).toContain('xcodebuild timed out after 15000ms'); - expect(error.message).toContain('request budget'); - return true; - }, + // A budget spent before the remaining probes could start is not an + // unreadable toolchain: nothing probed it, so the error says the budget + // ran out rather than pointing at `xcode-select`. + (error: unknown) => expectRunnerPhaseBudgetExhausted(error), ); // 30 s + a 15 s retry spends the whole budget on the first probe; the two // xcrun probes then fail on the budget instead of blocking for 30 s each. @@ -320,15 +312,11 @@ describe('toolchain probe budget', () => { assert.throws( () => resolveExpectedRunnerCacheMetadata(IOS_SIMULATOR, undefined, { deadline: phaseDeadline }), - (error: unknown) => { - assert.ok(error instanceof AppError); - assert.equal(error.details?.reason, 'apple_toolchain_probe_unavailable'); - expect(error.message).toContain('xcodebuild timed out after 4000ms'); - expect(error.message).toContain('request budget'); - return true; - }, + (error: unknown) => expectRunnerPhaseBudgetExhausted(error), ); assert.equal(runCmdSync.mock.calls.length, 1); + // The one attempt was capped by the phase, not by the 30 s per-call ceiling. + assert.equal(runCmdSync.mock.calls[0]?.[2]?.timeoutMs, 4_000); assert.equal(clock.nowMs, 4_000); }); @@ -389,6 +377,17 @@ describe('toolchain probe budget', () => { }); }); +/** The error a runner phase raises when a step is reached with nothing left to spend. */ +function expectRunnerPhaseBudgetExhausted(error: unknown): boolean { + assert.ok(error instanceof AppError); + assert.equal(error.code, 'COMMAND_FAILED'); + assert.equal(error.details?.reason, 'runner_phase_budget_exhausted'); + assert.equal(error.details?.phase, 'apple_toolchain_probe'); + assert.equal(error.details?.retriable, true); + expect(error.message).toContain('budget ran out'); + return true; +} + /** * A clock the probes' own budget reads, advanced only by * {@link blockForWholeTimeout}. Without it a mock that throws immediately diff --git a/packages/platform-apple/src/runner/host.ts b/packages/platform-apple/src/runner/host.ts index 4088131653..5e3c51a6ae 100644 --- a/packages/platform-apple/src/runner/host.ts +++ b/packages/platform-apple/src/runner/host.ts @@ -156,12 +156,12 @@ export type AppleRunnerHost = { */ isCommandTimeoutError(error: unknown): boolean; /** - * Ceiling on one toolchain identity probe attempt, in milliseconds - * (`COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` in - * `packages/platform-apple/src/core/config.ts`, which owns it for both - * toolchain probers). It arrives through the port rather than by import so - * the runner's cache-metadata module, which every Apple façade evaluates, - * does not grow its eager import closure to read one number. + * Ceiling on one Apple toolchain identity probe attempt, in milliseconds: + * `COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` from `@agent-device/host-kit/command`, + * which owns it for both Apple toolchain probers. Like every other host-kit + * symbol above it arrives through this port rather than by import, because + * `scripts/__tests__/eager-closure-budgets.test.ts` holds the runner entry to + * the modules it evaluates today and a static edge to host-kit adds five. */ coldToolchainProbeTimeoutMs(): number; // Diagnostics (@agent-device/host-kit/diagnostics) diff --git a/packages/platform-apple/src/runner/runner-adoption.ts b/packages/platform-apple/src/runner/runner-adoption.ts index b608c19df0..bdb8242bdc 100644 --- a/packages/platform-apple/src/runner/runner-adoption.ts +++ b/packages/platform-apple/src/runner/runner-adoption.ts @@ -1,12 +1,14 @@ import path from 'node:path'; import { resolveIosSimulatorDeviceSetPath, + type Deadline, emitDiagnostic, isProcessAlive, parseBooleanLiteral, type ExecResult, } from './host.ts'; import type { DeviceInfo } from '@agent-device/kernel/device'; +import { isRequestCanceledError } from '@agent-device/kernel/errors'; import { sendRunnerCommandOnce } from './runner-transport.ts'; import { withRunnerCommandId } from './runner-contract.ts'; import { @@ -21,7 +23,6 @@ import { resolveExpectedRunnerCacheMetadata, resolveRunnerDerivedPath, type RunnerCacheProbeBudget, - type RunnerPhaseDeadline, type RunnerXctestrunArtifact, } from './runner-xctestrun.ts'; import { @@ -60,7 +61,9 @@ export async function tryAdoptRunnerSessionFromLease( * the adopted session must be given what those probes left rather than a * fresh `startupTimeoutMs` (#2422). */ - phaseDeadline?: RunnerPhaseDeadline; + phaseDeadline?: Deadline; + /** The owning request's cancellation signal, forwarded to those probes. */ + signal?: AbortSignal; expectedRunnerSessionId?: string; }, ): Promise { @@ -101,6 +104,7 @@ export async function tryAdoptRunnerSessionFromLease( } const expectedDerived = resolveExpectedDerivedPath(device, { deadline: options.phaseDeadline, + signal: options.signal, }); if (!expectedDerived) return skip('expected_derived_unresolved'); if (!lease.xctestrunPath.startsWith(`${expectedDerived}${path.sep}`)) { @@ -158,7 +162,12 @@ function resolveExpectedDerivedPath( device, resolveExpectedRunnerCacheMetadata(device, undefined, budget), ); - } catch { + } catch (error) { + // An unresolvable fingerprint is a miss the caller recovers from by starting + // fresh. A canceled request is not: the client that asked for this startup + // is gone, so it leaves through the catch rather than becoming one more + // reason to keep going. + if (isRequestCanceledError(error)) throw error; return null; } } @@ -168,7 +177,7 @@ function buildAdoptedRunnerSession( lease: RunnerLease, runnerPid: number, expectedDerived: string, - options: { startupTimeoutMs?: number; phaseDeadline?: RunnerPhaseDeadline }, + options: { startupTimeoutMs?: number; phaseDeadline?: Deadline }, ): RunnerSession & { lease: RunnerLease } { const sessionId = lease.sessionId; const artifact: RunnerXctestrunArtifact = { diff --git a/packages/platform-apple/src/runner/runner-artifact.ts b/packages/platform-apple/src/runner/runner-artifact.ts index 558426618d..773710c21e 100644 --- a/packages/platform-apple/src/runner/runner-artifact.ts +++ b/packages/platform-apple/src/runner/runner-artifact.ts @@ -5,6 +5,7 @@ import os from 'node:os'; import path from 'node:path'; import { runCmdStreaming, + type Deadline, type ExecBackgroundResult, withKeyedLock, emitRequestProgress, @@ -33,7 +34,6 @@ import { resolveRunnerSigningBuildSettings, writeRunnerCacheMetadataForArtifacts, type ExistingXctestrunState, - type RunnerPhaseDeadline, type RunnerXctestrunCacheKind, type RunnerXctestrunCacheMetadata, } from './runner-cache.ts'; @@ -165,7 +165,7 @@ function resolveExternalXctestDerivedDataPath(xctestrunPath: string): string { async function ensureXctestrunUnderCacheLock(params: { device: DeviceInfo; options: RunnerXctestrunBuildOptions; - phaseDeadline: RunnerPhaseDeadline | undefined; + phaseDeadline: Deadline | undefined; projectRoot: string; expectedCacheMetadata: RunnerXctestrunCacheMetadata; derived: string; @@ -237,7 +237,7 @@ async function resolveReusableXctestrunArtifact(params: { async function buildXctestrunArtifact(params: { device: DeviceInfo; options: RunnerXctestrunBuildOptions; - phaseDeadline: RunnerPhaseDeadline | undefined; + phaseDeadline: Deadline | undefined; projectRoot: string; expectedCacheMetadata: RunnerXctestrunCacheMetadata; derived: string; diff --git a/packages/platform-apple/src/runner/runner-cache-metadata.ts b/packages/platform-apple/src/runner/runner-cache-metadata.ts index a381b0a284..70ce1780c5 100644 --- a/packages/platform-apple/src/runner/runner-cache-metadata.ts +++ b/packages/platform-apple/src/runner/runner-cache-metadata.ts @@ -38,9 +38,6 @@ const RUNNER_CACHE_METADATA_VALUE_MAX_LENGTH = 300; * (#2422). */ const TOOLCHAIN_FINGERPRINT_BUDGET_MS = 45_000; - -const TOOLCHAIN_PROBE_BUDGET_EXHAUSTED_DETAIL = - 'the request budget for reading the toolchain was exhausted before this probe could run'; const TOOLCHAIN_PROBE_MAX_BUFFER = 128 * 1024; const TOOLCHAIN_PROBE_DETAIL_MAX_LENGTH = 200; const TOOLCHAIN_PROBE_HINT = @@ -70,23 +67,16 @@ type ToolchainProbeFailure = { }; /** - * The one clock a runner phase spends: the cache decision's blocking toolchain - * probes and the step the phase exists for (an `xcodebuild` build, a runner - * startup) both read it, so what the probes spend is time the step no longer - * has. Create it once per phase with {@link createRunnerPhaseDeadline} and read - * the rest with {@link requireRunnerPhaseRemainingMs}; a step that hands the - * probes a timeout and then hands itself the same number again spends the - * phase's budget twice (#2422). - */ -export type RunnerPhaseDeadline = Deadline; - -/** - * The phase clock for a step whose budget is `timeoutMs`, or `undefined` for a - * caller that carries no budget at all (background and preflight surfaces). + * The one clock a runner phase spends, for a step whose budget is `timeoutMs`; + * `undefined` for a caller that carries no budget at all (background and + * preflight surfaces). The cache decision's blocking toolchain probes and the + * step the phase exists for (an `xcodebuild` build, a runner startup) both read + * it, so what the probes spend is time the step no longer has. Create it once + * per phase and read the rest with {@link requireRunnerPhaseRemainingMs}; a + * step that hands the probes a timeout and then hands itself the same number + * again spends the phase's budget twice (#2422). */ -export function createRunnerPhaseDeadline( - timeoutMs: number | undefined, -): RunnerPhaseDeadline | undefined { +export function createRunnerPhaseDeadline(timeoutMs: number | undefined): Deadline | undefined { if (timeoutMs === undefined || !Number.isFinite(timeoutMs)) return undefined; return Deadline.fromTimeoutMs(Math.max(0, timeoutMs)); } @@ -98,22 +88,30 @@ export function createRunnerPhaseDeadline( * would have to kill immediately. */ export function requireRunnerPhaseRemainingMs( - deadline: RunnerPhaseDeadline | undefined, + deadline: Deadline | undefined, fallbackTimeoutMs: number | undefined, phase: string, ): number | undefined { if (!deadline) return fallbackTimeoutMs; const remainingMs = Math.floor(deadline.remainingMs()); - if (remainingMs <= 0) { - throw new AppError('COMMAND_FAILED', 'The Apple runner budget ran out before this step began', { - phase, - reason: 'runner_phase_budget_exhausted', - retriable: true, - }); - } + if (remainingMs <= 0) throw runnerPhaseBudgetExhaustedError(phase); return remainingMs; } +/** + * The one error a runner phase raises when a step is reached with nothing left + * to spend, whether that step is an `xcodebuild` build, a runner startup, or a + * toolchain probe. It says the budget ran out, not that the thing it would have + * run is broken. + */ +function runnerPhaseBudgetExhaustedError(phase: string): AppError { + return new AppError('COMMAND_FAILED', 'The Apple runner budget ran out before this step began', { + phase, + reason: 'runner_phase_budget_exhausted', + retriable: true, + }); +} + /** * What the phase that wants a runner cache decision has left to spend on it. * The decision blocks the calling request on up to three synchronous `spawnSync` @@ -129,7 +127,7 @@ export function requireRunnerPhaseRemainingMs( */ export type RunnerCacheProbeBudget = { /** The owning phase's clock, shared with whatever the phase does next. */ - deadline?: RunnerPhaseDeadline; + deadline?: Deadline; /** The owning request's cancellation signal, if it carries one. */ signal?: AbortSignal; }; @@ -149,19 +147,20 @@ type ToolchainProbeClock = { function createToolchainProbeClock( budget: RunnerCacheProbeBudget | undefined, ): ToolchainProbeClock { - // Two clocks, because they bound different things: the phase's, which the - // build or startup after these probes will read the remainder of, and the - // fingerprint's own ceiling, which stops a caller with a generous phase - // budget from spending minutes on three stalled tools. const phaseDeadline = budget?.deadline; - const fingerprintDeadline = Deadline.fromTimeoutMs(TOOLCHAIN_FINGERPRINT_BUDGET_MS); + // The fingerprint's own deadline, opened at whichever of the two ceilings is + // nearer: the phase's remainder, or the fingerprint budget for a caller with + // no phase clock (or a generous one). Both are wall-clock, so the step after + // the probes still sees the time they spent. + const deadline = Deadline.fromTimeoutMs( + Math.min( + TOOLCHAIN_FINGERPRINT_BUDGET_MS, + phaseDeadline ? phaseDeadline.remainingMs() : Number.POSITIVE_INFINITY, + ), + ); return { attemptTimeoutMs: () => - Math.min( - coldToolchainProbeTimeoutMs(), - Math.floor(fingerprintDeadline.remainingMs()), - phaseDeadline ? Math.floor(phaseDeadline.remainingMs()) : Number.POSITIVE_INFINITY, - ), + Math.min(coldToolchainProbeTimeoutMs(), Math.floor(deadline.remainingMs())), throwIfCanceled: () => { if (budget?.signal?.aborted) { throw createRequestCanceledError({ phase: 'apple_toolchain_probe' }); @@ -347,12 +346,13 @@ function runToolchainProbe( clock: ToolchainProbeClock, ): ProbeResult { const probe = [cmd, ...args].join(' '); - // Both checks are outside the try: a canceled request is the caller's own - // error to see, and an exhausted budget must not start another blocking - // spawnSync just to time out again. + // Both checks are outside the try, and both throw rather than becoming a + // probe failure: a canceled request and a spent budget are the caller's own + // errors to see. Reporting an unreadable toolchain instead would blame the + // toolchain for a probe that never ran. clock.throwIfCanceled(); if (clock.attemptTimeoutMs() <= 0) { - return probeFailure(probe, 'probe_error', TOOLCHAIN_PROBE_BUDGET_EXHAUSTED_DETAIL); + throw runnerPhaseBudgetExhaustedError('apple_toolchain_probe'); } let output: { exitCode: number; stdout: string; stderr: string }; try { @@ -376,9 +376,9 @@ function runToolchainProbe( * Runs one toolchain probe, retrying exactly once if the attempt timed out and * the shared budget still has room. Apple's syspolicyd signature scan blocks * the first `xcodebuild`/`xcrun` exec after a fresh host boots (see - * `COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` in `../core/config.ts`, which reaches this - * file through the host port); the immediate next exec of the same tool is - * instant, so the retry recovers without widening the per-call budget. Only the + * `COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` in `@agent-device/host-kit/command`, which + * reaches this file through the host port); the immediate next exec of the same + * tool is instant, so the retry recovers without widening the per-call budget. Only the * exec layer's structured timeout is retried -- a tool that failed on its own * and merely said "timed out" in its output is not this stall. */ diff --git a/packages/platform-apple/src/runner/runner-cache.ts b/packages/platform-apple/src/runner/runner-cache.ts index 252896e10f..246d6fc532 100644 --- a/packages/platform-apple/src/runner/runner-cache.ts +++ b/packages/platform-apple/src/runner/runner-cache.ts @@ -29,7 +29,6 @@ export { resolveRunnerPerformanceBuildSettings, resolveRunnerSandboxBuildArgs, resolveRunnerSigningBuildSettings, - type RunnerPhaseDeadline, type RunnerXctestrunCacheMetadata, } from './runner-cache-metadata.ts'; diff --git a/packages/platform-apple/src/runner/runner-session.ts b/packages/platform-apple/src/runner/runner-session.ts index 89b88e1d9b..4098bef9a2 100644 --- a/packages/platform-apple/src/runner/runner-session.ts +++ b/packages/platform-apple/src/runner/runner-session.ts @@ -27,7 +27,6 @@ import { resolveExpectedRunnerCacheMetadata, resolveRunnerDerivedPath, type RunnerCacheProbeBudget, - type RunnerPhaseDeadline, } from './runner-xctestrun.ts'; import { resolveRunnerRequestSignal, @@ -138,7 +137,7 @@ export async function ensureRunnerSession( async function startRunnerSessionWithLease( device: DeviceInfo, options: RunnerSessionOptions, - phaseDeadline: RunnerPhaseDeadline | undefined, + phaseDeadline: Deadline | undefined, ): Promise { const startupTimings: Record = {}; // The owning request's abort signal so a client disconnect kills the blocking @@ -165,6 +164,7 @@ async function startRunnerSessionWithLease( await tryAdoptRunnerSessionFromLease(device, { startupTimeoutMs: options.startupTimeoutMs, phaseDeadline, + signal, expectedRunnerSessionId: options.expectedRunnerSessionId, }), ); diff --git a/packages/platform-apple/src/runner/runner-xctestrun.ts b/packages/platform-apple/src/runner/runner-xctestrun.ts index 66f1cf4f38..ca024295fc 100644 --- a/packages/platform-apple/src/runner/runner-xctestrun.ts +++ b/packages/platform-apple/src/runner/runner-xctestrun.ts @@ -19,6 +19,5 @@ export { resolveRunnerAppBundleId, resolveRunnerDerivedPath, type RunnerCacheProbeBudget, - type RunnerPhaseDeadline, } from './runner-cache-metadata.ts'; export { acquireXcodebuildSimulatorSetRedirect } from './runner-device-set.ts'; diff --git a/packages/platform-apple/src/snapshot-source/cache-identity.test.ts b/packages/platform-apple/src/snapshot-source/cache-identity.test.ts index af417da7bd..0a81965027 100644 --- a/packages/platform-apple/src/snapshot-source/cache-identity.test.ts +++ b/packages/platform-apple/src/snapshot-source/cache-identity.test.ts @@ -4,6 +4,7 @@ import { AppError } from '@agent-device/kernel/errors'; import { createSnapshotSourceHost } from './host.ts'; import { readSnapshotSourceToolchain } from './cache-identity.ts'; import { createSnapshotSourceDeadline, type SnapshotSourceDeadline } from './deadline.ts'; +import { SnapshotSourceError } from './errors.ts'; import type { ExecOptions, ExecResult } from '@agent-device/host-kit/command'; import type { SnapshotSourceHost } from './types.ts'; @@ -82,6 +83,38 @@ test('a toolchain host that never returns still fails at the deadline with the s assert.equal(clock.nowMs, 60_000); }); +test('a request canceled while a probe blocked surfaces the cancellation, not the timeout', async () => { + const clock = { nowMs: 0 }; + const request = new AbortController(); + let calls = 0; + const host = fakeToolchainHost((command, _args, options) => { + calls += 1; + const timeout = blockForWholeTimeout(clock, command, options); + // The abort lands while the attempt is still blocked, which is the case the + // deadline alone cannot tell from a plain timeout: it still has room. + request.abort(); + throw timeout; + }); + + await assert.rejects( + readSnapshotSourceToolchain( + host, + 'iOS 26.2', + createSnapshotSourceDeadline(120_000, request.signal, () => clock.nowMs), + ), + (error: unknown) => { + assert.ok(error instanceof SnapshotSourceError); + assert.equal(error.failureKind, 'cancelled'); + assert.equal(error.failureCode, 'abort-signal'); + assert.equal(error.details?.reason, 'request_canceled'); + return true; + }, + ); + // The deadline still had 90 s, so only the cancellation stops the retry. + assert.equal(calls, 1); + assert.equal(clock.nowMs, 30_000); +}); + test('a probe that failed on its own and merely says "timed out" in its message is not retried', async () => { const clock = { nowMs: 0 }; let calls = 0; diff --git a/packages/platform-apple/src/snapshot-source/cache-identity.ts b/packages/platform-apple/src/snapshot-source/cache-identity.ts index 5b7c057743..86ac65627a 100644 --- a/packages/platform-apple/src/snapshot-source/cache-identity.ts +++ b/packages/platform-apple/src/snapshot-source/cache-identity.ts @@ -1,9 +1,10 @@ import { createHash } from 'node:crypto'; import path from 'node:path'; -import { isCommandTimeoutError, type ExecResult } from '@agent-device/host-kit/command'; -// The per-attempt toolchain probe budget both Apple toolchain probers read; see -// its doc comment there for the cold-start stall it is sized for (#2422). -import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../core/config.ts'; +import { + COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, + isCommandTimeoutError, + type ExecResult, +} from '@agent-device/host-kit/command'; import { snapshotSourceError } from './errors.ts'; import { remainingSnapshotSourceMs, type SnapshotSourceDeadline } from './deadline.ts'; import type { SnapshotSourceHost } from './types.ts'; @@ -111,6 +112,10 @@ async function toolOutput( * Only the exec layer's own structured timeout counts -- a tool that failed by * itself and merely said "timed out" in its output is not this stall and is not * retried. + * + * A request canceled while the attempt blocked is the caller's own outcome, so + * it is raised as this module's typed cancellation rather than as the timeout + * that happened to be in flight when the abort landed. */ async function runToolchainProbe( host: SnapshotSourceHost, @@ -121,7 +126,9 @@ async function runToolchainProbe( try { return await execToolchainProbe(host, command, args, deadline); } catch (error) { - if (!isCommandTimeoutError(error) || !toolchainProbeDeadlineHasRoom(deadline)) throw error; + if (!isCommandTimeoutError(error)) throw error; + if (deadline.signal?.aborted) throw snapshotSourceError('cancelled', 'abort-signal'); + if (deadline.clock.remainingMs(deadline.now()) <= 0) throw error; return await execToolchainProbe(host, command, args, deadline); } } @@ -141,7 +148,3 @@ function execToolchainProbe( ), }); } - -function toolchainProbeDeadlineHasRoom(deadline: SnapshotSourceDeadline): boolean { - return !deadline.signal?.aborted && deadline.clock.remainingMs(deadline.now()) > 0; -} From 47220f68e80b0a0f44c4e1d00075960e05d0ea2c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Thu, 10 Sep 2026 12:47:37 +0200 Subject: [PATCH 6/9] fix(apple): check cancellation before the warm toolchain fingerprint cache --- .../runner/__tests__/runner-adoption.test.ts | 33 +++++++++++++++++-- .../__tests__/runner-cache-metadata.test.ts | 17 +++++++++- .../src/runner/runner-cache-metadata.ts | 7 +++- 3 files changed, 53 insertions(+), 4 deletions(-) diff --git a/packages/platform-apple/src/runner/__tests__/runner-adoption.test.ts b/packages/platform-apple/src/runner/__tests__/runner-adoption.test.ts index 53e5999ff3..a965252528 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-adoption.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-adoption.test.ts @@ -3,6 +3,7 @@ import path from 'node:path'; import { afterEach, beforeEach, expect, test, vi } from 'vitest'; import type { DeviceInfo } from '@agent-device/kernel/device'; import { createRequestCanceledError, isRequestCanceledError } from '@agent-device/kernel/errors'; +import { resetAllProcessMemosForTests } from '@agent-device/kernel/ttl-memo'; import { buildDetachedRunnerLease, buildRunnerLease, @@ -14,6 +15,7 @@ import { isIosRunnerDetachEnabled, tryAdoptRunnerSessionFromLease } from '../run import { sendRunnerCommandOnce } from '../runner-transport.ts'; import { resolveExpectedRunnerCacheMetadata } from '../runner-xctestrun.ts'; import { appleRunnerTestHost } from '../test-host.ts'; +import { appleToolchainProbeResult } from './apple-toolchain-fixtures.ts'; import { mkdtempForTestSync } from './tmp-dir.ts'; vi.mock('../runner-transport.ts', async (importOriginal) => { @@ -143,12 +145,12 @@ test('adoption succeeds for a live, matching, probe-healthy runner', async () => expect(readStaleRunnerLease(simulator.id)).toBeNull(); }); -test('a request canceled during the fingerprint probe fails adoption instead of skipping it', async () => { +test('a request canceled during the fingerprint probe fails adoption instead of skipping it, cold or with the fingerprint cache warm', async () => { // The fingerprint check runs the same blocking toolchain probes a fresh // startup would, and it is handed the request's signal. A cancellation from // there is not an unresolvable derived path: swallowing it would let startup // walk on past a client that is already gone (#2422). - writeStaleLease(); + const lease = writeStaleLease(); mockIsProcessAlive.mockReturnValue(true); const request = new AbortController(); request.abort(); @@ -162,6 +164,33 @@ test('a request canceled during the fingerprint probe fails adoption instead of tryAdoptRunnerSessionFromLease(simulator, { signal: request.signal }), ).rejects.toSatisfy(isRequestCanceledError); expect(mockSendRunnerCommandOnce).not.toHaveBeenCalled(); + + // The mock above only proves adoption propagates whatever the fingerprint + // call throws. Exercise the real production code path too: warm the actual + // toolchain fingerprint memo (the module-level cache in + // runner-cache-metadata.ts is a singleton the mock above never touches), + // then adopt again with an already-aborted signal. Before the fix, + // requireRunnerToolchainFingerprint returned the memoized value without + // checking the signal, so a cache hit let adoption go on to probe uptime + // and write the lease for an already-canceled request (#2422 round 4). + resetAllProcessMemosForTests(); + const { resolveExpectedRunnerCacheMetadata: actualResolveExpectedRunnerCacheMetadata } = + await vi.importActual('../runner-xctestrun.ts'); + appleRunnerTestHost.update({ runCmdSync: vi.fn(appleToolchainProbeResult) }); + actualResolveExpectedRunnerCacheMetadata(simulator); + + const warmRequest = new AbortController(); + warmRequest.abort(); + mockResolveExpectedRunnerCacheMetadata.mockImplementationOnce( + actualResolveExpectedRunnerCacheMetadata, + ); + + await expect( + tryAdoptRunnerSessionFromLease(simulator, { signal: warmRequest.signal }), + ).rejects.toSatisfy(isRequestCanceledError); + expect(mockSendRunnerCommandOnce).not.toHaveBeenCalled(); + // Ownership was never transferred: the stale lease is untouched. + expect(readStaleRunnerLease(simulator.id)?.ownerToken).toBe(lease.ownerToken); }); test('adoption is skipped for a recycled runner pid (start time mismatch)', async () => { diff --git a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts index bb1c8fdd24..8ca62aab72 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts @@ -338,7 +338,7 @@ describe('toolchain probe budget', () => { assert.equal(runCmdSync.mock.calls.length, 1); }); - test('an already-canceled request runs no toolchain probe at all', () => { + test('an already-canceled request runs no toolchain probe at all, cold or with the fingerprint cache warm', () => { installFakeToolchainClock(); runCmdSync.mockClear(); @@ -350,6 +350,21 @@ describe('toolchain probe budget', () => { (error: unknown) => isRequestCanceledError(error), ); assert.equal(runCmdSync.mock.calls.length, 0); + + // Warm the real fingerprint memo with an ordinary request, then repeat + // with an already-aborted signal: the cache-hit path must check + // cancellation before it returns the memoized value, not skip it (#2422). + resolveExpectedRunnerCacheMetadata(IOS_SIMULATOR); + runCmdSync.mockClear(); + + assert.throws( + () => + resolveExpectedRunnerCacheMetadata(IOS_SIMULATOR, undefined, { + signal: AbortSignal.abort(), + }), + (error: unknown) => isRequestCanceledError(error), + ); + assert.equal(runCmdSync.mock.calls.length, 0); }); test('a probe that failed on its own and merely says "timed out" in its message is not retried', () => { diff --git a/packages/platform-apple/src/runner/runner-cache-metadata.ts b/packages/platform-apple/src/runner/runner-cache-metadata.ts index 70ce1780c5..c31825af5e 100644 --- a/packages/platform-apple/src/runner/runner-cache-metadata.ts +++ b/packages/platform-apple/src/runner/runner-cache-metadata.ts @@ -284,9 +284,14 @@ function requireRunnerToolchainFingerprint( sdkName: string, budget: RunnerCacheProbeBudget | undefined, ): RunnerToolchainFingerprint { + // Checked before the cache, not just before the probes: a canceled request + // must surface as canceled even on a cache hit, or adoption reads a stale + // "success" and goes on to probe uptime and write the lease (#2422). + const clock = createToolchainProbeClock(budget); + clock.throwIfCanceled(); const cached = toolchainFingerprintCache().get(sdkName); if (cached) return cached; - const fingerprint = readRunnerToolchainFingerprint(sdkName, createToolchainProbeClock(budget)); + const fingerprint = readRunnerToolchainFingerprint(sdkName, clock); if (!fingerprint.ok) throw unavailableToolchainError(fingerprint.failures); toolchainFingerprintCache().set(sdkName, fingerprint.value); return fingerprint.value; From b6611b6cf6a0b71df0152ee8028d0356f0471ee8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Thu, 10 Sep 2026 12:58:41 +0200 Subject: [PATCH 7/9] refactor(apple): guard each toolchain probe attempt in one place Fold the toolchain probe's three duplicated cancellation/budget guard sites (runToolchainProbe's pre-check, runToolchainProbeCommand's retry pre-check, and execToolchainProbeCommand's timeout computation) into one: attemptToolchainProbe checks cancellation and the remaining budget before every exec, first attempt and retry alike. The outer runToolchainProbe now rethrows cancellation and a spent budget instead of swallowing them into a probe failure, and only genuine probe errors become one. --- .../src/runner/runner-cache-metadata.ts | 42 +++++++++++-------- 1 file changed, 25 insertions(+), 17 deletions(-) diff --git a/packages/platform-apple/src/runner/runner-cache-metadata.ts b/packages/platform-apple/src/runner/runner-cache-metadata.ts index c31825af5e..b319c9321f 100644 --- a/packages/platform-apple/src/runner/runner-cache-metadata.ts +++ b/packages/platform-apple/src/runner/runner-cache-metadata.ts @@ -2,7 +2,11 @@ import crypto from 'node:crypto'; import os from 'node:os'; import path from 'node:path'; import { isMacOs, type DeviceInfo } from '@agent-device/kernel/device'; -import { AppError, createRequestCanceledError } from '@agent-device/kernel/errors'; +import { + AppError, + createRequestCanceledError, + isRequestCanceledError, +} from '@agent-device/kernel/errors'; import { coldToolchainProbeTimeoutMs, createTtlMemo, @@ -351,19 +355,14 @@ function runToolchainProbe( clock: ToolchainProbeClock, ): ProbeResult { const probe = [cmd, ...args].join(' '); - // Both checks are outside the try, and both throw rather than becoming a - // probe failure: a canceled request and a spent budget are the caller's own - // errors to see. Reporting an unreadable toolchain instead would blame the - // toolchain for a probe that never ran. - clock.throwIfCanceled(); - if (clock.attemptTimeoutMs() <= 0) { - throw runnerPhaseBudgetExhaustedError('apple_toolchain_probe'); - } let output: { exitCode: number; stdout: string; stderr: string }; try { output = runToolchainProbeCommand(cmd, args, clock); } catch (error) { - clock.throwIfCanceled(); + // A canceled request and a spent budget are the caller's own errors to + // see, not an unreadable toolchain: only what's left becomes a probe + // failure. + if (isRequestCanceledError(error) || isRunnerPhaseBudgetExhaustedError(error)) throw error; return probeFailure(probe, 'probe_error', error instanceof Error ? error.message : `${error}`); } if (output.exitCode !== 0) { @@ -385,7 +384,10 @@ function runToolchainProbe( * reaches this file through the host port); the immediate next exec of the same * tool is instant, so the retry recovers without widening the per-call budget. Only the * exec layer's structured timeout is retried -- a tool that failed on its own - * and merely said "timed out" in its output is not this stall. + * and merely said "timed out" in its output is not this stall. The retry calls + * the same guarded attempt below, so a request canceled or a budget spent + * between attempts is caught there rather than trusted from before the first + * one. */ function runToolchainProbeCommand( cmd: string, @@ -393,27 +395,33 @@ function runToolchainProbeCommand( clock: ToolchainProbeClock, ): { exitCode: number; stdout: string; stderr: string } { try { - return execToolchainProbeCommand(cmd, args, clock); + return attemptToolchainProbe(cmd, args, clock); } catch (error) { if (!isCommandTimeoutError(error)) throw error; - clock.throwIfCanceled(); - if (clock.attemptTimeoutMs() <= 0) throw error; - return execToolchainProbeCommand(cmd, args, clock); + return attemptToolchainProbe(cmd, args, clock); } } -function execToolchainProbeCommand( +/** The one guard site for a toolchain probe attempt: cancellation and a spent budget both throw here, before anything execs. */ +function attemptToolchainProbe( cmd: string, args: string[], clock: ToolchainProbeClock, ): { exitCode: number; stdout: string; stderr: string } { + clock.throwIfCanceled(); + const timeoutMs = clock.attemptTimeoutMs(); + if (timeoutMs <= 0) throw runnerPhaseBudgetExhaustedError('apple_toolchain_probe'); return runCmdSync(cmd, args, { allowFailure: true, - timeoutMs: clock.attemptTimeoutMs(), + timeoutMs, maxBuffer: TOOLCHAIN_PROBE_MAX_BUFFER, }); } +function isRunnerPhaseBudgetExhaustedError(error: unknown): boolean { + return error instanceof AppError && error.details?.reason === 'runner_phase_budget_exhausted'; +} + function parseXcodeVersionOutput( output: ProbeResult, ): ProbeResult<{ version: string; buildVersion: string }> { From c24d42c95e1178e0833e5d9641a6d04e1c60c6d7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Thu, 10 Sep 2026 14:24:28 +0200 Subject: [PATCH 8/9] fix(apple): keep cancellation typed when the final toolchain probe fails The guard fold left one gap: a request that aborts while the last probe is in flight and then fails with a non-timeout error has no next attempt whose guard could see the abort, so the catch classified it as an unreadable toolchain. The catch checks the signal again before classifying, as it did before the fold. --- .../__tests__/runner-cache-metadata.test.ts | 22 +++++++++++++++++++ .../src/runner/runner-cache-metadata.ts | 6 ++++- 2 files changed, 27 insertions(+), 1 deletion(-) diff --git a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts index 8ca62aab72..334ac878e5 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts @@ -338,6 +338,28 @@ describe('toolchain probe budget', () => { assert.equal(runCmdSync.mock.calls.length, 1); }); + test('a non-timeout error that also cancels the request on the last probe surfaces cancellation, not an unavailable toolchain', () => { + const request = new AbortController(); + runCmdSync.mockImplementation((command: string, args: string[]) => { + // The final probe: abort the request and fail with a plain command + // error, not the exec layer's structured timeout -- there is no next + // attempt left to catch the cancellation, so the catch here must. + if (command === 'xcrun' && args.includes('--show-sdk-build-version')) { + request.abort(); + throw new AppError('COMMAND_FAILED', 'xcrun: unexpected error', {}); + } + return appleToolchainProbeResult(command, args); + }); + runCmdSync.mockClear(); + + assert.throws( + () => + resolveExpectedRunnerCacheMetadata(IOS_SIMULATOR, undefined, { signal: request.signal }), + (error: unknown) => isRequestCanceledError(error), + ); + assert.equal(runCmdSync.mock.calls.length, 3); + }); + test('an already-canceled request runs no toolchain probe at all, cold or with the fingerprint cache warm', () => { installFakeToolchainClock(); runCmdSync.mockClear(); diff --git a/packages/platform-apple/src/runner/runner-cache-metadata.ts b/packages/platform-apple/src/runner/runner-cache-metadata.ts index b319c9321f..3a78f35bc8 100644 --- a/packages/platform-apple/src/runner/runner-cache-metadata.ts +++ b/packages/platform-apple/src/runner/runner-cache-metadata.ts @@ -361,7 +361,11 @@ function runToolchainProbe( } catch (error) { // A canceled request and a spent budget are the caller's own errors to // see, not an unreadable toolchain: only what's left becomes a probe - // failure. + // failure. Checked again here (not just in attemptToolchainProbe) because + // the request can abort while this exec is in flight, after its own guard + // already passed -- including on the last probe, where there is no next + // attempt left to catch it. + clock.throwIfCanceled(); if (isRequestCanceledError(error) || isRunnerPhaseBudgetExhaustedError(error)) throw error; return probeFailure(probe, 'probe_error', error instanceof Error ? error.message : `${error}`); } From b21efb055b485fcceb952dfa6c3f5c00d3a2a8eb Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Thu, 10 Sep 2026 16:09:45 +0200 Subject: [PATCH 9/9] refactor(apple): own the toolchain probe budget in platform-apple and trim narration COLD_TOOLCHAIN_PROBE_TIMEOUT_MS moves from @agent-device/host-kit/command to runner/apple-runner-platform.ts, beside the SDK names the probes are run against. Both Apple toolchain probers import it directly, so the runner host port no longer carries a coldToolchainProbeTimeoutMs() accessor for a plain number. isCommandTimeoutError stays in host-kit, where the exec layer stamps the detail it reads. The comments that narrated control flow the code already shows are gone; the cold-start stall rationale (on the constant), the spawnSync cancellation limitation (on the probe clock) and one line per phase-deadline creation site remain. --- packages/host-kit/src/command.ts | 1 - packages/host-kit/src/internal/exec.ts | 24 +---- .../platform-apple/src/core/runner-host.ts | 2 - .../__tests__/runner-cache-metadata.test.ts | 5 +- .../src/runner/apple-runner-platform.ts | 13 +++ packages/platform-apple/src/runner/host.ts | 17 +--- .../src/runner/runner-adoption.ts | 12 +-- .../src/runner/runner-artifact.ts | 10 +- .../src/runner/runner-cache-metadata.ts | 95 +++++-------------- .../src/runner/runner-session.ts | 10 +- .../src/snapshot-source/cache-identity.ts | 23 +---- .../src/snapshot-source/deadline.ts | 7 +- 12 files changed, 54 insertions(+), 165 deletions(-) diff --git a/packages/host-kit/src/command.ts b/packages/host-kit/src/command.ts index 6b32fb47b3..95e68a8f5a 100644 --- a/packages/host-kit/src/command.ts +++ b/packages/host-kit/src/command.ts @@ -1,6 +1,5 @@ export { coerceExecResult, - COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, type CommandExecutorOverride, type ExecBackgroundOptions, type ExecBackgroundResult, diff --git a/packages/host-kit/src/internal/exec.ts b/packages/host-kit/src/internal/exec.ts index b9f2bb646a..bb00134573 100644 --- a/packages/host-kit/src/internal/exec.ts +++ b/packages/host-kit/src/internal/exec.ts @@ -593,12 +593,9 @@ function createTimeoutError( } /** - * True only for the COMMAND_FAILED error this module raises when it kills a - * command at its own `timeoutMs` — the structured signal both timeout sites - * above stamp on `details.timeoutMs`. Callers that retry a timed-out command - * classify with this instead of matching the message text, so a command whose - * own output happens to say "timed out after 10ms" is not mistaken for a - * timeout the exec layer imposed. + * True only for the COMMAND_FAILED error this module raises when it kills a command at + * its own `timeoutMs`. Callers classify with this rather than matching the message text, + * so a command whose own output says "timed out" is not mistaken for one exec killed. */ export function isCommandTimeoutError(error: unknown): boolean { return ( @@ -608,21 +605,6 @@ export function isCommandTimeoutError(error: unknown): boolean { ); } -/** - * Ceiling on one Apple toolchain identity probe attempt (`xcodebuild -version`, - * `xcrun --show-sdk-version`, `sw_vers`, `uname`, …). On a fresh macOS host, - * Apple's syspolicyd signature scan blocks the very first `xcodebuild`/`xcrun`/ - * large-binary exec after boot for roughly 18 to 19 seconds at 0% CPU; the - * second exec of the same tool is instant. A budget sized for a warm toolchain - * (the old 10 s / 5 s split) trips on that cold-start stall and reports a bogus - * toolchain-probe timeout unrelated to the change under test (#2422). - * - * It sits beside {@link isCommandTimeoutError} because it is a property of - * exec'ing an Apple tool rather than of either prober: both Apple toolchain - * probers read this one value. - */ -export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; - function createExitError( executable: string, cmd: string, diff --git a/packages/platform-apple/src/core/runner-host.ts b/packages/platform-apple/src/core/runner-host.ts index fbe331b209..6ef48432c9 100644 --- a/packages/platform-apple/src/core/runner-host.ts +++ b/packages/platform-apple/src/core/runner-host.ts @@ -3,7 +3,6 @@ import { publishFileSync, acquireProcessLock } from '@agent-device/host-kit/file import { resolveIosSimulatorDeviceSetPath } from '@agent-device/kernel/device-isolation'; import { - COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, isCommandTimeoutError, requireExecSuccess, runCmdBackground, @@ -58,7 +57,6 @@ export const appleRunnerHost: AppleRunnerHost = { runCmdBackground, requireExecSuccess, isCommandTimeoutError, - coldToolchainProbeTimeoutMs: () => COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, emitDiagnostic, withDiagnosticTimer, retryWithPolicy, diff --git a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts index 334ac878e5..91415f15a7 100644 --- a/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts +++ b/packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts @@ -15,10 +15,7 @@ import { resolveRunnerSandboxBuildArgs, resolveExpectedRunnerCacheMetadata, } from '../runner-cache-metadata.ts'; -// The one owning module for the probe budget: host-kit's exec layer. The -// snapshot-source prober imports it from there directly; this file's probes read -// the same value through the runner host port (#2422). -import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '@agent-device/host-kit/command'; +import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../apple-runner-platform.ts'; import { appleToolchainProbeResult, stubAppleToolchainProbes } from './apple-toolchain-fixtures.ts'; const runCmdSync = stubAppleToolchainProbes(); diff --git a/packages/platform-apple/src/runner/apple-runner-platform.ts b/packages/platform-apple/src/runner/apple-runner-platform.ts index 481547af7f..72fbbea11d 100644 --- a/packages/platform-apple/src/runner/apple-runner-platform.ts +++ b/packages/platform-apple/src/runner/apple-runner-platform.ts @@ -6,6 +6,19 @@ import { type DeviceInfo, } from '@agent-device/kernel/device'; +/** + * Ceiling on one Apple toolchain identity probe attempt (`xcodebuild -version`, `xcrun + * --sdk --show-sdk-version`). On a fresh macOS host Apple's syspolicyd signature + * scan blocks the first `xcodebuild`/`xcrun` exec after boot for roughly 18 to 19 seconds + * at 0% CPU, and the next exec of the same tool is instant; a budget sized for a warm + * toolchain (the old 10 s / 5 s split) trips on that stall and reports a toolchain + * timeout that says nothing about the toolchain (#2422). + * + * It sits beside the SDK names the probes run against so both Apple toolchain probers + * read one value without either owning it. + */ +export const COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000; + export type RunnerApplePlatformName = 'iOS' | 'tvOS' | 'macOS' | 'visionOS'; type RunnerPlatformDeviceKind = 'simulator' | 'device'; diff --git a/packages/platform-apple/src/runner/host.ts b/packages/platform-apple/src/runner/host.ts index 5e3c51a6ae..6e17e8fb66 100644 --- a/packages/platform-apple/src/runner/host.ts +++ b/packages/platform-apple/src/runner/host.ts @@ -149,21 +149,8 @@ export type AppleRunnerHost = { message: string, extra?: Record | ((result: ExecResult) => Record), ): ExecResult; - /** - * True only for the error the exec layer raises when it killed a command at - * the `timeoutMs` the caller asked for, read from the structured detail it - * stamps rather than from the message text. - */ + /** True only for the error the exec layer raises when it killed a command at `timeoutMs`. */ isCommandTimeoutError(error: unknown): boolean; - /** - * Ceiling on one Apple toolchain identity probe attempt, in milliseconds: - * `COLD_TOOLCHAIN_PROBE_TIMEOUT_MS` from `@agent-device/host-kit/command`, - * which owns it for both Apple toolchain probers. Like every other host-kit - * symbol above it arrives through this port rather than by import, because - * `scripts/__tests__/eager-closure-budgets.test.ts` holds the runner entry to - * the modules it evaluates today and a static edge to host-kit adds five. - */ - coldToolchainProbeTimeoutMs(): number; // Diagnostics (@agent-device/host-kit/diagnostics) emitDiagnostic(event: DiagnosticEventInput): void; withDiagnosticTimer( @@ -294,8 +281,6 @@ export const requireExecSuccess: AppleRunnerHost['requireExecSuccess'] = (result requireHost().requireExecSuccess(result, message, extra); export const isCommandTimeoutError: AppleRunnerHost['isCommandTimeoutError'] = (error) => requireHost().isCommandTimeoutError(error); -export const coldToolchainProbeTimeoutMs: AppleRunnerHost['coldToolchainProbeTimeoutMs'] = () => - requireHost().coldToolchainProbeTimeoutMs(); export const emitDiagnostic: AppleRunnerHost['emitDiagnostic'] = (event) => requireHost().emitDiagnostic(event); export const withDiagnosticTimer = ( diff --git a/packages/platform-apple/src/runner/runner-adoption.ts b/packages/platform-apple/src/runner/runner-adoption.ts index bdb8242bdc..ad97f5e7d9 100644 --- a/packages/platform-apple/src/runner/runner-adoption.ts +++ b/packages/platform-apple/src/runner/runner-adoption.ts @@ -55,12 +55,7 @@ export async function tryAdoptRunnerSessionFromLease( device: DeviceInfo, options: { startupTimeoutMs?: number; - /** - * The startup phase's clock, shared with the caller. The fingerprint check - * below runs the same blocking toolchain probes a fresh startup would, so - * the adopted session must be given what those probes left rather than a - * fresh `startupTimeoutMs` (#2422). - */ + /** The startup phase's clock: the fingerprint check below spends from it (#2422). */ phaseDeadline?: Deadline; /** The owning request's cancellation signal, forwarded to those probes. */ signal?: AbortSignal; @@ -163,10 +158,7 @@ function resolveExpectedDerivedPath( resolveExpectedRunnerCacheMetadata(device, undefined, budget), ); } catch (error) { - // An unresolvable fingerprint is a miss the caller recovers from by starting - // fresh. A canceled request is not: the client that asked for this startup - // is gone, so it leaves through the catch rather than becoming one more - // reason to keep going. + // An unresolvable fingerprint is a miss the caller starts fresh from; a cancel is not. if (isRequestCanceledError(error)) throw error; return null; } diff --git a/packages/platform-apple/src/runner/runner-artifact.ts b/packages/platform-apple/src/runner/runner-artifact.ts index 773710c21e..af7156d46e 100644 --- a/packages/platform-apple/src/runner/runner-artifact.ts +++ b/packages/platform-apple/src/runner/runner-artifact.ts @@ -90,11 +90,7 @@ export async function ensureXctestrunArtifact( if (external) return external; const projectRoot = findProjectRoot(); - // One clock for the whole build phase. The cache decision runs blocking - // toolchain probes before any build starts, so a cold probe's stall is time - // the build no longer has: both read this deadline rather than each starting - // from a fresh copy of `buildTimeoutMs` (#2422). The cache lock, the reuse - // evaluation, and the cleanup between them are on it too. + // One clock for the whole build phase: the toolchain probes and the xcodebuild share it. const phaseDeadline = createRunnerPhaseDeadline(options.buildTimeoutMs); const expectedCacheMetadata = resolveExpectedRunnerCacheMetadata(device, projectRoot, { deadline: phaseDeadline, @@ -260,10 +256,6 @@ async function buildXctestrunArtifact(params: { throw new AppError('COMMAND_FAILED', 'iOS runner project not found', { projectPath }); } - // What the phase has left after the toolchain probes, the cache lock, and the - // reuse evaluation -- computed before the build announces itself, so a phase - // already spent fails here instead of starting an xcodebuild it would have to - // kill at once (#2422). const buildTimeoutMs = requireRunnerPhaseRemainingMs( phaseDeadline, options.buildTimeoutMs, diff --git a/packages/platform-apple/src/runner/runner-cache-metadata.ts b/packages/platform-apple/src/runner/runner-cache-metadata.ts index 3a78f35bc8..15a402d844 100644 --- a/packages/platform-apple/src/runner/runner-cache-metadata.ts +++ b/packages/platform-apple/src/runner/runner-cache-metadata.ts @@ -8,7 +8,6 @@ import { isRequestCanceledError, } from '@agent-device/kernel/errors'; import { - coldToolchainProbeTimeoutMs, createTtlMemo, Deadline, isCommandTimeoutError, @@ -19,6 +18,7 @@ import { type TtlMemo, } from './host.ts'; import { + COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, resolveRunnerBuildDestinationFamily, resolveRunnerDerivedBaseName, resolveRunnerPlatformName, @@ -33,13 +33,9 @@ const RUNNER_CACHE_SCHEMA_VERSION = 2; const RUNNER_CACHE_METADATA_VALUE_MAX_LENGTH = 300; /** - * Ceiling on the wall clock the whole toolchain fingerprint may spend, across - * all three probes and their retries, when the owning phase carries no shorter - * budget. Sized for the one cold-start stall the retry exists for -- a single - * stalled probe (up to the host's `coldToolchainProbeTimeoutMs()`) plus its - * now-warm retry and the two remaining probes -- not for three independently - * stalling tools, which is why the per-call timeout alone is not the bound - * (#2422). + * Ceiling on the wall clock the whole toolchain fingerprint may spend, across all three + * probes and their retries, when the owning phase carries no shorter budget: one stalled + * probe, its warm retry, and the two probes still to run (#2422). */ const TOOLCHAIN_FINGERPRINT_BUDGET_MS = 45_000; const TOOLCHAIN_PROBE_MAX_BUFFER = 128 * 1024; @@ -71,14 +67,8 @@ type ToolchainProbeFailure = { }; /** - * The one clock a runner phase spends, for a step whose budget is `timeoutMs`; - * `undefined` for a caller that carries no budget at all (background and - * preflight surfaces). The cache decision's blocking toolchain probes and the - * step the phase exists for (an `xcodebuild` build, a runner startup) both read - * it, so what the probes spend is time the step no longer has. Create it once - * per phase and read the rest with {@link requireRunnerPhaseRemainingMs}; a - * step that hands the probes a timeout and then hands itself the same number - * again spends the phase's budget twice (#2422). + * The one clock a runner phase spends, created once per phase and read with + * {@link requireRunnerPhaseRemainingMs}; `undefined` for a caller carrying no budget. */ export function createRunnerPhaseDeadline(timeoutMs: number | undefined): Deadline | undefined { if (timeoutMs === undefined || !Number.isFinite(timeoutMs)) return undefined; @@ -86,10 +76,8 @@ export function createRunnerPhaseDeadline(timeoutMs: number | undefined): Deadli } /** - * What the phase has left for its next step, or `fallbackTimeoutMs` when it - * carries no deadline. Throws instead of returning zero: a step reached with - * nothing left must fail before it spawns anything, not start a process it - * would have to kill immediately. + * What the phase has left for its next step, or `fallbackTimeoutMs` when it carries no + * deadline. Throws rather than returning zero, so a spent phase fails before it spawns. */ export function requireRunnerPhaseRemainingMs( deadline: Deadline | undefined, @@ -102,12 +90,7 @@ export function requireRunnerPhaseRemainingMs( return remainingMs; } -/** - * The one error a runner phase raises when a step is reached with nothing left - * to spend, whether that step is an `xcodebuild` build, a runner startup, or a - * toolchain probe. It says the budget ran out, not that the thing it would have - * run is broken. - */ +/** Says the phase budget ran out, not that the step it would have run is broken. */ function runnerPhaseBudgetExhaustedError(phase: string): AppError { return new AppError('COMMAND_FAILED', 'The Apple runner budget ran out before this step began', { phase, @@ -117,17 +100,8 @@ function runnerPhaseBudgetExhaustedError(phase: string): AppError { } /** - * What the phase that wants a runner cache decision has left to spend on it. - * The decision blocks the calling request on up to three synchronous `spawnSync` - * probes, so the phase's own deadline and cancellation must reach them: an - * exhausted budget fails the decision instead of starting another 30 second - * probe, and a canceled request surfaces the cancellation rather than - * retrying (#2422). A caller with neither still gets - * {@link TOOLCHAIN_FINGERPRINT_BUDGET_MS} as the ceiling. - * - * `spawnSync` cannot be interrupted once it has started, so cancellation is - * observed between attempts; the per-attempt cap is what bounds how long that - * takes. + * What the phase that wants a runner cache decision has left to spend on it. A caller + * with neither field still gets {@link TOOLCHAIN_FINGERPRINT_BUDGET_MS} as the ceiling. */ export type RunnerCacheProbeBudget = { /** The owning phase's clock, shared with whatever the phase does next. */ @@ -137,9 +111,11 @@ export type RunnerCacheProbeBudget = { }; /** - * The remaining-time and cancellation view the probes consult. One is created - * per fingerprint read, so the three probes and their retries share -- and - * together cannot exceed -- a single budget. + * The remaining-time and cancellation view the probes consult: one per fingerprint read, + * so the three probes and their retries share a single budget. + * + * `spawnSync` cannot be interrupted once it has started, so cancellation is observed + * between attempts; the per-attempt cap is what bounds how long that takes. */ type ToolchainProbeClock = { /** Milliseconds the next attempt may block for; 0 once the budget is spent. */ @@ -152,10 +128,6 @@ function createToolchainProbeClock( budget: RunnerCacheProbeBudget | undefined, ): ToolchainProbeClock { const phaseDeadline = budget?.deadline; - // The fingerprint's own deadline, opened at whichever of the two ceilings is - // nearer: the phase's remainder, or the fingerprint budget for a caller with - // no phase clock (or a generous one). Both are wall-clock, so the step after - // the probes still sees the time they spent. const deadline = Deadline.fromTimeoutMs( Math.min( TOOLCHAIN_FINGERPRINT_BUDGET_MS, @@ -164,7 +136,7 @@ function createToolchainProbeClock( ); return { attemptTimeoutMs: () => - Math.min(coldToolchainProbeTimeoutMs(), Math.floor(deadline.remainingMs())), + Math.min(COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, Math.floor(deadline.remainingMs())), throwIfCanceled: () => { if (budget?.signal?.aborted) { throw createRequestCanceledError({ phase: 'apple_toolchain_probe' }); @@ -279,18 +251,14 @@ function toolchainFingerprintCache(): TtlMemo { - // One clock for the whole startup phase. The reuse check runs the same - // blocking toolchain probes the startup after it would, so a cold probe's - // stall is time the startup no longer has: everything below reads what this - // deadline has left rather than `startupTimeoutMs` again (#2422). + // One clock for the whole startup phase: the toolchain probes and the startup share it. const phaseDeadline = createRunnerPhaseDeadline(options.startupTimeoutMs); const existing = runnerSessions.get(device.id); if (existing) { @@ -195,10 +192,7 @@ async function startRunnerSessionWithLease( phase: 'ios_runner_startup_cleanup_stale_bundles_skipped', }); } - // What the startup phase has left after the reuse probe, the adoption attempt - // and the pre-build cleanup. Read before the build rather than after it: the - // build answers to its own `buildTimeoutMs` deadline, so charging it to the - // startup budget as well would spend that budget twice over (#2422). + // Read before the build, which answers to its own `buildTimeoutMs` deadline (#2422). const startupTimeoutMs = requireRunnerPhaseRemainingMs( phaseDeadline, options.startupTimeoutMs, diff --git a/packages/platform-apple/src/snapshot-source/cache-identity.ts b/packages/platform-apple/src/snapshot-source/cache-identity.ts index 86ac65627a..785b8708ba 100644 --- a/packages/platform-apple/src/snapshot-source/cache-identity.ts +++ b/packages/platform-apple/src/snapshot-source/cache-identity.ts @@ -1,10 +1,7 @@ import { createHash } from 'node:crypto'; import path from 'node:path'; -import { - COLD_TOOLCHAIN_PROBE_TIMEOUT_MS, - isCommandTimeoutError, - type ExecResult, -} from '@agent-device/host-kit/command'; +import { isCommandTimeoutError, type ExecResult } from '@agent-device/host-kit/command'; +import { COLD_TOOLCHAIN_PROBE_TIMEOUT_MS } from '../runner/apple-runner-platform.ts'; import { snapshotSourceError } from './errors.ts'; import { remainingSnapshotSourceMs, type SnapshotSourceDeadline } from './deadline.ts'; import type { SnapshotSourceHost } from './types.ts'; @@ -103,19 +100,9 @@ async function toolOutput( } /** - * Runs one toolchain probe, retrying exactly once if the attempt timed out - * and the deadline still has room. The retry absorbs the cold-start - * signature-verification stall named on COLD_TOOLCHAIN_PROBE_TIMEOUT_MS: the - * first exec of a tool on a fresh host can block for that long, but the - * immediate next exec of the same tool is instant. Both attempts read one - * deadline, so the retry gets what the stall left rather than a fresh ceiling. - * Only the exec layer's own structured timeout counts -- a tool that failed by - * itself and merely said "timed out" in its output is not this stall and is not - * retried. - * - * A request canceled while the attempt blocked is the caller's own outcome, so - * it is raised as this module's typed cancellation rather than as the timeout - * that happened to be in flight when the abort landed. + * Retries exactly once, and only the exec layer's structured timeout: the stall + * {@link COLD_TOOLCHAIN_PROBE_TIMEOUT_MS} names clears on the next exec of the same tool. + * Both attempts read one deadline, so the retry gets what the stall left. */ async function runToolchainProbe( host: SnapshotSourceHost, diff --git a/packages/platform-apple/src/snapshot-source/deadline.ts b/packages/platform-apple/src/snapshot-source/deadline.ts index f0d5a2fe38..0e95de0ef4 100644 --- a/packages/platform-apple/src/snapshot-source/deadline.ts +++ b/packages/platform-apple/src/snapshot-source/deadline.ts @@ -3,12 +3,7 @@ import { snapshotSourceError } from './errors.ts'; export type SnapshotSourceDeadline = Readonly<{ clock: Deadline; - /** - * The clock the deadline is read against. Injected so a test can prove that a - * step which blocked for the timeout it was handed leaves the next step only - * the remainder -- a fake that throws instantly moves no time and so cannot - * tell a shared budget from a fresh one (#2422). - */ + /** The clock the deadline is read against; injected so a test can move time (#2422). */ now: () => number; signal: AbortSignal | undefined; }>;