From 3aee5b78c4cc18235483f5ff8b5d590802daab52 Mon Sep 17 00:00:00 2001 From: Anh Do Date: Mon, 30 Dec 2024 16:38:28 +0700 Subject: [PATCH] Add more logging --- .../NavigationBar/View/MoreOptionsMenu.swift | 15 ++++++-- DuckDuckGo/Updates/UpdateController.swift | 36 +++++++++++++------ DuckDuckGo/Updates/UpdateUserDriver.swift | 20 +++++++++-- 3 files changed, 54 insertions(+), 17 deletions(-) diff --git a/DuckDuckGo/NavigationBar/View/MoreOptionsMenu.swift b/DuckDuckGo/NavigationBar/View/MoreOptionsMenu.swift index 76b4c80049..4604858512 100644 --- a/DuckDuckGo/NavigationBar/View/MoreOptionsMenu.swift +++ b/DuckDuckGo/NavigationBar/View/MoreOptionsMenu.swift @@ -331,11 +331,20 @@ final class MoreOptionsMenu: NSMenu, NSMenuDelegate { #if SPARKLE guard NSApp.runType != .uiTests, let updateController = Application.appDelegate.updateController, - let update = updateController.latestUpdate, - updateController.hasPendingUpdate - else { + let update = updateController.latestUpdate else { return } + + // Log edge cases where menu item appears but doesn't function + // To be removed in a future version + if !update.isInstalled, updateController.updateProgress.isDone { + updateController.log() + } + + guard updateController.hasPendingUpdate else { + return + } + addItem(UpdateMenuItemFactory.menuItem(for: update)) addItem(NSMenuItem.separator()) #endif diff --git a/DuckDuckGo/Updates/UpdateController.swift b/DuckDuckGo/Updates/UpdateController.swift index 9d28a981f4..6eee5bbb45 100644 --- a/DuckDuckGo/Updates/UpdateController.swift +++ b/DuckDuckGo/Updates/UpdateController.swift @@ -105,7 +105,7 @@ final class UpdateController: NSObject, UpdateControllerProtocol { @UserDefaultsWrapper(key: .automaticUpdates, defaultValue: true) var areAutomaticUpdatesEnabled: Bool { didSet { - Logger.updates.log("areAutomaticUpdatesEnabled: \(self.areAutomaticUpdatesEnabled)") + Logger.updates.log("areAutomaticUpdatesEnabled: \(self.areAutomaticUpdatesEnabled, privacy: .public)") if oldValue != areAutomaticUpdatesEnabled { userDriver?.cancelAndDismissCurrentUpdate() try? configureUpdater() @@ -239,7 +239,7 @@ extension UpdateController: SPUUpdaterDelegate { } func updater(_ updater: SPUUpdater, didAbortWithError error: Error) { - Logger.updates.error("Updater did abort with error: \(error.localizedDescription)") + Logger.updates.error("Updater did abort with error: \(error.localizedDescription, privacy: .public)") let errorCode = (error as NSError).code guard ![Int(Sparkle.SUError.noUpdateError.rawValue), Int(Sparkle.SUError.installationCanceledError.rawValue), @@ -252,7 +252,7 @@ extension UpdateController: SPUUpdaterDelegate { } func updater(_ updater: SPUUpdater, didFindValidUpdate item: SUAppcastItem) { - Logger.updates.log("Updater did find valid update: \(item.displayVersionString)(\(item.versionString))") + Logger.updates.log("Updater did find valid update: \(item.displayVersionString, privacy: .public)(\(item.versionString, privacy: .public))") PixelKit.fire(DebugEvent(GeneralPixel.updaterDidFindUpdate)) cachedUpdateResult = UpdateCheckResult(item: item, isInstalled: false) } @@ -261,7 +261,7 @@ extension UpdateController: SPUUpdaterDelegate { let nsError = error as NSError guard let item = nsError.userInfo[SPULatestAppcastItemFoundKey] as? SUAppcastItem else { return } - Logger.updates.log("Updater did not find update: \(String(describing: item.displayVersionString))(\(String(describing: item.versionString)))") + Logger.updates.log("Updater did not find update: \(String(describing: item.displayVersionString), privacy: .public)(\(String(describing: item.versionString), privacy: .public))") PixelKit.fire(DebugEvent(GeneralPixel.updaterDidNotFindUpdate, error: error)) // Edge case: User upgrades to latest version within their rollout group @@ -274,36 +274,50 @@ extension UpdateController: SPUUpdaterDelegate { } func updater(_ updater: SPUUpdater, didDownloadUpdate item: SUAppcastItem) { - Logger.updates.log("Updater did download update: \(item.displayVersionString)(\(item.versionString))") + Logger.updates.log("Updater did download update: \(item.displayVersionString, privacy: .public)(\(item.versionString, privacy: .public))") PixelKit.fire(DebugEvent(GeneralPixel.updaterDidDownloadUpdate)) } func updater(_ updater: SPUUpdater, didExtractUpdate item: SUAppcastItem) { - Logger.updates.log("Updater did extract update: \(item.displayVersionString)(\(item.versionString))") + Logger.updates.log("Updater did extract update: \(item.displayVersionString, privacy: .public)(\(item.versionString, privacy: .public))") } func updater(_ updater: SPUUpdater, willInstallUpdate item: SUAppcastItem) { - Logger.updates.log("Updater will install update: \(item.displayVersionString)(\(item.versionString))") + Logger.updates.log("Updater will install update: \(item.displayVersionString, privacy: .public)(\(item.versionString, privacy: .public))") } func updater(_ updater: SPUUpdater, willInstallUpdateOnQuit item: SUAppcastItem, immediateInstallationBlock immediateInstallHandler: @escaping () -> Void) -> Bool { - Logger.updates.log("Updater will install update on quit: \(item.displayVersionString)(\(item.versionString))") + Logger.updates.log("Updater will install update on quit: \(item.displayVersionString, privacy: .public)(\(item.versionString, privacy: .public))") userDriver?.configureResumeBlock(immediateInstallHandler) return true } func updater(_ updater: SPUUpdater, didFinishUpdateCycleFor updateCheck: SPUUpdateCheck, error: (any Error)?) { if error == nil { - Logger.updates.log("Updater did finish update cycle") + Logger.updates.log("Updater did finish update cycle with no error") updateProgress = .updateCycleDone } else if let errorCode = (error as? NSError)?.code, errorCode == Int(Sparkle.SUError.noUpdateError.rawValue) { Logger.updates.log("Updater did finish update cycle with no update found") updateProgress = .updateCycleDone - } else { - Logger.updates.log("Updater did finish update cycle with error") + } else if let error { + Logger.updates.log("Updater did finish update cycle with error: \(error.localizedDescription, privacy: .public)") } } + func log() { + Logger.updates.log("areAutomaticUpdatesEnabled: \(self.areAutomaticUpdatesEnabled, privacy: .public)") + if let cachedUpdateResult { + Logger.updates.log("cachedUpdateResult: \(cachedUpdateResult.item.displayVersionString, privacy: .public)(\(cachedUpdateResult.item.versionString, privacy: .public))") + } + if let state = userDriver?.sparkleUpdateState { + Logger.updates.log("Sparkle update state: (userInitiated: \(state.userInitiated, privacy: .public), stage: \(state.stage.rawValue, privacy: .public))") + } else { + Logger.updates.log("Sparkle update state: Unknown") + } + if let userDriver { + Logger.updates.log("isResumable: \(userDriver.isResumable, privacy: .public)") + } + } } #endif diff --git a/DuckDuckGo/Updates/UpdateUserDriver.swift b/DuckDuckGo/Updates/UpdateUserDriver.swift index 1914be348a..fefc73e0fe 100644 --- a/DuckDuckGo/Updates/UpdateUserDriver.swift +++ b/DuckDuckGo/Updates/UpdateUserDriver.swift @@ -79,14 +79,18 @@ enum UpdateCycleProgress { final class UpdateUserDriver: NSObject, SPUUserDriver { enum Checkpoint: Equatable { - case download - case restart + case download // for manual updates, pause the process before downloading the update + case restart // for automatic updates, pause the process before attempting to restart } private var internalUserDecider: InternalUserDecider private var checkpoint: Checkpoint + + // Resume the update process when the user explicitly chooses to do so private var onResuming: (() -> Void)? + + // Dismiss the current update for the time being but keep the downloaded file around private var onDismiss: () -> Void = {} var isResumable: Bool { @@ -99,6 +103,8 @@ final class UpdateUserDriver: NSObject, SPUUserDriver { @Published var updateProgress = UpdateCycleProgress.default var updateProgressPublisher: Published.Publisher { $updateProgress } + private(set) var sparkleUpdateState: SPUUserUpdateState? + init(internalUserDecider: InternalUserDecider, areAutomaticUpdatesEnabled: Bool) { self.internalUserDecider = internalUserDecider @@ -127,12 +133,16 @@ final class UpdateUserDriver: NSObject, SPUUserDriver { } func showUserInitiatedUpdateCheck(cancellation: @escaping () -> Void) { - Logger.updates.log("Updater started performing the update check. (isInternalUser: \(self.internalUserDecider.isInternalUser)") + Logger.updates.log("Updater started performing the update check. (isInternalUser: \(self.internalUserDecider.isInternalUser, privacy: .public))") updateProgress = .updateCycleDidStart } func showUpdateFound(with appcastItem: SUAppcastItem, state: SPUUserUpdateState, reply: @escaping (SPUUserUpdateChoice) -> Void) { + Logger.updates.log("Updater showed update found: (userInitiated: \(state.userInitiated, privacy: .public), stage: \(state.stage.rawValue, privacy: .public))") + sparkleUpdateState = state + if appcastItem.isInformationOnlyUpdate { + Logger.updates.log("Updater dismissed due to information only update") reply(.dismiss) } @@ -141,7 +151,9 @@ final class UpdateUserDriver: NSObject, SPUUserDriver { if checkpoint == .download { onResuming = { reply(.install) } updateProgress = .updateCycleDone + Logger.updates.log("Updater paused at download checkpoint (manual update pending user decision)") } else { + Logger.updates.log("Updater proceeded to installation") reply(.install) } } @@ -193,8 +205,10 @@ final class UpdateUserDriver: NSObject, SPUUserDriver { if checkpoint == .restart { onResuming = { reply(.install) } + Logger.updates.log("Updater paused at restart checkpoint (automatic update pending user decision)") } else { reply(.install) + Logger.updates.log("Updater proceeded to installation") } updateProgress = .updateCycleDone