diff --git a/clients/apple/Sources/PunktfunkClient/ContentView.swift b/clients/apple/Sources/PunktfunkClient/ContentView.swift index d758bf5b..822cfbf9 100644 --- a/clients/apple/Sources/PunktfunkClient/ContentView.swift +++ b/clients/apple/Sources/PunktfunkClient/ContentView.swift @@ -994,9 +994,15 @@ struct ContentView: View { model?.disconnect() // the captured-state ⌃⌥⇧D combo }, onFrame: { [meter = model.meter, latency = model.latency, - split = model.latencySplit, queue = model.clientQueue, - offset = conn.clockOffsetNs] au in + split = model.latencySplit, queue = model.clientQueue] au in meter.note(byteCount: au.data.count) + // Read the offset PER AU (an atomic load), never in the capture list: a + // capture-list `offset =` froze the connect-time estimate for the whole + // session, and on a host whose wall clock steps (VM + NTP) that frozen + // value shifted hostnet/e2e by ~15 ms between sessions while the meter's + // impossible-sample guard hid the damage (field 2026-08-13). See + // `PunktfunkConnection.clockOffsetNs`. + let offset = conn.clockOffsetNs latency.record(ptsNs: au.ptsNs, offsetNs: offset) // The same receipt, keyed by pts, awaiting its 0xCF host timing (the // host/network split — drained by the 1 s stats tick). receivedNs is diff --git a/clients/apple/Sources/PunktfunkClient/Session/SessionModel.swift b/clients/apple/Sources/PunktfunkClient/Session/SessionModel.swift index c2636151..1fc908af 100644 --- a/clients/apple/Sources/PunktfunkClient/Session/SessionModel.swift +++ b/clients/apple/Sources/PunktfunkClient/Session/SessionModel.swift @@ -20,6 +20,18 @@ import SwiftUI /// instrument: any visible overlay forces the metal layer through the compositor, which costs a /// refresh period on the vsync-latched platforms — this is how to measure with it off. private let statsLog = Logger(subsystem: "io.unom.punktfunk", category: "stats") +/// Mirror the 1 Hz vitals line to STDOUT as well as the unified log. +/// +/// Exists for **tvOS, where the unified log is unreachable**: `log stream --device` is gone from +/// modern macOS, `log collect --device-name` needs root and then fails "Device not configured" +/// (an Apple TV has no USB to fall back to), and libimobiledevice pairs against a different +/// database than Xcode. Stdout, however, IS bridged — `xcrun devicectl device process launch +/// --console -e '{"PUNKTFUNK_STATS_STDOUT":"1"}' io.unom.punktfunk` streams these lines straight +/// to the Mac. That is the only way to read a session's numbers with the **stats overlay OFF**, +/// which matters because the overlay is itself a composited layer over the Metal one — i.e. a +/// plausible cause of the very present-floor inflation the overlay is used to measure. +/// Env-gated: no cost, and no stdout noise, unless someone is deliberately measuring. +private let statsToStdout = ProcessInfo.processInfo.environment["PUNKTFUNK_STATS_STDOUT"] == "1" /// Pump-thread-side frame counters; a 1 Hz main-actor timer drains them into @Published /// values. NSLock instead of an actor — the writer is the (non-async) pump thread. @@ -137,6 +149,25 @@ final class SessionModel: ObservableObject { /// and under stage-1. @Published var osFloorP50Ms = 0.0 @Published var osFloorValid = false + /// The deadline link's `preferredFrameLatency` ASK beside its property READBACK (see + /// `PresentLinkInfo` — it exists because tvOS has no reachable log). ⚠ The readback is NOT + /// a grant: it is a plain float property, so it echoes whatever was stored unless the + /// system clamps the setter. readback ≠ ask ⇒ a visible clamp (the one signal the API can + /// give); readback == ask proves nothing — `osFloorP50Ms` (the measured vend lead) is the + /// truth-teller (field 2026-08-13: readback 1.00 beside a 32.5 ms floor). + @Published var linkLatencyAskFrames: Float = 0 + @Published var linkLatencyFrames: Float = 0 + @Published var linkRangeMinHz: Float = 0 + @Published var linkRangeMaxHz: Float = 0 + @Published var linkDrawables = 0 + @Published var linkInfoValid = false + /// Impossible samples the HOST-ANCHORED meters (host+network, end-to-end) refused this + /// second (`LatencyMeter.drainTrimmed`). Nonzero means the clock offset is lying and every + /// host-anchored p50/p95 this window is a TRUNCATED distribution — the HUD marks the window + /// suspect instead of letting a trimmed tail pose as a healthy small number (the field + /// "e2e 0–3 ms" reading, 2026-08-13). Client-local stages can't go negative, so they carry + /// no such term. + @Published var skewTrimPerS = 0 /// The AUDIO plane's latency, from the playback ring (`SessionAudio.Stats`): how much decoded /// audio is queued ahead of the speaker, and where that PUTS it relative to the picture /// (positive = audio behind). `audioValid` is false until playback runs. @@ -683,6 +714,10 @@ final class SessionModel: ObservableObject { displayValid = false clientQueueValid = false osFloorValid = false + linkInfoValid = false + // Drop the previous session's grant too — the shared box outlives the session, and a new + // link may never come up (a non-deadline rung has none at all). + PresentLinkInfo.shared.clear() audioValid = false lostFrames = 0 lostPct = 0 @@ -904,6 +939,10 @@ final class SessionModel: ObservableObject { } else { self.endToEndValid = false } + // Drained even when the stats drains came back empty — with a badly wrong offset + // an entire window is refused and only this counter still tells the story. + self.skewTrimPerS = + self.latency.drainTrimmed() + self.endToEnd.drainTrimmed() if let d = self.decodeStage.drain() { self.decodeP50Ms = d.p50Ms self.decodeValid = true @@ -923,6 +962,18 @@ final class SessionModel: ObservableObject { } else { self.osFloorValid = false } + // The display link's latency ask + property readback (deadline rung only) — a + // LEVEL, not a window, so it is read rather than drained. + if let l = PresentLinkInfo.shared.snapshot() { + self.linkLatencyAskFrames = l.ask + self.linkLatencyFrames = l.latency + self.linkRangeMinHz = l.rangeMin + self.linkRangeMaxHz = l.rangeMax + self.linkDrawables = l.drawables + self.linkInfoValid = true + } else { + self.linkInfoValid = false + } if let q = self.clientQueue.drain() { self.clientQueueP50Ms = q.p50Ms self.clientQueueValid = true @@ -951,6 +1002,14 @@ final class SessionModel: ObservableObject { // Swift Int is 64-bit → %lld, NOT %d (which is a 32-bit C int); macOS 26's // strict String(format:) validator rejects the %d/Int mismatch and drops // the whole line (a cascade error that also mis-blames the float args). + // + // ⚠ Every invalid-field fallback below MUST be a typed `-1.0` (or a + // `Double(...)`-wrapped value), never a bare `-1`: in this variadic + // `CVarArg` context the ternary does NOT unify to Double — the untyped + // literal goes in as Int, and `%f` then reads Int64(-1)'s all-ones bit + // pattern, which IS a quiet NaN. Field 2026-08-13 (tvOS, stage-1, the + // first session ever to have invalid fields while frames flowed): every + // fallback printed `nan`. Latent since the line was added. format: "fps=%lld presents=%lld e2e_p50=%.1f e2e_p95=%.1f hostnet_p50=%.1f " + "decode_p50=%.1f display_p50=%.1f lost=%lld " + "floor_p50=%.1f display_adj=%.1f e2e_adj=%.1f queue_p50=%.1f " @@ -958,22 +1017,35 @@ final class SessionModel: ObservableObject { // In the log as well as on the HUD because the overlay is only up when // someone thought to turn it on, and the reports that need these // numbers arrive after the fact. - + "audio_buffer=%lld audio_av_offset=%lld", + + "audio_buffer=%lld audio_av_offset=%lld " + // The deadline link's latency ask + property readback (both -1 on + // non-deadline rungs) — appended so the PUNKTFUNK_FRAME_LATENCY + // ladder is readable over the stdout channel with the HUD off, + // which is the only honest way to run it on a tvOS device. + + "link_ask=%.2f link_readback=%.2f " + // Impossible samples the host-anchored meters refused this window: + // nonzero ⇒ the clock offset is lying and e2e/hostnet above are + // truncated distributions — disregard their p50/p95. + + "skew_trim=%lld", frames, displayWindow?.count ?? 0, - self.endToEndValid ? self.endToEndP50Ms : -1, - self.endToEndValid ? self.endToEndP95Ms : -1, - self.hostNetworkValid ? self.hostNetworkP50Ms : -1, - self.decodeValid ? self.decodeP50Ms : -1, - self.displayValid ? self.displayP50Ms : -1, + self.endToEndValid ? self.endToEndP50Ms : -1.0, + self.endToEndValid ? self.endToEndP95Ms : -1.0, + self.hostNetworkValid ? self.hostNetworkP50Ms : -1.0, + self.decodeValid ? self.decodeP50Ms : -1.0, + self.displayValid ? self.displayP50Ms : -1.0, lost, - self.osFloorValid ? self.osFloorP50Ms : -1, - self.displayValid ? self.displayAdjP50Ms : -1, - self.endToEndValid ? self.endToEndAdjP50Ms : -1, - self.clientQueueValid ? self.clientQueueP50Ms : -1, + self.osFloorValid ? self.osFloorP50Ms : -1.0, + self.displayValid ? self.displayAdjP50Ms : -1.0, + self.endToEndValid ? self.endToEndAdjP50Ms : -1.0, + self.clientQueueValid ? self.clientQueueP50Ms : -1.0, self.audioValid ? self.audioBufferMs : -1, - self.audioValid ? self.audioAvOffsetMs : 0) + self.audioValid ? self.audioAvOffsetMs : 0, + self.linkInfoValid ? Double(self.linkLatencyAskFrames) : -1.0, + self.linkInfoValid ? Double(self.linkLatencyFrames) : -1.0, + self.skewTrimPerS) statsLog.info("\(line, privacy: .public)") + if statsToStdout { print("pf.stats \(line)") } } } } diff --git a/clients/apple/Sources/PunktfunkClient/Session/StreamHUDView.swift b/clients/apple/Sources/PunktfunkClient/Session/StreamHUDView.swift index 65b23f8d..b52ff10b 100644 --- a/clients/apple/Sources/PunktfunkClient/Session/StreamHUDView.swift +++ b/clients/apple/Sources/PunktfunkClient/Session/StreamHUDView.swift @@ -128,6 +128,29 @@ struct StreamHUDView: View { .font(.system(.caption2, design: .monospaced)) .foregroundStyle(.tertiary) } + // The deadline link's frame-latency ASK beside its property READBACK. ⚠ The + // readback is NOT a grant — the property echoes whatever we stored (field + // 2026-08-13: 1.00 beside a 32.5 ms `os present` floor). The line earns its + // place because a readback that DIFFERS from the ask is the one clamp signal + // the API can give, and on tvOS the screen is the only place to read either + // (no log is reachable on an Apple TV; see PresentLinkInfo). + if model.linkInfoValid { + Text("link latency ask \(model.linkLatencyAskFrames, specifier: "%.2f") readback \(model.linkLatencyFrames, specifier: "%.2f") · range \(model.linkRangeMinHz, specifier: "%.0f")-\(model.linkRangeMaxHz, specifier: "%.0f") Hz · drawables \(model.linkDrawables)") + .font(.system(.caption2, design: .monospaced)) + .foregroundStyle(.tertiary) + } + // The clock-offset tripwire: host-anchored meters refused samples as + // impossible (≤ 0 after offset correction) this second. When this shows, + // e2e and host+network above are TRUNCATED distributions — a wrong skew + // offset shifted them and the impossible half was trimmed — so their + // p50/p95 flatter the stream (the field "e2e 0–3 ms" reading). Orange on + // purpose: every other stat here stays legible-quiet, but a number that + // has stopped meaning anything must not. + if model.skewTrimPerS > 0 { + Text("clock offset suspect — \(model.skewTrimPerS)/s impossible samples trimmed; e2e & host+network unreliable") + .font(.system(.caption2, design: .monospaced)) + .foregroundStyle(.orange) + } // Client-queue wait (reassembly receipt → decode pull, ABI v9 split): ~0 on // a healthy stream and hidden as noise; shown from 2 ms — a persistent value // is a client-side standing backlog that pre-split builds displayed as diff --git a/clients/apple/Sources/PunktfunkKit/Connection/PunktfunkConnection.swift b/clients/apple/Sources/PunktfunkKit/Connection/PunktfunkConnection.swift index b525fa25..f033d191 100644 --- a/clients/apple/Sources/PunktfunkKit/Connection/PunktfunkConnection.swift +++ b/clients/apple/Sources/PunktfunkKit/Connection/PunktfunkConnection.swift @@ -382,12 +382,29 @@ public final class PunktfunkConnection { /// the client draws its own (a visible system cursor over the stream). public private(set) var resolvedCompositor: Compositor = .auto - /// Host clock minus client clock (nanoseconds), from the connect-time wall-clock skew handshake - /// (`punktfunk_connection_clock_offset_ns`). Add it to a local `CLOCK_REALTIME` instant to - /// express that instant in the host's capture clock — the clock each `AccessUnit.ptsNs` is - /// stamped in — so a glass-to-glass latency (present/enqueue time minus `ptsNs`) is valid across - /// machines. `0` = no correction (an older host that didn't answer, or synchronized clocks). - public private(set) var clockOffsetNs: Int64 = 0 + /// Host clock minus client clock (nanoseconds) — LIVE: the connect-time skew handshake's + /// estimate, kept fresh by the core's mid-stream re-syncs (every 60 s plus immediately on a + /// suspected wall-clock step; `punktfunk_connection_clock_offset_now_ns`, ABI v10). Add it to + /// a local `CLOCK_REALTIME` instant to express that instant in the host's capture clock — the + /// clock each `AccessUnit.ptsNs` is stamped in — so a glass-to-glass latency (present/enqueue + /// time minus `ptsNs`) is valid across machines. `0` = no correction (an older host that + /// didn't answer, synchronized clocks, or a closed connection). + /// + /// ⚠ LIVE means DO NOT CACHE. Until 2026-08-13 this was a connect-time snapshot, and the + /// core's own doc names the failure: "after an NTP step or slow drift the connect-time value + /// silently corrupts every capture-clock comparison." The field evidence was stark — two + /// sessions minutes apart against the same wired host read hostnet 17–21 ms, then a + /// physically impossible 4.4 ms (the host is a VM; VM wall clocks step), and LatencyMeter's + /// impossible-sample guard silently trimmed the shifted-negative half, so the HUD showed a + /// plausible small number instead of an alarm. Read this property at each use — it is an + /// atomic load behind the FFI — and never park it in a `let` or a closure capture list. + /// Cross-thread reads follow the `framesDropped()` precedent. + public var clockOffsetNs: Int64 { + guard let handle else { return 0 } + var offset: Int64 = 0 + _ = punktfunk_connection_clock_offset_now_ns(handle, &offset) + return offset + } /// The video encoder bitrate (kbps) the host actually configured — the requested /// `bitrateKbps` clamped to the host's range ([500, 2 000 000] kbps), or its default @@ -635,9 +652,6 @@ public final class PunktfunkConnection { var comp: UInt32 = 0 _ = punktfunk_connection_compositor(handle, &comp) resolvedCompositor = Compositor(rawValue: comp) ?? .auto - var offset: Int64 = 0 - _ = punktfunk_connection_clock_offset_ns(handle, &offset) - clockOffsetNs = offset var br: UInt32 = 0 _ = punktfunk_connection_bitrate(handle, &br) resolvedBitrateKbps = br diff --git a/clients/apple/Sources/PunktfunkKit/Video/LatencyMeter.swift b/clients/apple/Sources/PunktfunkKit/Video/LatencyMeter.swift index 919a8ee0..db5f0472 100644 --- a/clients/apple/Sources/PunktfunkKit/Video/LatencyMeter.swift +++ b/clients/apple/Sources/PunktfunkKit/Video/LatencyMeter.swift @@ -15,8 +15,9 @@ import Foundation /// `record(ptsNs:atNs:offsetNs:)` at present. /// /// For the host-anchored intervals (capture→…) the sample is `end + offset - pts_ns`, where -/// `pts_ns` is the host's capture wall clock (the AU's pts) and the connect-time **clock-skew -/// offset** (`PunktfunkConnection.clockOffsetNs`, host minus client) makes the difference valid +/// `pts_ns` is the host's capture wall clock (the AU's pts) and the LIVE **clock-skew +/// offset** (`PunktfunkConnection.clockOffsetNs`, host minus client, mid-stream re-synced — +/// read it per record, never cached) makes the difference valid /// across machines. `offsetNs == 0` means an old host that didn't answer the skew handshake (or /// genuinely synced clocks) — the number is then only meaningful same-host, and the HUD tags the /// end-to-end line `(same-host clock)`. @@ -24,6 +25,8 @@ public final class LatencyMeter: @unchecked Sendable { private let lock = NSLock() private var samplesUs: [Int64] = [] private var skewCorrected = false + /// Samples `record` refused as impossible since the last `drainTrimmed` (see the guard). + private var trimmed = 0 /// The most recent sample and the instant it ended, for `latestSample(asOfNs:maxAgeMs:)` — /// a LEVEL, not a window, so `drain` deliberately leaves both alone. private var latestNs: Int64 = 0 @@ -49,8 +52,19 @@ public final class LatencyMeter: @unchecked Sendable { public func record(ptsNs: UInt64, atNs: Int64, offsetNs: Int64) { let latNs = atNs &+ offsetNs &- Int64(bitPattern: ptsNs) // Drop absurd values (a clock step, a wildly wrong offset, garbage pts, or a stage whose - // start stamp is missing/after its end) — samples are clamped to (0, 10 s). - guard latNs > 0, latNs < 10_000_000_000 else { return } + // start stamp is missing/after its end) — samples are clamped to (0, 10 s). COUNTED, not + // silent: a cluster of non-positive samples is the signature of a wrong clock offset + // (client-local stages can't go negative), and a meter that quietly trims the impossible + // half of a shifted distribution presents the surviving tail as a plausible small number + // — field 2026-08-13: "e2e 0–3 ms p50 / 23 ms p95" on a session whose true hostnet was + // ~18 ms. `drainTrimmed` surfaces the count so the window can be MARKED suspect instead + // of looking healthy. + guard latNs > 0, latNs < 10_000_000_000 else { + lock.lock() + trimmed += 1 + lock.unlock() + return + } lock.lock() samplesUs.append(latNs / 1000) latestNs = latNs @@ -99,6 +113,18 @@ public final class LatencyMeter: @unchecked Sendable { public let skewCorrected: Bool } + /// Take-and-reset the count of impossible samples `record` refused (see its guard). Drained + /// SEPARATELY from `drain()` on purpose: with a badly wrong offset EVERY sample of a window + /// can be non-positive, `drain()` then returns `nil` — and a count folded into `Stats` would + /// vanish with it, hiding the very windows that scream loudest. This survives an empty window. + public func drainTrimmed() -> Int { + lock.lock() + defer { lock.unlock() } + let n = trimmed + trimmed = 0 + return n + } + /// Percentiles over the samples accumulated since the last drain, then reset the window. `nil` /// when no samples arrived in the interval. public func drain() -> Stats? { diff --git a/clients/apple/Sources/PunktfunkKit/Video/MetalVideoPresenter.swift b/clients/apple/Sources/PunktfunkKit/Video/MetalVideoPresenter.swift index 9f8a70ec..ccdd99b8 100644 --- a/clients/apple/Sources/PunktfunkKit/Video/MetalVideoPresenter.swift +++ b/clients/apple/Sources/PunktfunkKit/Video/MetalVideoPresenter.swift @@ -549,6 +549,11 @@ public final class MetalVideoPresenter { layer.contentsGravity = .resizeAspect // Triple-buffer: more in-flight drawables before `nextDrawable()` (called on the display-link / // MAIN thread) has to block waiting for one to free. + // ⚠ This is the STAGE-2/3 depth. Stage-4 (deadline pacing, the iOS/tvOS default) never + // calls `nextDrawable()` — the link vends every drawable — so the third slot only gives + // the compositor room to queue a second present ahead of scanout, i.e. the two-refresh + // present floor. `Stage2Pipeline.startDeadlinePresenter` clamps it to 2 for that pacing; + // keep the two in step if this number ever changes. layer.maximumDrawableCount = 3 return MetalVideoPresenter( diff --git a/clients/apple/Sources/PunktfunkKit/Video/SessionPresenter.swift b/clients/apple/Sources/PunktfunkKit/Video/SessionPresenter.swift index e684085d..9e194837 100644 --- a/clients/apple/Sources/PunktfunkKit/Video/SessionPresenter.swift +++ b/clients/apple/Sources/PunktfunkKit/Video/SessionPresenter.swift @@ -260,13 +260,22 @@ final class SessionPresenter { // value is deliberately ignored). The user-facing choice is the INTENT // (PresentPriority): latency (newest-wins zero-queue store) vs smoothness (a FIFO jitter // buffer; on macOS it additionally paces presents onto the vsync grid so the buffer - // drains on display cadence). Stage-1 is reachable only via env in DEBUG; release maps - // it back to the default (the stage-1 pump below stays the automatic Metal-missing - // fallback). + // drains on display cadence). Stage-1 resolves from the persisted picker only in DEBUG; + // in release the ENV alone reaches it (the stage-1 pump below stays the automatic + // Metal-missing fallback either way). #if DEBUG let allowStage1 = true #else - let allowStage1 = false + // The gate exists so a LEFTOVER value can't revive the freeze-prone fallback — but the + // persisted picker is no longer read at all (setting: nil below), so the only channel + // left is the env, and an env var is never leftover: it takes a devicectl/Xcode launch + // to exist. It must stay openable on Release because Release is the only build that + // measures presentation honestly, and stage-1 is the one rung that presents on the + // hardware video plane instead of through the GPU compositor — the A/B for the tvOS + // two-refresh present floor (field 2026-08-13: PUNKTFUNK_PRESENTER=stage1 on a Release + // build silently ran stage-4, which would have false-negatived that A/B). + let allowStage1 = + ProcessInfo.processInfo.environment["PUNKTFUNK_PRESENTER"] == "stage1" #endif let explicit = PresenterChoice.explicit( setting: nil, // the legacy DefaultsKey.presenter picker value is no longer read @@ -336,7 +345,7 @@ final class SessionPresenter { } else { let pump = StreamPump() pump.start( - connection: connection, layer: baseLayer, + connection: connection, layer: baseLayer, endToEndMeter: endToEndMeter, onFrame: onFrame, onSessionEnd: onSessionEnd, onDecodedSize: onDecodedSize) self.pump = pump } diff --git a/clients/apple/Sources/PunktfunkKit/Video/Stage2Pipeline.swift b/clients/apple/Sources/PunktfunkKit/Video/Stage2Pipeline.swift index c93f45e2..3a621ee7 100644 --- a/clients/apple/Sources/PunktfunkKit/Video/Stage2Pipeline.swift +++ b/clients/apple/Sources/PunktfunkKit/Video/Stage2Pipeline.swift @@ -271,6 +271,64 @@ final class LatestBox: @unchecked Sendable { } } +/// The deadline link's frame-latency ASK and property READBACK, published for the HUD to render. +/// +/// ⚠ A readback is NOT a grant. `preferredFrameLatency` is a plain read-write float +/// (CAMetalDisplayLink.h carries no doc contract), so reading it returns whatever we last +/// stored unless the system actively clamps the setter — and the 2026-08-13 field run proved +/// how misleading that is: it read 1.00 while the measured vend lead sat at 1.95 refresh +/// periods. The number that tells the truth about scheduling is the vend lead (the HUD's +/// `os present` floor), never this property. The line still earns its place twice over: a +/// readback that DIFFERS from the ask is the one clamp signal the API can give, and the ask +/// must be visible on screen because **on tvOS no log is reachable** — `log stream --device` +/// is gone from modern macOS, `log collect --device-name` needs root and then fails "Device +/// not configured" because an Apple TV has no USB to fall back to, and the libimobiledevice +/// pairing is a different database from Xcode's. Console.app is a GUI. +/// +/// A process-global rather than a sixth parameter threaded through SessionModel → StreamView → +/// controller → SessionPresenter → Stage2Pipeline → delegate: it is write-once-per-session +/// diagnostics, and this file already keeps `presentDebug`/`presentLog` at file scope. Reset by +/// `clear()` at session start so a stale session's answer can never be read as this one's. +public final class PresentLinkInfo: @unchecked Sendable { + public static let shared = PresentLinkInfo() + private let lock = NSLock() + private var ask: Float = 0 + private var latency: Float = 0 + private var rangeMin: Float = 0 + private var rangeMax: Float = 0 + private var drawables: Int = 0 + private var present = false + + private init() {} + + func publish(ask: Float, latency: Float, rangeMin: Float, rangeMax: Float, drawables: Int) { + lock.lock() + self.ask = ask + self.latency = latency + self.rangeMin = rangeMin + self.rangeMax = rangeMax + self.drawables = drawables + present = true + lock.unlock() + } + + /// Session start — a link that never comes up must not leave the previous one's answer up. + public func clear() { + lock.lock() + present = false + lock.unlock() + } + + /// `nil` until the link's first update (or on a non-deadline rung, which has no link). + public func snapshot() + -> (ask: Float, latency: Float, rangeMin: Float, rangeMax: Float, drawables: Int)? + { + lock.lock() + defer { lock.unlock() } + return present ? (ask, latency, rangeMin, rangeMax, drawables) : nil + } +} + /// Deadline pacing's staged frame-rate hint. SessionPresenter pushes the stream rate from the /// MAIN thread (session start + every layout/Reconfigure); the link's own thread drains and /// applies it, so the CAMetalDisplayLink is only ever touched from the thread that runs it. The @@ -312,9 +370,24 @@ private final class FrameRateHint: @unchecked Sendable { return p } private static func range(hz: Float, boosted: Bool) -> CAFrameRateRange { + #if os(tvOS) + // A TV is a FIXED-rate display: there is no ProMotion panel to lift and no Pencil to + // sample for, so the `max(hz, 120)` ceiling below asks a 60 Hz Apple TV to accept + // anything up to 120. A range is a promise about how variable our cadence may be, and a + // scheduler handed 60…120 on a fixed 60 Hz display has every reason to keep a frame of + // slack in hand — which is what a two-refresh `targetPresentationTimestamp` IS. Pin all + // three bounds to the stream rate so the deadline has nothing to hedge against. + // (Field 2026-08-13, Apple TV 4K / tvOS 27: `os present` stuck at ~2 × 16.67 with + // `preferredFrameLatency = 1` asked for and re-asserted every update; shrinking the + // drawable pool to 2 moved it not at all.) `boosted` is deliberately ignored — it exists + // for pen proximity, which tvOS does not have. + _ = boosted + return CAFrameRateRange(minimum: hz, maximum: hz, preferred: hz) + #else let cap = max(hz, 120) let preferred = boosted ? cap : hz return CAFrameRateRange(minimum: preferred, maximum: cap, preferred: preferred) + #endif } } @@ -435,18 +508,28 @@ private final class DeadlineLinkDelegate: NSObject, CAMetalDisplayLinkDelegate { private let phase: PhaseReporter? /// The OS-floor sampler (design/apple-presentation-rebuild.md): every update's vend→glass /// lead is recorded so its p50 becomes the "OS present floor" the HUD subtracts from the - /// shown display/e2e numbers. Self-adapting — reads ~2 refresh periods composited today, - /// would read ~1 under direct-to-display, tracks VRR rate changes. + /// shown display/e2e numbers. Self-adapting: ~1 refresh period is the goal, ~2 means the + /// compositor is running a frame ahead of us (what a 3-slot drawable pool bought it before + /// `startDeadlinePresenter` clamped stage-4 to 2). Tracks VRR rate changes. private let floorMeter: LatencyMeter? - /// One-shot: log the link's EFFECTIVE preferredFrameLatency after the first re-assert — - /// reads 1 while vendLeadMs sits at ~2 periods ⇒ the scheduler ignores the request while - /// the layer is composited (the promotion hunt); reads 2 ⇒ the system clamped it outright. + /// The pool depth this session vends from (`startDeadlinePresenter` sets it on the layer). + /// Carried only so the one-shot line below reports the two halves of the depth question + /// together — a `preferredFrameLatency` of 1 against a 3-slot pool is the configuration that + /// measured a two-refresh floor in the field, and reading either number alone hides that. + private let drawableCount: Int + /// The `preferredFrameLatency` this session asks for — 1 by default, PUNKTFUNK_FRAME_LATENCY + /// for the on-device ladder (see `startDeadlinePresenter` for the ladder's design). + private let latencyAsk: Float + /// One-shot: log the link's preferredFrameLatency READBACK after the first re-assert. A + /// readback differing from the ask ⇒ the system clamps the property (the one clamp signal + /// it can give); a readback EQUAL to the ask proves nothing — only vendLeadMs does (see + /// PresentLinkInfo's doc for the field lesson). private var loggedEffective = false init( stash: LatestBox, renderSignal: DispatchSemaphore, hint: FrameRateHint, stats: PresentDebugStats?, floorMeter: LatencyMeter?, - phase: PhaseReporter? + phase: PhaseReporter?, drawableCount: Int, latencyAsk: Float ) { self.stash = stash self.renderSignal = renderSignal @@ -454,23 +537,34 @@ private final class DeadlineLinkDelegate: NSObject, CAMetalDisplayLinkDelegate { self.stats = stats self.floorMeter = floorMeter self.phase = phase + self.drawableCount = drawableCount + self.latencyAsk = latencyAsk } func metalDisplayLink(_ link: CAMetalDisplayLink, needsUpdate update: CAMetalDisplayLink.Update) { if let range = hint.drain(), link.preferredFrameRateRange != range { link.preferredFrameRateRange = range } - // Re-assert the minimum-latency request every update (cheap compare): it was set once - // before add(to:), and whether a pre-add set survives scheduling is exactly the kind of + // Re-assert the latency ask every update (cheap compare): it was set once before + // add(to:), and whether a pre-add set survives scheduling is exactly the kind of // thing the vendLeadMs stat exists to catch — belt and braces. - if link.preferredFrameLatency != 1 { link.preferredFrameLatency = 1 } + if link.preferredFrameLatency != latencyAsk { link.preferredFrameLatency = latencyAsk } + // Publish every update, not just the first: the range is re-applied from the staged hint + // above (mode switch / rate change), and `preferredFrameLatency` is re-asserted right + // here — so the readback can change mid-session, and a write-once snapshot would keep + // showing the answer to a question we have since asked again. Cheap: five stores under + // an uncontended lock, once per refresh. + let range = link.preferredFrameRateRange + PresentLinkInfo.shared.publish( + ask: latencyAsk, latency: link.preferredFrameLatency, rangeMin: range.minimum, + rangeMax: range.maximum, drawables: drawableCount) if !loggedEffective { loggedEffective = true - let range = link.preferredFrameRateRange let msg = String( - format: "deadline link up: effective preferredFrameLatency=%.2f " - + "range=%.0f-%.0f preferred=%.0f", - link.preferredFrameLatency, range.minimum, range.maximum, range.preferred ?? 0) + format: "deadline link up: preferredFrameLatency ask=%.2f readback=%.2f " + + "maxDrawables=%d range=%.0f-%.0f preferred=%.0f", + latencyAsk, link.preferredFrameLatency, drawableCount, + range.minimum, range.maximum, range.preferred ?? 0) presentLog.info("\(msg, privacy: .public)") } // The link's own pipeline depth, measured: how far ahead of glass this vend runs. @@ -729,7 +823,13 @@ public final class Stage2Pipeline { /// (which withhold concealed frames) and driven by the pump (arm on a gap, poll per iteration). private let gate = ReanchorGate(framesDropped: 0) private var token = StopFlag() - private var offsetNs: Int64 = 0 + /// LIVE host↔client clock offset, read AT EACH RECORD — never cached per session. Until + /// 2026-08-13 this was a `let` snapshot of the connect-time handshake, and on a host whose + /// wall clock steps (a VM under NTP) the frozen value silently shifted every host-anchored + /// stat — field evidence: hostnet 17–21 ms one session, a physically impossible 4.4 ms the + /// next, same wired host. The core re-syncs the estimate mid-stream (60 s + step detection); + /// each call is an atomic load behind the FFI. + private var clockOffset: () -> Int64 = { 0 } /// Signalled when the pump thread exits, so `stop()` can join it (bounded) before `decoder.reset()` /// — otherwise a pump iteration already past its `token.isStopped` check can rebuild a decode session /// right after the reset (a brief orphan session). `pumpJoinable` is armed by `start`, consumed by @@ -831,7 +931,7 @@ public final class Stage2Pipeline { onSessionEnd: (@Sendable () -> Void)?, onDecodedSize: (@Sendable (Int, Int) -> Void)? = nil ) { - offsetNs = connection.clockOffsetNs + clockOffset = { connection.clockOffsetNs } // live (re-synced) — see the field doc recovery.bind(connection) // arm host-keyframe recovery for this session decodeReport.bind(connection) // arm the Automatic-bitrate decode signal for this session phaseReporter.bind(connection) // arm phase reports (flushed only by the deadline link) @@ -1001,7 +1101,7 @@ public final class Stage2Pipeline { let ring = ring let endToEndMeter = endToEndMeter let displayMeter = displayMeter - let offsetNs = offsetNs + let clockOffset = clockOffset let renderSignal = renderSignal let renderStopped = renderStopped // Present policy — the user's V-Sync setting (default OFF = immediate, the long-proven @@ -1075,7 +1175,7 @@ public final class Stage2Pipeline { ?? Stage2Pipeline.realtimeNs(forDisplayLinkTimestamp: CACurrentMediaTime()) // End-to-end = capture→on-glass, measured directly (skew-corrected via the // connect-time clock offset) — the HUD headline. - endToEndMeter?.record(ptsNs: frame.ptsNs, atNs: atNs, offsetNs: offsetNs) + endToEndMeter?.record(ptsNs: frame.ptsNs, atNs: atNs, offsetNs: clockOffset()) // Display stage = decoded → on-glass. Both instants are client CLOCK_REALTIME, // so no skew offset applies. displayMeter?.record(ptsNs: UInt64(frame.decodedNs), atNs: atNs, offsetNs: 0) @@ -1134,11 +1234,52 @@ public final class Stage2Pipeline { let presenter = presenter let endToEndMeter = endToEndMeter let displayMeter = displayMeter - let offsetNs = offsetNs + let clockOffset = clockOffset let hint = frameRateHint let layer = presenter.layer let stash = LatestBox() + // ⭐ Shrink the drawable pool to 2 for THIS pacing — the measured fix for a present floor + // stuck at two refreshes (field 2026-08-13, Apple TV 4K / tvOS 27: `os present +32.5` at + // 60 Hz = 1.95 × 16.67, i.e. the system running a whole frame ahead of us). + // + // `maximumDrawableCount` is 3 from MetalVideoPresenter.make(), and its rationale there — + // "more in-flight drawables before nextDrawable() has to block" — is a STAGE-2 concern. + // Stage-4 never calls nextDrawable(): every drawable is vended by the link + // (`update.drawable` → stash → `render(into:)`), so the third slot buys this path nothing + // and costs it a refresh — a pool of 3 is exactly the room the compositor needs to keep + // two presents queued ahead of scanout, which is what `preferredFrameLatency = 1` is + // asking it not to do. Two slots is the shallowest pool that still double-buffers: one + // vended (stashed or being rendered), one being scanned out. + // + // Set HERE, not on the link thread: this runs before either the render thread or the link + // thread exists, so the layer still has a single writer (the render thread owns + // drawableSize/format afterwards — see MetalVideoPresenter's threading notes). + // PUNKTFUNK_DRAWABLE_COUNT=3 restores the old depth for an on-glass A/B without a + // rebuild; values outside 2...3 are ignored (CAMetalLayer's own accepted range). + let drawableCount = + ProcessInfo.processInfo.environment["PUNKTFUNK_DRAWABLE_COUNT"] + .flatMap(Int.init) + .flatMap { (2...3).contains($0) ? $0 : nil } ?? 2 + layer.maximumDrawableCount = drawableCount + + // The frame-latency ASK (default 1 — wake as late as fits: latch the NEXT refresh). + // PUNKTFUNK_FRAME_LATENCY overrides it for the on-device ladder. The property is a + // FLOAT, so sub-frame asks (0.5) are expressible; whether the scheduler honours them — + // or reacts to the property at all — is exactly what the ladder measures. Field + // 2026-08-13 (Apple TV 4K, tvOS 27): ask 1 → vend lead 1.95 refresh periods, and the + // readback echoed the ask throughout (it is a plain property — see PresentLinkInfo). + // The discriminating runs, watching `os present` (the vend lead), are: + // ask=2 → lead grows to ~3 ⇒ the property WORKS and the tvOS floor is ~ask+1; + // lead stays ~2 ⇒ the property is INERT here — stop pulling this lever. + // ask=0.5 → any lead below ~1.9 ⇒ a real in-regime win to then tune. + // Clamped to 0...4: negatives/NaN are meaningless, and beyond 4 asked-for frames of + // latency nothing is being measured. + let latencyAsk = + ProcessInfo.processInfo.environment["PUNKTFUNK_FRAME_LATENCY"] + .flatMap(Float.init) + .flatMap { $0.isFinite ? min(max($0, 0), 4) : nil } ?? 1 + let floorMeter = presentFloorMeter let phaseReporter = phaseReporter // The link starts LAZILY — the render thread triggers this after the FIRST decoded @@ -1151,9 +1292,10 @@ public final class Stage2Pipeline { let linkThread = Thread { let delegate = DeadlineLinkDelegate( stash: stash, renderSignal: renderSignal, hint: hint, stats: debugStats, - floorMeter: floorMeter, phase: phaseReporter) + floorMeter: floorMeter, phase: phaseReporter, + drawableCount: drawableCount, latencyAsk: latencyAsk) let link = CAMetalDisplayLink(metalLayer: layer) - link.preferredFrameLatency = 1 // wake as late as fits: latch the NEXT refresh + link.preferredFrameLatency = latencyAsk // see the ladder note above if let range = hint.drain() { link.preferredFrameRateRange = range } link.delegate = delegate // weak — this closure is the strong ref link.add(to: RunLoop.current, forMode: .default) @@ -1223,7 +1365,7 @@ public final class Stage2Pipeline { let onGlass: (Int64?) -> Void = { presentedNs in let atNs = presentedNs ?? Stage2Pipeline.realtimeNs(forDisplayLinkTimestamp: CACurrentMediaTime()) - endToEndMeter?.record(ptsNs: frame.ptsNs, atNs: atNs, offsetNs: offsetNs) + endToEndMeter?.record(ptsNs: frame.ptsNs, atNs: atNs, offsetNs: clockOffset()) displayMeter?.record(ptsNs: UInt64(frame.decodedNs), atNs: atNs, offsetNs: 0) debugStats?.presented(atNs: presentedNs, issuedNs: issuedNs) } diff --git a/clients/apple/Sources/PunktfunkKit/Video/StreamPump.swift b/clients/apple/Sources/PunktfunkKit/Video/StreamPump.swift index 21c14ad0..97b811ee 100644 --- a/clients/apple/Sources/PunktfunkKit/Video/StreamPump.swift +++ b/clients/apple/Sources/PunktfunkKit/Video/StreamPump.swift @@ -17,9 +17,18 @@ final class StreamPump { /// Pump thread: pull AUs, wrap, enqueue. Non-IDR AUs before the first format /// description are dropped. `onFrame`/`onSessionEnd` fire on the pump thread. + /// + /// `endToEndMeter` is stage-1's ONLY latency instrument, and it measures capture→ENQUEUE — + /// not capture→glass like the Metal rungs: the layer decodes AND presents after our hand-off, + /// and AVSampleBufferDisplayLayer has no presented callback, so the tail past enqueue (its + /// internal decode + the video-plane flip) is unmeasurable from the app. Cross-rung + /// comparisons must read this as e2e MINUS decode+display and settle the remainder on + /// camera. It is still worth wiring: matching pre-tail halves between rungs pins any felt + /// difference on the present tail — the video-plane-vs-compositor question itself. func start( connection: PunktfunkConnection, layer: AVSampleBufferDisplayLayer, + endToEndMeter: LatencyMeter? = nil, onFrame: (@Sendable (AccessUnit) -> Void)?, onSessionEnd: (@Sendable () -> Void)?, onDecodedSize: (@Sendable (Int, Int) -> Void)? = nil @@ -158,7 +167,14 @@ final class StreamPump { // flagging it DoNotDisplay — the layer still decodes it (keeping the reference // chain fed) but shows the last GOOD picture until a clean re-anchor lifts the // gate. Folded from the AU's wire flags (stage-1 has no decode callback). - if !gate.onDecoded(flags: au.flags) { + if gate.onDecoded(flags: au.flags) { + // Capture→enqueue (see start's doc). Only frames that will DISPLAY: + // a withheld frame never reaches glass, so its enqueue instant would + // dilute the population the Metal rungs are compared against. The + // offset is read PER ENQUEUE — it is live (mid-stream re-synced) and + // caching it rebuilds the stale-offset corruption (see clockOffsetNs). + endToEndMeter?.record(ptsNs: au.ptsNs, offsetNs: connection.clockOffsetNs) + } else { StreamPump.setDoNotDisplay(sample) } layer.enqueue(sample)