Fix per-keystroke render-grid replay loop on iOS, instrument sync latency

Packages/iOS/CmuxMobileDiagnostics/Sources/CmuxMobileDiagnostics/MobileDebugLogSink.swift

@@ -91,16 +91,32 @@ public actor MobileDebugLogSink {
     /// file logging is configured, the same line is also appended to disk before
     /// this method returns.
     public func append(_ message: String) {
+        appendMessages(CollectionOfOne(message))
+    }
+
+    /// Append a batch while holding actor ownership across the whole write.
+    ///
+    /// Latency tracing uses this internal path so its single consumer can
+    /// forward a drained batch without spawning one task per trace line.
+    func appendBatch(_ messages: [String]) {
+        appendMessages(messages)
+    }
+
+    private func appendMessages<Messages: Collection>(_ messages: Messages)
+    where Messages.Element == String {
+        guard !messages.isEmpty else { return }
         let elapsed = String(format: "%9.3f", now().timeIntervalSince(startedAt))
-        let line = "[\(elapsed)] \(message)"
-        buffer.append(line)
+        let lines = messages.map { "[\(elapsed)] \($0)" }
+        buffer.append(contentsOf: lines)
         if buffer.count > capacity {
             buffer.removeFirst(buffer.count - capacity)
         }
-        for continuation in continuations.values {
-            continuation.yield(line)
+        for line in lines {
+            for continuation in continuations.values {
+                continuation.yield(line)
+            }
+            appendToFile(line)
         }
-        appendToFile(line)
     }
 
     /// The full buffer as newline-joined text, newest last.

Packages/iOS/CmuxMobileDiagnostics/Sources/CmuxMobileDiagnostics/MobileLatencyTrace.swift

@@ -0,0 +1,118 @@
+import Dispatch
+import Foundation
+
+/// Low-overhead, opt-in latency stamps for DEBUG mobile builds.
+public enum MobileLatencyTrace {
+    #if DEBUG
+    private static let writer = MobileLatencyTraceWriter(capacity: 4_096)
+    #endif
+
+    /// 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 when tracing is enabled.
+    ///
+    /// - 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
+        guard isEnabled else { return }
+        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 isEnabled else { return }
+        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)"
+        writer.enqueue("LAT \(stage) t=\(uptimeMicroseconds)\(suffix)")
+    }
+    #endif
+}

Packages/iOS/CmuxMobileDiagnostics/Sources/CmuxMobileDiagnostics/MobileLatencyTraceWriter.swift

@@ -0,0 +1,92 @@
+#if DEBUG
+import Foundation
+internal import os
+
+/// Fixed-capacity producer buffer for synchronous latency-trace call sites.
+final class MobileLatencyTraceWriter: Sendable {
+    private struct State: Sendable {
+        var entries: [String?]
+        var head = 0
+        var count = 0
+        var droppedCount = 0
+        var consumerStarted = false
+
+        init(capacity: Int) {
+            entries = Array(repeating: nil, count: capacity)
+        }
+
+        mutating func enqueue(_ line: String) {
+            guard count < entries.count else {
+                droppedCount += 1
+                return
+            }
+            entries[(head + count) % entries.count] = line
+            count += 1
+        }
+
+        mutating func drain(maximumCount: Int) -> [String]? {
+            guard count > 0 || droppedCount > 0 else { return nil }
+            var lines: [String] = []
+            lines.reserveCapacity(min(count, maximumCount) + (droppedCount > 0 ? 1 : 0))
+            if droppedCount > 0 {
+                let uptimeMicroseconds = DispatchTime.now().uptimeNanoseconds / 1_000
+                lines.append(
+                    "LAT trace.dropped t=\(uptimeMicroseconds) n=\(droppedCount) side=ios"
+                )
+                droppedCount = 0
+            }
+            let drainedCount = min(count, maximumCount)
+            for _ in 0..<drainedCount {
+                if let line = entries[head] {
+                    lines.append(line)
+                }
+                entries[head] = nil
+                head = (head + 1) % entries.count
+                count -= 1
+            }
+            return lines
+        }
+    }
+
+    private static let batchSize = 128
+    // lint:allow lock - trace stamps are synchronous hot-path callbacks; this
+    // lock guards only bounded O(1) ring-buffer bookkeeping and never performs I/O.
+    private let state: OSAllocatedUnfairLock<State>
+    private let signals: AsyncStream<Void>
+    private let signalContinuation: AsyncStream<Void>.Continuation
+
+    init(capacity: Int) {
+        precondition(capacity > 0)
+        state = OSAllocatedUnfairLock(initialState: State(capacity: capacity))
+        (signals, signalContinuation) = AsyncStream.makeStream(
+            bufferingPolicy: .bufferingNewest(1)
+        )
+    }
+
+    @inline(__always)
+    func enqueue(_ line: String) {
+        let shouldStartConsumer = state.withLock { state in
+            state.enqueue(line)
+            guard !state.consumerStarted else { return false }
+            state.consumerStarted = true
+            return true
+        }
+        if shouldStartConsumer {
+            Task.detached { [self] in
+                await consume()
+            }
+        }
+        signalContinuation.yield()
+    }
+
+    private func consume() async {
+        for await _ in signals {
+            while let batch = state.withLock({
+                $0.drain(maximumCount: Self.batchSize)
+            }) {
+                await MobileDebugLog.shared.sink.appendBatch(batch)
+            }
+        }
+    }
+}
+#endif

Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileLatencyProbe.swift

@@ -0,0 +1,53 @@
+#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
+    private static var hasAutoNavigatedProcessRun = false
+
+    static var hasUnclaimedConfiguration: Bool {
+        configuration != nil && !hasClaimedProcessRun
+    }
+
+    static func claimAutoNavigation() -> Bool {
+        guard hasUnclaimedConfiguration, !hasAutoNavigatedProcessRun else {
+            return false
+        }
+        hasAutoNavigatedProcessRun = true
+        return true
+    }
+
+    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

Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+LatencyProbe.swift

@@ -0,0 +1,78 @@
+#if DEBUG
+import CmuxMobileDiagnostics
+import Foundation
+
+extension MobileShellComposite {
+    func startLatencyProbeAutoNavigationIfNeeded() {
+        guard connectionState == .connected,
+              latencyProbeAutoNavigationTask == nil,
+              MobileLatencyProbe.hasUnclaimedConfiguration,
+              terminalOutputStreamTokensBySurfaceID.isEmpty,
+              deeplinkWorkspaceNavigationRequest == nil,
+              workspaces.contains(where: { !$0.terminals.isEmpty }) else {
+            return
+        }
+        latencyProbeAutoNavigationTask = Task { @MainActor [weak self] in
+            defer { self?.latencyProbeAutoNavigationTask = nil }
+            do {
+                try await Task.sleep(for: .seconds(1))
+                guard let self,
+                      self.connectionState == .connected,
+                      self.terminalOutputStreamTokensBySurfaceID.isEmpty,
+                      self.deeplinkWorkspaceNavigationRequest == nil,
+                      let workspaceID = self.workspaces.first(where: {
+                          !$0.terminals.isEmpty
+                      })?.id,
+                      MobileLatencyProbe.claimAutoNavigation() else {
+                    return
+                }
+                self.navigateToWorkspaceForDeeplink(workspaceID, origin: .external)
+            } catch {
+                return
+            }
+        }
+    }
+
+    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..<configuration.count {
+                    try Task.checkCancellation()
+                    guard let self,
+                          self.connectionState == .connected,
+                          self.hasTerminalOutputSink(surfaceID: surfaceID) else {
+                        return
+                    }
+                    MobileLatencyTrace.stamp("probe.send", "i=\(index)")
+                    self.sendTerminalRawInput(
+                        MobileLatencyProbe.input(at: index),
+                        surfaceID: surfaceID
+                    )
+                    if index + 1 < configuration.count {
+                        try await Task.sleep(
+                            for: .milliseconds(configuration.intervalMilliseconds)
+                        )
+                    }
+                }
+            } catch {
+                return
+            }
+        }
+    }
+
+    func cancelLatencyProbe() {
+        latencyProbeAutoNavigationTask?.cancel()
+        latencyProbeAutoNavigationTask = nil
+        latencyProbeTask?.cancel()
+        latencyProbeTask = nil
+    }
+}
+#endif