From cfe4a86e6f20f3a299fa1cada83a0868da54b37b Mon Sep 17 00:00:00 2001 From: Abdulaziz Albahar <67667005+azooz2003-bit@users.noreply.github.com> Date: Wed, 23 Sep 2026 12:21:23 -0700 Subject: [PATCH 1/6] telemetry(ios): make a stalled terminal replay visible in Axiom A blank terminal with a blinking cursor is a surface the phone rebuilt blank waiting on a `mobile.terminal.replay` response that has not come back. Only the replay repaints it, and the replay barrier suppresses live output while it is outstanding, so the whole episode lasts exactly as long as that one RPC. None of it reached Axiom. Every terminal trace phase is terminal, so `MobileTerminalTraceReporter` emitted a row only once an operation settled and the worst stalls (the ones that never settle) produced nothing. The replay lifecycle logs that would have explained them are all `#if DEBUG`, so internal and TestFlight builds record none of it. In a 5-day window on one phone's local diagnostics, 305 replays never received a response and 441 episodes ran past 5s with a median of 34s; Axiom could account for none of them. Adds, without changing delivery behavior: - `DiagnosticTerminalTracePhase.stalled`, stamped by a probe at bounded marks while a replay is outstanding. It is deliberately non-terminal: the pending start survives so the settled phase still reports. - `MobileTerminalReplayTrigger` plus a packed trace context, so each row names the codepath that asked for the replay, whether the surface was rebuilt blank (a blank screen, not merely stale text), whether a barrier is suppressing output, and the retry index. Every one of the 23 replay request sites now declares its trigger; the parameter is required, so a new codepath cannot silently report `unknown`. - `host_elapsed_ms` on the replay response, stamped as `hostCaptureFinished`, splitting a slow Mac capture from a slow or stalled transport. The Mac already measured this and kept it local. - The matching web contract: new outcome, phases, and fields, validated and exported as span attributes. The probe uses the injected control-plane clock and is cancelled whenever the request settles or is replaced. --- .../DiagnosticTerminalTrace.swift | 7 ++ .../MobileTerminalReplayTrace.swift | 102 ++++++++++++++++ ...obileTerminalReplayTraceContextTests.swift | 65 ++++++++++ .../MobileTerminalTraceReporter.swift | 39 +++++- .../MobileTerminalTraceStallTests.swift | 113 ++++++++++++++++++ .../MobileTerminalReplayResponse.swift | 12 ++ .../MobileShellComposite+AppDiagnostics.swift | 26 ++++ .../MobileShellComposite+TerminalLane.swift | 2 + ...hellComposite+TerminalOutputDelivery.swift | 52 ++++++-- ...ellComposite+TerminalReplayLifecycle.swift | 47 ++++++-- ...leShellComposite+TerminalReplayRetry.swift | 6 +- ...llComposite+TerminalReplayStallProbe.swift | 97 +++++++++++++++ ...obileShellComposite+TerminalViewport.swift | 18 ++- ...ShellComposite+WorkspaceListRecovery.swift | 6 +- .../MobileShellComposite.swift | 51 +++++++- Sources/TerminalController.swift | 6 + .../observability/mobileNetworkOutcome.ts | 60 +++++++++- .../mobile-replay-stall-observability.test.ts | 68 +++++++++++ 18 files changed, 745 insertions(+), 32 deletions(-) create mode 100644 Packages/Shared/CMUXMobileCore/Sources/CMUXMobileCore/MobileTerminalReplayTrace.swift create mode 100644 Packages/Shared/CMUXMobileCore/Tests/CMUXMobileCoreTests/MobileTerminalReplayTraceContextTests.swift create mode 100644 Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift create mode 100644 Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayStallProbe.swift create mode 100644 web/tests/mobile-replay-stall-observability.test.ts diff --git a/Packages/Shared/CMUXMobileCore/Sources/CMUXMobileCore/DiagnosticTerminalTrace.swift b/Packages/Shared/CMUXMobileCore/Sources/CMUXMobileCore/DiagnosticTerminalTrace.swift index 3bb85bfc2063..d00465a60ef1 100644 --- a/Packages/Shared/CMUXMobileCore/Sources/CMUXMobileCore/DiagnosticTerminalTrace.swift +++ b/Packages/Shared/CMUXMobileCore/Sources/CMUXMobileCore/DiagnosticTerminalTrace.swift @@ -18,6 +18,13 @@ public enum DiagnosticTerminalTracePhase: Int, Sendable, Codable, CaseIterable { case applied = 7 case failed = 8 case discarded = 9 + /// The operation is still in flight past a stall threshold. + /// + /// Unlike every other phase this is not terminal: it is emitted by a + /// probe while the request is outstanding, so an operation that never + /// settles still produces evidence. A settled operation emits its real + /// terminal phase afterwards. + case stalled = 10 } /// A short opaque ID that can safely cross the mobile RPC boundary. diff --git a/Packages/Shared/CMUXMobileCore/Sources/CMUXMobileCore/MobileTerminalReplayTrace.swift b/Packages/Shared/CMUXMobileCore/Sources/CMUXMobileCore/MobileTerminalReplayTrace.swift new file mode 100644 index 000000000000..0df7112bf62b --- /dev/null +++ b/Packages/Shared/CMUXMobileCore/Sources/CMUXMobileCore/MobileTerminalReplayTrace.swift @@ -0,0 +1,102 @@ +import Foundation + +/// Why a terminal replay was requested. +/// +/// A replay is the only path that repaints a surface the phone has just +/// rebuilt blank, so the trigger is the difference between "the user is +/// looking at a blank terminal" and "the user is looking at slightly stale +/// text". Values are stable on the wire: they are packed into the terminal +/// trace's payload slot and read back in the analytics pipeline. +/// Raw values are never reused: a removed case leaves its number retired so a +/// newer producer cannot be misread as an older codepath. +public enum MobileTerminalReplayTrigger: Int, Sendable, Codable, CaseIterable { + /// No reason was recorded. Nothing produces this today; it is the + /// well-defined zero so an empty payload slot decodes without inventing a + /// codepath. + case unknown = 0 + /// The output stream reset; the surface was rebuilt blank. + case outputReset = 1 + /// The render pipeline reset; the surface was rebuilt blank. + case renderPipelineReset = 2 + /// A viewport transition armed a barrier and re-requested state. + case viewportTransition = 3 + /// A render-grid delta did not chain onto the delivered revision. + case revisionChainBreak = 4 + /// A render-grid delta did not chain onto the delivered history rows. + case historyChainBreak = 5 + /// First attach to a surface with no delivered baseline. + case coldAttach = 6 + /// A previous replay attempt failed or came back unusable. + case failureRetry = 7 + /// The phone dropped a delivered frame before it reached the grid. + case droppedFrame = 8 + /// The grid apply contract rejected a frame at paint time. + case applyFenceFailure = 9 + /// Pending input never echoed, so the mirror is presumed diverged. + case pendingInputDrop = 10 + /// The event subscription was re-established. + case resubscribe = 11 + /// The Mac left the alternate screen, so the primary baseline is unknown. + case screenTransition = 14 + /// A render-grid delta arrived with no delivered baseline to patch. + case missingBaseline = 15 + /// A gap in the byte stream needs an authoritative screen to verify it. + case byteGap = 16 +} + +/// Categorical context recorded alongside one replay trace. +/// +/// The terminal trace event carries a single integer payload slot, so this +/// packs the fields that decide whether a slow replay is user-visible. The +/// encoding is stable on the wire and round-trips through ``encoded``. +public struct MobileTerminalReplayTraceContext: Equatable, Sendable { + /// Highest retry attempt the encoding can represent. + public static let maxAttempt = 15 + + /// Why this replay was requested. + public let trigger: MobileTerminalReplayTrigger + /// Whether the surface had been rebuilt blank when the replay was + /// requested. A slow replay on a blank surface is the blank-screen stall; + /// a slow replay on a painted surface only holds back fresh output. + public let surfaceIsBlank: Bool + /// Whether a replay barrier is suppressing live output for this surface. + public let barrierActive: Bool + /// Zero-based retry index within the current replay episode. + public let attempt: Int + + public init( + trigger: MobileTerminalReplayTrigger, + surfaceIsBlank: Bool, + barrierActive: Bool, + attempt: Int + ) { + self.trigger = trigger + self.surfaceIsBlank = surfaceIsBlank + self.barrierActive = barrierActive + self.attempt = min(max(0, attempt), Self.maxAttempt) + } + + /// Packs the context into one non-negative integer payload slot. + public var encoded: Int { + var value = trigger.rawValue & 0xFF + if surfaceIsBlank { value |= 1 << 8 } + if barrierActive { value |= 1 << 9 } + value |= (attempt & 0xF) << 10 + return value + } + + /// Unpacks a context previously produced by ``encoded``. + /// + /// Returns `nil` for a negative value or an unknown trigger so a future + /// producer cannot be silently misread as `unknown` by an older consumer. + public init?(encoded: Int) { + guard encoded >= 0, + let trigger = MobileTerminalReplayTrigger(rawValue: encoded & 0xFF) else { + return nil + } + self.trigger = trigger + self.surfaceIsBlank = (encoded & (1 << 8)) != 0 + self.barrierActive = (encoded & (1 << 9)) != 0 + self.attempt = (encoded >> 10) & 0xF + } +} diff --git a/Packages/Shared/CMUXMobileCore/Tests/CMUXMobileCoreTests/MobileTerminalReplayTraceContextTests.swift b/Packages/Shared/CMUXMobileCore/Tests/CMUXMobileCoreTests/MobileTerminalReplayTraceContextTests.swift new file mode 100644 index 000000000000..11b63402089a --- /dev/null +++ b/Packages/Shared/CMUXMobileCore/Tests/CMUXMobileCoreTests/MobileTerminalReplayTraceContextTests.swift @@ -0,0 +1,65 @@ +import Testing + +@testable import CMUXMobileCore + +@Suite("Replay trace context encoding") +struct MobileTerminalReplayTraceContextTests { + @Test func everyTriggerRoundTripsWithBothFlags() { + for trigger in MobileTerminalReplayTrigger.allCases { + for blank in [true, false] { + for barrier in [true, false] { + let context = MobileTerminalReplayTraceContext( + trigger: trigger, + surfaceIsBlank: blank, + barrierActive: barrier, + attempt: 3 + ) + #expect(MobileTerminalReplayTraceContext(encoded: context.encoded) == context) + } + } + } + } + + @Test func attemptClampsToTheEncodableRange() { + let context = MobileTerminalReplayTraceContext( + trigger: .failureRetry, + surfaceIsBlank: true, + barrierActive: true, + attempt: 99 + ) + #expect(context.attempt == MobileTerminalReplayTraceContext.maxAttempt) + #expect(MobileTerminalReplayTraceContext(encoded: context.encoded) == context) + } + + @Test func negativeAttemptClampsToZero() { + let context = MobileTerminalReplayTraceContext( + trigger: .coldAttach, + surfaceIsBlank: false, + barrierActive: false, + attempt: -4 + ) + #expect(context.attempt == 0) + #expect(context.encoded == MobileTerminalReplayTrigger.coldAttach.rawValue) + } + + /// An older consumer must not read a future trigger as `unknown`: that + /// would silently attribute a new codepath's stalls to the wrong bucket. + @Test func unknownTriggerDecodesToNilRatherThanUnknown() { + let futureTrigger = 0xFE + #expect(MobileTerminalReplayTraceContext(encoded: futureTrigger) == nil) + #expect(MobileTerminalReplayTraceContext(encoded: -1) == nil) + } + + @Test func flagsAreIndependentOfTheTriggerBits() { + let blankOnly = MobileTerminalReplayTraceContext( + trigger: .outputReset, surfaceIsBlank: true, barrierActive: false, attempt: 0 + ) + let barrierOnly = MobileTerminalReplayTraceContext( + trigger: .outputReset, surfaceIsBlank: false, barrierActive: true, attempt: 0 + ) + #expect(blankOnly.encoded != barrierOnly.encoded) + #expect(MobileTerminalReplayTraceContext(encoded: blankOnly.encoded)?.surfaceIsBlank == true) + #expect(MobileTerminalReplayTraceContext(encoded: barrierOnly.encoded)?.surfaceIsBlank == false) + #expect(MobileTerminalReplayTraceContext(encoded: barrierOnly.encoded)?.barrierActive == true) + } +} diff --git a/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift b/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift index c57e7e65625b..c4acc447d730 100644 --- a/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift +++ b/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift @@ -17,6 +17,7 @@ public final class MobileTerminalTraceReporter: Sendable { private struct Start: Sendable { let operation: DiagnosticTerminalTraceOperation let tNanos: UInt64 + let replayContext: MobileTerminalReplayTraceContext? } private struct State: Sendable { @@ -59,6 +60,7 @@ public final class MobileTerminalTraceReporter: Sendable { let terminalPhase: DiagnosticTerminalTracePhase let durationMilliseconds: UInt32 let outcome: String + let replayContext: MobileTerminalReplayTraceContext? } private let emitter: any AnalyticsEmitting @@ -103,9 +105,31 @@ public final class MobileTerminalTraceReporter: Sendable { let oldest = state.starts.min(by: { $0.value.tNanos < $1.value.tNanos })?.key { state.starts.removeValue(forKey: oldest) } - state.starts[traceID.rawValue] = Start(operation: operation, tNanos: event.tNanos) + state.starts[traceID.rawValue] = Start( + operation: operation, + tNanos: event.tNanos, + replayContext: event.c.flatMap(MobileTerminalReplayTraceContext.init(encoded:)) + ) return nil } + // A stall report is the only non-terminal emission: the operation is + // still outstanding, so the pending start must survive for the phase + // that eventually settles it. Without this an operation that never + // settles produced no row at all. + if phase == .stalled { + guard let duration = event.ms else { return nil } + guard admitEmission(at: event.tNanos, state: &state) else { return nil } + let start = state.starts[traceID.rawValue] + return Observation( + traceID: traceID, + operation: start?.operation ?? operation, + terminalPhase: phase, + durationMilliseconds: duration, + outcome: "stalled", + replayContext: event.c.flatMap(MobileTerminalReplayTraceContext.init(encoded:)) + ?? start?.replayContext + ) + } guard phase == .applied || phase == .failed || phase == .discarded else { return nil } let start = state.starts.removeValue(forKey: traceID.rawValue) // Prefer the monotonic diagnostic timestamps whenever the start phase @@ -124,7 +148,8 @@ public final class MobileTerminalTraceReporter: Sendable { operation: start?.operation ?? operation, terminalPhase: phase, durationMilliseconds: duration, - outcome: outcome + outcome: outcome, + replayContext: start?.replayContext ) } @@ -140,7 +165,7 @@ public final class MobileTerminalTraceReporter: Sendable { } private static func properties(for observation: Observation) -> [String: AnalyticsValue] { - [ + var properties: [String: AnalyticsValue] = [ "phase": .string(tracePhase), "outcome": .string(observation.outcome), "duration_ms": .int(Int(observation.durationMilliseconds)), @@ -149,5 +174,13 @@ public final class MobileTerminalTraceReporter: Sendable { "operation": .string(String(describing: observation.operation)), "terminal_phase": .string(String(describing: observation.terminalPhase)), ] + if let context = observation.replayContext { + properties["replay_trigger"] = .string(String(describing: context.trigger)) + // The field that separates a blank terminal from a stale one. + properties["surface_blank"] = .bool(context.surfaceIsBlank) + properties["barrier_active"] = .bool(context.barrierActive) + properties["replay_attempt"] = .int(context.attempt) + } + return properties } } diff --git a/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift b/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift new file mode 100644 index 000000000000..33f4480b1bed --- /dev/null +++ b/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift @@ -0,0 +1,113 @@ +import CMUXMobileCore +import Testing + +@testable import CmuxMobileAnalytics + +private struct StallTestConsent: AnalyticsConsentProviding { + let isTelemetryEnabled: Bool +} + +/// A replay that never settles is the blank-terminal stall. These cover the +/// emission path that makes it visible at all. +@Suite("Terminal replay stall reporting") +struct MobileTerminalTraceStallTests { + private func makeReporter() -> (MobileTerminalTraceReporter, RecordingAnalyticsUploader) { + let uploader = RecordingAnalyticsUploader() + let emitter = AnalyticsEmitter( + uploader: uploader, + consent: StallTestConsent(isTelemetryEnabled: true), + anonymousID: "local-install" + ) + return (MobileTerminalTraceReporter(emitter: emitter), uploader) + } + + private func event( + _ phase: DiagnosticTerminalTracePhase, + at tNanos: UInt64, + trace: DiagnosticTerminalTraceID, + ms: UInt32? = nil, + c: Int? = nil + ) -> DiagnosticEvent { + DiagnosticEvent( + code: .terminalTrace, + tNanos: tNanos, + ms: ms, + a: DiagnosticTerminalTraceOperation.replay.rawValue, + b: phase.rawValue, + c: c, + traceID: trace.rawValue + ) + } + + @Test func aReplayThatNeverSettlesStillReportsToAxiom() async { + let (reporter, uploader) = makeReporter() + let trace = DiagnosticTerminalTraceID(rawValue: 0xB1A4)! + let context = MobileTerminalReplayTraceContext( + trigger: .outputReset, surfaceIsBlank: true, barrierActive: true, attempt: 0 + ) + reporter.ingest(event(.started, at: 1_000_000_000, trace: trace, c: context.encoded)) + reporter.ingest(event(.stalled, at: 3_000_000_000, trace: trace, ms: 2_000, c: context.encoded)) + reporter.ingest(event(.stalled, at: 31_000_000_000, trace: trace, ms: 30_000, c: context.encoded)) + await reporter.flush() + + let values = await uploader.uploadedEvents + #expect(values.count == 2) + #expect(values.allSatisfy { $0.properties["outcome"] == .string("stalled") }) + #expect(values.allSatisfy { $0.properties["terminal_phase"] == .string("stalled") }) + #expect(values.first?.properties["duration_ms"] == .int(2_000)) + #expect(values.last?.properties["duration_ms"] == .int(30_000)) + // The fields that separate a blank terminal from merely stale text. + #expect(values.first?.properties["surface_blank"] == .bool(true)) + #expect(values.first?.properties["barrier_active"] == .bool(true)) + #expect(values.first?.properties["replay_trigger"] == .string("outputReset")) + #expect(values.first?.properties["replay_attempt"] == .int(0)) + } + + /// A stall report must not consume the pending start: the settled phase + /// still has to report, and its duration must still span from `started`. + @Test func stallReportDoesNotSwallowTheSettledPhase() async { + let (reporter, uploader) = makeReporter() + let trace = DiagnosticTerminalTraceID(rawValue: 0xB1A5)! + let context = MobileTerminalReplayTraceContext( + trigger: .coldAttach, surfaceIsBlank: true, barrierActive: false, attempt: 2 + ) + reporter.ingest(event(.started, at: 1_000_000_000, trace: trace, c: context.encoded)) + reporter.ingest(event(.stalled, at: 3_000_000_000, trace: trace, ms: 2_000, c: context.encoded)) + reporter.ingest(event(.failed, at: 31_000_000_000, trace: trace)) + await reporter.flush() + + let values = await uploader.uploadedEvents + #expect(values.count == 2) + #expect(values.last?.properties["outcome"] == .string("failure")) + #expect(values.last?.properties["duration_ms"] == .int(30_000)) + // The context recorded at `started` survives onto the settled row. + #expect(values.last?.properties["replay_trigger"] == .string("coldAttach")) + #expect(values.last?.properties["surface_blank"] == .bool(true)) + #expect(values.last?.properties["replay_attempt"] == .int(2)) + } + + /// A fast successful replay stays below the slow threshold and must not + /// gain a row just because the context fields now exist. + @Test func fastSuccessfulReplayStillEmitsNothing() async { + let (reporter, uploader) = makeReporter() + let trace = DiagnosticTerminalTraceID(rawValue: 0xB1A6)! + let context = MobileTerminalReplayTraceContext( + trigger: .viewportTransition, surfaceIsBlank: false, barrierActive: true, attempt: 0 + ) + reporter.ingest(event(.started, at: 1_000_000_000, trace: trace, c: context.encoded)) + reporter.ingest(event(.applied, at: 1_300_000_000, trace: trace)) + await reporter.flush() + + #expect((await uploader.uploadedEvents).isEmpty) + } + + @Test func stallWithoutAnElapsedMagnitudeIsDropped() async { + let (reporter, uploader) = makeReporter() + let trace = DiagnosticTerminalTraceID(rawValue: 0xB1A7)! + reporter.ingest(event(.started, at: 1_000_000_000, trace: trace)) + reporter.ingest(event(.stalled, at: 3_000_000_000, trace: trace)) + await reporter.flush() + + #expect((await uploader.uploadedEvents).isEmpty) + } +} diff --git a/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileTerminalReplayResponse.swift b/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileTerminalReplayResponse.swift index 43422e2ff1de..2414d10e2d6b 100644 --- a/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileTerminalReplayResponse.swift +++ b/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileTerminalReplayResponse.swift @@ -21,6 +21,13 @@ public struct MobileTerminalReplayResponse: Decodable, Sendable { public let columns: Int? /// The host grid row count (debug diagnostics only). public let rows: Int? + /// Milliseconds the host spent between receiving this replay request and + /// finishing the capture it answers with. + /// + /// Subtracting this from the phone's own request round trip separates a + /// slow host capture from a slow or stalled transport. Absent on hosts + /// that predate the field. + public let hostElapsedMilliseconds: UInt32? private enum CodingKeys: String, CodingKey { case dataBase64 = "data_b64" @@ -29,6 +36,7 @@ public struct MobileTerminalReplayResponse: Decodable, Sendable { case sequence = "seq" case columns case rows + case hostElapsedMilliseconds = "host_elapsed_ms" } public init(from decoder: any Decoder) throws { @@ -41,6 +49,10 @@ public struct MobileTerminalReplayResponse: Decodable, Sendable { sequence = try container.decodeIfPresent(UInt64.self, forKey: .sequence) columns = try container.decodeIfPresent(Int.self, forKey: .columns) rows = try container.decodeIfPresent(Int.self, forKey: .rows) + hostElapsedMilliseconds = try? container.decodeIfPresent( + UInt32.self, + forKey: .hostElapsedMilliseconds + ) } /// Decode a replay response from raw JSON data. diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+AppDiagnostics.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+AppDiagnostics.swift index b0e98b058685..9e8559ee44e4 100644 --- a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+AppDiagnostics.swift +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+AppDiagnostics.swift @@ -24,6 +24,32 @@ extension MobileShellComposite { ) } + /// Adds one bounded terminal trace phase to the diagnostic spine, carrying + /// the categorical context that decides whether a slow replay is a blank + /// screen or merely stale text. + /// + /// The trace event has one integer payload slot, and this overload spends + /// it on ``MobileTerminalReplayTraceContext``. Use it for the phases that + /// have no byte count to report (`started` and `stalled`); the phases that + /// carry a payload size keep using `detail`. + public func recordTerminalTrace( + operation: DiagnosticTerminalTraceOperation, + phase: DiagnosticTerminalTracePhase, + traceID: DiagnosticTerminalTraceID, + surfaceID: String? = nil, + startedAt: Date? = nil, + replayContext: MobileTerminalReplayTraceContext + ) { + recordTerminalTrace( + operation: operation, + phase: phase, + traceID: traceID, + surfaceID: surfaceID, + startedAt: startedAt, + detail: replayContext.encoded + ) + } + /// Adds one bounded terminal trace phase to the diagnostic spine. public func recordTerminalTrace( operation: DiagnosticTerminalTraceOperation, diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalLane.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalLane.swift index 58dddb01d7f1..d545cc423c59 100644 --- a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalLane.swift +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalLane.swift @@ -157,6 +157,7 @@ extension MobileShellComposite { guard frame.sequence <= deliveredSequence else { requestAuthoritativeTerminalResync( surfaceID: surfaceID, + trigger: .byteGap, reason: "iroh_terminal_lane_gap" ) return .suspendUntilAuthoritativeOutput @@ -182,6 +183,7 @@ extension MobileShellComposite { guard frame.kind == .replay else { requestAuthoritativeTerminalResync( surfaceID: surfaceID, + trigger: .missingBaseline, reason: "iroh_terminal_lane_missing_baseline" ) return .suspendUntilAuthoritativeOutput diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalOutputDelivery.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalOutputDelivery.swift index 4493e2e735a9..015d87c895b8 100644 --- a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalOutputDelivery.swift +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalOutputDelivery.swift @@ -212,7 +212,7 @@ extension MobileShellComposite { "sync.render_grid_advisory source=\(source) surface=\(renderGrid.surfaceID) screen=\(renderGrid.activeScreen.rawValue) seq=\(renderGrid.stateSeq) requestReplay=\(deliveryDecision.requestReplay) updateTrackedScreen=\(deliveryDecision.updateTrackedScreen) deliverViewportPolicy=\(deliveryDecision.deliverViewportPolicy)" ) if deliveryDecision.requestReplay { - requestTerminalReplay(surfaceID: renderGrid.surfaceID) + requestTerminalReplay(surfaceID: renderGrid.surfaceID, trigger: .screenTransition) } #if DEBUG MobileLatencyTrace.stamp( @@ -272,7 +272,10 @@ extension MobileShellComposite { "base=\(deltaBase.map(String.init) ?? "nil") " + "delivered=\(delivered.map(String.init) ?? "nil") seq=\(renderGrid.stateSeq)" ) - terminalOutputNeedsReplay(surfaceID: renderGrid.surfaceID) + terminalOutputNeedsReplay( + surfaceID: renderGrid.surfaceID, + trigger: .historyChainBreak + ) #if DEBUG MobileLatencyTrace.stamp( "gate", @@ -299,7 +302,10 @@ extension MobileShellComposite { guard let deliveredRevisionContinuity, let deliveredColumns = deliveredRevisionContinuity.columns, let deliveredRows = deliveredRevisionContinuity.rows else { - terminalOutputNeedsReplay(surfaceID: renderGrid.surfaceID) + terminalOutputNeedsReplay( + surfaceID: renderGrid.surfaceID, + trigger: .applyFenceFailure + ) return } replaceablePatchShapeMatches = deliveredColumns == renderGrid.columns @@ -327,7 +333,10 @@ extension MobileShellComposite { "base=\(baseText) epoch=\(renderGrid.renderEpoch.prefix(8)) " + "delivered=\(deliveredText) seq=\(renderGrid.stateSeq)" ) - terminalOutputNeedsReplay(surfaceID: renderGrid.surfaceID) + terminalOutputNeedsReplay( + surfaceID: renderGrid.surfaceID, + trigger: .revisionChainBreak + ) #if DEBUG MobileLatencyTrace.stamp( "gate", @@ -523,6 +532,7 @@ extension MobileShellComposite { MobileDebugLog.anchormux("terminal.output.replay_retry_after_drop surface=\(surfaceID)") requestTerminalReplay( surfaceID: surfaceID, + trigger: .droppedFrame, replayBarrierToken: replayBarrierToken, coveredReplayBarrierDroppedOutputCount: droppedOutputCount ) @@ -538,7 +548,7 @@ extension MobileShellComposite { MobileDebugLog.anchormux( "terminal.output.pending_overflow surface=\(surfaceID) cap=\(TerminalOutputDeliveryQueue.maxPendingDeliveries)" ) - terminalOutputNeedsReplay(surfaceID: surfaceID) + terminalOutputNeedsReplay(surfaceID: surfaceID, trigger: .droppedFrame) return false } if bypassReplayBarrier, @@ -665,7 +675,11 @@ extension MobileShellComposite { terminalRenderGridBaselineReplayBarrierTokensBySurfaceID[surfaceID] = replayBarrierToken } MobileDebugLog.anchormux("terminal.output.replay_followup surface=\(surfaceID)") - requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: .coldAttach, + replayBarrierToken: replayBarrierToken + ) return } _ = failOpenTerminalReplayBarrier( @@ -754,7 +768,11 @@ extension MobileShellComposite { terminalAlternateRenderGridBaselineSurfaceIDs.remove(surfaceID) terminalMirrorHydrationNeededSurfaceIDs.insert(surfaceID) MobileDebugLog.anchormux("terminal.output.reset surface=\(surfaceID)") - requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: .outputReset, + replayBarrierToken: replayBarrierToken + ) } private func retryTerminalReplayAfterAckReset( @@ -795,6 +813,7 @@ extension MobileShellComposite { MobileDebugLog.anchormux("terminal.output.reset_replay_ack surface=\(surfaceID)") requestTerminalReplay( surfaceID: surfaceID, + trigger: .outputReset, replayBarrierToken: retryToken, coveredReplayBarrierDroppedOutputCount: terminalReplayBarrierDroppedOutputCountsBySurfaceID[surfaceID] @@ -805,6 +824,19 @@ extension MobileShellComposite { /// Reached from the render-pipeline reset: the surface was rebuilt blank, /// so (like ``terminalOutputDidReset``) no pre-barrier baseline survives. public func terminalOutputNeedsReplay(surfaceID: String) { + terminalOutputNeedsReplay(surfaceID: surfaceID, trigger: .renderPipelineReset) + } + + /// Same repair, naming the codepath that detected the divergence. + /// + /// The protocol entry point above cannot carry a reason, and every + /// detector funnels through here, so without this the whole class of + /// chain, shape, and overflow repairs is one undifferentiated bucket in + /// analytics. + func terminalOutputNeedsReplay( + surfaceID: String, + trigger: MobileTerminalReplayTrigger + ) { guard terminalByteContinuationsBySurfaceID[surfaceID] != nil else { return } if let pendingAckToken = terminalViewportReplayBarrierPendingAckTokensBySurfaceID[surfaceID], terminalReplayBarrierTokensBySurfaceID[surfaceID] == pendingAckToken { @@ -822,7 +854,11 @@ extension MobileShellComposite { terminalAlternateRenderGridBaselineSurfaceIDs.remove(surfaceID) terminalMirrorHydrationNeededSurfaceIDs.insert(surfaceID) MobileDebugLog.anchormux("terminal.output.replay_requested surface=\(surfaceID)") - requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: trigger, + replayBarrierToken: replayBarrierToken + ) } } diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayLifecycle.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayLifecycle.swift index 504dcf5114c3..e60f0840a859 100644 --- a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayLifecycle.swift +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayLifecycle.swift @@ -1,3 +1,4 @@ +internal import CMUXMobileCore internal import CmuxMobileDiagnostics internal import CmuxMobileRPC public import Foundation @@ -119,13 +120,21 @@ extension MobileShellComposite { /// Supersede every older replay and output acknowledgement for a surface, /// then request one authoritative replacement owned by the new barrier. - func requestAuthoritativeTerminalResync(surfaceID: String, reason: String) { + func requestAuthoritativeTerminalResync( + surfaceID: String, + trigger: MobileTerminalReplayTrigger, + reason: String + ) { guard hasTerminalOutputSink(surfaceID: surfaceID), remoteClient != nil else { return } let replayBarrierToken = beginTerminalReplayBarrierCarryingReplacedWork(surfaceID: surfaceID) MobileDebugLog.anchormux( "CMUX_REPLAY authoritative_resync reason=\(reason) surface=\(surfaceID)" ) - requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: trigger, + replayBarrierToken: replayBarrierToken + ) } func requestColdAttachTerminalReplay(surfaceID: String) { @@ -145,7 +154,11 @@ extension MobileShellComposite { if supportedHostCapabilities.contains(Self.terminalReplayCapability) { let replayBarrierToken = beginTerminalReplayBarrier(surfaceID: surfaceID) terminalColdAttachReplayBarrierTokensBySurfaceID[surfaceID] = replayBarrierToken - requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: .coldAttach, + replayBarrierToken: replayBarrierToken + ) return } if supportedHostCapabilities.isEmpty { @@ -153,7 +166,10 @@ extension MobileShellComposite { } else { terminalColdReplayNeedsBarrierUpgradeSurfaceIDs.remove(surfaceID) } - requestTerminalReplay(surfaceID: surfaceID) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: .coldAttach + ) } func upgradePendingColdTerminalReplaysIfNeeded() { @@ -167,13 +183,20 @@ extension MobileShellComposite { // terminal.replay.v1 still need the pre-connection mount's cold // replay; mirror the unbarriered fallback used when mounting // after the connection resolved. - requestTerminalReplay(surfaceID: surfaceID) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: .coldAttach + ) continue } guard terminalReplayBarrierTokensBySurfaceID[surfaceID] == nil else { continue } let replayBarrierToken = beginTerminalReplayBarrier(surfaceID: surfaceID) terminalColdAttachReplayBarrierTokensBySurfaceID[surfaceID] = replayBarrierToken - requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: .coldAttach, + replayBarrierToken: replayBarrierToken + ) } } @@ -388,6 +411,7 @@ extension MobileShellComposite { @discardableResult func requestTerminalReplayForCurrentBarrier( surfaceID: String, + trigger: MobileTerminalReplayTrigger, replayBarrierToken: UUID?, coveredReplayBarrierDroppedOutputCount: UInt64?, reason: String @@ -401,6 +425,7 @@ extension MobileShellComposite { MobileDebugLog.anchormux("CMUX_REPLAY retry_\(reason) surface=\(surfaceID)") requestTerminalReplay( surfaceID: surfaceID, + trigger: trigger, replayBarrierToken: replayBarrierToken, coveredReplayBarrierDroppedOutputCount: coveredReplayBarrierDroppedOutputCount ) @@ -437,6 +462,7 @@ extension MobileShellComposite { func clearTerminalReplayInFlightIfCurrent(surfaceID: String, requestID: UUID) { guard terminalReplayRequestIDsInFlightBySurfaceID[surfaceID] == requestID else { return } + cancelTerminalReplayStallProbe(surfaceID: surfaceID) terminalReplaySurfaceIDsInFlight.remove(surfaceID) terminalReplayRequestIDsInFlightBySurfaceID.removeValue(forKey: surfaceID) terminalReplayTasksBySurfaceID.removeValue(forKey: surfaceID) @@ -444,6 +470,7 @@ extension MobileShellComposite { } func cancelTerminalReplayInFlight(surfaceID: String) { + cancelTerminalReplayStallProbe(surfaceID: surfaceID) terminalReplayTasksBySurfaceID.removeValue(forKey: surfaceID)?.cancel() terminalReplaySurfaceIDsInFlight.remove(surfaceID) terminalReplayRequestIDsInFlightBySurfaceID.removeValue(forKey: surfaceID) @@ -451,6 +478,7 @@ extension MobileShellComposite { } func cancelAllTerminalReplayTasks() { + cancelAllTerminalReplayStallProbes() for task in terminalReplayTasksBySurfaceID.values { task.cancel() } @@ -546,6 +574,7 @@ extension MobileShellComposite { } shouldRearmAfterTimeout = !self.requestTerminalReplayForCurrentBarrier( surfaceID: surfaceID, + trigger: .viewportTransition, replayBarrierToken: retryToken, coveredReplayBarrierDroppedOutputCount: nil, reason: "viewport_transition_timeout" @@ -597,7 +626,11 @@ extension MobileShellComposite { let replayBarrierToken = beginTerminalReplayBarrier(surfaceID: surfaceID) terminalRenderGridBaselineReplayRequestCountsBySurfaceID[surfaceID] = requestCount + 1 terminalRenderGridBaselineReplayBarrierTokensBySurfaceID[surfaceID] = replayBarrierToken - requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: .missingBaseline, + replayBarrierToken: replayBarrierToken + ) } /// An authoritative replay was accepted: its state supersedes the diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayRetry.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayRetry.swift index b450fb34b60c..98acbac038f9 100644 --- a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayRetry.swift +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayRetry.swift @@ -1,4 +1,5 @@ import Foundation +internal import CMUXMobileCore internal import CmuxMobileDiagnostics /// Retry accounting for the pending-input render-grid drop path, layered on @@ -40,7 +41,7 @@ extension MobileShellComposite { terminalReplayFailureRetryCountsBySurfaceID.removeValue(forKey: surfaceID) return } - requestTerminalReplay(surfaceID: surfaceID) + requestTerminalReplay(surfaceID: surfaceID, trigger: .pendingInputDrop) } @discardableResult @@ -59,6 +60,7 @@ extension MobileShellComposite { clearTerminalReplayInFlightIfCurrent(surfaceID: surfaceID, requestID: replayRequestID) requestTerminalReplay( surfaceID: surfaceID, + trigger: .failureRetry, replayBarrierToken: retryToken, coveredReplayBarrierDroppedOutputCount: coveredReplayBarrierDroppedOutputCount ?? terminalReplayBarrierDroppedOutputCountsBySurfaceID[surfaceID] @@ -68,7 +70,7 @@ extension MobileShellComposite { if replayBarrierToken == nil, prepareNonBarrierTerminalReplayFailureRetry(surfaceID: surfaceID) { clearTerminalReplayInFlightIfCurrent(surfaceID: surfaceID, requestID: replayRequestID) - requestTerminalReplay(surfaceID: surfaceID) + requestTerminalReplay(surfaceID: surfaceID, trigger: .failureRetry) return true } let retryBudgetExhausted = retryBudgetWasExhausted diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayStallProbe.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayStallProbe.swift new file mode 100644 index 000000000000..b5df52a420f2 --- /dev/null +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalReplayStallProbe.swift @@ -0,0 +1,97 @@ +internal import CMUXMobileCore +internal import Foundation + +/// Emits evidence while a terminal replay is still outstanding. +/// +/// Every other terminal trace phase is terminal, so a replay that never +/// settles produces no analytics row at all: the worst stalls, where the +/// surface has been rebuilt blank and only the replay response can repaint +/// it, were exactly the ones Axiom could not see. This probe closes that gap +/// by stamping ``DiagnosticTerminalTracePhase/stalled`` on a bounded schedule +/// while the request is in flight, carrying the elapsed time and the context +/// that says whether the user is looking at a blank terminal. +/// +/// The probe is pure telemetry. It never requests, retries, or fails a +/// replay, and cancelling it cannot change delivery behavior. +extension MobileShellComposite { + /// Elapsed marks, in seconds, at which an outstanding replay is stamped. + /// + /// The first mark sits just above the applied-replay p90 so ordinary slow + /// replays stay quiet, and the last mark sits past the RPC deadline so a + /// request the deadline failed to bound still reports. + static let terminalReplayStallProbeMarks: [Duration] = [ + .seconds(2), .seconds(5), .seconds(10), .seconds(20), + .seconds(35), .seconds(60), .seconds(120), .seconds(300), + ] + + func armTerminalReplayStallProbe( + surfaceID: String, + requestID: UUID, + traceID: DiagnosticTerminalTraceID, + startedAt: Date, + context: MobileTerminalReplayTraceContext + ) { + cancelTerminalReplayStallProbe(surfaceID: surfaceID) + let clock = controlPlaneSchedulingClock + let marks = Self.terminalReplayStallProbeMarks + terminalReplayStallProbeTasksBySurfaceID[surfaceID] = Task { @MainActor [weak self] in + var elapsed: Duration = .zero + for mark in marks { + let step = mark - elapsed + guard step > .zero else { continue } + do { + try await clock.sleep(for: step, tolerance: nil) + } catch { + return + } + elapsed = mark + guard !Task.isCancelled, let self else { return } + // The request settled (or was replaced) while this slept; the + // settled phase is the authoritative record from here on. + guard self.terminalReplayRequestIDsInFlightBySurfaceID[surfaceID] == requestID else { + return + } + self.recordTerminalTrace( + operation: .replay, + phase: .stalled, + traceID: traceID, + surfaceID: surfaceID, + startedAt: startedAt, + replayContext: context + ) + } + } + } + + func cancelTerminalReplayStallProbe(surfaceID: String) { + terminalReplayStallProbeTasksBySurfaceID.removeValue(forKey: surfaceID)?.cancel() + } + + func cancelAllTerminalReplayStallProbes() { + for task in terminalReplayStallProbeTasksBySurfaceID.values { + task.cancel() + } + terminalReplayStallProbeTasksBySurfaceID = [:] + } + + /// The categorical context for a replay about to be requested. + /// + /// `surfaceIsBlank` reuses the same condition the request uses to decide + /// whether to ask the Mac for scrollback: the mirror needs hydration, or + /// no baseline was ever delivered. Both mean nothing survives locally to + /// paint, so the surface is blank until this replay lands. + func terminalReplayTraceContext( + surfaceID: String, + trigger: MobileTerminalReplayTrigger, + replayBarrierToken: UUID? + ) -> MobileTerminalReplayTraceContext { + MobileTerminalReplayTraceContext( + trigger: trigger, + surfaceIsBlank: deliveredTerminalByteEndSeqBySurfaceID[surfaceID] == nil + || terminalMirrorHydrationNeededSurfaceIDs.contains(surfaceID), + barrierActive: replayBarrierToken != nil + || terminalReplayBarrierTokensBySurfaceID[surfaceID] != nil, + attempt: terminalReplayFailureRetryCountsBySurfaceID[surfaceID] ?? 0 + ) + } +} diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalViewport.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalViewport.swift index 3e2edea287b5..ca0a1cc67a24 100644 --- a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalViewport.swift +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+TerminalViewport.swift @@ -304,7 +304,11 @@ extension MobileShellComposite { MobileDebugLog.anchormux( "terminal.output.viewport_resync surface=\(surfaceID) grid=\(effectiveGrid.columns)x\(effectiveGrid.rows)" ) - requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: .viewportTransition, + replayBarrierToken: replayBarrierToken + ) replayRequested = true } else if prearmedReplayBarrierToken == nil, terminalReplayBarrierTokensBySurfaceID[surfaceID] != nil, @@ -318,7 +322,11 @@ extension MobileShellComposite { // barrier's owed work. let replayBarrierToken = beginTerminalReplayBarrierCarryingReplacedWork(surfaceID: surfaceID) MobileDebugLog.anchormux("terminal.output.viewport_rearm_exhausted surface=\(surfaceID)") - requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: .viewportTransition, + replayBarrierToken: replayBarrierToken + ) replayRequested = true } else { replayRequested = finishPrearmedTerminalViewportBarrierWithoutResize( @@ -503,7 +511,11 @@ extension MobileShellComposite { hasTerminalOutputSink(surfaceID: surfaceID), remoteClient != nil { MobileDebugLog.anchormux("terminal.output.viewport_replay_after_\(reason) surface=\(surfaceID)") - requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: token) + requestTerminalReplay( + surfaceID: surfaceID, + trigger: .viewportTransition, + replayBarrierToken: token + ) return true } clearTerminalReplayBarrierIfCurrent( diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+WorkspaceListRecovery.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+WorkspaceListRecovery.swift index 3ce1cb513f57..a12e6b620a28 100644 --- a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+WorkspaceListRecovery.swift +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite+WorkspaceListRecovery.swift @@ -440,7 +440,11 @@ extension MobileShellComposite { connectionState == .connected else { return } if subscribed || runtime?.supportsServerPushEvents == false { for surfaceID in surfaceIDs { - requestAuthoritativeTerminalResync(surfaceID: surfaceID, reason: "manual_reconnect") + requestAuthoritativeTerminalResync( + surfaceID: surfaceID, + trigger: .resubscribe, + reason: "manual_reconnect" + ) } } await refreshWorkspaces() diff --git a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite.swift b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite.swift index 8860565d025d..855bdcabab01 100644 --- a/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite.swift +++ b/Packages/iOS/CmuxMobileShell/Sources/CmuxMobileShell/MobileShellComposite.swift @@ -1589,6 +1589,8 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { var terminalReplaySurfaceIDsInFlight: Set var terminalReplayRequestIDsInFlightBySurfaceID: [String: UUID] var terminalReplayTasksBySurfaceID: [String: Task] + /// Telemetry-only probes that stamp an outstanding replay as stalled. + var terminalReplayStallProbeTasksBySurfaceID: [String: Task] var terminalReplayBarrierWatchdogTasksBySurfaceID: [String: Task] var terminalReplayBarrierWatchdogIDsBySurfaceID: [String: UUID] var terminalReplayBarrierWatchdogTokensBySurfaceID: [String: UUID] @@ -2013,6 +2015,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { self.terminalReplaySurfaceIDsInFlight = [] self.terminalReplayRequestIDsInFlightBySurfaceID = [:] self.terminalReplayTasksBySurfaceID = [:] + self.terminalReplayStallProbeTasksBySurfaceID = [:] self.terminalReplayBarrierWatchdogTasksBySurfaceID = [:] self.terminalReplayBarrierWatchdogIDsBySurfaceID = [:] self.terminalReplayBarrierWatchdogTokensBySurfaceID = [:] @@ -14606,7 +14609,11 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { "sync.resync reason=\(reason) restart=\(restartEventStream) surfaces=\(surfaceIDs.count)" ) for surfaceID in surfaceIDs { - requestAuthoritativeTerminalResync(surfaceID: surfaceID, reason: reason) + requestAuthoritativeTerminalResync( + surfaceID: surfaceID, + trigger: .resubscribe, + reason: reason + ) } } @@ -14760,6 +14767,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { } else { self.requestAuthoritativeTerminalResync( surfaceID: surfaceID, + trigger: .pendingInputDrop, reason: "input_seq_wait_retry" ) } @@ -14771,6 +14779,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { for surfaceID in terminalByteContinuationsBySurfaceID.keys { requestAuthoritativeTerminalResync( surfaceID: surfaceID, + trigger: .resubscribe, reason: reason ) } @@ -15093,6 +15102,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { /// for TUIs, and a VT export is still a replay stream rather than state. func requestTerminalReplay( surfaceID: String, + trigger: MobileTerminalReplayTrigger, replayBarrierToken: UUID? = nil, coveredReplayBarrierDroppedOutputCount: UInt64? = nil ) { @@ -15171,11 +15181,30 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { ) let diagnosticStartedAt = appDiagnosticNow() let terminalTraceID = DiagnosticTerminalTraceID() + // Captured before the request so the stall probe and the settled + // phases all describe the same episode, even after retries mutate the + // surface's counters. + let replayTraceContext = terminalReplayTraceContext( + surfaceID: surfaceID, + trigger: trigger, + replayBarrierToken: replayBarrierTokenForRequest + ) recordTerminalTrace( operation: .replay, phase: .started, traceID: terminalTraceID, - surfaceID: surfaceID + surfaceID: surfaceID, + replayContext: replayTraceContext + ) + // Nothing else reports an outstanding replay: every other phase is + // terminal, so a request that never settles would otherwise leave no + // trace of a surface that stayed blank waiting for it. + armTerminalReplayStallProbe( + surfaceID: surfaceID, + requestID: replayRequestID, + traceID: terminalTraceID, + startedAt: diagnosticStartedAt, + context: replayTraceContext ) recordAppEvent( .terminalReplayStarted, @@ -15266,6 +15295,18 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { // suspension point, so every staleness guard below already // observes post-decode state. let decoded = await Self.decodeTerminalReplayResponseOffMain(data) + // Splits the round trip: this phase's detail is the host's own + // capture time, so the remainder is transport and queueing. + if let hostElapsed = decoded.payload?.hostElapsedMilliseconds { + self.recordTerminalTrace( + operation: .replay, + phase: .hostCaptureFinished, + traceID: terminalTraceID, + surfaceID: surfaceID, + startedAt: diagnosticStartedAt, + detail: Int(hostElapsed) + ) + } self.recordTerminalTrace( operation: .replay, phase: .decoded, @@ -15300,6 +15341,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { transferredInFlightToRetry = true guard self.requestTerminalReplayForCurrentBarrier( surfaceID: surfaceID, + trigger: .failureRetry, replayBarrierToken: replayBarrierTokenForRequest, coveredReplayBarrierDroppedOutputCount: nil, reason: "stale_client" @@ -15476,6 +15518,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { transferredInFlightToRetry = true self.requestTerminalReplay( surfaceID: surfaceID, + trigger: .failureRetry, replayBarrierToken: retryToken, coveredReplayBarrierDroppedOutputCount: self.terminalReplayBarrierDroppedOutputCountsBySurfaceID[surfaceID] @@ -15604,6 +15647,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { transferredInFlightToRetry = true guard self.requestTerminalReplayForCurrentBarrier( surfaceID: surfaceID, + trigger: .failureRetry, replayBarrierToken: replayBarrierTokenForRequest, coveredReplayBarrierDroppedOutputCount: nil, reason: "stale_client" @@ -15660,6 +15704,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { transferredInFlightToRetry = true self.requestTerminalReplay( surfaceID: surfaceID, + trigger: .failureRetry, replayBarrierToken: retryToken, coveredReplayBarrierDroppedOutputCount: coveredReplayBarrierDroppedOutputCountForRequest ) @@ -15828,7 +15873,7 @@ public final class MobileShellComposite: MobileTerminalOutputSinking { // state. Keep the catch-up replay nonblocking so later live // bytes continue while it verifies the missing interval. refreshTerminalOutputSubscription(reason: "seq_gap", restartEventStream: false) - requestTerminalReplay(surfaceID: surfaceID) + requestTerminalReplay(surfaceID: surfaceID, trigger: .byteGap) return } if endSeq <= deliveredSeq { diff --git a/Sources/TerminalController.swift b/Sources/TerminalController.swift index e2279423ad3d..70015cf4c937 100644 --- a/Sources/TerminalController.swift +++ b/Sources/TerminalController.swift @@ -15374,6 +15374,12 @@ class TerminalController { } } recordTrace("host_capture_finished") + // Hand the phone the host's own share of this round trip. Without it a + // slow replay is unattributable: the phone cannot tell a slow capture + // here from a slow or stalled transport between us. + payload["host_elapsed_ms"] = Int( + (DispatchTime.now().uptimeNanoseconds &- traceStartedAt) / 1_000_000 + ) return .ok(payload) } diff --git a/web/services/observability/mobileNetworkOutcome.ts b/web/services/observability/mobileNetworkOutcome.ts index 9a6dc36c785e..bfb7fd02b6a4 100644 --- a/web/services/observability/mobileNetworkOutcome.ts +++ b/web/services/observability/mobileNetworkOutcome.ts @@ -17,7 +17,7 @@ const phases = new Set([ "endpoint_start", "pairing", "transport_dial", "host_auth", "rpc_ready", "recovery", "relay_policy", "discovery", "initial_connect", "terminal_trace", ]); -const outcomes = new Set(["success", "failure", "timeout", "cancelled", "abandoned"]); +const outcomes = new Set(["success", "failure", "timeout", "cancelled", "abandoned", "stalled"]); const failures = new Set([ "offline", "timedOut", "connectionRefused", "hostUnreachable", "permissionDenied", "dnsFailed", "secureChannelFailed", "unsupportedRoute", @@ -57,13 +57,14 @@ const allowedPropertyKeys = new Set([ "input_failed_count", "histogram_version", "input_to_output_histogram", "input_to_visible_histogram", "render_histogram", "duration_ms", "threshold_ms", "stage", "trace_id", "operation", "terminal_phase", + "replay_trigger", "surface_blank", "barrier_active", "replay_attempt", "model_count", "phase", "attempt", "retry_delay_ms", "stop_reason", "correlation_id", ]); export type MobileNetworkOutcome = { readonly timestamp: string; readonly phase: string; - readonly outcome: "success" | "failure" | "timeout" | "cancelled" | "abandoned"; + readonly outcome: "success" | "failure" | "timeout" | "cancelled" | "abandoned" | "stalled"; readonly durationMs: number; readonly runtimeRole: "mobileClient"; readonly userUsable: boolean; @@ -90,6 +91,14 @@ export type MobileNetworkOutcome = { readonly traceId?: string; readonly operation?: string; readonly terminalPhase?: string; + /** Why the replay this trace describes was requested. */ + readonly replayTrigger?: string; + /** The surface had been rebuilt blank, so this stall is a blank screen. */ + readonly surfaceBlank?: boolean; + /** A replay barrier was suppressing live output for the surface. */ + readonly barrierActive?: boolean; + /** Zero-based retry index within the replay episode. */ + readonly replayAttempt?: number; }; export type MobileTerminalLatencyWindow = { @@ -341,7 +350,15 @@ export function parseMobileTaskModelDiscovery(candidate: unknown): MobileTaskMod } type CoreObservation = Pick; -type Metadata = Pick; +type Metadata = Pick; + +/** Mirrors `MobileTerminalReplayTrigger` in CMUXMobileCore. */ +const replayTriggers = new Set([ + "unknown", "outputReset", "renderPipelineReset", "viewportTransition", + "revisionChainBreak", "historyChainBreak", "coldAttach", "failureRetry", + "droppedFrame", "applyFenceFailure", "pendingInputDrop", "resubscribe", + "screenTransition", "missingBaseline", "byteGap", +]); function validTimestamp(value: unknown): value is string { return typeof value === "string" @@ -420,6 +437,25 @@ function parseInitialConnectionFields( }; } +/// Categorical context for a replay trace. Split out of `parseMetadata` to +/// keep that function under the repository complexity limit. +function parseReplayContextFields( + properties: Record, +): Pick | null { + const replayTrigger = optionalSetValue(properties.replay_trigger, replayTriggers); + const surfaceBlank = optionalBoolean(properties.surface_blank); + const barrierActive = optionalBoolean(properties.barrier_active); + const replayAttempt = optionalDiagnosticInteger(properties.replay_attempt, 0xff); + if (replayTrigger === false || replayAttempt === false) return null; + if (surfaceBlank === null || barrierActive === null) return null; + return { + ...(typeof replayTrigger === "string" ? { replayTrigger } : {}), + ...(typeof surfaceBlank === "boolean" ? { surfaceBlank } : {}), + ...(typeof barrierActive === "boolean" ? { barrierActive } : {}), + ...(typeof replayAttempt === "number" ? { replayAttempt } : {}), + }; +} + function parseMetadata(properties: Record): Metadata | null { const platform = optionalExact(properties.platform, "ios"); const clientChannel = optionalSetValue(properties.client_channel, new Set(["dev", "nightly", "production", "unknown"])) as @@ -433,10 +469,11 @@ function parseMetadata(properties: Record): Metadata | null { const traceId = optionalTraceID(properties.trace_id); const operation = optionalSetValue(properties.operation, new Set(["replay", "artifactScan", "artifactList", "model_list"])); const terminalPhase = optionalSetValue(properties.terminal_phase, new Set([ - "applied", "failed", "discarded", + "applied", "failed", "discarded", "hostCaptureFinished", "stalled", ])); + const replayFields = parseReplayContextFields(properties); if ([platform, clientChannel, appVersion, buildNumber, bundleIdentifier, osVersion, deviceModel, - traceId, operation, terminalPhase].includes(false)) return null; + traceId, operation, terminalPhase].includes(false) || replayFields === null) return null; if (properties.phase === "terminal_trace" && (typeof traceId !== "string" || typeof operation !== "string" || typeof terminalPhase !== "string")) { return null; @@ -451,6 +488,7 @@ function parseMetadata(properties: Record): Metadata | null { ...(typeof deviceModel === "string" ? { deviceModel } : {}), ...(typeof traceId === "string" ? { traceId } : {}), ...(typeof operation === "string" ? { operation } : {}), + ...replayFields, ...(typeof terminalPhase === "string" ? { terminalPhase } : {}), }; } @@ -494,6 +532,10 @@ export async function emitMobileNetworkOutcomes( "cmux.mobile.trace_id": observation.traceId, "cmux.mobile.operation": observation.operation, "cmux.mobile.terminal_phase": observation.terminalPhase, + "cmux.mobile.replay_trigger": observation.replayTrigger, + "cmux.mobile.surface_blank": observation.surfaceBlank, + "cmux.mobile.barrier_active": observation.barrierActive, + "cmux.mobile.replay_attempt": observation.replayAttempt, }, (span) => { if (observation.outcome === "failure" || observation.outcome === "timeout") { @@ -638,6 +680,14 @@ function optionalDiagnosticInteger(value: unknown, maximum = 0xffff_ffff): numbe return parsed === null || parsed > maximum ? false : parsed; } +/// `false` is a legitimate value here, so an invalid one reports `null` +/// rather than joining the `false`-means-rejected convention used by the +/// string and integer helpers. +function optionalBoolean(value: unknown): boolean | undefined | null { + if (value === undefined) return undefined; + return typeof value === "boolean" ? value : null; +} + function optionalExact(value: unknown, expected: T): T | undefined | false { if (value === undefined) return undefined; return value === expected ? expected : false; diff --git a/web/tests/mobile-replay-stall-observability.test.ts b/web/tests/mobile-replay-stall-observability.test.ts new file mode 100644 index 000000000000..d130095b7818 --- /dev/null +++ b/web/tests/mobile-replay-stall-observability.test.ts @@ -0,0 +1,68 @@ +import { describe, expect, test } from "bun:test"; + +import { parseMobileNetworkOutcome } from "../services/observability/mobileNetworkOutcome"; + +/** + * A replay that never settles leaves a surface blank with only a cursor. The + * client reports it as a non-terminal `stalled` phase; these lock the contract + * that carries that row through to Axiom. + */ +describe("terminal replay stall telemetry", () => { + const stall = (properties: Record = {}) => ({ + event: "ios_connectivity_latency", + timestamp: "2026-09-23T19:05:25.000Z", + properties: { + runtime_role: "mobileClient", + phase: "terminal_trace", + outcome: "stalled", + duration_ms: 30_000, + user_usable: false, + trace_id: "00000000000b1a4f", + operation: "replay", + terminal_phase: "stalled", + replay_trigger: "outputReset", + surface_blank: true, + barrier_active: true, + replay_attempt: 1, + ...properties, + }, + }); + + test("accepts a stalled replay with its blank-surface context", () => { + const parsed = parseMobileNetworkOutcome(stall()); + expect(parsed).not.toBeNull(); + expect(parsed?.outcome).toBe("stalled"); + expect(parsed?.terminalPhase).toBe("stalled"); + expect(parsed?.replayTrigger).toBe("outputReset"); + expect(parsed?.surfaceBlank).toBe(true); + expect(parsed?.barrierActive).toBe(true); + expect(parsed?.replayAttempt).toBe(1); + }); + + test("keeps surface_blank false distinguishable from an absent value", () => { + const painted = parseMobileNetworkOutcome(stall({ surface_blank: false })); + expect(painted?.surfaceBlank).toBe(false); + const absent = parseMobileNetworkOutcome( + stall({ surface_blank: undefined, barrier_active: undefined }), + ); + expect(absent).not.toBeNull(); + expect(absent?.surfaceBlank).toBeUndefined(); + }); + + test("rejects a non-boolean blank flag and an unknown trigger", () => { + expect(parseMobileNetworkOutcome(stall({ surface_blank: "yes" }))).toBeNull(); + expect(parseMobileNetworkOutcome(stall({ replay_trigger: "madeUp" }))).toBeNull(); + }); + + test("accepts the host capture split on a settled replay", () => { + const parsed = parseMobileNetworkOutcome( + stall({ outcome: "success", terminal_phase: "hostCaptureFinished" }), + ); + expect(parsed?.terminalPhase).toBe("hostCaptureFinished"); + }); + + test("still requires trace id and operation on every terminal trace", () => { + expect(parseMobileNetworkOutcome(stall({ trace_id: undefined }))).toBeNull(); + expect(parseMobileNetworkOutcome(stall({ operation: undefined }))).toBeNull(); + }); +}); From 72241fde6c8e6166e18c9b5a46f2a5dfcb68df2d Mon Sep 17 00:00:00 2001 From: Abdulaziz Albahar <67667005+azooz2003-bit@users.noreply.github.com> Date: Wed, 23 Sep 2026 13:24:29 -0700 Subject: [PATCH 2/6] telemetry(ios): record whether a stall was on screen or across suspension A suspended app runs no code, so an operation that spans suspension accrues wall-clock time it never spent waiting in front of anyone. Both numbers land in the same `duration_ms`, which makes any percentile over the mix meaningless. This is not hypothetical: in a field episode the phone reported five surfaces failing at an identical 155.699s, and only 91s of that window was foreground. Every mass failure fired within ~30ms of an app lifecycle transition, because nothing could time out while the app was suspended. Reading those durations as blank-screen time overstates them roughly threefold. `MobileTerminalLatencyReporter` already takes the lifecycle edge; `MobileTerminalTraceReporter` did not. Give it the same `setForeground`, stamp `app_foreground` on every emitted row, and carry it through the web contract as a span attribute. --- .../MobileTerminalTraceReporter.swift | 26 +++++++++++++++++-- .../MobileTerminalTraceStallTests.swift | 25 ++++++++++++++++++ ...bileShellRenderGridInputCatchUpTests.swift | 6 ++--- ...RenderGridReplayRetryExhaustionTests.swift | 2 +- ...eShellRenderGridReplayStalenessTests.swift | 10 +++---- .../MobileShellReplayDropRecoveryTests.swift | 2 +- ...MobileShellReplayFallbackScreenTests.swift | 2 ++ .../TerminalByteGapRebaseTests.swift | 3 ++- .../TerminalOutputDeliveryQueueTests.swift | 2 +- .../TerminalReplayBarrierFollowUpTests.swift | 3 ++- .../TerminalViewportResyncTests.swift | 13 +++++----- ios/cmux/AppCompositionRoot.swift | 3 +++ .../observability/mobileNetworkOutcome.ts | 17 +++++++++--- .../mobile-replay-stall-observability.test.ts | 7 +++++ 14 files changed, 96 insertions(+), 25 deletions(-) diff --git a/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift b/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift index c4acc447d730..84d82ae923fe 100644 --- a/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift +++ b/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift @@ -24,6 +24,14 @@ public final class MobileTerminalTraceReporter: Sendable { var starts: [UInt64: Start] = [:] var windowStart: UInt64 = 0 var emittedInWindow = 0 + /// Whether the app was in the foreground when the phase was recorded. + /// + /// A suspended app runs no code, so an operation that spans + /// suspension accrues wall-clock time it never spent waiting on + /// screen. Without this flag a stall of a few foreground seconds and + /// one that sat in a pocket for an hour are indistinguishable in + /// Axiom, and any percentile over the mix is meaningless. + var isForeground = true } private final class StateStore: @unchecked Sendable { @@ -47,6 +55,10 @@ public final class MobileTerminalTraceReporter: Sendable { } } + func setForeground(_ active: Bool) { + queue.async { [self] in state.isForeground = active } + } + func drain() async { await withCheckedContinuation { continuation in queue.async { continuation.resume() } @@ -61,6 +73,7 @@ public final class MobileTerminalTraceReporter: Sendable { let durationMilliseconds: UInt32 let outcome: String let replayContext: MobileTerminalReplayTraceContext? + let isForeground: Bool } private let emitter: any AnalyticsEmitting @@ -81,6 +94,12 @@ public final class MobileTerminalTraceReporter: Sendable { } } + /// Records the app lifecycle edge so each emitted row says whether its + /// elapsed time was spent on screen. + public func setForeground(_ active: Bool) { + state.setForeground(active) + } + public func flush() async { await state.drain() await emitter.flush() @@ -127,7 +146,8 @@ public final class MobileTerminalTraceReporter: Sendable { durationMilliseconds: duration, outcome: "stalled", replayContext: event.c.flatMap(MobileTerminalReplayTraceContext.init(encoded:)) - ?? start?.replayContext + ?? start?.replayContext, + isForeground: state.isForeground ) } guard phase == .applied || phase == .failed || phase == .discarded else { return nil } @@ -149,7 +169,8 @@ public final class MobileTerminalTraceReporter: Sendable { terminalPhase: phase, durationMilliseconds: duration, outcome: outcome, - replayContext: start?.replayContext + replayContext: start?.replayContext, + isForeground: state.isForeground ) } @@ -173,6 +194,7 @@ public final class MobileTerminalTraceReporter: Sendable { "trace_id": .string(observation.traceID.stringValue), "operation": .string(String(describing: observation.operation)), "terminal_phase": .string(String(describing: observation.terminalPhase)), + "app_foreground": .bool(observation.isForeground), ] if let context = observation.replayContext { properties["replay_trigger"] = .string(String(describing: context.trigger)) diff --git a/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift b/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift index 33f4480b1bed..6144a6bd2a0a 100644 --- a/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift +++ b/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift @@ -101,6 +101,31 @@ struct MobileTerminalTraceStallTests { #expect((await uploader.uploadedEvents).isEmpty) } + /// A stall that accrued its time while the app was suspended is not a + /// blank screen anyone saw. Mixing the two makes every percentile in + /// Axiom meaningless, so each row has to say which it was. + @Test func stallRowsRecordWhetherTheAppWasOnScreen() async { + let (reporter, uploader) = makeReporter() + let context = MobileTerminalReplayTraceContext( + trigger: .outputReset, surfaceIsBlank: true, barrierActive: true, attempt: 0 + ) + let onScreen = DiagnosticTerminalTraceID(rawValue: 0xB1B0)! + reporter.ingest(event(.started, at: 1_000_000_000, trace: onScreen, c: context.encoded)) + reporter.ingest(event(.stalled, at: 6_000_000_000, trace: onScreen, ms: 5_000, c: context.encoded)) + await reporter.flush() + #expect((await uploader.uploadedEvents).last?.properties["app_foreground"] == .bool(true)) + + reporter.setForeground(false) + let suspended = DiagnosticTerminalTraceID(rawValue: 0xB1B1)! + reporter.ingest(event(.started, at: 7_000_000_000, trace: suspended, c: context.encoded)) + reporter.ingest(event(.stalled, at: 67_000_000_000, trace: suspended, ms: 60_000, c: context.encoded)) + await reporter.flush() + let values = await uploader.uploadedEvents + #expect(values.count == 2) + #expect(values.last?.properties["app_foreground"] == .bool(false)) + #expect(values.last?.properties["duration_ms"] == .int(60_000)) + } + @Test func stallWithoutAnElapsedMagnitudeIsDropped() async { let (reporter, uploader) = makeReporter() let trace = DiagnosticTerminalTraceID(rawValue: 0xB1A7)! diff --git a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridInputCatchUpTests.swift b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridInputCatchUpTests.swift index c9bcbef0232b..cc5e3f019c48 100644 --- a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridInputCatchUpTests.swift +++ b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridInputCatchUpTests.swift @@ -439,7 +439,7 @@ import Testing renderGridFrame(surfaceID: surfaceID, seq: 99, text: "stale-replay"), renderGridFrame(surfaceID: surfaceID, seq: 100, text: "fresh-replay"), ]) - store.requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach, replayBarrierToken: replayBarrierToken) await router.waitForCount(of: "mobile.terminal.replay", atLeast: replayCountAfterMount + 1) let retryRequested = await router.waitForCount( of: "mobile.terminal.replay", @@ -475,7 +475,7 @@ import Testing let transport = try #require(box.get()) await router.holdNextReplayResponses() - store.requestTerminalReplay(surfaceID: surfaceID) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach) let oldReplayInFlight = await router.waitForCount( of: "mobile.terminal.replay", atLeast: replayCountAfterMount + 1 @@ -542,7 +542,7 @@ import Testing renderGridFrame(surfaceID: surfaceID, seq: 98, text: "stale-replay-2"), renderGridFrame(surfaceID: surfaceID, seq: 99, text: "stale-replay-3"), ]) - store.requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: replayBarrierToken) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach, replayBarrierToken: replayBarrierToken) let exhaustedRetriesSent = await router.waitForCount(of: "mobile.terminal.replay", atLeast: replayCountAfterMount + 3) #expect(exhaustedRetriesSent) let replaySettled = try await pollUntil { diff --git a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridReplayRetryExhaustionTests.swift b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridReplayRetryExhaustionTests.swift index 01bb92bb2999..e377cbb290e0 100644 --- a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridReplayRetryExhaustionTests.swift +++ b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridReplayRetryExhaustionTests.swift @@ -24,7 +24,7 @@ import Testing let transport = try #require(box.get()) await router.holdNextReplayResponses() - store.requestTerminalReplay(surfaceID: surfaceID) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach) let oldReplayInFlight = await router.waitForCount( of: "mobile.terminal.replay", atLeast: replayCountAfterMount + 1 diff --git a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridReplayStalenessTests.swift b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridReplayStalenessTests.swift index 648397c7dd82..d7b3c30ea852 100644 --- a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridReplayStalenessTests.swift +++ b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellRenderGridReplayStalenessTests.swift @@ -165,7 +165,7 @@ func screenAnchoredReplayBaselinesNextLiveDelta(historyRows: UInt64) async throw await router.holdNextReplayResponses() let replayCountBeforeHeldReplay = await router.count(of: "mobile.terminal.replay") - store.requestTerminalReplay(surfaceID: "live-terminal") + store.requestTerminalReplay(surfaceID: "live-terminal", trigger: .coldAttach) let heldReplayRequested = try await pollUntil { await router.count(of: "mobile.terminal.replay") > replayCountBeforeHeldReplay } @@ -229,7 +229,7 @@ func screenAnchoredReplayBaselinesNextLiveDelta(historyRows: UInt64) async throw await router.holdNextReplayResponses() let replayCountBeforeHeldReplay = await router.count(of: "mobile.terminal.replay") - store.requestTerminalReplay(surfaceID: "live-terminal") + store.requestTerminalReplay(surfaceID: "live-terminal", trigger: .coldAttach) let heldReplayRequested = try await pollUntil { await router.count(of: "mobile.terminal.replay") > replayCountBeforeHeldReplay } @@ -297,7 +297,7 @@ func screenAnchoredReplayBaselinesNextLiveDelta(historyRows: UInt64) async throw await router.holdNextReplayResponses() let replayCountBeforeHeldReplay = await router.count(of: "mobile.terminal.replay") - store.requestTerminalReplay(surfaceID: "live-terminal") + store.requestTerminalReplay(surfaceID: "live-terminal", trigger: .coldAttach) let heldReplayRequested = try await pollUntil { await router.count(of: "mobile.terminal.replay") > replayCountBeforeHeldReplay } @@ -365,7 +365,7 @@ func screenAnchoredReplayBaselinesNextLiveDelta(historyRows: UInt64) async throw await router.holdNextReplayResponses() let replayCountBeforeHeldReplay = await router.count(of: "mobile.terminal.replay") - store.requestTerminalReplay(surfaceID: "live-terminal") + store.requestTerminalReplay(surfaceID: "live-terminal", trigger: .coldAttach) let heldReplayRequested = try await pollUntil { await router.count(of: "mobile.terminal.replay") > replayCountBeforeHeldReplay } @@ -434,7 +434,7 @@ func screenAnchoredReplayBaselinesNextLiveDelta(historyRows: UInt64) async throw await router.holdNextReplayResponses() let replayCountBeforeHeldReplay = await router.count(of: "mobile.terminal.replay") - store.requestTerminalReplay(surfaceID: "live-terminal") + store.requestTerminalReplay(surfaceID: "live-terminal", trigger: .coldAttach) let heldReplayRequested = try await pollUntil { await router.count(of: "mobile.terminal.replay") > replayCountBeforeHeldReplay } diff --git a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellReplayDropRecoveryTests.swift b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellReplayDropRecoveryTests.swift index 7639baa0a1c4..0773e26f7688 100644 --- a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellReplayDropRecoveryTests.swift +++ b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellReplayDropRecoveryTests.swift @@ -47,7 +47,7 @@ import Testing recoveryRenderGridFrame(surfaceID: surfaceID, seq: 12, text: "current"), recoveryRenderGridFrame(surfaceID: surfaceID, seq: 12, text: "current"), ]) - store.requestTerminalReplay(surfaceID: surfaceID) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach) await router.waitForCount(of: "mobile.terminal.replay", atLeast: replayCountAfterMount + 1) store.terminalReplayBarrierTokensBySurfaceID[surfaceID] = UUID() diff --git a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellReplayFallbackScreenTests.swift b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellReplayFallbackScreenTests.swift index 5043566463b3..52a5809477db 100644 --- a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellReplayFallbackScreenTests.swift +++ b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/MobileShellReplayFallbackScreenTests.swift @@ -1,3 +1,4 @@ +import CMUXMobileCore import Foundation import Testing @testable import CmuxMobileShell @@ -35,6 +36,7 @@ import Testing let replayBarrierToken = store.beginTerminalReplayBarrier(surfaceID: "live-terminal") store.requestTerminalReplay( surfaceID: "live-terminal", + trigger: .coldAttach, replayBarrierToken: replayBarrierToken ) await router.waitForCount( diff --git a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalByteGapRebaseTests.swift b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalByteGapRebaseTests.swift index a22862faef24..839ef266313c 100644 --- a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalByteGapRebaseTests.swift +++ b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalByteGapRebaseTests.swift @@ -1,3 +1,4 @@ +import CMUXMobileCore import Foundation import Testing @testable import CmuxMobileShell @@ -68,7 +69,7 @@ import Testing #expect(firstDelivered) await router.holdNextReplayResponses() - store.requestTerminalReplay(surfaceID: surfaceID) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach) await router.waitForCount(of: "mobile.terminal.replay", atLeast: replayCountAfterMount + 1) #expect(store.terminalReplaySurfaceIDsInFlight.contains(surfaceID)) diff --git a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalOutputDeliveryQueueTests.swift b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalOutputDeliveryQueueTests.swift index 6b5ddb6567f1..50c4b4e1646d 100644 --- a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalOutputDeliveryQueueTests.swift +++ b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalOutputDeliveryQueueTests.swift @@ -548,7 +548,7 @@ import Testing let replayCountAfterExhaustion = await router.count(of: "mobile.terminal.replay") await router.enqueueReplayTexts(["resync-replay"]) - store.requestTerminalReplay(surfaceID: surfaceID) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach) let genericReplayRequested = await waitForReplayRequestCount(router, atLeast: replayCountAfterExhaustion + 1) #expect(genericReplayRequested, "generic resync must still work after fail-open clears the barrier") diff --git a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalReplayBarrierFollowUpTests.swift b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalReplayBarrierFollowUpTests.swift index b9f55244af56..7c4a1f58b7b9 100644 --- a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalReplayBarrierFollowUpTests.swift +++ b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalReplayBarrierFollowUpTests.swift @@ -1,3 +1,4 @@ +import CMUXMobileCore import Foundation import Testing @testable import CmuxMobileShell @@ -121,7 +122,7 @@ import Testing full: true )) let firstBarrierToken = store.beginTerminalReplayBarrier(surfaceID: surfaceID) - store.requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: firstBarrierToken) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach, replayBarrierToken: firstBarrierToken) await router.waitForCount(of: "mobile.terminal.replay", atLeast: 2) let firstReplayChunk = try #require(await iterator.next()) diff --git a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalViewportResyncTests.swift b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalViewportResyncTests.swift index 68854dcf32bd..29f7b7127581 100644 --- a/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalViewportResyncTests.swift +++ b/Packages/iOS/CmuxMobileShell/Tests/CmuxMobileShellTests/TerminalViewportResyncTests.swift @@ -1,3 +1,4 @@ +import CMUXMobileCore import CmuxMobileShellModel import Foundation import Testing @@ -221,7 +222,7 @@ import Testing rows: 30 ) ) - store.requestTerminalReplay(surfaceID: surfaceID) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach) #expect(store.terminalReplayBarrierTokensBySurfaceID[surfaceID] == nil) #expect( await router.waitForCount( @@ -289,7 +290,7 @@ import Testing store.terminalOutputDidProcess(surfaceID: surfaceID, streamToken: initialViewportChunk.streamToken) await router.failNextReplay(code: "viewport_transition") - store.requestTerminalReplay(surfaceID: surfaceID) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach) let replayRequested = await router.waitForCount(of: "mobile.terminal.replay", atLeast: 3) #expect(replayRequested) let requestSettled = try await pollUntil { @@ -388,7 +389,7 @@ import Testing surfaceID: surfaceID ) #expect(!staleAccepted, "output must be dropped while a resize acknowledgement is in flight") - store.requestTerminalReplay(surfaceID: surfaceID) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach) let replayBeforeAck = await router.waitForCount( of: "mobile.terminal.replay", atLeast: replayCountAfterBaseline + 1, @@ -720,7 +721,7 @@ import Testing // A recovery path (liveness probe repair, resync, advisory) asks for an // authoritative replay. It must defer to the pending acknowledgement, // not fire a competing replay. - store.requestTerminalReplay(surfaceID: surfaceID) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach) let competingReplay = await router.waitForCount( of: "mobile.terminal.replay", atLeast: replayCountAfterBaseline + 1, @@ -1310,7 +1311,7 @@ import Testing let staleToken = store.beginTerminalReplayBarrier(surfaceID: surfaceID) let currentToken = store.beginTerminalReplayBarrier(surfaceID: surfaceID) let replayCountBeforeStaleRequest = await router.count(of: "mobile.terminal.replay") - store.requestTerminalReplay(surfaceID: surfaceID, replayBarrierToken: staleToken) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach, replayBarrierToken: staleToken) let staleReplayRequested = await router.waitForCount( of: "mobile.terminal.replay", @@ -1453,7 +1454,7 @@ import Testing #expect(clearRequest.clearsViewport) let replayCount = await router.count(of: "mobile.terminal.replay") - store.requestTerminalReplay(surfaceID: surfaceID) + store.requestTerminalReplay(surfaceID: surfaceID, trigger: .coldAttach) let replaySent = await router.waitForCount( of: "mobile.terminal.replay", atLeast: replayCount + 1 diff --git a/ios/cmux/AppCompositionRoot.swift b/ios/cmux/AppCompositionRoot.swift index 8f71a878963e..3647700fc973 100644 --- a/ios/cmux/AppCompositionRoot.swift +++ b/ios/cmux/AppCompositionRoot.swift @@ -395,6 +395,7 @@ final class AppCompositionRoot { switch phase { case .active: analytics.terminalLatencyReporter.setForeground(true) + analytics.terminalTraceReporter.setForeground(true) diagnosticLog.recordAppEvent(.appForegrounded) connectionMethodStore.recordConfiguredMethodDiagnostic() let isFullForegroundReturn = !hasForegrounded || wasBackgrounded @@ -429,12 +430,14 @@ final class AppCompositionRoot { hasForegrounded = true case .inactive: analytics.terminalLatencyReporter.setForeground(false) + analytics.terminalTraceReporter.setForeground(false) diagnosticLog.recordAppEvent(.appBecameInactive) // The switcher opened; a swipe-kill from here may skip the // background transition entirely, so snapshot diagnostics now. break case .background: analytics.terminalLatencyReporter.setForeground(false) + analytics.terminalTraceReporter.setForeground(false) diagnosticLog.recordAppEvent(.appBackgrounded) wasBackgrounded = true Task { await irx.didEnterBackground() } diff --git a/web/services/observability/mobileNetworkOutcome.ts b/web/services/observability/mobileNetworkOutcome.ts index bfb7fd02b6a4..edc032085ac1 100644 --- a/web/services/observability/mobileNetworkOutcome.ts +++ b/web/services/observability/mobileNetworkOutcome.ts @@ -57,7 +57,7 @@ const allowedPropertyKeys = new Set([ "input_failed_count", "histogram_version", "input_to_output_histogram", "input_to_visible_histogram", "render_histogram", "duration_ms", "threshold_ms", "stage", "trace_id", "operation", "terminal_phase", - "replay_trigger", "surface_blank", "barrier_active", "replay_attempt", + "replay_trigger", "surface_blank", "barrier_active", "replay_attempt", "app_foreground", "model_count", "phase", "attempt", "retry_delay_ms", "stop_reason", "correlation_id", ]); @@ -99,6 +99,12 @@ export type MobileNetworkOutcome = { readonly barrierActive?: boolean; /** Zero-based retry index within the replay episode. */ readonly replayAttempt?: number; + /** + * Whether the app was on screen when this phase was recorded. A suspended + * app runs no code, so elapsed time that spans suspension was never spent + * waiting on screen; percentiles that mix the two are meaningless. + */ + readonly appForeground?: boolean; }; export type MobileTerminalLatencyWindow = { @@ -350,7 +356,7 @@ export function parseMobileTaskModelDiscovery(candidate: unknown): MobileTaskMod } type CoreObservation = Pick; -type Metadata = Pick; +type Metadata = Pick; /** Mirrors `MobileTerminalReplayTrigger` in CMUXMobileCore. */ const replayTriggers = new Set([ @@ -441,18 +447,20 @@ function parseInitialConnectionFields( /// keep that function under the repository complexity limit. function parseReplayContextFields( properties: Record, -): Pick | null { +): Pick | null { const replayTrigger = optionalSetValue(properties.replay_trigger, replayTriggers); const surfaceBlank = optionalBoolean(properties.surface_blank); const barrierActive = optionalBoolean(properties.barrier_active); + const appForeground = optionalBoolean(properties.app_foreground); const replayAttempt = optionalDiagnosticInteger(properties.replay_attempt, 0xff); if (replayTrigger === false || replayAttempt === false) return null; - if (surfaceBlank === null || barrierActive === null) return null; + if (surfaceBlank === null || barrierActive === null || appForeground === null) return null; return { ...(typeof replayTrigger === "string" ? { replayTrigger } : {}), ...(typeof surfaceBlank === "boolean" ? { surfaceBlank } : {}), ...(typeof barrierActive === "boolean" ? { barrierActive } : {}), ...(typeof replayAttempt === "number" ? { replayAttempt } : {}), + ...(typeof appForeground === "boolean" ? { appForeground } : {}), }; } @@ -536,6 +544,7 @@ export async function emitMobileNetworkOutcomes( "cmux.mobile.surface_blank": observation.surfaceBlank, "cmux.mobile.barrier_active": observation.barrierActive, "cmux.mobile.replay_attempt": observation.replayAttempt, + "cmux.mobile.app_foreground": observation.appForeground, }, (span) => { if (observation.outcome === "failure" || observation.outcome === "timeout") { diff --git a/web/tests/mobile-replay-stall-observability.test.ts b/web/tests/mobile-replay-stall-observability.test.ts index d130095b7818..a85697069898 100644 --- a/web/tests/mobile-replay-stall-observability.test.ts +++ b/web/tests/mobile-replay-stall-observability.test.ts @@ -24,6 +24,7 @@ describe("terminal replay stall telemetry", () => { surface_blank: true, barrier_active: true, replay_attempt: 1, + app_foreground: true, ...properties, }, }); @@ -49,6 +50,12 @@ describe("terminal replay stall telemetry", () => { expect(absent?.surfaceBlank).toBeUndefined(); }); + test("carries whether the stall was on screen or across suspension", () => { + expect(parseMobileNetworkOutcome(stall())?.appForeground).toBe(true); + expect(parseMobileNetworkOutcome(stall({ app_foreground: false }))?.appForeground).toBe(false); + expect(parseMobileNetworkOutcome(stall({ app_foreground: "yes" }))).toBeNull(); + }); + test("rejects a non-boolean blank flag and an unknown trigger", () => { expect(parseMobileNetworkOutcome(stall({ surface_blank: "yes" }))).toBeNull(); expect(parseMobileNetworkOutcome(stall({ replay_trigger: "madeUp" }))).toBeNull(); From d8a93068653ea1704ee485911402b38452e57d1b Mon Sep 17 00:00:00 2001 From: Abdulaziz Albahar <67667005+azooz2003-bit@users.noreply.github.com> Date: Wed, 23 Sep 2026 13:49:23 -0700 Subject: [PATCH 3/6] test(ios): a silently black-holed RPC transport must be condemned Red on purpose. A QUIC path can stop carrying traffic without closing: `receive()` never returns and never throws, so `readLoop` cannot tear the connection down, and `ensureConnected` hands the same transport to every later request because it returns the installed one unchecked. `timeoutPendingRequest` condemns a transport only through `recycleTransportIfActiveWrite`, which needs the timed-out request to be the active write AND the transport to already report itself closed. A path that black-holes after the write succeeded satisfies neither, so the deadline fails one request and leaves the corpse installed. The retry rides it and burns another full deadline. Two written requests answered by total silence is the evidence. The second test is the guard that keeps this from punishing a healthy lane: a transport still delivering other traffic must survive a request timeout. --- .../MobileCoreRPCSilentTransportTests.swift | 91 +++++++++++++++++++ 1 file changed, 91 insertions(+) create mode 100644 Packages/iOS/CmuxMobileRPC/Tests/CmuxMobileRPCTests/MobileCoreRPCSilentTransportTests.swift diff --git a/Packages/iOS/CmuxMobileRPC/Tests/CmuxMobileRPCTests/MobileCoreRPCSilentTransportTests.swift b/Packages/iOS/CmuxMobileRPC/Tests/CmuxMobileRPCTests/MobileCoreRPCSilentTransportTests.swift new file mode 100644 index 000000000000..4d8288e6b1de --- /dev/null +++ b/Packages/iOS/CmuxMobileRPC/Tests/CmuxMobileRPCTests/MobileCoreRPCSilentTransportTests.swift @@ -0,0 +1,91 @@ +import CMUXMobileCore +import Foundation +import Testing +@testable import CmuxMobileRPC + +/// A QUIC path can stop carrying traffic without closing: `receive()` never +/// returns and never throws, so the read loop cannot tear the connection down. +/// Every request then rides that corpse until its own deadline, and because +/// the deadline failed only the request, the retry rode it again. Two of those +/// is a minute of blank terminal on the phone. +@Suite struct MobileCoreRPCSilentTransportTests { + private func makeClient( + transport: any CmxByteTransport, + port: Int, + timeoutNanoseconds: UInt64 = 200_000_000 + ) throws -> MobileCoreRPCClient { + let route = try hostPortRoute(kind: .debugLoopback, host: "127.0.0.1", port: port) + let runtime = TestMobileSyncRuntime( + transportFactory: FixedTransportFactory(transport: transport), + rpcRequestTimeoutNanoseconds: timeoutNanoseconds + ) + let ticket = try CmxAttachTicket( + workspaceID: "workspace-main", + terminalID: "terminal-main", + macDeviceID: "test-mac", + macDisplayName: "Test Mac", + routes: [route], + expiresAt: Date().addingTimeInterval(60), + authToken: "ticket-secret" + ) + return MobileCoreRPCClient( + runtime: runtime, + route: route, + ticket: ticket, + allowsStackAuthFallback: true + ) + } + + private func replayRequest(id: String) throws -> Data { + try MobileCoreRPCClient.requestData( + method: "mobile.terminal.replay", + params: ["workspace_id": "workspace-main", "surface_id": "surface-main"], + id: id + ) + } + + @Test func aTransportThatDeliversNothingIsCondemnedOnTheSecondTimeout() async throws { + let transport = ControllableResponseTransport(closeEndsReceive: true) + let client = try makeClient(transport: transport, port: 59310) + + do { + _ = try await client.sendRequest(try replayRequest(id: "replay-1")) + Issue.record("Expected the first replay to fail") + } catch {} + // One unanswered request is ambiguous; the connection survives it. + #expect(await transport.closed() == false) + + do { + _ = try await client.sendRequest(try replayRequest(id: "replay-2")) + Issue.record("Expected the retry to fail") + } catch {} + + // Both writes succeeded and the transport never reported itself + // closed, so nothing else in the session could condemn it. Two + // written requests answered by total silence is the evidence. + #expect(await transport.closed()) + } + + /// The guard that keeps this from punishing a healthy connection: if + /// anything at all arrived while the request was outstanding, the lane is + /// demonstrably alive and only the request failed. + @Test func aTransportStillDeliveringIsKeptWhenOneRequestTimesOut() async throws { + let transport = ControllableResponseTransport(closeEndsReceive: true) + let client = try makeClient(transport: transport, port: 59311) + + async let outcome: Void = { + do { + _ = try await client.sendRequest(try replayRequest(id: "replay-2")) + Issue.record("Expected the replay to fail") + } catch {} + }() + + await transport.waitUntilSent(count: 1) + // Unrelated inbound traffic: proves the lane still carries bytes even + // though this request is never answered. + try await transport.deliverResponse(id: "someone-else", status: "ok") + await outcome + + #expect(await transport.closed() == false) + } +} From c9bb4c8bf0872b493b6682f670dfec2b849eee0f Mon Sep 17 00:00:00 2001 From: Abdulaziz Albahar <67667005+azooz2003-bit@users.noreply.github.com> Date: Wed, 23 Sep 2026 13:49:24 -0700 Subject: [PATCH 4/6] fix(ios): condemn an RPC transport that goes silent across two requests This is the blank iOS terminal. A surface rebuilt blank is repainted only by a replay, so the blank lasts exactly as long as that one RPC, and the RPC was riding a dead connection nothing would replace. Field evidence from one phone, foreground-only: 19:08:45 replay attempt -> 29.5s, no response 19:09:15 replay attempt -> 29.5s, no response 19:09:44 replay attempt -> 6.8s, failed 19:09:51 fresh dial, connected in 262ms -> replays APPLIED in 1.1s No new dial happened between 19:08:45 and 19:09:51. All three attempts rode one transport that had reported `Transport connected` in 217-709ms and `Connection recovery succeeded`. Workspace-list refreshes over the same session were failing too, so this was never replay-specific. Count inbound deliveries, snapshot the count when arming a response timeout, and on expiry treat "this request reached the wire and not one byte arrived while it was outstanding" as a silent timeout. Two of those in a row condemns the connection, so the next request dials fresh instead of inheriting the corpse. Three deliberate narrowings, each pinned by an existing test: - One silent timeout is not enough. A host can be slow or silent on a single method while its connection is healthy, which `responseTimeoutDoesNotCloseMultiplexedSession` pins. Any inbound delivery resets the streak, so it only survives a lane gone quiet. - A request that expired while still queued never reached the wire and proves nothing about delivery; it means the write queue is backed up, which the head-of-line handling already owns. Without this, `requestDeadlineOrCancellationPreservesNativeWrite` correctly fails. - The installed connection must be unchanged, so a timeout cannot condemn a connection that already replaced the one it belonged to. Halves the field blank: the lane is now replaced on the second attempt rather than surviving three. --- .../CmuxMobileRPC/MobileCoreRPCSession.swift | 82 ++++++++++++++++++- 1 file changed, 79 insertions(+), 3 deletions(-) diff --git a/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileCoreRPCSession.swift b/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileCoreRPCSession.swift index 87dafa941568..ef5f62c8eb2b 100644 --- a/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileCoreRPCSession.swift +++ b/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileCoreRPCSession.swift @@ -92,6 +92,26 @@ actor MobileCoreRPCSession { private var connectionTask: ConnectingTask? private var recordedConnectCancellationAttemptIDs: Set = [] private var installedConnectionID: UUID? + /// Counts inbound deliveries on the installed transport. + /// + /// A QUIC path can stop carrying traffic without closing: `receive()` + /// never returns and never throws, so `readLoop` cannot tear the + /// connection down and every request rides it until its own deadline. + /// Comparing this counter across a request's lifetime answers the one + /// question that separates "this request is slow" from "this transport is + /// dead": did anything at all arrive while it was outstanding. + private var inboundDeliveryCount: UInt64 = 0 + /// Consecutive response timeouts that saw no inbound delivery at all. + /// + /// One unanswered request is genuinely ambiguous: a host can be slow or + /// silent on a single method while its connection is perfectly healthy, + /// and `responseTimeoutDoesNotCloseMultiplexedSession` pins that. Two in a + /// row without a single byte arriving in between is not ambiguous. Any + /// inbound delivery resets this, so the streak only survives a lane that + /// has gone completely quiet. + private var silentTimeoutStreak = 0 + /// Silent timeouts required before the installed transport is condemned. + static let minimumSilentTimeoutsBeforeCondemning = 2 private var readerTask: Task? /// Watches the complete native connection, separately from the control /// lane reader. IROH can close the shared QUIC session without making a @@ -1038,6 +1058,9 @@ actor MobileCoreRPCSession { } // Enforce size per decoded frame. A chunk can finish one valid // maximum-size frame and also contain bytes from the next frame. + inboundDeliveryCount &+= 1 + // The lane just proved it still carries bytes. + silentTimeoutStreak = 0 buffer.append(chunk) do { while !Task.isCancelled, installedConnectionID == connectionID { @@ -1085,7 +1108,11 @@ actor MobileCoreRPCSession { pipelinedContinuation?.resume(returning: .cancelled) } - private func timeoutPendingRequest(requestID: String) async { + private func timeoutPendingRequest( + requestID: String, + armedConnectionID: UUID? = nil, + armedInboundCount: UInt64 = 0 + ) async { let legacyContinuation = pending.removeValue(forKey: requestID) let pipelinedSettlement = pipelinedPending.removeValue( forKey: requestID @@ -1094,6 +1121,11 @@ actor MobileCoreRPCSession { return } requestTimeoutTasks.removeValue(forKey: requestID)?.cancel() + // A request still sitting in the write queue never reached the wire, + // so its expiry says nothing about whether the transport can deliver. + // It means the queue is backed up, which the head-of-line handling + // below already owns. + let reachedTheWire = queuedWriteIDs[requestID] == nil var condemnedWriteRequestID = requestID if let queuedWriteID = queuedWriteIDs.removeValue(forKey: requestID) { cancelledQueuedWriteIDs.insert(queuedWriteID) @@ -1107,13 +1139,34 @@ actor MobileCoreRPCSession { condemnedWriteRequestID = write.requestID } } - let error: MobileShellConnectionError = if await recycleTransportIfActiveWrite( + var error: MobileShellConnectionError = if await recycleTransportIfActiveWrite( requestID: condemnedWriteRequestID ) { .transportWriteTimedOut } else { .requestTimedOut } + // `recycleTransportIfActiveWrite` only condemns a transport whose + // *write* is stuck and that already reports itself closed. A path that + // black-holes after the write succeeded satisfies neither, so without + // this the dead transport stays installed and `ensureConnected` hands + // it to the retry, which burns another full deadline. Two of those is + // a minute of blank terminal. + if case .requestTimedOut = error, + reachedTheWire, + transportDeliveredNothing( + armedConnectionID: armedConnectionID, + armedInboundCount: armedInboundCount + ) { + silentTimeoutStreak += 1 + if silentTimeoutStreak >= Self.minimumSilentTimeoutsBeforeCondemning { + silentTimeoutStreak = 0 + error = .connectionClosed + await tearDown(error: .connectionClosed) + } + } else if reachedTheWire { + silentTimeoutStreak = 0 + } let settlement = PendingRequestSettlement.response(.failure(error)) legacyContinuation?.resume(returning: settlement) switch pipelinedSettlement { @@ -1150,6 +1203,8 @@ actor MobileCoreRPCSession { timeoutNanoseconds: UInt64 ) { requestTimeoutTasks[requestID]?.cancel() + let armedConnectionID = installedConnectionID + let armedInboundCount = inboundDeliveryCount requestTimeoutTasks[requestID] = Task { [weak self, taskTimeout] in do { try await taskTimeout.sleep(nanoseconds: timeoutNanoseconds) @@ -1157,10 +1212,31 @@ actor MobileCoreRPCSession { return } guard let self else { return } - await self.timeoutPendingRequest(requestID: requestID) + await self.timeoutPendingRequest( + requestID: requestID, + armedConnectionID: armedConnectionID, + armedInboundCount: armedInboundCount + ) } } + /// Whether a timed-out request proves its transport can no longer deliver. + /// + /// Only a transport that delivered *nothing* for the whole life of the + /// request is condemned. If anything arrived (another response, an event + /// frame, a terminal delta) the lane is demonstrably alive and this one + /// request was merely slow, so the request fails alone. Requires the same + /// installed connection throughout: a timeout belonging to a connection + /// that has already been replaced says nothing about the current one. + private func transportDeliveredNothing( + armedConnectionID: UUID?, + armedInboundCount: UInt64 + ) -> Bool { + guard let armedConnectionID, + installedConnectionID == armedConnectionID else { return false } + return inboundDeliveryCount == armedInboundCount + } + func settlePendingRequest( requestID: String, settlement: PendingRequestSettlement From 93577e632029f11fdd7236c10de2521824f146ce Mon Sep 17 00:00:00 2001 From: Abdulaziz Albahar <67667005+azooz2003-bit@users.noreply.github.com> Date: Wed, 23 Sep 2026 14:20:32 -0700 Subject: [PATCH 5/6] fix(ios): scope silent-timeout evidence to one connection and one window Two CodeRabbit findings on the condemnation heuristic, both correct. `tearDown` cleared the installed connection but not `silentTimeoutStreak`, so a replacement transport inherited the streak accumulated against the one it replaced. Connection A leaving the streak at 1 meant B was condemned on its first silent timeout, on a single piece of evidence, which is exactly what the two-timeout rule exists to prevent. Evidence is per connection; reset it there. `timeoutPendingRequest` also incremented the shared streak once per timed out request, so concurrent requests could condemn a transport inside one silence window. That is the field shape: a foreground repaint fires a replay for every mounted surface at once, and six replays answered by one quiet period is one piece of evidence, not six. Stamp each armed timeout with the current silent epoch and count a timeout only when it was armed after the last counted one. Adds the concurrency case as a test. 197/197 pass. --- .../CmuxMobileRPC/MobileCoreRPCSession.swift | 46 +++++++++++++------ .../MobileCoreRPCSilentTransportTests.swift | 21 +++++++++ 2 files changed, 53 insertions(+), 14 deletions(-) diff --git a/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileCoreRPCSession.swift b/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileCoreRPCSession.swift index ef5f62c8eb2b..1e2622c2f090 100644 --- a/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileCoreRPCSession.swift +++ b/Packages/iOS/CmuxMobileRPC/Sources/CmuxMobileRPC/MobileCoreRPCSession.swift @@ -110,6 +110,13 @@ actor MobileCoreRPCSession { /// inbound delivery resets this, so the streak only survives a lane that /// has gone completely quiet. private var silentTimeoutStreak = 0 + /// Increments once per counted silent timeout. + /// + /// Requests armed before the previous silent timeout belong to the same + /// silence window. Six replays fired together and answered by one quiet + /// period is one piece of evidence, not six, so only a request armed + /// after the last counted timeout may advance the streak. + private var silentTimeoutEpoch: UInt64 = 0 /// Silent timeouts required before the installed transport is condemned. static let minimumSilentTimeoutsBeforeCondemning = 2 private var readerTask: Task? @@ -400,6 +407,10 @@ actor MobileCoreRPCSession { return } isTearingDown = true + // Evidence is per connection. A replacement transport must not + // inherit a streak accumulated against the one it replaces, or its + // first silent timeout condemns it on a single piece of evidence. + silentTimeoutStreak = 0 defer { isTearingDown = false let waiters = tearDownWaiters @@ -1111,7 +1122,8 @@ actor MobileCoreRPCSession { private func timeoutPendingRequest( requestID: String, armedConnectionID: UUID? = nil, - armedInboundCount: UInt64 = 0 + armedInboundCount: UInt64 = 0, + armedSilentEpoch: UInt64 = 0 ) async { let legacyContinuation = pending.removeValue(forKey: requestID) let pipelinedSettlement = pipelinedPending.removeValue( @@ -1152,20 +1164,24 @@ actor MobileCoreRPCSession { // this the dead transport stays installed and `ensureConnected` hands // it to the retry, which burns another full deadline. Two of those is // a minute of blank terminal. - if case .requestTimedOut = error, - reachedTheWire, - transportDeliveredNothing( - armedConnectionID: armedConnectionID, - armedInboundCount: armedInboundCount - ) { - silentTimeoutStreak += 1 - if silentTimeoutStreak >= Self.minimumSilentTimeoutsBeforeCondemning { + if case .requestTimedOut = error, reachedTheWire { + if transportDeliveredNothing( + armedConnectionID: armedConnectionID, + armedInboundCount: armedInboundCount + ) { + // Requests armed before the last counted timeout share its + // silence window; they are already represented by it. + if armedSilentEpoch == silentTimeoutEpoch { + silentTimeoutEpoch &+= 1 + silentTimeoutStreak += 1 + if silentTimeoutStreak >= Self.minimumSilentTimeoutsBeforeCondemning { + error = .connectionClosed + await tearDown(error: .connectionClosed) + } + } + } else { silentTimeoutStreak = 0 - error = .connectionClosed - await tearDown(error: .connectionClosed) } - } else if reachedTheWire { - silentTimeoutStreak = 0 } let settlement = PendingRequestSettlement.response(.failure(error)) legacyContinuation?.resume(returning: settlement) @@ -1205,6 +1221,7 @@ actor MobileCoreRPCSession { requestTimeoutTasks[requestID]?.cancel() let armedConnectionID = installedConnectionID let armedInboundCount = inboundDeliveryCount + let armedSilentEpoch = silentTimeoutEpoch requestTimeoutTasks[requestID] = Task { [weak self, taskTimeout] in do { try await taskTimeout.sleep(nanoseconds: timeoutNanoseconds) @@ -1215,7 +1232,8 @@ actor MobileCoreRPCSession { await self.timeoutPendingRequest( requestID: requestID, armedConnectionID: armedConnectionID, - armedInboundCount: armedInboundCount + armedInboundCount: armedInboundCount, + armedSilentEpoch: armedSilentEpoch ) } } diff --git a/Packages/iOS/CmuxMobileRPC/Tests/CmuxMobileRPCTests/MobileCoreRPCSilentTransportTests.swift b/Packages/iOS/CmuxMobileRPC/Tests/CmuxMobileRPCTests/MobileCoreRPCSilentTransportTests.swift index 4d8288e6b1de..57d569ae0ff1 100644 --- a/Packages/iOS/CmuxMobileRPC/Tests/CmuxMobileRPCTests/MobileCoreRPCSilentTransportTests.swift +++ b/Packages/iOS/CmuxMobileRPC/Tests/CmuxMobileRPCTests/MobileCoreRPCSilentTransportTests.swift @@ -66,6 +66,27 @@ import Testing #expect(await transport.closed()) } + /// Six replays fired together and answered by one quiet period is one + /// piece of evidence, not six. Without a silence-window guard a single + /// quiet moment condemns the transport on concurrent requests alone. + @Test func concurrentTimeoutsInOneSilenceWindowAreOnePieceOfEvidence() async throws { + let transport = ControllableResponseTransport(closeEndsReceive: true) + let client = try makeClient(transport: transport, port: 59312) + + await withTaskGroup(of: Void.self) { group in + for index in 0..<4 { + group.addTask { + _ = try? await client.sendRequest( + try self.replayRequest(id: "concurrent-\(index)") + ) + } + } + await group.waitForAll() + } + + #expect(await transport.closed() == false) + } + /// The guard that keeps this from punishing a healthy connection: if /// anything at all arrived while the request was outstanding, the lane is /// demonstrably alive and only the request failed. From 0e43d39e1f09db454f0c0723f680d5f70b6efaed Mon Sep 17 00:00:00 2001 From: Abdulaziz Albahar <67667005+azooz2003-bit@users.noreply.github.com> Date: Wed, 23 Sep 2026 14:21:53 -0700 Subject: [PATCH 6/6] fix(ios): app_foreground must mean the whole trace was on screen It stamped the scene state at emission time, so a replay that began on screen, spent an hour suspended and settled after reactivation reported `app_foreground: true` carrying a duration that was mostly pocket time. That is indistinguishable from a replay that really did spend its whole life in front of someone, which is the exact confusion the flag was added to remove. Count transitions out of the foreground, record the count at `started`, and report true only when the app is foreground now AND the count has not moved. A trace whose start was dropped under admission pressure reports false: an operation whose beginning is unknown cannot claim its elapsed time was screen time. --- .../MobileTerminalTraceReporter.swift | 32 ++++++++++++++++--- .../MobileTerminalTraceStallTests.swift | 20 ++++++++++++ 2 files changed, 48 insertions(+), 4 deletions(-) diff --git a/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift b/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift index 84d82ae923fe..b93675c51d88 100644 --- a/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift +++ b/Packages/iOS/CmuxMobileAnalytics/Sources/CmuxMobileAnalytics/MobileTerminalTraceReporter.swift @@ -18,12 +18,22 @@ public final class MobileTerminalTraceReporter: Sendable { let operation: DiagnosticTerminalTraceOperation let tNanos: UInt64 let replayContext: MobileTerminalReplayTraceContext? + /// Background-transition count when this operation began. + let backgroundEpoch: UInt64 } private struct State: Sendable { var starts: [UInt64: Start] = [:] var windowStart: UInt64 = 0 var emittedInWindow = 0 + /// Counts transitions out of the foreground. + /// + /// Comparing this against the value recorded at `started` answers the + /// question the flag below cannot: an operation that began on screen, + /// spent an hour suspended and settled after reactivation is in the + /// foreground when it reports, but its elapsed time is not screen + /// time. Only an unchanged count means the whole trace was on screen. + var backgroundEpoch: UInt64 = 0 /// Whether the app was in the foreground when the phase was recorded. /// /// A suspended app runs no code, so an operation that spans @@ -56,7 +66,10 @@ public final class MobileTerminalTraceReporter: Sendable { } func setForeground(_ active: Bool) { - queue.async { [self] in state.isForeground = active } + queue.async { [self] in + if !active, state.isForeground { state.backgroundEpoch &+= 1 } + state.isForeground = active + } } func drain() async { @@ -127,7 +140,8 @@ public final class MobileTerminalTraceReporter: Sendable { state.starts[traceID.rawValue] = Start( operation: operation, tNanos: event.tNanos, - replayContext: event.c.flatMap(MobileTerminalReplayTraceContext.init(encoded:)) + replayContext: event.c.flatMap(MobileTerminalReplayTraceContext.init(encoded:)), + backgroundEpoch: state.backgroundEpoch ) return nil } @@ -147,7 +161,7 @@ public final class MobileTerminalTraceReporter: Sendable { outcome: "stalled", replayContext: event.c.flatMap(MobileTerminalReplayTraceContext.init(encoded:)) ?? start?.replayContext, - isForeground: state.isForeground + isForeground: stayedForeground(start, state: state) ) } guard phase == .applied || phase == .failed || phase == .discarded else { return nil } @@ -170,10 +184,20 @@ public final class MobileTerminalTraceReporter: Sendable { durationMilliseconds: duration, outcome: outcome, replayContext: start?.replayContext, - isForeground: state.isForeground + isForeground: stayedForeground(start, state: state) ) } + /// Whether the whole operation stayed on screen. + /// + /// Conservative when the start was dropped under admission pressure: an + /// operation whose beginning is unknown cannot claim its elapsed time was + /// screen time. + private static func stayedForeground(_ start: Start?, state: State) -> Bool { + guard let start else { return false } + return state.isForeground && start.backgroundEpoch == state.backgroundEpoch + } + private static func admitEmission(at now: UInt64, state: inout State) -> Bool { if state.windowStart == 0 || now < state.windowStart || now - state.windowStart >= 60 * 1_000_000_000 { diff --git a/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift b/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift index 6144a6bd2a0a..0a0489d09462 100644 --- a/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift +++ b/Packages/iOS/CmuxMobileAnalytics/Tests/CmuxMobileAnalyticsTests/MobileTerminalTraceStallTests.swift @@ -126,6 +126,26 @@ struct MobileTerminalTraceStallTests { #expect(values.last?.properties["duration_ms"] == .int(60_000)) } + /// The case that makes the flag trustworthy: a replay that begins on + /// screen, spans suspension, and settles after reactivation is in the + /// foreground when it reports, but its elapsed time is not screen time. + @Test func aTraceThatSpannedSuspensionIsNotReportedAsOnScreen() async { + let (reporter, uploader) = makeReporter() + let trace = DiagnosticTerminalTraceID(rawValue: 0xB1B2)! + let context = MobileTerminalReplayTraceContext( + trigger: .outputReset, surfaceIsBlank: true, barrierActive: true, attempt: 0 + ) + reporter.ingest(event(.started, at: 1_000_000_000, trace: trace, c: context.encoded)) + reporter.setForeground(false) + reporter.setForeground(true) + reporter.ingest(event(.failed, at: 160_000_000_000, trace: trace)) + await reporter.flush() + + let values = await uploader.uploadedEvents + #expect(values.count == 1) + #expect(values.last?.properties["app_foreground"] == .bool(false)) + } + @Test func stallWithoutAnElapsedMagnitudeIsDropped() async { let (reporter, uploader) = makeReporter() let trace = DiagnosticTerminalTraceID(rawValue: 0xB1A7)!