From a5410da49278c683dfa6df894cc40550356bb026 Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Sun, 13 Sep 2026 19:12:26 -0700 Subject: [PATCH] diagnostics(cloud): correlate machine terminal attachment state --- Sources/Cloud/CloudMachineLinkManager.swift | 37 ++++++++++--- .../Cloud/CloudTerminalAttachmentLog.swift | 54 +++++++++++++++---- .../Cloud/CloudTuiManualMirrorSession.swift | 8 +-- Sources/CloudTerminalOverlayCoordinator.swift | 9 ++++ .../CloudTerminalAttachmentResolver.swift | 10 +++- .../CmuxTuiSurfaceProvider+ManualMirror.swift | 6 ++- ...CloudTerminalAttachmentRecoveryTests.swift | 24 +++++++++ 7 files changed, 122 insertions(+), 26 deletions(-) diff --git a/Sources/Cloud/CloudMachineLinkManager.swift b/Sources/Cloud/CloudMachineLinkManager.swift index 550ee1b6fa94..847ef9b54b8d 100644 --- a/Sources/Cloud/CloudMachineLinkManager.swift +++ b/Sources/Cloud/CloudMachineLinkManager.swift @@ -143,20 +143,26 @@ actor CloudMachineLinkManager { if let inFlight = connecting[machineID] { return try await inFlight.value } + let correlationID = UUID().uuidString.lowercased() StartupBreadcrumbLog.append( "cloud.link.start", - fields: ["machine": machineID, "knownDevice": paths.deviceFingerprint(for: machineID) == nil ? "0" : "1"] + fields: [ + "machine": machineID, + "knownDevice": paths.deviceFingerprint(for: machineID) == nil ? "0" : "1", + "correlation": correlationID, + "outcome": "started" + ] ) if let failure = lastFailure[machineID], Date().timeIntervalSince(failure.at) < retryBackoff { - recordPreflightFailure(machineID: machineID, reason: "retry_backoff") + recordPreflightFailure(machineID: machineID, reason: "retry_backoff", correlationID: correlationID) throw ManagerError.retryLater(failure.error) } guard let clientURL else { - recordPreflightFailure(machineID: machineID, reason: "client_missing") + recordPreflightFailure(machineID: machineID, reason: "client_missing", correlationID: correlationID) throw ManagerError.clientMissing } guard privateRoutes[machineID] != nil else { - recordPreflightFailure(machineID: machineID, reason: "private_route_required") + recordPreflightFailure(machineID: machineID, reason: "private_route_required", correlationID: correlationID) throw ManagerError.privateRouteRequired(machineID) } #if DEBUG @@ -244,7 +250,12 @@ actor CloudMachineLinkManager { #endif StartupBreadcrumbLog.append( "cloud.link.connected", - fields: ["machine": machineID, "session": connected.session] + fields: [ + "machine": machineID, + "session": connected.session, + "correlation": correlationID, + "outcome": "connected" + ] ) pushHostTheme(machineID: machineID, socketPath: connected.socketPath) return connected @@ -257,7 +268,12 @@ actor CloudMachineLinkManager { #endif StartupBreadcrumbLog.append( "cloud.link.failed", - fields: ["machine": machineID, "error": CloudDiagnosticFailure.classify(error).rawValue] + fields: [ + "machine": machineID, + "error": CloudDiagnosticFailure.classify(error).rawValue, + "correlation": correlationID, + "outcome": "failed" + ] ) throw error } @@ -268,10 +284,15 @@ actor CloudMachineLinkManager { } /// Records a preflight failure without mutating link retry state. - private func recordPreflightFailure(machineID: String, reason: String) { + private func recordPreflightFailure(machineID: String, reason: String, correlationID: String) { StartupBreadcrumbLog.append( "cloud.link.failed", - fields: ["machine": machineID, "error": reason] + fields: [ + "machine": machineID, + "error": reason, + "correlation": correlationID, + "outcome": "failed" + ] ) } diff --git a/Sources/Cloud/CloudTerminalAttachmentLog.swift b/Sources/Cloud/CloudTerminalAttachmentLog.swift index f20e08e7303a..a6b7df9e575b 100644 --- a/Sources/Cloud/CloudTerminalAttachmentLog.swift +++ b/Sources/Cloud/CloudTerminalAttachmentLog.swift @@ -11,43 +11,75 @@ import os struct CloudTerminalAttachmentLog: Sendable { private static let logger = Logger(subsystem: "com.cmuxterm.app", category: "CloudTerminalAttachment") + /// Correlates resolver, attachment, and presentation observations for one + /// attachment transaction without carrying terminal contents or payloads. + let correlationID: String + + init(correlationID: String = UUID().uuidString.lowercased()) { + self.correlationID = correlationID + } + func resolution(machineID: String, terminalID: String, attempt: Int, outcome: CloudTuiSurfaceIDResolution) { switch outcome { case let .resolved(surfaceID): - Self.logger.info("resolve machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) attempt=\(attempt) outcome=resolved surface=\(surfaceID)") + Self.logger.info("correlation=\(correlationID, privacy: .public) resolve machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) attempt=\(attempt) outcome=resolved surface=\(surfaceID)") case .noPlacement: - Self.logger.info("resolve machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) attempt=\(attempt) outcome=needs-projection") + Self.logger.info("correlation=\(correlationID, privacy: .public) resolve machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) attempt=\(attempt) outcome=needs-projection") case .exited: - Self.logger.notice("resolve machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) attempt=\(attempt) outcome=exited") + Self.logger.notice("correlation=\(correlationID, privacy: .public) resolve machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) attempt=\(attempt) outcome=exited") case let .retryable(reason, _): - Self.logger.error("resolve machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) attempt=\(attempt) outcome=retryable reason=\(reason, privacy: .private)") + Self.logger.error("correlation=\(correlationID, privacy: .public) resolve machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) attempt=\(attempt) outcome=retryable reason=\(reason, privacy: .private)") } } func daemonAnswer(machineID: String, terminalID: String, command: String, answer: CloudTuiDaemonAnswer) { switch answer { case let .rejected(code): - Self.logger.info("daemon machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) command=\(command, privacy: .public) rejected=\(code, privacy: .private)") + Self.logger.info("correlation=\(correlationID, privacy: .public) daemon machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) command=\(command, privacy: .public) outcome=rejected rejected=\(code, privacy: .private)") case let .transportFailure(text): - Self.logger.error("daemon machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) command=\(command, privacy: .public) transport-failure=\(text, privacy: .private)") + Self.logger.error("correlation=\(correlationID, privacy: .public) daemon machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) command=\(command, privacy: .public) outcome=transport-failure transport-failure=\(text, privacy: .private)") case let .unrecognized(text): - Self.logger.error("daemon machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) command=\(command, privacy: .public) unrecognized=\(text, privacy: .private)") + Self.logger.error("correlation=\(correlationID, privacy: .public) daemon machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) command=\(command, privacy: .public) outcome=unrecognized unrecognized=\(text, privacy: .private)") } } func projection(machineID: String, terminalID: String, placement: SurfaceRemotePlacement) { - Self.logger.info("project machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) workspace=\(placement.workspaceID, privacy: .public) tab=\(placement.tabID, privacy: .public)") + Self.logger.info("correlation=\(correlationID, privacy: .public) project machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) outcome=projected workspace=\(placement.workspaceID, privacy: .public) tab=\(placement.tabID, privacy: .public)") } func phase(machineID: String, terminalID: String, surfaceID: UInt64, phase: CloudTuiManualMirrorPhase, reason: CloudTerminalAttachmentInterruption?) { - Self.logger.info("phase machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) surface=\(surfaceID) phase=\(String(describing: phase), privacy: .public) reason=\(reason?.logDescription ?? "-", privacy: .public) detail=\(reason?.detail ?? "-", privacy: .private)") + let outcome: String + switch phase { + case .idle: outcome = "idle" + case .connecting: outcome = "connecting" + case .attached: outcome = "attached" + case .disconnected: outcome = reason?.logDescription ?? "disconnected" + case .stopped: outcome = "ended" + } + Self.logger.info("correlation=\(correlationID, privacy: .public) phase machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) surface=\(surfaceID) phase=\(String(describing: phase), privacy: .public) outcome=\(outcome, privacy: .public) reason=\(reason?.logDescription ?? "-", privacy: .public) detail=\(reason?.detail ?? "-", privacy: .private)") } func retry(machineID: String, failures: Int, delay: Duration) { - Self.logger.notice("retry machine=\(machineID, privacy: .public) failures=\(failures) delay=\(String(describing: delay), privacy: .public)") + Self.logger.notice("correlation=\(correlationID, privacy: .public) retry machine=\(machineID, privacy: .public) failures=\(failures) outcome=scheduled delay=\(String(describing: delay), privacy: .public)") } func giveUp(machineID: String, terminalID: String, attempts: Int, reason: String) { - Self.logger.error("give-up machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) attempts=\(attempts) reason=\(reason, privacy: .private)") + Self.logger.error("correlation=\(correlationID, privacy: .public) give-up machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) attempts=\(attempts) outcome=give-up reason=\(reason, privacy: .private)") + } + + /// Records which owner presented the connection state for one pane. + /// + /// Only stable identities and state labels are emitted. The rendered + /// terminal contents and any command or error payload remain absent. + func presentation( + machineID: String, + terminalID: String, + destination: String, + visible: Bool, + presented: Bool, + phase: CloudTuiManualMirrorPhase, + hasPresentation: Bool + ) { + Self.logger.info("correlation=\(correlationID, privacy: .public) presentation machine=\(machineID, privacy: .public) terminal=\(terminalID, privacy: .public) destination=\(destination, privacy: .public) visible=\(visible) bound=\(presented) phase=\(String(describing: phase), privacy: .public) outcome=\(hasPresentation ? "shown" : "hidden", privacy: .public)") } } diff --git a/Sources/Cloud/CloudTuiManualMirrorSession.swift b/Sources/Cloud/CloudTuiManualMirrorSession.swift index 587566a30815..5b255f5d5480 100644 --- a/Sources/Cloud/CloudTuiManualMirrorSession.swift +++ b/Sources/Cloud/CloudTuiManualMirrorSession.swift @@ -77,11 +77,12 @@ final class CloudTuiManualMirrorSession { /// What the pane shows about this attachment; written only by `transition`. let attachmentStatus: CloudTerminalAttachmentStatus private let watchdog: CloudTuiManualMirrorWatchdog - private let log = CloudTerminalAttachmentLog() + private let log: CloudTerminalAttachmentLog private var attachAttempts = 0 private var interruption: CloudTerminalAttachmentInterruption? private var automaticReconnectSuppressed = false var allowsAutomaticReconnect: Bool { !automaticReconnectSuppressed } + var attachmentCorrelationID: String { log.correlationID } var connectionPresentation: CloudTerminalReconnectOverlayPolicy.Presentation? { guard let state = CloudManualMirrorPresentation( phase: phase, replayReceived: diagnosticReplayReceived @@ -124,6 +125,7 @@ final class CloudTuiManualMirrorSession { commandBuilder: CloudTuiManualIOCommand = CloudTuiManualIOCommand(), deadlines: CloudTuiManualMirrorDeadlines = .standard, clock: any Clock = ContinuousClock(), + correlationID: String? = nil, onNeedsReconnect: @escaping @MainActor () -> Void ) { self.operations = operations @@ -135,6 +137,7 @@ final class CloudTuiManualMirrorSession { self.commandBuilder = commandBuilder self.deadlines = deadlines self.clock = clock + log = CloudTerminalAttachmentLog(correlationID: correlationID ?? UUID().uuidString.lowercased()) attachmentStatus = CloudTerminalAttachmentStatus(machineID: machineID) watchdog = CloudTuiManualMirrorWatchdog(deadlines: deadlines, clock: clock) inputRouter = CloudTuiManualIOInputRouter( @@ -387,7 +390,6 @@ final class CloudTuiManualMirrorSession { sendClaimIfNeeded() } } - /// Re-asserts this pane as the geometry owner after a focus/input handoff. /// The first report is normally followed by an automatic claim; this method /// is also used by the composed explicit-input callback. @@ -401,7 +403,6 @@ final class CloudTuiManualMirrorSession { claimUnsupported = false sendClaimIfNeeded() } - /// Permanently tears down this view's attachment without closing the remote /// terminal. Closing the control socket is the cleanup fence for old /// servers; newer servers additionally retire the lease with the same close. @@ -443,7 +444,6 @@ final class CloudTuiManualMirrorSession { } self.surface = nil } - private func finishDiagnostics(error: Error? = nil) { diagnosticDeadline?.cancel() diagnosticDeadline = nil diff --git a/Sources/CloudTerminalOverlayCoordinator.swift b/Sources/CloudTerminalOverlayCoordinator.swift index 712b01e09f1c..a51f01665a4a 100644 --- a/Sources/CloudTerminalOverlayCoordinator.swift +++ b/Sources/CloudTerminalOverlayCoordinator.swift @@ -100,6 +100,15 @@ final class CloudTerminalOverlayCoordinator { let next: Destination = overlay == nil ? .hidden : (presented ? .terminal : .anchor) if next != lastDestination, let session { cloudTerminalPresentationLogger.notice("pane terminal=\(session.terminalID, privacy: .private(mask: .hash)) destination=\(next.rawValue, privacy: .public) bound=\(presented) phase=\(String(describing: session.phase), privacy: .public)") + CloudTerminalAttachmentLog(correlationID: session.attachmentCorrelationID).presentation( + machineID: session.machineID, + terminalID: session.terminalID, + destination: next.rawValue, + visible: visible, + presented: presented, + phase: session.phase, + hasPresentation: presentation != nil + ) } lastDestination = next } diff --git a/Sources/Surfaces/CloudTerminalAttachmentResolver.swift b/Sources/Surfaces/CloudTerminalAttachmentResolver.swift index 7c9a2aaf8d9d..798cfefb8989 100644 --- a/Sources/Surfaces/CloudTerminalAttachmentResolver.swift +++ b/Sources/Surfaces/CloudTerminalAttachmentResolver.swift @@ -27,20 +27,26 @@ struct CloudTerminalAttachmentResolver: Sendable { /// Deadline for each daemon round trip. The bundled client's raw bridge /// gives up after 10 s; this bound only covers a client that never starts. var commandDeadline: Duration - private let log = CloudTerminalAttachmentLog() + private let log: CloudTerminalAttachmentLog init( machineID: String = "", commandRunner: any CloudTuiCommandRunning, socketPath: String, - commandDeadline: Duration = .seconds(15) + commandDeadline: Duration = .seconds(15), + correlationID: String? = nil ) { self.machineID = machineID self.commandRunner = commandRunner self.socketPath = socketPath self.commandDeadline = commandDeadline + log = CloudTerminalAttachmentLog(correlationID: correlationID ?? UUID().uuidString.lowercased()) } + /// The privacy-safe identifier shared by resolver diagnostics for one + /// attachment transaction. + var attachmentCorrelationID: String { log.correlationID } + /// The private resolver's verdict, before any snapshot fallback. enum ModernOutcome: Equatable, Sendable { case decided(CloudTuiSurfaceIDResolution) diff --git a/Sources/Surfaces/CmuxTuiSurfaceProvider+ManualMirror.swift b/Sources/Surfaces/CmuxTuiSurfaceProvider+ManualMirror.swift index ec64e970b4b4..512713ee1132 100644 --- a/Sources/Surfaces/CmuxTuiSurfaceProvider+ManualMirror.swift +++ b/Sources/Surfaces/CmuxTuiSurfaceProvider+ManualMirror.swift @@ -19,6 +19,7 @@ extension CmuxTuiSurfaceProvider { guard let link = await links.link(machineID: machineID) else { throw ProviderError.machineAsleep(machineID) } + let correlationID = UUID().uuidString.lowercased() // A pool terminal opened into a mirrored workspace takes its tab there, not in // whichever workspace the daemon happens to focus. let resolved = try await resolveSurfaceIDForMaterialization( @@ -26,6 +27,7 @@ extension CmuxTuiSurfaceProvider { socketPath: connected.socketPath, link: link, requiresExistingView: remoteTabID != nil, + correlationID: correlationID, // A newly-created terminal carries the workspace selected by the // creation request even before its first tab receipt arrives. Keep // that identity ahead of the local binding or daemon focus so a @@ -41,6 +43,7 @@ extension CmuxTuiSurfaceProvider { terminalID: resource.id.key, remoteSurfaceID: resolved.surfaceID, operations: links.operations, + correlationID: correlationID, onNeedsReconnect: { [weak self] in self?.scheduleRefresh() } @@ -100,9 +103,10 @@ extension CmuxTuiSurfaceProvider { socketPath: String, link: CloudMachineLink, requiresExistingView: Bool, + correlationID: String, preferredWorkspaceID: String? = nil ) async throws -> (surfaceID: UInt64, placement: SurfaceRemotePlacement?) { - let resolver = CloudTerminalAttachmentResolver(machineID: machineID, commandRunner: link, socketPath: socketPath) + let resolver = CloudTerminalAttachmentResolver(machineID: machineID, commandRunner: link, socketPath: socketPath, correlationID: correlationID) var failures = 0 var lastReason = "" var lastFailure = CloudTuiSurfaceIDResolution.Failure.notReady diff --git a/cmuxTests/CloudTerminalAttachmentRecoveryTests.swift b/cmuxTests/CloudTerminalAttachmentRecoveryTests.swift index 75e349d0bb87..1b78da5dd830 100644 --- a/cmuxTests/CloudTerminalAttachmentRecoveryTests.swift +++ b/cmuxTests/CloudTerminalAttachmentRecoveryTests.swift @@ -15,6 +15,30 @@ import Testing private static let terminalID = "term_41fb0b7fe0f204d428acf9db124023f4" private static let socketPath = "/tmp/cmux-12362-fixture.sock" + /// Resolver and session logs can be joined without exposing terminal data. + /// The correlation value is caller supplied so a materialization can carry + /// one id from identity resolution through native presentation. + @Test @MainActor + func attachmentDiagnosticsKeepOneCorrelationIDAcrossResolverAndSession() { + let correlationID = "attachment-correlation-12567" + let resolver = CloudTerminalAttachmentResolver( + commandRunner: ScriptedTuiCommandRunner(), + socketPath: Self.socketPath, + correlationID: correlationID + ) + let session = CloudTuiManualMirrorSession( + machineID: "machine", + terminalID: Self.terminalID, + remoteSurfaceID: 17, + correlationID: correlationID, + onNeedsReconnect: {} + ) + defer { session.stop() } + + #expect(resolver.attachmentCorrelationID == correlationID) + #expect(session.attachmentCorrelationID == correlationID) + } + /// The deployed daemon (897bb7a9) validates `resolve-terminal` ids as /// UUIDv4 host ids, so a public `term_…` id answers `invalid_terminal_id`, /// and the compatibility tree only lists terminals that have a tab. A