diff --git a/Cargo.lock b/Cargo.lock index e3c5696e..d27868a4 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -4383,6 +4383,7 @@ version = "0.1.0" dependencies = [ "bevy", "half", + "serde_json", "skate-core", "skate-data", ] diff --git a/crates/skate-game/Cargo.toml b/crates/skate-game/Cargo.toml index 709c3d7e..aba17f63 100644 --- a/crates/skate-game/Cargo.toml +++ b/crates/skate-game/Cargo.toml @@ -9,3 +9,4 @@ bevy.workspace = true skate-core.workspace = true skate-data.workspace = true half = "=2.7.1" +serde_json.workspace = true diff --git a/crates/skate-game/src/app.rs b/crates/skate-game/src/app.rs index f19c2b3d..64b4106e 100644 --- a/crates/skate-game/src/app.rs +++ b/crates/skate-game/src/app.rs @@ -95,6 +95,7 @@ pub(crate) fn build( world::WorldPlugin, camera::CameraPlugin, verification::VerificationPlugin, + crate::performance::PerformancePlugin, )); app } diff --git a/crates/skate-game/src/main.rs b/crates/skate-game/src/main.rs index 5923cd48..7d4ae50b 100644 --- a/crates/skate-game/src/main.rs +++ b/crates/skate-game/src/main.rs @@ -10,6 +10,7 @@ mod input; mod physics; mod skater_animation; mod verification; +mod performance; mod world; mod skate_world; diff --git a/crates/skate-game/src/performance.rs b/crates/skate-game/src/performance.rs new file mode 100644 index 00000000..bbd23e1e --- /dev/null +++ b/crates/skate-game/src/performance.rs @@ -0,0 +1,103 @@ +//! Opt-in repeatable frame/physics timing: SKATE_PERF_REPORT=path.json. +use bevy::prelude::*; +use std::{path::PathBuf, time::Instant}; +use std::sync::{Arc, Mutex}; +use bevy::render::{Render, RenderApp, RenderSystems}; + +#[derive(Resource)] +pub(crate) struct Performance { + path: PathBuf, + start: Option, + frame_start: Instant, + previous: Instant, + physics_ms: f64, + ticks: u32, + samples: Vec<[f64; 4]>, + render: Arc>>, +} +impl Performance { + pub(crate) fn physics(&mut self, elapsed: std::time::Duration) { + self.physics_ms += elapsed.as_secs_f64() * 1000.; + self.ticks += 1; + } +} + +pub(crate) struct PerformancePlugin; +impl Plugin for PerformancePlugin { + fn build(&self, app: &mut App) { + let Some(path) = std::env::var_os("SKATE_PERF_REPORT") else { return; }; + let now = Instant::now(); + let render = Arc::new(Mutex::new(Vec::new())); + if let Some(render_app) = app.get_sub_app_mut(RenderApp) { + render_app.insert_resource(RenderPerformance { start: None, frame: now, prepared: now, samples: render.clone() }) + .add_systems(Render, render_begin.before(RenderSystems::ExtractCommands)) + .add_systems(Render, render_prepared.after(RenderSystems::Prepare).before(RenderSystems::Render)) + .add_systems(Render, render_finish.after(RenderSystems::PostCleanup)); + } + // Benchmark measurements must not depend on whether the window has focus. + app.insert_resource(bevy::winit::WinitSettings::continuous()); + app.insert_resource(Performance { + path: path.into(), start: None, frame_start: now, previous: now, + physics_ms: 0., ticks: 0, samples: Vec::new(), render, + }).add_systems(First, begin).add_systems(Last, finish); + } +} +fn begin(mut p: ResMut) { + p.frame_start = Instant::now(); + p.physics_ms = 0.; + p.ticks = 0; +} +fn finish(mut p: ResMut, mut exit: MessageWriter) { + let now = Instant::now(); + let elapsed = now.duration_since(*p.start.get_or_insert(now)).as_secs_f64(); + let frame = now.duration_since(p.previous).as_secs_f64() * 1000.; + p.previous = now; + // Exclude initialization and shader warmup. Frame interval includes render + // synchronization; CPU schedule time is First..Last of the main world. + if elapsed > 10. { + let sample = [frame, now.duration_since(p.frame_start).as_secs_f64() * 1000., p.physics_ms, f64::from(p.ticks)]; + p.samples.push(sample); + } + if elapsed > 25. && !p.samples.is_empty() { + let mean = |column: usize| p.samples.iter().map(|s| s[column]).sum::() / p.samples.len() as f64; + let mut frames: Vec<_> = p.samples.iter().map(|s| s[0]).collect(); + frames.sort_by(f64::total_cmp); + let render = p.render.lock().unwrap(); + let render_mean = |column: usize| render.iter().map(|s| s[column]).sum::() / render.len().max(1) as f64; + let report = serde_json::json!({ + "frames": frames.len(), "fps": 1000. / mean(0), + "frame_ms_mean": mean(0), "frame_ms_median": frames[frames.len()/2], + "frame_ms_p95": frames[(frames.len()-1)*95/100], + "main_schedule_ms_mean": mean(1), "physics_ms_per_frame": mean(2), + "physics_ticks_per_frame": mean(3), + "physics_ms_per_tick": mean(2) / mean(3).max(f64::EPSILON), + "render_prepare_ms_mean": render_mean(0), "render_submit_ms_mean": render_mean(1), + "samples": p.samples, + }); + match std::fs::write(&p.path, serde_json::to_vec_pretty(&report).unwrap()) { + Ok(()) => { eprintln!("SKATE_PERF_REPORT {}", p.path.display()); exit.write(AppExit::Success); } + Err(e) => { eprintln!("Performance report: {e}"); exit.write(AppExit::error()); } + } + } +} + +#[derive(Resource)] +struct RenderPerformance { + start: Option, frame: Instant, prepared: Instant, + samples: Arc>>, +} +fn render_begin(mut p: ResMut) { + p.frame = Instant::now(); +} +fn render_prepared(mut p: ResMut) { + p.prepared = Instant::now(); +} +fn render_finish(mut p: ResMut) { + let now = Instant::now(); + if now.duration_since(*p.start.get_or_insert(now)).as_secs_f64() > 10. { + p.samples.lock().unwrap().push([ + p.prepared.duration_since(p.frame).as_secs_f64() * 1000., + now.duration_since(p.prepared).as_secs_f64() * 1000., + ]); + } +} diff --git a/crates/skate-game/src/physics.rs b/crates/skate-game/src/physics.rs index ec6a6b28..8a395b63 100644 --- a/crates/skate-game/src/physics.rs +++ b/crates/skate-game/src/physics.rs @@ -205,10 +205,12 @@ fn advance( mut camera: ResMut, mut cadence: ResMut>, mut exit: MessageWriter, + mut performance: Option>, ) { if physics.failed { return; } + let timer = performance.as_ref().map(|_| std::time::Instant::now()); let mut actions = input.player_actions(); let input_available = input .status @@ -239,6 +241,9 @@ fn advance( exit.write(AppExit::error()); } cadence.set_timestep(physics.clock.period()); + if let (Some(performance), Some(timer)) = (performance.as_mut(), timer) { + performance.physics(timer.elapsed()); + } } impl GamePhysics {