diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+CommandDispatch.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+CommandDispatch.swift index 7b75a4e23f..f58f712686 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+CommandDispatch.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+CommandDispatch.swift @@ -358,7 +358,7 @@ extension RunnerTests { outputPath: resolvedOutPath, fps: command.fps.map { Int32($0) } ) - try recorder.start { [weak self] in + try startRecording(recorder) { [weak self] in guard let self else { return .failure(.unresolvedScreen) } return self.captureRunnerFrameResult(app: activeApp) } diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+MainThreadWork.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+MainThreadWork.swift index d624b10ba6..267f2b0b61 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+MainThreadWork.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+MainThreadWork.swift @@ -12,7 +12,9 @@ import XCTest extension RunnerTests { /// Tracks one main-queue dispatch so the watchdog and the dispatched block can agree, under /// `mainThreadWorkLock`, on exactly one of: finished in time, or abandoned. - private final class MainThreadWorkState { + private final class MainThreadWorkState { + let completed = DispatchSemaphore(value: 0) + var result: Result? var finished = false var abandoned = false } @@ -62,24 +64,71 @@ extension RunnerTests { if Thread.isMainThread { return try work() } - var result: Result? - let semaphore = DispatchSemaphore(value: 0) - let workState = MainThreadWorkState() + mainThreadWorkLock.lock() + let state = enqueueMainThreadWorkLocked(operation, work) + mainThreadWorkLock.unlock() + return try awaitMainThreadWork( + state, + operation: operation, + timeout: timeout, + timeoutError: timeoutError, + onAbandoned: onAbandoned + ) + } + + /// Runs optional `work` like `runMainThreadWork`, but only while no other dispatched main-thread + /// work is in flight; otherwise it returns `nil` without dispatching. The check and the enqueue + /// happen under one hold of `mainThreadWorkLock`, the same lock every dispatch enqueues under, so + /// admitted work never waits in the main queue behind a command's hop. The in-flight count covers + /// abandoned work too: a block stays counted until it returns, and it marks itself abandoned in + /// the same window, so occupancy that outlived its slice is already declined here. + func runMainThreadWorkIfIdle( + _ operation: String, + timeout: TimeInterval, + timeoutError: @escaping () -> Error, + _ work: @escaping () throws -> T + ) throws -> T? { + if Thread.isMainThread { + return nil + } + mainThreadWorkLock.lock() + guard mainThreadWorkInFlightCount == 0 else { + mainThreadWorkLock.unlock() + return nil + } + let state = enqueueMainThreadWorkLocked(operation, work) + mainThreadWorkLock.unlock() + return try awaitMainThreadWork( + state, + operation: operation, + timeout: timeout, + timeoutError: timeoutError, + onAbandoned: nil + ) + } + + private func enqueueMainThreadWorkLocked( + _ operation: String, + _ work: @escaping () throws -> T + ) -> MainThreadWorkState { + let state = MainThreadWorkState() + mainThreadWorkInFlightCount += 1 DispatchQueue.main.async { do { - result = .success(try work()) + state.result = .success(try work()) } catch { - result = .failure(error) + state.result = .failure(error) } self.mainThreadWorkLock.lock() - let abandoned = workState.abandoned + self.mainThreadWorkInFlightCount -= 1 + let abandoned = state.abandoned if abandoned { self.abandonedMainThreadWorkCount -= 1 if self.abandonedMainThreadWorkCount == 0 { self.abandonedMainThreadWorkSince = nil } } else { - workState.finished = true + state.finished = true } let allDrained = abandoned && self.abandonedMainThreadWorkCount == 0 self.mainThreadWorkLock.unlock() @@ -89,14 +138,29 @@ extension RunnerTests { NSLog("AGENT_DEVICE_RUNNER_ABANDONED_WORK_DRAINED") } } - semaphore.signal() + state.completed.signal() } - let waitResult = semaphore.wait(timeout: .now() + timeout) + return state + } + + private func awaitMainThreadWork( + _ state: MainThreadWorkState, + operation: String, + timeout: TimeInterval, + timeoutError: @escaping () -> Error, + onAbandoned: (() -> Void)? + ) throws -> T { + let waitResult = state.completed.wait(timeout: .now() + timeout) if waitResult == .timedOut { + #if AGENT_DEVICE_RUNNER_UNIT_TESTS + mainThreadWorkTimedOutForTesting?() + #endif + // Work that finished before the lock was taken already stored its result: it is answered + // like work that finished in time, so an action that happened is never reported as a timeout. mainThreadWorkLock.lock() - let abandoned = !workState.finished + let abandoned = !state.finished if abandoned { - workState.abandoned = true + state.abandoned = true abandonedMainThreadWorkCount += 1 if abandonedMainThreadWorkSince == nil { abandonedMainThreadWorkSince = Date() @@ -110,10 +174,10 @@ extension RunnerTests { timeout ) onAbandoned?() + throw timeoutError() } - throw timeoutError() } - switch result { + switch state.result { case .success(let value): return value case .failure(let error): diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+ScreenRecorder.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+ScreenRecorder.swift index a7e13154fe..c70b0e3228 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+ScreenRecorder.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests+ScreenRecorder.swift @@ -24,14 +24,20 @@ extension RunnerTests { private var isStopping = false private var startedSession = false private var startError: Error? + #if AGENT_DEVICE_RUNNER_UNIT_TESTS + private var appendedFramesForTesting: [RunnerImage] = [] + #endif init(outputPath: String, fps: Int32?) { self.outputPath = outputPath self.fps = fps } + /// `bootstrap` must produce the frame that sizes the writer and runs on the caller's thread. + /// `frame` answers each tick with an image, or `nil` to drop the tick. func start( - capture: @escaping () -> Result + bootstrap: @escaping () -> Result, + frame: @escaping () -> RunnerImage? ) throws { let url = URL(fileURLWithPath: outputPath) let directory = url.deletingLastPathComponent() @@ -49,7 +55,7 @@ extension RunnerTests { var lastFailure: RunnerAppScreenCaptureFailure? let bootstrapDeadline = Date().addingTimeInterval(2.0) while Date() < bootstrapDeadline { - switch capture() { + switch bootstrap() { case .success(let captured): bootstrapImage = captured.image dimensions = CGSize(width: captured.pixelWidth, height: captured.pixelHeight) @@ -129,8 +135,8 @@ extension RunnerTests { timer.setEventHandler { [weak self] in guard let self else { return } if self.shouldStop() { return } - guard case .success(let captured) = capture() else { return } - self.append(image: captured.image) + guard let image = frame() else { return } + self.append(image: image) } self.timer = timer timer.resume() @@ -227,6 +233,9 @@ extension RunnerTests { return } lastTimestampValue = timestampValue + #if AGENT_DEVICE_RUNNER_UNIT_TESTS + appendedFramesForTesting.append(image) + #endif } private func timestampCandidateValue(for nowUptime: TimeInterval) -> Int64 { @@ -285,6 +294,27 @@ extension RunnerTests { } extension RunnerTests { + /// Starts `recorder` on the frames `capture` produces. The bootstrap frame is taken on the calling + /// thread, which is main for `record start`. Each later tick is optional work: it hops to main only + /// while no other main-thread work is in flight, so it never queues behind a command. + /// A capture still running after `recordingFrameCaptureTimeout` is abandoned and its frame dropped; + /// its late result is never returned. + func startRecording( + _ recorder: ScreenRecorder, + capture: @escaping () -> Result + ) throws { + try recorder.start(bootstrap: capture) { [weak self] in + guard let self else { return nil } + return try? self.runMainThreadWorkIfIdle( + "recording_frame", + timeout: self.recordingFrameCaptureTimeout, + timeoutError: self.mainThreadExecutionTimeoutError + ) { + try capture().get().image + } + } + } + /// The error a `record start` bootstrap raises when no initial frame arrived. On iOS the last capture /// refusal (if any) is the honest reason and travels as its own typed code; only when nothing /// refused — a macOS host capture, or a deadline that elapsed before any answer — does it fall back @@ -319,5 +349,11 @@ extension RunnerTests.ScreenRecorder { lastTimestampValue = allocatedTimestamp return allocatedTimestamp } + + func appendedFrameSnapshotForTesting() -> [RunnerImage] { + lock.lock() + defer { lock.unlock() } + return appendedFramesForTesting + } } #endif diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift index 19a55659bc..725261ff2a 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/RunnerTests.swift @@ -79,6 +79,10 @@ final class RunnerTests: XCTestCase { let xctestIdleKeepaliveInterval: TimeInterval = 60.0 let minRecordingFps = 1 let maxRecordingFps = 120 + // A recorder frame still capturing on main after this long is abandoned and dropped. It bounds a + // screenshot round trip, not the frame interval: a capture slower than the interval lowers the + // frame rate, and only a capture this slow counts as main-thread occupancy. + let recordingFrameCaptureTimeout: TimeInterval = 1 var needsPostSnapshotInteractionDelay = false // 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 @@ -106,6 +110,9 @@ final class RunnerTests: XCTestCase { // and post-capture bookkeeping stays off main (#1105/#1244). let mainThreadWorkLock = NSLock() var abandonedMainThreadWorkCount = 0 + // Dispatched main-queue work that has not finished yet, abandoned or not. Only optional work + // reads it, to stay off a main thread that commands are using; occupancy readers do not. + var mainThreadWorkInFlightCount = 0 var abandonedMainThreadWorkSince: Date? // Past this age the runner stops claiming "busy, retry soon" and reports itself wedged so // the daemon recycles it — the only cure once the main thread is stuck for good. @@ -201,6 +208,9 @@ final class RunnerTests: XCTestCase { var blockingSystemModalPresenceOverrideForTesting: Bool? var alertResolutionOverrideForTesting: ((Date) -> RunnerAlert?)? var alertButtonHittabilityProbeOverrideForTesting: ((Date) -> Bool)? + // Runs on the waiting thread after `runMainThreadWork`'s wait timed out and before it takes the + // lock that decides between finished and abandoned, so a test can finish the work in that window. + var mainThreadWorkTimedOutForTesting: (() -> Void)? #endif // Observability for the record(_:) suppression below: how many AX-broken-screen snapshot // issues this session muted, so wedge investigations see the volume without grepping logs. diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+MainThreadWorkTests.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+MainThreadWorkTests.swift index f98e37e7a8..3a292bff9e 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+MainThreadWorkTests.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+MainThreadWorkTests.swift @@ -89,5 +89,210 @@ extension RunnerTests { return XCTFail("expected the runner idle once the abandoned work drained") } } + + func testRunMainThreadWorkReturnsWorkThatFinishedAtTheTimeoutBoundary() { + let outcome = runMainThreadWorkFinishingAtTheTimeoutBoundary { 42 } + + XCTAssertNil(outcome.error, "work that finished before the lock must not read as a timeout") + XCTAssertEqual(outcome.value, 42) + XCTAssertEqual(outcome.abandonedCount, 0) + XCTAssertEqual(outcome.onAbandonedCalls, 0) + } + + func testRunMainThreadWorkRethrowsWorkThatFailedAtTheTimeoutBoundary() { + let outcome = runMainThreadWorkFinishingAtTheTimeoutBoundary { () throws -> Int in + throw NSError(domain: "agent-device.runner.tests", code: 7) + } + + XCTAssertNil(outcome.value) + XCTAssertEqual((outcome.error as NSError?)?.domain, "agent-device.runner.tests") + XCTAssertEqual((outcome.error as NSError?)?.code, 7) + XCTAssertEqual(outcome.abandonedCount, 0) + XCTAssertEqual(outcome.onAbandonedCalls, 0) + } + + func testRunMainThreadWorkIfIdleDeclinesWhileOtherWorkIsInFlight() { + final class Outcome { + var offeredWhileInFlight = false + var whileInFlight: Bool? + var ranWhileInFlight = false + var whenIdle: Bool? + var error: Error? + } + let outcome = Outcome() + let releaseCommand = DispatchSemaphore(value: 0) + let commandEntered = DispatchSemaphore(value: 0) + let finished = expectation(description: "optional work was offered during and after the command") + + DispatchQueue(label: "agent-device.runner.tests.in-flight-command").async { + _ = try? self.runMainThreadWork( + "command_execution", + timeout: 5, + timeoutError: self.mainThreadExecutionTimeoutError + ) { + commandEntered.signal() + _ = releaseCommand.wait(timeout: .now() + 3) + } + } + DispatchQueue(label: "agent-device.runner.tests.optional-work").async { + defer { finished.fulfill() } + guard commandEntered.wait(timeout: .now() + 3) == .success else { return } + do { + outcome.whileInFlight = try self.runMainThreadWorkIfIdle( + "recording_frame", + timeout: 5, + timeoutError: self.mainThreadExecutionTimeoutError + ) { () -> Bool in + outcome.ranWhileInFlight = true + return true + } + outcome.offeredWhileInFlight = true + } catch { + outcome.error = error + } + releaseCommand.signal() + let idleDeadline = Date().addingTimeInterval(3) + while Date() < idleDeadline { + self.mainThreadWorkLock.lock() + let inFlight = self.mainThreadWorkInFlightCount + self.mainThreadWorkLock.unlock() + if inFlight == 0 { break } + usleep(2_000) + } + do { + outcome.whenIdle = try self.runMainThreadWorkIfIdle( + "recording_frame", + timeout: 5, + timeoutError: self.mainThreadExecutionTimeoutError + ) { + Thread.isMainThread + } + } catch { + outcome.error = error + } + } + + wait(for: [finished], timeout: 10) + XCTAssertNil(outcome.error) + XCTAssertTrue(outcome.offeredWhileInFlight) + XCTAssertNil(outcome.whileInFlight, "optional work declines while a hop is in flight") + XCTAssertFalse(outcome.ranWhileInFlight, "declined work is never dispatched") + XCTAssertEqual(outcome.whenIdle, true, "optional work runs on main once main is idle") + XCTAssertFalse(hasAbandonedMainThreadWork()) + } + + func testRunMainThreadWorkIfIdleDeclinesAbandonedWorkUntilItDrains() { + final class Outcome { + var abandonedCount = 0 + var inFlightCount = 0 + var offeredWhileAbandoned = false + var whileAbandoned: Bool? + var ranWhileAbandoned = false + var afterDrain: Bool? + var error: Error? + } + let outcome = Outcome() + let releaseWork = DispatchSemaphore(value: 0) + let finished = expectation(description: "optional work was offered while abandoned and after drain") + + DispatchQueue(label: "agent-device.runner.tests.abandoned-then-drained").async { + defer { finished.fulfill() } + _ = try? self.runMainThreadWork( + "command_execution", + timeout: 0, + timeoutError: self.mainThreadExecutionTimeoutError + ) { + _ = releaseWork.wait(timeout: .now() + 3) + } + self.mainThreadWorkLock.lock() + outcome.abandonedCount = self.abandonedMainThreadWorkCount + outcome.inFlightCount = self.mainThreadWorkInFlightCount + self.mainThreadWorkLock.unlock() + do { + outcome.whileAbandoned = try self.runMainThreadWorkIfIdle( + "recording_frame", + timeout: 5, + timeoutError: self.mainThreadExecutionTimeoutError + ) { () -> Bool in + outcome.ranWhileAbandoned = true + return true + } + outcome.offeredWhileAbandoned = true + } catch { + outcome.error = error + } + releaseWork.signal() + let drainDeadline = Date().addingTimeInterval(3) + while self.hasAbandonedMainThreadWork(), Date() < drainDeadline { + usleep(2_000) + } + do { + outcome.afterDrain = try self.runMainThreadWorkIfIdle( + "recording_frame", + timeout: 5, + timeoutError: self.mainThreadExecutionTimeoutError + ) { + Thread.isMainThread + } + } catch { + outcome.error = error + } + } + + wait(for: [finished], timeout: 10) + XCTAssertNil(outcome.error) + XCTAssertEqual(outcome.abandonedCount, 1) + XCTAssertEqual(outcome.inFlightCount, 1, "abandoned work stays counted in flight until it returns") + XCTAssertTrue(outcome.offeredWhileAbandoned) + XCTAssertNil(outcome.whileAbandoned, "optional work declines while abandoned work holds main") + XCTAssertFalse(outcome.ranWhileAbandoned, "declined work is never dispatched") + XCTAssertEqual(outcome.afterDrain, true, "optional work runs on main once abandoned work drained") + XCTAssertFalse(hasAbandonedMainThreadWork()) + } + + private final class BoundaryOutcome { + var value: Int? + var error: Error? + var abandonedCount: Int? + var onAbandonedCalls = 0 + } + + /// Times the wait out immediately, then lets the work finish before the watchdog takes the lock: + /// the seam releases the blocked work and waits for the serial main queue to run past it. + private func runMainThreadWorkFinishingAtTheTimeoutBoundary( + _ produce: @escaping () throws -> Int + ) -> BoundaryOutcome { + let outcome = BoundaryOutcome() + let releaseWork = DispatchSemaphore(value: 0) + let finished = expectation(description: "off-main caller finished") + mainThreadWorkTimedOutForTesting = { + releaseWork.signal() + DispatchQueue.main.sync {} + } + defer { mainThreadWorkTimedOutForTesting = nil } + + DispatchQueue(label: "agent-device.runner.tests.timeout-boundary").async { + do { + outcome.value = try self.runMainThreadWork( + "command_execution", + timeout: 0, + timeoutError: self.mainThreadExecutionTimeoutError, + onAbandoned: { outcome.onAbandonedCalls += 1 } + ) { + _ = releaseWork.wait(timeout: .now() + 2) + return try produce() + } + } catch { + outcome.error = error + } + self.mainThreadWorkLock.lock() + outcome.abandonedCount = self.abandonedMainThreadWorkCount + self.mainThreadWorkLock.unlock() + finished.fulfill() + } + + wait(for: [finished], timeout: 3) + return outcome + } } #endif diff --git a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+RecordingTests.swift b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+RecordingTests.swift index ce8bd2c2c5..0c97926342 100644 --- a/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+RecordingTests.swift +++ b/apple/runner/AgentDeviceRunner/AgentDeviceRunnerUITests/UnitTests/RunnerTests+RecordingTests.swift @@ -1,4 +1,9 @@ import XCTest +#if canImport(UIKit) +import UIKit +#elseif canImport(AppKit) +import AppKit +#endif extension RunnerTests { #if AGENT_DEVICE_RUNNER_UNIT_TESTS @@ -76,10 +81,13 @@ extension RunnerTests { var captureCalls = 0 var thrown: Error? XCTAssertThrowsError( - try recorder.start(capture: { - captureCalls += 1 - return .failure(.unresolvedWindow) - }) + try recorder.start( + bootstrap: { + captureCalls += 1 + return .failure(.unresolvedWindow) + }, + frame: { nil } + ) ) { error in thrown = error XCTAssertEqual( @@ -96,3 +104,425 @@ extension RunnerTests { } } #endif + +#if AGENT_DEVICE_RUNNER_UNIT_TESTS +/// Frames for a recording test. Every capture draws a new image, so an appended frame is identified +/// by instance, and holds the calling thread for `captureDelay` like a screenshot round trip. An +/// armed wedge makes the next capture block the main thread until released, and remembers the image +/// that capture will hand back late. +private final class RecordingFrameSource { + static let side = 128 + private let captureDelay: TimeInterval + private let lock = NSLock() + private var wedgeArmed = false + private var wedgedImage: RunnerImage? + let wedgeEntered = DispatchSemaphore(value: 0) + let releaseWedge = DispatchSemaphore(value: 0) + + init(captureDelay: TimeInterval = 0) { + self.captureDelay = captureDelay + } + + var lateImage: RunnerImage? { + lock.lock() + defer { lock.unlock() } + return wedgedImage + } + + func armWedge() { + lock.lock() + wedgeArmed = true + lock.unlock() + } + + func capture() -> Result { + if captureDelay > 0 { + Thread.sleep(forTimeInterval: captureDelay) + } + let image = Self.makeImage() + lock.lock() + let wedge = wedgeArmed + wedgeArmed = false + if wedge { + wedgedImage = image + } + lock.unlock() + if wedge { + wedgeEntered.signal() + _ = releaseWedge.wait(timeout: .now() + 10) + } + return .success( + CapturedAppScreen( + image: image, + displayID: 0, + pixelWidth: Self.side, + pixelHeight: Self.side, + pixelsPerPoint: 1 + ) + ) + } + + private static func makeImage() -> RunnerImage { + let context = CGContext( + data: nil, + width: side, + height: side, + bitsPerComponent: 8, + bytesPerRow: 0, + space: CGColorSpaceCreateDeviceRGB(), + bitmapInfo: CGImageAlphaInfo.noneSkipFirst.rawValue + )! + context.setFillColor(red: 0, green: 0.4, blue: 1, alpha: 1) + context.fill(CGRect(x: 0, y: 0, width: side, height: side)) + let cgImage = context.makeImage()! + #if canImport(UIKit) + return UIImage(cgImage: cgImage) + #else + return NSImage(cgImage: cgImage, size: NSSize(width: side, height: side)) + #endif + } +} + +/// Samples, off main, the readers that commands consult for main-thread occupancy until stopped. +private final class MainThreadOccupancySampler { + private let lock = NSLock() + private var stopped = false + private let done = DispatchSemaphore(value: 0) + private(set) var sampled = false + private(set) var sawBusy = false + private(set) var sawAbandoned = false + private(set) var sawXCTestTierSkip = false + + init(runner: RunnerTests) { + DispatchQueue(label: "agent-device.runner.tests.occupancy-sampler").async { + defer { self.done.signal() } + while !self.isStopped { + let busy = runner.currentMainThreadBusyState().reportsMainThreadBusy + let abandoned = runner.hasAbandonedMainThreadWork() + let tierSkip = runner.shouldSkipSnapshotBackendForAbandonedMainThreadWork(.recursiveTree) + self.lock.lock() + self.sampled = true + self.sawBusy = self.sawBusy || busy + self.sawAbandoned = self.sawAbandoned || abandoned + self.sawXCTestTierSkip = self.sawXCTestTierSkip || tierSkip + self.lock.unlock() + usleep(2_000) + } + } + } + + private var isStopped: Bool { + lock.lock() + defer { lock.unlock() } + return stopped + } + + func stop() { + lock.lock() + stopped = true + lock.unlock() + _ = done.wait(timeout: .now() + 2) + } +} + +extension RunnerTests { + func testRecordingFrameTimeoutDropsTheFrameAndResumesOnceTheWorkDrains() throws { + let source = RecordingFrameSource() + let recorder = ScreenRecorder(outputPath: recordingTestOutputPath(), fps: 10) + try startRecording(recorder, capture: source.capture) + defer { try? recorder.stop() } + XCTAssertTrue(pumpMainThread(until: { recorder.appendedFrameSnapshotForTesting().count >= 3 })) + + final class Observation { + var abandonedWhileWedged: Int? + var framesWhileWedged: Int? + var secondsToAbandon: TimeInterval? + } + let observation = Observation() + let observed = expectation(description: "the wedged frame was abandoned and released") + source.armWedge() + DispatchQueue(label: "agent-device.runner.tests.recording-timeout").async { + defer { + source.releaseWedge.signal() + observed.fulfill() + } + guard source.wedgeEntered.wait(timeout: .now() + 3) == .success else { return } + let enteredAt = Date() + guard self.waitOffMain(until: { self.hasAbandonedMainThreadWork() }) else { return } + observation.secondsToAbandon = Date().timeIntervalSince(enteredAt) + self.mainThreadWorkLock.lock() + observation.abandonedWhileWedged = self.abandonedMainThreadWorkCount + self.mainThreadWorkLock.unlock() + observation.framesWhileWedged = recorder.appendedFrameSnapshotForTesting().count + } + wait(for: [observed], timeout: 15) + + let framesAtRelease = observation.framesWhileWedged ?? 0 + XCTAssertTrue( + pumpMainThread(until: { + !self.hasAbandonedMainThreadWork() + && recorder.appendedFrameSnapshotForTesting().count >= framesAtRelease + 2 + }), + "the abandoned capture drains and the recorder appends frames again" + ) + XCTAssertEqual(observation.abandonedWhileWedged, 1, "the timed-out frame counts as abandoned") + XCTAssertLessThan( + observation.secondsToAbandon ?? .infinity, + recordingFrameCaptureTimeout + 1, + "a frame is bounded by the recording capture timeout, not the command watchdog" + ) + let lateImage = try XCTUnwrap(source.lateImage) + XCTAssertFalse( + recorder.appendedFrameSnapshotForTesting().contains { $0 === lateImage }, + "the late result of the abandoned capture is never appended" + ) + } + + func testRecordingPersistentWedgeKeepsOneCaptureQueuedOnMain() throws { + let source = RecordingFrameSource() + let recorder = ScreenRecorder(outputPath: recordingTestOutputPath(), fps: 20) + try startRecording(recorder, capture: source.capture) + defer { try? recorder.stop() } + XCTAssertTrue(pumpMainThread(until: { recorder.appendedFrameSnapshotForTesting().count >= 2 })) + + final class Observation { + var maxAbandoned = 0 + var maxInFlight = 0 + } + let observation = Observation() + let observed = expectation(description: "the wedge was held for many ticks") + source.armWedge() + DispatchQueue(label: "agent-device.runner.tests.recording-wedge").async { + defer { + source.releaseWedge.signal() + observed.fulfill() + } + guard source.wedgeEntered.wait(timeout: .now() + 3) == .success else { return } + let holdUntil = Date().addingTimeInterval(self.recordingFrameCaptureTimeout * 2.5) + while Date() < holdUntil { + self.mainThreadWorkLock.lock() + observation.maxAbandoned = max(observation.maxAbandoned, self.abandonedMainThreadWorkCount) + observation.maxInFlight = max(observation.maxInFlight, self.mainThreadWorkInFlightCount) + self.mainThreadWorkLock.unlock() + usleep(10_000) + } + } + wait(for: [observed], timeout: 15) + XCTAssertTrue(pumpMainThread(until: { !self.hasAbandonedMainThreadWork() })) + + XCTAssertEqual( + observation.maxAbandoned, + 1, + "every tick against a wedged main thread leaves one recorder capture pending, not one per tick" + ) + XCTAssertEqual(observation.maxInFlight, 1, "skipped ticks dispatch nothing to main") + } + + func testRecordingStopDuringATimedOutCaptureAppendsNoLateFrame() throws { + let source = RecordingFrameSource() + let recorder = ScreenRecorder(outputPath: recordingTestOutputPath(), fps: 10) + try startRecording(recorder, capture: source.capture) + XCTAssertTrue(pumpMainThread(until: { recorder.appendedFrameSnapshotForTesting().count >= 2 })) + + final class Observation { + var stopError: Error? + var stopReturnedWhileWedged = false + var framesAtStop: Int? + } + let observation = Observation() + let observed = expectation(description: "stop returned during the timed-out capture") + source.armWedge() + DispatchQueue(label: "agent-device.runner.tests.recording-stop").async { + defer { + source.releaseWedge.signal() + observed.fulfill() + } + guard source.wedgeEntered.wait(timeout: .now() + 3) == .success else { return } + guard self.waitOffMain(until: { self.hasAbandonedMainThreadWork() }) else { return } + do { + try recorder.stop() + } catch { + observation.stopError = error + } + observation.stopReturnedWhileWedged = self.hasAbandonedMainThreadWork() + observation.framesAtStop = recorder.appendedFrameSnapshotForTesting().count + } + wait(for: [observed], timeout: 20) + XCTAssertTrue(pumpMainThread(until: { !self.hasAbandonedMainThreadWork() })) + sleepFor(0.3) + + XCTAssertNil(observation.stopError) + XCTAssertTrue(observation.stopReturnedWhileWedged, "stop must not wait for the wedged capture") + XCTAssertEqual(recorder.appendedFrameSnapshotForTesting().count, observation.framesAtStop) + let lateImage = try XCTUnwrap(source.lateImage) + XCTAssertFalse(recorder.appendedFrameSnapshotForTesting().contains { $0 === lateImage }) + } + + func testRecordingStopRefusesAFrameThatFinishedAtTheTimeoutBoundary() throws { + let source = RecordingFrameSource() + let recorder = ScreenRecorder(outputPath: recordingTestOutputPath(), fps: 10) + try startRecording(recorder, capture: source.capture) + XCTAssertTrue(pumpMainThread(until: { recorder.appendedFrameSnapshotForTesting().count >= 2 })) + + final class Observation { + var framesAtStop: Int? + } + let observation = Observation() + mainThreadWorkTimedOutForTesting = { + try? recorder.stop() + observation.framesAtStop = recorder.appendedFrameSnapshotForTesting().count + source.releaseWedge.signal() + DispatchQueue.main.sync {} + } + defer { mainThreadWorkTimedOutForTesting = nil } + source.armWedge() + XCTAssertTrue(pumpMainThread(until: { observation.framesAtStop != nil })) + sleepFor(0.3) + + XCTAssertFalse(hasAbandonedMainThreadWork(), "a capture finished at the boundary is not abandoned") + let lateImage = try XCTUnwrap(source.lateImage) + XCTAssertFalse( + recorder.appendedFrameSnapshotForTesting().contains { $0 === lateImage }, + "a frame returned after stop is never appended" + ) + XCTAssertEqual(recorder.appendedFrameSnapshotForTesting().count, observation.framesAtStop) + } + + func testRecordingAfterAStopDuringATimedOutCaptureStartsClean() throws { + let first = RecordingFrameSource() + let firstRecorder = ScreenRecorder(outputPath: recordingTestOutputPath(), fps: 10) + try startRecording(firstRecorder, capture: first.capture) + XCTAssertTrue(pumpMainThread(until: { firstRecorder.appendedFrameSnapshotForTesting().count >= 2 })) + let stopped = expectation(description: "first recording stopped during its timed-out capture") + first.armWedge() + DispatchQueue(label: "agent-device.runner.tests.recording-restart").async { + defer { + first.releaseWedge.signal() + stopped.fulfill() + } + guard first.wedgeEntered.wait(timeout: .now() + 3) == .success else { return } + guard self.waitOffMain(until: { self.hasAbandonedMainThreadWork() }) else { return } + try? firstRecorder.stop() + } + wait(for: [stopped], timeout: 20) + XCTAssertTrue(pumpMainThread(until: { !self.hasAbandonedMainThreadWork() })) + let firstFrames = firstRecorder.appendedFrameSnapshotForTesting() + + let second = RecordingFrameSource() + let secondOutputPath = recordingTestOutputPath() + let secondRecorder = ScreenRecorder(outputPath: secondOutputPath, fps: 10) + try startRecording(secondRecorder, capture: second.capture) + XCTAssertTrue(pumpMainThread(until: { secondRecorder.appendedFrameSnapshotForTesting().count >= 3 })) + try secondRecorder.stop() + + let secondFrames = secondRecorder.appendedFrameSnapshotForTesting() + XCTAssertFalse(secondFrames.contains { frame in firstFrames.contains { $0 === frame } }) + let lateImage = try XCTUnwrap(first.lateImage) + XCTAssertFalse(secondFrames.contains { $0 === lateImage }) + XCTAssertFalse(firstRecorder.appendedFrameSnapshotForTesting().contains { $0 === lateImage }) + XCTAssertEqual(firstRecorder.appendedFrameSnapshotForTesting().count, firstFrames.count) + XCTAssertFalse(hasAbandonedMainThreadWork()) + let attributes = try FileManager.default.attributesOfItem(atPath: secondOutputPath) + XCTAssertGreaterThan((attributes[.size] as? NSNumber)?.intValue ?? 0, 0) + } + + func testRecordingFrameNeverQueuesBehindACommandsMainThreadWork() throws { + let source = RecordingFrameSource() + let recorder = ScreenRecorder(outputPath: recordingTestOutputPath(), fps: 60) + try startRecording(recorder, capture: source.capture) + defer { try? recorder.stop() } + XCTAssertTrue(pumpMainThread(until: { recorder.appendedFrameSnapshotForTesting().count >= 3 })) + + let occupancy = MainThreadOccupancySampler(runner: self) + let commandFinished = expectation(description: "the command's main-thread hops finished") + final class Outcome { + var error: Error? + } + let outcome = Outcome() + DispatchQueue(label: "agent-device.runner.tests.recording-command").async { + defer { + occupancy.stop() + commandFinished.fulfill() + } + do { + for _ in 0..<2 { + try self.runMainThreadWork( + "command_execution", + timeout: self.mainThreadExecutionTimeout, + timeoutError: self.mainThreadExecutionTimeoutError + ) { + Thread.sleep(forTimeInterval: self.recordingFrameCaptureTimeout + 0.3) + } + } + } catch { + outcome.error = error + } + } + wait(for: [commandFinished], timeout: 15) + let framesAfterCommand = recorder.appendedFrameSnapshotForTesting().count + XCTAssertTrue( + pumpMainThread(until: { recorder.appendedFrameSnapshotForTesting().count >= framesAfterCommand + 2 }), + "the recorder appends frames again once the command leaves main" + ) + + XCTAssertNil(outcome.error) + XCTAssertTrue(occupancy.sampled, "the sampler ran while the command held main") + XCTAssertFalse(occupancy.sawBusy, "a recorder tick must not make the busy gate or stamp see occupancy") + XCTAssertFalse(occupancy.sawAbandoned, "a recorder tick must not mark work abandoned") + XCTAssertFalse(occupancy.sawXCTestTierSkip, "a recorder tick must not skip XCTest snapshot tiers") + guard case .idle = currentMainThreadBusyState() else { + return XCTFail("expected the runner idle after the command") + } + } + + func testRecordingFrameSlowerThanTheIntervalStillYieldsFrames() throws { + let fps: Int32 = 20 + let interval = 1.0 / Double(fps) + let source = RecordingFrameSource(captureDelay: interval * 1.6) + let recorder = ScreenRecorder(outputPath: recordingTestOutputPath(), fps: fps) + try startRecording(recorder, capture: source.capture) + defer { try? recorder.stop() } + XCTAssertTrue(pumpMainThread(until: { recorder.appendedFrameSnapshotForTesting().count >= 2 })) + + let window: TimeInterval = 1.5 + let occupancy = MainThreadOccupancySampler(runner: self) + let framesBefore = recorder.appendedFrameSnapshotForTesting().count + sleepFor(window) + occupancy.stop() + let yielded = recorder.appendedFrameSnapshotForTesting().count - framesBefore + + XCTAssertGreaterThanOrEqual( + yielded, + Int(window / (interval * 1.6) / 3), + "a capture slower than the interval lowers the frame rate instead of dropping every frame" + ) + XCTAssertTrue(occupancy.sampled) + XCTAssertFalse(occupancy.sawAbandoned, "an ordinary slow capture is not abandoned work") + XCTAssertFalse(occupancy.sawBusy, "an ordinary slow capture keeps the runner available") + } + + private func recordingTestOutputPath() -> String { + (NSTemporaryDirectory() as NSString).appendingPathComponent( + "record-bounded-\(UUID().uuidString).mp4" + ) + } + + private func pumpMainThread(timeout: TimeInterval = 5, until condition: () -> Bool) -> Bool { + let deadline = Date().addingTimeInterval(timeout) + while !condition() { + if Date() >= deadline { return false } + sleepFor(0.01) + } + return true + } + + private func waitOffMain(timeout: TimeInterval = 5, until condition: () -> Bool) -> Bool { + let deadline = Date().addingTimeInterval(timeout) + while !condition() { + if Date() >= deadline { return false } + usleep(5_000) + } + return true + } +} +#endif diff --git a/website/docs/docs/commands.md b/website/docs/docs/commands.md index 516cc31350..b2a54416e2 100644 --- a/website/docs/docs/commands.md +++ b/website/docs/docs/commands.md @@ -1060,6 +1060,7 @@ agent-device record stop # Stop active recording - Burned-in touch overlays are exported only on macOS hosts, because the overlay pipeline depends on Swift + AVFoundation helpers. - On Linux or other non-macOS hosts, `record stop` still succeeds and returns the raw video plus telemetry sidecar, and includes `overlayWarning` when burn-in overlays were skipped. - On iOS simulators, a busy CoreSimulator host recording slot makes `record start` return non-retriable `DEVICE_IN_USE` with `details.reason: apple_simulator_recording_busy`. Use `record stop` in the session that owns the active recording. If a previous recorder died and no recording is active, ask the host operator to restart the CoreSimulator stream service before retrying. +- When the Apple runner records (`--fps` sets its frame rate), it captures a frame only while no command is using the runner's main thread; a frame that falls during that work is skipped instead of queued behind it. A capture slower than the frame interval lowers the frame rate, and a capture still running after one second is dropped. A busy app or a long command can therefore yield fewer frames than `--fps` requests. - Android uses `adb shell screenrecord`, which has a 180s platform limit. `record start` publishes a durable device manifest. Longer recordings are split into MP4 chunks while the daemon stays alive; after daemon restart, `record stop` recovers only manifest-owned chunks and warns when gesture overlay telemetry was lost. - Android `screenrecord` encodes a frame only when the screen changes, so a clip ends at the last frame the recorder encoded instead of at `record stop`: a window that ends on an unchanged screen yields a shorter video, while every on-screen change inside the window stays at its real offset in it. `record stop` reports `durationMs` as host wall clock from `record start` until the export finished, and when the video can be measured it also reports `capturedDurationMs` and warns with how much of the window that video covers. - Limrun iOS and Android direct sessions record the whole simulator or emulator screen through the provider's server-side recorder, so every `--scope` captures the same frame and `--fps` and `--hide-touches` are refused with `INVALID_ARGS` before any device work. `record stop` asks the instance to stop once and then downloads the served MP4 to the output path; that download is bounded to end inside the request window, so a slow or dropped transfer ends typed, leaves no file behind, and is retried by the next `record stop` from the same URL while the instance lives. Nothing survives a daemon restart: the recording is `unreattachable` and the instance disposes the file when the lease is released.