| 1 | @_spi(Fixtures) import CallsKit |
| 2 | import Foundation |
| 3 | |
| 4 | /// `CallsInterop --audio-start-stall`: the main thread is never held |
| 5 | /// longer than `limit` while the audio starts — Test audio before a call, |
| 6 | /// and a call's audio as a join starts it — on the real engine module. |
| 7 | /// |
| 8 | /// 0.3.8 held it for a pause and then a beachball (Paul's AirPods, |
| 9 | /// 2026-09-27): building the factory, applying the loopback's answer, and |
| 10 | /// `initRecording` waiting out the headset's switch to its hands-free |
| 11 | /// profile, all on the main thread. The switch is stood in for by holding |
| 12 | /// the engine's start on WebRTC's worker thread for 1.5 s |
| 13 | /// (AudioStartProbe.engineStartDelay), where a real one holds it. |
| 14 | /// |
| 15 | /// First a control: a deliberate 300 ms block of the main thread must be |
| 16 | /// seen, so a pass means the watchdog was looking. Prints one PASS or FAIL |
| 17 | /// line per run, with the longest stall; exits 0 only if all passed. |
| 18 | @MainActor enum AudioStartStallHarness { |
| 19 | static let limit = 0.1 |
| 20 | static let switchDelay = 1.5 |
| 21 | |
| 22 | static func run() async -> Bool { |
| 23 | let dog = MainThreadWatchdog() |
| 24 | dog.start() |
| 25 | try? await Task.sleep(for: .milliseconds(200)) |
| 26 | var passed = await control(dog) |
| 27 | |
| 28 | passed = await testAudio(dog, label: "Test audio start", delay: 0) && passed |
| 29 | passed = await testAudio(dog, label: "Test audio start, Bluetooth switch simulated", delay: switchDelay) && passed |
| 30 | passed = await testAudio( |
| 31 | dog, label: "Test audio closed while its microphone starts", delay: switchDelay, closeAfter: 0.3) && passed |
| 32 | passed = await callJoin(dog) && passed |
| 33 | _ = dog.stop() |
| 34 | return passed |
| 35 | } |
| 36 | |
| 37 | private static func control(_ dog: MainThreadWatchdog) async -> Bool { |
| 38 | let label = "audio start stall control (the watchdog sees a 300 ms block)" |
| 39 | dog.reset() |
| 40 | Thread.sleep(forTimeInterval: 0.3) |
| 41 | // The watchdog's posts answer once the main thread is free again. |
| 42 | try? await Task.sleep(for: .milliseconds(50)) |
| 43 | let seen = dog.longestSoFar |
| 44 | if seen >= 0.25 { |
| 45 | print("PASS \(label): saw \(ms(seen))") |
| 46 | return true |
| 47 | } |
| 48 | print("FAIL \(label): saw only \(ms(seen))") |
| 49 | return false |
| 50 | } |
| 51 | |
| 52 | private static func testAudio( |
| 53 | _ dog: MainThreadWatchdog, label: String, delay: TimeInterval, closeAfter: Double? = nil |
| 54 | ) async -> Bool { |
| 55 | AudioStartProbe.engineStartDelay = delay |
| 56 | defer { AudioStartProbe.engineStartDelay = 0 } |
| 57 | await settle() |
| 58 | dog.reset() |
| 59 | let report = await AudioStartProbe.testAudio(closeAfter: closeAfter) |
| 60 | let stall = dog.longestSoFar |
| 61 | var problems: [String] = [] |
| 62 | if stall > limit { problems.append("main thread held \(ms(stall)), limit \(ms(limit))") } |
| 63 | let firstShown = report.phases.first { $0.phase != .idle } |
| 64 | if let firstShown, firstShown.at > limit { |
| 65 | problems.append("the window said nothing for \(ms(firstShown.at))") |
| 66 | } |
| 67 | if firstShown == nil { problems.append("the window never said it was starting") } |
| 68 | let starting = report.phases.first { if case .starting = $0.phase { return true } else { return false } } |
| 69 | let ended = report.phases.last { $0.phase == .running || $0.phase == .failed || $0.phase == .cancelled } |
| 70 | if closeAfter == nil { |
| 71 | if !report.asked { problems.append("the module was never asked for the microphone") } |
| 72 | if delay > 0, let starting, let ended, ended.at - starting.at < delay * 0.9 { |
| 73 | problems.append( |
| 74 | "'Starting microphone…' showed for \(ms(ended.at - starting.at)), not for the \(ms(delay)) switch") |
| 75 | } |
| 76 | } else if ended?.phase != .cancelled { |
| 77 | problems.append("closing partway left the phase at \(String(describing: ended?.phase))") |
| 78 | } |
| 79 | if report.recordingAfter { problems.append("the microphone was left open") } |
| 80 | let phases = report.phases.map { "\(String(describing: $0.phase)) at \(ms($0.at))" }.joined(separator: ", ") |
| 81 | let detail = |
| 82 | "longest main-thread stall \(ms(stall)); start took \(ms(report.startSeconds)); phases: \(phases); asked \(report.asked); problem: \(report.problem ?? "none"); \(report.detail)" |
| 83 | if problems.isEmpty { |
| 84 | print("PASS \(label): \(detail)") |
| 85 | return true |
| 86 | } |
| 87 | print("FAIL \(label): \(problems.joined(separator: "; ")) [\(detail)]") |
| 88 | return false |
| 89 | } |
| 90 | |
| 91 | private static func callJoin(_ dog: MainThreadWatchdog) async -> Bool { |
| 92 | let label = "Call join audio start, Bluetooth switch simulated" |
| 93 | AudioStartProbe.engineStartDelay = switchDelay |
| 94 | defer { AudioStartProbe.engineStartDelay = 0 } |
| 95 | await settle() |
| 96 | dog.reset() |
| 97 | let report = await AudioStartProbe.callJoin(camera: Interop.camera) |
| 98 | let stall = dog.longestSoFar |
| 99 | var problems: [String] = [] |
| 100 | if stall > limit { problems.append("main thread held \(ms(stall)), limit \(ms(limit))") } |
| 101 | if !report.asked { problems.append("the module was never asked for the microphone") } |
| 102 | if let problem = report.problem { problems.append(problem) } |
| 103 | if report.recordingAfter { problems.append("the microphone was left open") } |
| 104 | let detail = |
| 105 | "longest main-thread stall \(ms(stall)); audio start took \(ms(report.startSeconds)); asked \(report.asked); \(report.detail)" |
| 106 | if problems.isEmpty { |
| 107 | print("PASS \(label): \(detail)") |
| 108 | return true |
| 109 | } |
| 110 | print("FAIL \(label): \(problems.joined(separator: "; ")) [\(detail)]") |
| 111 | return false |
| 112 | } |
| 113 | |
| 114 | /// Lets the last run's queued stops and closes finish before the next |
| 115 | /// is measured. |
| 116 | private static func settle() async { |
| 117 | try? await Task.sleep(for: .milliseconds(300)) |
| 118 | } |
| 119 | |
| 120 | static func ms(_ seconds: Double) -> String { "\(Int((seconds * 1000).rounded())) ms" } |
| 121 | } |
| 122 | |
amadan