diff --git a/LoopFollow/Controllers/BackgroundAlertManager.swift b/LoopFollow/Controllers/BackgroundAlertManager.swift index 8b844c983..b4cd22680 100644 --- a/LoopFollow/Controllers/BackgroundAlertManager.swift +++ b/LoopFollow/Controllers/BackgroundAlertManager.swift @@ -64,14 +64,14 @@ class BackgroundAlertManager { func scheduleBackgroundAlert(force: Bool = false) { guard isAlertScheduled, Storage.shared.backgroundRefreshType.value != .none else { return } - // Throttle execution if not forced: only run once every 10 seconds. - if !force { - let now = Date() - if let lastDate = lastScheduleDate, now.timeIntervalSince(lastDate) < 10 { - return - } - lastScheduleDate = now + // Throttle execution if not forced: only run once every 10 seconds. A forced + // run stamps the date too, so the next tick doesn't immediately repeat the + // remove-and-re-add it just performed. + let now = Date() + if !force, let lastDate = lastScheduleDate, now.timeIntervalSince(lastDate) < 10 { + return } + lastScheduleDate = now removeDeliveredNotifications() diff --git a/LoopFollow/Helpers/BackgroundRefreshManager.swift b/LoopFollow/Helpers/BackgroundRefreshManager.swift index ab2b42e67..b1a6427b6 100644 --- a/LoopFollow/Helpers/BackgroundRefreshManager.swift +++ b/LoopFollow/Helpers/BackgroundRefreshManager.swift @@ -3,6 +3,7 @@ import BackgroundTasks import Foundation +import UIKit class BackgroundRefreshManager { static let shared = BackgroundRefreshManager() @@ -10,6 +11,18 @@ class BackgroundRefreshManager { private let taskIdentifier = "\(Bundle.main.bundleIdentifier ?? "com.loopfollow").audiorefresh" + /// Spacing for the routine health check. iOS treats this as a floor and + /// schedules on its own budget, so the effective interval is longer. + private let refreshInterval: TimeInterval = 15 * 60 + + /// Serialises the read-modify-write around the pending request, so a routine + /// request can't land on top of an immediate one. + private let queue = DispatchQueue(label: "com.LoopFollow.BackgroundRefreshQueue") + + /// True while the pending request asks for the earliest window iOS will give. + /// Guarded by `queue`. + private var immediateRequested = false + func register() { BGTaskScheduler.shared.register(forTaskWithIdentifier: taskIdentifier, using: nil) { task in guard let refreshTask = task as? BGAppRefreshTask else { return } @@ -20,47 +33,147 @@ class BackgroundRefreshManager { private func handleRefreshTask(_ task: BGAppRefreshTask) { LogManager.shared.log(category: .taskScheduler, message: "BGAppRefreshTask fired") - // Guard against double setTaskCompleted if expiration fires while the - // main-queue block is in-flight (Apple documents this as a programming error). + // Guard against double setTaskCompleted (Apple documents this as a programming + // error). The restart below keeps the task open for seconds, so expiration and + // the main-queue block genuinely race for the flag and it needs a lock. + let lock = NSLock() var completed = false + let claim: () -> Bool = { + lock.lock() + defer { lock.unlock() } + guard !completed else { return false } + completed = true + return true + } + let complete: (Bool) -> Void = { success in + guard claim() else { return } + task.setTaskCompleted(success: success) + } task.expirationHandler = { - guard !completed else { return } - completed = true LogManager.shared.log(category: .taskScheduler, message: "BGAppRefreshTask expired") - task.setTaskCompleted(success: false) - self.scheduleRefresh() + complete(false) + } + + // This task exists only to revive the Silent Tune keep-alive. Reading the mode + // is safe before storage is confirmed readable: the default is `.silentTune`, + // so an unhydrated read keeps the check armed rather than cancelling it. + guard !StorageReadiness.ready.value || Storage.shared.backgroundRefreshType.value == .silentTune else { + LogManager.shared.log(category: .taskScheduler, message: "Background refresh no longer needed for the current mode; cancelling") + BGTaskScheduler.shared.cancel(taskRequestWithIdentifier: taskIdentifier) + queue.async { self.immediateRequested = false } + complete(true) + return + } + + // Queue the successor before doing any work, so an early expiration or a + // crash still leaves a pending request behind. + queue.async { + self.immediateRequested = false + self.submit(earliestBeginDate: Date(timeIntervalSinceNow: self.refreshInterval)) } DispatchQueue.main.async { - guard !completed else { return } - completed = true - if let mainVC = self.getMainViewController() { - if !mainVC.backgroundTask.player.isPlaying { - LogManager.shared.log(category: .taskScheduler, message: "audio dead, attempting restart") - mainVC.backgroundTask.stopBackgroundTask() - mainVC.backgroundTask.startBackgroundTask() - LogManager.shared.log(category: .taskScheduler, message: "audio restart initiated") - } else { - LogManager.shared.log(category: .taskScheduler, message: "audio alive, no action needed", isDebug: true) + guard let backgroundTask = MainViewController.shared?.backgroundTask else { + LogManager.shared.log(category: .taskScheduler, message: "No main view controller yet; nothing to check") + complete(true) + return + } + guard !backgroundTask.isPlaying else { + // Full level: `.taskScheduler` debug lines are dropped before the file + // write, and a healthy check should leave a trace of its own. + LogManager.shared.log(category: .taskScheduler, message: "audio alive, no action needed") + self.armBackgroundAlerts() + TaskScheduler.shared.checkTasksNow() + complete(true) + return + } + + LogManager.shared.log(category: .taskScheduler, message: "audio dead, attempting restart") + // The task must stay open until the restart resolves: completing it here + // lets iOS suspend the app, and a pending retry would then not run until + // something else resumes the process — minutes or hours later. + backgroundTask.restartAudio(reason: "BGAppRefreshTask") { success in + LogManager.shared.log( + category: .taskScheduler, + message: success ? "audio restart succeeded" : "audio restart failed" + ) + // Only on success: a failed restart means suspension is imminent, and + // dispatching fetches that cannot finish helps nothing. + if success { + self.armBackgroundAlerts() + TaskScheduler.shared.checkTasksNow() } + complete(success) } - self.scheduleRefresh() - task.setTaskCompleted(success: true) } } + /// Clears any delivered "App inactive" notification and re-arms the 6/12/18 minute + /// alerts from this moment. A process launched into the background never ran + /// `appMovedToBackground`, so this is the only place its alerts are armed. + private func armBackgroundAlerts() { + // The task fires while backgrounded, but its work lands on the main queue and + // the user may have opened the app in between. Alerts belong only to a + // backgrounded app. + guard UIApplication.shared.applicationState == .background else { return } + BackgroundAlertManager.shared.startBackgroundAlert() + } + + /// Requests the routine health check, leaving an existing pending request alone + /// when it would run at least as soon. Every background transition calls this, so + /// the earliest pending request is the one that survives. func scheduleRefresh() { + let desired = Date(timeIntervalSinceNow: refreshInterval) + BGTaskScheduler.shared.getPendingTaskRequests { [weak self] pending in + guard let self else { return } + self.queue.async { + // Category `.general`: LogManager drops `.taskScheduler` debug lines + // before the file write, and these belong in a shared log. + guard !self.immediateRequested else { + LogManager.shared.log(category: .general, message: "Keeping the pending immediate refresh request", isDebug: true) + return + } + if let existing = pending.first(where: { $0.identifier == self.taskIdentifier }) { + guard let existingDate = existing.earliestBeginDate else { return } + guard existingDate > desired else { + LogManager.shared.log(category: .general, message: "Refresh already pending at \(existingDate); leaving it", isDebug: true) + return + } + } + self.submit(earliestBeginDate: desired) + } + } + } + + /// Requests the earliest window iOS is willing to give, used when the audio + /// keep-alive has been lost and a background refresh is the only route back to + /// running code. + func scheduleImmediateRefresh() { + queue.async { + // The flag tracks what is actually pending. A submit that throws — as it + // does when Background App Refresh is switched off — must not leave the + // routine check suppressed behind a request that was never accepted. + self.immediateRequested = self.submit(earliestBeginDate: nil) + LogManager.shared.log( + category: .taskScheduler, + message: self.immediateRequested + ? "Requested the earliest possible background refresh" + : "Could not request a background refresh; no recovery window is pending" + ) + } + } + + @discardableResult + private func submit(earliestBeginDate: Date?) -> Bool { let request = BGAppRefreshTaskRequest(identifier: taskIdentifier) - request.earliestBeginDate = Date(timeIntervalSinceNow: 15 * 60) + request.earliestBeginDate = earliestBeginDate do { try BGTaskScheduler.shared.submit(request) + return true } catch { LogManager.shared.log(category: .taskScheduler, message: "Failed to schedule BGAppRefreshTask: \(error)") + return false } } - - private func getMainViewController() -> MainViewController? { - MainViewController.shared - } } diff --git a/LoopFollow/Helpers/BackgroundTaskAudio.swift b/LoopFollow/Helpers/BackgroundTaskAudio.swift index 25aa6b3c8..cfbe5c0e1 100755 --- a/LoopFollow/Helpers/BackgroundTaskAudio.swift +++ b/LoopFollow/Helpers/BackgroundTaskAudio.swift @@ -2,30 +2,175 @@ // BackgroundTaskAudio.swift import AVFoundation +import UIKit +/// Keeps the app running in the background by looping a silent audio file. +/// +/// The audio session is the only background-execution claim Silent Tune has, so +/// losing it means the process is suspended within seconds and no app code — +/// including any retry timer — runs again until iOS resumes the app. Every +/// reactivation attempt therefore runs inside a `UIApplication` background-task +/// assertion, which grants runtime independently of the audio claim, and the +/// attempts are bounded to stay inside that assertion's budget. class BackgroundTask { // MARK: - Vars var player = AVAudioPlayer() - private var retryCount = 0 - private let maxRetries = 3 + /// True while the silent loop actually holds the background-audio claim. + var isPlaying: Bool { player.isPlaying } + + /// Attempts spread over `retryInterval`, sized to fit a background-task + /// assertion (~30s) and a `BGAppRefreshTask` window with room to spare. + private let maxAttempts = 10 + private let retryInterval: TimeInterval = 2.0 + + /// Delay before the first attempt after an interruption ends, letting the + /// interrupting app (e.g. Clock alarm) fully release the audio session. + /// Without it `setActive(true)` races with the alarm and fails with + /// `AVAudioSession.ErrorCode.cannotInterruptOthers` (560557684). + private let postInterruptionDelay: TimeInterval = 0.5 + + /// Window after an interruption begins in which a matching `.ended` supersedes + /// the recovery. Longer than `postInterruptionDelay` so a blip's own restart + /// lands first; short enough that a real claim loss is addressed promptly. + private let interruptionSettleDelay: TimeInterval = 1.0 + + private var recoveryWorkItem: DispatchWorkItem? + private var assertionID: UIBackgroundTaskIdentifier = .invalid + + /// Callers waiting on the outcome. A caller holding a `BGAppRefreshTask` open + /// must always hear back so it can complete the task, so a sequence that + /// supersedes another inherits its waiters. + private var pendingCompletions: [(Bool) -> Void] = [] + + /// Per-sequence diagnostics: how long recovery has been running, how many + /// attempts it took, and the last session error. A first-attempt success stays + /// quiet; anything slower reports what it cost. + private var sequenceStart: Date? + private var attemptsMade = 0 + private var lastFailureCode: Int? + + /// Set when a sequence runs out of attempts, so the eventual recovery is reported + /// at full level however it arrives. + private var lastSequenceGaveUp = false + + /// True while the active sequence was started by an interruption beginning. + /// Exhausting the attempts there is expected for any interrupter that outlasts + /// the assertion (a phone call), and iOS still commonly heals it by delivering + /// `.ended`, so that case must not be announced as a failed keep-alive. + private var startedByInterruption = false // MARK: - Methods func startBackgroundTask() { - NotificationCenter.default.removeObserver(self, name: AVAudioSession.interruptionNotification, object: nil) + attachObservers() + onMain { self.recover(after: 0, reason: "start") } + } + + /// Idempotent. A process launched into the background by `BGAppRefreshTask` never + /// sees a backgrounding transition, so the keep-alive attaches these wherever it + /// starts. + private func attachObservers() { + removeObservers() NotificationCenter.default.addObserver(self, selector: #selector(interruptedAudio), name: AVAudioSession.interruptionNotification, object: AVAudioSession.sharedInstance()) - retryCount = 0 - playAudio() + // A route disappearing pauses the player without any interruption notification, + // and a media services reset invalidates the session and player outright — + // neither is observable through `interruptionNotification`. + NotificationCenter.default.addObserver(self, selector: #selector(audioRouteChanged), name: AVAudioSession.routeChangeNotification, object: nil) + NotificationCenter.default.addObserver(self, selector: #selector(mediaServicesWereReset), name: AVAudioSession.mediaServicesWereResetNotification, object: nil) } func stopBackgroundTask() { + removeObservers() + onMain { + self.cancelRecovery() + self.player.stop() + // Reached only from the foreground transition: with the app open, the + // next backgrounding is a clean start. + self.lastSequenceGaveUp = false + LogManager.shared.log(category: .general, message: "Silent audio stopped", isDebug: true) + } + } + + /// Reactivates the silent loop, retrying until it plays or the attempt budget + /// is spent, and reports the outcome. Runtime is held by a background-task + /// assertion for the whole sequence, so the retries survive the loss of the + /// audio claim that made them necessary. + /// - Parameter completion: Called on the main queue with the final state. + func restartAudio(reason: String, completion: ((Bool) -> Void)? = nil) { + attachObservers() + onMain { + self.player.stop() + self.recover(after: 0, reason: reason, completion: completion) + } + } + + private func removeObservers() { NotificationCenter.default.removeObserver(self, name: AVAudioSession.interruptionNotification, object: nil) - player.stop() - LogManager.shared.log(category: .general, message: "Silent audio stopped", isDebug: true) + NotificationCenter.default.removeObserver(self, name: AVAudioSession.routeChangeNotification, object: nil) + NotificationCenter.default.removeObserver(self, name: AVAudioSession.mediaServicesWereResetNotification, object: nil) + } + + // MARK: - Route and media services handling + + @objc private func audioRouteChanged(_ notification: Notification) { + guard let userInfo = notification.userInfo, + let reasonValue = userInfo[AVAudioSessionRouteChangeReasonKey] as? UInt, + let reason = AVAudioSession.RouteChangeReason(rawValue: reasonValue) + else { return } + + let previous = userInfo[AVAudioSessionRouteChangePreviousRouteKey] as? AVAudioSessionRouteDescription + let route = "reason=\(describe(reason)) from=\(portTypes(previous)) to=\(portTypes(AVAudioSession.sharedInstance().currentRoute))" + + switch reason { + case .oldDeviceUnavailable, .newDeviceAvailable: + LogManager.shared.log(category: .general, message: "[LA] Audio route changed, restarting silent audio: \(route)") + // CarPlay and Bluetooth transitions emit a burst of route changes; each + // supersedes the last, so the ladder runs once against the settled route. + onMain { self.recover(after: self.interruptionSettleDelay, reason: "route change") } + + case .categoryChange: + // `playAudio` sets the category itself, and an alarm takes over the + // session the same way. Both make this reason unsafe to act on. + LogManager.shared.log(category: .general, message: "[LA] Audio route changed, ignoring: \(route)", isDebug: true) + + default: + // Recorded for diagnosis without acting. + LogManager.shared.log(category: .general, message: "[LA] Audio route changed, no action: \(route)") + } } + @objc private func mediaServicesWereReset(_: Notification) { + LogManager.shared.log(category: .general, message: "[LA] Media services were reset — session and player are invalid, rebuilding") + // `playAudio` reconfigures the category, reactivates, and creates a fresh + // player, which is the recovery Apple prescribes for a reset. + onMain { self.recover(after: self.interruptionSettleDelay, reason: "media services reset") } + } + + /// Port types only — `portName` carries the user's accessory name, which must not + /// reach a shared log. + private func portTypes(_ route: AVAudioSessionRouteDescription?) -> String { + guard let route, !route.outputs.isEmpty else { return "none" } + return route.outputs.map { $0.portType.rawValue }.joined(separator: "+") + } + + private func describe(_ reason: AVAudioSession.RouteChangeReason) -> String { + switch reason { + case .newDeviceAvailable: "newDeviceAvailable" + case .oldDeviceUnavailable: "oldDeviceUnavailable" + case .categoryChange: "categoryChange" + case .override: "override" + case .wakeFromSleep: "wakeFromSleep" + case .noSuitableRouteForCategory: "noSuitableRouteForCategory" + case .routeConfigurationChange: "routeConfigurationChange" + case .unknown: "unknown" + @unknown default: "other" + } + } + + // MARK: - Interruption handling + @objc private func interruptedAudio(_ notification: Notification) { guard notification.name == AVAudioSession.interruptionNotification, let userInfo = notification.userInfo, @@ -35,7 +180,19 @@ class BackgroundTask { switch type { case .began: - LogManager.shared.log(category: .general, message: "[LA] Silent audio session interrupted (began)") + let reason = (userInfo[AVAudioSessionInterruptionReasonKey] as? UInt) + .flatMap { AVAudioSession.InterruptionReason(rawValue: $0) } + LogManager.shared.log( + category: .general, + message: "[LA] Silent audio session interrupted (began), reason=\(describe(reason)), otherAudioPlaying=\(AVAudioSession.sharedInstance().isOtherAudioPlaying)" + ) + // iOS delivers `.ended` only if the app is still running, and the lost + // audio claim means suspension is imminent, so recovery cannot wait for + // it. The delay is a supersede window: a brief interrupter's `.ended` + // arrives well inside it and cancels this work, so momentary blips stay + // quiet. Work that does run is therefore a reliable signal that the + // claim is really gone, whatever `player.isPlaying` reports. + onMain { self.recover(after: self.interruptionSettleDelay, reason: "interruption began", startedByInterruption: true) } case .ended: if let optionsValue = userInfo[AVAudioSessionInterruptionOptionKey] as? UInt { @@ -44,47 +201,223 @@ class BackgroundTask { LogManager.shared.log(category: .general, message: "[LA] Silent audio interruption ended — shouldResume not set, attempting restart anyway") } } - LogManager.shared.log(category: .general, message: "[LA] Silent audio interruption ended — scheduling restart in 0.5s") - retryCount = 0 - // Brief delay to let the interrupting app (e.g. Clock alarm) fully release the audio - // session before we attempt to reactivate. Without this, setActive(true) races with - // the alarm and fails with AVAudioSession.ErrorCode.cannotInterruptOthers (560557684). - DispatchQueue.main.asyncAfter(deadline: .now() + 0.5) { [weak self] in - self?.playAudio() - } + LogManager.shared.log(category: .general, message: "[LA] Silent audio interruption ended — scheduling restart in \(postInterruptionDelay)s") + onMain { self.recover(after: self.postInterruptionDelay, reason: "interruption ended") } @unknown default: break } } - private func playAudio() { - let attemptDesc = retryCount == 0 ? "initial attempt" : "retry \(retryCount)/\(maxRetries)" + private func describe(_ reason: AVAudioSession.InterruptionReason?) -> String { + switch reason { + case .default: "default" + case .builtInMicMuted: "builtInMicMuted" + case .none: "unknown" + @unknown default: "other" + } + } + + // MARK: - Recovery + + /// Runs one bounded recovery sequence, superseding any sequence already in flight. + private func recover(after delay: TimeInterval, reason: String, startedByInterruption: Bool = false, completion: ((Bool) -> Void)? = nil) { + // Waiters from the in-flight sequence inherit this sequence's outcome. + recoveryWorkItem?.cancel() + recoveryWorkItem = nil + if let completion { + pendingCompletions.append(completion) + } + self.startedByInterruption = startedByInterruption + if sequenceStart == nil { + sequenceStart = Date() + attemptsMade = 0 + lastFailureCode = nil + } + + // `player.isPlaying` reports true for a while after the session is taken, so + // recovery runs unconditionally. Reattempting against a playing player is + // harmless: `playAudio` activates the session before touching `player`, leaving + // a working one untouched when an attempt fails. + // + // The assertion is taken before the delay so the first attempt is covered too. + beginAssertion() + + guard delay > 0 else { + attempt(1, of: reason) + return + } + + let work = DispatchWorkItem { [weak self] in + guard let self else { return } + self.recoveryWorkItem = nil + self.attempt(1, of: reason) + } + recoveryWorkItem = work + DispatchQueue.main.asyncAfter(deadline: .now() + delay, execute: work) + } + + private func attempt(_ number: Int, of reason: String) { + attemptsMade = number + if startedByInterruption, number == 1 { + // Reached only when the settle window elapsed without an `.ended`, so the + // interrupter holds the session and the app may be suspended before the + // ladder finishes. + BackgroundRefreshManager.shared.scheduleImmediateRefresh() + } + if playAudio(attempt: number, reason: reason) { + finishRecovery(success: true) + return + } + + guard number < maxAttempts else { + LogManager.shared.log( + category: .general, + message: "Silent audio recovery gave up after \(number) attempts over \(elapsedDescription()) (\(reason)), last error: \(Self.describeSessionError(lastFailureCode ?? 0))" + ) + lastSequenceGaveUp = true + if !startedByInterruption { + NotificationCenter.default.post(name: .backgroundAudioFailed, object: nil) + } + // The attempts are spent and there is no audio claim left, so a background + // refresh is the only remaining route back to running code. + BackgroundRefreshManager.shared.scheduleImmediateRefresh() + finishRecovery(success: false) + return + } + + let work = DispatchWorkItem { [weak self] in + guard let self else { return } + self.recoveryWorkItem = nil + self.attempt(number + 1, of: reason) + } + recoveryWorkItem = work + DispatchQueue.main.asyncAfter(deadline: .now() + retryInterval, execute: work) + } + + /// - Returns: True when the silent loop is confirmed playing. + private func playAudio(attempt: Int, reason: String) -> Bool { do { - let bundle = Bundle.main.path(forResource: "blank", ofType: "wav") - let alertSound = URL(fileURLWithPath: bundle!) + guard let path = Bundle.main.path(forResource: "blank", ofType: "wav") else { + LogManager.shared.log(category: .general, message: "playAudio failed: blank.wav missing from bundle") + return false + } try AVAudioSession.sharedInstance().setCategory(.playback, mode: .default, options: .mixWithOthers) try AVAudioSession.sharedInstance().setActive(true) - try player = AVAudioPlayer(contentsOf: alertSound) + player = try AVAudioPlayer(contentsOf: URL(fileURLWithPath: path)) // Play audio forever by setting num of loops to -1 player.numberOfLoops = -1 player.volume = 0.01 player.prepareToPlay() player.play() - retryCount = 0 - LogManager.shared.log(category: .general, message: "Silent audio playing (\(attemptDesc))", isDebug: true) - } catch { - LogManager.shared.log(category: .general, message: "playAudio failed (\(attemptDesc)), error: \(error)") - if retryCount < maxRetries { - retryCount += 1 - LogManager.shared.log(category: .general, message: "playAudio scheduling retry \(retryCount)/\(maxRetries) in 2s") - DispatchQueue.main.asyncAfter(deadline: .now() + 2.0) { [weak self] in - self?.playAudio() - } + guard player.isPlaying else { + LogManager.shared.log(category: .general, message: "playAudio: play() did not start the player (attempt \(attempt)/\(maxAttempts), \(reason))") + return false + } + if attempt > 1 || lastFailureCode != nil || lastSequenceGaveUp { + // A recovery following a logged failure reports itself, so the log + // always says whether the failure resolved. `lastFailureCode` survives + // a supersede, so the elapsed figure spans the whole window. + LogManager.shared.log(category: .general, message: "Silent audio playing again after \(attempt) attempt(s) over \(elapsedDescription()) (\(reason))") } else { - LogManager.shared.log(category: .general, message: "playAudio failed after \(maxRetries) retries — posting BackgroundAudioFailed") - NotificationCenter.default.post(name: .backgroundAudioFailed, object: nil) + LogManager.shared.log(category: .general, message: "Silent audio playing (\(reason))", isDebug: true) } + lastSequenceGaveUp = false + return true + } catch { + let code = (error as NSError).code + // Every attempt against the same holder reports the same code; log the + // first and any change, so a 10-attempt ladder can't bury the log. + let isNewFailure = code != lastFailureCode + lastFailureCode = code + LogManager.shared.log( + category: .general, + message: "playAudio failed (attempt \(attempt)/\(maxAttempts), \(reason)), code \(code) \(Self.describeSessionError(code)): \(error.localizedDescription)", + isDebug: !isNewFailure + ) + return false + } + } + + private func elapsedDescription() -> String { + guard let start = sequenceStart else { return "unknown" } + return String(format: "%.1fs", Date().timeIntervalSince(start)) + } + + private func finishRecovery(success: Bool) { + recoveryWorkItem = nil + let completions = pendingCompletions + pendingCompletions = [] + startedByInterruption = false + sequenceStart = nil + attemptsMade = 0 + lastFailureCode = nil + endAssertion() + for completion in completions { + completion(success) + } + } + + private func cancelRecovery() { + recoveryWorkItem?.cancel() + finishRecovery(success: player.isPlaying) + } + + // MARK: - Runtime assertion + + /// Holds runtime while the audio claim is gone, so queued retries actually run. + private func beginAssertion() { + guard assertionID == .invalid else { return } + // UIKit invokes the expiration handler on the main thread, which is the only + // queue that touches the recovery state. + assertionID = UIApplication.shared.beginBackgroundTask(withName: "SilentAudioRecovery") { [weak self] in + guard let self else { return } + LogManager.shared.log( + category: .general, + message: "Silent audio recovery assertion expired after \(self.attemptsMade) attempts over \(self.elapsedDescription()); the app is about to be suspended without an audio claim" + ) + self.lastSequenceGaveUp = true + // A success ends the assertion, so reaching expiration means the claim was + // never re-established — arm the net without consulting `player.isPlaying`. + BackgroundRefreshManager.shared.scheduleImmediateRefresh() + self.cancelRecovery() + } + } + + private func endAssertion() { + guard assertionID != .invalid else { return } + UIApplication.shared.endBackgroundTask(assertionID) + assertionID = .invalid + } + + // MARK: - Helpers + + private func onMain(_ work: @escaping () -> Void) { + if Thread.isMainThread { + work() + } else { + DispatchQueue.main.async(execute: work) + } + } + + /// `AVAudioSession.ErrorCode` values are four-character codes; the raw number + /// alone is unreadable in a shared log. + static func describeSessionError(_ code: Int) -> String { + switch AVAudioSession.ErrorCode(rawValue: code) { + case .cannotInterruptOthers: "cannotInterruptOthers" + case .siriIsRecording: "siriIsRecording" + case .cannotStartPlaying: "cannotStartPlaying" + case .cannotStartRecording: "cannotStartRecording" + case .insufficientPriority: "insufficientPriority" + case .resourceNotAvailable: "resourceNotAvailable" + case .mediaServicesFailed: "mediaServicesFailed" + case .isBusy: "isBusy" + case .incompatibleCategory: "incompatibleCategory" + case .expiredSession: "expiredSession" + case .sessionNotActive: "sessionNotActive" + case .badParam: "badParam" + case .none: "unspecified" + default: "other" } } } diff --git a/LoopFollow/Task/TaskScheduler.swift b/LoopFollow/Task/TaskScheduler.swift index b76ac3022..95a2d49ff 100644 --- a/LoopFollow/Task/TaskScheduler.swift +++ b/LoopFollow/Task/TaskScheduler.swift @@ -28,6 +28,24 @@ class TaskScheduler { private var tasks: [TaskID: ScheduledTask] = [:] private var currentTimer: DispatchSourceTimer? + /// When tasks last fired. `minAgoUpdate` reschedules itself at most 60s out, so + /// with runtime this advances at least once a minute; a larger jump means the + /// process was suspended and is the window the background alerts fire in. + private var lastFireDate: Date? + + /// Counterpart to `lastFireDate` that includes time asleep and cannot be moved by + /// a clock correction. The difference between the two measures a clock step. + private var lastFireUptime: UInt64? + + /// Above normal tick jitter, below the 6-minute first background alert. + private let runtimeGapThreshold: TimeInterval = 120 + + /// Queue-confined park tracking. A normal park clears within milliseconds, so a + /// survivor at this age is wedged or was suspended mid-park. + private var parkedSince: Date? + private var parkedReporter: DispatchWorkItem? + private let parkedReportDelay: TimeInterval = 5 + private init() {} // MARK: - Public API @@ -72,6 +90,12 @@ class TaskScheduler { return } + if earliestTask.nextRun == .distantFuture { + noteTimerParked() + } else { + clearTimerParked() + } + let interval = earliestTask.nextRun.timeIntervalSinceNow let safeInterval = max(interval, 0) @@ -90,6 +114,7 @@ class TaskScheduler { BackgroundAlertManager.shared.scheduleBackgroundAlert() let now = Date() + noteRuntimeGap(at: now) for taskID in TaskID.allCases { guard let task = tasks[taskID], task.nextRun <= now else { @@ -108,6 +133,61 @@ class TaskScheduler { } } + /// `fireOverdueTasks` parks a task at `.distantFuture` and its action reschedules + /// it asynchronously, so every task being parked at once is normal for the + /// milliseconds in between. A park outliving that leaves nothing to wake the timer, + /// so it is reported by duration and the routine case stays silent. + private func noteTimerParked() { + guard parkedSince == nil else { return } + let since = Date() + parkedSince = since + let work = DispatchWorkItem { [weak self] in + guard let self, self.parkedSince == since else { return } + LogManager.shared.log( + category: .taskScheduler, + message: "Timer still parked after \(Int(Date().timeIntervalSince(since)))s: every task is awaiting its action to reschedule it" + ) + } + parkedReporter = work + queue.asyncAfter(deadline: .now() + parkedReportDelay, execute: work) + } + + private func clearTimerParked() { + parkedReporter?.cancel() + parkedReporter = nil + parkedSince = nil + } + + /// Records one line per lost-runtime window, giving the length of a background + /// stall directly. + private func noteRuntimeGap(at now: Date) { + // CLOCK_MONOTONIC keeps counting while the device sleeps, so it measures a + // suspension. + let uptime = clock_gettime_nsec_np(CLOCK_MONOTONIC) + defer { + lastFireDate = now + lastFireUptime = uptime + } + guard let last = lastFireDate, let lastUptime = lastFireUptime else { return } + // Boot time is authoritative: a wall-clock correction must not hide a stall. + let gap = Double(uptime &- lastUptime) / 1_000_000_000 + let wallGap = now.timeIntervalSince(last) + guard gap >= runtimeGapThreshold else { return } + // Silent Tune is the only mode whose invariant is continuous runtime, which is + // what this measures. `.none` is meant to be suspended and the Bluetooth modes + // tick at heartbeat cadence, so for both a gap is normal. + guard Storage.shared.backgroundRefreshType.value == .silentTune else { return } + let alerts = BackgroundAlertDuration.allCases + .filter { gap >= $0.rawValue } + .map { "\(Int($0.rawValue / 60))" } + let fired = alerts.isEmpty ? "none" : alerts.joined(separator: "/") + " min" + var message = "Regained runtime after \(Int(gap))s with no scheduler tick; background alerts fired: \(fired)" + if abs(wallGap - gap) >= 5 { + message += "; wall clock moved \(Int(wallGap - gap))s relative to boot time" + } + LogManager.shared.log(category: .taskScheduler, message: message) + } + private func formatTime(_ date: Date) -> String { let formatter = DateFormatter() formatter.dateStyle = .none diff --git a/LoopFollow/ViewControllers/MainViewController.swift b/LoopFollow/ViewControllers/MainViewController.swift index ed1ce880f..9c96252d5 100644 --- a/LoopFollow/ViewControllers/MainViewController.swift +++ b/LoopFollow/ViewControllers/MainViewController.swift @@ -579,6 +579,11 @@ class MainViewController: UIViewController, UNUserNotificationCenterDelegate { } @objc func appMovedToBackground() { + LogManager.shared.log( + category: .general, + message: "App moved to background (refreshType=\(Storage.shared.backgroundRefreshType.value.rawValue), lowPowerMode=\(ProcessInfo.processInfo.isLowPowerModeEnabled), backgroundRefreshStatus=\(Self.describe(UIApplication.shared.backgroundRefreshStatus)))" + ) + // Allow screen to turn off UIApplication.shared.isIdleTimerDisabled = false @@ -688,7 +693,18 @@ class MainViewController: UIViewController, UNUserNotificationCenterDelegate { scheduleAllTasks() } + private static func describe(_ status: UIBackgroundRefreshStatus) -> String { + switch status { + case .available: "available" + case .denied: "denied" + case .restricted: "restricted" + @unknown default: "unknown" + } + } + @objc func appCameToForeground() { + LogManager.shared.log(category: .general, message: "App came to foreground") + // BFU recovery (StorageReadiness.recover) is driven by AppDelegate before this // controller exists (the readiness gate), so handleBFUReloadCompleted() above // is a vestigial no-op in the gated flow.