#[cfg(all(test, feature = "perf-trace"))]
use std::cell::Cell;
#[cfg(feature = "perf-trace")]
use std::cell::RefCell;
use std::collections::VecDeque;
#[cfg(feature = "perf-trace")]
use std::sync::OnceLock;
use std::time::{Duration, Instant};
pub const RING_CAPACITY: usize = 120;
pub const BUDGET_60HZ: Duration = Duration::from_micros(16_667);
pub const BUDGET_120HZ: Duration = Duration::from_micros(8_333);
const EMIT_INTERVAL: Duration = Duration::from_secs(2);
#[cfg(feature = "perf-trace")]
pub fn enabled() -> bool {
static ENABLED: OnceLock<bool> = OnceLock::new();
*ENABLED
.get_or_init(|| trace_switch(option_env!("FRUST_TRACE"), runtime_trace_var().as_deref()))
}
#[cfg(not(feature = "perf-trace"))]
#[inline]
pub fn enabled() -> bool {
false
}
#[cfg(feature = "perf-trace")]
fn runtime_trace_var() -> Option<String> {
std::env::var("FRUST_TRACE").ok()
}
#[cfg(feature = "perf-trace")]
fn trace_switch(compile_time: Option<&str>, runtime: Option<&str>) -> bool {
fn is_set_non_zero(value: Option<&str>) -> bool {
matches!(value, Some(v) if v != "0")
}
is_set_non_zero(compile_time) || is_set_non_zero(runtime)
}
#[cfg(feature = "perf-trace")]
pub fn raw_enabled() -> bool {
static RAW_ENABLED: OnceLock<bool> = OnceLock::new();
*RAW_ENABLED.get_or_init(|| {
trace_switch(
option_env!("FRUST_TRACE_RAW"),
runtime_trace_raw_var().as_deref(),
)
})
}
#[cfg(not(feature = "perf-trace"))]
#[inline]
pub fn raw_enabled() -> bool {
false
}
#[cfg(feature = "perf-trace")]
fn runtime_trace_raw_var() -> Option<String> {
std::env::var("FRUST_TRACE_RAW").ok()
}
#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
pub struct FramePasses {
pub rebuild: Duration,
pub layout: Duration,
pub paint: Duration,
pub encode: Duration,
pub acquire: Duration,
pub submit: Duration,
pub skipped: bool,
pub gpu: Option<GpuPasses>,
}
#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
pub struct GpuPasses {
pub prepass: Duration,
pub main: Duration,
pub composite: Duration,
pub blit: Duration,
}
impl GpuPasses {
pub fn total(&self) -> Duration {
self.prepass
.saturating_add(self.main)
.saturating_add(self.composite)
.saturating_add(self.blit)
}
}
impl FramePasses {
pub fn total(&self) -> Duration {
self.rebuild + self.layout + self.paint + self.encode + self.acquire + self.submit
}
#[must_use]
pub fn with_gpu(mut self, gpu: GpuPasses) -> Self {
self.gpu = Some(gpu);
self
}
pub fn from_split(ui: UiSpans, render: RenderSpans) -> Self {
Self {
rebuild: ui.rebuild,
layout: ui.layout,
paint: ui.paint,
encode: render.encode,
acquire: render.acquire,
submit: render.submit,
skipped: ui.skipped,
gpu: None,
}
}
}
#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
pub struct UiSpans {
pub rebuild: Duration,
pub layout: Duration,
pub paint: Duration,
pub skipped: bool,
}
#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
pub struct RenderSpans {
pub encode: Duration,
pub acquire: Duration,
pub submit: Duration,
}
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub struct FrameSummary {
pub frame_count: usize,
pub total_p50: Duration,
pub total_p95: Duration,
pub total_p99: Duration,
pub rebuild_p95: Duration,
pub layout_p95: Duration,
pub paint_p95: Duration,
pub encode_p95: Duration,
pub acquire_p95: Duration,
pub submit_p95: Duration,
pub over_60hz_budget: u64,
pub over_120hz_budget: u64,
pub skipped_frames: u64,
}
#[derive(Debug)]
pub struct FrameStats {
enabled: bool,
#[cfg_attr(not(feature = "perf-trace"), allow(dead_code))]
raw: bool,
#[cfg_attr(not(feature = "perf-trace"), allow(dead_code))]
raw_buf: String,
ring_capacity: usize,
ring: VecDeque<FramePasses>,
total_frames: u64,
skipped_frames: u64,
over_60hz: u64,
over_120hz: u64,
since_last_emit: Duration,
#[cfg(all(test, feature = "perf-trace"))]
marker_log: Vec<String>,
}
impl FrameStats {
pub fn new() -> Self {
let is_enabled = enabled();
Self::with_capacity_enabled_and_raw(RING_CAPACITY, is_enabled, is_enabled && raw_enabled())
}
pub fn new_enabled(is_enabled: bool) -> Self {
Self::with_capacity_enabled(RING_CAPACITY, is_enabled)
}
pub fn with_capacity_enabled(capacity: usize, is_enabled: bool) -> Self {
Self::with_capacity_enabled_and_raw(capacity, is_enabled, false)
}
pub fn with_capacity_enabled_and_raw(capacity: usize, is_enabled: bool, is_raw: bool) -> Self {
let raw = is_enabled && is_raw;
Self {
enabled: is_enabled,
raw,
raw_buf: if raw {
String::with_capacity(288)
} else {
String::new()
},
ring_capacity: capacity,
ring: if is_enabled {
VecDeque::with_capacity(capacity)
} else {
VecDeque::new()
},
total_frames: 0,
skipped_frames: 0,
over_60hz: 0,
over_120hz: 0,
since_last_emit: Duration::ZERO,
#[cfg(all(test, feature = "perf-trace"))]
marker_log: Vec::new(),
}
}
pub fn record(&mut self, passes: FramePasses) {
#[cfg(feature = "devtools")]
crate::devtools::publish_frame(&passes);
if !self.enabled {
return;
}
self.total_frames += 1;
#[cfg(feature = "perf-trace")]
self.emit_scenario_markers();
if passes.skipped {
self.skipped_frames += 1;
}
let total = passes.total();
if total > BUDGET_60HZ {
self.over_60hz += 1;
}
if total > BUDGET_120HZ {
self.over_120hz += 1;
}
self.since_last_emit += total;
#[cfg(feature = "perf-trace")]
if self.raw {
format_raw_frame_line(&mut self.raw_buf, self.total_frames, &passes);
log::info!("{}", self.raw_buf);
}
if self.ring.len() == self.ring_capacity {
self.ring.pop_front();
}
self.ring.push_back(passes);
}
#[cfg(feature = "perf-trace")]
fn emit_scenario_markers(&mut self) {
let mut markers = take_staged_markers();
markers.absorb(take_pending_markers());
for marker in markers.markers {
let line = format_scenario_marker(marker.edge, &marker.name, self.total_frames);
log::info!("{line}");
#[cfg(test)]
self.marker_log.push(line);
}
if markers.dropped > 0 {
let line = format_marker_overflow_line(self.total_frames, markers.dropped);
log::warn!("{line}");
#[cfg(test)]
self.marker_log.push(line);
}
}
#[cfg(all(test, feature = "perf-trace"))]
pub(crate) fn marker_log(&self) -> &[String] {
&self.marker_log
}
pub fn total_frames(&self) -> u64 {
self.total_frames
}
pub fn summary(&self) -> FrameSummary {
let active: Vec<&FramePasses> = self.ring.iter().filter(|p| !p.skipped).collect();
let mut totals: Vec<Duration> = active.iter().map(|p| p.total()).collect();
let mut rebuilds: Vec<Duration> = active.iter().map(|p| p.rebuild).collect();
let mut layouts: Vec<Duration> = active.iter().map(|p| p.layout).collect();
let mut paints: Vec<Duration> = active.iter().map(|p| p.paint).collect();
let mut encodes: Vec<Duration> = active.iter().map(|p| p.encode).collect();
let mut acquires: Vec<Duration> = active.iter().map(|p| p.acquire).collect();
let mut submits: Vec<Duration> = active.iter().map(|p| p.submit).collect();
totals.sort_unstable();
rebuilds.sort_unstable();
layouts.sort_unstable();
paints.sort_unstable();
encodes.sort_unstable();
acquires.sort_unstable();
submits.sort_unstable();
FrameSummary {
frame_count: self.ring.len(),
total_p50: nearest_rank_percentile(&totals, 50),
total_p95: nearest_rank_percentile(&totals, 95),
total_p99: nearest_rank_percentile(&totals, 99),
rebuild_p95: nearest_rank_percentile(&rebuilds, 95),
layout_p95: nearest_rank_percentile(&layouts, 95),
paint_p95: nearest_rank_percentile(&paints, 95),
encode_p95: nearest_rank_percentile(&encodes, 95),
acquire_p95: nearest_rank_percentile(&acquires, 95),
submit_p95: nearest_rank_percentile(&submits, 95),
over_60hz_budget: self.over_60hz,
over_120hz_budget: self.over_120hz,
skipped_frames: self.skipped_frames,
}
}
pub fn should_emit(&self) -> bool {
self.enabled && self.since_last_emit >= EMIT_INTERVAL
}
pub fn emit_log(&mut self) {
if !self.enabled {
return;
}
#[cfg(feature = "perf-trace")]
{
let s = self.summary();
log::info!(
"frust-perf frame n={} total_p50_ms={} total_p95_ms={} total_p99_ms={} \
rebuild_p95_ms={} layout_p95_ms={} paint_p95_ms={} encode_p95_ms={} \
acquire_p95_ms={} submit_p95_ms={} \
over_60hz={} over_120hz={} skipped={} total_frames={}",
s.frame_count,
s.total_p50.as_millis(),
s.total_p95.as_millis(),
s.total_p99.as_millis(),
s.rebuild_p95.as_millis(),
s.layout_p95.as_millis(),
s.paint_p95.as_millis(),
s.encode_p95.as_millis(),
s.acquire_p95.as_millis(),
s.submit_p95.as_millis(),
s.over_60hz_budget,
s.over_120hz_budget,
s.skipped_frames,
self.total_frames,
);
}
self.since_last_emit = Duration::ZERO;
}
}
impl Default for FrameStats {
fn default() -> Self {
Self::new()
}
}
fn nearest_rank_percentile(sorted: &[Duration], p: u32) -> Duration {
let n = sorted.len() as u32;
if n == 0 {
return Duration::ZERO;
}
let rank = (p * n).div_ceil(100);
let rank = rank.clamp(1, n);
sorted[(rank - 1) as usize]
}
#[cfg(feature = "perf-trace")]
const RAW_FRAME_PREFIX: &str = "frust-perf raw";
#[cfg(feature = "perf-trace")]
fn format_raw_frame_line(buf: &mut String, n: u64, passes: &FramePasses) {
use std::fmt::Write as _;
buf.clear();
let _ = write!(
buf,
"{RAW_FRAME_PREFIX} n={n} total_us={} rebuild_us={} layout_us={} paint_us={} \
encode_us={} acquire_us={} submit_us={} skipped={} gpu_q={}",
passes.total().as_micros(),
passes.rebuild.as_micros(),
passes.layout.as_micros(),
passes.paint.as_micros(),
passes.encode.as_micros(),
passes.acquire.as_micros(),
passes.submit.as_micros(),
u8::from(passes.skipped),
u8::from(passes.gpu.is_some()),
);
if let Some(gpu) = passes.gpu {
let _ = write!(
buf,
" gpu_total_us={} gpu_prepass_us={} gpu_main_us={} gpu_composite_us={} \
gpu_blit_us={}",
gpu.total().as_micros(),
gpu.prepass.as_micros(),
gpu.main.as_micros(),
gpu.composite.as_micros(),
gpu.blit.as_micros(),
);
}
}
#[cfg(feature = "perf-trace")]
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
enum MarkerEdge {
Start,
End,
}
#[cfg(feature = "perf-trace")]
impl MarkerEdge {
const fn prefix(self) -> &'static str {
match self {
MarkerEdge::Start => "bench-scenario-start",
MarkerEdge::End => "bench-scenario-end",
}
}
}
#[cfg(feature = "perf-trace")]
#[derive(Debug, Clone, PartialEq, Eq)]
pub(crate) struct ScenarioMarker {
edge: MarkerEdge,
name: Box<str>,
}
#[cfg(feature = "perf-trace")]
pub(crate) const MARKER_QUEUE_CAP: usize = 256;
#[cfg(feature = "perf-trace")]
#[derive(Debug, Default)]
pub(crate) struct MarkerQueue {
markers: VecDeque<ScenarioMarker>,
dropped: u64,
}
#[cfg(feature = "perf-trace")]
impl MarkerQueue {
pub(crate) const fn new() -> Self {
Self {
markers: VecDeque::new(),
dropped: 0,
}
}
pub(crate) fn is_empty(&self) -> bool {
self.markers.is_empty() && self.dropped == 0
}
fn push(&mut self, marker: ScenarioMarker) {
if self.markers.len() >= MARKER_QUEUE_CAP {
self.markers.pop_front();
self.dropped = self.dropped.saturating_add(1);
}
self.markers.push_back(marker);
}
pub(crate) fn absorb(&mut self, other: MarkerQueue) {
self.dropped = self.dropped.saturating_add(other.dropped);
for marker in other.markers {
self.push(marker);
}
}
pub(crate) fn take(&mut self) -> MarkerQueue {
std::mem::take(self)
}
pub(crate) fn clear(&mut self) {
self.markers.clear();
self.dropped = 0;
}
}
#[cfg(feature = "perf-trace")]
thread_local! {
static PENDING: RefCell<MarkerQueue> = const { RefCell::new(MarkerQueue::new()) };
static STAGED: RefCell<MarkerQueue> = const { RefCell::new(MarkerQueue::new()) };
}
#[cfg(feature = "perf-trace")]
#[inline]
pub(crate) fn take_pending_markers() -> MarkerQueue {
if !markers_enabled() {
return MarkerQueue::new();
}
PENDING.with(|pending| pending.borrow_mut().take())
}
#[cfg(feature = "perf-trace")]
pub(crate) fn stage_markers(markers: MarkerQueue) {
if markers.is_empty() {
return;
}
STAGED.with(|staged| staged.borrow_mut().absorb(markers));
}
#[cfg(feature = "perf-trace")]
fn take_staged_markers() -> MarkerQueue {
STAGED.with(|staged| {
let mut staged = staged.borrow_mut();
if staged.is_empty() {
MarkerQueue::new()
} else {
staged.take()
}
})
}
#[cfg(all(test, feature = "perf-trace"))]
thread_local! {
static MARKERS_FORCE_ENABLED: Cell<bool> = const { Cell::new(false) };
}
#[cfg(all(test, feature = "perf-trace"))]
pub(crate) struct MarkerTestGuard {
_private: (),
}
#[cfg(all(test, feature = "perf-trace"))]
impl Drop for MarkerTestGuard {
fn drop(&mut self) {
MARKERS_FORCE_ENABLED.with(|forced| forced.set(false));
reset_marker_route();
}
}
#[cfg(all(test, feature = "perf-trace"))]
fn reset_marker_route() {
PENDING.with(|pending| pending.borrow_mut().clear());
STAGED.with(|staged| staged.borrow_mut().clear());
}
#[cfg(all(test, feature = "perf-trace"))]
pub(crate) fn marker_test_guard(force_enabled: bool) -> MarkerTestGuard {
reset_marker_route();
MARKERS_FORCE_ENABLED.with(|forced| forced.set(force_enabled));
MarkerTestGuard { _private: () }
}
#[cfg(feature = "perf-trace")]
#[inline]
fn markers_enabled() -> bool {
#[cfg(test)]
if MARKERS_FORCE_ENABLED.with(Cell::get) {
return true;
}
enabled()
}
#[cfg(feature = "perf-trace")]
fn push_marker(edge: MarkerEdge, name: &str) {
if !markers_enabled() {
return;
}
PENDING.with(|pending| {
pending.borrow_mut().push(ScenarioMarker {
edge,
name: name.into(),
});
});
}
#[cfg(feature = "perf-trace")]
fn format_scenario_marker(edge: MarkerEdge, name: &str, frame: u64) -> String {
format!("{} n={frame} {name}", edge.prefix())
}
#[cfg(feature = "perf-trace")]
const MARKER_OVERFLOW_PREFIX: &str = "frust-perf marker-overflow";
#[cfg(feature = "perf-trace")]
fn format_marker_overflow_line(frame: u64, dropped: u64) -> String {
format!("{MARKER_OVERFLOW_PREFIX} n={frame} dropped={dropped}")
}
#[cfg_attr(not(feature = "perf-trace"), allow(unused_variables))]
pub fn mark_scenario_start(name: &str) {
#[cfg(feature = "perf-trace")]
push_marker(MarkerEdge::Start, name);
}
#[cfg_attr(not(feature = "perf-trace"), allow(unused_variables))]
pub fn mark_scenario_end(name: &str) {
#[cfg(feature = "perf-trace")]
push_marker(MarkerEdge::End, name);
}
#[cfg_attr(not(feature = "perf-trace"), allow(unused_variables))]
pub fn bench_emit(line: &str) {
#[cfg(feature = "perf-trace")]
if enabled() && raw_enabled() {
log::info!("{line}");
}
}
pub const SPAN_NATIVE_LIB_LOAD: &str = "native_lib_load";
pub const SPAN_INIT_ENTRY: &str = "init_entry";
pub const SPAN_ADAPTER_READY: &str = "adapter_ready";
pub const SPAN_DEVICE_READY: &str = "device_ready";
pub const SPAN_RENDERER_READY: &str = "renderer_ready";
pub const SPAN_PIPELINE_CACHE_RESTORED: &str = "pipeline_cache_restored";
pub const SPAN_FIRST_REBUILD_DONE: &str = "first_rebuild_done";
pub const SPAN_FIRST_ENCODE_DONE: &str = "first_encode_done";
pub const SPAN_FIRST_FRAME_PRESENTED: &str = "first_frame_presented";
pub trait Clock {
fn now(&mut self) -> Duration;
}
impl<F: FnMut() -> Duration> Clock for F {
fn now(&mut self) -> Duration {
self()
}
}
#[derive(Debug)]
pub struct SystemClock {
start: Instant,
}
impl SystemClock {
pub fn new() -> Self {
Self {
start: Instant::now(),
}
}
}
impl Default for SystemClock {
fn default() -> Self {
Self::new()
}
}
impl Clock for SystemClock {
fn now(&mut self) -> Duration {
self.start.elapsed()
}
}
pub struct StartupSpans<C: Clock = SystemClock> {
enabled: bool,
clock: C,
begin: Duration,
spans: Vec<(&'static str, Duration)>,
}
impl StartupSpans<SystemClock> {
pub fn begin() -> Self {
Self::begin_with_enabled(SystemClock::new(), enabled())
}
}
impl<C: Clock> StartupSpans<C> {
pub fn begin_with_enabled(mut clock: C, is_enabled: bool) -> Self {
let begin = clock.now();
Self {
enabled: is_enabled,
clock,
begin,
spans: Vec::new(),
}
}
pub fn record(&mut self, name: &'static str) {
if !self.enabled {
return;
}
let now = self.clock.now();
self.spans.push((name, now.saturating_sub(self.begin)));
}
pub fn spans(&self) -> &[(&'static str, Duration)] {
&self.spans
}
pub fn emit_log(&self) {
if self.enabled && !self.spans.is_empty() {
#[cfg(feature = "perf-trace")]
{
let mut line = String::from("frust-perf startup");
for (name, delta) in &self.spans {
line.push_str(&format!(" {name}={}ms", delta.as_millis()));
}
log::info!("{line}");
}
}
}
}
#[cfg(test)]
mod tests {
use super::*;
#[cfg(feature = "perf-trace")]
#[test]
fn trace_switch_off_when_neither_set() {
assert!(!trace_switch(None, None));
}
#[cfg(feature = "perf-trace")]
#[test]
fn trace_switch_on_when_compile_time_set_non_zero() {
assert!(trace_switch(Some("1"), None));
}
#[cfg(feature = "perf-trace")]
#[test]
fn trace_switch_on_when_runtime_set_non_zero() {
assert!(trace_switch(None, Some("1")));
}
#[cfg(feature = "perf-trace")]
#[test]
fn trace_switch_off_when_either_is_literal_zero_and_other_unset() {
assert!(!trace_switch(Some("0"), None));
assert!(!trace_switch(None, Some("0")));
}
#[cfg(feature = "perf-trace")]
#[test]
fn trace_switch_on_when_either_source_wins() {
assert!(trace_switch(Some("0"), Some("1")));
assert!(trace_switch(Some("1"), Some("0")));
}
#[cfg(not(feature = "perf-trace"))]
#[test]
fn enabled_and_raw_enabled_are_const_false_without_feature() {
assert!(!enabled(), "perf-trace off ⇒ enabled() is a false constant");
assert!(
!raw_enabled(),
"perf-trace off ⇒ raw_enabled() is a false constant"
);
}
#[cfg(not(feature = "perf-trace"))]
#[test]
fn disabled_build_public_api_is_callable_and_inert() {
let mut stats = FrameStats::new();
stats.record(passes(20, 5, 5, 2));
assert_eq!(stats.total_frames(), 0, "feature-off new() is disabled");
assert_eq!(stats.summary().frame_count, 0);
assert!(!stats.should_emit());
stats.emit_log();
let mut spans = StartupSpans::begin();
spans.record(SPAN_INIT_ENTRY);
assert!(spans.spans().is_empty(), "feature-off begin() is disabled");
spans.emit_log();
mark_scenario_start("smoke");
mark_scenario_end("smoke");
bench_emit("smoke op=write");
}
#[test]
fn percentile_known_distribution_1_to_100ms() {
let sorted: Vec<Duration> = (1..=100).map(Duration::from_millis).collect();
assert_eq!(
nearest_rank_percentile(&sorted, 50),
Duration::from_millis(50)
);
assert_eq!(
nearest_rank_percentile(&sorted, 95),
Duration::from_millis(95)
);
assert_eq!(
nearest_rank_percentile(&sorted, 99),
Duration::from_millis(99)
);
}
#[test]
fn percentile_small_sample_rounds_up_rank() {
let sorted: Vec<Duration> = (1..=4).map(Duration::from_millis).collect();
assert_eq!(
nearest_rank_percentile(&sorted, 50),
Duration::from_millis(2)
);
assert_eq!(
nearest_rank_percentile(&sorted, 95),
Duration::from_millis(4)
);
}
#[test]
fn percentile_single_value_returns_it_for_every_percentile() {
let sorted = [Duration::from_millis(42)];
assert_eq!(
nearest_rank_percentile(&sorted, 50),
Duration::from_millis(42)
);
assert_eq!(
nearest_rank_percentile(&sorted, 99),
Duration::from_millis(42)
);
}
#[test]
fn percentile_empty_sample_is_zero() {
assert_eq!(nearest_rank_percentile(&[], 50), Duration::ZERO);
}
fn passes(rebuild_ms: u64, layout_ms: u64, paint_ms: u64, encode_ms: u64) -> FramePasses {
FramePasses {
rebuild: Duration::from_millis(rebuild_ms),
layout: Duration::from_millis(layout_ms),
paint: Duration::from_millis(paint_ms),
encode: Duration::from_millis(encode_ms),
acquire: Duration::ZERO,
submit: Duration::ZERO,
skipped: false,
gpu: None,
}
}
#[test]
fn disabled_recorder_records_nothing_and_never_allocates() {
let mut stats = FrameStats::new_enabled(false);
for _ in 0..500 {
stats.record(passes(20, 5, 5, 2));
}
assert_eq!(stats.total_frames(), 0);
assert_eq!(
stats.ring.capacity(),
0,
"disabled recorder must never reserve ring capacity"
);
let s = stats.summary();
assert_eq!(s.frame_count, 0);
assert_eq!(s.total_p50, Duration::ZERO);
assert!(!stats.should_emit());
}
#[test]
fn over_budget_counters_are_exact() {
let mut stats = FrameStats::new_enabled(true);
stats.record(passes(2, 1, 1, 1));
stats.record(passes(4, 2, 2, 2));
stats.record(passes(10, 5, 3, 2));
let s = stats.summary();
assert_eq!(
s.over_120hz_budget, 2,
"10ms and 20ms frames exceed the 8.3ms budget"
);
assert_eq!(
s.over_60hz_budget, 1,
"only the 20ms frame exceeds the 16.6ms budget"
);
}
#[test]
fn skipped_frames_counted_but_excluded_from_percentiles() {
let mut stats = FrameStats::new_enabled(true);
stats.record(passes(10, 2, 2, 2)); stats.record(FramePasses {
skipped: true,
..Default::default()
}); stats.record(passes(10, 2, 2, 2));
let s = stats.summary();
assert_eq!(s.skipped_frames, 1);
assert_eq!(stats.total_frames(), 3);
assert_eq!(s.frame_count, 3, "ring buffer holds all recorded frames...");
assert_eq!(
s.total_p50,
Duration::from_millis(16),
"...but percentiles exclude the skipped one"
);
}
#[test]
fn summary_attributes_encode_acquire_and_submit_spans_separately() {
let mut stats = FrameStats::new_enabled(true);
stats.record(FramePasses {
rebuild: Duration::from_millis(2),
layout: Duration::from_millis(1),
paint: Duration::from_millis(1),
encode: Duration::from_millis(6),
acquire: Duration::from_millis(9),
submit: Duration::from_millis(3),
skipped: false,
gpu: None,
});
let s = stats.summary();
assert_eq!(
s.encode_p95,
Duration::from_millis(6),
"encode span attributed"
);
assert_eq!(
s.acquire_p95,
Duration::from_millis(9),
"acquire span attributed"
);
assert_eq!(
s.submit_p95,
Duration::from_millis(3),
"submit span attributed"
);
assert_eq!(s.total_p95, Duration::from_millis(22));
}
#[test]
fn from_split_recombines_the_two_half_frames_without_changing_the_record() {
let ui = UiSpans {
rebuild: Duration::from_millis(2),
layout: Duration::from_millis(1),
paint: Duration::from_millis(1),
skipped: false,
};
let render = RenderSpans {
encode: Duration::from_millis(6),
acquire: Duration::from_millis(9),
submit: Duration::from_millis(3),
};
let split = FramePasses::from_split(ui, render);
let whole = FramePasses {
rebuild: Duration::from_millis(2),
layout: Duration::from_millis(1),
paint: Duration::from_millis(1),
encode: Duration::from_millis(6),
acquire: Duration::from_millis(9),
submit: Duration::from_millis(3),
skipped: false,
gpu: None,
};
assert_eq!(split, whole, "split reassembly must equal the whole frame");
assert_eq!(split.total(), Duration::from_millis(22));
}
#[cfg(feature = "perf-trace")]
#[test]
fn from_split_v3_wire_format_is_identical_to_single_thread() {
let ui = UiSpans {
rebuild: Duration::from_millis(2),
layout: Duration::from_millis(1),
paint: Duration::from_millis(1),
skipped: false,
};
let render = RenderSpans {
encode: Duration::from_millis(6),
acquire: Duration::from_millis(9),
submit: Duration::from_millis(3),
};
let split = FramePasses::from_split(ui, render);
let whole = FramePasses {
rebuild: Duration::from_millis(2),
layout: Duration::from_millis(1),
paint: Duration::from_millis(1),
encode: Duration::from_millis(6),
acquire: Duration::from_millis(9),
submit: Duration::from_millis(3),
skipped: false,
gpu: None,
};
let mut split_line = String::new();
let mut whole_line = String::new();
format_raw_frame_line(&mut split_line, 1, &split);
format_raw_frame_line(&mut whole_line, 1, &whole);
assert_eq!(
split_line, whole_line,
"v3 wire format is unchanged by the split"
);
}
#[test]
fn from_split_preserves_the_ui_side_skipped_verdict() {
let ui = UiSpans {
skipped: true,
..Default::default()
};
let split = FramePasses::from_split(ui, RenderSpans::default());
assert!(split.skipped, "the UI-side skip verdict must be preserved");
assert_eq!(split.total(), Duration::ZERO);
}
#[test]
fn ring_buffer_evicts_oldest_beyond_capacity() {
let mut stats = FrameStats::with_capacity_enabled(3, true);
stats.record(passes(1, 0, 0, 0));
stats.record(passes(2, 0, 0, 0));
stats.record(passes(3, 0, 0, 0));
stats.record(passes(4, 0, 0, 0));
let s = stats.summary();
assert_eq!(s.frame_count, 3);
assert_eq!(s.total_p50, Duration::from_millis(3));
assert_eq!(stats.total_frames(), 4);
}
#[test]
fn should_emit_rate_limits_on_accumulated_frame_time() {
let mut stats = FrameStats::new_enabled(true);
assert!(!stats.should_emit());
for _ in 0..100 {
stats.record(passes(10, 3, 2, 1));
}
assert!(!stats.should_emit());
for _ in 0..25 {
stats.record(passes(10, 3, 2, 1));
}
assert!(stats.should_emit());
stats.emit_log();
assert!(!stats.should_emit(), "emit_log resets the accumulator");
}
#[test]
fn a_reassembled_split_frame_carries_no_gpu_reading_until_one_is_attached() {
let split = FramePasses::from_split(
UiSpans {
rebuild: Duration::from_millis(2),
..Default::default()
},
RenderSpans {
encode: Duration::from_millis(6),
acquire: Duration::from_millis(9),
submit: Duration::from_millis(3),
},
);
assert_eq!(split.gpu, None, "neither half measures GPU time");
let gpu = GpuPasses {
prepass: Duration::from_micros(10),
main: Duration::from_micros(20),
composite: Duration::from_micros(30),
blit: Duration::from_micros(40),
};
let timed = split.with_gpu(gpu);
assert_eq!(timed.gpu, Some(gpu));
assert_eq!(timed.total(), split.total(), "GPU time is not frame time");
assert_eq!(gpu.total(), Duration::from_micros(100));
assert_eq!(FramePasses { gpu: None, ..timed }, split);
}
#[test]
fn an_all_zero_gpu_reading_is_still_a_reading() {
let timed = FramePasses::default().with_gpu(GpuPasses::default());
assert_eq!(timed.gpu, Some(GpuPasses::default()));
assert_eq!(timed.gpu.map(|gpu| gpu.total()), Some(Duration::ZERO));
assert_eq!(FramePasses::default().gpu, None);
}
#[cfg(feature = "perf-trace")]
struct ParsedRawFrameLine {
n: u64,
total_us: u128,
rebuild_us: u128,
layout_us: u128,
paint_us: u128,
encode_us: u128,
acquire_us: u128,
submit_us: u128,
skipped: bool,
gpu_q: bool,
gpu: Vec<(String, u128)>,
}
#[cfg(feature = "perf-trace")]
fn parse_raw_frame_line(line: &str) -> Option<ParsedRawFrameLine> {
let rest = line.strip_prefix(RAW_FRAME_PREFIX)?.trim_start();
let mut n = None;
let mut total_us = None;
let mut rebuild_us = None;
let mut layout_us = None;
let mut paint_us = None;
let mut encode_us = None;
let mut acquire_us = None;
let mut submit_us = None;
let mut skipped = None;
let mut gpu_q = None;
let mut gpu = Vec::new();
for field in rest.split_whitespace() {
let (key, value) = field.split_once('=')?;
match key {
"n" => n = value.parse().ok(),
"total_us" => total_us = value.parse().ok(),
"rebuild_us" => rebuild_us = value.parse().ok(),
"layout_us" => layout_us = value.parse().ok(),
"paint_us" => paint_us = value.parse().ok(),
"encode_us" => encode_us = value.parse().ok(),
"acquire_us" => acquire_us = value.parse().ok(),
"submit_us" => submit_us = value.parse().ok(),
"skipped" => skipped = value.parse::<u8>().ok().map(|v| v != 0),
"gpu_q" => gpu_q = value.parse::<u8>().ok().map(|v| v != 0),
other if other.starts_with("gpu_") => {
gpu.push((other.to_string(), value.parse().ok()?));
}
_ => {}
}
}
Some(ParsedRawFrameLine {
n: n?,
total_us: total_us?,
rebuild_us: rebuild_us?,
layout_us: layout_us?,
paint_us: paint_us?,
encode_us: encode_us?,
acquire_us: acquire_us?,
submit_us: submit_us?,
skipped: skipped?,
gpu_q: gpu_q?,
gpu,
})
}
#[cfg(feature = "perf-trace")]
#[test]
fn raw_frame_line_format_round_trips() {
let mut buf = String::new();
let p = FramePasses {
rebuild: Duration::from_micros(1234),
layout: Duration::from_micros(200),
paint: Duration::from_micros(300),
encode: Duration::from_micros(50),
acquire: Duration::from_micros(80),
submit: Duration::from_micros(40),
skipped: false,
gpu: None,
};
format_raw_frame_line(&mut buf, 42, &p);
assert!(buf.starts_with(RAW_FRAME_PREFIX));
let parsed = parse_raw_frame_line(&buf).expect("line must parse");
assert_eq!(parsed.n, 42);
assert_eq!(parsed.total_us, p.total().as_micros());
assert_eq!(parsed.rebuild_us, 1234);
assert_eq!(parsed.layout_us, 200);
assert_eq!(parsed.paint_us, 300);
assert_eq!(parsed.encode_us, 50);
assert_eq!(parsed.acquire_us, 80);
assert_eq!(parsed.submit_us, 40);
assert!(!parsed.skipped);
assert!(!parsed.gpu_q, "a frame with no GPU reading reports gpu_q=0");
}
#[cfg(feature = "perf-trace")]
#[test]
fn a_frame_without_a_gpu_reading_writes_gpu_q_zero_and_no_gpu_columns() {
let mut buf = String::new();
format_raw_frame_line(&mut buf, 3, &passes(10, 2, 2, 2));
assert!(buf.contains(" gpu_q=0"));
assert!(
!buf.contains("gpu_total_us"),
"no gpu_* column may be emitted without a reading: {buf}"
);
let parsed = parse_raw_frame_line(&buf).expect("line must parse");
assert!(!parsed.gpu_q);
assert!(parsed.gpu.is_empty());
}
#[cfg(feature = "perf-trace")]
#[test]
fn a_gpu_timed_frame_appends_every_span_in_the_declared_order() {
let gpu = GpuPasses {
prepass: Duration::from_micros(120),
main: Duration::from_micros(2400),
composite: Duration::from_micros(650),
blit: Duration::from_micros(75),
};
let mut buf = String::new();
format_raw_frame_line(&mut buf, 9, &passes(4, 1, 1, 2).with_gpu(gpu));
let parsed = parse_raw_frame_line(&buf).expect("line must parse");
assert!(parsed.gpu_q);
assert_eq!(
parsed.gpu,
vec![
("gpu_total_us".to_string(), 3245),
("gpu_prepass_us".to_string(), 120),
("gpu_main_us".to_string(), 2400),
("gpu_composite_us".to_string(), 650),
("gpu_blit_us".to_string(), 75),
],
"field order is wire contract: {buf}"
);
assert_eq!(gpu.total(), Duration::from_micros(3245));
}
#[cfg(feature = "perf-trace")]
#[test]
fn the_v3_prefix_of_a_v4_line_is_byte_identical() {
let base = passes(4, 1, 1, 2);
let mut v3_line = String::new();
let mut v4_line = String::new();
format_raw_frame_line(&mut v3_line, 11, &base);
format_raw_frame_line(
&mut v4_line,
11,
&base.with_gpu(GpuPasses {
main: Duration::from_micros(1),
..GpuPasses::default()
}),
);
let (v3_head, v3_marker) = v3_line
.rsplit_once(" gpu_q=")
.expect("every v4 line carries the marker");
assert_eq!(v3_marker, "0");
assert!(
v4_line.starts_with(v3_head),
"the v3 field set must be byte-identical:\n{v3_line}\n{v4_line}"
);
}
#[cfg(feature = "perf-trace")]
#[test]
fn a_gpu_timed_frames_total_excludes_the_gpu_spans() {
let base = passes(4, 1, 1, 2);
let timed = base.with_gpu(GpuPasses {
main: Duration::from_millis(50),
..GpuPasses::default()
});
assert_eq!(timed.total(), base.total());
let mut buf = String::new();
format_raw_frame_line(&mut buf, 1, &timed);
let parsed = parse_raw_frame_line(&buf).expect("line must parse");
assert_eq!(parsed.total_us, base.total().as_micros());
}
#[cfg(feature = "perf-trace")]
#[test]
fn raw_frame_line_represents_skipped_flag() {
let mut buf = String::new();
let p = FramePasses {
skipped: true,
..Default::default()
};
format_raw_frame_line(&mut buf, 7, &p);
let parsed = parse_raw_frame_line(&buf).expect("line must parse");
assert!(parsed.skipped, "skipped frame must still be represented");
assert_eq!(parsed.total_us, 0);
assert_eq!(parsed.n, 7);
}
#[cfg(feature = "perf-trace")]
#[test]
fn raw_enabled_record_formats_one_line_per_frame() {
let mut stats = FrameStats::with_capacity_enabled_and_raw(4, true, true);
stats.record(passes(10, 2, 2, 2));
let parsed = parse_raw_frame_line(&stats.raw_buf).expect("line must parse");
assert_eq!(parsed.n, 1);
stats.record(passes(5, 1, 1, 1));
let parsed = parse_raw_frame_line(&stats.raw_buf).expect("line must parse");
assert_eq!(parsed.n, 2, "frame index advances per recorded frame");
}
#[test]
fn raw_disabled_record_never_touches_raw_line_buffer() {
let mut stats = FrameStats::with_capacity_enabled_and_raw(4, true, false);
for _ in 0..5 {
stats.record(passes(1, 1, 1, 1));
}
assert!(
stats.raw_buf.is_empty(),
"raw-export off must never format into the raw line buffer"
);
assert_eq!(stats.total_frames(), 5, "non-raw recording still happens");
}
#[test]
fn raw_requires_enabled_too() {
let mut stats = FrameStats::with_capacity_enabled_and_raw(4, false, true);
stats.record(passes(10, 2, 2, 2));
assert_eq!(stats.total_frames(), 0, "disabled recorder still no-ops");
assert!(stats.raw_buf.is_empty());
}
#[cfg(feature = "perf-trace")]
#[test]
fn scenario_marker_format_start_and_end() {
assert_eq!(
format_scenario_marker(MarkerEdge::Start, "cold_start", 5),
"bench-scenario-start n=5 cold_start"
);
assert_eq!(
format_scenario_marker(MarkerEdge::End, "cold_start", 6),
"bench-scenario-end n=6 cold_start"
);
}
#[cfg(feature = "perf-trace")]
#[test]
fn markers_raised_while_perf_is_disabled_accumulate_nothing() {
let _guard = marker_test_guard(false);
mark_scenario_start("smoke");
mark_scenario_end("smoke");
assert!(
take_pending_markers().is_empty(),
"a disabled marker must never reach the queue"
);
}
#[cfg(feature = "perf-trace")]
#[test]
fn inline_executor_drains_this_threads_pending_queue_at_record() {
let _guard = marker_test_guard(true);
let mut stats = FrameStats::with_capacity_enabled_and_raw(4, true, true);
mark_scenario_start("s3-create1k");
stats.record(passes(10, 2, 2, 2));
assert_eq!(
stats.marker_log(),
["bench-scenario-start n=1 s3-create1k"],
"the marker rides the frame being recorded when it was raised"
);
mark_scenario_end("s3-create1k");
stats.record(passes(10, 2, 2, 2));
assert_eq!(
stats.marker_log(),
[
"bench-scenario-start n=1 s3-create1k",
"bench-scenario-end n=2 s3-create1k",
]
);
stats.record(passes(10, 2, 2, 2));
assert_eq!(stats.marker_log().len(), 2);
assert_eq!(stats.total_frames(), 3);
}
#[cfg(feature = "perf-trace")]
#[test]
fn markers_are_emitted_with_raw_export_off() {
let _guard = marker_test_guard(true);
let mut stats = FrameStats::with_capacity_enabled_and_raw(4, true, false);
mark_scenario_start("s8-write");
stats.record(passes(10, 2, 2, 2));
assert_eq!(stats.marker_log(), ["bench-scenario-start n=1 s8-write"]);
assert!(
stats.raw_buf.is_empty(),
"raw export stays off — only the marker line was emitted"
);
}
#[cfg(feature = "perf-trace")]
#[test]
fn a_disabled_recorder_emits_no_marker_line() {
let _guard = marker_test_guard(true);
let mut stats = FrameStats::with_capacity_enabled_and_raw(4, false, true);
mark_scenario_start("s3-update");
stats.record(passes(10, 2, 2, 2));
assert!(stats.marker_log().is_empty());
assert_eq!(stats.total_frames(), 0);
}
#[cfg(feature = "perf-trace")]
#[test]
fn staged_markers_ride_the_next_recorded_frame_in_order() {
let _guard = marker_test_guard(true);
let mut stats = FrameStats::with_capacity_enabled_and_raw(4, true, true);
mark_scenario_start("s3-clear");
mark_scenario_end("s3-clear");
stage_markers(take_pending_markers());
stats.record(passes(10, 2, 2, 2));
assert_eq!(
stats.marker_log(),
[
"bench-scenario-start n=1 s3-clear",
"bench-scenario-end n=1 s3-clear",
],
"both edges collapsing onto one frame is the empty half-open \
window a dropped op frame honestly produces"
);
stats.record(passes(10, 2, 2, 2));
assert_eq!(stats.marker_log().len(), 2, "staged markers emit once");
}
#[cfg(feature = "perf-trace")]
#[test]
fn stage_markers_of_an_empty_batch_is_a_no_op() {
let _guard = marker_test_guard(true);
let mut stats = FrameStats::with_capacity_enabled_and_raw(4, true, true);
stage_markers(take_pending_markers());
stats.record(passes(10, 2, 2, 2));
assert!(stats.marker_log().is_empty());
}
#[cfg(feature = "perf-trace")]
#[test]
fn an_overflowing_queue_drops_the_oldest_markers_and_reports_the_count() {
let _guard = marker_test_guard(true);
let mut stats = FrameStats::with_capacity_enabled_and_raw(4, true, true);
let raised = MARKER_QUEUE_CAP + 3;
for i in 0..raised {
mark_scenario_start(&format!("s3-op{i}"));
}
stats.record(passes(10, 2, 2, 2));
let log = stats.marker_log();
assert_eq!(
log.len(),
MARKER_QUEUE_CAP + 1,
"a capped queue's worth of markers, plus one overflow notice"
);
assert_eq!(
log[0], "bench-scenario-start n=1 s3-op3",
"the three OLDEST were dropped, and the survivors keep the \
unannotated marker shape"
);
assert_eq!(
log[MARKER_QUEUE_CAP - 1],
format!("bench-scenario-start n=1 s3-op{}", raised - 1),
"the newest raised marker survived"
);
assert_eq!(
log[MARKER_QUEUE_CAP],
"frust-perf marker-overflow n=1 dropped=3"
);
mark_scenario_end("s3-done");
stats.record(passes(10, 2, 2, 2));
assert_eq!(
stats.marker_log()[MARKER_QUEUE_CAP + 1..],
["bench-scenario-end n=2 s3-done"]
);
}
#[test]
fn disabled_should_emit_and_emit_log_are_no_ops() {
let mut stats = FrameStats::new_enabled(false);
assert!(!stats.should_emit());
stats.emit_log(); assert_eq!(stats.total_frames(), 0);
}
struct FakeClock {
elapsed: Duration,
step: Duration,
}
impl Clock for FakeClock {
fn now(&mut self) -> Duration {
let now = self.elapsed;
self.elapsed += self.step;
now
}
}
#[test]
fn spans_recorded_in_order_with_monotonic_nonnegative_deltas() {
let clock = FakeClock {
elapsed: Duration::ZERO,
step: Duration::from_millis(10),
};
let mut spans = StartupSpans::begin_with_enabled(clock, true);
spans.record(SPAN_INIT_ENTRY);
spans.record(SPAN_ADAPTER_READY);
spans.record(SPAN_DEVICE_READY);
spans.record(SPAN_RENDERER_READY);
let recorded = spans.spans();
assert_eq!(recorded.len(), 4);
assert_eq!(recorded[0].0, SPAN_INIT_ENTRY);
assert_eq!(recorded[3].0, SPAN_RENDERER_READY);
let mut last = Duration::ZERO;
for (_, delta) in recorded {
assert!(*delta >= last, "deltas must be non-decreasing");
assert!(*delta >= Duration::ZERO);
last = *delta;
}
assert_eq!(recorded[0].1, Duration::from_millis(10));
assert_eq!(recorded[1].1, Duration::from_millis(20));
assert_eq!(recorded[2].1, Duration::from_millis(30));
assert_eq!(recorded[3].1, Duration::from_millis(40));
}
#[test]
fn disabled_spans_record_nothing() {
let clock = FakeClock {
elapsed: Duration::ZERO,
step: Duration::from_millis(10),
};
let mut spans = StartupSpans::begin_with_enabled(clock, false);
spans.record(SPAN_INIT_ENTRY);
assert!(spans.spans().is_empty());
spans.emit_log(); }
#[test]
fn closure_clock_satisfies_clock_trait() {
let mut n = 0u64;
let clock = move || {
n += 10;
Duration::from_millis(n)
};
let mut spans = StartupSpans::begin_with_enabled(clock, true);
spans.record(SPAN_FIRST_REBUILD_DONE);
spans.record(SPAN_FIRST_FRAME_PRESENTED);
assert_eq!(spans.spans().len(), 2);
assert!(spans.spans()[1].1 >= spans.spans()[0].1);
}
}