diff --git a/.github/workflows/1874-diagnose.yml b/.github/workflows/1874-diagnose.yml new file mode 100644 index 0000000000..2539704f6b --- /dev/null +++ b/.github/workflows/1874-diagnose.yml @@ -0,0 +1,112 @@ +name: 1874 Diagnose + +on: + workflow_dispatch: + inputs: + iterations: + description: 'Loop iterations per job' + required: false + default: '25' + push: + branches: + - diagnose/1874-commit-stall + +permissions: + contents: read + +concurrency: + group: ${{ github.workflow }}-${{ github.ref }} + cancel-in-progress: true + +jobs: + stall-loop: + name: ${{ matrix.arch }} ${{ matrix.mode }} stall loop + runs-on: macos-26 + timeout-minutes: 90 + strategy: + fail-fast: false + matrix: + mode: [isolated, pair] + arch: [x86_64, arm64] + env: + IOS_RUNTIME_VERSION: '26.2' + AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH: ${{ github.workspace }}/.tmp/ios-runner-derived + AGENT_DEVICE_XCUITEST_INCLUDE_UNIT_TESTS: '1' + AGENT_DEVICE_XCUITEST_ARCHS: ${{ matrix.arch }} + steps: + - uses: actions/checkout@v4 + + - name: Setup toolchain + uses: ./.github/actions/setup-node-pnpm + + - name: Restore and build iOS XCTest runner + uses: ./.github/actions/setup-apple-runner-build + with: + derived-path: ${{ env.AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH }} + cache-key-prefix: ios-runner-prebuilt + cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }}-1874-${{ matrix.arch }} + gate: swift-runner-ios + xcuitest-platform: ios + xcuitest-destination: generic/platform=iOS Simulator + + - name: Boot iOS test simulator + id: ios-simulator + uses: ./.github/actions/boot-ios-test-simulator + with: + runtime-version: ${{ env.IOS_RUNTIME_VERSION }} + preferred-device-name: iPhone 17 Pro + + - name: Stall loop + run: | + set -euo pipefail + XCTESTRUN_PATH="$(find "$AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH/Build/Products" -maxdepth 1 -name '*.xctestrun' -print -quit)" + test -n "$XCTESTRUN_PATH" + UDID="${{ steps.ios-simulator.outputs.simulator-udid }}" + ITER="${{ github.event.inputs.iterations || '25' }}" + + if [ "${{ matrix.mode }}" = "pair" ]; then + EXTRA_ONLY_TESTING=(-only-testing:AgentDeviceRunnerUITests/RunnerTests/testBareDelayedTypeFailsWhenTappedInputDisappearsMidCommand) + else + EXTRA_ONLY_TESTING=() + fi + + sys_prof="$(system_profiler SPHardwareDataType 2>/dev/null | grep -E 'Chip|Cores|Memory' || true)" + echo "HOST: $sys_prof" | tee stall-summary.txt + + pass=0; fail=0 + for i in $(seq 1 "$ITER"); do + LOG=".tmp/stall-run-$i.log" + set +e + xcodebuild test-without-building \ + -xctestrun "$XCTESTRUN_PATH" \ + -destination "platform=iOS Simulator,id=$UDID" \ + -only-testing:AgentDeviceRunnerUITests/RunnerTests/testBareTypeUsesTappedInputWhenSoftwareKeyboardIsHidden \ + ${EXTRA_ONLY_TESTING[@]+"${EXTRA_ONLY_TESTING[@]}"} \ + > "$LOG" 2>&1 + rc=$? + set -e + if grep -q "testBareTypeUsesTappedInputWhenSoftwareKeyboardIsHidden]' passed" "$LOG"; then + pass=$((pass+1)); verdict=pass + else + fail=$((fail+1)); verdict=STALL + fi + phase="$(grep -o 'phase=type-all durationMs=[0-9.]*' "$LOG" | tail -1)" + polls="$(grep -c 'DEBUG-1874] poll' "$LOG" || true)" + echo "iter=$i verdict=$verdict rc=$rc $phase polls=$polls" | tee -a stall-summary.txt + if [ "$verdict" = "STALL" ]; then + grep 'DEBUG-1874' "$LOG" | head -40 | tee -a stall-summary.txt + cp "$LOG" ".tmp/stall-failure-$i.log" + fi + done + + echo "RESULT arch=${{ matrix.arch }} mode=${{ matrix.mode }}: $pass passed, $fail stalled of $ITER" | tee -a stall-summary.txt + + - name: Upload stall evidence + if: always() + uses: actions/upload-artifact@v4 + with: + name: stall-evidence-${{ matrix.arch }}-${{ matrix.mode }} + path: | + stall-summary.txt + .tmp/stall-failure-*.log + if-no-files-found: ignore diff --git a/.github/workflows/conformance-differential.yml b/.github/workflows/conformance-differential.yml index 082a630ef2..60fad18a24 100644 --- a/.github/workflows/conformance-differential.yml +++ b/.github/workflows/conformance-differential.yml @@ -45,6 +45,7 @@ jobs: timeout-minutes: 90 env: IOS_RUNTIME_VERSION: '26.2' + AGENT_DEVICE_XCUITEST_ARCHS: 'arm64' AGENT_DEVICE_STATE_DIR: ${{ github.workspace }}/.tmp/agent-device-state AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH: ${{ github.workspace }}/.tmp/ios-runner-derived steps: @@ -59,7 +60,7 @@ jobs: with: derived-path: ${{ env.AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH }} cache-key-prefix: ios-runner-prebuilt - cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }} + cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }}-arm64 gate: swift-runner-ios xcuitest-platform: ios xcuitest-destination: generic/platform=iOS Simulator diff --git a/.github/workflows/ios.yml b/.github/workflows/ios.yml index 0f64b91b4d..16f6ca79b7 100644 --- a/.github/workflows/ios.yml +++ b/.github/workflows/ios.yml @@ -74,6 +74,11 @@ jobs: AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH: ${{ github.workspace }}/.tmp/ios-runner-derived AGENT_DEVICE_IOS_PREPARE_TIMEOUT_MS: '420000' AGENT_DEVICE_XCUITEST_INCLUDE_UNIT_TESTS: '1' + # A generic simulator destination leaves the active arch undefined and Xcode 26.6 + # defaults it to x86_64, which runs the whole runner under Rosetta on arm64 hosts. + # Pin the native slice: measured ~30% faster commits on identical CI hardware + # (#1874 diagnosis, PR #1941). + AGENT_DEVICE_XCUITEST_ARCHS: 'arm64' AGENT_DEVICE_IOS_APP_EVENT_URL_TEMPLATE: agent-device-test-app:///automation?event={event}&payload={payload} steps: - name: Checkout @@ -113,7 +118,7 @@ jobs: with: derived-path: ${{ env.AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH }} cache-key-prefix: ios-runner-prebuilt - cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }} + cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }}-arm64 gate: swift-runner-ios xcuitest-platform: ios xcuitest-destination: generic/platform=iOS Simulator diff --git a/.github/workflows/perf-nightly.yml b/.github/workflows/perf-nightly.yml index 81caf11a65..5814855ead 100644 --- a/.github/workflows/perf-nightly.yml +++ b/.github/workflows/perf-nightly.yml @@ -32,6 +32,7 @@ jobs: timeout-minutes: 80 env: IOS_RUNTIME_VERSION: '26.2' + AGENT_DEVICE_XCUITEST_ARCHS: 'arm64' AGENT_DEVICE_STATE_DIR: ${{ github.workspace }}/.tmp/agent-device-state AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH: ${{ github.workspace }}/.tmp/ios-runner-derived AGENT_DEVICE_IOS_PREPARE_TIMEOUT_MS: '420000' @@ -47,7 +48,7 @@ jobs: with: derived-path: ${{ env.AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH }} cache-key-prefix: ios-runner-prebuilt - cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }} + cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }}-arm64 gate: swift-runner-ios xcuitest-platform: ios xcuitest-destination: generic/platform=iOS Simulator diff --git a/.github/workflows/replays-manual.yml b/.github/workflows/replays-manual.yml index 14706da132..acdc155376 100644 --- a/.github/workflows/replays-manual.yml +++ b/.github/workflows/replays-manual.yml @@ -91,6 +91,7 @@ jobs: timeout-minutes: 80 env: IOS_RUNTIME_VERSION: '26.2' + AGENT_DEVICE_XCUITEST_ARCHS: 'arm64' AGENT_DEVICE_STATE_DIR: ${{ github.workspace }}/.tmp/agent-device-state AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH: ${{ github.workspace }}/.tmp/ios-runner-derived AGENT_DEVICE_IOS_PREPARE_TIMEOUT_MS: '420000' @@ -111,7 +112,7 @@ jobs: with: derived-path: ${{ env.AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH }} cache-key-prefix: ios-runner-prebuilt - cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }} + cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }}-arm64 gate: swift-runner-ios xcuitest-platform: ios xcuitest-destination: generic/platform=iOS Simulator diff --git a/.github/workflows/xctest-nightly.yml b/.github/workflows/xctest-nightly.yml index 4af521cff9..25840247fb 100644 --- a/.github/workflows/xctest-nightly.yml +++ b/.github/workflows/xctest-nightly.yml @@ -78,8 +78,10 @@ jobs: # methods exist at all. Dropping it would build a different variant (cache miss) whose # bundle contains no tests, and `xcodebuild` reports running zero tests as success — the # "silent 0-test green" this lane would then be. The test-count assertion below is the - # backstop for exactly that. + # backstop for exactly that. AGENT_DEVICE_XCUITEST_ARCHS rides the cache key too: dropping + # it silently reverts the runner to Xcode's x86_64 default under Rosetta. IOS_RUNTIME_VERSION: '26.2' + AGENT_DEVICE_XCUITEST_ARCHS: 'arm64' AGENT_DEVICE_XCUITEST_INCLUDE_UNIT_TESTS: '1' AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH: ${{ github.workspace }}/.tmp/ios-runner-derived RESULT_BUNDLE_PATH: ${{ github.workspace }}/.tmp/xctest-nightly/RunnerTests.xcresult @@ -103,7 +105,7 @@ jobs: with: derived-path: ${{ env.AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH }} cache-key-prefix: ios-runner-prebuilt - cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }} + cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }}-arm64 gate: swift-runner-ios xcuitest-platform: ios xcuitest-destination: generic/platform=iOS Simulator diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift index b37bf14661..865136b1f7 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift @@ -40,9 +40,14 @@ extension RunnerTests { replacingExistingText: Bool ) -> SynthesizedTextEntryAction { #if os(iOS) + let postStartedAt = Date() let result = replacingExistingText ? RunnerSynthesizedTextEntry.replaceText(withApplication: app, text: text) : RunnerSynthesizedTextEntry.synthesizeText(withApplication: app, text: text) + NSLog( + "[DEBUG-1874] synthesize posted %d chars status=%d tookMs=%.0f", + text.count, result.status.rawValue, postStartedAt.timeIntervalSinceNow * -1000 + ) return Self.action(status: result.status, message: result.message) #else return .fallback @@ -184,6 +189,47 @@ extension RunnerTests { return expectedText.hasPrefix(observedText) ? .pending : .diverged } + /// Length of the shared prefix of two strings. Feeds value-free commit-wait logging: the + /// expected-prefix walk over time distinguishes throttled delivery (grows slowly) from a + /// wedged pipeline (freezes) without ever logging the field's contents. + static func commonPrefixLength(_ lhs: String, _ rhs: String) -> Int { + var length = 0 + for (l, r) in zip(lhs, rhs) { + if l != r { break } + length += 1 + } + return length + } + + /// The emitted cadence line, as a pure function so its output is assertable. Only lengths and + /// a timestamp are representable here; there is no String parameter, so observed field + /// contents cannot reach runner.log through this boundary whatever they contain. + static func commitCadenceLogLine( + elapsedMs: Int, + observedLen: Int, + expectedPrefixLen: Int + ) -> String { + "[DEBUG-1874] poll t=\(elapsedMs)ms observedLen=\(observedLen) expectedPrefixLen=\(expectedPrefixLen)" + } + + /// The typed boundary for commit-wait cadence evidence. The poll path must log through this + /// function and never through a raw NSLog: every parameter is an Int, so the polled value's + /// contents are unrepresentable at the call site. + static func logCommitCadence( + elapsedMs: Int, + observedLen: Int, + expectedPrefixLen: Int + ) { + NSLog( + "%@", + commitCadenceLogLine( + elapsedMs: elapsedMs, + observedLen: observedLen, + expectedPrefixLen: expectedPrefixLen + ) + ) + } + /// How the commit wait ended. Distinct from `SynthesizedTextCommitProgress`, which classifies a /// single observation: this is the whole wait's verdict, and it exists so the deadline can be /// told apart from success. The wait used to return `Void`, which made an expired deadline @@ -265,20 +311,37 @@ extension RunnerTests { let expectedText = textBefore + typedText let placeholder = resolveTextEntryElement(app: app, target: target)?.placeholderValue let deadline = Date().addingTimeInterval(TextEntryTiming.synthesizedCommitTimeout) - return Self.awaitSynthesizedCommitOutcome( + let waitStartedAt = Date() + NSLog("[DEBUG-1874] wait start expectedLen=%ld", expectedText.count) + let outcome = Self.awaitSynthesizedCommitOutcome( expectedText: expectedText, placeholder: placeholder, isExpired: { Date() >= deadline }, observe: { - editableTextValue( + let observedText = editableTextValue( for: resolveTextEntryElement(app: app, target: target), treatingPlaceholderAsEmpty: true ) + // Cadence evidence stays value-free: the polled value is user content typed through + // `type` and must never reach runner.log. Lengths and the expected-prefix walk are + // enough to distinguish throttling (prefix grows slowly) from a wedge (it freezes). + Self.logCommitCadence( + elapsedMs: Int(waitStartedAt.timeIntervalSinceNow * -1000), + observedLen: observedText?.count ?? -1, + expectedPrefixLen: observedText.map { Self.commonPrefixLength($0, expectedText) } ?? -1 + ) + return observedText }, // XCUI resolution shares the automation channel with the in-flight synthesized event. // Sparse reads let the target consume that event instead of continuously interrupting it. waitForNextObservation: { sleepFor(TextEntryTiming.synthesizedCommitPollInterval) } ) + NSLog( + "[DEBUG-1874] wait outcome=%@ elapsedMs=%.0f", + String(describing: outcome), + waitStartedAt.timeIntervalSinceNow * -1000 + ) + return outcome } static func shouldUseResolvedCoordinateTextEntryRoute( diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift index 9202609a22..3e98afc626 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift @@ -308,6 +308,31 @@ extension RunnerTests { XCTAssertFalse(result.repaired) XCTAssertEqual(result.textEntryRoute, "synthesized-first-responder-replacement") } + + func testCommonPrefixLengthWalksTheExpectedPrefixOnly() { + XCTAssertEqual(Self.commonPrefixLength("hardware-keyboard", "hardware-keyboard"), 17) + XCTAssertEqual(Self.commonPrefixLength("h", "hardware-keyboard"), 1) + XCTAssertEqual(Self.commonPrefixLength("ha", "hardware-keyboard"), 2) + XCTAssertEqual(Self.commonPrefixLength("", "hardware-keyboard"), 0) + // Divergence stops the count: the app transformed the input, and the walk must not + // resume matching after the first differing character. + XCTAssertEqual(Self.commonPrefixLength("hx", "hardware-keyboard"), 1) + XCTAssertEqual(Self.commonPrefixLength("hardware-keyboarx", "hardware-keyboard"), 15) + } + + func testCommitCadenceLogLineEmitsLengthsOnlyNeverContents() { + // Sentinel secret: even when the polled field holds credential-shaped content, the only + // channel into runner.log is this line, and its inputs are lengths. The exact-equality + // assert fails if any content-bearing parameter or interpolation is ever added. + let secret = "hunter2-typed-credential" + let line = Self.commitCadenceLogLine( + elapsedMs: 42, + observedLen: secret.count, + expectedPrefixLen: 8 + ) + XCTAssertEqual(line, "[DEBUG-1874] poll t=42ms observedLen=24 expectedPrefixLen=8") + XCTAssertFalse(line.contains(secret)) + } #endif #endif } diff --git a/scripts/build-xcuitest-apple.sh b/scripts/build-xcuitest-apple.sh index 2306dacbfd..6c0b5fd556 100644 --- a/scripts/build-xcuitest-apple.sh +++ b/scripts/build-xcuitest-apple.sh @@ -138,6 +138,14 @@ if is_truthy "${AGENT_DEVICE_XCUITEST_INCLUDE_UNIT_TESTS:-}"; then SWIFT_FLAGS="$SWIFT_FLAGS -D AGENT_DEVICE_RUNNER_UNIT_TESTS" fi +# Optional arch override. A generic simulator destination leaves the active arch +# undefined; Xcode versions differ on the default (26.6 picks x86_64, which runs +# under Rosetta on arm64 hosts). Set AGENT_DEVICE_XCUITEST_ARCHS=arm64 to pin it. +ARCH_BUILD_SETTINGS="" +if [ -n "${AGENT_DEVICE_XCUITEST_ARCHS:-}" ]; then + ARCH_BUILD_SETTINGS="ARCHS=$AGENT_DEVICE_XCUITEST_ARCHS" +fi + node --experimental-strip-types scripts/swift-toolchain-tmpdir.ts xcodebuild build-for-testing \ -project "$PROJECT_PATH" \ -scheme "$SCHEME" \ @@ -154,6 +162,7 @@ node --experimental-strip-types scripts/swift-toolchain-tmpdir.ts xcodebuild bui -IDEPackageSupportDisablePluginExecutionSandbox=1 \ ENABLE_USER_SCRIPT_SANDBOXING=NO \ OTHER_SWIFT_FLAGS="$SWIFT_FLAGS" \ + $ARCH_BUILD_SETTINGS \ $SIGNING_BUILD_SETTINGS node --experimental-strip-types scripts/patch-xcuitest-runner-icon.ts "$DERIVED_PATH" diff --git a/src/__tests__/apple-runner-log-redaction.test.ts b/src/__tests__/apple-runner-log-redaction.test.ts new file mode 100644 index 0000000000..1d72336ec5 --- /dev/null +++ b/src/__tests__/apple-runner-log-redaction.test.ts @@ -0,0 +1,76 @@ +import assert from 'node:assert/strict'; +import fs from 'node:fs'; +import path from 'node:path'; +import { fileURLToPath } from 'node:url'; +import { test } from 'vitest'; + +const repoRoot = path.resolve(path.dirname(fileURLToPath(import.meta.url)), '../..'); +const synthesizedTextEntryPath = path.join( + repoRoot, + 'apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift', +); + +// The synthesized bare-type commit wait polls the target field's live value on the shipped +// `type` path. That value is user content — a `type` command may carry credentials, tokens, or +// PII — and runner.log persists across the session. Cadence evidence must stay value-free. +// +// The enforcement is a typed Swift boundary (`logCommitCadence`), whose parameters are Ints +// only, so observed contents are unrepresentable at the call site; its emitted line is pinned +// by a sentinel-secret test in the host-lane policy tests. This guard is structural: it fails +// if the boundary disappears or if the poll path logs any other way. It deliberately does not +// parse Swift format strings — that review shape let raw values slip through interpolation. + +const boundarySignature = + /static func commitCadenceLogLine\(\s*elapsedMs: Int,\s*observedLen: Int,\s*expectedPrefixLen: Int\s*\) -> String/; +const loggingBoundarySignature = + /static func logCommitCadence\(\s*elapsedMs: Int,\s*observedLen: Int,\s*expectedPrefixLen: Int\s*\)/; + +function extractObserveClosure(source: string): string { + const start = source.indexOf('observe: {'); + assert.ok(start !== -1, 'commit wait must inject an observe closure'); + const end = source.indexOf('waitForNextObservation:', start); + assert.ok(end !== -1, 'commit wait must keep its waitForNextObservation seam'); + return source.slice(start, end); +} + +test('commit-wait cadence logging goes through the typed value-free boundary', () => { + const source = fs.readFileSync(synthesizedTextEntryPath, 'utf8'); + + assert.match( + source, + boundarySignature, + 'commitCadenceLogLine must accept only lengths/timestamps (Int parameters)', + ); + assert.match( + source, + loggingBoundarySignature, + 'logCommitCadence is the only sanctioned logging entry for the poll path', + ); + + const observeClosure = extractObserveClosure(source); + const directNSLogs = observeClosure.match(/NSLog\(/g) ?? []; + assert.deepEqual( + directNSLogs, + [], + 'the poll path must log through logCommitCadence, never through a raw NSLog', + ); + assert.match( + observeClosure, + /Self\.logCommitCadence\(/, + 'the poll path must emit its cadence evidence through the typed boundary', + ); + + // Cheap extra: no NSLog anywhere in the module interpolates the raw observed binding. + for ( + let index = source.indexOf('NSLog('); + index !== -1; + index = source.indexOf('NSLog(', index + 1) + ) { + const window = source.slice(index, index + 400); + assert.doesNotMatch( + window, + /NSLog\([^)]*\bobservedText\b/, + 'raw observedText must never reach NSLog', + ); + } +});