Address updater feedback

DuckDuckGo/NavigationBar/View/MoreOptionsMenu.swift

@@ -331,12 +331,20 @@ final class MoreOptionsMenu: NSMenu, NSMenuDelegate {
 #if SPARKLE
         guard NSApp.runType != .uiTests,
               let updateController = Application.appDelegate.updateController,
-              let update = updateController.latestUpdate,
-              !update.isInstalled,
-              updateController.updateProgress.isDone
-        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

DuckDuckGo/Updates/ReleaseNotesTabExtension.swift

@@ -133,7 +133,7 @@ extension ReleaseNotesValues {
          releaseNotes: [String]? = nil,
          releaseNotesPrivacyPro: [String]? = nil,
          downloadProgress: Double? = nil,
-         automaticUpdate: Bool? = nil) {
+         automaticUpdate: Bool?) {
         self.status = status.rawValue
         self.currentVersion = currentVersion
         self.latestVersion = latestVersion
@@ -145,14 +145,15 @@ extension ReleaseNotesValues {
         self.automaticUpdate = automaticUpdate
     }
 
-    init(from updateController: UpdateController?) {
+    init(from updateController: UpdateController) {
         let currentVersion = "\(AppVersion().versionNumber) (\(AppVersion().buildNumber))"
-        let lastUpdate = UInt((updateController?.lastUpdateCheckDate ?? Date()).timeIntervalSince1970)
+        let lastUpdate = UInt((updateController.lastUpdateCheckDate ?? Date()).timeIntervalSince1970)
 
-        guard let updateController, let latestUpdate = updateController.latestUpdate else {
-            self.init(status: updateController?.updateProgress.toStatus ?? .loaded,
+        guard let latestUpdate = updateController.latestUpdate else {
+            self.init(status: updateController.updateProgress.toStatus,
                       currentVersion: currentVersion,
-                      lastUpdate: lastUpdate)
+                      lastUpdate: lastUpdate,
+                      automaticUpdate: updateController.areAutomaticUpdatesEnabled)
             return
         }
 
@@ -194,11 +195,11 @@ private extension Update {
 private extension UpdateCycleProgress {
     var toStatus: ReleaseNotesValues.Status {
         switch self {
-        case .updateCycleDidStart: return .loading
+        case .updateCycleNotStarted, .updateCycleDidStart: return .loading
         case .downloadDidStart, .downloading: return .updateDownloading
         case .extractionDidStart, .extracting, .readyToInstallAndRelaunch, .installationDidStart, .installing: return .updatePreparing
         case .updaterError: return .updateError
-        case .updateCycleNotStarted, .updateCycleDone: return .updateReady
+        case .updateCycleDone: return .loaded
         }
     }
 

DuckDuckGo/Updates/ReleaseNotesUserScript.swift

@@ -77,7 +77,10 @@ final class ReleaseNotesUserScript: NSObject, Subfeature {
             return
         }
 
-        let updateController = Application.appDelegate.updateController
+        guard let updateController = Application.appDelegate.updateController else {
+            return
+        }
+
         let values = ReleaseNotesValues(from: updateController)
         broker?.push(method: "onUpdate", params: values, for: self, into: webView)
     }

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) (\(error.pixelParameters, 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 valid update: \(item.displayVersionString, privacy: .public)(\(item.versionString, privacy: .public))")
         PixelKit.fire(DebugEvent(GeneralPixel.updaterDidNotFindUpdate, error: error))
 
         // Edge case: User upgrades to latest version within their rollout group
@@ -274,30 +274,51 @@ 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, 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")
-            updateProgress = .updateCycleDone
+            Logger.updates.log("Updater did finish update cycle with no error")
+            updateProgress = .updateCycleDone(.finishedWithNoError)
         } 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")
+            updateProgress = .updateCycleDone(.finishedWithNoUpdateFound)
+        } else if let error {
+            Logger.updates.log("Updater did finish update cycle with error: \(error.localizedDescription, privacy: .public) (\(error.pixelParameters, privacy: .public))")
         }
     }
 
+    func log() {
+        Logger.updates.log("areAutomaticUpdatesEnabled: \(self.areAutomaticUpdatesEnabled, privacy: .public)")
+        Logger.updates.log("updateProgress: \(self.updateProgress, 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

DuckDuckGo/Updates/UpdateNotificationPresenter.swift

@@ -26,7 +26,7 @@ final class UpdateNotificationPresenter {
     static let presentationTimeInterval: TimeInterval = 10
 
     func showUpdateNotification(icon: NSImage, text: String, buttonText: String? = nil, presentMultiline: Bool = false) {
-        Logger.updates.log("Notification presented: \(text)")
+        Logger.updates.log("Notification presented: \(text, privacy: .public)")
 
         DispatchQueue.main.async {
             guard let windowController = WindowControllersManager.shared.lastKeyMainWindowController ?? WindowControllersManager.shared.mainWindowControllers.last,

DuckDuckGo/Updates/UpdateUserDriver.swift

@@ -40,10 +40,19 @@ enum UpdateState {
     }
 }
 
-enum UpdateCycleProgress {
+enum UpdateCycleProgress: CustomStringConvertible {
+    enum DoneReason: Int {
+        case finishedWithNoError = 100
+        case finishedWithNoUpdateFound = 101
+        case pausedAtDownloadCheckpoint = 102
+        case pausedAtRestartCheckpoint = 103
+        case proceededToInstallationAtRestartCheckpoint = 104
+        case dismissedWithNoError = 105
+    }
+
     case updateCycleNotStarted
     case updateCycleDidStart
-    case updateCycleDone
+    case updateCycleDone(DoneReason)
     case downloadDidStart
     case downloading(Double)
     case extractionDidStart
@@ -75,19 +84,39 @@ enum UpdateCycleProgress {
         default: return false
         }
     }
+
+    var description: String {
+        switch self {
+        case .updateCycleNotStarted: return "updateCycleNotStarted"
+        case .updateCycleDidStart: return "updateCycleDidStart"
+        case .updateCycleDone(let reason): return "updateCycleDone(\(reason.rawValue))"
+        case .downloadDidStart: return "downloadDidStart"
+        case .downloading(let percentage): return "downloading(\(percentage))"
+        case .extractionDidStart: return "extractionDidStart"
+        case .extracting(let percentage): return "extracting(\(percentage))"
+        case .readyToInstallAndRelaunch: return "readyToInstallAndRelaunch"
+        case .installationDidStart: return "installationDidStart"
+        case .installing: return "installing"
+        case .updaterError(let error): return "updaterError(\(error.localizedDescription))(\(error.pixelParameters))"
+        }
+    }
 }
 
 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)?
-    private var onSkipping: () -> Void = {}
+
+    // Dismiss the current update for the time being but keep the downloaded file around
+    private var onDismiss: () -> Void = {}
 
     var isResumable: Bool {
         onResuming != nil
@@ -99,6 +128,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
@@ -109,8 +140,13 @@ final class UpdateUserDriver: NSObject, SPUUserDriver {
         onResuming?()
     }
 
+    func configureResumeBlock(_ block: @escaping () -> Void) {
+        guard !isResumable else { return }
+        onResuming = block
+    }
+
     func cancelAndDismissCurrentUpdate() {
-        onSkipping()
+        onDismiss()
     }
 
     func show(_ request: SPUUpdatePermissionRequest) async -> SUUpdatePermissionResponse {
@@ -122,21 +158,27 @@ 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 shown 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)
         }
 
-        onSkipping = { reply(.skip) }
+        onDismiss = { reply(.dismiss) }
 
         if checkpoint == .download {
             onResuming = { reply(.install) }
-            updateProgress = .updateCycleDone
+            updateProgress = .updateCycleDone(.pausedAtDownloadCheckpoint)
+            Logger.updates.log("Updater paused at download checkpoint (manual update pending user decision)")
         } else {
+            Logger.updates.log("Updater proceeded to installation at download checkpoint")
             reply(.install)
         }
     }
@@ -154,11 +196,13 @@ final class UpdateUserDriver: NSObject, SPUUserDriver {
     }
 
     func showUpdaterError(_ error: any Error, acknowledgement: @escaping () -> Void) {
+        Logger.updates.error("Updater encountered an error: \(error.localizedDescription, privacy: .public) (\(error.pixelParameters, privacy: .public))")
         updateProgress = .updaterError(error)
         acknowledgement()
     }
 
     func showDownloadInitiated(cancellation: @escaping () -> Void) {
+        Logger.updates.log("Updater started downloading the update")
         updateProgress = .downloadDidStart
     }
 
@@ -176,6 +220,7 @@ final class UpdateUserDriver: NSObject, SPUUserDriver {
     }
 
     func showDownloadDidStartExtractingUpdate() {
+        Logger.updates.log("Updater started extracting the update")
         updateProgress = .extractionDidStart
     }
 
@@ -184,19 +229,27 @@ final class UpdateUserDriver: NSObject, SPUUserDriver {
     }
 
     func showReady(toInstallAndRelaunch reply: @escaping (SPUUserUpdateChoice) -> Void) {
-        onSkipping = { reply(.skip) }
+        onDismiss = { reply(.dismiss) }
 
         if checkpoint == .restart {
             onResuming = { reply(.install) }
+            updateProgress = .updateCycleDone(.pausedAtRestartCheckpoint)
+            Logger.updates.log("Updater paused at restart checkpoint (automatic update pending user decision)")
         } else {
             reply(.install)
+            updateProgress = .updateCycleDone(.proceededToInstallationAtRestartCheckpoint)
+            Logger.updates.log("Updater proceeded to installation at restart checkpoint")
         }
-
-        updateProgress = .updateCycleDone
     }
 
     func showInstallingUpdate(withApplicationTerminated applicationTerminated: Bool, retryTerminatingApplication: @escaping () -> Void) {
+        Logger.updates.info("Updater started the installation")
         updateProgress = .installationDidStart
+
+        if !applicationTerminated {
+            Logger.updates.log("Updater re-sent a quit event")
+            retryTerminatingApplication()
+        }
     }
 
     func showUpdateInstalledAndRelaunched(_ relaunched: Bool, acknowledgement: @escaping () -> Void) {
@@ -210,7 +263,7 @@ final class UpdateUserDriver: NSObject, SPUUserDriver {
 
     func dismissUpdateInstallation() {
         guard !updateProgress.isFailed else { return }
-        updateProgress = .updateCycleDone
+        updateProgress = .updateCycleDone(.dismissedWithNoError)
     }
 }