mirror of
https://github.com/yattee/yattee.git
synced 2026-10-29 16:07:20 +00:00
728e3b7286
- MPVRenderView keeps its display link paused while the stream has no video, instead of rendering and presenting 60 empty frames a second - Chapter segments get clamped played/buffered fractions and are equatable, so a time update re-renders only the chapter under the playhead instead of every segment - The mini player pauses its scrolling titles while the expanded player covers it (iOS/tvOS) - Performance logging no longer flags the first sample after a foreground/background transition as high CPU With the expanded player open in audio-only mode on an iPhone 12 mini, app CPU dropped from ~30% to ~12% and wakeups from ~128/s to ~37/s.
420 lines
16 KiB
Swift
420 lines
16 KiB
Swift
//
|
||
// PerformanceMonitor.swift
|
||
// Yattee
|
||
//
|
||
// Performance Logging: periodic resource usage with attribution, in the
|
||
// foreground and the background, under the Performance log category.
|
||
//
|
||
|
||
import Foundation
|
||
#if os(iOS) || os(tvOS)
|
||
import UIKit
|
||
#elseif os(macOS)
|
||
import AppKit
|
||
#endif
|
||
#if os(iOS) || os(macOS)
|
||
import MetricKit
|
||
#endif
|
||
|
||
/// Logs a resource sample every 5 seconds while Performance Logging is on:
|
||
/// CPU split by area and thread, wakeups, GPU, memory, disk, the
|
||
/// activity counters (`PerfCounter`) as rates, and app/player context.
|
||
/// Each foreground/background transition also logs a summary of the period
|
||
/// that just ended.
|
||
///
|
||
/// MetricKit reports (daily metrics, CPU exceptions, hangs) are logged
|
||
/// whenever logging is enabled, independent of the Performance toggle.
|
||
final class PerformanceMonitor: @unchecked Sendable {
|
||
static let shared = PerformanceMonitor()
|
||
static let enabledKey = "performanceLoggingEnabled"
|
||
|
||
private static let interval: TimeInterval = 5
|
||
/// Process CPU above these (percent of one core) logs the sample as a warning.
|
||
private static let highCPUForeground = 60.0
|
||
private static let highCPUBackground = 15.0
|
||
|
||
// Confined to `queue`.
|
||
private let queue = DispatchQueue(label: "stream.yattee.performance", qos: .utility)
|
||
private var sampler: ResourceSampler?
|
||
private var timer: DispatchSourceTimer?
|
||
private var period: Period?
|
||
private var context = ""
|
||
private var isBackground = false
|
||
|
||
// Main thread only.
|
||
@MainActor private weak var appEnvironment: AppEnvironment?
|
||
@MainActor private var runLoopObserver: CFRunLoopObserver?
|
||
@MainActor private var started = false
|
||
@MainActor private var batteryReference: (date: Date, level: Float)?
|
||
#if os(iOS) || os(macOS)
|
||
@MainActor private var metricSubscriber: MetricSubscriber?
|
||
#endif
|
||
|
||
private init() {}
|
||
|
||
var isEnabled: Bool {
|
||
UserDefaults.standard.bool(forKey: Self.enabledKey)
|
||
}
|
||
|
||
@MainActor
|
||
func start(appEnvironment: AppEnvironment) {
|
||
guard !started else { return }
|
||
started = true
|
||
self.appEnvironment = appEnvironment
|
||
observeLifecycle()
|
||
#if os(iOS) || os(macOS)
|
||
let subscriber = MetricSubscriber()
|
||
MXMetricManager.shared.add(subscriber)
|
||
metricSubscriber = subscriber
|
||
#endif
|
||
if isEnabled {
|
||
activate()
|
||
}
|
||
}
|
||
|
||
@MainActor
|
||
func setEnabled(_ enabled: Bool) {
|
||
guard enabled != isEnabled else { return }
|
||
UserDefaults.standard.set(enabled, forKey: Self.enabledKey)
|
||
if enabled {
|
||
activate()
|
||
} else {
|
||
deactivate()
|
||
}
|
||
}
|
||
|
||
// MARK: - Activation
|
||
|
||
@MainActor
|
||
private func activate() {
|
||
PerfCounter.setEnabled(true)
|
||
installRunLoopObserver()
|
||
#if os(iOS)
|
||
UIDevice.current.isBatteryMonitoringEnabled = true
|
||
#endif
|
||
|
||
let mainThreadPort = pthread_mach_thread_np(pthread_self())
|
||
let background = currentlyInBackground()
|
||
let context = makeContext()
|
||
queue.async {
|
||
self.isBackground = background
|
||
self.context = context
|
||
let sampler = ResourceSampler(mainThreadPort: mainThreadPort)
|
||
sampler.reset()
|
||
self.sampler = sampler
|
||
_ = PerfCounter.take()
|
||
self.period = Period(background: background)
|
||
|
||
let timer = DispatchSource.makeTimerSource(queue: self.queue)
|
||
timer.schedule(deadline: .now() + Self.interval, repeating: Self.interval, leeway: .milliseconds(500))
|
||
timer.setEventHandler { self.tick() }
|
||
timer.resume()
|
||
self.timer = timer
|
||
|
||
self.log(.info, "Performance logging started", details: "context: " + context)
|
||
}
|
||
}
|
||
|
||
@MainActor
|
||
private func deactivate() {
|
||
PerfCounter.setEnabled(false)
|
||
if let runLoopObserver {
|
||
CFRunLoopRemoveObserver(CFRunLoopGetMain(), runLoopObserver, .commonModes)
|
||
self.runLoopObserver = nil
|
||
}
|
||
queue.async {
|
||
self.timer?.cancel()
|
||
self.timer = nil
|
||
self.logPeriodSummary()
|
||
self.period = nil
|
||
self.sampler = nil
|
||
self.log(.info, "Performance logging stopped", details: nil)
|
||
}
|
||
}
|
||
|
||
@MainActor
|
||
private func installRunLoopObserver() {
|
||
guard runLoopObserver == nil else { return }
|
||
let observer = CFRunLoopObserverCreateWithHandler(nil, CFRunLoopActivity.afterWaiting.rawValue, true, 0) { _, _ in
|
||
PerfCounter.count("main.runLoopWakeup")
|
||
}
|
||
CFRunLoopAddObserver(CFRunLoopGetMain(), observer, .commonModes)
|
||
runLoopObserver = observer
|
||
}
|
||
|
||
// MARK: - Lifecycle
|
||
|
||
@MainActor
|
||
private func observeLifecycle() {
|
||
let center = NotificationCenter.default
|
||
#if os(iOS) || os(tvOS)
|
||
let transitions: [(Notification.Name, Bool)] = [
|
||
(UIApplication.didEnterBackgroundNotification, true),
|
||
(UIApplication.willEnterForegroundNotification, false),
|
||
]
|
||
#elseif os(macOS)
|
||
let transitions: [(Notification.Name, Bool)] = [
|
||
(NSApplication.didResignActiveNotification, true),
|
||
(NSApplication.didBecomeActiveNotification, false),
|
||
]
|
||
#endif
|
||
for (name, background) in transitions {
|
||
center.addObserver(forName: name, object: nil, queue: .main) { _ in
|
||
MainActor.assumeIsolated {
|
||
PerformanceMonitor.shared.stateChanged(background: background)
|
||
}
|
||
}
|
||
}
|
||
}
|
||
|
||
@MainActor
|
||
private func stateChanged(background: Bool) {
|
||
guard PerfCounter.enabled else { return }
|
||
let context = makeContext()
|
||
queue.async {
|
||
guard self.sampler != nil, background != self.isBackground else { return }
|
||
// Close the period at the transition with a final sample.
|
||
self.takeSample()
|
||
self.logPeriodSummary()
|
||
self.context = context
|
||
self.isBackground = background
|
||
self.period = Period(background: background)
|
||
}
|
||
}
|
||
|
||
// MARK: - Sampling
|
||
|
||
private func tick() {
|
||
takeSample()
|
||
// Refresh the context for the next sample; the main thread may be
|
||
// busy, so the sample itself never waits for it.
|
||
DispatchQueue.main.async {
|
||
let context = MainActor.assumeIsolated { self.makeContext() }
|
||
self.queue.async { self.context = context }
|
||
}
|
||
}
|
||
|
||
/// Must run on `queue`.
|
||
private func takeSample() {
|
||
guard let sampler else { return }
|
||
let sample = sampler.sample()
|
||
let counts = PerfCounter.take()
|
||
guard sample.wall > 0 else { return }
|
||
period?.add(sample, counts: counts)
|
||
|
||
// A sample right after the previous one (at a transition) only feeds the period totals.
|
||
guard sample.wall >= 1, UserDefaults.standard.bool(forKey: "loggingEnabled") else { return }
|
||
|
||
let state = isBackground ? "bg" : "fg"
|
||
let threshold = isBackground ? Self.highCPUBackground : Self.highCPUForeground
|
||
let footprint = sample.footprintMB.map { "\($0)MB" } ?? "?"
|
||
let wakeups = (sample.idleWakeupsPerSecond ?? 0) + (sample.interruptWakeupsPerSecond ?? 0)
|
||
let message = String(format: "Perf [%@] cpu %.1f%% | %@ | wakeups %.0f/s | mem %@",
|
||
state, sample.cpuPercent, sample.areasText, wakeups, footprint)
|
||
|
||
var lines = [
|
||
"threads: \(sample.hotThreadsText)",
|
||
sample.powerText,
|
||
String(format: "cpu: user %.1f%% system %.1f%% | %d threads | disk ops read %d write %d | window %.1fs",
|
||
sample.userPercent, sample.systemPercent, sample.threadCount,
|
||
sample.diskReadOps, sample.diskWriteOps, sample.wall),
|
||
]
|
||
lines.append(contentsOf: Self.describeCounts(counts, over: sample.wall))
|
||
lines.append("context: \(context)")
|
||
|
||
// The first sample of a period includes the transition work itself.
|
||
let isHigh = sample.cpuPercent >= threshold && (period?.sampleCount ?? 0) > 1
|
||
log(isHigh ? .warning : .info, message, details: lines.joined(separator: "\n"))
|
||
}
|
||
|
||
/// Must run on `queue`.
|
||
private func logPeriodSummary() {
|
||
guard let period, period.wall > 0,
|
||
UserDefaults.standard.bool(forKey: "loggingEnabled") else { return }
|
||
let wall = period.wall
|
||
let minutes = Int(wall) / 60
|
||
let seconds = Int(wall) % 60
|
||
let areas = period.areaSeconds.sorted { $0.value > $1.value }
|
||
.map { String(format: "%@ %.1f", $0.key, $0.value / wall * 100) }
|
||
.joined(separator: " ")
|
||
|
||
var lines = [
|
||
String(format: "cpu: avg %.1f%% max %.1f%% | %@", period.cpuSeconds / wall * 100, period.maxCPU, areas.isEmpty ? "idle" : areas),
|
||
String(format: "wakeups: avg %.0f/s", period.wakeups / wall),
|
||
]
|
||
lines.append(contentsOf: Self.describeCounts(period.counts, over: wall))
|
||
lines.append("context: \(context)")
|
||
|
||
log(.info, "Perf summary [\(period.background ? "bg" : "fg")] \(minutes)m \(seconds)s",
|
||
details: lines.joined(separator: "\n"))
|
||
}
|
||
|
||
/// Counters as rates: views in their own line, everything else as "activity".
|
||
private static func describeCounts(_ counts: [String: Int], over wall: TimeInterval) -> [String] {
|
||
func format(_ entries: [(key: String, value: Int)], stripping prefix: String = "") -> String {
|
||
entries.prefix(15).map { entry in
|
||
let name = String(entry.key.dropFirst(prefix.count))
|
||
if entry.key.hasSuffix(".bytes") {
|
||
return String(format: "%@ %.1fKB/s", name, Double(entry.value) / 1024 / wall)
|
||
}
|
||
return String(format: "%@ %.1f/s", name, Double(entry.value) / wall)
|
||
}.joined(separator: ", ")
|
||
}
|
||
let sorted = counts.sorted { $0.value > $1.value }
|
||
let views = sorted.filter { $0.key.hasPrefix("view.") }
|
||
let activity = sorted.filter { !$0.key.hasPrefix("view.") }
|
||
return [
|
||
"activity: " + (activity.isEmpty ? "none" : format(activity)),
|
||
"views: " + (views.isEmpty ? "none" : format(views, stripping: "view.")),
|
||
]
|
||
}
|
||
|
||
private func log(_ level: LogLevel, _ message: String, details: String?) {
|
||
LoggingService.shared.log(level: level, category: .performance, message: message, details: details)
|
||
}
|
||
|
||
// MARK: - Context
|
||
|
||
@MainActor
|
||
private func currentlyInBackground() -> Bool {
|
||
#if os(iOS) || os(tvOS)
|
||
UIApplication.shared.applicationState == .background
|
||
#elseif os(macOS)
|
||
!NSApplication.shared.isActive
|
||
#endif
|
||
}
|
||
|
||
@MainActor
|
||
private func makeContext() -> String {
|
||
var parts: [String] = []
|
||
|
||
#if os(iOS) || os(tvOS)
|
||
let appState: String = switch UIApplication.shared.applicationState {
|
||
case .active: "active"
|
||
case .inactive: "inactive"
|
||
case .background: "background"
|
||
@unknown default: "unknown"
|
||
}
|
||
parts.append("app \(appState)")
|
||
#elseif os(macOS)
|
||
parts.append("app \(NSApplication.shared.isActive ? "active" : "inactive")")
|
||
#endif
|
||
|
||
if let appEnvironment {
|
||
let state = appEnvironment.playerService.state
|
||
var player = "player \(state.playbackState)"
|
||
if state.currentVideo != nil {
|
||
player += state.currentStream?.isAudioOnly == true ? " audio-only" : " video"
|
||
player += " pip=\(state.pipState)"
|
||
player += " expanded=\(appEnvironment.navigationCoordinator.isPlayerExpanded)"
|
||
player += " publishesTime=\(state.publishesTimeUpdates)"
|
||
}
|
||
parts.append(player)
|
||
}
|
||
|
||
let thermal: String = switch ProcessInfo.processInfo.thermalState {
|
||
case .nominal: "nominal"
|
||
case .fair: "fair"
|
||
case .serious: "serious"
|
||
case .critical: "critical"
|
||
@unknown default: "unknown"
|
||
}
|
||
parts.append("thermal \(thermal)")
|
||
if ProcessInfo.processInfo.isLowPowerModeEnabled {
|
||
parts.append("low power mode")
|
||
}
|
||
|
||
#if os(iOS)
|
||
parts.append(batteryDescription())
|
||
#endif
|
||
|
||
return parts.joined(separator: " | ")
|
||
}
|
||
|
||
#if os(iOS)
|
||
/// Battery level, and the drain rate while unplugged once it is measurable.
|
||
@MainActor
|
||
private func batteryDescription() -> String {
|
||
let device = UIDevice.current
|
||
guard device.batteryLevel >= 0 else { return "battery ?" }
|
||
let level = device.batteryLevel
|
||
var text = "battery \(Int(level * 100))%"
|
||
|
||
guard device.batteryState == .unplugged else {
|
||
batteryReference = nil
|
||
return text + " (\(device.batteryState == .full ? "full" : "charging"))"
|
||
}
|
||
guard let reference = batteryReference, level <= reference.level else {
|
||
batteryReference = (Date(), level)
|
||
return text
|
||
}
|
||
let hours = Date().timeIntervalSince(reference.date) / 3600
|
||
if hours >= 5.0 / 60, reference.level > level {
|
||
text += String(format: " (%.0f%%/h over %.0fm)", Double(reference.level - level) * 100 / hours, hours * 60)
|
||
}
|
||
return text
|
||
}
|
||
#endif
|
||
}
|
||
|
||
// MARK: - Period
|
||
|
||
/// Totals for one foreground or background period.
|
||
private struct Period {
|
||
let background: Bool
|
||
var sampleCount = 0
|
||
var wall: TimeInterval = 0
|
||
var cpuSeconds: Double = 0
|
||
var maxCPU: Double = 0
|
||
var areaSeconds: [String: Double] = [:]
|
||
var wakeups: Double = 0
|
||
var counts: [String: Int] = [:]
|
||
|
||
init(background: Bool) {
|
||
self.background = background
|
||
}
|
||
|
||
mutating func add(_ sample: ResourceSample, counts: [String: Int]) {
|
||
sampleCount += 1
|
||
wall += sample.wall
|
||
cpuSeconds += sample.cpuPercent / 100 * sample.wall
|
||
if sample.wall >= 1 {
|
||
maxCPU = max(maxCPU, sample.cpuPercent)
|
||
}
|
||
for area in sample.areas {
|
||
areaSeconds[area.area, default: 0] += area.percent / 100 * sample.wall
|
||
}
|
||
wakeups += ((sample.idleWakeupsPerSecond ?? 0) + (sample.interruptWakeupsPerSecond ?? 0)) * sample.wall
|
||
self.counts.merge(counts, uniquingKeysWith: +)
|
||
}
|
||
}
|
||
|
||
// MARK: - MetricKit
|
||
|
||
#if os(iOS) || os(macOS)
|
||
/// Logs MetricKit payloads. The system delivers them at most daily (metrics)
|
||
/// or shortly after the event (diagnostics), usually on a later launch.
|
||
private final class MetricSubscriber: NSObject, MXMetricManagerSubscriber {
|
||
func didReceive(_ payloads: [MXMetricPayload]) {
|
||
for payload in payloads {
|
||
LoggingService.shared.log(level: .info, category: .performance,
|
||
message: "MetricKit metrics \(payload.timeStampBegin.formatted()) – \(payload.timeStampEnd.formatted())",
|
||
details: String(decoding: payload.jsonRepresentation(), as: UTF8.self))
|
||
}
|
||
}
|
||
|
||
func didReceive(_ payloads: [MXDiagnosticPayload]) {
|
||
for payload in payloads {
|
||
var kinds: [String] = []
|
||
if let cpu = payload.cpuExceptionDiagnostics, !cpu.isEmpty { kinds.append("\(cpu.count) CPU exception(s)") }
|
||
if let hangs = payload.hangDiagnostics, !hangs.isEmpty { kinds.append("\(hangs.count) hang(s)") }
|
||
if let disk = payload.diskWriteExceptionDiagnostics, !disk.isEmpty { kinds.append("\(disk.count) disk write exception(s)") }
|
||
if let crashes = payload.crashDiagnostics, !crashes.isEmpty { kinds.append("\(crashes.count) crash(es)") }
|
||
LoggingService.shared.log(level: kinds.isEmpty ? .info : .warning, category: .performance,
|
||
message: "MetricKit diagnostics: \(kinds.isEmpty ? "none" : kinds.joined(separator: ", "))",
|
||
details: String(decoding: payload.jsonRepresentation(), as: UTF8.self))
|
||
}
|
||
}
|
||
}
|
||
#endif
|