From 5d463af1227af7019eb7b3328dc94f96ec067ee5 Mon Sep 17 00:00:00 2001 From: Lawrence Chen <54008264+lawrencecchen@users.noreply.github.com> Date: Tue, 3 Mar 2026 15:20:42 -0800 Subject: [PATCH] Fix ghost terminal surface rebind after close (#808) * Fix ghost terminal lifecycle rebind race * Address review feedback on portal regression checks * Address follow-up review feedback --- Sources/AppDelegate.swift | 39 ++- Sources/GhosttyTerminalView.swift | 124 +++++++- Sources/Panels/TerminalPanel.swift | 19 ++ Sources/TabManager.swift | 55 +++- Sources/TerminalController.swift | 10 + Sources/TerminalWindowPortal.swift | 173 +++++++++- Sources/Workspace.swift | 105 +++++- ...it_cmd_shift_d_ctrl_d_no_portal_orphans.py | 301 ++++++++++++++++++ 8 files changed, 811 insertions(+), 15 deletions(-) create mode 100644 tests_v2/test_split_cmd_shift_d_ctrl_d_no_portal_orphans.py diff --git a/Sources/AppDelegate.swift b/Sources/AppDelegate.swift index b2bd485e..607fdb56 100644 --- a/Sources/AppDelegate.swift +++ b/Sources/AppDelegate.swift @@ -6179,11 +6179,17 @@ final class AppDelegate: NSObject, NSApplicationDelegate, UNUserNotificationCent } if matchShortcut(event: event, shortcut: KeyboardShortcutSettings.shortcut(for: .splitBrowserRight)) { +#if DEBUG + dlog("shortcut.action name=splitBrowserRight \(debugShortcutRouteSnapshot(event: event))") +#endif _ = performBrowserSplitShortcut(direction: .right) return true } if matchShortcut(event: event, shortcut: KeyboardShortcutSettings.shortcut(for: .splitBrowserDown)) { +#if DEBUG + dlog("shortcut.action name=splitBrowserDown \(debugShortcutRouteSnapshot(event: event))") +#endif _ = performBrowserSplitShortcut(direction: .down) return true } @@ -6697,7 +6703,38 @@ final class AppDelegate: NSObject, NSApplicationDelegate, UNUserNotificationCent func performBrowserSplitShortcut(direction: SplitDirection) -> Bool { _ = synchronizeActiveMainWindowContext(preferredWindow: NSApp.keyWindow ?? NSApp.mainWindow) - guard let panelId = tabManager?.createBrowserSplit(direction: direction) else { return false } + #if DEBUG + let directionLabel: String + switch direction { + case .left: directionLabel = "left" + case .right: directionLabel = "right" + case .up: directionLabel = "up" + case .down: directionLabel = "down" + } + let selectedTabBefore = tabManager?.selectedTabId?.uuidString.prefix(5) ?? "nil" + let focusedPanelBefore = tabManager?.selectedWorkspace?.focusedPanelId?.uuidString.prefix(5) ?? "nil" + dlog( + "split.browser.shortcut pre dir=\(directionLabel) " + + "tab=\(selectedTabBefore) focusedPanel=\(focusedPanelBefore)" + ) + #endif + + guard let panelId = tabManager?.createBrowserSplit(direction: direction) else { + #if DEBUG + dlog("split.browser.shortcut failed dir=\(directionLabel)") + #endif + return false + } + + #if DEBUG + let selectedTabAfter = tabManager?.selectedTabId?.uuidString.prefix(5) ?? "nil" + let focusedPanelAfter = tabManager?.selectedWorkspace?.focusedPanelId?.uuidString.prefix(5) ?? "nil" + dlog( + "split.browser.shortcut post dir=\(directionLabel) " + + "created=\(panelId.uuidString.prefix(5)) tab=\(selectedTabAfter) focusedPanel=\(focusedPanelAfter)" + ) + #endif + _ = focusBrowserAddressBar(panelId: panelId) return true } diff --git a/Sources/GhosttyTerminalView.swift b/Sources/GhosttyTerminalView.swift index d1085f97..6688cbfc 100644 --- a/Sources/GhosttyTerminalView.swift +++ b/Sources/GhosttyTerminalView.swift @@ -1613,6 +1613,13 @@ final class TerminalSurface: Identifiable, ObservableObject { private let maxPendingTextBytes = 1_048_576 private var backgroundSurfaceStartQueued = false private var surfaceCallbackContext: Unmanaged? + private enum PortalLifecycleState: String { + case live + case closing + case closed + } + private var portalLifecycleState: PortalLifecycleState = .live + private var portalLifecycleGeneration: UInt64 = 1 @Published var searchState: SearchState? = nil { didSet { if let searchState { @@ -1672,6 +1679,52 @@ final class TerminalSurface: Identifiable, ObservableObject { attachedView?.tabId = newTabId surfaceView.tabId = newTabId } + + func portalBindingGeneration() -> UInt64 { + portalLifecycleGeneration + } + + func portalBindingStateLabel() -> String { + portalLifecycleState.rawValue + } + + func canAcceptPortalBinding(expectedSurfaceId: UUID?, expectedGeneration: UInt64?) -> Bool { + guard portalLifecycleState == .live else { return false } + if let expectedSurfaceId, expectedSurfaceId != id { + return false + } + if let expectedGeneration, expectedGeneration != portalLifecycleGeneration { + return false + } + return true + } + + func beginPortalCloseLifecycle(reason: String) { + guard portalLifecycleState != .closed else { return } + guard portalLifecycleState != .closing else { return } + portalLifecycleState = .closing + portalLifecycleGeneration &+= 1 +#if DEBUG + dlog( + "surface.lifecycle.close.begin surface=\(id.uuidString.prefix(5)) " + + "workspace=\(tabId.uuidString.prefix(5)) reason=\(reason) " + + "generation=\(portalLifecycleGeneration)" + ) +#endif + } + + private func markPortalLifecycleClosed(reason: String) { + guard portalLifecycleState != .closed else { return } + portalLifecycleState = .closed + portalLifecycleGeneration &+= 1 +#if DEBUG + dlog( + "surface.lifecycle.close.sealed surface=\(id.uuidString.prefix(5)) " + + "workspace=\(tabId.uuidString.prefix(5)) reason=\(reason) " + + "generation=\(portalLifecycleGeneration)" + ) +#endif + } #if DEBUG private static let surfaceLogPath = "/tmp/cmux-ghostty-surface.log" private static let sizeLogPath = "/tmp/cmux-ghostty-size.log" @@ -2288,6 +2341,8 @@ final class TerminalSurface: Identifiable, ObservableObject { #endif deinit { + markPortalLifecycleClosed(reason: "deinit") + let callbackContext = surfaceCallbackContext surfaceCallbackContext = nil @@ -2299,16 +2354,38 @@ final class TerminalSurface: Identifiable, ObservableObject { surface = nil guard let surfaceToFree else { +#if DEBUG + dlog( + "surface.lifecycle.deinit.skip surface=\(id.uuidString.prefix(5)) " + + "workspace=\(tabId.uuidString.prefix(5)) reason=noRuntimeSurface" + ) +#endif callbackContext?.release() return } +#if DEBUG + let surfaceToken = String(id.uuidString.prefix(5)) + let workspaceToken = String(tabId.uuidString.prefix(5)) + dlog( + "surface.lifecycle.deinit.begin surface=\(surfaceToken) " + + "workspace=\(workspaceToken) hasAttachedView=\(attachedView != nil ? 1 : 0) " + + "hostedInWindow=\(hostedView.window != nil ? 1 : 0)" + ) +#endif + // Keep teardown asynchronous to avoid re-entrant close/deinit loops, but retain // callback userdata until surface free completes so callbacks never dereference // a deallocated view pointer. Task { @MainActor in ghostty_surface_free(surfaceToFree) callbackContext?.release() +#if DEBUG + dlog( + "surface.lifecycle.deinit.end surface=\(surfaceToken) " + + "workspace=\(workspaceToken) freed=1" + ) +#endif } } } @@ -3764,6 +3841,13 @@ class GhosttyNSView: NSView, NSUserInterfaceValidations { deinit { // Surface lifecycle is managed by TerminalSurface, not the view +#if DEBUG + dlog( + "surface.view.deinit view=\(Unmanaged.passUnretained(self).toOpaque()) " + + "surface=\(terminalSurface?.id.uuidString.prefix(5) ?? "nil") " + + "inWindow=\(window != nil ? 1 : 0) hasSuperview=\(superview != nil ? 1 : 0)" + ) +#endif if let eventMonitor { NSEvent.removeMonitor(eventMonitor) } @@ -4111,6 +4195,25 @@ final class GhosttySurfaceScrollView: NSView { } #endif + func portalBindingGuardState() -> (surfaceId: UUID?, generation: UInt64?, state: String) { + guard let terminalSurface = surfaceView.terminalSurface else { + return (surfaceId: nil, generation: nil, state: "missingSurface") + } + return ( + surfaceId: terminalSurface.id, + generation: terminalSurface.portalBindingGeneration(), + state: terminalSurface.portalBindingStateLabel() + ) + } + + func canAcceptPortalBinding(expectedSurfaceId: UUID?, expectedGeneration: UInt64?) -> Bool { + guard let terminalSurface = surfaceView.terminalSurface else { return false } + return terminalSurface.canAcceptPortalBinding( + expectedSurfaceId: expectedSurfaceId, + expectedGeneration: expectedGeneration + ) + } + init(surfaceView: GhosttyNSView) { self.surfaceView = surfaceView backgroundView = NSView(frame: .zero) @@ -4249,6 +4352,13 @@ final class GhosttySurfaceScrollView: NSView { } deinit { +#if DEBUG + dlog( + "surface.hosted.deinit surface=\(debugSurfaceId?.uuidString.prefix(5) ?? "nil") " + + "inWindow=\(window != nil ? 1 : 0) hasSuperview=\(superview != nil ? 1 : 0) " + + "hidden=\(isHidden ? 1 : 0) frame=\(String(format: "%.1fx%.1f", frame.width, frame.height))" + ) +#endif observers.forEach { NotificationCenter.default.removeObserver($0) } windowObservers.forEach { NotificationCenter.default.removeObserver($0) } cancelFocusRequest() @@ -5660,6 +5770,8 @@ struct GhosttyTerminalView: NSViewRepresentable { hostedView.setSearchOverlay(searchState: searchState) hostedView.setFocusHandler { onFocus?(terminalSurface.id) } hostedView.setTriggerFlashHandler(onTriggerFlash) + let portalExpectedSurfaceId = terminalSurface.id + let portalExpectedGeneration = terminalSurface.portalBindingGeneration() let forwardedDropZone = isVisibleInUI ? paneDropZone : nil #if DEBUG if coordinator.lastPaneDropZone != paneDropZone { @@ -5695,7 +5807,9 @@ struct GhosttyTerminalView: NSViewRepresentable { hostedView: hostedView, to: host, visibleInUI: coordinator.desiredIsVisibleInUI, - zPriority: coordinator.desiredPortalZPriority + zPriority: coordinator.desiredPortalZPriority, + expectedSurfaceId: portalExpectedSurfaceId, + expectedGeneration: portalExpectedGeneration ) coordinator.lastBoundHostId = ObjectIdentifier(host) hostedView.setVisibleInUI(coordinator.desiredIsVisibleInUI) @@ -5719,7 +5833,9 @@ struct GhosttyTerminalView: NSViewRepresentable { hostedView: hostedView, to: host, visibleInUI: coordinator.desiredIsVisibleInUI, - zPriority: coordinator.desiredPortalZPriority + zPriority: coordinator.desiredPortalZPriority, + expectedSurfaceId: portalExpectedSurfaceId, + expectedGeneration: portalExpectedGeneration ) coordinator.lastBoundHostId = ObjectIdentifier(host) hostedView.setVisibleInUI(coordinator.desiredIsVisibleInUI) @@ -5742,7 +5858,9 @@ struct GhosttyTerminalView: NSViewRepresentable { hostedView: hostedView, to: host, visibleInUI: coordinator.desiredIsVisibleInUI, - zPriority: coordinator.desiredPortalZPriority + zPriority: coordinator.desiredPortalZPriority, + expectedSurfaceId: portalExpectedSurfaceId, + expectedGeneration: portalExpectedGeneration ) coordinator.lastBoundHostId = hostId } diff --git a/Sources/Panels/TerminalPanel.swift b/Sources/Panels/TerminalPanel.swift index c8ba8507..cee42f2e 100644 --- a/Sources/Panels/TerminalPanel.swift +++ b/Sources/Panels/TerminalPanel.swift @@ -1,6 +1,7 @@ import Foundation import Combine import AppKit +import Bonsplit /// TerminalPanel wraps an existing TerminalSurface and conforms to the Panel protocol. /// This allows TerminalSurface to be used within the bonsplit-based layout system. @@ -139,9 +140,27 @@ final class TerminalPanel: Panel, ObservableObject { // The surface will be cleaned up by its deinit // Detach from the window portal on real close so stale hosted views // cannot remain above browser panes after split close. + surface.beginPortalCloseLifecycle(reason: "panel.close") +#if DEBUG + let frame = String(format: "%.1fx%.1f", hostedView.frame.width, hostedView.frame.height) + let bounds = String(format: "%.1fx%.1f", hostedView.bounds.width, hostedView.bounds.height) + dlog( + "surface.panel.close.begin panel=\(id.uuidString.prefix(5)) " + + "workspace=\(workspaceId.uuidString.prefix(5)) runtimeSurface=\(surface.surface != nil ? 1 : 0) " + + "inWindow=\(hostedView.window != nil ? 1 : 0) hasSuperview=\(hostedView.superview != nil ? 1 : 0) " + + "hidden=\(hostedView.isHidden ? 1 : 0) frame=\(frame) bounds=\(bounds)" + ) +#endif unfocus() hostedView.setVisibleInUI(false) TerminalWindowPortalRegistry.detach(hostedView: hostedView) +#if DEBUG + dlog( + "surface.panel.close.end panel=\(id.uuidString.prefix(5)) " + + "inWindow=\(hostedView.window != nil ? 1 : 0) hasSuperview=\(hostedView.superview != nil ? 1 : 0) " + + "hidden=\(hostedView.isHidden ? 1 : 0)" + ) +#endif } func requestViewReattach() { diff --git a/Sources/TabManager.swift b/Sources/TabManager.swift index e9ffa00d..39b26771 100644 --- a/Sources/TabManager.swift +++ b/Sources/TabManager.swift @@ -1866,9 +1866,24 @@ class TabManager: ObservableObject { guard let selectedTabId, let tab = tabs.first(where: { $0.id == selectedTabId }), let focusedPanelId = tab.focusedPanelId else { return } +#if DEBUG + let directionLabel = direction.debugLabel + dlog( + "split.create.request kind=terminal dir=\(directionLabel) " + + "tab=\(selectedTabId.uuidString.prefix(5)) panel=\(focusedPanelId.uuidString.prefix(5)) " + + "panels=\(tab.panels.count) panes=\(tab.bonsplitController.allPaneIds.count)" + ) +#endif tab.clearSplitZoom() sentryBreadcrumb("split.create", data: ["direction": String(describing: direction)]) - _ = newSplit(tabId: selectedTabId, surfaceId: focusedPanelId, direction: direction) + let createdPanelId = newSplit(tabId: selectedTabId, surfaceId: focusedPanelId, direction: direction) +#if DEBUG + dlog( + "split.create.result kind=terminal dir=\(directionLabel) " + + "created=\(createdPanelId?.uuidString.prefix(5) ?? "nil") " + + "panels=\(tab.panels.count) panes=\(tab.bonsplitController.allPaneIds.count)" + ) +#endif } /// Create a new browser split from the currently focused panel. @@ -1877,14 +1892,30 @@ class TabManager: ObservableObject { guard let selectedTabId, let tab = tabs.first(where: { $0.id == selectedTabId }), let focusedPanelId = tab.focusedPanelId else { return nil } +#if DEBUG + let directionLabel = direction.debugLabel + dlog( + "split.create.request kind=browser dir=\(directionLabel) " + + "tab=\(selectedTabId.uuidString.prefix(5)) panel=\(focusedPanelId.uuidString.prefix(5)) " + + "panels=\(tab.panels.count) panes=\(tab.bonsplitController.allPaneIds.count)" + ) +#endif tab.clearSplitZoom() - return newBrowserSplit( + let createdPanelId = newBrowserSplit( tabId: selectedTabId, fromPanelId: focusedPanelId, orientation: direction.orientation, insertFirst: direction.insertFirst, url: url ) +#if DEBUG + dlog( + "split.create.result kind=browser dir=\(directionLabel) " + + "created=\(createdPanelId?.uuidString.prefix(5) ?? "nil") " + + "panels=\(tab.panels.count) panes=\(tab.bonsplitController.allPaneIds.count)" + ) +#endif + return createdPanelId } /// Refresh Bonsplit right-side action button tooltips for all workspaces. @@ -1985,12 +2016,21 @@ class TabManager: ObservableObject { /// Returns the new panel's ID (which is also the surface ID for terminals) func newSplit(tabId: UUID, surfaceId: UUID, direction: SplitDirection, focus: Bool = true) -> UUID? { guard let tab = tabs.first(where: { $0.id == tabId }) else { return nil } - return tab.newTerminalSplit( + let createdPanel = tab.newTerminalSplit( from: surfaceId, orientation: direction.orientation, insertFirst: direction.insertFirst, focus: focus )?.id +#if DEBUG + let directionLabel = direction.debugLabel + dlog( + "split.newSurface result dir=\(directionLabel) " + + "tab=\(tabId.uuidString.prefix(5)) source=\(surfaceId.uuidString.prefix(5)) " + + "created=\(createdPanel?.uuidString.prefix(5) ?? "nil") focus=\(focus ? 1 : 0)" + ) +#endif + return createdPanel } /// Move focus in the specified direction @@ -3569,6 +3609,15 @@ enum SplitDirection { var insertFirst: Bool { self == .left || self == .up } + + var debugLabel: String { + switch self { + case .left: return "left" + case .right: return "right" + case .up: return "up" + case .down: return "down" + } + } } /// Resize direction for backwards compatibility diff --git a/Sources/TerminalController.swift b/Sources/TerminalController.swift index 116c293c..aaf34f86 100644 --- a/Sources/TerminalController.swift +++ b/Sources/TerminalController.swift @@ -1521,6 +1521,8 @@ class TerminalController { return v2Result(id: id, self.v2DebugRenderStats(params: params)) case "debug.layout": return v2Result(id: id, self.v2DebugLayout()) + case "debug.portal.stats": + return v2Result(id: id, self.v2DebugPortalStats()) case "debug.bonsplit_underflow.count": return v2Result(id: id, self.v2DebugBonsplitUnderflowCount()) case "debug.bonsplit_underflow.reset": @@ -1725,6 +1727,7 @@ class TerminalController { "debug.terminal.read_text", "debug.terminal.render_stats", "debug.layout", + "debug.portal.stats", "debug.bonsplit_underflow.count", "debug.bonsplit_underflow.reset", "debug.empty_panel.count", @@ -8526,6 +8529,13 @@ class TerminalController { return .ok(["layout": obj]) } + private func v2DebugPortalStats() -> V2CallResult { + let payload: [String: Any] = v2MainSync { + TerminalWindowPortalRegistry.debugPortalStats() + } + return .ok(payload) + } + private func v2DebugBonsplitUnderflowCount() -> V2CallResult { let resp = bonsplitUnderflowCount() guard resp.hasPrefix("OK ") else { return .err(code: "internal_error", message: resp, data: nil) } diff --git a/Sources/TerminalWindowPortal.swift b/Sources/TerminalWindowPortal.swift index 8e8dc306..0c466aca 100644 --- a/Sources/TerminalWindowPortal.swift +++ b/Sources/TerminalWindowPortal.swift @@ -1488,6 +1488,55 @@ final class WindowTerminalPortal: NSObject { } #if DEBUG + struct DebugStats { + let windowNumber: Int + let entryCount: Int + let hostSubviewCount: Int + let terminalSubviewCount: Int + let mappedTerminalSubviewCount: Int + let orphanTerminalSubviewCount: Int + let visibleOrphanTerminalSubviewCount: Int + let staleEntryCount: Int + } + + func debugStats() -> DebugStats { + let terminalSubviews = hostView.subviews.compactMap { $0 as? GhosttySurfaceScrollView } + var mappedTerminalSubviewCount = 0 + var orphanTerminalSubviewCount = 0 + var visibleOrphanTerminalSubviewCount = 0 + + for hostedView in terminalSubviews { + let hostedId = ObjectIdentifier(hostedView) + if entriesByHostedId[hostedId] != nil { + mappedTerminalSubviewCount += 1 + } else { + orphanTerminalSubviewCount += 1 + if hostedView.window != nil, + !hostedView.isHidden, + hostedView.frame.width > Self.tinyHideThreshold, + hostedView.frame.height > Self.tinyHideThreshold { + visibleOrphanTerminalSubviewCount += 1 + } + } + } + + let staleEntryCount = entriesByHostedId.values.reduce(0) { partialResult, entry in + guard let hostedView = entry.hostedView else { return partialResult + 1 } + return hostedView.superview === hostView ? partialResult : partialResult + 1 + } + + return DebugStats( + windowNumber: window?.windowNumber ?? -1, + entryCount: entriesByHostedId.count, + hostSubviewCount: hostView.subviews.count, + terminalSubviewCount: terminalSubviews.count, + mappedTerminalSubviewCount: mappedTerminalSubviewCount, + orphanTerminalSubviewCount: orphanTerminalSubviewCount, + visibleOrphanTerminalSubviewCount: visibleOrphanTerminalSubviewCount, + staleEntryCount: staleEntryCount + ) + } + func debugEntryCount() -> Int { entriesByHostedId.count } @@ -1540,6 +1589,30 @@ final class WindowTerminalPortal: NSObject { enum TerminalWindowPortalRegistry { private static var portalsByWindowId: [ObjectIdentifier: WindowTerminalPortal] = [:] private static var hostedToWindowId: [ObjectIdentifier: ObjectIdentifier] = [:] +#if DEBUG + private static var blockedBindCount: Int = 0 + private static var blockedBindReasons: [String: Int] = [:] +#endif + + private static func bindBlockReason( + expectedSurfaceId: UUID?, + expectedGeneration: UInt64?, + actual: (surfaceId: UUID?, generation: UInt64?, state: String) + ) -> String { + if actual.surfaceId == nil { + return "missingSurface" + } + if actual.state != "live" { + return "state_\(actual.state)" + } + if let expectedSurfaceId, actual.surfaceId != expectedSurfaceId { + return "surfaceMismatch" + } + if let expectedGeneration, actual.generation != expectedGeneration { + return "generationMismatch" + } + return "guardRejected" + } private static func installWindowCloseObserverIfNeeded(for window: NSWindow) { guard objc_getAssociatedObject(window, &cmuxWindowTerminalPortalCloseObserverKey) == nil else { return } @@ -1603,11 +1676,46 @@ enum TerminalWindowPortalRegistry { return portal } - static func bind(hostedView: GhosttySurfaceScrollView, to anchorView: NSView, visibleInUI: Bool, zPriority: Int = 0) { + static func bind( + hostedView: GhosttySurfaceScrollView, + to anchorView: NSView, + visibleInUI: Bool, + zPriority: Int = 0, + expectedSurfaceId: UUID? = nil, + expectedGeneration: UInt64? = nil + ) { guard let window = anchorView.window else { return } let windowId = ObjectIdentifier(window) let hostedId = ObjectIdentifier(hostedView) + let guardState = hostedView.portalBindingGuardState() + guard hostedView.canAcceptPortalBinding( + expectedSurfaceId: expectedSurfaceId, + expectedGeneration: expectedGeneration + ) else { + if let oldWindowId = hostedToWindowId.removeValue(forKey: hostedId) { + portalsByWindowId[oldWindowId]?.detachHostedView(withId: hostedId) + } +#if DEBUG + let reason = bindBlockReason( + expectedSurfaceId: expectedSurfaceId, + expectedGeneration: expectedGeneration, + actual: guardState + ) + blockedBindCount += 1 + blockedBindReasons[reason, default: 0] += 1 + dlog( + "portal.bind.blocked hosted=\(portalDebugToken(hostedView)) " + + "reason=\(reason) expectedSurface=\(expectedSurfaceId?.uuidString.prefix(5) ?? "nil") " + + "expectedGeneration=\(expectedGeneration.map { String($0) } ?? "nil") " + + "actualSurface=\(guardState.surfaceId?.uuidString.prefix(5) ?? "nil") " + + "actualGeneration=\(guardState.generation.map { String($0) } ?? "nil") " + + "actualState=\(guardState.state)" + ) +#endif + return + } + let nextPortal = portal(for: window) if let oldWindowId = hostedToWindowId[hostedId], @@ -1674,5 +1782,68 @@ enum TerminalWindowPortalRegistry { static func debugPortalCount() -> Int { portalsByWindowId.count } + + static func debugPortalStats() -> [String: Any] { + var portals: [[String: Any]] = [] + var totals: [String: Int] = [ + "entry_count": 0, + "host_subview_count": 0, + "terminal_subview_count": 0, + "mapped_terminal_subview_count": 0, + "orphan_terminal_subview_count": 0, + "visible_orphan_terminal_subview_count": 0, + "stale_entry_count": 0, + "mapped_hosted_count": 0, + ] + + for (windowId, portal) in portalsByWindowId { + let stats = portal.debugStats() + let mappedHostedCount = hostedToWindowId.values.reduce(0) { partialResult, mappedWindowId in + partialResult + (mappedWindowId == windowId ? 1 : 0) + } + let integrityOK = + stats.orphanTerminalSubviewCount == 0 && + stats.visibleOrphanTerminalSubviewCount == 0 && + stats.staleEntryCount == 0 && + mappedHostedCount == stats.entryCount + + portals.append([ + "window_number": stats.windowNumber, + "entry_count": stats.entryCount, + "mapped_hosted_count": mappedHostedCount, + "host_subview_count": stats.hostSubviewCount, + "terminal_subview_count": stats.terminalSubviewCount, + "mapped_terminal_subview_count": stats.mappedTerminalSubviewCount, + "orphan_terminal_subview_count": stats.orphanTerminalSubviewCount, + "visible_orphan_terminal_subview_count": stats.visibleOrphanTerminalSubviewCount, + "stale_entry_count": stats.staleEntryCount, + "integrity_ok": integrityOK, + ]) + + totals["entry_count", default: 0] += stats.entryCount + totals["host_subview_count", default: 0] += stats.hostSubviewCount + totals["terminal_subview_count", default: 0] += stats.terminalSubviewCount + totals["mapped_terminal_subview_count", default: 0] += stats.mappedTerminalSubviewCount + totals["orphan_terminal_subview_count", default: 0] += stats.orphanTerminalSubviewCount + totals["visible_orphan_terminal_subview_count", default: 0] += stats.visibleOrphanTerminalSubviewCount + totals["stale_entry_count", default: 0] += stats.staleEntryCount + totals["mapped_hosted_count", default: 0] += mappedHostedCount + } + + portals.sort { + let lhs = ($0["window_number"] as? Int) ?? Int.min + let rhs = ($1["window_number"] as? Int) ?? Int.min + return lhs < rhs + } + + return [ + "portal_count": portals.count, + "hosted_mapping_count": hostedToWindowId.count, + "guarded_bind_blocked_count": blockedBindCount, + "guarded_bind_blocked_reasons": blockedBindReasons, + "portals": portals, + "totals": totals, + ] + } #endif } diff --git a/Sources/Workspace.swift b/Sources/Workspace.swift index 4417cb13..533f6580 100644 --- a/Sources/Workspace.swift +++ b/Sources/Workspace.swift @@ -2152,12 +2152,29 @@ final class Workspace: Identifiable, ObservableObject { /// Close a panel. /// Returns true when a bonsplit tab close request was issued. func closePanel(_ panelId: UUID, force: Bool = false) -> Bool { +#if DEBUG + let mappedTabIdBeforeClose = surfaceIdFromPanelId(panelId) + dlog( + "surface.close.request panel=\(panelId.uuidString.prefix(5)) " + + "force=\(force ? 1 : 0) mappedTab=\(mappedTabIdBeforeClose.map { String(String(describing: $0).prefix(5)) } ?? "nil") " + + "focusedPanel=\(focusedPanelId?.uuidString.prefix(5) ?? "nil") " + + "focusedPane=\(bonsplitController.focusedPaneId?.id.uuidString.prefix(5) ?? "nil") " + + "\(debugPanelLifecycleState(panelId: panelId, panel: panels[panelId]))" + ) +#endif if let tabId = surfaceIdFromPanelId(panelId) { if force { forceCloseTabIds.insert(tabId) } // Close the tab in bonsplit (this triggers delegate callback) - return bonsplitController.closeTab(tabId) + let closed = bonsplitController.closeTab(tabId) +#if DEBUG + dlog( + "surface.close.request.done panel=\(panelId.uuidString.prefix(5)) " + + "tab=\(String(describing: tabId).prefix(5)) closed=\(closed ? 1 : 0) force=\(force ? 1 : 0)" + ) +#endif + return closed } // Mapping can transiently drift during split-tree mutations. If the target panel is @@ -2189,12 +2206,38 @@ final class Workspace: Identifiable, ObservableObject { dlog( "surface.close.fallback panel=\(panelId.uuidString.prefix(5)) " + "selectedTab=\(String(describing: selected.id).prefix(5)) " + - "closed=\(closed ? 1 : 0)" + "closed=\(closed ? 1 : 0) " + + "\(debugPanelLifecycleState(panelId: panelId, panel: panels[panelId]))" ) #endif return closed } +#if DEBUG + private func debugPanelLifecycleState(panelId: UUID, panel: (any Panel)?) -> String { + guard let panel else { return "panelState=missing" } + if let terminal = panel as? TerminalPanel { + let hosted = terminal.hostedView + let frame = String(format: "%.1fx%.1f", hosted.frame.width, hosted.frame.height) + let bounds = String(format: "%.1fx%.1f", hosted.bounds.width, hosted.bounds.height) + let hasRuntimeSurface = terminal.surface.surface != nil ? 1 : 0 + return + "panelState=terminal panel=\(panelId.uuidString.prefix(5)) " + + "surface=\(terminal.id.uuidString.prefix(5)) runtimeSurface=\(hasRuntimeSurface) " + + "inWindow=\(hosted.window != nil ? 1 : 0) hasSuperview=\(hosted.superview != nil ? 1 : 0) " + + "hidden=\(hosted.isHidden ? 1 : 0) frame=\(frame) bounds=\(bounds)" + } + if let browser = panel as? BrowserPanel { + let webView = browser.webView + let frame = String(format: "%.1fx%.1f", webView.frame.width, webView.frame.height) + return + "panelState=browser panel=\(panelId.uuidString.prefix(5)) " + + "webInWindow=\(webView.window != nil ? 1 : 0) webHasSuperview=\(webView.superview != nil ? 1 : 0) frame=\(frame)" + } + return "panelState=\(String(describing: type(of: panel))) panel=\(panelId.uuidString.prefix(5))" + } +#endif + func paneId(forPanelId panelId: UUID) -> PaneID? { guard let tabId = surfaceIdFromPanelId(panelId) else { return nil } return bonsplitController.allPaneIds.first { paneId in @@ -3731,7 +3774,11 @@ extension Workspace: BonsplitDelegate { // Clean up our panel guard let panelId = panelIdFromSurfaceId(tabId) else { #if DEBUG - NSLog("[Workspace] didCloseTab: no panelId for tabId") + dlog( + "surface.didCloseTab.skip tab=\(String(describing: tabId).prefix(5)) " + + "pane=\(pane.id.uuidString.prefix(5)) reason=missingPanelMapping " + + "panels=\(panels.count) panes=\(controller.allPaneIds.count)" + ) #endif scheduleTerminalGeometryReconcile() if !isDetaching { @@ -3740,11 +3787,15 @@ extension Workspace: BonsplitDelegate { return } - #if DEBUG - NSLog("[Workspace] didCloseTab panelId=\(panelId) remainingPanels=\(panels.count - 1) remainingPanes=\(controller.allPaneIds.count)") - #endif - let panel = panels[panelId] +#if DEBUG + dlog( + "surface.didCloseTab.begin tab=\(String(describing: tabId).prefix(5)) " + + "pane=\(pane.id.uuidString.prefix(5)) panel=\(panelId.uuidString.prefix(5)) " + + "isDetaching=\(isDetaching ? 1 : 0) selectAfter=\(selectTabId.map { String(String(describing: $0).prefix(5)) } ?? "nil") " + + "\(debugPanelLifecycleState(panelId: panelId, panel: panel))" + ) +#endif if isDetaching, let panel { let browserPanel = panel as? BrowserPanel @@ -3795,6 +3846,12 @@ extension Workspace: BonsplitDelegate { // prune the source workspace/window after the tab is attached elsewhere. if panels.isEmpty { if isDetaching { +#if DEBUG + dlog( + "surface.didCloseTab.end tab=\(String(describing: tabId).prefix(5)) " + + "panel=\(panelId.uuidString.prefix(5)) mode=detachingEmptyWorkspace" + ) +#endif scheduleTerminalGeometryReconcile() return } @@ -3808,6 +3865,13 @@ extension Workspace: BonsplitDelegate { } scheduleTerminalGeometryReconcile() scheduleFocusReconcile() +#if DEBUG + dlog( + "surface.didCloseTab.end tab=\(String(describing: tabId).prefix(5)) " + + "panel=\(panelId.uuidString.prefix(5)) mode=replacementCreated " + + "replacement=\(replacement.id.uuidString.prefix(5)) panels=\(panels.count)" + ) +#endif return } @@ -3829,6 +3893,15 @@ extension Workspace: BonsplitDelegate { if bonsplitController.allPaneIds.contains(pane) { normalizePinnedTabs(in: pane) } +#if DEBUG + let focusedPaneAfter = bonsplitController.focusedPaneId?.id.uuidString.prefix(5) ?? "nil" + let focusedPanelAfter = focusedPanelId?.uuidString.prefix(5) ?? "nil" + dlog( + "surface.didCloseTab.end tab=\(String(describing: tabId).prefix(5)) " + + "panel=\(panelId.uuidString.prefix(5)) panels=\(panels.count) panes=\(controller.allPaneIds.count) " + + "focusedPane=\(focusedPaneAfter) focusedPanel=\(focusedPanelAfter)" + ) +#endif scheduleTerminalGeometryReconcile() if !isDetaching { scheduleFocusReconcile() @@ -3913,9 +3986,21 @@ extension Workspace: BonsplitDelegate { func splitTabBar(_ controller: BonsplitController, didClosePane paneId: PaneID) { let closedPanelIds = pendingPaneClosePanelIds.removeValue(forKey: paneId.id) ?? [] let shouldScheduleFocusReconcile = !isDetachingCloseTransaction +#if DEBUG + dlog( + "surface.didClosePane.begin pane=\(paneId.id.uuidString.prefix(5)) " + + "closedPanels=\(closedPanelIds.count) detaching=\(isDetachingCloseTransaction ? 1 : 0)" + ) +#endif if !closedPanelIds.isEmpty { for panelId in closedPanelIds { +#if DEBUG + dlog( + "surface.didClosePane.panel pane=\(paneId.id.uuidString.prefix(5)) " + + "panel=\(panelId.uuidString.prefix(5)) \(debugPanelLifecycleState(panelId: panelId, panel: panels[panelId]))" + ) +#endif panels[panelId]?.close() panels.removeValue(forKey: panelId) panelDirectories.removeValue(forKey: panelId) @@ -3948,6 +4033,12 @@ extension Workspace: BonsplitDelegate { if shouldScheduleFocusReconcile { scheduleFocusReconcile() } +#if DEBUG + dlog( + "surface.didClosePane.end pane=\(paneId.id.uuidString.prefix(5)) " + + "remainingPanels=\(panels.count) remainingPanes=\(bonsplitController.allPaneIds.count)" + ) +#endif } func splitTabBar(_ controller: BonsplitController, shouldClosePane pane: PaneID) -> Bool { diff --git a/tests_v2/test_split_cmd_shift_d_ctrl_d_no_portal_orphans.py b/tests_v2/test_split_cmd_shift_d_ctrl_d_no_portal_orphans.py new file mode 100644 index 00000000..7f5257e2 --- /dev/null +++ b/tests_v2/test_split_cmd_shift_d_ctrl_d_no_portal_orphans.py @@ -0,0 +1,301 @@ +#!/usr/bin/env python3 +""" +Regression: a Ctrl-D closed terminal must never become visible again before deinit. + +This targets the "ghost terminal" race: + 1) close starts (`surface.close.childExited`) + 2) panel is detached + 3) stale host callback re-binds the same surface + 4) it flips visible/active again (`ws.term.visible transition=0->1`) + 5) deinit only happens later + +Old behavior can pass steady-state orphan counts while still showing this transient bug. +""" + +import os +import re +import sys +import time +from pathlib import Path + +sys.path.insert(0, str(Path(__file__).parent)) +from cmux import cmux, cmuxError + + +SOCKET_PATH = os.environ.get("CMUX_SOCKET", "/tmp/cmux-debug.sock") +LOG_PATH_OVERRIDE = os.environ.get("CMUX_DEBUG_LOG") +ITERATIONS = int(os.environ.get("CMUX_PORTAL_ORPHAN_ITERS", "16")) +PANE_TIMEOUT_S = float(os.environ.get("CMUX_PORTAL_ORPHAN_PANE_TIMEOUT_S", "3.0")) +INTEGRITY_TIMEOUT_S = float(os.environ.get("CMUX_PORTAL_ORPHAN_INTEGRITY_TIMEOUT_S", "1.5")) +POLL_S = float(os.environ.get("CMUX_PORTAL_ORPHAN_POLL_S", "0.02")) +CTRL_D_RETRY_INTERVAL_S = float(os.environ.get("CMUX_PORTAL_ORPHAN_CTRL_D_RETRY_INTERVAL_S", "0.20")) +CTRL_D_MAX_EXTRA = int(os.environ.get("CMUX_PORTAL_ORPHAN_CTRL_D_MAX_EXTRA", "3")) +POST_CLOSE_SETTLE_S = float(os.environ.get("CMUX_PORTAL_ORPHAN_POST_CLOSE_SETTLE_S", "0.08")) +LOG_FLUSH_S = float(os.environ.get("CMUX_PORTAL_ORPHAN_LOG_FLUSH_S", "0.15")) + +RE_CLOSE = re.compile(r"surface\.close\.childExited .* surface=([0-9A-F]{5})\b") +RE_DEINIT_BEGIN = re.compile(r"surface\.lifecycle\.deinit\.begin surface=([0-9A-F]{5})\b") +RE_DEINIT_END = re.compile(r"surface\.lifecycle\.deinit\.end surface=([0-9A-F]{5})\b") +RE_VISIBLE_ON = re.compile(r"ws\.term\.visible .* surface=([0-9A-F]{5}) .* transition=0->1\b") + + +def _derive_log_path(socket_path: str) -> str: + if LOG_PATH_OVERRIDE: + return LOG_PATH_OVERRIDE + base = os.path.basename(socket_path) + if base.startswith("cmux-debug-") and base.endswith(".sock"): + slug = base[len("cmux-debug-") : -len(".sock")] + return f"/tmp/cmux-debug-{slug}.log" + return "/tmp/cmux-debug.log" + + +def _read_new_lines(log_path: str, offset: int) -> tuple[list[str], int]: + if not os.path.exists(log_path): + raise cmuxError(f"debug log not found at {log_path}") + with open(log_path, "rb") as f: + f.seek(offset) + data = f.read() + new_offset = f.tell() + if not data: + return [], new_offset + return data.decode("utf-8", errors="replace").splitlines(), new_offset + + +def _pane_count(layout_payload: dict) -> int: + return len((layout_payload.get("layout") or {}).get("panes") or []) + + +def _selected_panel_by_pane(layout_payload: dict) -> dict[str, str]: + out: dict[str, str] = {} + for row in layout_payload.get("selectedPanels") or []: + pane_id = str(row.get("paneId") or "") + panel_id = str(row.get("panelId") or "") + if pane_id and panel_id: + out[pane_id] = panel_id + return out + + +def _pane_sort_key(pane: dict) -> tuple[float, float]: + frame = pane.get("frame") or {} + x = float(frame.get("x", 0.0)) + y = float(frame.get("y", 0.0)) + return (x, y) + + +def _panel_for_pane(layout_payload: dict, pane: dict) -> str: + pane_id = str(pane.get("paneId") or "") + selected = _selected_panel_by_pane(layout_payload) + panel_id = str(selected.get(pane_id) or "") + if not panel_id: + raise cmuxError(f"missing selected panel for pane: pane_id={pane_id} selected={selected}") + return panel_id + + +def _rightmost_panel(layout_payload: dict) -> str: + panes = (layout_payload.get("layout") or {}).get("panes") or [] + if len(panes) < 2: + raise cmuxError(f"expected >=2 panes to find rightmost panel, got {len(panes)}") + rightmost = max(panes, key=_pane_sort_key) + return _panel_for_pane(layout_payload, rightmost) + + +def _bottom_right_panel(layout_payload: dict) -> str: + panes = (layout_payload.get("layout") or {}).get("panes") or [] + if len(panes) < 3: + raise cmuxError(f"expected >=3 panes to find bottom-right panel, got {len(panes)}") + bottom_right = max(panes, key=_pane_sort_key) + return _panel_for_pane(layout_payload, bottom_right) + + +def _wait_for_panes(c: cmux, target_panes: int, *, timeout_s: float, context: str) -> dict: + deadline = time.time() + timeout_s + last = None + while time.time() < deadline: + last = c.layout_debug() + if _pane_count(last) == target_panes: + return last + time.sleep(POLL_S) + raise cmuxError( + f"timed out waiting for {target_panes} panes ({context}); " + f"last_panes={_pane_count(last or {})} last_layout={last}" + ) + + +def _portal_stats(c: cmux, *, timeout_s: float) -> dict: + stats = c._call("debug.portal.stats", timeout_s=timeout_s) or {} + if not isinstance(stats, dict): + raise cmuxError(f"debug.portal.stats returned non-dict payload: {stats!r}") + return stats + + +def _portal_integrity_error(stats: dict) -> str | None: + totals = stats.get("totals") or {} + if not isinstance(totals, dict): + return f"portal totals payload is not a dict: {totals!r}" + + required_keys = ( + "orphan_terminal_subview_count", + "visible_orphan_terminal_subview_count", + "stale_entry_count", + ) + missing = [key for key in required_keys if key not in totals] + if missing: + return f"portal totals missing required counters: {', '.join(missing)}" + + try: + orphan = int(totals["orphan_terminal_subview_count"]) + visible_orphan = int(totals["visible_orphan_terminal_subview_count"]) + stale = int(totals["stale_entry_count"]) + except (TypeError, ValueError): + return ( + "portal totals contains non-integer counters " + f"(orphan={totals.get('orphan_terminal_subview_count')!r}, " + f"visible_orphan={totals.get('visible_orphan_terminal_subview_count')!r}, " + f"stale={totals.get('stale_entry_count')!r})" + ) + + if orphan != 0 or visible_orphan != 0 or stale != 0: + return ( + "portal totals show orphan/stale entries " + f"(orphan={orphan}, visible_orphan={visible_orphan}, stale={stale})" + ) + return None + + +def _wait_for_portal_integrity(c: cmux, *, timeout_s: float, context: str) -> None: + deadline = time.time() + timeout_s + last = None + error = None + while time.time() < deadline: + remaining = deadline - time.time() + if remaining <= 0: + break + last = _portal_stats(c, timeout_s=min(remaining, 0.5)) + error = _portal_integrity_error(last) + if error is None: + return + time.sleep(POLL_S) + raise cmuxError(f"{context}: {error}; stats={last}") + + +def _close_bottom_right_via_ctrl_d(c: cmux, *, bottom_right_panel_id: str, context: str) -> dict: + c.send_key_surface(bottom_right_panel_id, "ctrl-d") + next_retry_at = time.time() + CTRL_D_RETRY_INTERVAL_S + extra = 0 + deadline = time.time() + PANE_TIMEOUT_S + last = None + + while time.time() < deadline: + last = c.layout_debug() + if _pane_count(last) == 2: + return last + + if extra < CTRL_D_MAX_EXTRA and time.time() >= next_retry_at: + c.send_key_surface(bottom_right_panel_id, "ctrl-d") + extra += 1 + next_retry_at = time.time() + CTRL_D_RETRY_INTERVAL_S + time.sleep(POLL_S) + + raise cmuxError( + f"{context}: timed out collapsing back to 2 panes after ctrl-d " + f"(extra_ctrl_d={extra}, panel={bottom_right_panel_id}); last_layout={last}" + ) + + +def _find_close_rebind_violations(lines: list[str]) -> tuple[int, list[str]]: + close_pending: set[str] = set() + deinit_started: set[str] = set() + close_count = 0 + violations: list[str] = [] + + for line in lines: + m = RE_CLOSE.search(line) + if m: + sid = m.group(1) + close_pending.add(sid) + close_count += 1 + continue + + m = RE_DEINIT_BEGIN.search(line) + if m: + sid = m.group(1) + deinit_started.add(sid) + continue + + m = RE_DEINIT_END.search(line) + if m: + sid = m.group(1) + close_pending.discard(sid) + deinit_started.discard(sid) + continue + + m = RE_VISIBLE_ON.search(line) + if m: + sid = m.group(1) + if sid in close_pending: + violations.append(line) + + return close_count, violations + + +def main() -> int: + log_path = _derive_log_path(SOCKET_PATH) + if not os.path.exists(log_path): + raise cmuxError(f"debug log not found at {log_path} for socket={SOCKET_PATH}") + log_offset = os.path.getsize(log_path) + + with cmux(SOCKET_PATH) as c: + c.activate_app() + workspace_id = c.new_workspace() + c.select_workspace(workspace_id) + time.sleep(0.2) + + c.new_split("right") + layout = _wait_for_panes(c, 2, timeout_s=PANE_TIMEOUT_S, context="initial right split") + _wait_for_portal_integrity(c, timeout_s=INTEGRITY_TIMEOUT_S, context="after initial right split") + + for iteration in range(1, ITERATIONS + 1): + right_panel_id = _rightmost_panel(layout) + c.focus_surface_by_panel(right_panel_id) + c.new_split("down") + layout = _wait_for_panes( + c, + 3, + timeout_s=PANE_TIMEOUT_S, + context=f"iter={iteration} after split down", + ) + + bottom_right_panel_id = _bottom_right_panel(layout) + layout = _close_bottom_right_via_ctrl_d( + c, + bottom_right_panel_id=bottom_right_panel_id, + context=f"iter={iteration}", + ) + _wait_for_portal_integrity(c, timeout_s=INTEGRITY_TIMEOUT_S, context=f"iter={iteration} integrity") + if POST_CLOSE_SETTLE_S > 0: + time.sleep(POST_CLOSE_SETTLE_S) + + c.close_workspace(workspace_id) + + if LOG_FLUSH_S > 0: + time.sleep(LOG_FLUSH_S) + lines, _ = _read_new_lines(log_path, log_offset) + close_count, violations = _find_close_rebind_violations(lines) + if close_count == 0: + raise cmuxError("no surface.close.childExited events captured; test did not exercise close path") + if violations: + sample = "\n".join(violations[:5]) + raise cmuxError( + "detected close->visible rebind race (closed surface became visible before deinit):\n" + f"{sample}" + ) + + print( + "PASS: no close->visible rebind races during split-down + ctrl-d churn " + f"(iters={ITERATIONS}, closes={close_count})" + ) + return 0 + + +if __name__ == "__main__": + raise SystemExit(main())