Browse Source

Fix Live Activity restart classification, foreground race, and add troubleshooting logs (#615)

* Fix Live Activity restart classification and foreground race

- handleExpiredToken, endOnTerminate, forceRestart: mark endingForRestart
  before ending so the state observer does not misclassify the resulting
  .dismissed as a user swipe (which would set dismissedByUser=true and
  block auto-restart on the next background refresh).
- Defer foreground restart from willEnterForeground to didBecomeActive
  so Activity.request() is not called before the scene is active
  (avoids the "visibility" failure).
- Remove duplicate orphan LiveActivitySettingsView.swift under Settings/
  (not referenced by the Xcode project).

* Add Live Activity troubleshooting logs

- startIfNeeded: log entry state (authorized, activities, current, flags)
  and enrich Activity.request failure with NSError domain/code + scene state.
- renewIfNeeded: enrich catch with NSError domain/code + authorization state.
- handleForeground / handleDidBecomeActive: include applicationState and
  the existing activities count at entry.
- observePushToken: log token fingerprint (last 8 chars) and prior value so
  token rotations are visible.
- update: log when the direct ActivityKit update is skipped (app backgrounded)
  and when APNs is skipped because no push token has been received yet.
- performRefresh: log the gate that blocks LA updates — especially
  dismissedByUser=true, which previously caused silent extended outages.
- handleExpiredToken: log current id, activities count, and flags before
  ending so APNs 410/404 events are correlatable to the restart path.
- bind: include activityState and the previous endingForRestart value so
  the dismissal-classification path is traceable.
Jonas Björkert 2 months ago
parent
commit
22dc3080b6

+ 93 - 17
LoopFollow/LiveActivity/LiveActivityManager.swift

@@ -87,12 +87,18 @@ final class LiveActivityManager {
 
     @objc private func handleDidBecomeActive() {
         guard Storage.shared.laEnabled.value else { return }
-        if skipNextDidBecomeActive {
-            LogManager.shared.log(category: .general, message: "[LA] didBecomeActive: skipped (handleForeground owns restart)", isDebug: true)
-            skipNextDidBecomeActive = false
+        let appState = UIApplication.shared.applicationState.rawValue
+        let existing = Activity<GlucoseLiveActivityAttributes>.activities.count
+        if pendingForegroundRestart {
+            pendingForegroundRestart = false
+            LogManager.shared.log(
+                category: .general,
+                message: "[LA] didBecomeActive: running deferred foreground restart (appState=\(appState), activities=\(existing))"
+            )
+            performForegroundRestart()
             return
         }
-        LogManager.shared.log(category: .general, message: "[LA] didBecomeActive: calling startFromCurrentState, dismissedByUser=\(dismissedByUser)", isDebug: true)
+        LogManager.shared.log(category: .general, message: "[LA] didBecomeActive: startFromCurrentState (appState=\(appState), activities=\(existing), current=\(current?.id ?? "nil"), dismissedByUser=\(dismissedByUser))", isDebug: true)
         Task { @MainActor in
             self.startFromCurrentState()
         }
@@ -105,10 +111,12 @@ final class LiveActivityManager {
         let renewBy = Storage.shared.laRenewBy.value
         let now = Date().timeIntervalSince1970
         let overlayIsShowing = renewBy > 0 && now >= renewBy - LiveActivityManager.renewalWarning
+        let appState = UIApplication.shared.applicationState.rawValue
+        let existing = Activity<GlucoseLiveActivityAttributes>.activities.count
 
         LogManager.shared.log(
             category: .general,
-            message: "[LA] foreground: renewalFailed=\(renewalFailed), overlayShowing=\(overlayIsShowing), current=\(current?.id ?? "nil"), dismissedByUser=\(dismissedByUser), renewBy=\(renewBy), now=\(now)"
+            message: "[LA] foreground: appState=\(appState), activities=\(existing), renewalFailed=\(renewalFailed), overlayShowing=\(overlayIsShowing), current=\(current?.id ?? "nil"), dismissedByUser=\(dismissedByUser), renewBy=\(renewBy), now=\(now)"
         )
 
         guard renewalFailed || overlayIsShowing else {
@@ -116,13 +124,17 @@ final class LiveActivityManager {
             return
         }
 
+        // willEnterForegroundNotification fires before the scene reaches
+        // foregroundActive — Activity.request() returns `visibility` during
+        // this window. Defer the actual restart to didBecomeActive.
+        pendingForegroundRestart = true
         LogManager.shared.log(
             category: .general,
-            message: "[LA] ending stale LA and restarting (renewalFailed=\(renewalFailed), overlayShowing=\(overlayIsShowing))"
+            message: "[LA] foreground: scheduling restart on next didBecomeActive (renewalFailed=\(renewalFailed), overlayShowing=\(overlayIsShowing))"
         )
+    }
 
-        skipNextDidBecomeActive = true
-
+    private func performForegroundRestart() {
         // Mark restart intent BEFORE clearing storage flags, so any late .dismissed
         // from the old activity is never misclassified as a user swipe.
         endingForRestart = true
@@ -249,14 +261,22 @@ final class LiveActivityManager {
     /// a .dismissed delivery triggered by our own end() call is never misclassified as a
     /// user swipe — regardless of the order in which the MainActor executes the two writes.
     private var endingForRestart = false
-    /// Set by handleForeground() when it takes ownership of the restart sequence.
-    /// Prevents handleDidBecomeActive() from racing with an in-flight end+restart.
-    private var skipNextDidBecomeActive = false
+    /// Set by handleForeground() when the renewal window has been detected.
+    /// The actual end+restart is run from handleDidBecomeActive() because
+    /// Activity.request() returns `visibility` during willEnterForeground.
+    private var pendingForegroundRestart = false
 
     // MARK: - Public API
 
     func startIfNeeded() {
-        guard ActivityAuthorizationInfo().areActivitiesEnabled else {
+        let authorized = ActivityAuthorizationInfo().areActivitiesEnabled
+        let existingCount = Activity<GlucoseLiveActivityAttributes>.activities.count
+        LogManager.shared.log(
+            category: .general,
+            message: "[LA] startIfNeeded: authorized=\(authorized), activities=\(existingCount), current=\(current?.id ?? "nil"), dismissedByUser=\(dismissedByUser), laEnabled=\(Storage.shared.laEnabled.value)",
+            isDebug: true
+        )
+        guard authorized else {
             LogManager.shared.log(category: .general, message: "Live Activity not authorized")
             return
         }
@@ -335,7 +355,12 @@ final class LiveActivityManager {
             Storage.shared.laRenewalFailed.value = false
             LogManager.shared.log(category: .general, message: "Live Activity started id=\(activity.id)")
         } catch {
-            LogManager.shared.log(category: .general, message: "Live Activity failed to start: \(error)")
+            let ns = error as NSError
+            let scene = isAppVisibleForLiveActivityStart()
+            LogManager.shared.log(
+                category: .general,
+                message: "Live Activity failed to start: \(error) domain=\(ns.domain) code=\(ns.code) — authorized=\(ActivityAuthorizationInfo().areActivitiesEnabled), sceneActive=\(scene), activities=\(Activity<GlucoseLiveActivityAttributes>.activities.count)"
+            )
         }
     }
 
@@ -344,6 +369,10 @@ final class LiveActivityManager {
     /// Does not clear laEnabled — the user's preference is preserved for relaunch.
     func endOnTerminate() {
         guard let activity = current else { return }
+        // Flag the end as system-initiated so the state observer does not
+        // classify the resulting `.dismissed` as a user swipe (laRenewBy is
+        // cleared below, which would otherwise make pastDeadline=false).
+        endingForRestart = true
         current = nil
         Storage.shared.laRenewBy.value = 0
         LALivenessStore.clear()
@@ -399,6 +428,10 @@ final class LiveActivityManager {
     func forceRestart() {
         guard Storage.shared.laEnabled.value else { return }
         LogManager.shared.log(category: .general, message: "[LA] forceRestart called")
+        // Mark as system-initiated so any residual `.dismissed` delivered from
+        // the cancelled state observer stream cannot flip dismissedByUser=true
+        // and spoil the freshly started LA.
+        endingForRestart = true
         dismissedByUser = false
         Storage.shared.laRenewBy.value = 0
         Storage.shared.laRenewalFailed.value = false
@@ -515,7 +548,11 @@ final class LiveActivityManager {
             // Renewal failed — deadline was never written, so no rollback needed.
             let isFirstFailure = !Storage.shared.laRenewalFailed.value
             Storage.shared.laRenewalFailed.value = true
-            LogManager.shared.log(category: .general, message: "[LA] renewal failed, keeping existing LA: \(error)")
+            let ns = error as NSError
+            LogManager.shared.log(
+                category: .general,
+                message: "[LA] renewal failed, keeping existing LA: \(error) domain=\(ns.domain) code=\(ns.code) — authorized=\(ActivityAuthorizationInfo().areActivitiesEnabled), activities=\(Activity<GlucoseLiveActivityAttributes>.activities.count)"
+            )
             if isFirstFailure {
                 scheduleRenewalFailedNotification()
             }
@@ -557,9 +594,17 @@ final class LiveActivityManager {
         // WatchConnectivityManager.shared.send(snapshot: snapshot)
 
         // LA update: gated on LA being active, snapshot having changed, and activities enabled.
-        guard Storage.shared.laEnabled.value, !dismissedByUser else { return }
+        if !Storage.shared.laEnabled.value {
+            LogManager.shared.log(category: .general, message: "[LA] refresh: LA update skipped — laEnabled=false reason=\(reason)", isDebug: true)
+            return
+        }
+        if dismissedByUser {
+            LogManager.shared.log(category: .general, message: "[LA] refresh: LA update skipped — dismissedByUser=true reason=\(reason)")
+            return
+        }
         guard !snapshotUnchanged || forceRefreshNeeded else { return }
         guard ActivityAuthorizationInfo().areActivitiesEnabled else {
+            LogManager.shared.log(category: .general, message: "[LA] refresh: LA update skipped — areActivitiesEnabled=false reason=\(reason)")
             return
         }
         if current == nil, let existing = Activity<GlucoseLiveActivityAttributes>.activities.first {
@@ -632,6 +677,12 @@ final class LiveActivityManager {
 
             if isForeground {
                 await activity.update(content)
+            } else {
+                LogManager.shared.log(
+                    category: .general,
+                    message: "[LA] update seq=\(nextSeq) — app backgrounded, direct ActivityKit update skipped, relying on APNs",
+                    isDebug: true
+                )
             }
 
             if Task.isCancelled { return }
@@ -646,6 +697,11 @@ final class LiveActivityManager {
 
             if let token = pushToken {
                 await APNSClient.shared.sendLiveActivityUpdate(pushToken: token, state: state)
+            } else {
+                LogManager.shared.log(
+                    category: .general,
+                    message: "[LA] update seq=\(nextSeq) reason=\(reason) — no push token yet, APNs skipped"
+                )
             }
         }
     }
@@ -668,25 +724,45 @@ final class LiveActivityManager {
     private func bind(to activity: Activity<GlucoseLiveActivityAttributes>, logReason: String) {
         if current?.id == activity.id { return }
         current = activity
+        let wasEndingForRestart = endingForRestart
         dismissedByUser = false
         endingForRestart = false
         attachStateObserver(to: activity)
-        LogManager.shared.log(category: .general, message: "Live Activity bound id=\(activity.id) (\(logReason))", isDebug: true)
+        LogManager.shared.log(
+            category: .general,
+            message: "Live Activity bound id=\(activity.id) state=\(activity.activityState) (\(logReason)) — endingForRestart cleared (was \(wasEndingForRestart))",
+            isDebug: true
+        )
         observePushToken(for: activity)
     }
 
     private func observePushToken(for activity: Activity<GlucoseLiveActivityAttributes>) {
         tokenObservationTask?.cancel()
+        let activityID = activity.id
         tokenObservationTask = Task {
             for await tokenData in activity.pushTokenUpdates {
                 let token = tokenData.map { String(format: "%02x", $0) }.joined()
+                let previousTail = self.pushToken.map { String($0.suffix(8)) } ?? "nil"
+                let tail = String(token.suffix(8))
                 self.pushToken = token
-                LogManager.shared.log(category: .general, message: "Live Activity push token received", isDebug: true)
+                LogManager.shared.log(
+                    category: .general,
+                    message: "[LA] push token received id=\(activityID) token=…\(tail) (prev=…\(previousTail))"
+                )
             }
         }
     }
 
     func handleExpiredToken() {
+        let existing = Activity<GlucoseLiveActivityAttributes>.activities.count
+        LogManager.shared.log(
+            category: .general,
+            message: "[LA] handleExpiredToken: current=\(current?.id ?? "nil"), activities=\(existing), dismissedByUser=\(dismissedByUser) — marking endingForRestart and ending"
+        )
+        // Mark as system-initiated so the `.dismissed` delivered by end()
+        // is not classified as a user swipe — that would set dismissedByUser=true
+        // and block the auto-restart promised by the comment below.
+        endingForRestart = true
         end()
         // Activity will restart on next BG refresh via refreshFromCurrentState()
     }

+ 0 - 42
LoopFollow/Settings/LiveActivitySettingsView.swift

@@ -1,42 +0,0 @@
-// LoopFollow
-// LiveActivitySettingsView.swift
-
-import SwiftUI
-
-struct LiveActivitySettingsView: View {
-    @State private var laEnabled: Bool = Storage.shared.laEnabled.value
-    @State private var restartConfirmed = false
-
-    var body: some View {
-        Form {
-            Section(header: Text("Live Activity")) {
-                Toggle("Enable Live Activity", isOn: $laEnabled)
-            }
-
-            if laEnabled {
-                Section {
-                    Button(restartConfirmed ? "Live Activity Restarted" : "Restart Live Activity") {
-                        LiveActivityManager.shared.forceRestart()
-                        restartConfirmed = true
-                        DispatchQueue.main.asyncAfter(deadline: .now() + 2) {
-                            restartConfirmed = false
-                        }
-                    }
-                    .disabled(restartConfirmed)
-                }
-            }
-        }
-        .onReceive(Storage.shared.laEnabled.$value) { newValue in
-            if newValue != laEnabled { laEnabled = newValue }
-        }
-        .onChange(of: laEnabled) { newValue in
-            Storage.shared.laEnabled.value = newValue
-            if !newValue {
-                LiveActivityManager.shared.end(dismissalPolicy: .immediate)
-            }
-        }
-        .preferredColorScheme(Storage.shared.appearanceMode.value.colorScheme)
-        .navigationTitle("Live Activity")
-        .navigationBarTitleDisplayMode(.inline)
-    }
-}