fix(ios): budget cold toolchain probes for the first-exec signature stall - #2423
Conversation
Size Report
Startup median (7 runs, lower is better):
|
|
Fixed the eager-closure-budgets failure (666283b). Root cause: Fix: deleted Verified locally against merge-base
|
|
The runner probes need to honor the remaining request budget at 666283b. Three synchronous probes can each run twice for 30 seconds, blocking for roughly 180 seconds without a deadline or cancellation check. Please pass the owning budget through, cap each attempt by its remaining time, and test exhausted and canceled requests; the current immediate-throw mocks do not prove the deadline. Both retry classifiers also inspect error text. The subprocess timeout already carries structured timeout details. Please classify that signal instead, and test that a non-timeout error with similar wording is not retried. |
666283b to
6bf0809
Compare
|
Both review points addressed at 6bf0809 (rebased on 1. The probes now honor the owning request budget. The budget threaded is the one the request already carries into the runner
One clock is created per fingerprint read, so the three probes and their retries
Worst-case wall clock: 45 s, down from ~180 s. A caller with no budget of its 2. Typed timeout classifier in both consumers.
New tests. The immediate-throw mocks are replaced by a fake clock installed
Verified locally against merge-base |
|
The typed timeout check and shared probe budget are improvements, but |
6bf0809 to
b9bc957
Compare
|
Addressing the three 15:13 points. Branch was rebased onto main (now including #2420, #2421, #2416) and force-pushed with lease; the fix itself is unchanged in substance, just re-based. (a) One deadline across the probes and the step they precede
New regression test:
Net effect on worst-case wall clock: a cold-start probe stall now comes out of the phase budget instead of stacking on top of it, so the worst case for the phase is the phase budget itself, not phase-budget-plus-probe-stall. (b)
(c) The constant has one owner
Gate results (from the worktree, post-rebase)
Force-pushed |
|
The shared phase deadline, fake-clock tests and single timeout owner address the previous findings at b9bc957. One cancellation case remains: after a probe times out, toolchainProbeDeadlineHasRoom returns false for an aborted signal and rethrows the timeout. Preserve the typed cancellation instead, and add a timeout-then-abort regression proving there is no retry and the cancellation reason survives. CI is green. Please also replace Closes #2422 with a reference, or split its remaining native-runtime compile-timeout case into a tracked follow-up before closing it; that third site is outside this fix. |
b9bc957 to
2f4462e
Compare
|
Round 3, rebased on The remaining cancellation case
New regression in Runner side checked as asked: Cancellation swallowed in adoption
Simplifications
Net production diff: 421+/66- over 13 files → 431+/67- over 12 files. The deletions above are offset by the shared error constructor, the adoption signal plumbing, and the doc that moved with the constant. One item I could not do: deleting the port methodYou asked me to drop
What I shipped instead keeps the part that was actually wrong — two homes for one number — and drops the part that was not: host-kit owns the constant, Split-outPer your second note, the third site named on #2422 — the fixed 45 s clang compile budget in VerificationTouched test files,
|
|
The timeout-then-abort fix is in place at 2f4462e, but the warm-cache path still skips cancellation: requireRunnerToolchainFingerprint returns its memoized value before checking the signal. Adoption can then probe uptime and write the lease for an already-canceled request. Check cancellation before the cache return, and add a regression that warms the real fingerprint cache before passing an aborted signal; require typed cancellation with no uptime probe or lease adoption. The compile-timeout follow-up is now correctly tracked in #2439. |
…tall 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
…ared 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.
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
…ep 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.
…y the probe budget
2f4462e to
47220f6
Compare
|
Addressed in 47220f6 (
Verification: |
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.
|
Pushed Net line delta: +25/-17 (net +8) in
Tests unchanged: all 55 cases across |
|
The guard cleanup at b6611b6 loses cancellation on a failed final probe. If xcrun --show-sdk-build-version aborts the request and throws a non-timeout error, the catch now converts it to apple_toolchain_probe_unavailable; there is no next attempt to check cancellation. Previously the catch checked the signal before classifying the failure. Preserve that check and add a regression where the final probe aborts and throws a non-timeout error, asserting the typed cancellation instead of a toolchain failure. |
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.
|
Restored in Regression added: the fake exec answers the first two probes and, on |
|
The cancellation regression is fixed at c24d42c. The final-probe test now checks the non-timeout failure case, and the common catch preserves typed cancellation without changing the retry budget. No remaining code findings; current checks are green. |
… 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.
|
Structural round on top of (A) The 30 s constant now lives in
|
| entry | merge-base | with the split | delta |
|---|---|---|---|
packages/platform-apple/src/app-lifecycle-facade.ts |
120 | 122 | +2 |
packages/platform-apple/src/app-resolution-facade.ts |
61 | 63 | +2 |
packages/platform-apple/src/doctor-facade.ts |
101 | 103 | +2 |
packages/platform-apple/src/perf-facade.ts |
60 | 62 | +2 |
packages/platform-apple/src/physical-device-facade.ts |
47 | 49 | +2 |
packages/platform-apple/src/runner-operations-facade.ts |
100 | 102 | +2 |
packages/platform-apple/src/runner/index.ts |
13 | 15 | +2 |
Seven failures, +2 each — one per extracted module, since neither pulls an edge the closure does not already have. There is no approval row for growth of an existing entry, so this needs a gate follow-up (an approval path for a same-weight file split, or a way to say "these modules are one unit"). The plant was discarded; runner-cache-metadata.ts is unchanged in structure.
(C) Comments
Production diff (':!*.test.ts' ':!*__tests__*', vs merge-base 41e2633): 164 → 69 added comment lines, −95, with zero code change from the trim (the only non-comment lines this commit touches are the constant's move).
Kept, once each: the cold-start stall rationale (on the constant), "spawnSync cannot be interrupted once it has started, so cancellation is observed between attempts" (on ToolchainProbeClock), and one line at each phase-deadline creation site saying the probes and the step share it (runner-artifact.ts, runner-session.ts). Gone: the multi-paragraph docs on createRunnerPhaseDeadline, requireRunnerPhaseRemainingMs, runnerPhaseBudgetExhaustedError, RunnerCacheProbeBudget, runToolchainProbeCommand and its cache-identity.ts twin, the "arrives through the port" paragraph (deleted with the port method), the clock-construction narration and the catch-block narration.
Verified from the worktree
runner-cache-metadata.test.ts / runner-adoption.test.ts / runner-artifact-phase-budget.test.ts / cache-identity.test.ts (56 passed) · pnpm typecheck · pnpm lint · pnpm check:layering · eager-closure gate vs origin/main (581 passed) · pnpm check:affected --run (719 files, 5413 tests, no runner-client.test.ts timeout this run).
|
No code findings in b21efb0. Moving the shared timeout into the Apple module removes the extra host-port plumbing without changing retry, cancellation or deadline behavior. The integration failure is an unrelated connection reset while fetching Chrome-for-Testing metadata; rerun that job before merge. |
|
…ager closure grows The no-growth diagnostic in scripts/__tests__/eager-closure-budgets.ts only named the FIRST newly evaluated module and always advised a dynamic import. On #2423 that sent five reviewers toward the wrong fix when the growth was a small new module that belonged in a module every affected entry already evaluated -- the dynamic-import advice was never coherent for a brand-new module with no old edge to defer. - describeClosureGrowth now lists every added module (bounded to 10), each with the shortest static import route from the entry to it. - describeSharedGrowthHomes runs once after every entry is evaluated: when two or more entries grew by the same added module, it names the modules they already evaluate at the merge-base under that module's own package -- candidate homes, not a verdict. - classifyGrowth's closing advice now states the two common causes (a new static edge, or something that used to load lazily) and the two remedies (give the symbol a home in a module already in the closure, or make the new edge lazy) instead of prescribing one fix. The verdict logic (when an entry is flagged as having grown) is unchanged.
…r host port R77 apple-runner-host-port bans a direct @agent-device/host-kit/* value import from packages/platform-apple/src/runner/**; the port at runner/host.ts, bound in core/runner-host.ts, is the only door. runner/** sits in the eager closure of seven Apple facade entries eager-closure-budgets.ts holds at a fixed size, so a direct import grows all seven at once (#2423 measured one candidate import adding 5 modules to runner/index.ts's closure, 13 -> 18, after two review rounds spent rediscovering this).
…r host port (#2470) R77 apple-runner-host-port bans a direct @agent-device/host-kit/* value import from packages/platform-apple/src/runner/**; the port at runner/host.ts, bound in core/runner-host.ts, is the only door. runner/** sits in the eager closure of seven Apple facade entries eager-closure-budgets.ts holds at a fixed size, so a direct import grows all seven at once (#2423 measured one candidate import adding 5 modules to runner/index.ts's closure, 13 -> 18, after two review rounds spent rediscovering this).
…ager closure grows The no-growth diagnostic in scripts/__tests__/eager-closure-budgets.ts only named the FIRST newly evaluated module and always advised a dynamic import. On #2423 that sent five reviewers toward the wrong fix when the growth was a small new module that belonged in a module every affected entry already evaluated -- the dynamic-import advice was never coherent for a brand-new module with no old edge to defer. - describeClosureGrowth now lists every added module (bounded to 10), each with the shortest static import route from the entry to it. - describeSharedGrowthHomes runs once after every entry is evaluated: when two or more entries grew by the same added module, it names the modules they already evaluate at the merge-base under that module's own package -- candidate homes, not a verdict. - classifyGrowth's closing advice now states the two common causes (a new static edge, or something that used to load lazily) and the two remedies (give the symbol a home in a module already in the closure, or make the new edge lazy) instead of prescribing one fix. The verdict logic (when an entry is flagged as having grown) is unchanged.
…losure grows (#2471) * chore(gates): name the added modules and their import paths when an eager closure grows The no-growth diagnostic in scripts/__tests__/eager-closure-budgets.ts only named the FIRST newly evaluated module and always advised a dynamic import. On #2423 that sent five reviewers toward the wrong fix when the growth was a small new module that belonged in a module every affected entry already evaluated -- the dynamic-import advice was never coherent for a brand-new module with no old edge to defer. - describeClosureGrowth now lists every added module (bounded to 10), each with the shortest static import route from the entry to it. - describeSharedGrowthHomes runs once after every entry is evaluated: when two or more entries grew by the same added module, it names the modules they already evaluate at the merge-base under that module's own package -- candidate homes, not a verdict. - classifyGrowth's closing advice now states the two common causes (a new static edge, or something that used to load lazily) and the two remedies (give the symbol a home in a module already in the closure, or make the new edge lazy) instead of prescribing one fix. The verdict logic (when an entry is flagged as having grown) is unchanged. * chore(gates): split the shared-growth-homes diagnostic into small helpers * chore(gates): aggregate only net growth and keep shared homes per added module The cross-entry shared-homes note took every entry with a newly evaluated module, which is not the condition the per-entry rule applies: a closure that swaps one module for another, or shrinks while adding one, has added modules and no growth. `classifyGrowth` passes it, so the aggregate must too -- entries now carry their head closure size and the grouping keeps only the ones whose closure actually grew. Candidate homes are no longer unioned across added modules. Each added module shared by two or more grown entries gets its own block naming those entries with how much each grew and the merge-base modules exactly those entries evaluate, so the label no longer claims a home is common to every failing entry when two independent groups are in play.
Cause
Cold Apple toolchain probes carried per-call budgets sized for a warm toolchain, below the ~18-19 s syspolicyd signature-verification stall that blocks the first
xcodebuild/xcrun/large-binary exec after a fresh macOS host boots (the second exec of the same tool is instant):packages/platform-apple/src/snapshot-source/cache-identity.ts:toolOutputranxcodebuild -version,sw_vers,uname,xcrun --show-sdk-versionwithtimeoutMs: Math.min(10_000, remaining).packages/platform-apple/src/runner/runner-cache-metadata.ts:TOOLCHAIN_PROBE_TIMEOUT_MS = 5_000for the runner cache key'sxcodebuild -version/xcrun --show-sdk-version/xcrun --show-sdk-build-versionprobes.Both tripped on cold CI runners even though the surrounding deadlines had room, producing a toolchain-probe timeout unrelated to the change under test (#2422).
Reviewing the first fix surfaced the real defect underneath: these probes block the calling request but were charged to nobody. A build or startup handed the probes a timeout and then handed itself the same number again, so a stalled probe spent the phase's budget twice.
Fix
One owner for the probe budget.
COLD_TOOLCHAIN_PROBE_TIMEOUT_MS = 30_000lives inpackages/host-kit/src/internal/exec.ts, besideisCommandTimeoutError, and is exported through@agent-device/host-kit/command— it is a property of exec'ing an Apple tool, not of either prober.cache-identity.tsimports it directly.runner-cache-metadata.tsreads it through the Apple runner host port, like every other host-kit symbol that file uses: a static edge from that file to host-kit adds five modules to thepackages/platform-apple/src/runner/index.tseager closure, whichscripts/__tests__/eager-closure-budgets.test.tsholds at 13.One clock per runner phase.
createRunnerPhaseDeadlineopens a singleDeadlinewhen a build or a startup begins; the cache decision's toolchain probes and the step the phase exists for both read it, andrequireRunnerPhaseRemainingMsthrowsrunner_phase_budget_exhaustedrather than starting a process it would have to kill at once. The toolchain fingerprint opens its own deadline at whichever ceiling is nearer — the phase's remainder, orTOOLCHAIN_FINGERPRINT_BUDGET_MS(45 s) for a caller with no phase clock — so the three probes and their retries share one budget instead of one each.Retry exactly once, on the shared remainder. Both probers retry a timed-out attempt once, classified by the exec layer's structured
details.timeoutMsrather than by message text, so a tool that failed on its own and merely said "timed out" is not retried.Cancellation stays typed. A request canceled while a probe blocked surfaces its own cancellation, not the timeout that happened to be in flight:
cache-identity.tsraises the snapshot-sourcecancelled/abort-signalerror,runner-cache-metadata.tsraisescreateRequestCanceledError.runner-adoption.tsforwards the request signal into the fingerprint probes and rethrows a cancellation fromresolveExpectedDerivedPathinstead of turning it intoskip('expected_derived_unresolved')and walking on past a client that is gone.Budget exhaustion is not a broken toolchain. A probe reached with nothing left throws the same
runner_phase_budget_exhaustederror the build and startup steps throw, instead of reportingapple_toolchain_probe_unavailablewith a "checkxcode-select" hint for a toolchain that was never probed.Tests
packages/platform-apple/src/snapshot-source/cache-identity.test.ts(new file): cold-start recovery on retry with the retry charged the remainder; a probe that spends the whole deadline is not retried; a never-returning host retries exactly once; a self-reported "timed out" is not retried; and a request aborted while a probe blocked throws the typedcancelled/abort-signalerror after exactly one exec.packages/platform-apple/src/runner/__tests__/runner-cache-metadata.test.ts: the same cases againstresolveExpectedRunnerCacheMetadata, plus the shared-budget stop, a 4 s phase capping the single attempt, and cancellation both mid-probe and before the first exec. A fake clock advances only when a probe actually blocks for the timeout it was handed, so a case claiming the budget was spent had to spend it.packages/platform-apple/src/runner/__tests__/runner-artifact-phase-budget.test.ts(new file): the build phase's remaining time after the probes.packages/platform-apple/src/runner/__tests__/runner-adoption.test.ts: an aborted request during the fingerprint probe fails adoption instead of skipping it.packages/host-kit/src/internal/exec.test.ts:isCommandTimeoutErroraccepts only the exec layer's own structured timeout.Verification
pnpm check:affected --run: all green.pnpm typecheck,pnpm lint,pnpm check:layering: pass.scripts/__tests__/eager-closure-budgets.test.tsagainst the merge-base: no closure grows.This unblocks the iOS smoke/preflight lane that was failing on cold runners for #2418, #2420, #2421.
The third site named on #2422 (the fixed 45 s clang compile budget in
native-runtime.test.ts) is split out as #2439 and not covered here.Closes #2422