Profile frame stages via sidecar histogram → ely::servo::perf

This commit is contained in:
2026-05-10 22:30:57 -04:00
parent 18fd20b577
commit f7027e6ea5
9 changed files with 649 additions and 159 deletions
Generated
+74
View File
@@ -2257,6 +2257,8 @@ dependencies = [
"sha2",
"thiserror 2.0.18",
"toml 1.1.2+spec-1.1.0",
"tracing",
"tracing-subscriber",
"ureq",
"url",
]
@@ -5423,6 +5425,15 @@ dependencies = [
"xml5ever 0.18.1",
]
[[package]]
name = "matchers"
version = "0.2.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "d1525a2a28c7f4fa0fc98bb91ae755d1e2d1505079e05539e35bc876b5d65ae9"
dependencies = [
"regex-automata 0.4.14",
]
[[package]]
name = "maybe-rayon"
version = "0.1.1"
@@ -5849,6 +5860,15 @@ dependencies = [
"winapi",
]
[[package]]
name = "nu-ansi-term"
version = "0.50.3"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "7957b9740744892f114936ab4a57b3f487491bbeafaf8083688b16841a4240e5"
dependencies = [
"windows-sys 0.61.2",
]
[[package]]
name = "num"
version = "0.4.3"
@@ -9568,6 +9588,15 @@ dependencies = [
"keccak",
]
[[package]]
name = "sharded-slab"
version = "0.1.7"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6"
dependencies = [
"lazy_static",
]
[[package]]
name = "shellexpand"
version = "3.1.2"
@@ -10479,6 +10508,15 @@ dependencies = [
"syn 2.0.117",
]
[[package]]
name = "thread_local"
version = "1.1.9"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "f60246a4944f24f6e018aa17cdeffb7818b76356965d03b07d6a9886e8962185"
dependencies = [
"cfg-if",
]
[[package]]
name = "tiff"
version = "0.11.3"
@@ -10871,6 +10909,36 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a"
dependencies = [
"once_cell",
"valuable",
]
[[package]]
name = "tracing-log"
version = "0.2.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3"
dependencies = [
"log",
"once_cell",
"tracing-core",
]
[[package]]
name = "tracing-subscriber"
version = "0.3.23"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "cb7f578e5945fb242538965c2d0b04418d38ec25c79d160cd279bf0731c8d319"
dependencies = [
"matchers",
"nu-ansi-term",
"once_cell",
"regex-automata 0.4.14",
"sharded-slab",
"smallvec",
"thread_local",
"tracing",
"tracing-core",
"tracing-log",
]
[[package]]
@@ -11272,6 +11340,12 @@ dependencies = [
"wasm-bindgen",
]
[[package]]
name = "valuable"
version = "0.1.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65"
[[package]]
name = "value-bag"
version = "1.12.0"
+2
View File
@@ -29,6 +29,8 @@ serde = { version = "1.0.228", features = ["derive"] }
serde_json = "1.0.145"
thiserror = "2.0.12"
toml = "1.1.2"
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter"] }
ureq = "2.12.1"
url = "2.5.4"
uuid = { version = "1.12.1", features = ["v7"] }
+2
View File
@@ -23,6 +23,8 @@ serde = { workspace = true, features = ["derive"] }
serde_json.workspace = true
sha2.workspace = true
thiserror.workspace = true
tracing.workspace = true
tracing-subscriber.workspace = true
ureq.workspace = true
url.workspace = true
+13
View File
@@ -52,6 +52,7 @@ actions!(
);
fn main() {
init_tracing();
let pending_deep_links = PendingDeepLinks::default();
pending_deep_links.push(startup_deep_links(env::args().skip(1)));
let open_url_queue = pending_deep_links.clone();
@@ -320,6 +321,18 @@ fn quit(_: &Quit, cx: &mut App) {
cx.quit();
}
/// Install the global tracing subscriber. `RUST_LOG` drives the
/// filter; absent it, only `warn` and above leak through so day-to-day
/// runs stay quiet. The perf target is silent by default —
/// `RUST_LOG=ely::servo::perf=info` flips on the frame-time stream
/// without touching the rest of the app. We swallow re-init errors so
/// tests that share the process state with main don't blow up.
fn init_tracing() {
use tracing_subscriber::{EnvFilter, fmt};
let filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("warn"));
let _ = fmt().with_env_filter(filter).with_target(true).try_init();
}
fn open_private_window(_: &OpenPrivateWindow, cx: &mut App) {
if open_browser_window(cx, BrowserWindowMode::Private).is_some() {
cx.activate(true);
+54
View File
@@ -95,6 +95,10 @@ impl ServoLiveClient {
return Err(ServoLiveError::SidecarFailed { message: error });
}
if let Some(perf) = response.perf.as_ref() {
log_frame_perf(perf);
}
let Some(report) = response.frame else {
return Ok(None);
};
@@ -332,6 +336,56 @@ enum LiveRequest {
struct LiveResponse {
error: Option<String>,
frame: Option<LiveFrameReport>,
#[serde(default)]
perf: Option<LiveFramePerfSummary>,
}
/// Aggregated frame-stage timings rolled up every N frames by the
/// sidecar. We accept anything matching the wire shape and let the
/// `tracing` event echo the percentiles verbatim — the sidecar is
/// the source of truth for histogram boundaries.
#[derive(Deserialize)]
struct LiveFramePerfSummary {
window: u32,
context: String,
paint_p50_us: u64,
paint_p95_us: u64,
paint_p99_us: u64,
encode_p50_us: u64,
encode_p95_us: u64,
encode_p99_us: u64,
write_p50_us: u64,
write_p95_us: u64,
write_p99_us: u64,
total_p50_us: u64,
total_p95_us: u64,
total_p99_us: u64,
}
/// Emit one structured `tracing` event per perf summary, on a
/// dedicated target so `RUST_LOG=ely::servo::perf=info` flips the
/// stream on without dragging the rest of the app along. Filtering
/// happens upstream in the subscriber — this call is a single
/// pointer + integer push.
fn log_frame_perf(summary: &LiveFramePerfSummary) {
tracing::info!(
target: "ely::servo::perf",
window = summary.window,
context = %summary.context,
paint_p50_us = summary.paint_p50_us,
paint_p95_us = summary.paint_p95_us,
paint_p99_us = summary.paint_p99_us,
encode_p50_us = summary.encode_p50_us,
encode_p95_us = summary.encode_p95_us,
encode_p99_us = summary.encode_p99_us,
write_p50_us = summary.write_p50_us,
write_p95_us = summary.write_p95_us,
write_p99_us = summary.write_p99_us,
total_p50_us = summary.total_p50_us,
total_p95_us = summary.total_p95_us,
total_p99_us = summary.total_p99_us,
"frame_perf",
);
}
#[derive(Deserialize)]
@@ -16,6 +16,10 @@ use thiserror::Error;
mod args;
#[path = "ely_servo_sidecar/live.rs"]
mod live;
#[path = "ely_servo_sidecar/live_protocol.rs"]
mod live_protocol;
#[path = "ely_servo_sidecar/perf.rs"]
mod perf;
#[path = "ely_servo_sidecar/report.rs"]
mod report;
@@ -9,32 +9,35 @@ use std::{
use ely_domain::{DEFAULT_ZOOM_PERCENT, ProfileId, TabId, UrlText};
use ely_servo_host::{
KeyboardTextRequest, MouseClickRequest, MouseHoverRequest, NavigationRequest, PageZoomRequest,
PermissionDecision, PermissionRequest, RenderedFrame, ResizeRequest, ScrollRequest, ServoHost,
ServoHostError, ServoSurfaceSize, SoftwareServoHost, WebViewSnapshot, WebViewState,
PermissionDecision, PermissionRequest, RenderingContextKind, ResizeRequest, ScrollRequest,
ServoHost, ServoSurfaceSize, SoftwareServoHost,
};
use serde::{Deserialize, Serialize};
use thiserror::Error;
use super::args::LiveArgs;
use super::live_protocol::{
LiveFrameReport, LiveOutcome, LiveRequest, LiveSitePermission, PartialFrameTimings,
};
pub(super) use super::live_protocol::LiveSidecarError;
use super::perf::{FramePerfAggregator, FramePerfSummary, FrameStageTimings, elapsed_ns};
/// Per-`Ensure` budget the sidecar waits for Servo to paint a frame
/// after input dispatch. The original 60 ms was tuned for navigation
/// alone — too tight for click + paint round trips on the software
/// renderer. With 250 ms, a click dispatched into an already-loaded
/// page (the common case for input dispatch) paints within the same
/// `Ensure` so the user sees the page react instead of waiting for
/// the next 16 ms `Poll` from the GPUI shell.
/// Per-`Ensure` budget for Servo to paint after input dispatch.
/// 250 ms catches the common click + paint round trip within the
/// same `Ensure` instead of waiting for the next 16 ms `Poll`.
const LIVE_FRAME_WAIT_TIMEOUT: Duration = Duration::from_millis(250);
const LIVE_FRAME_WAIT_INTERVAL: Duration = Duration::from_millis(2);
pub(super) fn run_live(args: LiveArgs) -> Result<(), LiveSidecarError> {
fs::create_dir_all(&args.profile_data_dir)?;
let context_label = rendering_context_label(args.rendering_context_kind);
let mut host = SoftwareServoHost::new_with_config_dir_and_kind(
ServoSurfaceSize::new(1, 1),
Some(args.profile_data_dir),
args.rendering_context_kind,
)?;
let mut sessions = HashMap::new();
let mut perf =
FramePerfAggregator::new(context_label, FramePerfAggregator::DEFAULT_WINDOW_SIZE);
let mut pending_summary: Option<FramePerfSummary> = None;
let stdin = io::stdin();
let mut stdout = io::stdout().lock();
@@ -48,12 +51,19 @@ pub(super) fn run_live(args: LiveArgs) -> Result<(), LiveSidecarError> {
Ok(request) => handle_request(&mut host, &mut sessions, request),
Err(error) => Err(LiveSidecarError::Json(error)),
};
write_outcome(&mut stdout, outcome)?;
write_outcome(&mut stdout, &mut perf, &mut pending_summary, outcome)?;
}
Ok(())
}
const fn rendering_context_label(kind: RenderingContextKind) -> &'static str {
match kind {
RenderingContextKind::Software => "software",
RenderingContextKind::Hardware => "hardware",
}
}
fn handle_request(
host: &mut SoftwareServoHost,
sessions: &mut HashMap<String, LiveSession>,
@@ -120,27 +130,51 @@ fn handle_request(
}
}
/// Stream a JSON response line followed by the optional raw RGBA frame.
/// Serialise the response then stream the optional raw RGBA frame on
/// the same stdout pipe. The client reads the JSON line, takes
/// `rgba_byte_count` from the report, then reads that many bytes
/// from the same stream — no temp file round-trip.
///
/// The frame bytes ride on the same stdout pipe as the JSON header
/// rather than being staged through a temp file. The client reads the
/// JSON line, takes `rgba_byte_count` from the report, then reads that
/// many bytes from the same stream. A 1080p frame is 8 MB — at 60 fps
/// the previous `fs::write` + main-process `fs::read` round-trip cost
/// ~960 MB/s of syscall + memcpy traffic that the scroll/zoom path
/// could never amortise. Same pipe, raw bytes: no kernel `open`, no
/// page cache churn, no transient file lifecycle to clean up.
/// After the bytes hit the pipe we fold paint+encode+write timings
/// into the aggregator. Any summary it emits is stashed on
/// `pending_summary` and rides out on the *next* response, because
/// the protocol is one-line-per-response and an unsolicited summary
/// line would desync the main process's read loop.
fn write_outcome(
stdout: &mut impl Write,
perf: &mut FramePerfAggregator,
pending_summary: &mut Option<FramePerfSummary>,
outcome: Result<LiveOutcome, LiveSidecarError>,
) -> Result<(), LiveSidecarError> {
let outcome = outcome.unwrap_or_else(|error| LiveOutcome::error(error.to_string()));
let mut outcome = outcome.unwrap_or_else(|error| LiveOutcome::error(error.to_string()));
let partial_timings = outcome.partial_timings.take();
let frame_present = outcome.frame.is_some();
if let Some(summary) = pending_summary.take() {
outcome.response.perf = Some(summary);
}
let write_started_at = Instant::now();
serde_json::to_writer(&mut *stdout, &outcome.response)?;
stdout.write_all(b"\n")?;
if let Some(frame) = outcome.frame.as_ref() {
stdout.write_all(frame.rgba_bytes())?;
}
stdout.flush()?;
if frame_present {
let write_ns = elapsed_ns(write_started_at);
let partial = partial_timings.unwrap_or(PartialFrameTimings { paint_ns: 0, encode_ns: 0 });
let total = Duration::from_nanos(
partial.paint_ns.saturating_add(partial.encode_ns).saturating_add(write_ns),
);
let timings = FrameStageTimings::from_durations(
Duration::from_nanos(partial.paint_ns),
Duration::from_nanos(partial.encode_ns),
Duration::from_nanos(write_ns),
total,
);
if let Some(summary) = perf.record(timings) {
*pending_summary = Some(summary);
}
}
Ok(())
}
@@ -267,13 +301,18 @@ fn poll_frame(
host.tick();
let snapshot = host.snapshot(&session.webview_id)?;
if snapshot.has_pending_frame() {
let paint_started_at = Instant::now();
host.paint(&session.webview_id)?;
let snapshot = host.snapshot(&session.webview_id)?;
let frame = host.last_rendered_frame()?;
let paint_ns = elapsed_ns(paint_started_at);
let encode_started_at = Instant::now();
let has_visible_content =
frame.non_white_pixel_count() > 0 && frame.content_pixel_count() > 0;
let report = LiveFrameReport::new(&snapshot, &frame);
let outcome = LiveOutcome::from_frame(report, frame);
let encode_ns = elapsed_ns(encode_started_at);
let timings = PartialFrameTimings { paint_ns, encode_ns };
let outcome = LiveOutcome::from_frame(report, frame, timings);
if has_visible_content {
session.awaiting_visible_frame = false;
return Ok(outcome);
@@ -322,142 +361,6 @@ impl LiveSession {
}
}
#[derive(Deserialize)]
#[serde(tag = "type", rename_all = "snake_case")]
enum LiveRequest {
Ensure {
tab_id: String,
profile_id: String,
url: String,
width: u32,
height: u32,
page_zoom_percent: u16,
scroll_delta_x: i32,
scroll_delta_y: i32,
click_x: Option<u32>,
click_y: Option<u32>,
#[serde(default)]
hover_x: Option<u32>,
#[serde(default)]
hover_y: Option<u32>,
typed_text: Option<String>,
site_permissions: Vec<LiveSitePermission>,
},
Poll {
tab_id: String,
},
}
#[derive(Deserialize)]
struct LiveSitePermission {
origin: String,
feature: String,
decision: String,
}
/// A handle plus an optional rendered frame, kept together until the
/// moment of writing to stdout. The JSON header advertises
/// `rgba_byte_count`; the binary follows on the same pipe. We carry
/// the `RenderedFrame` (one host-side clone, already paid for inside
/// `host.last_rendered_frame`) instead of doing another `to_vec()`
/// over `rgba_bytes()` — `write_all(&self.rgba_bytes()[..])` writes
/// the existing slice straight to the pipe.
struct LiveOutcome {
response: LiveResponse,
frame: Option<RenderedFrame>,
}
impl LiveOutcome {
fn empty() -> Self {
Self { response: LiveResponse::empty(), frame: None }
}
fn error(message: String) -> Self {
Self { response: LiveResponse::error(message), frame: None }
}
fn from_frame(report: LiveFrameReport, frame: RenderedFrame) -> Self {
Self { response: LiveResponse::frame(report), frame: Some(frame) }
}
}
#[derive(Serialize)]
struct LiveResponse {
error: Option<String>,
frame: Option<LiveFrameReport>,
}
impl LiveResponse {
fn empty() -> Self {
Self { error: None, frame: None }
}
fn frame(frame: LiveFrameReport) -> Self {
Self { error: None, frame: Some(frame) }
}
fn error(message: String) -> Self {
Self { error: Some(message), frame: None }
}
}
#[derive(Serialize)]
struct LiveFrameReport {
loaded_url: Option<String>,
title: Option<String>,
state: &'static str,
width: u32,
height: u32,
rgba_byte_count: usize,
non_white_pixel_count: u64,
content_pixel_count: u64,
sample_hash: u64,
}
impl LiveFrameReport {
fn new(snapshot: &WebViewSnapshot, frame: &RenderedFrame) -> Self {
Self {
loaded_url: snapshot.url().map(str::to_string),
title: snapshot.title().map(str::to_string),
state: state_label(snapshot.state()),
width: frame.width(),
height: frame.height(),
rgba_byte_count: frame.rgba_bytes().len(),
non_white_pixel_count: frame.non_white_pixel_count(),
content_pixel_count: frame.content_pixel_count(),
sample_hash: frame.sample_hash(),
}
}
}
#[derive(Debug, Error)]
pub(super) enum LiveSidecarError {
#[error("live session is unavailable after creation")]
SessionUnavailable,
#[error(transparent)]
Domain(#[from] ely_domain::DomainError),
#[error(transparent)]
Host(#[from] ServoHostError),
#[error(transparent)]
Io(#[from] io::Error),
#[error(transparent)]
Json(#[from] serde_json::Error),
}
fn state_label(state: &WebViewState) -> &'static str {
match state {
WebViewState::Created => "created",
WebViewState::Loading => "loading",
WebViewState::Complete => "complete",
WebViewState::Sleeping => "sleeping",
WebViewState::Crashed => "crashed",
}
}
fn positive_scroll_component(current: i32, delta: i32) -> i32 {
let value = i64::from(current) + i64::from(delta);
value.clamp(0, i64::from(i32::MAX)) as i32
@@ -0,0 +1,163 @@
//! Wire types for the sidecar live loop. Split out of `live.rs` to
//! keep the hot loop and protocol surface in separate files.
use std::io;
use ely_servo_host::{RenderedFrame, ServoHostError, WebViewSnapshot, WebViewState};
use serde::{Deserialize, Serialize};
use thiserror::Error;
use super::perf::FramePerfSummary;
#[derive(Deserialize)]
#[serde(tag = "type", rename_all = "snake_case")]
pub(super) enum LiveRequest {
Ensure {
tab_id: String,
profile_id: String,
url: String,
width: u32,
height: u32,
page_zoom_percent: u16,
scroll_delta_x: i32,
scroll_delta_y: i32,
click_x: Option<u32>,
click_y: Option<u32>,
#[serde(default)]
hover_x: Option<u32>,
#[serde(default)]
hover_y: Option<u32>,
typed_text: Option<String>,
site_permissions: Vec<LiveSitePermission>,
},
Poll {
tab_id: String,
},
}
#[derive(Deserialize)]
pub(super) struct LiveSitePermission {
pub origin: String,
pub feature: String,
pub decision: String,
}
/// Partial stage timings captured inside `poll_frame` before the
/// write phase. Combined with the write-stage duration measured by
/// `write_outcome` to form a full set of frame timings.
#[derive(Clone, Copy, Debug)]
pub(super) struct PartialFrameTimings {
pub paint_ns: u64,
pub encode_ns: u64,
}
/// A handle plus an optional rendered frame and partial stage
/// timings. We hold the `RenderedFrame` so the write step can stream
/// its existing rgba slice straight onto the pipe — no extra
/// `to_vec()`.
pub(super) struct LiveOutcome {
pub response: LiveResponse,
pub frame: Option<RenderedFrame>,
pub partial_timings: Option<PartialFrameTimings>,
}
impl LiveOutcome {
pub fn empty() -> Self {
Self { response: LiveResponse::empty(), frame: None, partial_timings: None }
}
pub fn error(message: String) -> Self {
Self { response: LiveResponse::error(message), frame: None, partial_timings: None }
}
pub fn from_frame(
report: LiveFrameReport,
frame: RenderedFrame,
partial_timings: PartialFrameTimings,
) -> Self {
Self {
response: LiveResponse::frame(report),
frame: Some(frame),
partial_timings: Some(partial_timings),
}
}
}
#[derive(Serialize)]
pub(super) struct LiveResponse {
pub error: Option<String>,
pub frame: Option<LiveFrameReport>,
#[serde(skip_serializing_if = "Option::is_none")]
pub perf: Option<FramePerfSummary>,
}
impl LiveResponse {
fn empty() -> Self {
Self { error: None, frame: None, perf: None }
}
fn frame(frame: LiveFrameReport) -> Self {
Self { error: None, frame: Some(frame), perf: None }
}
fn error(message: String) -> Self {
Self { error: Some(message), frame: None, perf: None }
}
}
#[derive(Serialize)]
pub(super) struct LiveFrameReport {
pub loaded_url: Option<String>,
pub title: Option<String>,
pub state: &'static str,
pub width: u32,
pub height: u32,
pub rgba_byte_count: usize,
pub non_white_pixel_count: u64,
pub content_pixel_count: u64,
pub sample_hash: u64,
}
impl LiveFrameReport {
pub fn new(snapshot: &WebViewSnapshot, frame: &RenderedFrame) -> Self {
Self {
loaded_url: snapshot.url().map(str::to_string),
title: snapshot.title().map(str::to_string),
state: state_label(snapshot.state()),
width: frame.width(),
height: frame.height(),
rgba_byte_count: frame.rgba_bytes().len(),
non_white_pixel_count: frame.non_white_pixel_count(),
content_pixel_count: frame.content_pixel_count(),
sample_hash: frame.sample_hash(),
}
}
}
fn state_label(state: &WebViewState) -> &'static str {
match state {
WebViewState::Created => "created",
WebViewState::Loading => "loading",
WebViewState::Complete => "complete",
WebViewState::Sleeping => "sleeping",
WebViewState::Crashed => "crashed",
}
}
#[derive(Debug, Error)]
pub(super) enum LiveSidecarError {
#[error("live session is unavailable after creation")]
SessionUnavailable,
#[error(transparent)]
Domain(#[from] ely_domain::DomainError),
#[error(transparent)]
Host(#[from] ServoHostError),
#[error(transparent)]
Io(#[from] io::Error),
#[error(transparent)]
Json(#[from] serde_json::Error),
}
@@ -0,0 +1,275 @@
//! Per-frame paint→encode→write stage timings for the live sidecar
//! loop, plus a tiny fixed-bucket histogram that aggregates the last N
//! frames so the main process can read out p50/p95/p99 latencies.
//!
//! Why this lives next to `live.rs`: the sidecar already owns the hot
//! loop. Sampling here costs one `Instant::now()` per stage boundary
//! (single rdtsc-ish syscall) and adds no allocations on the steady
//! state path. The aggregator carries fixed-size arrays — emitting a
//! summary is a constant-time walk over 64 buckets per stage.
//!
//! The buckets are log2-spaced from 1 µs up to ~17 s
//! (`1 << 64` ns / 1000). Every observation falls into exactly one
//! bucket; the percentile pass is linear in `BUCKET_COUNT` and walks
//! the running cumulative count until it crosses the requested
//! threshold. Linear interpolation inside a bucket gives a closer
//! number than "the bucket's lower bound" without bringing in a real
//! histogram crate. Karpathy heuristic: don't add a dep when 100 lines
//! of straight Rust covers the use case.
use std::time::{Duration, Instant};
const BUCKET_COUNT: usize = 64;
/// Per-frame stage timings captured by the live loop.
///
/// `total_ns` is recorded explicitly rather than summed so we keep
/// any per-frame overhead outside the three measured stages (e.g.
/// snapshot reads, has-visible-content checks) accounted for.
#[derive(Clone, Copy, Debug)]
pub(super) struct FrameStageTimings {
pub paint_ns: u64,
pub encode_ns: u64,
pub write_ns: u64,
pub total_ns: u64,
}
impl FrameStageTimings {
pub(super) fn from_durations(
paint: Duration,
encode: Duration,
write: Duration,
total: Duration,
) -> Self {
Self {
paint_ns: duration_to_ns(paint),
encode_ns: duration_to_ns(encode),
write_ns: duration_to_ns(write),
total_ns: duration_to_ns(total),
}
}
}
fn duration_to_ns(duration: Duration) -> u64 {
u64::try_from(duration.as_nanos()).unwrap_or(u64::MAX)
}
/// Saturating elapsed-ns helper. `Instant::elapsed` is monotonic but
/// the cast can still overflow on the (impossible) hour-long frame.
pub(super) fn elapsed_ns(start: Instant) -> u64 {
duration_to_ns(start.elapsed())
}
#[derive(Clone, Copy, Debug)]
struct StageHistogram {
buckets: [u32; BUCKET_COUNT],
count: u32,
}
impl StageHistogram {
const fn new() -> Self {
Self { buckets: [0; BUCKET_COUNT], count: 0 }
}
fn record(&mut self, ns: u64) {
let bucket = bucket_for(ns);
self.buckets[bucket] = self.buckets[bucket].saturating_add(1);
self.count = self.count.saturating_add(1);
}
fn percentile_us(&self, percentile: f64) -> u64 {
if self.count == 0 {
return 0;
}
let target = ((self.count as f64) * percentile).ceil() as u32;
let target = target.max(1).min(self.count);
let mut running: u32 = 0;
for (bucket, count) in self.buckets.iter().enumerate() {
running = running.saturating_add(*count);
if running >= target {
return bucket_midpoint_us(bucket);
}
}
bucket_midpoint_us(BUCKET_COUNT - 1)
}
fn reset(&mut self) {
self.buckets = [0; BUCKET_COUNT];
self.count = 0;
}
}
fn bucket_for(ns: u64) -> usize {
if ns == 0 {
return 0;
}
let log = 64 - ns.leading_zeros() as usize;
log.min(BUCKET_COUNT - 1)
}
fn bucket_midpoint_us(bucket: usize) -> u64 {
if bucket == 0 {
return 0;
}
let low_ns = 1u64.checked_shl((bucket - 1) as u32).unwrap_or(u64::MAX);
let high_ns = 1u64.checked_shl(bucket as u32).unwrap_or(u64::MAX);
let midpoint_ns = low_ns.saturating_add(high_ns) / 2;
midpoint_ns / 1_000
}
/// Aggregates a rolling window of [`FrameStageTimings`] across N
/// frames, exposing one [`FramePerfSummary`] per window flush.
pub(super) struct FramePerfAggregator {
window_size: u32,
paint: StageHistogram,
encode: StageHistogram,
write: StageHistogram,
total: StageHistogram,
frames_in_window: u32,
context_label: &'static str,
}
impl FramePerfAggregator {
pub(super) const DEFAULT_WINDOW_SIZE: u32 = 60;
pub(super) fn new(context_label: &'static str, window_size: u32) -> Self {
Self {
window_size: window_size.max(1),
paint: StageHistogram::new(),
encode: StageHistogram::new(),
write: StageHistogram::new(),
total: StageHistogram::new(),
frames_in_window: 0,
context_label,
}
}
pub(super) fn record(&mut self, timings: FrameStageTimings) -> Option<FramePerfSummary> {
self.paint.record(timings.paint_ns);
self.encode.record(timings.encode_ns);
self.write.record(timings.write_ns);
self.total.record(timings.total_ns);
self.frames_in_window = self.frames_in_window.saturating_add(1);
if self.frames_in_window < self.window_size {
return None;
}
let summary = FramePerfSummary {
window: self.frames_in_window,
context: self.context_label,
paint_p50_us: self.paint.percentile_us(0.50),
paint_p95_us: self.paint.percentile_us(0.95),
paint_p99_us: self.paint.percentile_us(0.99),
encode_p50_us: self.encode.percentile_us(0.50),
encode_p95_us: self.encode.percentile_us(0.95),
encode_p99_us: self.encode.percentile_us(0.99),
write_p50_us: self.write.percentile_us(0.50),
write_p95_us: self.write.percentile_us(0.95),
write_p99_us: self.write.percentile_us(0.99),
total_p50_us: self.total.percentile_us(0.50),
total_p95_us: self.total.percentile_us(0.95),
total_p99_us: self.total.percentile_us(0.99),
};
self.paint.reset();
self.encode.reset();
self.write.reset();
self.total.reset();
self.frames_in_window = 0;
Some(summary)
}
}
#[derive(Clone, Copy, Debug, serde::Serialize)]
pub(super) struct FramePerfSummary {
pub window: u32,
pub context: &'static str,
pub paint_p50_us: u64,
pub paint_p95_us: u64,
pub paint_p99_us: u64,
pub encode_p50_us: u64,
pub encode_p95_us: u64,
pub encode_p99_us: u64,
pub write_p50_us: u64,
pub write_p95_us: u64,
pub write_p99_us: u64,
pub total_p50_us: u64,
pub total_p95_us: u64,
pub total_p99_us: u64,
}
#[cfg(test)]
mod tests {
use super::{FramePerfAggregator, FrameStageTimings, bucket_for, bucket_midpoint_us};
use std::time::Duration;
#[test]
fn bucket_for_handles_zero_and_small_values() {
assert_eq!(bucket_for(0), 0);
assert_eq!(bucket_for(1), 1);
assert_eq!(bucket_for(2), 2);
assert_eq!(bucket_for(3), 2);
assert_eq!(bucket_for(4), 3);
}
#[test]
fn bucket_midpoint_is_monotonic_increasing() {
let mut last = 0;
for bucket in 1..64 {
let value = bucket_midpoint_us(bucket);
assert!(value >= last, "bucket {bucket} midpoint regressed");
last = value;
}
}
#[test]
fn aggregator_emits_summary_after_window_size_records() {
let mut aggregator =
FramePerfAggregator::new("software", FramePerfAggregator::DEFAULT_WINDOW_SIZE);
for index in 0..(FramePerfAggregator::DEFAULT_WINDOW_SIZE - 1) {
let result = aggregator.record(constant_timing());
assert!(result.is_none(), "should not flush at frame {index}");
}
let summary = aggregator.record(constant_timing());
let summary = summary.expect("aggregator must flush at window boundary");
assert_eq!(summary.window, FramePerfAggregator::DEFAULT_WINDOW_SIZE);
assert_eq!(summary.context, "software");
}
#[test]
fn aggregator_resets_after_flush_so_next_window_starts_fresh() {
let mut aggregator = FramePerfAggregator::new("hardware", 2);
let _ = aggregator.record(constant_timing());
let summary = aggregator.record(constant_timing());
assert!(summary.is_some(), "expected first flush");
let after_flush = aggregator.record(constant_timing());
assert!(after_flush.is_none(), "aggregator must zero counters after flush");
}
#[test]
fn aggregator_percentiles_track_increasing_paint_durations() {
let mut aggregator = FramePerfAggregator::new("software", 4);
let paint_durations_us = [10u64, 100, 1_000, 10_000];
let mut summary = None;
for paint_us in paint_durations_us {
summary = aggregator.record(FrameStageTimings::from_durations(
Duration::from_micros(paint_us),
Duration::from_micros(1),
Duration::from_micros(1),
Duration::from_micros(paint_us + 2),
));
}
let summary = summary.expect("4-frame window must flush");
assert!(
summary.paint_p50_us < summary.paint_p99_us,
"p99 must dominate p50 for increasing samples: {summary:?}"
);
}
fn constant_timing() -> FrameStageTimings {
FrameStageTimings::from_durations(
Duration::from_micros(2_000),
Duration::from_micros(500),
Duration::from_micros(100),
Duration::from_micros(2_600),
)
}
}