From 00eab69b901823d2e8ae6aab29d2ad359e16394f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Fri, 21 Aug 2026 13:57:10 +0200 Subject: [PATCH 1/7] diagnose(1874): instrument synthesized commit wait and add stall loop workflow --- .github/workflows/1874-diagnose.yml | 110 ++++++++++++++++++ .../RunnerTests+SynthesizedTextEntry.swift | 19 ++- 2 files changed, 127 insertions(+), 2 deletions(-) create mode 100644 .github/workflows/1874-diagnose.yml diff --git a/.github/workflows/1874-diagnose.yml b/.github/workflows/1874-diagnose.yml new file mode 100644 index 0000000000..d7c79c6f94 --- /dev/null +++ b/.github/workflows/1874-diagnose.yml @@ -0,0 +1,110 @@ +name: 1874 Diagnose + +on: + workflow_dispatch: + inputs: + iterations: + description: 'Loop iterations per job' + required: false + default: '12' + push: + branches: + - diagnose/1874-commit-stall + +permissions: + contents: read + +concurrency: + group: ${{ github.workflow }}-${{ github.ref }} + cancel-in-progress: true + +jobs: + stall-loop: + name: ${{ matrix.mode }} stall loop + runs-on: macos-26 + timeout-minutes: 90 + strategy: + fail-fast: false + matrix: + mode: [isolated, pair] + 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' + 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 + 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 || '12' }}" + + 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[@]}" \ + > "$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 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.mode }} + path: | + stall-summary.txt + .tmp/stall-failure-*.log + if-no-files-found: ignore diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift index b37bf14661..60e52408cd 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 @@ -265,20 +270,30 @@ 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 expected=%d chars", 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 ) + NSLog( + "[DEBUG-1874] poll t=%.0fms observed=%@", + waitStartedAt.timeIntervalSinceNow * -1000, + observedText.map { String($0.prefix(40)) } ?? "nil" + ) + 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( From 3685a7e98c7b839f79d2067c8457b07ff01e629c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Fri, 21 Aug 2026 15:07:21 +0200 Subject: [PATCH 2/7] diagnose(1874): fix empty-array expansion under set -u; raise default iterations --- .github/workflows/1874-diagnose.yml | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/.github/workflows/1874-diagnose.yml b/.github/workflows/1874-diagnose.yml index d7c79c6f94..31e8f65b1c 100644 --- a/.github/workflows/1874-diagnose.yml +++ b/.github/workflows/1874-diagnose.yml @@ -6,7 +6,7 @@ on: iterations: description: 'Loop iterations per job' required: false - default: '12' + default: '25' push: branches: - diagnose/1874-commit-stall @@ -60,7 +60,7 @@ jobs: 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 || '12' }}" + ITER="${{ github.event.inputs.iterations || '25' }}" if [ "${{ matrix.mode }}" = "pair" ]; then EXTRA_ONLY_TESTING=(-only-testing:AgentDeviceRunnerUITests/RunnerTests/testBareDelayedTypeFailsWhenTappedInputDisappearsMidCommand) @@ -79,7 +79,7 @@ jobs: -xctestrun "$XCTESTRUN_PATH" \ -destination "platform=iOS Simulator,id=$UDID" \ -only-testing:AgentDeviceRunnerUITests/RunnerTests/testBareTypeUsesTappedInputWhenSoftwareKeyboardIsHidden \ - "${EXTRA_ONLY_TESTING[@]}" \ + ${EXTRA_ONLY_TESTING[@]+"${EXTRA_ONLY_TESTING[@]}"} \ > "$LOG" 2>&1 rc=$? set -e From e7b078d5f3828530edfa8dbf74b894401c82c5ee Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Fri, 21 Aug 2026 17:14:32 +0200 Subject: [PATCH 3/7] diagnose(1874): add arm64 matrix leg to isolate the Rosetta factor --- .github/workflows/1874-diagnose.yml | 10 ++++++---- scripts/build-xcuitest-apple.sh | 9 +++++++++ 2 files changed, 15 insertions(+), 4 deletions(-) diff --git a/.github/workflows/1874-diagnose.yml b/.github/workflows/1874-diagnose.yml index 31e8f65b1c..2539704f6b 100644 --- a/.github/workflows/1874-diagnose.yml +++ b/.github/workflows/1874-diagnose.yml @@ -20,17 +20,19 @@ concurrency: jobs: stall-loop: - name: ${{ matrix.mode }} 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 @@ -42,7 +44,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 }}-1874 + cache-key-suffix: -ios-${{ env.IOS_RUNTIME_VERSION }}-1874-${{ matrix.arch }} gate: swift-runner-ios xcuitest-platform: ios xcuitest-destination: generic/platform=iOS Simulator @@ -97,13 +99,13 @@ jobs: fi done - echo "RESULT mode=${{ matrix.mode }}: $pass passed, $fail stalled of $ITER" | tee -a stall-summary.txt + 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.mode }} + name: stall-evidence-${{ matrix.arch }}-${{ matrix.mode }} path: | stall-summary.txt .tmp/stall-failure-*.log 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" From 4c1c61fa7d0b2510345f70d46e89ea6a744cc227 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Fri, 21 Aug 2026 18:12:35 +0200 Subject: [PATCH 4/7] ci: build the iOS runner for the native arm64 slice A generic simulator destination leaves the active arch undefined; Xcode 26.6 defaults it to x86_64, running the whole runner under Rosetta on arm64 hosts. Pin ARCHS=arm64 across every lane that builds the iOS runner and bump the derived-data cache suffixes. Measured ~30% faster commits on identical CI hardware; delivery-throttle episodes still occur but start from a lower base. --- .github/workflows/conformance-differential.yml | 3 ++- .github/workflows/ios.yml | 7 ++++++- .github/workflows/perf-nightly.yml | 3 ++- .github/workflows/replays-manual.yml | 3 ++- .github/workflows/xctest-nightly.yml | 6 ++++-- 5 files changed, 16 insertions(+), 6 deletions(-) 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 From 443d62d5034c9a697291e9b7dde3d88eeb937b0f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Fri, 21 Aug 2026 18:54:54 +0200 Subject: [PATCH 5/7] diagnose(1874): keep commit-wait cadence evidence value-free The per-poll trace logged the observed field's contents (prefix(40)) on the shipped type path; that value is user content and runner.log persists. Log lengths and the expected-prefix walk instead, allowlist every string-interpolating NSLog format in the module behind a source-scan guard, and pin commonPrefixLength in the host-lane policy tests. --- .../RunnerTests+SynthesizedTextEntry.swift | 28 ++++++-- .../RunnerTests+TextEntryPolicyTests.swift | 11 +++ .../apple-runner-log-redaction.test.ts | 70 +++++++++++++++++++ 3 files changed, 105 insertions(+), 4 deletions(-) create mode 100644 src/__tests__/apple-runner-log-redaction.test.ts diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift index 60e52408cd..aae8f67f63 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift @@ -189,6 +189,18 @@ 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 + } + /// 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 @@ -271,7 +283,7 @@ extension RunnerTests { let placeholder = resolveTextEntryElement(app: app, target: target)?.placeholderValue let deadline = Date().addingTimeInterval(TextEntryTiming.synthesizedCommitTimeout) let waitStartedAt = Date() - NSLog("[DEBUG-1874] wait start expected=%d chars", expectedText.count) + NSLog("[DEBUG-1874] wait start expectedLen=%ld", expectedText.count) let outcome = Self.awaitSynthesizedCommitOutcome( expectedText: expectedText, placeholder: placeholder, @@ -281,10 +293,14 @@ extension RunnerTests { 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). NSLog( - "[DEBUG-1874] poll t=%.0fms observed=%@", + "[DEBUG-1874] poll t=%.0fms observedLen=%ld expectedPrefixLen=%ld", waitStartedAt.timeIntervalSinceNow * -1000, - observedText.map { String($0.prefix(40)) } ?? "nil" + observedText?.count ?? -1, + observedText.map { Self.commonPrefixLength($0, expectedText) } ?? -1 ) return observedText }, @@ -292,7 +308,11 @@ extension RunnerTests { // 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) + NSLog( + "[DEBUG-1874] wait outcome=%@ elapsedMs=%.0f", + String(describing: outcome), + waitStartedAt.timeIntervalSinceNow * -1000 + ) return outcome } diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift index 9202609a22..5a62b24bd3 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift @@ -308,6 +308,17 @@ 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) + } #endif #endif } 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..5be974fb4f --- /dev/null +++ b/src/__tests__/apple-runner-log-redaction.test.ts @@ -0,0 +1,70 @@ +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: +// lengths, timestamps, and enum names only. +// +// Guard shape: every NSLog format string in the module that interpolates a string (%@) must be +// on this allowlist of static, non-field-content formats. Reintroducing raw observed text into +// runner logging requires adding a new %@ format here, which fails this test until a human +// reviews it. +const allowedStringInterpolatingFormats = new Set([ + 'AGENT_DEVICE_RUNNER_TEXT_ENTRY_ROUTE route=%@', + 'AGENT_DEVICE_RUNNER_TEXT_ENTRY_ROUTE route=verified-fallback reason=%@', + 'AGENT_DEVICE_RUNNER_TEXT_ENTRY_PHASE commandId=%@ phase=%@ durationMs=%.1f chars=%d mode=%@', + '[DEBUG-1874] wait outcome=%@ elapsedMs=%.0f', +]); + +function extractNSLogStatements(source: string): string[] { + const statements: string[] = []; + let index = source.indexOf('NSLog('); + while (index !== -1) { + let depth = 0; + let cursor = index + 'NSLog'.length; + for (; cursor < source.length; cursor += 1) { + if (source[cursor] === '(') depth += 1; + if (source[cursor] === ')') { + depth -= 1; + if (depth === 0) break; + } + } + statements.push(source.slice(index, cursor + 1)); + index = source.indexOf('NSLog(', cursor); + } + return statements; +} + +test('synthesized text entry logging stays free of observed field contents', () => { + const source = fs.readFileSync(synthesizedTextEntryPath, 'utf8'); + const statements = extractNSLogStatements(source); + assert.ok(statements.length > 0, 'expected NSLog statements in the module'); + + for (const statement of statements) { + const formatMatch = statement.match(/"((?:[^"\\]|\\.)*)"/); + assert.ok(formatMatch, `NSLog without a literal format string: ${statement}`); + const format = formatMatch[1]; + if (!format.includes('%@')) continue; + assert.ok( + allowedStringInterpolatingFormats.has(format), + `unreviewed string-interpolating log format "${format}" — field contents must never reach runner.log`, + ); + } + + // The invariant this module must keep: cadence evidence names lengths, not contents. + assert.match( + source, + /poll t=%\.0fms observedLen=%ld expectedPrefixLen=%ld/, + 'commit-wait polling must log value-free cadence evidence', + ); +}); From 3cb1a532db4aba67083d2aa1dade2fea1e5ce9a9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Fri, 21 Aug 2026 18:58:33 +0200 Subject: [PATCH 6/7] diagnose(1874): narrow the log-format match for typecheck --- src/__tests__/apple-runner-log-redaction.test.ts | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/src/__tests__/apple-runner-log-redaction.test.ts b/src/__tests__/apple-runner-log-redaction.test.ts index 5be974fb4f..14568a7e7a 100644 --- a/src/__tests__/apple-runner-log-redaction.test.ts +++ b/src/__tests__/apple-runner-log-redaction.test.ts @@ -51,9 +51,8 @@ test('synthesized text entry logging stays free of observed field contents', () assert.ok(statements.length > 0, 'expected NSLog statements in the module'); for (const statement of statements) { - const formatMatch = statement.match(/"((?:[^"\\]|\\.)*)"/); - assert.ok(formatMatch, `NSLog without a literal format string: ${statement}`); - const format = formatMatch[1]; + const format = statement.match(/"((?:[^"\\]|\\.)*)"/)?.[1]; + assert.ok(format != null, `NSLog without a literal format string: ${statement}`); if (!format.includes('%@')) continue; assert.ok( allowedStringInterpolatingFormats.has(format), From 956cd3759c2aca4a32c2c5ad337a9a17125f2d8f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Fri, 21 Aug 2026 20:08:46 +0200 Subject: [PATCH 7/7] diagnose(1874): route cadence evidence through a typed value-free boundary MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit logCommitCadence accepts Int lengths and a timestamp only, so observed field contents are unrepresentable at the poll call site; its emitted line is pinned by a sentinel-secret test in the host-lane policy tests. The source guard becomes structural — boundary present, poll path logs through it, no raw NSLog in the observe closure — instead of parsing Swift format strings. #1874 is reopened as the removal-tracking thread for this temporary instrumentation. --- .../RunnerTests+SynthesizedTextEntry.swift | 38 +++++++- .../RunnerTests+TextEntryPolicyTests.swift | 14 +++ .../apple-runner-log-redaction.test.ts | 97 ++++++++++--------- 3 files changed, 99 insertions(+), 50 deletions(-) diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift index aae8f67f63..865136b1f7 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedTextEntry.swift @@ -201,6 +201,35 @@ extension RunnerTests { 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 @@ -296,11 +325,10 @@ extension RunnerTests { // 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). - NSLog( - "[DEBUG-1874] poll t=%.0fms observedLen=%ld expectedPrefixLen=%ld", - waitStartedAt.timeIntervalSinceNow * -1000, - observedText?.count ?? -1, - observedText.map { Self.commonPrefixLength($0, expectedText) } ?? -1 + Self.logCommitCadence( + elapsedMs: Int(waitStartedAt.timeIntervalSinceNow * -1000), + observedLen: observedText?.count ?? -1, + expectedPrefixLen: observedText.map { Self.commonPrefixLength($0, expectedText) } ?? -1 ) return observedText }, diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift index 5a62b24bd3..3e98afc626 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+TextEntryPolicyTests.swift @@ -319,6 +319,20 @@ extension RunnerTests { 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/src/__tests__/apple-runner-log-redaction.test.ts b/src/__tests__/apple-runner-log-redaction.test.ts index 14568a7e7a..1d72336ec5 100644 --- a/src/__tests__/apple-runner-log-redaction.test.ts +++ b/src/__tests__/apple-runner-log-redaction.test.ts @@ -12,58 +12,65 @@ const synthesizedTextEntryPath = path.join( // 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: -// lengths, timestamps, and enum names only. +// PII — and runner.log persists across the session. Cadence evidence must stay value-free. // -// Guard shape: every NSLog format string in the module that interpolates a string (%@) must be -// on this allowlist of static, non-field-content formats. Reintroducing raw observed text into -// runner logging requires adding a new %@ format here, which fails this test until a human -// reviews it. -const allowedStringInterpolatingFormats = new Set([ - 'AGENT_DEVICE_RUNNER_TEXT_ENTRY_ROUTE route=%@', - 'AGENT_DEVICE_RUNNER_TEXT_ENTRY_ROUTE route=verified-fallback reason=%@', - 'AGENT_DEVICE_RUNNER_TEXT_ENTRY_PHASE commandId=%@ phase=%@ durationMs=%.1f chars=%d mode=%@', - '[DEBUG-1874] wait outcome=%@ elapsedMs=%.0f', -]); +// 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. -function extractNSLogStatements(source: string): string[] { - const statements: string[] = []; - let index = source.indexOf('NSLog('); - while (index !== -1) { - let depth = 0; - let cursor = index + 'NSLog'.length; - for (; cursor < source.length; cursor += 1) { - if (source[cursor] === '(') depth += 1; - if (source[cursor] === ')') { - depth -= 1; - if (depth === 0) break; - } - } - statements.push(source.slice(index, cursor + 1)); - index = source.indexOf('NSLog(', cursor); - } - return statements; +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('synthesized text entry logging stays free of observed field contents', () => { +test('commit-wait cadence logging goes through the typed value-free boundary', () => { const source = fs.readFileSync(synthesizedTextEntryPath, 'utf8'); - const statements = extractNSLogStatements(source); - assert.ok(statements.length > 0, 'expected NSLog statements in the module'); - - for (const statement of statements) { - const format = statement.match(/"((?:[^"\\]|\\.)*)"/)?.[1]; - assert.ok(format != null, `NSLog without a literal format string: ${statement}`); - if (!format.includes('%@')) continue; - assert.ok( - allowedStringInterpolatingFormats.has(format), - `unreviewed string-interpolating log format "${format}" — field contents must never reach runner.log`, - ); - } - // The invariant this module must keep: cadence evidence names lengths, not contents. assert.match( source, - /poll t=%\.0fms observedLen=%ld expectedPrefixLen=%ld/, - 'commit-wait polling must log value-free cadence evidence', + 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', + ); + } });