also looking at this
fix(mobile-e2e): launch iOS apps without a pty, so a cold simulator cannot eat the budget
#212
5 files
+74
-23
| @@ -330,6 +330,8 @@ jobs: | ||
| 330 | 330 | path: | |
| 331 | 331 | artifacts/mobile-e2e/ios-zig-slice/console.log |
| 332 | 332 | artifacts/mobile-e2e/ios-zig-slice/console.plain |
| 333 | artifacts/mobile-e2e/ios-zig-slice/app-stdout.log | |
| 334 | artifacts/mobile-e2e/ios-zig-slice/app-stderr.log | |
| 333 | 335 | if-no-files-found: error |
| 334 | 336 | retention-days: 30 |
| 335 | 337 | |
| @@ -22,6 +22,9 @@ echo "==> building the craft iOS simulator library" | ||
| 22 | 22 | SDK="$(xcrun --sdk iphonesimulator --show-sdk-path)" |
| 23 | 23 | APP="$OUT/CraftSlice.app" |
| 24 | 24 | rm -rf "$OUT"; mkdir -p "$APP" |
| 25 | # Absolute, because the app writes its console to paths under here and resolves | |
| 26 | # them from its own working directory, not this script's. | |
| 27 | OUT="$(cd "$OUT" && pwd)"; APP="$OUT/CraftSlice.app" | |
| 25 | 28 | |
| 26 | 29 | echo "==> compiling the fixture" |
| 27 | 30 | # The ObjC translation units first, then swiftc drives the link. swiftc is the |
| @@ -117,9 +120,22 @@ xcrun simctl location "$UDID" set 37.3317,-122.0307 | ||
| 117 | 120 | # i=68 assertion below fails loudly, which is the right way round. |
| 118 | 121 | xcrun simctl privacy "$UDID" grant kTCCServiceSpeechRecognition "$BUNDLE_ID" 2>/dev/null || true |
| 119 | 122 | |
| 123 | # The app's stdout and stderr, each to a file, gathered into $LOG as it runs. | |
| 124 | # | |
| 125 | # Not `simctl launch --console-pty`, for the reason scripts/mobile-e2e/ios.ts | |
| 126 | # gives: the first pty launch after a cold boot took about 200 seconds to start | |
| 127 | # the app, against 10 for a plain launch, and that wait came out of this | |
| 128 | # script's budget. `NSUnbufferedIO=YES` is what lets a file see the output | |
| 129 | # while the app runs; without it nothing arrives. And no pty means no CRLF, so | |
| 130 | # the lines grepped below end where they appear to. | |
| 131 | STDOUT_LOG="$OUT/app-stdout.log" | |
| 132 | STDERR_LOG="$OUT/app-stderr.log" | |
| 120 | 133 | LOG="$OUT/console.log" |
| 121 | xcrun simctl launch --console-pty "$UDID" "$BUNDLE_ID" > "$LOG" 2>&1 & | |
| 122 | LAUNCH_PID=$! | |
| 134 | : > "$LOG" | |
| 135 | SIMCTL_CHILD_NSUnbufferedIO=YES xcrun simctl launch --terminate-running-process \ | |
| 136 | --stdout="$STDOUT_LOG" --stderr="$STDERR_LOG" "$UDID" "$BUNDLE_ID" | |
| 137 | ||
| 138 | gather_log() { cat "$STDOUT_LOG" "$STDERR_LOG" > "$LOG" 2>/dev/null || true; } | |
| 123 | 139 | |
| 124 | 140 | # The round trip is fast, but a cold simulator is not. Poll rather than sleep a |
| 125 | 141 | # fixed amount, so a slow boot does not read as a failure. |
| @@ -141,6 +157,7 @@ DEADLINE=$(( $(date +%s) + SLICE_TIMEOUT )) | ||
| 141 | 157 | |
| 142 | 158 | missing_ids() { |
| 143 | 159 | local missing="" |
| 160 | gather_log | |
| 144 | 161 | for id in $AWAITED_IDS; do |
| 145 | 162 | # ERE with an explicit boundary rather than \b, which is a GNU |
| 146 | 163 | # extension this script cannot count on, and rather than a bare |
| @@ -159,12 +176,13 @@ while :; do | ||
| 159 | 176 | echo "FAIL: timed out after ${SLICE_TIMEOUT}s waiting for:$MISSING" |
| 160 | 177 | echo " The app never got that far — this is a timeout, not a wrong answer." |
| 161 | 178 | echo " Raise CRAFT_SLICE_TIMEOUT if the machine is simply slow." |
| 162 | kill "$LAUNCH_PID" 2>/dev/null || true | |
| 179 | xcrun simctl terminate "$UDID" "$BUNDLE_ID" 2>/dev/null || true | |
| 163 | 180 | exit 1 |
| 164 | 181 | fi |
| 165 | 182 | sleep 1 |
| 166 | 183 | done |
| 167 | kill "$LAUNCH_PID" 2>/dev/null || true | |
| 184 | xcrun simctl terminate "$UDID" "$BUNDLE_ID" 2>/dev/null || true | |
| 185 | gather_log | |
| 168 | 186 | |
| 169 | 187 | echo "==> console" |
| 170 | 188 | cat "$LOG" || true |
| @@ -200,7 +218,12 @@ echo "==> assertions" | ||
| 200 | 218 | PLAIN="$OUT/console.plain" |
| 201 | 219 | sed -e $'s/\x1b\[[0-9;]*m//g' -e 's/\r$//' "$LOG" > "$PLAIN" |
| 202 | 220 | |
| 203 | count() { grep -cE "craft-bridge dispatch t=mobile a=[A-Za-z]+ i=$1\$" "$PLAIN" || true; } | |
| 221 | # The same boundary missing_ids waits on. This used to demand the id end the | |
| 222 | # line, while the wait accepted any non-digit after it, so a line the loop had | |
| 223 | # already counted as arrived could fail its assertion here: on main, run | |
| 224 | # 35094828558 waited for i=76, found it, and then reported that | |
| 225 | # getCurrentPosition "did not return the simulated coordinate". | |
| 226 | count() { grep -cE "craft-bridge dispatch t=mobile a=[A-Za-z]+ i=$1(\$|[^0-9])" "$PLAIN" || true; } | |
| 204 | 227 | |
| 205 | 228 | C1="$(count 1)"; C2="$(count 2)"; C3="$(count 3)" |
| 206 | 229 | |
| @@ -1,5 +1,5 @@ | ||
| 1 | 1 | import type { LegOutcome, RunnerOptions } from './types' |
| 2 | import { closeSync, copyFileSync, existsSync, mkdirSync, openSync, readFileSync, rmSync, writeFileSync } from 'node:fs' | |
| 2 | import { copyFileSync, existsSync, mkdirSync, readFileSync, rmSync, writeFileSync } from 'node:fs' | |
| 3 | 3 | import { join } from 'node:path' |
| 4 | 4 | import { bootSimulator, init, pickSimulator } from '../../packages/ios/src/index' |
| 5 | 5 | import { evaluateRun, hasTerminated, ZIG_REFUSED_ACTIONS, ZIG_TESTED_ACTIONS, zigDispatchedActions, zigRefusals } from './protocol' |
| @@ -120,30 +120,53 @@ async function runLeg(leg: Leg, options: RunnerOptions): Promise<LegOutcome> { | ||
| 120 | 120 | // this run never wrote. |
| 121 | 121 | await command(['xcrun', 'simctl', 'pbcopy', device.udid], { stdin: 'craft-e2e-pasteboard-cleared', allowFailure: true }) |
| 122 | 122 | |
| 123 | // The app's own stdout and stderr, straight to a file. `--console-pty` is | |
| 124 | // what makes Swift's `print` - and therefore the page's `craft.log` - leave | |
| 125 | // the device at all; without it the launch returns a pid and says nothing. | |
| 126 | // A raw descriptor rather than a pipe, so the writing outlives this process | |
| 127 | // reading it and the poll below sees the file grow. | |
| 123 | // The app's stdout and stderr, each to its own file, read back while it | |
| 124 | // runs. Swift's `print` carries the page's `craft.log`; Zig's logger writes | |
| 125 | // to stderr. | |
| 126 | // | |
| 127 | // Not `simctl launch --console-pty`, which is what this was. On a freshly | |
| 128 | // booted simulator the first pty launch took about 200 seconds to start the | |
| 129 | // app, measured on a new device, against 10 for a plain launch. The clock | |
| 130 | // below used to start at that spawn, so the shim leg, always the first | |
| 131 | // launch after boot, could spend its whole budget waiting for the app to | |
| 132 | // exist and fail with "the test page never announced a plan". It did, on | |
| 133 | // main (run 35091847509) and on #208 and #210. The runtime leg, second on | |
| 134 | // the same device, never did. | |
| 135 | // | |
| 136 | // `NSUnbufferedIO=YES` is what makes plain files usable. A pty is line | |
| 137 | // buffered and a file is not: without the variable, `print` wrote nothing | |
| 138 | // at all, not even once the app was terminated. Xcode sets it for the same | |
| 139 | // reason. `SIMCTL_CHILD_` is how simctl hands a variable to the app. | |
| 140 | // | |
| 141 | // And the launch now fails on its own terms. `simctl launch` returns once | |
| 142 | // the app has a pid, so a launch that cannot happen is an exception naming | |
| 143 | // simctl's error, not a timeout blamed on the page. | |
| 144 | const stdoutPath = join(evidence, 'app-stdout.log') | |
| 145 | const stderrPath = join(evidence, 'app-stderr.log') | |
| 128 | 146 | const consolePath = join(evidence, 'console.log') |
| 129 | const consoleFd = openSync(consolePath, 'w') | |
| 130 | const launched = Bun.spawn(['xcrun', 'simctl', 'launch', '--console-pty', device.udid, BUNDLE_ID], { | |
| 131 | stdout: consoleFd, | |
| 132 | stderr: consoleFd, | |
| 133 | }) | |
| 147 | const readConsole = () => [stdoutPath, stderrPath] | |
| 148 | .map(path => existsSync(path) ? readFileSync(path, 'utf8') : '') | |
| 149 | .join('') | |
| 134 | 150 | |
| 135 | // The suite is quick once the app is up, but a cold simulator is not, so | |
| 136 | // poll for the terminator rather than sleeping a fixed amount. | |
| 151 | await command([ | |
| 152 | 'xcrun', 'simctl', 'launch', '--terminate-running-process', | |
| 153 | `--stdout=${stdoutPath}`, `--stderr=${stderrPath}`, | |
| 154 | device.udid, BUNDLE_ID, | |
| 155 | ], { env: { SIMCTL_CHILD_NSUnbufferedIO: 'YES' }, logPath: join(evidence, 'simctl.log') }) | |
| 156 | ||
| 157 | // The suite is quick once the app is up, so poll for the terminator rather | |
| 158 | // than sleeping a fixed amount. | |
| 137 | 159 | // |
| 138 | 160 | // `hasTerminated` parses rather than matching a substring, because the very |
| 139 | 161 | // next statement kills the writer: a poll landing mid-write of the final |
| 140 | 162 | // line would otherwise leave a truncated event in the file and turn a |
| 141 | 163 | // passing suite into "driver emitted an unparseable event". |
| 142 | const finished = await waitForFile(consolePath, options.timeoutMs, hasTerminated) | |
| 164 | const finished = await waitForFile(consolePath, options.timeoutMs, hasTerminated, async () => { | |
| 165 | writeFileSync(consolePath, readConsole()) | |
| 166 | }) | |
| 143 | 167 | |
| 144 | launched.kill() | |
| 145 | closeSync(consoleFd) | |
| 146 | 168 | await command(['xcrun', 'simctl', 'terminate', device.udid, BUNDLE_ID], { allowFailure: true }) |
| 169 | writeFileSync(consolePath, readConsole()) | |
| 147 | 170 | |
| 148 | 171 | // Evidence before assertions, always: a leg that dies here is the one whose |
| 149 | 172 | // screenshot is worth the most. |
| @@ -171,8 +171,8 @@ function firstJsonObject(text: string): string | null { | ||
| 171 | 171 | /** |
| 172 | 172 | * Pull the driver's events out of a device log. |
| 173 | 173 | * |
| 174 | * The log is not ours: on iOS it is the app's whole stderr as | |
| 175 | * `simctl launch --console-pty` saw it, on Android a logcat slice, both | |
| 174 | * The log is not ours: on iOS it is the app's whole stdout and stderr as | |
| 175 | * `simctl launch --stdout --stderr` wrote them, on Android a logcat slice, both | |
| 176 | 176 | * carrying unrelated system chatter and, on iOS, ANSI colouring. So lines are |
| 177 | 177 | * found by marker rather than by position, colour codes are stripped first, |
| 178 | 178 | * and a marker line with no readable event is reported rather than skipped - |
| @@ -10,6 +10,8 @@ export interface CommandOptions { | ||
| 10 | 10 | /** Record the failure and carry on, for teardown steps whose failure is not the story. */ |
| 11 | 11 | allowFailure?: boolean |
| 12 | 12 | stdin?: string |
| 13 | /** Added to the inherited environment, not a replacement for it. */ | |
| 14 | env?: Record<string, string> | |
| 13 | 15 | /** |
| 14 | 16 | * Write raw stdout bytes here instead of returning them as text. |
| 15 | 17 | * |
| @@ -36,6 +38,7 @@ export interface CommandResult { | ||
| 36 | 38 | export async function command(argv: string[], options: CommandOptions = {}): Promise<CommandResult> { |
| 37 | 39 | const spawned = Bun.spawn(argv, { |
| 38 | 40 | cwd: options.cwd, |
| 41 | env: options.env ? { ...process.env, ...options.env } : undefined, | |
| 39 | 42 | stdin: options.stdin === undefined ? 'ignore' : new TextEncoder().encode(options.stdin), |
| 40 | 43 | stdout: 'pipe', |
| 41 | 44 | stderr: 'pipe', |