From 5962daa37d4e40ad6917f24a394f0140d745532a Mon Sep 17 00:00:00 2001 From: Abdulaziz Albahar <67667005+azooz2003-bit@users.noreply.github.com> Date: Wed, 29 Jul 2026 00:38:42 -0700 Subject: [PATCH 1/9] =?UTF-8?q?Add=20iOS=E2=86=94Mac=20sync=20latency=20tr?= =?UTF-8?q?acing,=20probe,=20and=20analyzer?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../MobileLatencyTrace.swift | 112 ++++ .../CmuxMobileShell/MobileLatencyProbe.swift | 40 ++ .../MobileShellComposite+LatencyProbe.swift | 46 ++ .../MobileShellComposite+StateSync.swift | 9 + .../MobileShellComposite+TerminalLane.swift | 12 +- ...hellComposite+TerminalOutputDelivery.swift | 44 +- .../MobileShellComposite.swift | 49 +- .../TerminalOutputDelivery.swift | 7 +- .../MobileTerminalOutputSinking.swift | 14 + .../GhosttySurfaceRepresentable.swift | 67 +- .../GhosttySurfaceView+LatencyTrace.swift | 10 + .../GhosttySurfaceView.swift | 10 + Sources/App/HostLatencyTrace.swift | 58 ++ .../MobileHostConnectionEventQueue.swift | 29 +- Sources/Mobile/MobileHostService.swift | 32 +- Sources/Mobile/MobileStateSync.swift | 7 + Sources/Mobile/MobileTerminalByteTee.swift | 3 + .../Mobile/MobileTerminalRenderObserver.swift | 18 +- .../Mobile/MobileWorkspaceListObserver.swift | 3 + Sources/TerminalController.swift | 6 + cmux.xcodeproj/project.pbxproj | 4 + scripts/mobile-latency-trace/README.md | 47 ++ scripts/mobile-latency-trace/analyze.py | 581 ++++++++++++++++++ 23 files changed, 1165 insertions(+), 43 deletions(-) create mode 100644 Packages/iOS/CmuxMobileDiagnostics/Sources/CmuxMobileDiagnostics/MobileLatencyTrace.swift create mode 100644 Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileLatencyProbe.swift create mode 100644 Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+LatencyProbe.swift create mode 100644 Packages/iOS/CmuxMobileTerminal/Sources/CmuxMobileTerminal/GhosttySurfaceView+LatencyTrace.swift create mode 100644 Sources/App/HostLatencyTrace.swift create mode 100644 scripts/mobile-latency-trace/README.md create mode 100755 scripts/mobile-latency-trace/analyze.py diff --git a/Packages/iOS/CmuxMobileDiagnostics/Sources/CmuxMobileDiagnostics/MobileLatencyTrace.swift b/Packages/iOS/CmuxMobileDiagnostics/Sources/CmuxMobileDiagnostics/MobileLatencyTrace.swift new file mode 100644 index 000000000000..47053acc3ca4 --- /dev/null +++ b/Packages/iOS/CmuxMobileDiagnostics/Sources/CmuxMobileDiagnostics/MobileLatencyTrace.swift @@ -0,0 +1,112 @@ +import Dispatch +import Foundation + +/// Low-overhead, opt-in latency stamps for DEBUG mobile builds. +public enum MobileLatencyTrace { + /// Whether latency tracing is enabled for this process. + public static let isEnabled: Bool = { + #if DEBUG + ProcessInfo.processInfo.environment["CMUX_LATENCY_TRACE"] == "1" + || UserDefaults.standard.bool(forKey: "cmux.debug.latency-trace") + #else + false + #endif + }() + + /// Emits one machine-parseable latency stamp to the mobile file sink. + /// + /// - Parameters: + /// - stage: Stable stage token. + /// - fields: Integer or short-token fields, without terminal content. + @inline(__always) + public static func stamp( + _ stage: StaticString, + _ fields: @autoclosure () -> String = "" + ) { + #if DEBUG + guard isEnabled else { return } + write(stage, uptimeMicroseconds: nowUptimeMicroseconds(), fields: fields()) + #endif + } + + /// Captures the monotonic clock only when tracing is enabled. + @inline(__always) + public static func captureTime() -> UInt64? { + #if DEBUG + guard isEnabled else { return nil } + return nowUptimeMicroseconds() + #else + return nil + #endif + } + + /// Emits a stamp at a previously captured time without another gate check. + /// + /// - Parameters: + /// - stage: Stable stage token. + /// - uptimeMicroseconds: Previously captured monotonic uptime. + /// - fields: Integer or short-token fields, without terminal content. + @inline(__always) + public static func stamp( + _ stage: StaticString, + at uptimeMicroseconds: UInt64, + _ fields: @autoclosure () -> String = "" + ) { + #if DEBUG + write(stage, uptimeMicroseconds: uptimeMicroseconds, fields: fields()) + #endif + } + + /// Returns elapsed microseconds from a captured trace start. + /// + /// - Parameter start: Previously captured monotonic uptime. + /// - Returns: Elapsed monotonic microseconds. + @inline(__always) + public static func elapsedMicroseconds(since start: UInt64) -> UInt64 { + #if DEBUG + nowUptimeMicroseconds() &- start + #else + 0 + #endif + } + + #if DEBUG + /// Emits a completion stamp for an optionally captured trace start. + /// + /// - Parameters: + /// - stage: Stable completion-stage token. + /// - start: Captured start, or `nil` when tracing was disabled. + /// - fields: Builds fields from the elapsed microseconds. + @inline(__always) + public static func stampElapsed( + _ stage: StaticString, + since start: UInt64?, + _ fields: (_ elapsedMicroseconds: UInt64) -> String + ) { + guard let start else { return } + let completionTime = nowUptimeMicroseconds() + write( + stage, + uptimeMicroseconds: completionTime, + fields: fields(completionTime &- start) + ) + } + + @inline(__always) + private static func nowUptimeMicroseconds() -> UInt64 { + // Simulator uptime is in the host Mac clock domain, so simulator and + // Mac stamps are directly comparable. A physical iPhone is not. + DispatchTime.now().uptimeNanoseconds / 1_000 + } + + @inline(__always) + private static func write( + _ stage: StaticString, + uptimeMicroseconds: UInt64, + fields: String + ) { + let suffix = fields.isEmpty ? "" : " \(fields)" + MobileDebugLog.shared.append("LAT \(stage) t=\(uptimeMicroseconds)\(suffix)") + } + #endif +} diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileLatencyProbe.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileLatencyProbe.swift new file mode 100644 index 000000000000..8b22099e1af8 --- /dev/null +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileLatencyProbe.swift @@ -0,0 +1,40 @@ +#if DEBUG +import Foundation + +/// Process-scoped configuration and claim gate for the DEBUG typing probe. +@MainActor +enum MobileLatencyProbe { + struct Configuration { + let count: Int + let intervalMilliseconds: Int + } + + private static let configuration: Configuration? = { + guard let raw = ProcessInfo.processInfo.environment["CMUX_LATENCY_PROBE"] else { + return nil + } + if raw == "1" { + return Configuration(count: 40, intervalMilliseconds: 250) + } + let parts = raw.split(separator: ":", omittingEmptySubsequences: false) + guard parts.count == 2, + let count = Int(parts[0]), count > 0, + let intervalMilliseconds = Int(parts[1]), intervalMilliseconds > 0 else { + return nil + } + return Configuration(count: count, intervalMilliseconds: intervalMilliseconds) + }() + + private static var hasClaimedProcessRun = false + + static func claimConfiguration() -> Configuration? { + guard !hasClaimedProcessRun, let configuration else { return nil } + hasClaimedProcessRun = true + return configuration + } + + static func input(at index: Int) -> Data { + Data([UInt8(ascii: "a") + UInt8(index % 26)]) + } +} +#endif diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+LatencyProbe.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+LatencyProbe.swift new file mode 100644 index 000000000000..89c13e5cf3b3 --- /dev/null +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+LatencyProbe.swift @@ -0,0 +1,46 @@ +#if DEBUG +import CmuxMobileDiagnostics +import Foundation + +extension MobileShellComposite { + func startLatencyProbeIfReady() { + guard connectionState == .connected, + latencyProbeTask == nil, + let surfaceID = terminalOutputStreamTokensBySurfaceID.keys.first, + let configuration = MobileLatencyProbe.claimConfiguration() else { + return + } + latencyProbeTask = Task { @MainActor [weak self] in + defer { self?.latencyProbeTask = nil } + do { + try await Task.sleep(for: .seconds(3)) + for index in 0.. 0 { terminalMirrorHydrationNeededSurfaceIDs.remove(renderGrid.surfaceID) } + #if DEBUG + MobileLatencyTrace.stamp("gate", "seq=\(renderGrid.stateSeq) out=delivered") + #endif } /// Whether a surface currently has an attached output stream consumer. @@ -235,13 +269,15 @@ extension MobileShellComposite { func deliverTerminalBytes( _ bytes: Data, surfaceID: String, + endSequence: UInt64? = nil, bypassReplayBarrier: Bool = false ) -> Bool { return deliverTerminalOutput( TerminalOutputDelivery( bytes: bytes, replaceable: false, - viewportPolicy: .natural + viewportPolicy: .natural, + endSequence: endSequence ), surfaceID: surfaceID, bypassReplayBarrier: bypassReplayBarrier @@ -369,6 +405,7 @@ extension MobileShellComposite { streamToken: streamToken, viewportPolicy: immediate.viewportPolicy, sourceRenderGridFrame: immediate.sourceRenderGridFrame, + endSequence: immediate.endSequence, requiresVerifiedReplay: requiresVerifiedReplayApplication(for: immediate), terminalConfigTheme: immediate.terminalConfigTheme ) @@ -477,6 +514,7 @@ extension MobileShellComposite { streamToken: streamToken, viewportPolicy: next.viewportPolicy, sourceRenderGridFrame: next.sourceRenderGridFrame, + endSequence: next.endSequence, requiresVerifiedReplay: requiresVerifiedReplayApplication(for: next), terminalConfigTheme: next.terminalConfigTheme )) diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite.swift index 3e011acbc47f..d69abe5ef873 100644 --- a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite.swift +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite.swift @@ -146,9 +146,15 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { if connectionState == .connected { restartTerminalLanesForMountedSurfaces() scheduleWorkspaceChangesSummaryRefresh() + #if DEBUG + startLatencyProbeIfReady() + #endif } else { deactivateAllTerminalLanes() resetWorkspaceChangesState() + #if DEBUG + cancelLatencyProbe() + #endif } // Intentional teardown (sign-out, hide, switch) must not look like // a network outage: swallow this edge and reset the throttle so a @@ -984,6 +990,10 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { private var rawTerminalInputBuffer: MobileTerminalInputSendBuffer private var rawTerminalInputDrainWaiters: [CheckedContinuation] private var isRawTerminalInputDrainLoopRunning: Bool + #if DEBUG + var latencyProbeTask: Task? + private var rawTerminalInputLatencyBatchNumber: UInt64 + #endif private var pairingAttemptID: UUID /// High-level shell phase derived from sign-in and connection state. @@ -1220,6 +1230,10 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { self.rawTerminalInputBuffer = MobileTerminalInputSendBuffer() self.rawTerminalInputDrainWaiters = [] self.isRawTerminalInputDrainLoopRunning = false + #if DEBUG + self.latencyProbeTask = nil + self.rawTerminalInputLatencyBatchNumber = 0 + #endif self.pairingAttemptID = UUID() } @@ -5362,11 +5376,22 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { // Matches MobileIrohTerminalLane.maximumInputByteCount and the Mac lane // router's maximumInputFrameByteCount. while let chunk = rawTerminalInputBuffer.nextBatch(maximumByteCount: 16 * 1_024) { + #if DEBUG + rawTerminalInputLatencyBatchNumber &+= 1 + let latencyBatchNumber = rawTerminalInputLatencyBatchNumber + MobileLatencyTrace.stamp( + "in.send", + "n=\(latencyBatchNumber) bytes=\(chunk.text.utf8.count)" + ) + #endif await sendRemoteTerminalInput( chunk.text, workspaceID: chunk.workspaceID, terminalID: chunk.terminalID ) + #if DEBUG + MobileLatencyTrace.stamp("in.settled", "n=\(latencyBatchNumber)") + #endif } } @@ -7556,6 +7581,9 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { let remoteSeq = payload.terminalSeq else { return } + #if DEBUG + MobileLatencyTrace.stamp("in.resp", "ack_seq=\(remoteSeq)") + #endif let localSeq = deliveredTerminalByteEndSeqBySurfaceID[surfaceID] ?? 0 guard remoteSeq > localSeq else { return } let canRenderGridAdvancePendingSeq = terminalOutputTransport == .renderGrid @@ -7627,6 +7655,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { pendingTerminalInputDroppedRenderGridSurfaceIDs.remove(surfaceID) #if DEBUG mobileShellLog.info("CMUX_REPLAY register sink surface=\(surfaceID, privacy: .public) connected=\(self.connectionState == .connected, privacy: .public) hasClient=\(self.remoteClient != nil, privacy: .public) workspaceCount=\(self.workspaces.count, privacy: .public)") + startLatencyProbeIfReady() #endif requestColdAttachTerminalReplay(surfaceID: surfaceID) ensureTerminalLane(surfaceID: surfaceID) @@ -8064,6 +8093,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { let accepted = self.deliverTerminalBytes( deliverBytes, surfaceID: surfaceID, + endSequence: replaySeq, bypassReplayBarrier: replayBarrierTokenForRequest != nil ) if accepted, @@ -8165,6 +8195,9 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { guard let json = event.payloadJSON else { return } + #if DEBUG + let latencyReceiveTime = MobileLatencyTrace.captureTime() + #endif // The frame may arrive nested under `render_grid` or as the bare payload; // try the wrapper first, then fall back to decoding the whole payload. let renderGridDTO = try? MobileTerminalRenderGridEvent.decode(json) @@ -8173,6 +8206,14 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { return } #if DEBUG + if let latencyReceiveTime { + let decodeDuration = MobileLatencyTrace.elapsedMicroseconds(since: latencyReceiveTime) + MobileLatencyTrace.stamp( + "ev.grid", + at: latencyReceiveTime, + "seq=\(renderGrid.stateSeq) bytes=\(json.count) dec_us=\(decodeDuration)" + ) + } mobileShellLog.info("CMUX_REPLAY live render_grid surface=\(renderGrid.surfaceID, privacy: .public) full=\(renderGrid.full, privacy: .public) spans=\(renderGrid.rowSpans.count, privacy: .public) cleared=\(renderGrid.clearedRows.count, privacy: .public) seq=\(renderGrid.stateSeq, privacy: .public) hasSink=true") #endif deliverAuthoritativeTerminalRenderGrid(renderGrid, source: "event") @@ -8264,7 +8305,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { b: Int(clamping: seq) )) mobileShellLog.info("terminal byte gap surface=\(surfaceID, privacy: .public) deliveredSeq=\(deliveredSeq, privacy: .public) nextSeq=\(seq, privacy: .public)") - guard deliverTerminalBytes(bytes, surfaceID: surfaceID) else { return } + guard deliverTerminalBytes(bytes, surfaceID: surfaceID, endSequence: endSeq) else { return } markTerminalBytesDelivered(surfaceID: surfaceID, endSeq: endSeq) if terminalReplaySurfaceIDsInFlight.contains(surfaceID) { cancelTerminalReplayInFlight(surfaceID: surfaceID) @@ -8281,7 +8322,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { } let overlap = deliveredSeq - seq let deliverBytes = Data(bytes.dropFirst(Int(overlap))) - guard deliverTerminalBytes(deliverBytes, surfaceID: surfaceID) else { return } + guard deliverTerminalBytes(deliverBytes, surfaceID: surfaceID, endSequence: endSeq) else { return } markTerminalBytesDelivered(surfaceID: surfaceID, endSeq: endSeq) return } @@ -8295,12 +8336,12 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { if seq < floorSeq { let overlap = floorSeq - seq let deliverBytes = Data(bytes.dropFirst(Int(overlap))) - guard deliverTerminalBytes(deliverBytes, surfaceID: surfaceID) else { return } + guard deliverTerminalBytes(deliverBytes, surfaceID: surfaceID, endSequence: endSeq) else { return } markTerminalBytesDelivered(surfaceID: surfaceID, endSeq: endSeq) return } } - guard deliverTerminalBytes(bytes, surfaceID: surfaceID) else { return } + guard deliverTerminalBytes(bytes, surfaceID: surfaceID, endSequence: endSeq) else { return } markTerminalBytesDelivered(surfaceID: surfaceID, endSeq: endSeq) } diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/TerminalOutputDelivery.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/TerminalOutputDelivery.swift index bf8d628d6220..ba3eb6c93924 100644 --- a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/TerminalOutputDelivery.swift +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/TerminalOutputDelivery.swift @@ -20,6 +20,7 @@ struct TerminalOutputDelivery: Equatable, Sendable { private var payload: Payload var replacementScope: ReplacementScope? var viewportPolicy: MobileTerminalOutputViewportPolicy? + var endSequence: UInt64? var replaceable: Bool { replacementScope != nil @@ -29,17 +30,20 @@ struct TerminalOutputDelivery: Equatable, Sendable { bytes: Data, replaceable: Bool, replacementScope: ReplacementScope? = nil, - viewportPolicy: MobileTerminalOutputViewportPolicy? = nil + viewportPolicy: MobileTerminalOutputViewportPolicy? = nil, + endSequence: UInt64? = nil ) { self.payload = .bytes(bytes) self.replacementScope = replaceable ? (replacementScope ?? .byteViewport) : nil self.viewportPolicy = viewportPolicy + self.endSequence = endSequence } init(theme frame: MobileTerminalRenderGridFrame) { self.payload = .theme(frame) self.replacementScope = .terminalTheme self.viewportPolicy = nil + self.endSequence = frame.stateSeq } init( @@ -51,6 +55,7 @@ struct TerminalOutputDelivery: Equatable, Sendable { self.payload = .renderGrid(frame) self.replacementScope = replaceable ? (replacementScope ?? .renderGridViewport) : nil self.viewportPolicy = viewportPolicy + self.endSequence = frame.stateSeq } var bytes: Data { diff --git a/Packages/iOS/CmuxMobileShellModel/Sources/CmuxMobileShellModel/MobileTerminalOutputSinking.swift b/Packages/iOS/CmuxMobileShellModel/Sources/CmuxMobileShellModel/MobileTerminalOutputSinking.swift index f41543b6e00f..9ef194cc1b97 100644 --- a/Packages/iOS/CmuxMobileShellModel/Sources/CmuxMobileShellModel/MobileTerminalOutputSinking.swift +++ b/Packages/iOS/CmuxMobileShellModel/Sources/CmuxMobileShellModel/MobileTerminalOutputSinking.swift @@ -27,16 +27,29 @@ public struct MobileTerminalOutputChunk: Sendable { public let viewportPolicy: MobileTerminalOutputViewportPolicy? /// Source grid whose VT replay bytes are carried by this chunk. public let sourceRenderGridFrame: MobileTerminalRenderGridFrame? + /// Terminal byte high-water mark represented by this chunk, when known. + public let endSequence: UInt64? /// Whether nonempty output must pass render-grid verification before display. public let requiresVerifiedReplay: Bool /// Raw Ghostty defaults that must be installed before this chunk's VT replay. public let terminalConfigTheme: TerminalTheme? + /// Creates one backpressured terminal-output chunk. + /// + /// - Parameters: + /// - data: VT or PTY bytes to apply. + /// - streamToken: Identity of the mounted output stream. + /// - viewportPolicy: Optional viewport policy to apply with the bytes. + /// - sourceRenderGridFrame: Source grid represented by the bytes. + /// - endSequence: Terminal byte high-water mark represented by the chunk. + /// - requiresVerifiedReplay: Whether the verified replay path is required. + /// - terminalConfigTheme: Raw Ghostty defaults paired with the bytes. public init( data: Data, streamToken: UUID, viewportPolicy: MobileTerminalOutputViewportPolicy? = nil, sourceRenderGridFrame: MobileTerminalRenderGridFrame? = nil, + endSequence: UInt64? = nil, requiresVerifiedReplay: Bool = false, terminalConfigTheme: TerminalTheme? = nil ) { @@ -44,6 +57,7 @@ public struct MobileTerminalOutputChunk: Sendable { self.streamToken = streamToken self.viewportPolicy = viewportPolicy self.sourceRenderGridFrame = sourceRenderGridFrame + self.endSequence = endSequence self.requiresVerifiedReplay = requiresVerifiedReplay self.terminalConfigTheme = terminalConfigTheme } diff --git a/Packages/iOS/CmuxMobileShellUI/Sources/CmuxMobileShellUI/GhosttySurfaceRepresentable.swift b/Packages/iOS/CmuxMobileShellUI/Sources/CmuxMobileShellUI/GhosttySurfaceRepresentable.swift index 3a6a5431751e..b5f3814f675d 100644 --- a/Packages/iOS/CmuxMobileShellUI/Sources/CmuxMobileShellUI/GhosttySurfaceRepresentable.swift +++ b/Packages/iOS/CmuxMobileShellUI/Sources/CmuxMobileShellUI/GhosttySurfaceRepresentable.swift @@ -333,18 +333,38 @@ struct GhosttySurfaceRepresentable: UIViewRepresentable { guard !Task.isCancelled else { return } guard let self else { return } guard let surfaceView else { return } + #if DEBUG + let latencySequence = chunk.sourceRenderGridFrame?.stateSeq + ?? chunk.endSequence + ?? 0 + MobileLatencyTrace.stamp("ap.yield", "seq=\(latencySequence)") + let latencyApplyStart = MobileLatencyTrace.captureTime() + #endif switch terminalOutputApplicationPath( for: chunk, expectedSurfaceID: surfaceID ) { case .verifiedReplay: guard let frame = chunk.sourceRenderGridFrame else { return } - await self.applyVerifiedRenderGrid( + let applied = await self.applyVerifiedRenderGrid( frame, chunk: chunk, surfaceView: surfaceView, store: store ) + if applied { + #if DEBUG + surfaceView.markLatencyAppliedSequence(frame.stateSeq) + MobileLatencyTrace.stampElapsed( + "ap.done", + since: latencyApplyStart + ) { "seq=\(frame.stateSeq) path=verified us=\($0)" } + #endif + store.terminalOutputDidProcess( + surfaceID: surfaceID, + streamToken: chunk.streamToken + ) + } continue case .rejectUnverified: let transactionID = self.verifiedReplayState.rejectUnverifiedOutput() @@ -413,6 +433,13 @@ struct GhosttySurfaceRepresentable: UIViewRepresentable { continue } } + #if DEBUG + surfaceView.markLatencyAppliedSequence(latencySequence) + MobileLatencyTrace.stampElapsed( + "ap.done", + since: latencyApplyStart + ) { "seq=\(latencySequence) path=legacy us=\($0)" } + #endif store.terminalOutputDidProcess( surfaceID: surfaceID, streamToken: chunk.streamToken @@ -476,16 +503,16 @@ struct GhosttySurfaceRepresentable: UIViewRepresentable { chunk: MobileTerminalOutputChunk, surfaceView: GhosttySurfaceView, store: CMUXMobileShellStore - ) async { + ) async -> Bool { if let chunkConfigTheme = chunk.terminalConfigTheme, chunkConfigTheme != store.terminalConfigTheme(for: surfaceID) { store.terminalOutputDidReset( surfaceID: surfaceID, streamToken: chunk.streamToken ) - return + return false } - await applyThemeMatchedVerifiedRenderGrid( + return await applyThemeMatchedVerifiedRenderGrid( frame, chunk: chunk, surfaceView: surfaceView, @@ -498,33 +525,33 @@ struct GhosttySurfaceRepresentable: UIViewRepresentable { chunk: MobileTerminalOutputChunk, surfaceView: GhosttySurfaceView, store: CMUXMobileShellStore - ) async { + ) async -> Bool { guard case .apply(let transaction) = verifiedReplayState.begin(frame: frame) else { _ = await surfaceView.freezeVerifiedReplayPresentation( transactionID: frame.renderRevision ) - guard !Task.isCancelled else { return } + guard !Task.isCancelled else { return false } requestVerifiedReplayReset(transactionID: nil, chunk: chunk, store: store) - return + return false } let frozen = await surfaceView.freezeVerifiedReplayPresentation( transactionID: transaction.id ) - guard !Task.isCancelled else { return } + guard !Task.isCancelled else { return false } guard frozen else { requestVerifiedReplayReset(transactionID: transaction.id, chunk: chunk, store: store) - return + return false } activeViewportPolicy = .remoteGrid(columns: frame.columns, rows: frame.rows) let resized = await surfaceView.applyViewSizeAndWait( cols: frame.columns, rows: frame.rows ) - guard !Task.isCancelled else { return } + guard !Task.isCancelled else { return false } guard resized else { requestVerifiedReplayReset(transactionID: transaction.id, chunk: chunk, store: store) - return + return false } if !chunk.data.isEmpty || chunk.terminalConfigTheme != nil { @@ -532,10 +559,10 @@ struct GhosttySurfaceRepresentable: UIViewRepresentable { chunk.data, terminalConfigTheme: chunk.terminalConfigTheme ) - guard !Task.isCancelled else { return } + guard !Task.isCancelled else { return false } guard applied else { requestVerifiedReplayReset(transactionID: transaction.id, chunk: chunk, store: store) - return + return false } } @@ -544,8 +571,8 @@ struct GhosttySurfaceRepresentable: UIViewRepresentable { configuredCursorColor: chunk.terminalConfigTheme?.cursor ?? surfaceView.terminalConfigTheme.cursor ) - guard !Task.isCancelled else { return } - finishVerifiedReplay( + guard !Task.isCancelled else { return false } + return finishVerifiedReplay( transactionID: transaction.id, observed: observed, chunk: chunk, @@ -577,7 +604,7 @@ struct GhosttySurfaceRepresentable: UIViewRepresentable { chunk: MobileTerminalOutputChunk, surfaceView: GhosttySurfaceView, store: CMUXMobileShellStore - ) { + ) -> Bool { switch verifiedReplayState.complete( transactionID: transactionID, observedFrame: observed @@ -591,17 +618,15 @@ struct GhosttySurfaceRepresentable: UIViewRepresentable { surfaceID: surfaceID, streamToken: chunk.streamToken ) - return + return false } - store.terminalOutputDidProcess( - surfaceID: surfaceID, - streamToken: chunk.streamToken - ) + return true case .keepFrozenAndRequestReplay, .ignoreStaleCompletion: store.terminalOutputDidReset( surfaceID: surfaceID, streamToken: chunk.streamToken ) + return false } } diff --git a/Packages/iOS/CmuxMobileTerminal/Sources/CmuxMobileTerminal/GhosttySurfaceView+LatencyTrace.swift b/Packages/iOS/CmuxMobileTerminal/Sources/CmuxMobileTerminal/GhosttySurfaceView+LatencyTrace.swift new file mode 100644 index 000000000000..260a1ed0a8be --- /dev/null +++ b/Packages/iOS/CmuxMobileTerminal/Sources/CmuxMobileTerminal/GhosttySurfaceView+LatencyTrace.swift @@ -0,0 +1,10 @@ +#if DEBUG && canImport(UIKit) +extension GhosttySurfaceView { + /// Associates subsequent render completions with the latest applied frame. + /// + /// - Parameter sequence: Applied terminal byte high-water mark. + public func markLatencyAppliedSequence(_ sequence: UInt64) { + latencyLastAppliedSequence = sequence + } +} +#endif diff --git a/Packages/iOS/CmuxMobileTerminal/Sources/CmuxMobileTerminal/GhosttySurfaceView.swift b/Packages/iOS/CmuxMobileTerminal/Sources/CmuxMobileTerminal/GhosttySurfaceView.swift index cacaa88e2dc8..56210e2785e8 100644 --- a/Packages/iOS/CmuxMobileTerminal/Sources/CmuxMobileTerminal/GhosttySurfaceView.swift +++ b/Packages/iOS/CmuxMobileTerminal/Sources/CmuxMobileTerminal/GhosttySurfaceView.swift @@ -366,6 +366,9 @@ public final class GhosttySurfaceView: UIView, TerminalSurfaceHosting { var surface: ghostty_surface_t? var surfaceGeneration: UInt64 = 0 + #if DEBUG + var latencyLastAppliedSequence: UInt64? + #endif private var lastReportedSize: TerminalGridSize? /// Latest natural grid awaiting a debounced report to the Mac. The display /// link sends it only after the grid has held steady for @@ -3118,6 +3121,13 @@ public final class GhosttySurfaceView: UIView, TerminalSurfaceHosting { DispatchQueue.main.async { guard let self else { return } guard self.surfaceGeneration == generation else { return } + #if DEBUG + if let sequence = self.latencyLastAppliedSequence { + MobileLatencyTrace.stamp("rd.present", "seq=\(sequence)") + } else { + MobileLatencyTrace.stamp("rd.present") + } + #endif self.renderInFlight = false self.renderInFlightSince = nil guard !self.isDismantled else { diff --git a/Sources/App/HostLatencyTrace.swift b/Sources/App/HostLatencyTrace.swift new file mode 100644 index 000000000000..9310ad1b2bfe --- /dev/null +++ b/Sources/App/HostLatencyTrace.swift @@ -0,0 +1,58 @@ +#if DEBUG +import Dispatch +import Foundation + +/// Low-overhead, opt-in latency stamps for DEBUG host builds. +enum HostLatencyTrace { + static let isEnabled = + ProcessInfo.processInfo.environment["CMUX_LATENCY_TRACE"] == "1" + || UserDefaults.standard.bool(forKey: "cmux.debug.latency-trace") + + @inline(__always) + static func stamp( + _ stage: StaticString, + _ fields: @autoclosure () -> String = "" + ) { + guard isEnabled else { return } + write(stage, uptimeMicroseconds: nowUptimeMicroseconds(), fields: fields()) + } + + @inline(__always) + static func captureTime() -> UInt64? { + guard isEnabled else { return nil } + return nowUptimeMicroseconds() + } + + @inline(__always) + static func stampElapsed( + _ stage: StaticString, + since start: UInt64?, + _ fields: (_ elapsedMicroseconds: UInt64) -> String + ) { + guard let start else { return } + let completionTime = nowUptimeMicroseconds() + write( + stage, + uptimeMicroseconds: completionTime, + fields: fields(completionTime &- start) + ) + } + + @inline(__always) + private static func nowUptimeMicroseconds() -> UInt64 { + // Simulator uptime is in the host Mac clock domain, so simulator and + // Mac stamps are directly comparable. A physical iPhone is not. + DispatchTime.now().uptimeNanoseconds / 1_000 + } + + @inline(__always) + private static func write( + _ stage: StaticString, + uptimeMicroseconds: UInt64, + fields: String + ) { + let suffix = fields.isEmpty ? "" : " \(fields)" + cmuxDebugLog("LAT \(stage) t=\(uptimeMicroseconds)\(suffix)") + } +} +#endif diff --git a/Sources/Mobile/MobileHostConnectionEventQueue.swift b/Sources/Mobile/MobileHostConnectionEventQueue.swift index 4c47ac8d02bc..be1dd3023fed 100644 --- a/Sources/Mobile/MobileHostConnectionEventQueue.swift +++ b/Sources/Mobile/MobileHostConnectionEventQueue.swift @@ -50,12 +50,15 @@ struct MobileHostEventEnqueueResult: Sendable { /// Surfaces whose queued render-grid frames were shed; the caller must ask /// the producer for a full-frame resync of each. let renderGridResyncSurfaceIDs: Set + /// Queue depth immediately after an admitted append. + let depthAfterEnqueue: Int? static let rejected = MobileHostEventEnqueueResult( admitted: false, startDrain: false, shouldClose: false, - renderGridResyncSurfaceIDs: [] + renderGridResyncSurfaceIDs: [], + depthAfterEnqueue: nil ) } @@ -76,6 +79,7 @@ final class MobileHostConnectionEventQueue: @unchecked Sendable { let topic: String let coalesceKey: String? let frame: Data + let stateSeq: UInt64? } static let defaultMaximumEventCount = 256 @@ -140,6 +144,7 @@ final class MobileHostConnectionEventQueue: @unchecked Sendable { topic: String, coalesceKey: String?, isFullRenderGridFrame: Bool, + stateSeq: UInt64? = nil, frame: Data ) -> MobileHostEventEnqueueResult { lock.lock() @@ -172,7 +177,8 @@ final class MobileHostConnectionEventQueue: @unchecked Sendable { admitted: false, startDrain: false, shouldClose: false, - renderGridResyncSurfaceIDs: resyncSurfaceIDs + renderGridResyncSurfaceIDs: resyncSurfaceIDs, + depthAfterEnqueue: nil ) } guard hasRoomLocked(for: frame) else { @@ -182,7 +188,8 @@ final class MobileHostConnectionEventQueue: @unchecked Sendable { admitted: false, startDrain: false, shouldClose: true, - renderGridResyncSurfaceIDs: resyncSurfaceIDs + renderGridResyncSurfaceIDs: resyncSurfaceIDs, + depthAfterEnqueue: nil ) } if isRenderGrid, let coalesceKey { @@ -199,11 +206,20 @@ final class MobileHostConnectionEventQueue: @unchecked Sendable { admitted: false, startDrain: false, shouldClose: false, - renderGridResyncSurfaceIDs: resyncSurfaceIDs + renderGridResyncSurfaceIDs: resyncSurfaceIDs, + depthAfterEnqueue: nil ) } - queuedEvents.append(QueuedEvent(topic: topic, coalesceKey: coalesceKey, frame: frame)) + queuedEvents.append( + QueuedEvent( + topic: topic, + coalesceKey: coalesceKey, + frame: frame, + stateSeq: stateSeq + ) + ) queuedByteCount += frame.count + let depthAfterEnqueue = queuedEvents.count if isRenderGrid, isFullRenderGridFrame, let coalesceKey { poisonedRenderGridSurfaceIDs.remove(coalesceKey) resyncAfterDrainSurfaceIDs.remove(coalesceKey) @@ -217,7 +233,8 @@ final class MobileHostConnectionEventQueue: @unchecked Sendable { admitted: true, startDrain: startDrain, shouldClose: false, - renderGridResyncSurfaceIDs: resyncSurfaceIDs + renderGridResyncSurfaceIDs: resyncSurfaceIDs, + depthAfterEnqueue: depthAfterEnqueue ) } diff --git a/Sources/Mobile/MobileHostService.swift b/Sources/Mobile/MobileHostService.swift index 3938c6a45139..9f0a1a32c973 100644 --- a/Sources/Mobile/MobileHostService.swift +++ b/Sources/Mobile/MobileHostService.swift @@ -443,7 +443,8 @@ final class MobileHostService { /// synchronous bounded queues as every other event. nonisolated static func emitRenderGridEvent( framesByAnchor: [MobileTerminalRenderGridFrame.Anchor: (payloadJSON: Data, isFullFrame: Bool)], - surfaceID: String + surfaceID: String, + stateSeq: UInt64 ) { let topic = MobileHostEventTopicPolicy.renderGridTopic guard !framesByAnchor.isEmpty, @@ -462,7 +463,7 @@ final class MobileHostService { encodedByAnchor[anchor] = (frame, item.isFullFrame) } guard !encodedByAnchor.isEmpty else { return } - deliverEventFrames(topic: topic, coalesceKey: surfaceID) { connection in + deliverEventFrames(topic: topic, coalesceKey: surfaceID, stateSeq: stateSeq) { connection in encodedByAnchor[ MobileTerminalRenderGridAnchorRegistry.shared.anchor(connectionID: connection.connectionID) ] @@ -507,7 +508,7 @@ final class MobileHostService { coalesceKey: String?, isFullRenderGridFrame: Bool ) { - deliverEventFrames(topic: topic, coalesceKey: coalesceKey) { _ in + deliverEventFrames(topic: topic, coalesceKey: coalesceKey, stateSeq: nil) { _ in (frame, isFullRenderGridFrame) } } @@ -521,6 +522,7 @@ final class MobileHostService { nonisolated private static func deliverEventFrames( topic: String, coalesceKey: String?, + stateSeq: UInt64?, frameFor: (MobileHostConnection) -> (frame: Data, isFullRenderGridFrame: Bool)? ) { let connections = MobileHostConnectionRegistry.shared.snapshot() @@ -535,8 +537,14 @@ final class MobileHostService { item.frame, topic: topic, coalesceKey: coalesceKey, - isFullRenderGridFrame: item.isFullRenderGridFrame + isFullRenderGridFrame: item.isFullRenderGridFrame, + stateSeq: stateSeq ) + #if DEBUG + if let stateSeq, result.admitted, let depth = result.depthAfterEnqueue { + HostLatencyTrace.stamp("host.enq", "seq=\(stateSeq) depth=\(depth)") + } + #endif resyncSurfaceIDs.formUnion(result.renderGridResyncSurfaceIDs) if result.startDrain { Task { await connection.drainQueuedEvents() } @@ -2384,6 +2392,7 @@ actor MobileHostConnection { coalesceKey: MobileHostService.eventCoalesceKey(topic: topic, payload: payload), isFullRenderGridFrame: topic == MobileHostEventTopicPolicy.renderGridTopic && payload["full"] as? Bool == true, + stateSeq: nil, frame: frame ) if !result.renderGridResyncSurfaceIDs.isEmpty { @@ -2418,12 +2427,14 @@ actor MobileHostConnection { _ frame: Data, topic: String, coalesceKey: String?, - isFullRenderGridFrame: Bool + isFullRenderGridFrame: Bool, + stateSeq: UInt64? ) -> MobileHostEventEnqueueResult { eventQueue.enqueue( topic: topic, coalesceKey: coalesceKey, isFullRenderGridFrame: isFullRenderGridFrame, + stateSeq: stateSeq, frame: frame ) } @@ -2481,10 +2492,21 @@ actor MobileHostConnection { return } guard eventQueue.isSubscribed(topic: event.topic) else { continue } + #if DEBUG + let latencyWriteStart = event.stateSeq == nil ? nil : HostLatencyTrace.captureTime() + #endif guard await deliverQueuedEvent(event) else { eventQueue.abandonDrain() return } + #if DEBUG + if let stateSeq = event.stateSeq { + HostLatencyTrace.stampElapsed( + "host.write", + since: latencyWriteStart + ) { "seq=\(stateSeq) us=\($0)" } + } + #endif let resyncSurfaceIDs = eventQueue.takeResyncAfterDrainRequests() if !resyncSurfaceIDs.isEmpty { MobileTerminalRenderObserver.requestRenderGridFullResync( diff --git a/Sources/Mobile/MobileStateSync.swift b/Sources/Mobile/MobileStateSync.swift index ced29bbaa770..37a0708644a8 100644 --- a/Sources/Mobile/MobileStateSync.swift +++ b/Sources/Mobile/MobileStateSync.swift @@ -97,6 +97,13 @@ final class MobileStateSyncHost { removedIDs: change.removedIDs ) guard let payload = try? MobileSyncFrameCoder().jsonObject(from: event) else { return } + #if DEBUG + HostLatencyTrace.stamp( + "host.sync.emit", + "coll=\(collection.rawValue) rev=\(change.toRev) " + + "rows=\(change.records.count + change.removedIDs.count)" + ) + #endif MobileHostService.shared.emitEvent(topic: Self.deltaTopic, payload: payload) } diff --git a/Sources/Mobile/MobileTerminalByteTee.swift b/Sources/Mobile/MobileTerminalByteTee.swift index 5184982878d5..24bf4847d8e6 100644 --- a/Sources/Mobile/MobileTerminalByteTee.swift +++ b/Sources/Mobile/MobileTerminalByteTee.swift @@ -179,6 +179,9 @@ final class MobileTerminalByteTee { state.replayBuffer.removeFirst(state.replayBuffer.count - replayBudget) } statesBySurfaceID[surfaceID] = state + #if DEBUG + HostLatencyTrace.stamp("host.tee", "seq=\(state.seq) bytes=\(data.count)") + #endif MobileTerminalRenderObserver.shared.noteTerminalBytes(surfaceID: surfaceID) if let continuations = laneContinuationsBySurfaceID[surfaceID] { diff --git a/Sources/Mobile/MobileTerminalRenderObserver.swift b/Sources/Mobile/MobileTerminalRenderObserver.swift index f1ce3f531d99..4b4760730dde 100644 --- a/Sources/Mobile/MobileTerminalRenderObserver.swift +++ b/Sources/Mobile/MobileTerminalRenderObserver.swift @@ -209,6 +209,9 @@ final class MobileTerminalRenderObserver { } private func flushTerminalUpdates() { + #if DEBUG + HostLatencyTrace.stamp("host.flush", "pending=\(pendingSurfaceIDs.count)") + #endif isEmitFlushScheduled = false guard hasAnyRenderEventSubscribers else { refreshNotificationDemand() @@ -301,6 +304,9 @@ final class MobileTerminalRenderObserver { var surfaceIDString: String? for anchor in anchors { + #if DEBUG + let latencyExportStart = HostLatencyTrace.captureTime() + #endif guard let emitted = emitRenderGridFrame( surface: surface, surfaceID: surfaceID, @@ -312,6 +318,15 @@ final class MobileTerminalRenderObserver { sharedTheme: &sharedTheme ) else { continue } guard let payloadJSON = try? JSONEncoder().encode(emitted) else { continue } + #if DEBUG + HostLatencyTrace.stampElapsed( + "host.grid", + since: latencyExportStart + ) { + "seq=\(emitted.stateSeq) exp_us=\($0) bytes=\(payloadJSON.count) " + + "kind=\(emitted.full ? "full" : "delta")" + } + #endif framesByAnchor[anchor] = (payloadJSON, emitted.full) emittedByAnchor[anchor] = emitted surfaceIDString = emitted.surfaceID @@ -319,7 +334,8 @@ final class MobileTerminalRenderObserver { guard !framesByAnchor.isEmpty, let surfaceIDString else { return } MobileHostService.emitRenderGridEvent( framesByAnchor: framesByAnchor, - surfaceID: surfaceIDString + surfaceID: surfaceIDString, + stateSeq: stateSeq ) #if DEBUG for (anchor, frame) in emittedByAnchor { diff --git a/Sources/Mobile/MobileWorkspaceListObserver.swift b/Sources/Mobile/MobileWorkspaceListObserver.swift index f6cbbf3e6d53..0b7d17d5b4fc 100644 --- a/Sources/Mobile/MobileWorkspaceListObserver.swift +++ b/Sources/Mobile/MobileWorkspaceListObserver.swift @@ -312,6 +312,9 @@ final class MobileWorkspaceListObserver { } private func emitIfNeeded(force: Bool) { + #if DEBUG + HostLatencyTrace.stamp("host.sync.observe") + #endif let signpost = MobileWorkspaceObserverSignposts.begin("mobile-workspace-emit-if-needed", "force=\(force)"); defer { MobileWorkspaceObserverSignposts.end(signpost) } guard let tabManager else { return } let hash = Self.summaryHash( diff --git a/Sources/TerminalController.swift b/Sources/TerminalController.swift index 8324d70093f2..9fa4efb1bbd3 100644 --- a/Sources/TerminalController.swift +++ b/Sources/TerminalController.swift @@ -14826,6 +14826,9 @@ class TerminalController { guard let text = v2RawString(params, "text"), !text.isEmpty else { return .err(code: "invalid_params", message: "Missing text", data: nil) } + #if DEBUG + HostLatencyTrace.stamp("host.in.recv", "bytes=\(text.utf8.count)") + #endif if let error = mobileWorkspaceIDValidationError(params: params) { return error } @@ -14869,6 +14872,9 @@ class TerminalController { ] if let seq = MobileTerminalByteTee.shared.currentSequence(surfaceID: surfaceId) { payload["terminal_seq"] = seq + #if DEBUG + HostLatencyTrace.stamp("host.in.applied", "seq=\(seq)") + #endif } return .ok(payload) } diff --git a/cmux.xcodeproj/project.pbxproj b/cmux.xcodeproj/project.pbxproj index 426b4582ad8e..fd0c91616118 100644 --- a/cmux.xcodeproj/project.pbxproj +++ b/cmux.xcodeproj/project.pbxproj @@ -1095,6 +1095,7 @@ C0DE71B10000000000000001 /* AppDelegate+AgentChatNotifications.swift in Sources CD0CFE6000000000CD0CFE60 /* HostAccountFlow.swift in Sources */ = {isa = PBXBuildFile; fileRef = CD0CFE6100000000CD0CFE61 /* HostAccountFlow.swift */; }; B1F0C0030000000000000001 /* HostedInspectorDockControlScript.swift in Sources */ = {isa = PBXBuildFile; fileRef = B1F0C0030000000000000002 /* HostedInspectorDockControlScript.swift */; }; B1F0C0040000000000000001 /* HostedInspectorDockControlScriptTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = B1F0C0040000000000000002 /* HostedInspectorDockControlScriptTests.swift */; }; + F17A00000000000000000002 /* HostLatencyTrace.swift in Sources */ = {isa = PBXBuildFile; fileRef = F17A00000000000000000001 /* HostLatencyTrace.swift */; }; CD0CFE6200000000CD0CFE62 /* HostSettingsActions.swift in Sources */ = {isa = PBXBuildFile; fileRef = CD0CFE6300000000CD0CFE63 /* HostSettingsActions.swift */; }; 809100000000000000000001 /* HostSettingsShortcutNotificationTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = 809100000000000000000002 /* HostSettingsShortcutNotificationTests.swift */; }; F1C1AA21B7E84D10A1C10001 /* InactivePaneFirstClickFocusTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = F1C1AA20B7E84D10A1C10001 /* InactivePaneFirstClickFocusTests.swift */; }; @@ -3514,6 +3515,7 @@ C0DE71B10000000000000002 /* AppDelegate+AgentChatNotifications.swift */ = {isa = CD0CFE6100000000CD0CFE61 /* HostAccountFlow.swift */ = {isa = PBXFileReference; includeInIndex = 1; lastKnownFileType = sourcecode.swift; path = HostAccountFlow.swift; sourceTree = ""; }; B1F0C0030000000000000002 /* HostedInspectorDockControlScript.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = App/HostedInspectorDockControlScript.swift; sourceTree = ""; }; B1F0C0040000000000000002 /* HostedInspectorDockControlScriptTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = HostedInspectorDockControlScriptTests.swift; sourceTree = ""; }; + F17A00000000000000000001 /* HostLatencyTrace.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = App/HostLatencyTrace.swift; sourceTree = ""; }; CD0CFE6300000000CD0CFE63 /* HostSettingsActions.swift */ = {isa = PBXFileReference; includeInIndex = 1; lastKnownFileType = sourcecode.swift; path = HostSettingsActions.swift; sourceTree = ""; }; 809100000000000000000002 /* HostSettingsShortcutNotificationTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = HostSettingsShortcutNotificationTests.swift; sourceTree = ""; }; F1C1AA20B7E84D10A1C10001 /* InactivePaneFirstClickFocusTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = InactivePaneFirstClickFocusTests.swift; sourceTree = ""; }; @@ -5481,6 +5483,7 @@ C0DE71B10000000000000002 /* AppDelegate+AgentChatNotifications.swift */ = {isa = 895500000000000000000004 /* MainWindowController.swift */, A6D1F0000000000000000001 /* ReleasingWindowController.swift */, A500D011A1B2C3D4E5F60718 /* DebugLogging.swift */, + F17A00000000000000000001 /* HostLatencyTrace.swift */, D35B71010000000000000002 /* StartupBreadcrumbLog.swift */, A78C41010000000000000002 /* MacSentryStartupPolicy.swift */, A50016B0A1B2C3D4E5F60718 /* SessionSnapshotDebugBenchmark.swift */, @@ -8457,6 +8460,7 @@ C0DE71B10000000000000002 /* AppDelegate+AgentChatNotifications.swift */ = {isa = F5320000A1B2C3D4E5F60718 /* HermesAgentIndex.swift in Sources */, CD0CFE6000000000CD0CFE60 /* HostAccountFlow.swift in Sources */, B1F0C0030000000000000001 /* HostedInspectorDockControlScript.swift in Sources */, + F17A00000000000000000002 /* HostLatencyTrace.swift in Sources */, CD0CFE6200000000CD0CFE62 /* HostSettingsActions.swift in Sources */, C0DEA7720000000000000001 /* InternalFlagsWindow.swift in Sources */, 4D8B37E0E11A29997632765F /* InternalTabDragConfiguration.swift in Sources */, diff --git a/scripts/mobile-latency-trace/README.md b/scripts/mobile-latency-trace/README.md new file mode 100644 index 000000000000..eabe106509dd --- /dev/null +++ b/scripts/mobile-latency-trace/README.md @@ -0,0 +1,47 @@ +# Mobile latency tracing + +Tracing is DEBUG-only and off by default. For a tagged Mac build, enable it for +that bundle and relaunch: + +```bash +defaults write com.cmuxterm.app.debug.slat cmux.debug.latency-trace -bool true +./scripts/reload.sh --tag slat --launch +``` + +`CMUX_LATENCY_TRACE=1` is the equivalent process environment gate. The Mac log +is `/tmp/cmux-debug-slat.log`. + +For an iOS Simulator, enable tracing and the optional typing probe at launch: + +```bash +SIMCTL_CHILD_CMUX_LATENCY_TRACE=1 \ +SIMCTL_CHILD_CMUX_LATENCY_PROBE=40:250 \ +xcrun simctl launch +``` + +The probe waits for a connected shell with a mounted terminal, waits another +three seconds, then sends the configured number of single characters through +the production input path. + +Find the simulator log with: + +```bash +data_dir="$(xcrun simctl get_app_container data)" +ios_log="$data_dir/Library/Application Support/cmux-debug.log" +``` + +Simulator and Mac uptime share a clock domain, so analyze with `--same-clock`: + +```bash +python3 scripts/mobile-latency-trace/analyze.py \ + --mac-log /tmp/cmux-debug-slat.log \ + --ios-log "$ios_log" \ + --same-clock +``` + +Omit `--same-clock` for physical-iPhone captures. Add `--json` for raw joined +duration arrays. Run the embedded fixture check with: + +```bash +python3 scripts/mobile-latency-trace/analyze.py --selftest +``` diff --git a/scripts/mobile-latency-trace/analyze.py b/scripts/mobile-latency-trace/analyze.py new file mode 100755 index 000000000000..281a8bb2d611 --- /dev/null +++ b/scripts/mobile-latency-trace/analyze.py @@ -0,0 +1,581 @@ +#!/usr/bin/env python3 +"""Analyze cmux iOS↔Mac latency trace stamps.""" + +from __future__ import annotations + +import argparse +import json +import math +import re +import sys +from dataclasses import dataclass +from pathlib import Path +from typing import Callable, Iterable + + +LINE_RE = re.compile(r"LAT\s+(?P\S+)\s+t=(?P