diff --git a/src/game.rs b/src/game.rs index 5f9c687..df5926f 100644 --- a/src/game.rs +++ b/src/game.rs @@ -29,7 +29,7 @@ use bevy_ecs::event::EventRegistry; use bevy_ecs::observer::Trigger; use bevy_ecs::schedule::common_conditions::resource_changed; use bevy_ecs::schedule::{Condition, IntoScheduleConfigs, Schedule, SystemSet}; -use bevy_ecs::system::ResMut; +use bevy_ecs::system::{Local, ResMut}; use bevy_ecs::world::World; use glam::UVec2; use sdl2::event::EventType; @@ -365,7 +365,11 @@ impl Game { schedule.add_systems(( forced_dirty_system.run_if(resource_changed::.or(resource_changed::)), ( - input_system, + input_system.run_if(|mut local: Local| { + *local = local.wrapping_add(1u8); + // run every nth frame + *local % 2 == 0 + }), player_control_system, player_movement_system, startup_stage_system, diff --git a/src/systems/profiling.rs b/src/systems/profiling.rs index 7c68f80..7a622bc 100644 --- a/src/systems/profiling.rs +++ b/src/systems/profiling.rs @@ -3,7 +3,7 @@ use bevy_ecs::{resource::Resource, system::System}; use circular_buffer::CircularBuffer; use micromap::Map; use num_width::NumberWidth; -use parking_lot::{Mutex, RwLock}; +use parking_lot::Mutex; use smallvec::SmallVec; use std::fmt::Display; use std::time::Duration; @@ -46,7 +46,7 @@ impl Display for SystemId { } } -#[derive(Resource, Default, Debug)] +#[derive(Resource, Debug)] pub struct SystemTimings { /// Map of system names to a queue of durations, using a circular buffer. /// @@ -55,42 +55,54 @@ pub struct SystemTimings { /// /// Also, we use a micromap::Map as the number of systems is generally quite small. /// Just make sure to set the capacity appropriately, or it will panic. - pub timings: RwLock>, MAX_SYSTEMS>>, + /// + /// Pre-populated with all SystemId variants during initialization to avoid runtime allocations + /// and allow systems to have default zero timings when they don't submit data. + pub timings: Map>, MAX_SYSTEMS>, +} + +impl Default for SystemTimings { + fn default() -> Self { + let mut timings = Map::new(); + + // Pre-populate with all SystemId variants to avoid runtime allocations + // and provide default zero timings for systems that don't submit data + for id in SystemId::iter() { + timings.insert(id, Mutex::new(CircularBuffer::new())); + } + + Self { timings } + } } impl SystemTimings { pub fn add_timing(&self, id: SystemId, duration: Duration) { - // acquire a upgradable read lock - let mut timings = self.timings.upgradable_read(); - - // happy path, the name is already in the map (no need to mutate the hashmap) - if timings.contains_key(&id) { - let queue = timings - .get(&id) - .expect("System name not found in map after contains_key check"); - let mut queue = queue.lock(); - - queue.push_back(duration); - return; - } - - // otherwise, acquire a write lock and insert a new queue - timings.with_upgraded(|timings| { - let queue = timings.entry(id).or_insert_with(|| Mutex::new(CircularBuffer::new())); - queue.lock().push_back(duration); - }); + // Since all SystemId variants are pre-populated, we can use a simple read lock + let queue = self + .timings + .get(&id) + .expect("SystemId not found in pre-populated map - this is a bug"); + queue.lock().push_back(duration); } pub fn get_stats(&self) -> Map { - let timings = self.timings.read(); let mut stats = Map::new(); - for (id, queue) in timings.iter() { - if queue.lock().is_empty() { + // Iterate over all SystemId variants to ensure every system has an entry + for id in SystemId::iter() { + let queue = self + .timings + .get(&id) + .expect("SystemId not found in pre-populated map - this is a bug"); + + let queue_guard = queue.lock(); + if queue_guard.is_empty() { + // Return zero timing for systems that haven't submitted any data + stats.insert(id, (Duration::ZERO, Duration::ZERO)); continue; } - let durations: Vec = queue.lock().iter().map(|d| d.as_secs_f64() * 1000.0).collect(); + let durations: Vec = queue_guard.iter().map(|d| d.as_secs_f64() * 1000.0).collect(); let count = durations.len() as f64; let sum: f64 = durations.iter().sum(); @@ -100,7 +112,7 @@ impl SystemTimings { let std_dev = variance.sqrt(); stats.insert( - *id, + id, ( Duration::from_secs_f64(mean / 1000.0), Duration::from_secs_f64(std_dev / 1000.0), @@ -113,8 +125,7 @@ impl SystemTimings { pub fn get_total_stats(&self) -> (Duration, Duration) { let duration_sums = { - let timings = self.timings.read(); - timings + self.timings .iter() .map(|(_, queue)| queue.lock().iter().sum::()) .collect::>() diff --git a/tests/profiling.rs b/tests/profiling.rs index 4a06dd2..b412d06 100644 --- a/tests/profiling.rs +++ b/tests/profiling.rs @@ -1,5 +1,22 @@ use pacman::systems::profiling::{SystemId, SystemTimings}; use std::time::Duration; +use strum::IntoEnumIterator; + +macro_rules! assert_close { + ($actual:expr, $expected:expr, $concern:expr) => { + let tolerance = Duration::from_micros(500); + let diff = $actual.abs_diff($expected); + assert!( + diff < tolerance, + "Expected {expected:?} ± {tolerance:.0?}, got {actual:?}, off by {diff:?} ({concern})", + concern = $concern, + expected = $expected, + actual = $actual, + tolerance = tolerance, + diff = diff + ); + }; +} #[test] fn test_timing_statistics() { @@ -15,30 +32,79 @@ fn test_timing_statistics() { timings.add_timing(SystemId::Blinking, Duration::from_millis(2)); timings.add_timing(SystemId::Blinking, Duration::from_millis(1)); - fn close_enough(a: Duration, b: Duration) -> bool { - if a > b { - a - b < Duration::from_micros(500) // 0.1ms - } else { - b - a < Duration::from_micros(500) - } + { + let stats = timings.get_stats(); + let (avg, std_dev) = stats.get(&SystemId::PlayerControls).unwrap(); + + assert_close!(*avg, Duration::from_millis(10), "PlayerControls average timing"); + assert_close!(*std_dev, Duration::from_millis(2), "PlayerControls standard deviation timing"); } - let stats = timings.get_stats(); - let (avg, std_dev) = stats.get(&SystemId::PlayerControls).unwrap(); - - // Average should be 10ms, standard deviation should be small - assert!(close_enough(*avg, Duration::from_millis(10)), "avg: {:?}", avg); - assert!(close_enough(*std_dev, Duration::from_millis(2)), "std_dev: {:?}", std_dev); - - let (total_avg, total_std) = timings.get_total_stats(); - assert!( - close_enough(total_avg, Duration::from_millis(18)), - "total_avg: {:?}", - total_avg - ); - assert!( - close_enough(total_std, Duration::from_millis(17)), - "total_std: {:?}", - total_std - ); + { + let (total_avg, total_std) = timings.get_total_stats(); + assert_close!(total_avg, Duration::from_millis(2), "Total average timing across all systems"); + assert_close!( + total_std, + Duration::from_millis(7), + "Total standard deviation timing across all systems" + ); + } +} + +#[test] +fn test_default_zero_timing_for_unused_systems() { + let timings = SystemTimings::default(); + + // Add timing data for only one system + timings.add_timing(SystemId::PlayerControls, Duration::from_millis(5)); + + let stats = timings.get_stats(); + + // Verify all SystemId variants are present in the stats + let expected_count = SystemId::iter().count(); + assert_eq!(stats.len(), expected_count, "All SystemId variants should be in stats"); + + // Verify that the system with data has non-zero timing + let (avg, std_dev) = stats.get(&SystemId::PlayerControls).unwrap(); + assert_close!(*avg, Duration::from_millis(5), "System with data should have correct timing"); + assert_close!(*std_dev, Duration::ZERO, "Single measurement should have zero std dev"); + + // Verify that all other systems have zero timing + for id in SystemId::iter() { + if id != SystemId::PlayerControls { + let (avg, std_dev) = stats.get(&id).unwrap(); + assert_close!( + *avg, + Duration::ZERO, + format!("Unused system {:?} should have zero avg timing", id) + ); + assert_close!( + *std_dev, + Duration::ZERO, + format!("Unused system {:?} should have zero std dev", id) + ); + } + } +} + +#[test] +fn test_pre_populated_timing_entries() { + let timings = SystemTimings::default(); + + // Verify that we can add timing to any SystemId without panicking + // (this would fail with the old implementation if the entry didn't exist) + for id in SystemId::iter() { + timings.add_timing(id, Duration::from_nanos(1)); + } + + // Verify all systems now have non-zero timing + let stats = timings.get_stats(); + for id in SystemId::iter() { + let (avg, _) = stats.get(&id).unwrap(); + assert!( + *avg > Duration::ZERO, + "System {:?} should have non-zero timing after add_timing", + id + ); + } }