Add more logging

duckduckgo · Dec 31, 2024 · 3aee5b7 · 3aee5b7
1 parent 08b5e9b
commit 3aee5b7
Show file tree

Hide file tree

Showing 3 changed files with 54 additions and 17 deletions.
diff --git 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
@@ -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
@@ -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<UpdateCycleProgress>.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