perf(host): session-transition trace + Welcome-time display prep (native path)
Latency plan P0.1 + P1.1/P1.2 (design/first-frame-and-resize-latency.md): P0.1 — every native session runs a bringup::Trace (hello -> welcome -> start -> punch_done -> display_acquired -> capture_attached -> first_frame -> encoder_open -> first_au -> first_packet), one summary info! line when the first video packet leaves; each accepted resize runs its own trace (reconfigure -> pipeline_rebuilt). Totals surface per session as time_to_first_frame_ms / last_resize_ms in session_status -> mgmt /status, so every subsequent latency change is measured, not vibed. (The Windows manager logs its own activation/settle deltas — correlate by wall clock.) P1.1/P1.2 — on the Windows native path the display bring-up no longer serializes behind the Start round-trip and the up-to-2.5 s hole-punch wait: a prep thread kicks off at Welcome (mode is final there) and runs monitor create -> activation -> verified settle -> capture attach -> first frame -> encoder open while the network waits are in flight; the data plane hands it the post-punch SessionContext and it becomes the stream thread on a warm pipeline. Abort between Welcome and Start drops the hand-off channel and the prep result releases into the keep-alive machinery (stop/quit + watcher are created pre-handshake so a vanished client also aborts the build retries). Same slot-scoped begin_idd_setup serialization as the inline path. Linux keeps the inline bring-up (launch semantics bind before create); GameStream untouched. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
@@ -0,0 +1,89 @@
|
||||
//! Session-transition latency trace (design/first-frame-and-resize-latency.md P0.1).
|
||||
//!
|
||||
//! One [`Trace`] per transition — session bring-up (`hello → … → first_packet`) or a mid-stream
|
||||
//! resize (`reconfigure_received → … → pipeline_rebuilt`) — collects millisecond stage stamps
|
||||
//! across the threads a transition crosses (handshake task, display-prep/encode thread, send
|
||||
//! thread) and emits ONE summary `info!` line when the transition completes, so every landed
|
||||
//! latency change is measured against a number instead of vibes. The completed total also lands
|
||||
//! in a shared slot [`crate::session_status`] exposes (`time_to_first_frame_ms` /
|
||||
//! `last_resize_ms`), so the web-console Dashboard and future regressions can read it per session.
|
||||
//!
|
||||
//! Deliberately coarse: stages are stamped where the session layer can see them; layers the trace
|
||||
//! doesn't reach (the Windows display manager's activation ladder / settle waits) log their own
|
||||
//! per-stage deltas and correlate by wall clock.
|
||||
|
||||
use std::sync::atomic::{AtomicBool, AtomicU32, Ordering};
|
||||
use std::sync::{Arc, Mutex};
|
||||
use std::time::Instant;
|
||||
|
||||
/// A single transition's stage trace. Cheap and thread-safe: `mark` is a mutex push, `finish`
|
||||
/// emits the one summary line (exactly once — later calls no-op, so an abandoned trace stays
|
||||
/// silent).
|
||||
pub(crate) struct Trace {
|
||||
/// Which transition this traces (`"bringup"` / `"resize"`) — the summary line's `kind`.
|
||||
kind: &'static str,
|
||||
origin: Instant,
|
||||
/// `(stage, ms since origin)` in stamp order.
|
||||
stages: Mutex<Vec<(&'static str, u32)>>,
|
||||
finished: AtomicBool,
|
||||
/// Where the completed total lands — shared with [`crate::session_status`].
|
||||
total_ms: Arc<AtomicU32>,
|
||||
}
|
||||
|
||||
impl Trace {
|
||||
/// Start a trace at "now" (= the first stage's zero point). `total_ms` is the shared slot the
|
||||
/// completed total is stored into (0 until the transition finishes).
|
||||
pub(crate) fn start(kind: &'static str, total_ms: Arc<AtomicU32>) -> Arc<Self> {
|
||||
Arc::new(Self {
|
||||
kind,
|
||||
origin: Instant::now(),
|
||||
stages: Mutex::new(Vec::new()),
|
||||
finished: AtomicBool::new(false),
|
||||
total_ms,
|
||||
})
|
||||
}
|
||||
|
||||
/// The shared slot the completed total is stored into (for `session_status::register`).
|
||||
pub(crate) fn total_slot(&self) -> Arc<AtomicU32> {
|
||||
self.total_ms.clone()
|
||||
}
|
||||
|
||||
/// Stamp a stage at "now" — first occurrence only (a retried build re-crosses its stamp
|
||||
/// points; the first crossing is the one the transition timeline wants). No-op after
|
||||
/// [`finish`](Self::finish), so steady-state paths that also cross a stamped point stay free.
|
||||
pub(crate) fn mark(&self, stage: &'static str) {
|
||||
if self.finished.load(Ordering::Relaxed) {
|
||||
return;
|
||||
}
|
||||
let ms = self.origin.elapsed().as_millis().min(u32::MAX as u128) as u32;
|
||||
let mut stages = self.stages.lock().unwrap();
|
||||
if stages.iter().any(|(s, _)| *s == stage) {
|
||||
return;
|
||||
}
|
||||
stages.push((stage, ms));
|
||||
}
|
||||
|
||||
/// Stamp the final stage and emit the one-line summary (first call only). The final stage's
|
||||
/// offset is the transition total, stored into the shared slot.
|
||||
pub(crate) fn finish(&self, stage: &'static str) {
|
||||
if self.finished.swap(true, Ordering::Relaxed) {
|
||||
return;
|
||||
}
|
||||
let total = self.origin.elapsed().as_millis().min(u32::MAX as u128) as u32;
|
||||
let mut stages = self.stages.lock().unwrap();
|
||||
stages.push((stage, total));
|
||||
let line = stages
|
||||
.iter()
|
||||
.map(|(s, ms)| format!("{s}+{ms}"))
|
||||
.collect::<Vec<_>>()
|
||||
.join(" ");
|
||||
drop(stages);
|
||||
self.total_ms.store(total.max(1), Ordering::Relaxed);
|
||||
tracing::info!(
|
||||
kind = self.kind,
|
||||
total_ms = total,
|
||||
stages = %line,
|
||||
"session-transition trace"
|
||||
);
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user