diff --git a/Cargo.lock b/Cargo.lock index 34c0916..9399b7b 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -576,6 +576,7 @@ dependencies = [ "lazy_static", "libc", "once_cell", + "parking_lot", "pathfinding", "phf", "rand", diff --git a/Cargo.toml b/Cargo.toml index ba45bf8..2f5454a 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -6,7 +6,7 @@ edition = "2021" # See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html [dependencies] -tracing = { version = "0.1.40", features = ["max_level_debug", "release_max_level_debug"]} +tracing = { version = "0.1.41", features = ["max_level_debug", "release_max_level_debug"]} tracing-error = "0.2.0" tracing-subscriber = {version = "0.3.17", features = ["env-filter"]} lazy_static = "1.5.0" @@ -17,7 +17,7 @@ pathfinding = "4.14" once_cell = "1.21.3" thiserror = "2.0.14" anyhow = "1.0" -glam = { version = "0.30.5", features = [] } +glam = "0.30.5" serde = { version = "1.0.219", features = ["derive"] } serde_json = "1.0.142" smallvec = "1.15.1" @@ -26,6 +26,7 @@ strum_macros = "0.27.2" phf = { version = "0.12.1", features = ["macros"] } bevy_ecs = "0.16.1" bitflags = "2.9.1" +parking_lot = "0.12.3" [profile.release] lto = true diff --git a/src/app.rs b/src/app.rs index b81bd1e..3fb6021 100644 --- a/src/app.rs +++ b/src/app.rs @@ -5,13 +5,14 @@ use sdl2::render::TextureCreator; use sdl2::ttf::Sdl2TtfContext; use sdl2::video::WindowContext; use sdl2::{AudioSubsystem, EventPump, Sdl, VideoSubsystem}; -use tracing::warn; +use tracing::{field, info, warn}; use crate::error::{GameError, GameResult}; use crate::constants::{CANVAS_SIZE, LOOP_TIME, SCALE}; use crate::game::Game; use crate::platform::get_platform; +use crate::systems::profiling::SystemTimings; pub struct App { pub game: Game, @@ -64,12 +65,6 @@ impl App { let game = Game::new(canvas, texture_creator, event_pump)?; // game.audio.set_mute(cfg!(debug_assertions)); - // Initial draw - // game.draw(&mut canvas, &mut backbuffer) - // .map_err(|e| GameError::Sdl(e.to_string()))?; - // game.present_backbuffer(&mut canvas, &backbuffer, glam::Vec2::ZERO) - // .map_err(|e| GameError::Sdl(e.to_string()))?; - Ok(App { game, focused: true, @@ -116,17 +111,23 @@ impl App { return false; } - // if let Err(e) = self.game.draw(&mut self.canvas, &mut self.backbuffer) { - // error!("Failed to draw game: {}", e); - // } + // Show timings if the loop took more than 25% of the loop time + let show_timings = start.elapsed() > (LOOP_TIME / 4); + if show_timings || true { + if let Some(timings) = self.game.world.get_resource::() { + let mut timings = timings.timings.lock(); + let total = timings.values().sum::(); + info!("Total: {:?}, Timings: {:?}", total, field::debug(&timings)); + timings.clear(); + } + } + // Sleep if we still have time left if start.elapsed() < LOOP_TIME { let time = LOOP_TIME.saturating_sub(start.elapsed()); if time != Duration::ZERO { get_platform().sleep(time, self.focused); } - } else { - warn!("Game loop behind schedule by: {:?}", start.elapsed() - LOOP_TIME); } true diff --git a/src/game/mod.rs b/src/game/mod.rs index 0aed0bb..9a29d3a 100644 --- a/src/game/mod.rs +++ b/src/game/mod.rs @@ -19,6 +19,7 @@ use crate::systems::{ control::player_system, input::input_system, movement::movement_system, + profiling::{profile, SystemTimings}, render::{directional_render_system, render_system, BackbufferResource, MapTextureResource}, }; use crate::texture::animated::AnimatedTexture; @@ -171,6 +172,7 @@ impl Game { world.insert_resource(map); world.insert_resource(GlobalState { exit: false }); world.insert_resource(ScoreResource(0)); + world.insert_resource(SystemTimings::default()); world.insert_resource(Bindings::default()); world.insert_resource(DeltaTime(0f32)); @@ -188,13 +190,13 @@ impl Game { schedule.add_systems( ( - input_system, - player_system, - movement_system, - collision_system, - blinking_system, - directional_render_system, - render_system, + profile("input", input_system), + profile("player", player_system), + profile("movement", movement_system), + profile("collision", collision_system), + profile("blinking", blinking_system), + profile("directional_render", directional_render_system), + profile("render", render_system), ) .chain(), ); diff --git a/src/systems/mod.rs b/src/systems/mod.rs index 86a6b08..abdbe9a 100644 --- a/src/systems/mod.rs +++ b/src/systems/mod.rs @@ -9,4 +9,5 @@ pub mod components; pub mod control; pub mod input; pub mod movement; +pub mod profiling; pub mod render; diff --git a/src/systems/profiling.rs b/src/systems/profiling.rs new file mode 100644 index 0000000..0f3995d --- /dev/null +++ b/src/systems/profiling.rs @@ -0,0 +1,32 @@ +use bevy_ecs::prelude::Resource; +use bevy_ecs::system::{IntoSystem, System}; +use parking_lot::Mutex; +use std::collections::HashMap; +use std::time::Duration; + +#[derive(Resource, Default, Debug)] +pub struct SystemTimings { + pub timings: Mutex>, +} + +pub fn profile(name: &'static str, system: S) -> impl FnMut(&mut bevy_ecs::world::World) +where + S: IntoSystem<(), (), M> + 'static, +{ + let mut system: S::System = IntoSystem::into_system(system); + let mut is_initialized = false; + move |world: &mut bevy_ecs::world::World| { + if !is_initialized { + system.initialize(world); + is_initialized = true; + } + + let start = std::time::Instant::now(); + system.run((), world); + let duration = start.elapsed(); + + if let Some(mut timings) = world.get_resource_mut::() { + timings.timings.lock().insert(name, duration); + } + } +}