From 3f25f77fcc0a7f5be71593d15f139dc78371e4e6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Oskar=20Kwas=CC=81niewski?= Date: Wed, 23 Sep 2026 14:14:51 +0200 Subject: [PATCH 1/4] fix(ios-runner): log the fast app guard and gesture policy only when they change Two days of one e2e suite left a 374k-line runner.log: 35,080 FAST_APP_GUARD and 5,612 SYNTHESIZED_GESTURE_POLICY lines, one per command, each restating a fact that had not changed since the previous command. Both markers now go through a small RepeatedLogSuppressor keyed by marker (and gesture kind for the policy): a line is written when the fact differs from the last one written under that key, and the suppressor is reset with the cached target so a rebind states the fact once more. COMMAND_ACCEPTED/COMPLETED pairs are untouched. Verified on an iOS simulator against Settings: 8 tap commands wrote 1 guard line and 1 policy line. --- .../RunnerTests+Lifecycle.swift | 66 +++++++++++++++++-- ...RunnerTests+SynthesizedGesturePolicy.swift | 29 ++++---- .../RunnerTests.swift | 5 ++ 3 files changed, 80 insertions(+), 20 deletions(-) diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift index 67c689cb1c..a08991b121 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift @@ -179,6 +179,7 @@ extension RunnerTests { currentAppProcessIdentifier = nil clearRememberedTextEntryTap() snapshotXCTestPenaltyWarmupExemptionPending = false + repeatedLogSuppressor.reset() } func resetTargetAfterExternalRelaunch() -> Response { @@ -253,11 +254,11 @@ extension RunnerTests { return false } guard activeApp.state == .runningForeground else { return false } - NSLog( - "AGENT_DEVICE_RUNNER_FAST_APP_GUARD command=%@ bundle=%@ state=%d", - String(describing: command), - requestedBundleId, - activeApp.state.rawValue + let state = activeApp.state.rawValue + repeatedLogSuppressor.logIfChanged( + key: "fast_app_guard", + fact: "\(requestedBundleId) \(state)", + line: "AGENT_DEVICE_RUNNER_FAST_APP_GUARD command=\(String(describing: command)) bundle=\(requestedBundleId) state=\(state)" ) return true } @@ -479,3 +480,58 @@ extension RunnerTests { usleep(useconds_t(delay * 1_000_000)) } } + +/// Writes a repeating log fact only when it changes. `logIfChanged` compares `fact` with the last +/// one written under `key` and, on a change, writes `line` (which may carry per-command detail the +/// comparison ignores). `reset` forgets every key so the next call writes again. +final class RepeatedLogSuppressor { + private let lock = NSLock() + private var lastFacts: [String: String] = [:] + + @discardableResult + func logIfChanged(key: String, fact: String, line: @autoclosure () -> String) -> Bool { + lock.lock() + let changed = lastFacts[key] != fact + if changed { + lastFacts[key] = fact + } + lock.unlock() + if changed { + NSLog("%@", line()) + } + return changed + } + + func reset() { + lock.lock() + lastFacts.removeAll() + lock.unlock() + } +} + +#if AGENT_DEVICE_RUNNER_UNIT_TESTS +extension RunnerTests { + func testRepeatedLogSuppressorWritesOnlyWhenTheFactChangesUntilReset() { + let suppressor = RepeatedLogSuppressor() + XCTAssertTrue(suppressor.logIfChanged(key: "guard", fact: "app 4", line: "guard first")) + XCTAssertFalse(suppressor.logIfChanged(key: "guard", fact: "app 4", line: "guard repeat")) + XCTAssertFalse(suppressor.logIfChanged(key: "guard", fact: "app 4", line: "guard repeat")) + XCTAssertTrue(suppressor.logIfChanged(key: "guard", fact: "app 2", line: "guard changed")) + XCTAssertTrue(suppressor.logIfChanged(key: "policy", fact: "app 2", line: "other key")) + suppressor.reset() + XCTAssertTrue( + suppressor.logIfChanged(key: "guard", fact: "app 2", line: "guard after reset"), + "a reset must restate the fact once more" + ) + } + + func testInvalidatingTheCachedTargetResetsTheRepeatedLogSuppressor() { + repeatedLogSuppressor.reset() + XCTAssertTrue(repeatedLogSuppressor.logIfChanged(key: "guard", fact: "app", line: "first")) + XCTAssertFalse(repeatedLogSuppressor.logIfChanged(key: "guard", fact: "app", line: "repeat")) + invalidateCachedTarget(reason: "unit_test") + XCTAssertTrue(repeatedLogSuppressor.logIfChanged(key: "guard", fact: "app", line: "rebind")) + repeatedLogSuppressor.reset() + } +} +#endif diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift index 15af0ebee6..d9bab438a0 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift @@ -139,22 +139,21 @@ extension RunnerTests { fallbackAttempted: Bool ) { #if os(iOS) - guard let context else { - NSLog( - "AGENT_DEVICE_RUNNER_SYNTHESIZED_GESTURE_POLICY kind=%@ context=unavailable fallbackAttempted=%@", - kind.rawValue, - fallbackAttempted.description - ) - return + let line: String + if let context { + line = + "AGENT_DEVICE_RUNNER_SYNTHESIZED_GESTURE_POLICY kind=\(kind.rawValue) axHealth=\(context.accessibilityHealth.rawValue) frameSource=window keyboardPolicy=\(context.keyboardPolicy.rawValue) fallbackPolicy=\(context.fallbackPolicy.rawValue) fallbackAllowed=\(context.allowsXCTestCoordinateFallback) fallbackAttempted=\(fallbackAttempted)" + } else { + line = + "AGENT_DEVICE_RUNNER_SYNTHESIZED_GESTURE_POLICY kind=\(kind.rawValue) context=unavailable fallbackAttempted=\(fallbackAttempted)" } - NSLog( - "AGENT_DEVICE_RUNNER_SYNTHESIZED_GESTURE_POLICY kind=%@ axHealth=%@ frameSource=window keyboardPolicy=%@ fallbackPolicy=%@ fallbackAllowed=%@ fallbackAttempted=%@", - kind.rawValue, - context.accessibilityHealth.rawValue, - context.keyboardPolicy.rawValue, - context.fallbackPolicy.rawValue, - context.allowsXCTestCoordinateFallback.description, - fallbackAttempted.description + // The decision is the fact: the same policy for a gesture kind on every tap of a session is + // one line, a changed policy (AX health, keyboard, fallback) is a new one. Keyed per kind so + // alternating taps and scrolls do not restate each other. + repeatedLogSuppressor.logIfChanged( + key: "synthesized_gesture_policy:\(kind.rawValue)", + fact: line, + line: line ) #endif } diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift index 594f4e71a4..8af6259a53 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift @@ -76,6 +76,11 @@ final class RunnerTests: XCTestCase { let minRecordingFps = 1 let maxRecordingFps = 120 var needsPostSnapshotInteractionDelay = false + // Per-command markers that restate the same fact on every command (the fast app guard, the + // synthesized gesture policy) write only when that fact changes: two days of one e2e suite + // produced 35k identical FAST_APP_GUARD lines and 5.6k policy lines in a 374k-line runner.log. + // Reset with the cached target so a rebind states the fact once more. + let repeatedLogSuppressor = RepeatedLogSuppressor() /// When the first interaction after an activation may run, on the monotonic uptime clock. /// The guarantee is a minimum gap *since the activation*, not a pause at the interaction: /// a caller that already spent that gap elsewhere (an agent's round trip is 190-260 ms) From d557ea580da2a8cd7369d2431525415f96e974ec Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Oskar=20Kwas=CC=81niewski?= Date: Wed, 23 Sep 2026 14:29:09 +0200 Subject: [PATCH 2/4] docs(ios-runner): describe the log suppressor without suite-specific numbers --- .../AgentDeviceRunnerUITests/RunnerTests.swift | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift index 8af6259a53..656abfc01a 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift @@ -77,9 +77,9 @@ final class RunnerTests: XCTestCase { let maxRecordingFps = 120 var needsPostSnapshotInteractionDelay = false // Per-command markers that restate the same fact on every command (the fast app guard, the - // synthesized gesture policy) write only when that fact changes: two days of one e2e suite - // produced 35k identical FAST_APP_GUARD lines and 5.6k policy lines in a 374k-line runner.log. - // Reset with the cached target so a rebind states the fact once more. + // synthesized gesture policy) write only when that fact changes; otherwise a long session fills + // runner.log with one identical line per command. Reset with the cached target so a rebind + // states the fact once more. let repeatedLogSuppressor = RepeatedLogSuppressor() /// When the first interaction after an activation may run, on the monotonic uptime clock. /// The guarantee is a minimum gap *since the activation*, not a pause at the interaction: From a2f0a5cd98800ca65d734cbd94790bdaf1edd6f5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Oskar=20Kwas=CC=81niewski?= Date: Wed, 23 Sep 2026 14:45:13 +0200 Subject: [PATCH 3/4] refactor(ios-runner): two last-written fields replace the log suppressor Review follow-ups on the deduped per-command markers: - the RepeatedLogSuppressor class (string keys, lock, autoclosure) is gone; the two markers keep a last-written line beside the other target-bound state, the policy one keyed by SynthesizedGesturePolicyKind - the target-reset chorus copied at three sites (host activate, invalidate, activate target) is one resetTargetBoundState(), so a rebind through any of them restates both markers, as the comment already claimed - the guard line drops command=, which a deduped line would misreport; the command is on the adjacent COMMAND_ACCEPTED line - the policy line is built by one pure function with its own unit test --- .../RunnerTests+Lifecycle.swift | 85 ++++++------------- ...RunnerTests+SynthesizedGesturePolicy.swift | 57 +++++++++---- .../RunnerTests.swift | 11 +-- 3 files changed, 73 insertions(+), 80 deletions(-) diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift index a08991b121..a5ab8dcdf6 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift @@ -166,8 +166,17 @@ extension RunnerTests { currentApp = app currentBundleId = nil currentAppProcessIdentifier = nil + resetTargetBoundState() + } + + /// State that belongs to the currently bound target and must not outlive it: the text-entry tap + /// witness, the fresh-process snapshot warmup exemption, and the last-written per-command log + /// markers. Every site that binds, rebinds, or drops the target runs this. + func resetTargetBoundState() { clearRememberedTextEntryTap() snapshotXCTestPenaltyWarmupExemptionPending = false + lastLoggedFastAppGuardLine = nil + lastLoggedGesturePolicyLines.removeAll() } func invalidateCachedTarget(reason: String) { @@ -177,9 +186,7 @@ extension RunnerTests { currentApp = nil currentBundleId = nil currentAppProcessIdentifier = nil - clearRememberedTextEntryTap() - snapshotXCTestPenaltyWarmupExemptionPending = false - repeatedLogSuppressor.reset() + resetTargetBoundState() } func resetTargetAfterExternalRelaunch() -> Response { @@ -254,12 +261,13 @@ extension RunnerTests { return false } guard activeApp.state == .runningForeground else { return false } - let state = activeApp.state.rawValue - repeatedLogSuppressor.logIfChanged( - key: "fast_app_guard", - fact: "\(requestedBundleId) \(state)", - line: "AGENT_DEVICE_RUNNER_FAST_APP_GUARD command=\(String(describing: command)) bundle=\(requestedBundleId) state=\(state)" - ) + // The command is on the adjacent COMMAND_ACCEPTED line; repeating it here would make a deduped + // marker read as if only that command ever passed the guard. + let line = "AGENT_DEVICE_RUNNER_FAST_APP_GUARD bundle=\(requestedBundleId) state=\(activeApp.state.rawValue)" + if lastLoggedFastAppGuardLine != line { + lastLoggedFastAppGuardLine = line + NSLog("%@", line) + } return true } @@ -313,8 +321,7 @@ extension RunnerTests { currentApp = target currentBundleId = bundleId currentAppProcessIdentifier = Self.processIdentifier(of: target) - clearRememberedTextEntryTap() - snapshotXCTestPenaltyWarmupExemptionPending = false + resetTargetBoundState() beginFirstInteractionStabilization() return target } @@ -481,57 +488,15 @@ extension RunnerTests { } } -/// Writes a repeating log fact only when it changes. `logIfChanged` compares `fact` with the last -/// one written under `key` and, on a change, writes `line` (which may carry per-command detail the -/// comparison ignores). `reset` forgets every key so the next call writes again. -final class RepeatedLogSuppressor { - private let lock = NSLock() - private var lastFacts: [String: String] = [:] - - @discardableResult - func logIfChanged(key: String, fact: String, line: @autoclosure () -> String) -> Bool { - lock.lock() - let changed = lastFacts[key] != fact - if changed { - lastFacts[key] = fact - } - lock.unlock() - if changed { - NSLog("%@", line()) - } - return changed - } - - func reset() { - lock.lock() - lastFacts.removeAll() - lock.unlock() - } -} - #if AGENT_DEVICE_RUNNER_UNIT_TESTS extension RunnerTests { - func testRepeatedLogSuppressorWritesOnlyWhenTheFactChangesUntilReset() { - let suppressor = RepeatedLogSuppressor() - XCTAssertTrue(suppressor.logIfChanged(key: "guard", fact: "app 4", line: "guard first")) - XCTAssertFalse(suppressor.logIfChanged(key: "guard", fact: "app 4", line: "guard repeat")) - XCTAssertFalse(suppressor.logIfChanged(key: "guard", fact: "app 4", line: "guard repeat")) - XCTAssertTrue(suppressor.logIfChanged(key: "guard", fact: "app 2", line: "guard changed")) - XCTAssertTrue(suppressor.logIfChanged(key: "policy", fact: "app 2", line: "other key")) - suppressor.reset() - XCTAssertTrue( - suppressor.logIfChanged(key: "guard", fact: "app 2", line: "guard after reset"), - "a reset must restate the fact once more" - ) - } - - func testInvalidatingTheCachedTargetResetsTheRepeatedLogSuppressor() { - repeatedLogSuppressor.reset() - XCTAssertTrue(repeatedLogSuppressor.logIfChanged(key: "guard", fact: "app", line: "first")) - XCTAssertFalse(repeatedLogSuppressor.logIfChanged(key: "guard", fact: "app", line: "repeat")) - invalidateCachedTarget(reason: "unit_test") - XCTAssertTrue(repeatedLogSuppressor.logIfChanged(key: "guard", fact: "app", line: "rebind")) - repeatedLogSuppressor.reset() + func testResettingTargetBoundStateForgetsTheLastWrittenMarkers() { + defer { invalidateCachedTarget(reason: "unit_test_cleanup") } + lastLoggedFastAppGuardLine = "AGENT_DEVICE_RUNNER_FAST_APP_GUARD bundle=app state=4" + lastLoggedGesturePolicyLines[.scroll] = "AGENT_DEVICE_RUNNER_SYNTHESIZED_GESTURE_POLICY kind=scroll" + resetTargetBoundState() + XCTAssertNil(lastLoggedFastAppGuardLine, "a rebind must state the guard once more") + XCTAssertTrue(lastLoggedGesturePolicyLines.isEmpty, "a rebind must state the policy once more") } } #endif diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift index d9bab438a0..3f2f8d90a4 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift @@ -139,25 +139,52 @@ extension RunnerTests { fallbackAttempted: Bool ) { #if os(iOS) - let line: String - if let context { - line = - "AGENT_DEVICE_RUNNER_SYNTHESIZED_GESTURE_POLICY kind=\(kind.rawValue) axHealth=\(context.accessibilityHealth.rawValue) frameSource=window keyboardPolicy=\(context.keyboardPolicy.rawValue) fallbackPolicy=\(context.fallbackPolicy.rawValue) fallbackAllowed=\(context.allowsXCTestCoordinateFallback) fallbackAttempted=\(fallbackAttempted)" - } else { - line = - "AGENT_DEVICE_RUNNER_SYNTHESIZED_GESTURE_POLICY kind=\(kind.rawValue) context=unavailable fallbackAttempted=\(fallbackAttempted)" - } - // The decision is the fact: the same policy for a gesture kind on every tap of a session is - // one line, a changed policy (AX health, keyboard, fallback) is a new one. Keyed per kind so - // alternating taps and scrolls do not restate each other. - repeatedLogSuppressor.logIfChanged( - key: "synthesized_gesture_policy:\(kind.rawValue)", - fact: line, - line: line + let line = Self.synthesizedGesturePolicyLine( + kind: kind, + context: context, + fallbackAttempted: fallbackAttempted ) + // The same decision for the same gesture kind on every command is one line; a changed policy + // (AX health, keyboard, fallback) is a new one. + if lastLoggedGesturePolicyLines[kind] != line { + lastLoggedGesturePolicyLines[kind] = line + NSLog("%@", line) + } #endif } + + static func synthesizedGesturePolicyLine( + kind: SynthesizedGesturePolicyKind, + context: SynthesizedCoordinateContext?, + fallbackAttempted: Bool + ) -> String { + guard let context else { + return "AGENT_DEVICE_RUNNER_SYNTHESIZED_GESTURE_POLICY kind=\(kind.rawValue)" + + " context=unavailable fallbackAttempted=\(fallbackAttempted)" + } + return "AGENT_DEVICE_RUNNER_SYNTHESIZED_GESTURE_POLICY kind=\(kind.rawValue)" + + " axHealth=\(context.accessibilityHealth.rawValue) frameSource=window" + + " keyboardPolicy=\(context.keyboardPolicy.rawValue)" + + " fallbackPolicy=\(context.fallbackPolicy.rawValue)" + + " fallbackAllowed=\(context.allowsXCTestCoordinateFallback)" + + " fallbackAttempted=\(fallbackAttempted)" + } +} + +#if AGENT_DEVICE_RUNNER_UNIT_TESTS && os(iOS) +extension RunnerTests { + func testSynthesizedGesturePolicyMarkerWritesOncePerKindUntilTheDecisionChanges() { + defer { invalidateCachedTarget(reason: "unit_test_cleanup") } + logSynthesizedGesturePolicyDecision(kind: .coordinateTap, context: nil, fallbackAttempted: false) + logSynthesizedGesturePolicyDecision(kind: .coordinateTap, context: nil, fallbackAttempted: false) + logSynthesizedGesturePolicyDecision(kind: .scroll, context: nil, fallbackAttempted: false) + XCTAssertEqual(lastLoggedGesturePolicyLines.count, 2, "one remembered line per gesture kind") + let before = lastLoggedGesturePolicyLines[.coordinateTap] + logSynthesizedGesturePolicyDecision(kind: .coordinateTap, context: nil, fallbackAttempted: true) + XCTAssertNotEqual(lastLoggedGesturePolicyLines[.coordinateTap], before, "a changed decision is a new line") + } } +#endif #if AGENT_DEVICE_RUNNER_UNIT_TESTS extension RunnerTests { diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift index 656abfc01a..9dd3e9b666 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift @@ -76,11 +76,12 @@ final class RunnerTests: XCTestCase { let minRecordingFps = 1 let maxRecordingFps = 120 var needsPostSnapshotInteractionDelay = false - // Per-command markers that restate the same fact on every command (the fast app guard, the - // synthesized gesture policy) write only when that fact changes; otherwise a long session fills - // runner.log with one identical line per command. Reset with the cached target so a rebind - // states the fact once more. - let repeatedLogSuppressor = RepeatedLogSuppressor() + // Per-command markers that restate a fact of the bound target (the fast app guard, the + // synthesized gesture policy per gesture kind) write only when that fact changes; otherwise a + // long session fills runner.log with one identical line per command. Cleared with the rest of the + // target-bound state so a rebind states the fact once more. + var lastLoggedFastAppGuardLine: String? + var lastLoggedGesturePolicyLines: [SynthesizedGesturePolicyKind: String] = [:] /// When the first interaction after an activation may run, on the monotonic uptime clock. /// The guarantee is a minimum gap *since the activation*, not a pause at the interaction: /// a caller that already spent that gap elsewhere (an agent's round trip is 190-260 ms) From f18238c7121e648150351ffff84b55892407928f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Pierzcha=C5=82a?= Date: Wed, 23 Sep 2026 18:10:17 +0200 Subject: [PATCH 4/4] fix(ios-runner): reset log markers on a process rebind and count what they write refreshCachedTargetIfProcessChanged rebinds the target but only cleared the text-entry tap, so the new process could lose its guard or policy line. It now runs resetTargetBoundState. Markers write through runnerMarkerWriter so tests count emitted lines, and the fast app guard dedup is testable on its own. Drops the unused command parameter of canUseFastForegroundAppGuard. Co-Authored-By: Claude --- .../RunnerTests+CommandExecution.swift | 6 ++-- .../RunnerTests+Lifecycle.swift | 32 +++++++++++++++---- ...RunnerTests+SynthesizedGesturePolicy.swift | 18 ++++++++--- .../RunnerTests.swift | 1 + 4 files changed, 42 insertions(+), 15 deletions(-) diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+CommandExecution.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+CommandExecution.swift index e23dd7952f..4aa3566778 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+CommandExecution.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+CommandExecution.swift @@ -1568,8 +1568,7 @@ extension RunnerTests { let skipExistenceWait = canUseFastForegroundAppGuard( activeApp: activeApp, - requestedBundleId: requestedBundleId, - command: command.command + requestedBundleId: requestedBundleId ) if !skipExistenceWait && !activeApp.waitForExistence(timeout: appExistenceTimeout) { if let bundleId = requestedBundleId { @@ -1591,8 +1590,7 @@ extension RunnerTests { } let skipInteractionExistenceWait = canUseFastForegroundAppGuard( activeApp: activeApp, - requestedBundleId: requestedBundleId, - command: command.command + requestedBundleId: requestedBundleId ) if !skipInteractionExistenceWait && !activeApp.waitForExistence(timeout: 2) { if let bundleId = requestedBundleId { diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift index a5ab8dcdf6..c892d2dc0b 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+Lifecycle.swift @@ -216,7 +216,7 @@ extension RunnerTests { ) currentApp = candidate currentAppProcessIdentifier = observedProcessIdentifier - clearRememberedTextEntryTap() + resetTargetBoundState() clearSnapshotXCTestChannelPenalty(reason: "target_process_changed") clearPrivateAXAcceptedDepth(reason: "target_process_changed") snapshotXCTestPenaltyWarmupExemptionPending = true @@ -254,21 +254,24 @@ extension RunnerTests { func canUseFastForegroundAppGuard( activeApp: XCUIApplication, - requestedBundleId: String?, - command: CommandType + requestedBundleId: String? ) -> Bool { guard let requestedBundleId, currentBundleId == requestedBundleId, currentApp != nil else { return false } guard activeApp.state == .runningForeground else { return false } + writeFastAppGuardMarker(bundleId: requestedBundleId, state: activeApp.state) + return true + } + + func writeFastAppGuardMarker(bundleId: String, state: XCUIApplication.State) { // The command is on the adjacent COMMAND_ACCEPTED line; repeating it here would make a deduped // marker read as if only that command ever passed the guard. - let line = "AGENT_DEVICE_RUNNER_FAST_APP_GUARD bundle=\(requestedBundleId) state=\(activeApp.state.rawValue)" + let line = "AGENT_DEVICE_RUNNER_FAST_APP_GUARD bundle=\(bundleId) state=\(state.rawValue)" if lastLoggedFastAppGuardLine != line { lastLoggedFastAppGuardLine = line - NSLog("%@", line) + runnerMarkerWriter(line) } - return true } /// The pid of the one other application holding an active accessibility session, or nil unless @@ -498,5 +501,22 @@ extension RunnerTests { XCTAssertNil(lastLoggedFastAppGuardLine, "a rebind must state the guard once more") XCTAssertTrue(lastLoggedGesturePolicyLines.isEmpty, "a rebind must state the policy once more") } + + func testFastAppGuardMarkerWritesOnceUntilTheFactChanges() { + var written: [String] = [] + runnerMarkerWriter = { written.append($0) } + defer { + runnerMarkerWriter = { NSLog("%@", $0) } + invalidateCachedTarget(reason: "unit_test_cleanup") + } + writeFastAppGuardMarker(bundleId: "com.example.app", state: .runningForeground) + writeFastAppGuardMarker(bundleId: "com.example.app", state: .runningForeground) + XCTAssertEqual(written.count, 1, "a repeated fact writes no second line") + writeFastAppGuardMarker(bundleId: "com.example.other", state: .runningForeground) + XCTAssertEqual(written.count, 2, "a changed fact writes a new line") + resetTargetBoundState() + writeFastAppGuardMarker(bundleId: "com.example.other", state: .runningForeground) + XCTAssertEqual(written.count, 3, "a rebind states the same fact once more") + } } #endif diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift index 3f2f8d90a4..a74bcd7908 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+SynthesizedGesturePolicy.swift @@ -148,7 +148,7 @@ extension RunnerTests { // (AX health, keyboard, fallback) is a new one. if lastLoggedGesturePolicyLines[kind] != line { lastLoggedGesturePolicyLines[kind] = line - NSLog("%@", line) + runnerMarkerWriter(line) } #endif } @@ -174,14 +174,22 @@ extension RunnerTests { #if AGENT_DEVICE_RUNNER_UNIT_TESTS && os(iOS) extension RunnerTests { func testSynthesizedGesturePolicyMarkerWritesOncePerKindUntilTheDecisionChanges() { - defer { invalidateCachedTarget(reason: "unit_test_cleanup") } + var written: [String] = [] + runnerMarkerWriter = { written.append($0) } + defer { + runnerMarkerWriter = { NSLog("%@", $0) } + invalidateCachedTarget(reason: "unit_test_cleanup") + } logSynthesizedGesturePolicyDecision(kind: .coordinateTap, context: nil, fallbackAttempted: false) logSynthesizedGesturePolicyDecision(kind: .coordinateTap, context: nil, fallbackAttempted: false) + XCTAssertEqual(written.count, 1, "a repeated decision writes no second line") logSynthesizedGesturePolicyDecision(kind: .scroll, context: nil, fallbackAttempted: false) - XCTAssertEqual(lastLoggedGesturePolicyLines.count, 2, "one remembered line per gesture kind") - let before = lastLoggedGesturePolicyLines[.coordinateTap] + XCTAssertEqual(written.count, 2, "each gesture kind states its own decision") + logSynthesizedGesturePolicyDecision(kind: .coordinateTap, context: nil, fallbackAttempted: true) + XCTAssertEqual(written.count, 3, "a changed decision writes a new line") + resetTargetBoundState() logSynthesizedGesturePolicyDecision(kind: .coordinateTap, context: nil, fallbackAttempted: true) - XCTAssertNotEqual(lastLoggedGesturePolicyLines[.coordinateTap], before, "a changed decision is a new line") + XCTAssertEqual(written.count, 4, "a rebind states the same decision once more") } } #endif diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift index 9dd3e9b666..afee02d03b 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift @@ -82,6 +82,7 @@ final class RunnerTests: XCTestCase { // target-bound state so a rebind states the fact once more. var lastLoggedFastAppGuardLine: String? var lastLoggedGesturePolicyLines: [SynthesizedGesturePolicyKind: String] = [:] + var runnerMarkerWriter: (String) -> Void = { NSLog("%@", $0) } /// When the first interaction after an activation may run, on the monotonic uptime clock. /// The guarantee is a minimum gap *since the activation*, not a pause at the interaction: /// a caller that already spent that gap elsewhere (an agent's round trip is 190-260 ms)