Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions packages/host-kit/src/command.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ export {
execFailureDetails,
type ExecOptions,
type ExecResult,
isCommandTimeoutError,
isExecutablePath,
requireExecSuccess,
resolveExecutableOverridePath,
Expand Down
35 changes: 35 additions & 0 deletions packages/host-kit/src/internal/exec.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ import path from 'node:path';
import { flushDiagnosticsToSessionFile, withDiagnosticsScope } from './diagnostics.ts';
import {
coerceExecResult,
isCommandTimeoutError,
requireExecSuccess,
runCmd,
runCmdBackground,
Expand Down Expand Up @@ -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);
});
16 changes: 16 additions & 0 deletions packages/host-kit/src/internal/exec.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
2 changes: 2 additions & 0 deletions packages/platform-apple/src/core/runner-host.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -55,6 +56,7 @@ export const appleRunnerHost: AppleRunnerHost = {
runCmdSync,
runCmdBackground,
requireExecSuccess,
isCommandTimeoutError,
emitDiagnostic,
withDiagnosticTimer,
retryWithPolicy,
Expand Down
Original file line number Diff line number Diff line change
@@ -1,8 +1,12 @@
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,
resolveRunnerBundleBuildSettings,
resolveRunnerMaxConcurrentDestinationsFlag,
Expand All @@ -11,10 +15,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),
Expand Down Expand Up @@ -240,6 +254,184 @@ 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 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 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);
});

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);
});

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('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);
});

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'
Expand Down
8 changes: 8 additions & 0 deletions packages/platform-apple/src/runner/host.ts
Original file line number Diff line number Diff line change
Expand Up @@ -149,6 +149,12 @@ export type AppleRunnerHost = {
message: string,
extra?: Record<string, unknown> | ((result: ExecResult) => Record<string, unknown>),
): 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<T>(
Expand Down Expand Up @@ -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 = <T>(
Expand Down
15 changes: 12 additions & 3 deletions packages/platform-apple/src/runner/runner-adoption.ts
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ import {
import {
resolveExpectedRunnerCacheMetadata,
resolveRunnerDerivedPath,
type RunnerCacheProbeBudget,
type RunnerXctestrunArtifact,
} from './runner-xctestrun.ts';
import {
Expand Down Expand Up @@ -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');
Expand Down Expand Up @@ -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;
}
Expand Down
8 changes: 7 additions & 1 deletion packages/platform-apple/src/runner/runner-artifact.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Expand Down
Loading
Loading