Skip to content

Commit

Permalink
Logging reworks
Browse files Browse the repository at this point in the history
  • Loading branch information
@jordanbaird
jordanbaird committed Jul 10, 2024
1 parent 4a63155 commit 868505d
Show file tree
Hide file tree
Showing 6 changed files with 40 additions and 44 deletions.
6 changes: 0 additions & 6 deletions Ice/LayoutBar/LayoutBarContainer.swift
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,6 @@

import Cocoa
import Combine
import OSLog

/// A container for the items in the menu bar layout interface.
class LayoutBarContainer: NSView {
Expand Down Expand Up @@ -304,8 +303,3 @@ class LayoutBarContainer: NSView {
}
}
}

// MARK: - Logger
private extension Logger {
static let layoutBar = Logger(category: "LayoutBar")
}
4 changes: 2 additions & 2 deletions Ice/Main/AppDelegate.swift
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
}

Expand All @@ -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
}

Expand Down
2 changes: 1 addition & 1 deletion Ice/Main/AppState.swift
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
Expand Down
11 changes: 7 additions & 4 deletions Ice/MenuBar/MenuBarItemImageCache.swift
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -231,6 +233,7 @@ class MenuBarItemImageCache: ObservableObject {
{
sectionsNeedingDisplay.append(section)
}

await updateCacheWithoutChecks(sections: sectionsNeedingDisplay)
}
}
Expand Down
51 changes: 25 additions & 26 deletions Ice/MenuBar/MenuBarItemManager.swift
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand All @@ -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 {
Expand All @@ -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)
}
}
}
Expand All @@ -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
Expand All @@ -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
}

Expand All @@ -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()
}
}
Expand Down Expand Up @@ -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()

Expand Down Expand Up @@ -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)

Expand Down Expand Up @@ -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
Expand All @@ -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
}
}
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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
}
Expand All @@ -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
}

Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand All @@ -964,7 +964,7 @@ extension MenuBarItemManager {
return
}

Logger.itemManager.info("Rehide timer fired")
Logger.itemManager.debug("Rehide timer fired")

Task {
await self.rehideTempShownItems()
Expand Down Expand Up @@ -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) {
Expand All @@ -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 {
Expand Down Expand Up @@ -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 {
Expand Down Expand Up @@ -1278,5 +1278,4 @@ private extension CGEvent {

private extension Logger {
static let itemManager = Logger(category: "MenuBarItemManager")
static let itemCache = Logger(category: "MenuBarItemManager.ItemCache")
}
10 changes: 5 additions & 5 deletions Ice/MenuBarAppearance/MenuBarOverlayPanel.swift
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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
}

Expand Down

0 comments on commit 868505d

Please sign in to comment.