Skip to content

Commit 8ebce7d

Browse files
committed
fix(ios-runner): bound a detached runner start by a budget it owns
A plain `wait` opened the lock-held start with no startup or build deadline. Once its caller deadline fired and the daemon cleared the request registration, nothing could end a wedged xctestrun build and every later command on the device queued behind the session lock. - ensureRunnerSession opens the start budget from startupTimeoutMs, else DEFAULT_RUNNER_START_BUDGET_MS (10 min: prepare defaults to 240 s, the iOS CI cold prepare gets 420 s, the cache-lock wait is already 10 min). A timer aborts the start's signal when spent, so exec kills xcodebuild, the lock is released and the caller sees runner_start_budget_exhausted. - the xctestrun build budget derives from the start budget; an explicit buildTimeoutMs can only shorten it. - launchDeadline never exceeds what the start budget has left: explicit startupTimeoutMs gives readiness the remainder, the default keeps the 45 s window. - a start that fails after its caller left logs ios_runner_detached_start_failed.
1 parent 54f18f6 commit 8ebce7d

3 files changed

Lines changed: 324 additions & 40 deletions

File tree

‎packages/platform-apple/src/runner/__tests__/runner-request-cancellation.test.ts‎

Lines changed: 172 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -68,8 +68,16 @@ vi.mock('../runner-xctestrun.ts', async () => {
6868
};
6969
});
7070

71-
import { createRequestCanceledError, isRequestCanceledError } from '@agent-device/kernel/errors';
72-
import { abortAllIosRunnerSessions, readRunnerSessionLiveness } from '../runner-session.ts';
71+
import {
72+
AppError,
73+
createRequestCanceledError,
74+
isRequestCanceledError,
75+
} from '@agent-device/kernel/errors';
76+
import {
77+
abortAllIosRunnerSessions,
78+
DEFAULT_RUNNER_START_BUDGET_MS,
79+
readRunnerSessionLiveness,
80+
} from '../runner-session.ts';
7381
import { RUNNER_STARTUP_TIMEOUT_MS } from '../runner-startup-transport.ts';
7482
import type { RunnerLease } from '../runner-lease.ts';
7583
import { executeRunnerCommand, prepareLocalIosRunner } from '../runner-lifecycle.ts';
@@ -333,6 +341,106 @@ test('a caller deadline during the xctestrun build leaves on time and the next r
333341
assert.equal(readRunnerSessionLiveness(device.id)?.liveness, 'ready');
334342
});
335343

344+
/**
345+
* A start that outlives its caller is bounded by a clock it owns. The caller's deadline fires mid
346+
* build, the daemon then clears the request's abort registration without aborting it, and the build
347+
* never finishes on its own: the default start budget must end it, release the session lock, and let
348+
* the request queued behind it start over (#2894 review).
349+
*/
350+
test('a wedged build with no caller left is ended by the default start budget and frees the device', async () => {
351+
vi.useFakeTimers({ toFake: ['setTimeout', 'clearTimeout', 'Date'] });
352+
const requestId = 'runner-wedged-build-request';
353+
registerRequestAbort(requestId);
354+
try {
355+
const controller = new AbortController();
356+
const device = { ...IOS_SIMULATOR, id: 'runner-wedged-build-sim' };
357+
const build = wedgeXctestrunBuild(() => controller.abort(callerDeadline()));
358+
const budgetOpenedAt = Date.now();
359+
360+
await assert.rejects(
361+
settleUnderFakeTimers(
362+
executeRunnerCommand(device, SNAPSHOT, {
363+
requestId,
364+
signal: controller.signal,
365+
logPath: '/tmp/runner.log',
366+
}),
367+
),
368+
readinessCanceled,
369+
);
370+
clearRequestCanceled(requestId);
371+
assert.equal(build.signal?.aborted, false, 'the caller deadline left the build running');
372+
assert.ok(
373+
build.remainingMs !== undefined && build.remainingMs <= DEFAULT_RUNNER_START_BUDGET_MS,
374+
'the build budget derives from the start budget',
375+
);
376+
377+
const next = executeRunnerCommand(device, SNAPSHOT, { logPath: '/tmp/runner.log' });
378+
const diagnostics = await captureDiagnostics(async () => {
379+
await vi.advanceTimersByTimeAsync(
380+
DEFAULT_RUNNER_START_BUDGET_MS - (Date.now() - budgetOpenedAt),
381+
);
382+
assert.equal(build.signal?.aborted, true, 'the start budget ended the wedged build');
383+
assert.equal(
384+
(build.signal?.reason as AppError | undefined)?.details?.reason,
385+
'runner_start_budget_exhausted',
386+
);
387+
await settleUnderFakeTimers(next);
388+
});
389+
390+
assert.match(diagnostics, /ios_runner_detached_start_failed/);
391+
assert.match(diagnostics, /runner_start_budget_exhausted/);
392+
assert.ok(
393+
Date.now() - budgetOpenedAt < DEFAULT_RUNNER_START_BUDGET_MS + 5_000,
394+
'the queued request settled as soon as the budget released the lock',
395+
);
396+
assert.equal(mockEnsureXctestrunArtifact.mock.calls.length, 2, 'the next request built anew');
397+
assert.equal(mockRunCmdBackground.mock.calls.length, 1, 'only the next request launched');
398+
assert.equal(readRunnerSessionLiveness(device.id)?.liveness, 'ready');
399+
assert.deepEqual(readRetainedLeaseDeviceIds(), [device.id]);
400+
} finally {
401+
clearRequestCanceled(requestId);
402+
vi.useRealTimers();
403+
}
404+
});
405+
406+
/** An explicit `startupTimeoutMs` is the start's whole budget, build included, ahead of the default. */
407+
test('an explicit startupTimeoutMs bounds the whole start ahead of the default budget', async () => {
408+
vi.useFakeTimers({ toFake: ['setTimeout', 'clearTimeout', 'Date'] });
409+
try {
410+
const device = { ...IOS_SIMULATOR, id: 'runner-explicit-start-budget-sim' };
411+
const build = wedgeXctestrunBuild();
412+
const startedAt = Date.now();
413+
414+
const command = executeRunnerCommand(device, SNAPSHOT, {
415+
startupTimeoutMs: 30_000,
416+
logPath: '/tmp/runner.log',
417+
});
418+
command.catch(() => {});
419+
await settleUnderFakeTimers(build.started);
420+
assert.ok(
421+
build.remainingMs !== undefined && build.remainingMs <= 30_000,
422+
'the build budget derives from the explicit start budget',
423+
);
424+
425+
await vi.advanceTimersByTimeAsync(30_000 - (Date.now() - startedAt));
426+
await assert.rejects(
427+
settleUnderFakeTimers(command),
428+
(error: unknown) =>
429+
error instanceof AppError &&
430+
error.details?.reason === 'runner_start_budget_exhausted' &&
431+
error.details?.timeoutMs === 30_000,
432+
);
433+
434+
assert.equal(build.signal?.aborted, true, 'the explicit budget ended the wedged build');
435+
assert.ok(Date.now() - startedAt < DEFAULT_RUNNER_START_BUDGET_MS);
436+
assert.equal(mockRunCmdBackground.mock.calls.length, 0, 'nothing was launched');
437+
assert.equal(readRunnerSessionLiveness(device.id), null);
438+
assert.deepEqual(readRetainedLeaseDeviceIds(), []);
439+
} finally {
440+
vi.useRealTimers();
441+
}
442+
});
443+
336444
test('prepare cancellation stops only its runner and preserves unrelated prep', async () => {
337445
const survivorRequestId = 'prepare-runner-survivor-B';
338446
const canceledRequestId = 'prepare-runner-canceled-A';
@@ -362,9 +470,12 @@ test('prepare cancellation stops only its runner and preserves unrelated prep',
362470
(error: unknown) => isRequestCanceledError(error),
363471
);
364472

365-
const canceledSignal = getRequestSignal(canceledRequestId);
366-
assert.ok(mockRunCmdBackground.mock.calls.some((call) => call[2]?.signal === canceledSignal));
367-
assert.equal(canceledSignal?.aborted, true);
473+
assert.equal(getRequestSignal(canceledRequestId)?.aborted, true);
474+
assert.equal(
475+
mockRunCmdBackground.mock.calls.at(-1)?.[2]?.signal?.aborted,
476+
true,
477+
'the request cancel reached the canceled launch',
478+
);
368479
assert.equal(readRunnerSessionLiveness(canceledDevice.id), null);
369480
assert.equal(readRunnerSessionLiveness(survivorDevice.id)?.liveness, 'ready');
370481
} finally {
@@ -395,10 +506,10 @@ test('normal command cancellation during launch or initial readiness retains no
395506
);
396507
assert.equal(readRunnerSessionLiveness(survivorDevice.id)?.liveness, 'ready');
397508

398-
const canceledSignal = getRequestSignal(launchCanceledRequestId);
399509
mockRunCmdBackground.mockImplementationOnce((_cmd, _args, options) => {
400-
assert.equal(options?.signal, canceledSignal);
510+
assert.equal(options?.signal?.aborted, false);
401511
markRequestCanceled(launchCanceledRequestId);
512+
assert.equal(options?.signal?.aborted, true, 'the request cancel reaches the launch');
402513
return makeBackgroundRunner(4343);
403514
});
404515

@@ -436,6 +547,60 @@ test('normal command cancellation during launch or initial readiness retains no
436547
}
437548
});
438549

550+
type WedgedXctestrunBuild = {
551+
/** The budget signal the build was handed; set once the build began. */
552+
signal?: AbortSignal;
553+
/** What the build budget had left when the build began. */
554+
remainingMs?: number;
555+
/** Resolves when the build began. */
556+
started: Promise<void>;
557+
};
558+
559+
/**
560+
* A build that never finishes on its own: like the real xcodebuild exec, it ends only when the budget
561+
* signal it was handed aborts, and then with the cancelled-command error the exec layer raises.
562+
*/
563+
function wedgeXctestrunBuild(onStart?: () => void): WedgedXctestrunBuild {
564+
let markStarted: () => void = () => {};
565+
const build: WedgedXctestrunBuild = {
566+
started: new Promise<void>((resolve) => {
567+
markStarted = resolve;
568+
}),
569+
};
570+
mockEnsureXctestrunArtifact.mockImplementationOnce(async (_device, options) => {
571+
const signal: AbortSignal = options.budget.signal;
572+
build.signal = signal;
573+
build.remainingMs = options.budget.deadline?.remainingMs();
574+
markStarted();
575+
onStart?.();
576+
await new Promise<never>((_, reject) => {
577+
signal.addEventListener(
578+
'abort',
579+
() => reject(createRequestCanceledError(undefined, signal.reason)),
580+
{ once: true },
581+
);
582+
});
583+
});
584+
return build;
585+
}
586+
587+
/**
588+
* Awaits a promise whose path may park on faked timers: the clock is advanced in small steps until
589+
* it settles, so the test never has to know which step waited. The steps spend fake time, which is
590+
* why budgets are measured from a `Date.now()` mark the test took itself.
591+
*/
592+
async function settleUnderFakeTimers<T>(promise: Promise<T>): Promise<T> {
593+
let settled = false;
594+
const tracked = promise.finally(() => {
595+
settled = true;
596+
});
597+
tracked.catch(() => {});
598+
for (let step = 0; step < 500 && !settled; step += 1) {
599+
await vi.advanceTimersByTimeAsync(10);
600+
}
601+
return await tracked;
602+
}
603+
439604
function readRetainedLeaseDeviceIds(): string[] {
440605
return fs.readdirSync(process.env.AGENT_DEVICE_IOS_RUNNER_LEASE_DIR!).map((entry) => {
441606
const contents = fs.readFileSync(

0 commit comments

Comments
 (0)