From 3b0292a51ba2c868012e0cef111897d29e3dffac Mon Sep 17 00:00:00 2001 From: Franz Hemmer Date: Wed, 11 Nov 2026 18:02:30 -0500 Subject: [PATCH] fix(native): let the host settle after simulator boot Main ba39899f lost tablet-10 to an XCTest "Timed out while requesting screenshot" driver failure, the third such loss in six complete native runs (also phone-6 on 7045e6d3 and tablet-8 on 719887a6). All three happened in the first scenario. Host telemetry shows the cause window: the 1-minute load peaks at 490-670 three to seven minutes after boot, while the new simulator starts its background services, and falls to about 200 by minutes eight to ten. After each boot the runner now waits at least 5 minutes, then until the 1-minute load is below 250, capped at 10 minutes, and records the wait and samples as hostSettle in the manifest. It only waits; it never fails, retries or changes a flow. Jobs keep their 60-minute limit. Refs #130 Co-Authored-By: Claude Opus 5.5 --- docs/native-simulator.md | 4 ++++ scripts/ios-native/hostSettle.mjs | 22 +++++++++++++++++++ scripts/ios-native/hostSettle.test.mjs | 30 ++++++++++++++++++++++++++ scripts/ios-native/run.mjs | 5 +++++ 4 files changed, 61 insertions(+) create mode 100644 scripts/ios-native/hostSettle.mjs create mode 100644 scripts/ios-native/hostSettle.test.mjs diff --git a/docs/native-simulator.md b/docs/native-simulator.md index f1a8238..513f369 100644 --- a/docs/native-simulator.md +++ b/docs/native-simulator.md @@ -69,6 +69,10 @@ The build artifact includes the unsigned simulator app, native dependency lock, Host diagnostics use a worker event loop so sampling continues during synchronous boot and CLI commands. They sample CPU load, free memory (`os.freemem()`, which on macOS can exclude reclaimable cached memory), VM page counters, a bounded list of simulator/driver process names, and the top eight processes of any kind by CPU and by RSS (executable basenames limited to a safe character set, otherwise "other"), with CPU and RSS, every fifteen seconds, with at most 240 samples. They exclude command arguments and environment values, publish atomic diagnostic checkpoints, and stop before the immutable evidence snapshot. Missing telemetry does not replace a qualification failure. Each phase gives Maestro its own hidden XDG state directory, retains at most eight 512-KiB tails of known XCTest runner logs after credential redaction, and records the selected log paths in its recovery evidence. Raw hidden state is excluded from publication. See [the native reliability investigation](native-reliability.md) for what these diagnostics are for and their limits. +## Post-boot settle + +A freshly booted simulator starts dozens of background services. On hosted 3-CPU runners the 1-minute load average peaked at 490-670 three to seven minutes after boot and fell to about 200 by minutes eight to ten, and every XCTest "Timed out while requesting screenshot" driver loss happened in the first scenario inside that peak (#130). After each boot the runner therefore waits at least 5 minutes, then until the 1-minute load falls below 250, for at most 10 minutes (`scripts/ios-native/hostSettle.mjs`). The wait and its load samples are recorded as `hostSettle` in the run manifest. It never fails, retries or changes a flow. + ## System gesture cancellations On loaded hosted simulators, UIKit's window-level system gesture gate sometimes recognizes during a synthesized tap and cancels the touch before the app acts on it (#130). The interaction's flow runner (`interaction.mjs`, used by authored flows and the hold, reroll and scoring steps) sends such a tap once more only when the app's own native cancel log proves it. The failed flow must fit one of two shapes: a positive `assertVisible` failed right after that tap with only waits, assertions or screenshots in between, and the cancelled touch is the last one since the flow started; or the flow's only effectful command is that tap, followed only by passive commands including a check, and exactly one touch began. In both, the touch is a stationary tap cancelled while a window-level gate (bucket 9) was recognized. At most one re-send per flow and two per interaction session. Each one is recorded as `system-gesture-cancel-reissue` in the phase's geometry log, as a `systemCancelReissues` entry in the run manifest, as a job warning and as a line in the step summary. A run with any re-send does not count toward the #130 restoration streak (see the [quality policy](quality-policy.md)). Any other failure still ends the run without replay. diff --git a/scripts/ios-native/hostSettle.mjs b/scripts/ios-native/hostSettle.mjs new file mode 100644 index 0000000..9f6e55d --- /dev/null +++ b/scripts/ios-native/hostSettle.mjs @@ -0,0 +1,22 @@ +import { loadavg } from "node:os"; +import { setTimeout as delay } from "node:timers/promises"; + +/** + * #130: a freshly booted simulator starts dozens of background services (widgets, intelligence, + * Fitness, sync agents). On hosted 3-CPU runners the 1-minute load average peaked at 490-670 + * three to seven minutes after boot and fell to about 200 by minutes eight to ten. Every XCTest + * "Timed out while requesting screenshot" driver loss so far happened in the first scenario, + * inside that peak. Wait at least `minMs` after boot, then until load falls below `threshold`, + * never longer than `maxMs`. It only waits: it never fails, retries or changes a flow. + */ +export async function settleAfterBoot({ load = () => loadavg()[0], now = Date.now, sleep = (ms) => delay(ms), + minMs = 300000, maxMs = 600000, threshold = 250, intervalMs = 15000 } = {}) { + const started = now(), samples = []; + for (;;) { + const elapsedMs = now() - started, load1 = load(); + if (samples.length < 64) samples.push({ elapsedMs, load1: Number.isFinite(load1) ? Math.round(load1 * 10) / 10 : null }); + if (elapsedMs >= minMs && Number.isFinite(load1) && load1 < threshold) return { status: "settled", waitedMs: elapsedMs, load1, threshold, minMs, maxMs, samples }; + if (elapsedMs >= maxMs) return { status: "cap-reached", waitedMs: elapsedMs, load1, threshold, minMs, maxMs, samples }; + await sleep(intervalMs); + } +} diff --git a/scripts/ios-native/hostSettle.test.mjs b/scripts/ios-native/hostSettle.test.mjs new file mode 100644 index 0000000..c05a095 --- /dev/null +++ b/scripts/ios-native/hostSettle.test.mjs @@ -0,0 +1,30 @@ +import assert from "node:assert/strict"; +import test from "node:test"; +import { settleAfterBoot } from "./hostSettle.mjs"; + +function clock(loads) { + let t = 0, i = 0; + return { now: () => t, sleep: async (ms) => { t += ms; i++; }, load: () => loads[Math.min(i, loads.length - 1)] }; +} + +test("waits the minimum even when load is already low, then proceeds", async () => { + const c = clock([10]); + const result = await settleAfterBoot({ ...c }); + assert.equal(result.status, "settled"); assert.equal(result.waitedMs, 300000); +}); + +test("after the minimum, waits for the post-boot peak to fall below the threshold", async () => { + // 15 s samples: rising to the peak, then falling (the hosted tablet-10 shape). + const shape = [60, 97, 148, 287, 294, 367, 413, 336, 489, 479, 334, 422, 293, 277, 190, 180, ...Array(40).fill(400)]; + const c = clock(shape.flatMap((v) => Array(2).fill(v))); + const result = await settleAfterBoot({ ...c }); + assert.equal(result.status, "settled"); assert(result.waitedMs >= 300000 && result.waitedMs < 600000); assert(result.load1 < 250); +}); + +test("never waits past the cap and never throws on unusable load readings", async () => { + const high = await settleAfterBoot({ ...clock([700]) }); + assert.equal(high.status, "cap-reached"); assert.equal(high.waitedMs, 600000); + const broken = await settleAfterBoot({ ...clock([Number.NaN]) }); + assert.equal(broken.status, "cap-reached"); assert.equal(broken.samples[0].load1, null); + assert(high.samples.length <= 64); +}); diff --git a/scripts/ios-native/run.mjs b/scripts/ios-native/run.mjs index a4f6a05..b1195e1 100644 --- a/scripts/ios-native/run.mjs +++ b/scripts/ios-native/run.mjs @@ -19,6 +19,7 @@ import { checkedCommandOutput } from "./commandResult.mjs"; import { startInputObservation } from "./inputObservation.mjs"; import { startDoneObservation } from "./doneObservation.mjs"; import { startHostTelemetry } from "./hostTelemetry.mjs"; +import { settleAfterBoot } from "./hostSettle.mjs"; import { newestNativeCancelText, retainNativeCancellation } from "./nativeCancelRetention.mjs"; import { retainCorruptionMarker, retainNativeModal, withModalRetention } from "./nativeModalRetention.mjs"; import { modalRouteRequested, ownedModalCapability, qualifyOwnedModal } from "./modalRoute.mjs"; @@ -179,6 +180,8 @@ async function exerciseModal(app, bundleId) { status: "running", nativeObservationStartedAtMs: Date.now() }; receipt.modalRoute = result; receipt.phase = "modal-prerequisite"; checkpoint(); sim("boot", device); sim("bootstatus", device, "-b"); + receipt.phase = "modal-host-settle"; checkpoint(); + (receipt.hostSettle ??= []).push({ device: "owned-modal", ...await settleAfterBoot() }); checkpoint(); sim("spawn", device, "defaults", "write", "NSGlobalDomain", "AppleLanguages", "-array", "en"); sim("spawn", device, "defaults", "write", "NSGlobalDomain", "AppleLocale", "-string", "en_US"); sim("install", device, app); sim("ui", device, "appearance", "dark"); sim("ui", device, "content_size", result.requestedContentSize); @@ -211,6 +214,8 @@ async function exercise(app, bundleId) { if (booted !== device) { if (booted) sim("shutdown", booted); sim("boot", device); sim("bootstatus", device, "-b"); booted = device; + receipt.phase = `host-settle-${scenario.id}`; checkpoint(); + (receipt.hostSettle ??= []).push({ device: scenario.device, ...await settleAfterBoot() }); checkpoint(); sim("spawn", device, "defaults", "write", "NSGlobalDomain", "AppleLanguages", "-array", "en"); sim("spawn", device, "defaults", "write", "NSGlobalDomain", "AppleLocale", "-string", "en_US"); sim("install", device, app);