mirror of
https://github.com/Xevion/Pac-Man.git
synced 2025-12-14 16:12:25 -06:00
feat: enhance profiling with tick-based timing management and zero-padding for skipped frames
This commit is contained in:
@@ -1,11 +1,11 @@
|
||||
use bevy_ecs::system::IntoSystem;
|
||||
use bevy_ecs::{resource::Resource, system::System};
|
||||
use circular_buffer::CircularBuffer;
|
||||
use micromap::Map;
|
||||
use num_width::NumberWidth;
|
||||
use parking_lot::Mutex;
|
||||
use smallvec::SmallVec;
|
||||
use std::fmt::Display;
|
||||
use std::sync::atomic::{AtomicU64, Ordering};
|
||||
use std::time::Duration;
|
||||
use strum::{EnumCount, IntoEnumIterator};
|
||||
use strum_macros::{EnumCount, EnumIter, IntoStaticStr};
|
||||
@@ -16,6 +16,124 @@ const MAX_SYSTEMS: usize = SystemId::COUNT;
|
||||
/// The number of durations to keep in the circular buffer.
|
||||
const TIMING_WINDOW_SIZE: usize = 30;
|
||||
|
||||
/// A timing buffer that tracks durations and automatically inserts zero durations for skipped ticks.
|
||||
#[derive(Debug, Default)]
|
||||
pub struct TimingBuffer {
|
||||
/// Circular buffer storing timing durations
|
||||
buffer: CircularBuffer<TIMING_WINDOW_SIZE, Duration>,
|
||||
/// The last tick when this buffer was updated
|
||||
last_tick: u64,
|
||||
}
|
||||
|
||||
impl TimingBuffer {
|
||||
/// Adds a timing duration for the current tick.
|
||||
///
|
||||
/// # Panics
|
||||
///
|
||||
/// Panics if `current_tick` is less than `last_tick`, indicating time went backwards.
|
||||
pub fn add_timing(&mut self, duration: Duration, current_tick: u64) {
|
||||
if current_tick < self.last_tick {
|
||||
panic!(
|
||||
"Time went backwards: current_tick ({}) < last_tick ({})",
|
||||
current_tick, self.last_tick
|
||||
);
|
||||
}
|
||||
|
||||
// Insert zero durations for any skipped ticks (but not the current tick)
|
||||
if current_tick > self.last_tick {
|
||||
let skipped_ticks = current_tick - self.last_tick - 1;
|
||||
for _ in 0..skipped_ticks {
|
||||
self.buffer.push_back(Duration::ZERO);
|
||||
}
|
||||
}
|
||||
|
||||
// Add the actual timing
|
||||
self.buffer.push_back(duration);
|
||||
self.last_tick = current_tick;
|
||||
}
|
||||
|
||||
/// Gets statistics for this timing buffer.
|
||||
///
|
||||
/// # Panics
|
||||
///
|
||||
/// Panics if `current_tick` is less than `last_tick`, indicating time went backwards.
|
||||
pub fn get_stats(&mut self, current_tick: u64) -> (Duration, Duration) {
|
||||
// Insert zero durations for any skipped ticks since last update (but not the current tick)
|
||||
if current_tick > self.last_tick {
|
||||
let skipped_ticks = current_tick - self.last_tick - 1;
|
||||
for _ in 0..skipped_ticks {
|
||||
self.buffer.push_back(Duration::ZERO);
|
||||
}
|
||||
self.last_tick = current_tick;
|
||||
}
|
||||
|
||||
// Calculate statistics using Welford's algorithm
|
||||
let mut sample_count = 0u16;
|
||||
let mut running_mean = 0.0;
|
||||
let mut sum_squared_diff = 0.0;
|
||||
|
||||
let skip = self.last_tick.saturating_sub(current_tick);
|
||||
for duration in self.buffer.iter().skip(skip as usize) {
|
||||
let duration_secs = duration.as_secs_f32();
|
||||
sample_count += 1;
|
||||
|
||||
let diff_from_mean = duration_secs - running_mean;
|
||||
running_mean += diff_from_mean / sample_count as f32;
|
||||
|
||||
let diff_from_new_mean = duration_secs - running_mean;
|
||||
sum_squared_diff += diff_from_mean * diff_from_new_mean;
|
||||
}
|
||||
|
||||
if sample_count > 0 {
|
||||
let variance = if sample_count > 1 {
|
||||
sum_squared_diff / (sample_count - 1) as f32
|
||||
} else {
|
||||
0.0
|
||||
};
|
||||
|
||||
(
|
||||
Duration::from_secs_f32(running_mean),
|
||||
Duration::from_secs_f32(variance.sqrt()),
|
||||
)
|
||||
} else {
|
||||
(Duration::ZERO, Duration::ZERO)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// A resource that tracks the current game tick using an atomic counter.
|
||||
/// This ensures thread-safe access to the tick counter across systems.
|
||||
#[derive(Resource, Debug)]
|
||||
pub struct Timing {
|
||||
/// Atomic counter for the current game tick
|
||||
current_tick: AtomicU64,
|
||||
}
|
||||
|
||||
impl Timing {
|
||||
/// Creates a new Timing resource starting at tick 0
|
||||
pub fn new() -> Self {
|
||||
Self {
|
||||
current_tick: AtomicU64::new(0),
|
||||
}
|
||||
}
|
||||
|
||||
/// Gets the current tick value
|
||||
pub fn get_current_tick(&self) -> u64 {
|
||||
self.current_tick.load(Ordering::Relaxed)
|
||||
}
|
||||
|
||||
/// Increments the tick counter and returns the new value
|
||||
pub fn increment_tick(&self) -> u64 {
|
||||
self.current_tick.fetch_add(1, Ordering::Relaxed) + 1
|
||||
}
|
||||
}
|
||||
|
||||
impl Default for Timing {
|
||||
fn default() -> Self {
|
||||
Self::new()
|
||||
}
|
||||
}
|
||||
|
||||
#[derive(EnumCount, EnumIter, IntoStaticStr, Debug, PartialEq, Eq, Hash, Copy, Clone)]
|
||||
pub enum SystemId {
|
||||
Total,
|
||||
@@ -43,33 +161,24 @@ pub enum SystemId {
|
||||
|
||||
impl Display for SystemId {
|
||||
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
|
||||
// Use strum_macros::IntoStaticStr to get the static string
|
||||
write!(f, "{}", Into::<&'static str>::into(self).to_ascii_lowercase())
|
||||
}
|
||||
}
|
||||
|
||||
#[derive(Resource, Debug)]
|
||||
pub struct SystemTimings {
|
||||
/// Map of system names to a queue of durations, using a circular buffer.
|
||||
///
|
||||
/// Uses a RwLock to allow multiple readers for the HashMap, and a Mutex on the circular buffer for exclusive access.
|
||||
/// This is probably overkill, but it's fun to play with.
|
||||
///
|
||||
/// 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.
|
||||
///
|
||||
/// 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<SystemId, Mutex<CircularBuffer<TIMING_WINDOW_SIZE, Duration>>, MAX_SYSTEMS>,
|
||||
/// Statically sized map of system names to timing buffers.
|
||||
pub timings: micromap::Map<SystemId, Mutex<TimingBuffer>, MAX_SYSTEMS>,
|
||||
}
|
||||
|
||||
impl Default for SystemTimings {
|
||||
fn default() -> Self {
|
||||
let mut timings = Map::new();
|
||||
let mut timings = micromap::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()));
|
||||
timings.insert(id, Mutex::new(TimingBuffer::default()));
|
||||
}
|
||||
|
||||
Self { timings }
|
||||
@@ -77,68 +186,39 @@ impl Default for SystemTimings {
|
||||
}
|
||||
|
||||
impl SystemTimings {
|
||||
pub fn add_timing(&self, id: SystemId, duration: Duration) {
|
||||
pub fn add_timing(&self, id: SystemId, duration: Duration, current_tick: u64) {
|
||||
// Since all SystemId variants are pre-populated, we can use a simple read lock
|
||||
let queue = self
|
||||
let buffer = self
|
||||
.timings
|
||||
.get(&id)
|
||||
.expect("SystemId not found in pre-populated map - this is a bug");
|
||||
queue.lock().push_back(duration);
|
||||
buffer.lock().add_timing(duration, current_tick);
|
||||
}
|
||||
|
||||
/// Add timing for the Total system (total frame time including scheduler.run)
|
||||
pub fn add_total_timing(&self, duration: Duration) {
|
||||
self.add_timing(SystemId::Total, duration);
|
||||
pub fn add_total_timing(&self, duration: Duration, current_tick: u64) {
|
||||
self.add_timing(SystemId::Total, duration, current_tick);
|
||||
}
|
||||
|
||||
pub fn get_stats(&self) -> Map<SystemId, (Duration, Duration), MAX_SYSTEMS> {
|
||||
let mut stats = Map::new();
|
||||
pub fn get_stats(&self, current_tick: u64) -> micromap::Map<SystemId, (Duration, Duration), MAX_SYSTEMS> {
|
||||
let mut stats = micromap::Map::new();
|
||||
|
||||
// Iterate over all SystemId variants to ensure every system has an entry
|
||||
for id in SystemId::iter() {
|
||||
let queue = self
|
||||
let buffer = self
|
||||
.timings
|
||||
.get(&id)
|
||||
.expect("SystemId not found in pre-populated map - this is a bug");
|
||||
|
||||
let queue_guard = queue.lock();
|
||||
// Welford's algorithm for a single-pass mean and variance calculation.
|
||||
|
||||
let mut sample_count = 0.0;
|
||||
let mut running_mean = 0.0;
|
||||
let mut sum_squared_diff = 0.0;
|
||||
|
||||
for duration in queue_guard.iter() {
|
||||
let duration_secs = duration.as_secs_f64();
|
||||
sample_count += 1.0;
|
||||
let diff_from_mean = duration_secs - running_mean;
|
||||
running_mean += diff_from_mean / sample_count;
|
||||
let diff_from_new_mean = duration_secs - running_mean;
|
||||
sum_squared_diff += diff_from_mean * diff_from_new_mean;
|
||||
}
|
||||
|
||||
let (average, standard_deviation) = if sample_count > 0.0 {
|
||||
let variance = if sample_count > 1.0 {
|
||||
sum_squared_diff / (sample_count - 1.0)
|
||||
} else {
|
||||
0.0
|
||||
};
|
||||
(
|
||||
Duration::from_secs_f64(running_mean),
|
||||
Duration::from_secs_f64(variance.sqrt()),
|
||||
)
|
||||
} else {
|
||||
(Duration::ZERO, Duration::ZERO)
|
||||
};
|
||||
|
||||
let (average, standard_deviation) = buffer.lock().get_stats(current_tick);
|
||||
stats.insert(id, (average, standard_deviation));
|
||||
}
|
||||
|
||||
stats
|
||||
}
|
||||
|
||||
pub fn format_timing_display(&self) -> SmallVec<[String; SystemId::COUNT]> {
|
||||
let stats = self.get_stats();
|
||||
pub fn format_timing_display(&self, current_tick: u64) -> SmallVec<[String; SystemId::COUNT]> {
|
||||
let stats = self.get_stats(current_tick);
|
||||
|
||||
// Get the Total system metrics instead of averaging all systems
|
||||
let (total_avg, total_std) = stats
|
||||
@@ -185,8 +265,9 @@ where
|
||||
system.run((), world);
|
||||
let duration = start.elapsed();
|
||||
|
||||
if let Some(timings) = world.get_resource::<SystemTimings>() {
|
||||
timings.add_timing(id, duration);
|
||||
if let (Some(timings), Some(timing)) = (world.get_resource::<SystemTimings>(), world.get_resource::<Timing>()) {
|
||||
let current_tick = timing.get_current_tick();
|
||||
timings.add_timing(id, duration, current_tick);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user