Add drag transfer timing logs for bonsplit tabs

This commit is contained in:
Lawrence Chen 2026-02-23 20:05:12 -08:00
parent 5e44aea2c9
commit 06adb6228c
2 changed files with 271 additions and 14 deletions

View file

@ -1890,19 +1890,67 @@ final class AppDelegate: NSObject, NSApplicationDelegate, UNUserNotificationCent
focus: Bool = true,
focusWindow: Bool = true
) -> Bool {
guard let source = locateSurface(surfaceId: panelId),
let sourceWorkspace = source.tabManager.tabs.first(where: { $0.id == source.workspaceId }),
let destinationManager = tabManagerFor(tabId: targetWorkspaceId),
let destinationWorkspace = destinationManager.tabs.first(where: { $0.id == targetWorkspaceId }) else {
#if DEBUG
let moveStart = ProcessInfo.processInfo.systemUptime
let splitLabel = splitTarget.map { split in
"\(split.orientation.rawValue):\(split.insertFirst ? 1 : 0)"
} ?? "none"
func elapsedMs(since start: TimeInterval) -> String {
let ms = (ProcessInfo.processInfo.systemUptime - start) * 1000
return String(format: "%.2f", ms)
}
dlog(
"surface.move.begin panel=\(panelId.uuidString.prefix(5)) targetWs=\(targetWorkspaceId.uuidString.prefix(5)) " +
"targetPane=\(targetPane?.id.uuidString.prefix(5) ?? "auto") targetIndex=\(targetIndex.map(String.init) ?? "nil") " +
"split=\(splitLabel) focus=\(focus ? 1 : 0) focusWindow=\(focusWindow ? 1 : 0)"
)
#endif
guard let source = locateSurface(surfaceId: panelId) else {
#if DEBUG
dlog("surface.move.fail panel=\(panelId.uuidString.prefix(5)) reason=sourcePanelNotFound elapsedMs=\(elapsedMs(since: moveStart))")
#endif
return false
}
guard let sourceWorkspace = source.tabManager.tabs.first(where: { $0.id == source.workspaceId }) else {
#if DEBUG
dlog("surface.move.fail panel=\(panelId.uuidString.prefix(5)) reason=sourceWorkspaceMissing elapsedMs=\(elapsedMs(since: moveStart))")
#endif
return false
}
guard let destinationManager = tabManagerFor(tabId: targetWorkspaceId) else {
#if DEBUG
dlog("surface.move.fail panel=\(panelId.uuidString.prefix(5)) reason=destinationManagerMissing elapsedMs=\(elapsedMs(since: moveStart))")
#endif
return false
}
guard let destinationWorkspace = destinationManager.tabs.first(where: { $0.id == targetWorkspaceId }) else {
#if DEBUG
dlog("surface.move.fail panel=\(panelId.uuidString.prefix(5)) reason=destinationWorkspaceMissing elapsedMs=\(elapsedMs(since: moveStart))")
#endif
return false
}
#if DEBUG
dlog(
"surface.move.route panel=\(panelId.uuidString.prefix(5)) sourceWs=\(sourceWorkspace.id.uuidString.prefix(5)) " +
"sourceWin=\(source.windowId.uuidString.prefix(5)) destinationWs=\(destinationWorkspace.id.uuidString.prefix(5)) " +
"sameWorkspace=\(destinationWorkspace.id == sourceWorkspace.id ? 1 : 0)"
)
#endif
let resolvedTargetPane = targetPane.flatMap { pane in
destinationWorkspace.bonsplitController.allPaneIds.first(where: { $0 == pane })
} ?? destinationWorkspace.bonsplitController.focusedPaneId
?? destinationWorkspace.bonsplitController.allPaneIds.first
guard let resolvedTargetPane else { return false }
guard let resolvedTargetPane else {
#if DEBUG
dlog(
"surface.move.fail panel=\(panelId.uuidString.prefix(5)) reason=targetPaneMissing " +
"destinationWs=\(destinationWorkspace.id.uuidString.prefix(5)) elapsedMs=\(elapsedMs(since: moveStart))"
)
#endif
return false
}
if destinationWorkspace.id == sourceWorkspace.id {
if let splitTarget {
@ -1913,26 +1961,62 @@ final class AppDelegate: NSObject, NSApplicationDelegate, UNUserNotificationCent
movingTab: sourceTabId,
insertFirst: splitTarget.insertFirst
) != nil else {
#if DEBUG
dlog(
"surface.move.fail panel=\(panelId.uuidString.prefix(5)) reason=sameWorkspaceSplitFailed " +
"targetPane=\(resolvedTargetPane.id.uuidString.prefix(5)) split=\(splitLabel) " +
"elapsedMs=\(elapsedMs(since: moveStart))"
)
#endif
return false
}
if focus {
source.tabManager.focusTab(sourceWorkspace.id, surfaceId: panelId, suppressFlash: true)
}
#if DEBUG
dlog(
"surface.move.end panel=\(panelId.uuidString.prefix(5)) path=sameWorkspaceSplit moved=1 " +
"targetPane=\(resolvedTargetPane.id.uuidString.prefix(5)) elapsedMs=\(elapsedMs(since: moveStart))"
)
#endif
return true
}
return sourceWorkspace.moveSurface(
let moved = sourceWorkspace.moveSurface(
panelId: panelId,
toPane: resolvedTargetPane,
atIndex: targetIndex,
focus: focus
)
#if DEBUG
dlog(
"surface.move.end panel=\(panelId.uuidString.prefix(5)) path=sameWorkspaceMove moved=\(moved ? 1 : 0) " +
"targetPane=\(resolvedTargetPane.id.uuidString.prefix(5)) targetIndex=\(targetIndex.map(String.init) ?? "nil") " +
"elapsedMs=\(elapsedMs(since: moveStart))"
)
#endif
return moved
}
let sourcePane = sourceWorkspace.paneId(forPanelId: panelId)
let sourceIndex = sourceWorkspace.indexInPane(forPanelId: panelId)
#if DEBUG
let detachStart = ProcessInfo.processInfo.systemUptime
#endif
guard let detached = sourceWorkspace.detachSurface(panelId: panelId) else { return false }
guard let detached = sourceWorkspace.detachSurface(panelId: panelId) else {
#if DEBUG
dlog(
"surface.move.fail panel=\(panelId.uuidString.prefix(5)) reason=detachFailed " +
"elapsedMs=\(elapsedMs(since: moveStart))"
)
#endif
return false
}
#if DEBUG
let detachMs = elapsedMs(since: detachStart)
let attachStart = ProcessInfo.processInfo.systemUptime
#endif
guard destinationWorkspace.attachDetachedSurface(
detached,
inPane: resolvedTargetPane,
@ -1946,10 +2030,23 @@ final class AppDelegate: NSObject, NSApplicationDelegate, UNUserNotificationCent
sourceIndex: sourceIndex,
focus: focus
)
#if DEBUG
dlog(
"surface.move.fail panel=\(panelId.uuidString.prefix(5)) reason=attachFailed " +
"detachMs=\(detachMs) elapsedMs=\(elapsedMs(since: moveStart))"
)
#endif
return false
}
#if DEBUG
let attachMs = elapsedMs(since: attachStart)
var splitMs = "0.00"
#endif
if let splitTarget {
#if DEBUG
let splitStart = ProcessInfo.processInfo.systemUptime
#endif
guard let movedTabId = destinationWorkspace.surfaceIdFromPanelId(panelId),
destinationWorkspace.bonsplitController.splitPane(
resolvedTargetPane,
@ -1966,15 +2063,31 @@ final class AppDelegate: NSObject, NSApplicationDelegate, UNUserNotificationCent
focus: focus
)
}
#if DEBUG
dlog(
"surface.move.fail panel=\(panelId.uuidString.prefix(5)) reason=postAttachSplitFailed " +
"detachMs=\(detachMs) attachMs=\(attachMs) elapsedMs=\(elapsedMs(since: moveStart))"
)
#endif
return false
}
#if DEBUG
splitMs = elapsedMs(since: splitStart)
#endif
}
#if DEBUG
let cleanupStart = ProcessInfo.processInfo.systemUptime
#endif
cleanupEmptySourceWorkspaceAfterSurfaceMove(
sourceWorkspace: sourceWorkspace,
sourceManager: source.tabManager,
sourceWindowId: source.windowId
)
#if DEBUG
let cleanupMs = elapsedMs(since: cleanupStart)
let focusStart = ProcessInfo.processInfo.systemUptime
#endif
if focus {
let destinationWindowId = focusWindow ? windowId(for: destinationManager) : nil
@ -1992,6 +2105,16 @@ final class AppDelegate: NSObject, NSApplicationDelegate, UNUserNotificationCent
)
}
}
#if DEBUG
let focusMs = elapsedMs(since: focusStart)
dlog(
"surface.move.end panel=\(panelId.uuidString.prefix(5)) path=crossWorkspace moved=1 " +
"sourceWs=\(sourceWorkspace.id.uuidString.prefix(5)) destinationWs=\(destinationWorkspace.id.uuidString.prefix(5)) " +
"targetPane=\(resolvedTargetPane.id.uuidString.prefix(5)) targetIndex=\(targetIndex.map(String.init) ?? "nil") " +
"split=\(splitLabel) detachMs=\(detachMs) attachMs=\(attachMs) splitMs=\(splitMs) " +
"cleanupMs=\(cleanupMs) focusMs=\(focusMs) elapsedMs=\(elapsedMs(since: moveStart))"
)
#endif
return true
}
@ -2006,8 +2129,33 @@ final class AppDelegate: NSObject, NSApplicationDelegate, UNUserNotificationCent
focus: Bool = true,
focusWindow: Bool = true
) -> Bool {
guard let located = locateBonsplitSurface(tabId: tabId) else { return false }
return moveSurface(
#if DEBUG
let moveStart = ProcessInfo.processInfo.systemUptime
func elapsedMs(since start: TimeInterval) -> String {
let ms = (ProcessInfo.processInfo.systemUptime - start) * 1000
return String(format: "%.2f", ms)
}
dlog(
"surface.moveBonsplit.begin tab=\(tabId.uuidString.prefix(5)) targetWs=\(targetWorkspaceId.uuidString.prefix(5)) " +
"targetPane=\(targetPane?.id.uuidString.prefix(5) ?? "auto") targetIndex=\(targetIndex.map(String.init) ?? "nil")"
)
#endif
guard let located = locateBonsplitSurface(tabId: tabId) else {
#if DEBUG
dlog(
"surface.moveBonsplit.fail tab=\(tabId.uuidString.prefix(5)) reason=tabNotFound " +
"targetWs=\(targetWorkspaceId.uuidString.prefix(5)) elapsedMs=\(elapsedMs(since: moveStart))"
)
#endif
return false
}
#if DEBUG
dlog(
"surface.moveBonsplit.located tab=\(tabId.uuidString.prefix(5)) panel=\(located.panelId.uuidString.prefix(5)) " +
"sourceWs=\(located.workspaceId.uuidString.prefix(5)) sourceWin=\(located.windowId.uuidString.prefix(5))"
)
#endif
let moved = moveSurface(
panelId: located.panelId,
toWorkspace: targetWorkspaceId,
targetPane: targetPane,
@ -2016,6 +2164,13 @@ final class AppDelegate: NSObject, NSApplicationDelegate, UNUserNotificationCent
focus: focus,
focusWindow: focusWindow
)
#if DEBUG
dlog(
"surface.moveBonsplit.end tab=\(tabId.uuidString.prefix(5)) panel=\(located.panelId.uuidString.prefix(5)) " +
"moved=\(moved ? 1 : 0) elapsedMs=\(elapsedMs(since: moveStart))"
)
#endif
return moved
}
func tabManagerFor(windowId: UUID) -> TabManager? {

View file

@ -1061,6 +1061,8 @@ final class Workspace: Identifiable, ObservableObject {
private var focusReconcileScheduled = false
#if DEBUG
private(set) var debugFocusReconcileScheduledDuringDetachCount: Int = 0
private var debugLastDidMoveTabTimestamp: TimeInterval = 0
private var debugDidMoveTabEventCount: UInt64 = 0
#endif
private var geometryReconcileScheduled = false
private var isNormalizingPinnedTabOrder = false
@ -1093,6 +1095,13 @@ final class Workspace: Identifiable, ObservableObject {
private var activeDetachCloseTransactions: Int = 0
private var isDetachingCloseTransaction: Bool { activeDetachCloseTransactions > 0 }
#if DEBUG
private func debugElapsedMs(since start: TimeInterval) -> String {
let ms = (ProcessInfo.processInfo.systemUptime - start) * 1000
return String(format: "%.2f", ms)
}
#endif
func panelIdFromSurfaceId(_ surfaceId: TabID) -> UUID? {
surfaceIdToPanelId[surfaceId]
}
@ -2190,6 +2199,14 @@ final class Workspace: Identifiable, ObservableObject {
func detachSurface(panelId: UUID) -> DetachedSurfaceTransfer? {
guard let tabId = surfaceIdFromPanelId(panelId) else { return nil }
guard panels[panelId] != nil else { return nil }
#if DEBUG
let detachStart = ProcessInfo.processInfo.systemUptime
dlog(
"split.detach.begin ws=\(id.uuidString.prefix(5)) panel=\(panelId.uuidString.prefix(5)) " +
"tab=\(tabId.uuid.uuidString.prefix(5)) activeDetachTxn=\(activeDetachCloseTransactions) " +
"pendingDetached=\(pendingDetachedSurfaces.count)"
)
#endif
detachingTabIds.insert(tabId)
forceCloseTabIds.insert(tabId)
@ -2199,10 +2216,24 @@ final class Workspace: Identifiable, ObservableObject {
detachingTabIds.remove(tabId)
pendingDetachedSurfaces.removeValue(forKey: tabId)
forceCloseTabIds.remove(tabId)
#if DEBUG
dlog(
"split.detach.fail ws=\(id.uuidString.prefix(5)) panel=\(panelId.uuidString.prefix(5)) " +
"tab=\(tabId.uuid.uuidString.prefix(5)) reason=closeTabRejected elapsedMs=\(debugElapsedMs(since: detachStart))"
)
#endif
return nil
}
return pendingDetachedSurfaces.removeValue(forKey: tabId)
let detached = pendingDetachedSurfaces.removeValue(forKey: tabId)
#if DEBUG
dlog(
"split.detach.end ws=\(id.uuidString.prefix(5)) panel=\(panelId.uuidString.prefix(5)) " +
"tab=\(tabId.uuid.uuidString.prefix(5)) transfer=\(detached != nil ? 1 : 0) " +
"elapsedMs=\(debugElapsedMs(since: detachStart))"
)
#endif
return detached
}
@discardableResult
@ -2212,8 +2243,31 @@ final class Workspace: Identifiable, ObservableObject {
atIndex index: Int? = nil,
focus: Bool = true
) -> UUID? {
guard bonsplitController.allPaneIds.contains(paneId) else { return nil }
guard panels[detached.panelId] == nil else { return nil }
#if DEBUG
let attachStart = ProcessInfo.processInfo.systemUptime
dlog(
"split.attach.begin ws=\(id.uuidString.prefix(5)) panel=\(detached.panelId.uuidString.prefix(5)) " +
"pane=\(paneId.id.uuidString.prefix(5)) index=\(index.map(String.init) ?? "nil") focus=\(focus ? 1 : 0)"
)
#endif
guard bonsplitController.allPaneIds.contains(paneId) else {
#if DEBUG
dlog(
"split.attach.fail ws=\(id.uuidString.prefix(5)) panel=\(detached.panelId.uuidString.prefix(5)) " +
"reason=invalidPane elapsedMs=\(debugElapsedMs(since: attachStart))"
)
#endif
return nil
}
guard panels[detached.panelId] == nil else {
#if DEBUG
dlog(
"split.attach.fail ws=\(id.uuidString.prefix(5)) panel=\(detached.panelId.uuidString.prefix(5)) " +
"reason=panelExists elapsedMs=\(debugElapsedMs(since: attachStart))"
)
#endif
return nil
}
panels[detached.panelId] = detached.panel
if let terminalPanel = detached.panel as? TerminalPanel {
@ -2264,6 +2318,12 @@ final class Workspace: Identifiable, ObservableObject {
manualUnreadPanelIds.remove(detached.panelId)
manualUnreadMarkedAt.removeValue(forKey: detached.panelId)
panelSubscriptions.removeValue(forKey: detached.panelId)
#if DEBUG
dlog(
"split.attach.fail ws=\(id.uuidString.prefix(5)) panel=\(detached.panelId.uuidString.prefix(5)) " +
"reason=createTabFailed elapsedMs=\(debugElapsedMs(since: attachStart))"
)
#endif
return nil
}
@ -2285,6 +2345,14 @@ final class Workspace: Identifiable, ObservableObject {
}
scheduleTerminalGeometryReconcile()
#if DEBUG
dlog(
"split.attach.end ws=\(id.uuidString.prefix(5)) panel=\(detached.panelId.uuidString.prefix(5)) " +
"tab=\(newTabId.uuid.uuidString.prefix(5)) pane=\(paneId.id.uuidString.prefix(5)) " +
"index=\(index.map(String.init) ?? "nil") focus=\(focus ? 1 : 0) " +
"elapsedMs=\(debugElapsedMs(since: attachStart))"
)
#endif
return detached.panelId
}
// MARK: - Focus Management
@ -2833,23 +2901,41 @@ final class Workspace: Identifiable, ObservableObject {
private func handleExternalTabDrop(_ request: BonsplitController.ExternalTabDropRequest) -> Bool {
guard let app = AppDelegate.shared else { return false }
#if DEBUG
let dropStart = ProcessInfo.processInfo.systemUptime
#endif
let targetPane: PaneID
let targetIndex: Int?
let splitTarget: (orientation: SplitOrientation, insertFirst: Bool)?
#if DEBUG
let destinationLabel: String
#endif
switch request.destination {
case .insert(let paneId, let index):
targetPane = paneId
targetIndex = index
splitTarget = nil
#if DEBUG
destinationLabel = "insert pane=\(paneId.id.uuidString.prefix(5)) index=\(index.map(String.init) ?? "nil")"
#endif
case .split(let paneId, let orientation, let insertFirst):
targetPane = paneId
targetIndex = nil
splitTarget = (orientation, insertFirst)
#if DEBUG
destinationLabel = "split pane=\(paneId.id.uuidString.prefix(5)) orientation=\(orientation.rawValue) insertFirst=\(insertFirst ? 1 : 0)"
#endif
}
return app.moveBonsplitTab(
#if DEBUG
dlog(
"split.externalDrop.begin ws=\(id.uuidString.prefix(5)) tab=\(request.tabId.uuid.uuidString.prefix(5)) " +
"sourcePane=\(request.sourcePaneId.id.uuidString.prefix(5)) destination=\(destinationLabel)"
)
#endif
let moved = app.moveBonsplitTab(
tabId: request.tabId.uuid,
toWorkspace: id,
targetPane: targetPane,
@ -2858,6 +2944,13 @@ final class Workspace: Identifiable, ObservableObject {
focus: true,
focusWindow: true
)
#if DEBUG
dlog(
"split.externalDrop.end ws=\(id.uuidString.prefix(5)) tab=\(request.tabId.uuid.uuidString.prefix(5)) " +
"moved=\(moved ? 1 : 0) elapsedMs=\(debugElapsedMs(since: dropStart))"
)
#endif
return moved
}
}
@ -3241,9 +3334,18 @@ extension Workspace: BonsplitDelegate {
func splitTabBar(_ controller: BonsplitController, didMoveTab tab: Bonsplit.Tab, fromPane source: PaneID, toPane destination: PaneID) {
#if DEBUG
let now = ProcessInfo.processInfo.systemUptime
let sincePrev: String
if debugLastDidMoveTabTimestamp > 0 {
sincePrev = String(format: "%.2f", (now - debugLastDidMoveTabTimestamp) * 1000)
} else {
sincePrev = "first"
}
debugLastDidMoveTabTimestamp = now
debugDidMoveTabEventCount += 1
let movedPanel = panelIdFromSurfaceId(tab.id)?.uuidString.prefix(5) ?? "unknown"
dlog(
"split.moveTab panel=\(movedPanel) " +
"split.moveTab idx=\(debugDidMoveTabEventCount) dtSincePrevMs=\(sincePrev) panel=\(movedPanel) " +
"from=\(source.id.uuidString.prefix(5)) to=\(destination.id.uuidString.prefix(5)) " +
"sourceTabs=\(controller.tabs(inPane: source).count) destTabs=\(controller.tabs(inPane: destination).count)"
)