yattee/Yattee/Services/Logging/BackgroundDiagnostics.swift

//
//  BackgroundDiagnostics.swift
//  Yattee
//
//  Heartbeat and event logging to diagnose battery drain and heat while the
//  app is in the background.
//

import Foundation

/// Render activity counters, reset each time they are read.
final class RenderDiagnosticsCounters: @unchecked Sendable {
    struct Counts {
        var linkFires = 0
        var renders = 0
        var presents = 0
        var backgroundRenders = 0
        var skippedInBackground = 0
    }

    private let lock = NSLock()
    private var counts = Counts()

    func increment(_ key: WritableKeyPath<Counts, Int>) {
        lock.withLock { counts[keyPath: key] += 1 }
    }

    func take() -> Counts {
        lock.withLock {
            defer { counts = Counts() }
            return counts
        }
    }
}

#if os(iOS)
import AVFoundation
import UIKit

/// Logs a process/app/player snapshot every 10 seconds while the app is not
/// active (every 30 seconds while active), plus lifecycle, audio and power
/// events, under the Diagnostics category.
///
/// Only does work while "Enable Logging" is on. Logs are persisted to disk by
/// `LogFileStore`, so they survive the app being swiped away.
///
/// The heartbeat timer runs on its own queue, independent of the main thread:
/// a "heartbeat gap" means the whole process was suspended, while a heartbeat
/// without its app snapshot means the main thread was blocked.
@MainActor
final class BackgroundDiagnostics {
    static let shared = BackgroundDiagnostics()

    private weak var playerService: PlayerService?
    private var observers: [NSObjectProtocol] = []
    private var runLoopObserver: CFRunLoopObserver?
    private var runLoopWakeups = 0
    private var started = false
    private let sampler = ProcessSampler()

    private init() {}

    func start(playerService: PlayerService) {
        guard !started else { return }
        started = true
        self.playerService = playerService

        UIDevice.current.isBatteryMonitoringEnabled = true
        sampler.setMainThreadPort(pthread_mach_thread_np(pthread_self()))
        installRunLoopObserver()
        observeEvents()
        sampler.start()
        log(.info, "Diagnostics started", details: appSnapshot())
    }

    // MARK: - Snapshot

    /// App, device, player, audio and render state. Must run on the main thread.
    func appSnapshot() -> String {
        let app = UIApplication.shared
        var lines: [String] = []

        var appLine = "app: state=\(describe(app.applicationState))"
        if app.applicationState == .background {
            let remaining = app.backgroundTimeRemaining
            appLine += " bgTimeRemaining=" + (remaining > 1e6 ? "unlimited" : "\(Int(remaining))s")
        }
        appLine += " protectedData=\(app.isProtectedDataAvailable ? "available" : "locked")"
        appLine += " scenes=[\(app.connectedScenes.map { describe($0.activationState) }.joined(separator: ","))]"
        appLine += " idleTimerDisabled=\(app.isIdleTimerDisabled)"
        lines.append(appLine)

        let device = UIDevice.current
        let battery = device.batteryLevel < 0 ? "?" : "\(Int(device.batteryLevel * 100))%"
        lines.append("device: thermal=\(describe(ProcessInfo.processInfo.thermalState)) battery=\(battery)"
            + " batteryState=\(describe(device.batteryState)) lowPower=\(ProcessInfo.processInfo.isLowPowerModeEnabled)")

        lines.append("mainRunLoop: wakeups=\(runLoopWakeups) since last sample")
        runLoopWakeups = 0

        if let playerService {
            let state = playerService.state
            lines.append("player: state=\(describe(state.playbackState)) pip=\(state.pipState)"
                + " backend=\(playerService.currentBackendType) video=\(state.currentVideo?.id.videoID ?? "none")"
                + " time=\(Int(state.currentTime))/\(Int(state.duration))"
                + " publishesTime=\(state.publishesTimeUpdates)")
            if let mpvBackend = playerService.currentBackend as? MPVBackend {
                lines.append("decoder: " + mpvBackend.decoderDiagnosticsSummary)
            }
        }

        let session = AVAudioSession.sharedInstance()
        let outputs = session.currentRoute.outputs.map { "\($0.portType.rawValue)(\($0.portName))" }
        lines.append("audio: category=\(session.category.rawValue) mode=\(session.mode.rawValue)"
            + " otherAudioPlaying=\(session.isOtherAudioPlaying)"
            + " silenceSecondaryHint=\(session.secondaryAudioShouldBeSilencedHint)"
            + " route=[\(outputs.joined(separator: ","))]")

        let renderViews = MPVRenderView.diagnosticsInstances
        if renderViews.isEmpty {
            lines.append("render: no MPV render views")
        } else {
            lines.append(contentsOf: renderViews.map { "render: " + $0.diagnosticsSummary() })
        }

        return lines.joined(separator: "\n")
    }

    /// Called by the sampler with the process-level part of a heartbeat.
    nonisolated fileprivate func deliverHeartbeat(process: String, highCPU: Bool, enqueuedAt: DispatchTime) {
        let latencyMs = (DispatchTime.now().uptimeNanoseconds - enqueuedAt.uptimeNanoseconds) / 1_000_000
        MainActor.assumeIsolated {
            let state = describe(UIApplication.shared.applicationState)
            // Background playback legitimately costs CPU; flag only when nothing is playing.
            let isPlaying = playerService?.state.playbackState == .playing
            log(highCPU && !isPlaying ? .warning : .info, "Heartbeat [\(state)]",
                details: process + "\nmainThread: latency=\(latencyMs)ms\n" + appSnapshot())
        }
    }

    // MARK: - Events

    private func installRunLoopObserver() {
        let observer = CFRunLoopObserverCreateWithHandler(nil, CFRunLoopActivity.afterWaiting.rawValue, true, 0) { _, _ in
            MainActor.assumeIsolated {
                BackgroundDiagnostics.shared.runLoopWakeups += 1
            }
        }
        CFRunLoopAddObserver(CFRunLoopGetMain(), observer, .commonModes)
        runLoopObserver = observer
    }

    private func observeEvents() {
        let center = NotificationCenter.default

        let lifecycle: [(Notification.Name, String)] = [
            (UIApplication.willResignActiveNotification, "App will resign active"),
            (UIApplication.didEnterBackgroundNotification, "App did enter background"),
            (UIApplication.willEnterForegroundNotification, "App will enter foreground"),
            (UIApplication.didBecomeActiveNotification, "App did become active"),
            (UIApplication.willTerminateNotification, "App will terminate"),
            (UIApplication.didReceiveMemoryWarningNotification, "Memory warning"),
            (UIApplication.protectedDataWillBecomeUnavailableNotification, "Device locking (protected data unavailable)"),
            (UIApplication.protectedDataDidBecomeAvailableNotification, "Device unlocked (protected data available)"),
            (ProcessInfo.thermalStateDidChangeNotification, "Thermal state changed"),
            (Notification.Name.NSProcessInfoPowerStateDidChange, "Low Power Mode changed"),
            (UIDevice.batteryStateDidChangeNotification, "Battery state changed"),
            (UIDevice.batteryLevelDidChangeNotification, "Battery level changed"),
            (AVAudioSession.mediaServicesWereResetNotification, "Audio media services were reset"),
            (AVAudioSession.mediaServicesWereLostNotification, "Audio media services were lost"),
        ]
        for (name, message) in lifecycle {
            observers.append(center.addObserver(forName: name, object: nil, queue: .main) { _ in
                MainActor.assumeIsolated {
                    BackgroundDiagnostics.shared.logEvent(message)
                }
            })
        }

        observers.append(center.addObserver(forName: AVAudioSession.interruptionNotification, object: nil, queue: .main) { notification in
            let info = notification.userInfo ?? [:]
            let type = (info[AVAudioSessionInterruptionTypeKey] as? UInt).flatMap(AVAudioSession.InterruptionType.init)
            let reason = (info[AVAudioSessionInterruptionReasonKey] as? UInt).flatMap(AVAudioSession.InterruptionReason.init)
            let options = (info[AVAudioSessionInterruptionOptionKey] as? UInt).map(AVAudioSession.InterruptionOptions.init)
            let details = "type=\(type == .began ? "began" : type == .ended ? "ended" : "?")"
                + " reason=\(reason.map { "\($0.rawValue)" } ?? "none")"
                + " shouldResume=\(options?.contains(.shouldResume) ?? false)"
            MainActor.assumeIsolated {
                BackgroundDiagnostics.shared.logEvent("Audio interruption", extra: details)
            }
        })

        observers.append(center.addObserver(forName: AVAudioSession.routeChangeNotification, object: nil, queue: .main) { notification in
            let info = notification.userInfo ?? [:]
            let reason = (info[AVAudioSessionRouteChangeReasonKey] as? UInt).flatMap(AVAudioSession.RouteChangeReason.init)
            let previous = (info[AVAudioSessionRouteChangePreviousRouteKey] as? AVAudioSessionRouteDescription)?
                .outputs.map { $0.portType.rawValue }.joined(separator: ",") ?? "?"
            let details = "reason=\(reason.map { "\($0.rawValue)" } ?? "?") previousRoute=[\(previous)]"
            MainActor.assumeIsolated {
                BackgroundDiagnostics.shared.logEvent("Audio route changed", extra: details)
            }
        })

        observers.append(center.addObserver(forName: AVAudioSession.silenceSecondaryAudioHintNotification, object: nil, queue: .main) { notification in
            let type = (notification.userInfo?[AVAudioSessionSilenceSecondaryAudioHintTypeKey] as? UInt)
                .flatMap(AVAudioSession.SilenceSecondaryAudioHintType.init)
            let details = "type=\(type == .begin ? "begin" : type == .end ? "end" : "?")"
            MainActor.assumeIsolated {
                BackgroundDiagnostics.shared.logEvent("Silence secondary audio hint", extra: details)
            }
        })
    }

    private func logEvent(_ message: String, extra: String? = nil) {
        guard LoggingService.shared.isEnabled else { return }
        var details = appSnapshot()
        if let extra {
            details = extra + "\n" + details
        }
        log(.info, message, details: details)
        // A fresh process sample right at the transition, and the cadence follows the new state.
        sampler.setAppActive(UIApplication.shared.applicationState == .active)
        sampler.sampleSoon()
    }

    private func log(_ level: LogLevel, _ message: String, details: String) {
        LoggingService.shared.log(level: level, category: .diagnostics, message: message, details: details)
    }

    // MARK: - Descriptions

    private func describe(_ state: UIApplication.State) -> String {
        switch state {
        case .active: "active"
        case .inactive: "inactive"
        case .background: "background"
        @unknown default: "unknown(\(state.rawValue))"
        }
    }

    private func describe(_ state: UIScene.ActivationState) -> String {
        switch state {
        case .foregroundActive: "foregroundActive"
        case .foregroundInactive: "foregroundInactive"
        case .background: "background"
        case .unattached: "unattached"
        @unknown default: "unknown"
        }
    }

    private func describe(_ state: ProcessInfo.ThermalState) -> String {
        switch state {
        case .nominal: "nominal"
        case .fair: "fair"
        case .serious: "serious"
        case .critical: "critical"
        @unknown default: "unknown"
        }
    }

    private func describe(_ state: UIDevice.BatteryState) -> String {
        switch state {
        case .unknown: "unknown"
        case .unplugged: "unplugged"
        case .charging: "charging"
        case .full: "full"
        @unknown default: "unknown"
        }
    }

    private func describe(_ state: PlaybackState) -> String {
        if case .failed = state { return "failed" }
        return "\(state)"
    }
}

/// Samples process CPU, per-thread CPU, wakeups, GPU time and memory on its own
/// queue. All mutable state is confined to `queue`.
private final class ProcessSampler: @unchecked Sendable {
    private static let interval: TimeInterval = 10
    /// While the app is active, log only every Nth sample.
    private static let activeLogEvery = 3
    /// Process CPU above this while not active is logged as a warning.
    private static let highCPUPercent = 15.0

    private let queue = DispatchQueue(label: "stream.yattee.diagnostics", qos: .utility)
    private var timer: DispatchSourceTimer?
    private var isAppActive = true
    private var tick = 0

    private var lastTick: Date?
    private var resourceSampler: ResourceSampler?
    private var pendingSoon = false

    func setMainThreadPort(_ port: mach_port_t) {
        queue.async { self.resourceSampler = ResourceSampler(mainThreadPort: port) }
    }

    func setAppActive(_ active: Bool) {
        queue.async { self.isAppActive = active }
    }

    func start() {
        queue.async {
            let timer = DispatchSource.makeTimerSource(queue: self.queue)
            timer.schedule(deadline: .now() + Self.interval, repeating: Self.interval, leeway: .seconds(1))
            timer.setEventHandler { self.fire(forced: false) }
            timer.resume()
            self.timer = timer
            _ = self.sample()  // baseline
        }
    }

    /// Take an extra sample shortly after a lifecycle event.
    func sampleSoon() {
        queue.async {
            guard !self.pendingSoon else { return }
            self.pendingSoon = true
            self.queue.asyncAfter(deadline: .now() + 1) {
                self.pendingSoon = false
                self.fire(forced: true)
            }
        }
    }

    private func fire(forced: Bool) {
        guard UserDefaults.standard.bool(forKey: "loggingEnabled") else {
            lastTick = nil
            return
        }

        let now = Date()
        if !forced, let lastTick {
            let gap = now.timeIntervalSince(lastTick)
            if gap > Self.interval * 2.5 {
                LoggingService.shared.log(level: .warning, category: .diagnostics,
                    message: "Heartbeat gap: \(Int(gap))s since previous heartbeat",
                    details: "The process was suspended (or not scheduled) during the gap.")
            }
        }
        if !forced {
            lastTick = now
            tick += 1
        }

        let process = sample()
        guard forced || !isAppActive || tick % Self.activeLogEvery == 0 else { return }

        let highCPU = !isAppActive && process.cpuPercent >= Self.highCPUPercent
        let enqueuedAt = DispatchTime.now()
        let responded = ResponseFlag()
        DispatchQueue.main.async {
            responded.set()
            BackgroundDiagnostics.shared.deliverHeartbeat(process: process.text, highCPU: highCPU, enqueuedAt: enqueuedAt)
        }
        queue.asyncAfter(deadline: .now() + 3) {
            guard !responded.isSet else { return }
            LoggingService.shared.log(level: .warning, category: .diagnostics,
                message: "Heartbeat: main thread did not respond within 3s", details: process.text)
        }
    }

    // MARK: - Sampling

    private struct ProcessSample {
        let text: String
        let cpuPercent: Double
    }

    private func sample() -> ProcessSample {
        guard let resourceSampler else { return ProcessSample(text: "cpu: unavailable", cpuPercent: 0) }
        let sample = resourceSampler.sample()
        let footprint = sample.footprintMB.map { "\($0)MB" } ?? "?"
        let text = String(format: "cpu: process=%.1f%% over %.0fs", sample.cpuPercent, sample.wall)
            + " threads=\(sample.threadCount) footprint=\(footprint)\n"
            + "hotThreads: \(sample.hotThreadsText)\n"
            + sample.powerText
        return ProcessSample(text: text, cpuPercent: sample.cpuPercent)
    }
}

/// Set from the main thread, read on the sampler queue.
private final class ResponseFlag: @unchecked Sendable {
    private let lock = NSLock()
    private var value = false

    var isSet: Bool { lock.withLock { value } }

    func set() {
        lock.withLock { value = true }
    }
}
#endif