From 868505deedd04286a865dbe2fc328deb7df24025 Mon Sep 17 00:00:00 2001 From: Jordan Baird Date: Wed, 10 Jul 2024 01:24:14 -0600 Subject: [PATCH] Logging reworks --- Ice/LayoutBar/LayoutBarContainer.swift | 6 --- Ice/Main/AppDelegate.swift | 4 +- Ice/Main/AppState.swift | 2 +- Ice/MenuBar/MenuBarItemImageCache.swift | 11 ++-- Ice/MenuBar/MenuBarItemManager.swift | 51 +++++++++---------- .../MenuBarOverlayPanel.swift | 10 ++-- 6 files changed, 40 insertions(+), 44 deletions(-) diff --git a/Ice/LayoutBar/LayoutBarContainer.swift b/Ice/LayoutBar/LayoutBarContainer.swift index 5d4f66f9..bd276b59 100644 --- a/Ice/LayoutBar/LayoutBarContainer.swift +++ b/Ice/LayoutBar/LayoutBarContainer.swift @@ -5,7 +5,6 @@ import Cocoa import Combine -import OSLog /// A container for the items in the menu bar layout interface. class LayoutBarContainer: NSView { @@ -304,8 +303,3 @@ class LayoutBarContainer: NSView { } } } - -// MARK: - Logger -private extension Logger { - static let layoutBar = Logger(category: "LayoutBar") -} diff --git a/Ice/Main/AppDelegate.swift b/Ice/Main/AppDelegate.swift index 773abb5e..d09bbca9 100644 --- a/Ice/Main/AppDelegate.swift +++ b/Ice/Main/AppDelegate.swift @@ -12,7 +12,7 @@ class AppDelegate: NSObject, NSApplicationDelegate { func applicationWillFinishLaunching(_ notification: Notification) { guard let appState else { - Logger.appDelegate.warning("\(#function) missing app state") + Logger.appDelegate.warning("Missing app state in applicationWillFinishLaunching") return } @@ -28,7 +28,7 @@ class AppDelegate: NSObject, NSApplicationDelegate { func applicationDidFinishLaunching(_ notification: Notification) { guard let appState else { - Logger.appDelegate.warning("\(#function) missing app state") + Logger.appDelegate.warning("Missing app state in applicationDidFinishLaunching") return } diff --git a/Ice/Main/AppState.swift b/Ice/Main/AppState.swift index 02640e21..5bd2e3a5 100644 --- a/Ice/Main/AppState.swift +++ b/Ice/Main/AppState.swift @@ -211,7 +211,7 @@ final class AppState: ObservableObject { activate() } else { Context.hasActivated[self] = true - Logger.appState.info("First time activating app, so going through Dock") + Logger.appState.debug("First time activating app, so going through Dock") // hack to make sure the app properly activates for the first time NSRunningApplication.runningApplications(withBundleIdentifier: "com.apple.dock").first?.activate() DispatchQueue.main.asyncAfter(deadline: .now() + 0.2) { diff --git a/Ice/MenuBar/MenuBarItemImageCache.swift b/Ice/MenuBar/MenuBarItemImageCache.swift index 3eaaca0f..1b769ebc 100644 --- a/Ice/MenuBar/MenuBarItemImageCache.swift +++ b/Ice/MenuBar/MenuBarItemImageCache.swift @@ -205,23 +205,25 @@ class MenuBarItemImageCache: ObservableObject { guard let appState else { return } + if !appState.navigationState.isIceBarPresented { - Logger.imageCache.info("Ice Bar not visible") guard appState.navigationState.isSettingsPresented else { - Logger.imageCache.info("Settings not visible, so deferring image cache") + Logger.imageCache.debug("Skipping image cache as Ice Bar not visible, Settings not visible") return } guard case .menuBarItems = appState.navigationState.settingsNavigationIdentifier else { - Logger.imageCache.info("Settings visible but not viewing menu bar items, so deferring image cache") + Logger.imageCache.debug("Skipping image cache as Ice Bar not visible, Settings visible but not on Menu Bar Items pane") return } } + if let lastItemMoveStartDate = appState.itemManager.lastItemMoveStartDate { guard Date.now.timeIntervalSince(lastItemMoveStartDate) > 3 else { - Logger.imageCache.info("Recently moved an item, so deferring image cache") + Logger.imageCache.debug("Skipping image cache as an item was recently moved") return } } + var sectionsNeedingDisplay = [MenuBarSection.Name]() if appState.navigationState.isSettingsPresented { sectionsNeedingDisplay = MenuBarSection.Name.allCases @@ -231,6 +233,7 @@ class MenuBarItemImageCache: ObservableObject { { sectionsNeedingDisplay.append(section) } + await updateCacheWithoutChecks(sections: sectionsNeedingDisplay) } } diff --git a/Ice/MenuBar/MenuBarItemManager.swift b/Ice/MenuBar/MenuBarItemManager.swift index 8006514b..38c0a4a1 100644 --- a/Ice/MenuBar/MenuBarItemManager.swift +++ b/Ice/MenuBar/MenuBarItemManager.swift @@ -139,11 +139,11 @@ extension MenuBarItemManager { /// Caches the given menu bar items, without checking whether the control items /// are in the correct order. private func uncheckedCacheItems(hiddenControlItem: MenuBarItem, alwaysHiddenControlItem: MenuBarItem?, otherItems: [MenuBarItem]) { - func notAdded(_ item: MenuBarItem) { - Logger.itemCache.warning("Item \"\(item.logString)\" not added to any section") + func logNotAddedWarning(for item: MenuBarItem) { + Logger.itemManager.warning("Item \"\(item.logString)\" doesn't seem to be in a section, so it wasn't cached") } - Logger.itemCache.info("Caching menu bar items") + Logger.itemManager.debug("Caching menu bar items") update(&itemCache) { cache in cache.clear() @@ -160,7 +160,7 @@ extension MenuBarItemManager { } else if item.frame.maxX <= alwaysHiddenControlItem.frame.minX { cache.appendItem(item, to: .alwaysHidden) } else { - notAdded(item) + logNotAddedWarning(for: item) } } } else { @@ -170,7 +170,7 @@ extension MenuBarItemManager { } else if item.frame.maxX <= hiddenControlItem.frame.minX { cache.appendItem(item, to: .hidden) } else { - notAdded(item) + logNotAddedWarning(for: item) } } } @@ -179,20 +179,20 @@ extension MenuBarItemManager { private func cacheItemsIfNeeded() async { guard tempShownItemsInfo.isEmpty else { - Logger.itemCache.info("Items temporarily shown, so deferring item cache") + Logger.itemManager.debug("Skipping item cache as items are temporarily shown") return } if let lastItemMoveStartDate { guard Date.now.timeIntervalSince(lastItemMoveStartDate) > 3 else { - Logger.itemManager.info("Recently moved an item, so deferring item cache") + Logger.itemManager.debug("Skipping item cache as an item was recently moved") return } } let itemWindowIDs = Bridging.getWindowList(option: [.menuBarItems, .activeSpace]) if cachedItemWindowIDs == itemWindowIDs { - Logger.itemManager.info("Menu bar item windows have not changed, so deferring item cache") + Logger.itemManager.debug("Skipping item cache as menu bar item windows have not changed") return } else { cachedItemWindowIDs = itemWindowIDs @@ -211,8 +211,9 @@ extension MenuBarItemManager { .map { items.remove(at: $0) } guard let hiddenControlItem else { + Logger.itemManager.warning("Missing control item for hidden section") + Logger.itemManager.debug("Clearing item cache") itemCache.clear() - Logger.itemCache.error("Missing control item for hidden section") return } @@ -229,7 +230,8 @@ extension MenuBarItemManager { otherItems: items ) } catch { - Logger.itemCache.error("Error enforcing control item order: \(error)") + Logger.itemManager.error("Error enforcing control item order: \(error)") + Logger.itemManager.debug("Clearing item cache") itemCache.clear() } } @@ -484,7 +486,7 @@ extension MenuBarItemManager { return rEvent } - Logger.itemManager.info("Received \(type.logString) at \(location.logString)") + Logger.itemManager.debug("Received \(type.logString) at \(location.logString)") proxy.disable() @@ -544,7 +546,7 @@ extension MenuBarItemManager { return rEvent } - Logger.itemManager.info("Forwarding \(type.logString) from \(initialLocation.logString) to \(forwardedLocation.logString)") + Logger.itemManager.debug("Forwarding \(type.logString) from \(initialLocation.logString) to \(forwardedLocation.logString)") postEvent(event, to: forwardedLocation) @@ -588,9 +590,7 @@ extension MenuBarItemManager { ) async throws { guard let currentFrame = getCurrentFrame(for: item) else { try await forwardEvent(event, from: initialLocation, to: forwardedLocation) - Logger.itemManager.warning("No item frame, so using fixed delay instead of frame check") - // this will be slow, but subsequent events will have a better chance of succeeding try await Task.sleep(for: .milliseconds(50)) return @@ -615,7 +615,7 @@ extension MenuBarItemManager { throw FrameCheckCancellationError() } if currentFrame != initialFrame { - Logger.itemManager.info("Menu bar item frame has changed to \(NSStringFromRect(currentFrame))") + Logger.itemManager.debug("Menu bar item frame has changed to \(NSStringFromRect(currentFrame))") return } } @@ -650,7 +650,7 @@ extension MenuBarItemManager { /// Tries to wake up the given item if it is not responding to events. private func wakeUpItem(_ item: MenuBarItem) async throws { - Logger.itemManager.info("Attempting to wake up \"\(item.logString)\"") + Logger.itemManager.debug("Attempting to wake up \"\(item.logString)\"") guard let source = CGEventSource(stateID: .hidSystemState) else { throw EventError(code: .invalidEventSource, item: item) @@ -750,7 +750,7 @@ extension MenuBarItemManager { ) } catch { let location = EventTap.Location.sessionEventTap - Logger.itemManager.info("Posting fallback event to \(location.logString)") + Logger.itemManager.debug("Posting fallback event to \(location.logString)") postEvent(fallbackEvent, to: location) throw error } @@ -763,7 +763,7 @@ extension MenuBarItemManager { /// - destination: A destination to move the menu bar item. func move(item: MenuBarItem, to destination: MoveDestination) async throws { if try itemHasCorrectPosition(item: item, for: destination) { - Logger.itemManager.info("\"\(item.logString)\" is already in the correct position") + Logger.itemManager.debug("\"\(item.logString)\" is already in the correct position") return } @@ -806,7 +806,7 @@ extension MenuBarItemManager { throw EventError(code: .couldNotComplete, item: item) } } catch where n < 5 { - Logger.itemManager.error("Attempt \(n) to move \"\(item.logString)\" failed: \(error)") + Logger.itemManager.warning("Attempt \(n) to move \"\(item.logString)\" failed: \(error)") try await wakeUpItem(item) Logger.itemManager.info("Retrying move") continue @@ -955,7 +955,7 @@ extension MenuBarItemManager { /// Schedules a timer for the given interval, attempting to rehide the current /// temporarily shown items when the timer fires. private func runTempShownItemTimer(for interval: TimeInterval) { - Logger.itemManager.info("Running rehide timer for temp shown items with interval: \(interval, format: .hybrid)") + Logger.itemManager.debug("Running rehide timer for temp shown items with interval: \(interval, format: .hybrid)") tempShownItemsTimer?.invalidate() tempShownItemsTimer = .scheduledTimer(withTimeInterval: interval, repeats: false) { [weak self] timer in @@ -964,7 +964,7 @@ extension MenuBarItemManager { return } - Logger.itemManager.info("Rehide timer fired") + Logger.itemManager.debug("Rehide timer fired") Task { await self.rehideTempShownItems() @@ -1039,7 +1039,7 @@ extension MenuBarItemManager { } if let menuWindow = WindowInfo.getAllWindows().first(where: { $0.layer == 101 }) { - Logger.itemManager.info("Waiting for menu to close before rehiding temp shown items") + Logger.itemManager.debug("Waiting for menu to close before rehiding temp shown items") let menuCheckTask = Task.detached(timeout: .seconds(1)) { while Set(Bridging.getWindowList(option: .onScreen)).contains(menuWindow.windowID) { @@ -1050,7 +1050,7 @@ extension MenuBarItemManager { do { try await menuCheckTask.value } catch is TaskTimeoutError { - Logger.itemManager.info("Menu check task timed out. Switching to timer") + Logger.itemManager.debug("Menu check task timed out. Switching to timer") runTempShownItemTimer(for: 3) return } catch { @@ -1092,11 +1092,11 @@ extension MenuBarItemManager { /// - alwaysHiddenControlItem: A menu bar item that represents the control item for the always-hidden section. func enforceControlItemOrder(hiddenControlItem: MenuBarItem, alwaysHiddenControlItem: MenuBarItem) async throws { guard !isMouseButtonDown else { - Logger.itemManager.info("Mouse button is down, so will not enforce control item order") + Logger.itemManager.debug("Mouse button is down, so will not enforce control item order") return } guard mouseMovedCount <= 0 else { - Logger.itemManager.info("Mouse has recently moved, so will not enforce control item order") + Logger.itemManager.debug("Mouse has recently moved, so will not enforce control item order") return } if hiddenControlItem.frame.maxX <= alwaysHiddenControlItem.frame.minX { @@ -1278,5 +1278,4 @@ private extension CGEvent { private extension Logger { static let itemManager = Logger(category: "MenuBarItemManager") - static let itemCache = Logger(category: "MenuBarItemManager.ItemCache") } diff --git a/Ice/MenuBarAppearance/MenuBarOverlayPanel.swift b/Ice/MenuBarAppearance/MenuBarOverlayPanel.swift index 5e8a23bc..3c455405 100644 --- a/Ice/MenuBarAppearance/MenuBarOverlayPanel.swift +++ b/Ice/MenuBarAppearance/MenuBarOverlayPanel.swift @@ -247,20 +247,20 @@ class MenuBarOverlayPanel: NSPanel { case .updates: "Preventing overlay panel from updating." } guard let appState else { - Logger.overlayPanel.notice("No app state. \(actionMessage)") + Logger.overlayPanel.debug("No app state. \(actionMessage)") return nil } guard !appState.menuBarManager.isMenuBarHiddenBySystemUserDefaults else { - Logger.overlayPanel.notice("Menu bar is hidden by system according to UserDefaults. \(actionMessage)") + Logger.overlayPanel.debug("Menu bar is hidden by system. \(actionMessage)") return nil } guard !appState.isActiveSpaceFullscreen else { - Logger.overlayPanel.notice("Active space is fullscreen. \(actionMessage)") + Logger.overlayPanel.debug("Active space is fullscreen. \(actionMessage)") return nil } let owningDisplay = owningScreen.displayID guard appState.menuBarManager.hasValidMenuBar(in: windows, for: owningDisplay) else { - Logger.overlayPanel.notice("No valid menu bar found. \(actionMessage)") + Logger.overlayPanel.debug("No valid menu bar found. \(actionMessage)") return nil } return owningDisplay @@ -312,7 +312,7 @@ class MenuBarOverlayPanel: NSPanel { } guard appState.menuBarManager.appearanceManager.overlayPanels.contains(self) else { - Logger.overlayPanel.notice("Overlay panel \(self) not retained") + Logger.overlayPanel.warning("Overlay panel \(self) not retained") return }