From 4f73dca34de6c51868d83d10026455cd2ad71f40 Mon Sep 17 00:00:00 2001 From: Carter Anderson Date: Sun, 28 Jun 2020 00:45:35 -0700 Subject: [PATCH] add system profile data to Diagnostics (opt in feature) --- Cargo.toml | 1 + crates/bevy_app/Cargo.toml | 3 + crates/bevy_app/src/app_builder.rs | 2 +- crates/bevy_diagnostic/Cargo.toml | 3 + crates/bevy_diagnostic/src/diagnostic.rs | 7 ++ crates/bevy_diagnostic/src/lib.rs | 8 ++ .../src/print_diagnostics_plugin.rs | 6 +- crates/bevy_diagnostic/src/system_profiler.rs | 73 +++++++++++++++++++ crates/bevy_legion/Cargo.toml | 1 + crates/bevy_legion/legion_core/Cargo.toml | 2 +- crates/bevy_legion/legion_systems/Cargo.toml | 3 +- crates/bevy_legion/legion_systems/src/lib.rs | 1 + .../legion_systems/src/profiler.rs | 24 ++++++ .../legion_systems/src/schedule.rs | 24 +++++- 14 files changed, 151 insertions(+), 7 deletions(-) create mode 100644 crates/bevy_diagnostic/src/system_profiler.rs create mode 100644 crates/bevy_legion/legion_systems/src/profiler.rs diff --git a/Cargo.toml b/Cargo.toml index 376d4cef3c..45c8b5d248 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -7,6 +7,7 @@ edition = "2018" [features] default = ["bevy_wgpu", "bevy_winit"] more-system-fns = ["legion/more-system-fns"] +profiler = ["bevy_app/profiler", "bevy_diagnostic/profiler"] [workspace] members = [ diff --git a/crates/bevy_app/Cargo.toml b/crates/bevy_app/Cargo.toml index 637115c1a6..145ea48bea 100644 --- a/crates/bevy_app/Cargo.toml +++ b/crates/bevy_app/Cargo.toml @@ -4,6 +4,9 @@ version = "0.1.0" authors = ["Carter Anderson "] edition = "2018" +[features] +profiler = ["legion/profiler"] + [dependencies] bevy_derive = { path = "../bevy_derive" } legion = { path = "../bevy_legion", features = ["serialize"] } diff --git a/crates/bevy_app/src/app_builder.rs b/crates/bevy_app/src/app_builder.rs index 9d63f5020c..0c7e0eae38 100644 --- a/crates/bevy_app/src/app_builder.rs +++ b/crates/bevy_app/src/app_builder.rs @@ -1,7 +1,7 @@ use crate::{ plugin::{load_plugin, AppPlugin}, schedule_plan::SchedulePlan, - stage, App, AppExit, Events, FromResources, System, startup_stage, + stage, startup_stage, App, AppExit, Events, FromResources, System, }; use legion::prelude::{IntoSystem, Resources, World}; diff --git a/crates/bevy_diagnostic/Cargo.toml b/crates/bevy_diagnostic/Cargo.toml index 3b51293eec..99cb50c611 100644 --- a/crates/bevy_diagnostic/Cargo.toml +++ b/crates/bevy_diagnostic/Cargo.toml @@ -4,6 +4,9 @@ version = "0.1.0" authors = ["Carter Anderson "] edition = "2018" +[features] +profiler = [] + [dependencies] bevy_app = { path = "../bevy_app" } bevy_core = { path = "../bevy_core" } diff --git a/crates/bevy_diagnostic/src/diagnostic.rs b/crates/bevy_diagnostic/src/diagnostic.rs index ed99dfd520..9c377b83be 100644 --- a/crates/bevy_diagnostic/src/diagnostic.rs +++ b/crates/bevy_diagnostic/src/diagnostic.rs @@ -13,6 +13,13 @@ impl DiagnosticId { } } +impl Default for DiagnosticId { + fn default() -> Self { + DiagnosticId(Uuid::new_v4()) + } + +} + #[derive(Debug)] pub struct DiagnosticMeasurement { pub time: SystemTime, diff --git a/crates/bevy_diagnostic/src/lib.rs b/crates/bevy_diagnostic/src/lib.rs index 6cb111fac6..c4a2b32701 100644 --- a/crates/bevy_diagnostic/src/lib.rs +++ b/crates/bevy_diagnostic/src/lib.rs @@ -1,6 +1,8 @@ mod diagnostic; mod frame_time_diagnostics_plugin; mod print_diagnostics_plugin; +#[cfg(feature = "profiler")] +mod system_profiler; pub use diagnostic::*; pub use frame_time_diagnostics_plugin::FrameTimeDiagnosticsPlugin; pub use print_diagnostics_plugin::PrintDiagnosticsPlugin; @@ -15,5 +17,11 @@ pub struct DiagnosticsPlugin; impl AppPlugin for DiagnosticsPlugin { fn build(&self, app: &mut AppBuilder) { app.init_resource::(); + #[cfg(feature = "profiler")] + { + use legion::prelude::IntoSystem; + app.add_resource::>(Box::new(system_profiler::SystemProfiler::default())) + .add_system_to_stage(bevy_app::stage::LAST, system_profiler::profiler_diagnostic_system.system()); + } } } diff --git a/crates/bevy_diagnostic/src/print_diagnostics_plugin.rs b/crates/bevy_diagnostic/src/print_diagnostics_plugin.rs index e2bbc30f63..fd6bd6b99b 100644 --- a/crates/bevy_diagnostic/src/print_diagnostics_plugin.rs +++ b/crates/bevy_diagnostic/src/print_diagnostics_plugin.rs @@ -53,7 +53,7 @@ impl PrintDiagnosticsPlugin { fn print_diagnostic(diagnostic: &Diagnostic) { if let Some(value) = diagnostic.value() { - print!("{:<20}: {:<19.6}", diagnostic.name, value); + print!("{:<65}: {:<10.6}", diagnostic.name, value); if let Some(average) = diagnostic.average() { print!(" (avg {:.6})", average); } @@ -70,7 +70,7 @@ impl PrintDiagnosticsPlugin { state.timer.tick(time.delta_seconds); if state.timer.finished { println!("Diagnostics:"); - println!("{}", "-".repeat(60)); + println!("{}", "-".repeat(93)); if let Some(ref filter) = state.filter { for diagnostic in filter.iter().map(|id| diagnostics.get(*id).unwrap()) { Self::print_diagnostic(diagnostic); @@ -93,7 +93,7 @@ impl PrintDiagnosticsPlugin { state.timer.tick(time.delta_seconds); if state.timer.finished { println!("Diagnostics (Debug):"); - println!("{}", "-".repeat(60)); + println!("{}", "-".repeat(93)); if let Some(ref filter) = state.filter { for diagnostic in filter.iter().map(|id| diagnostics.get(*id).unwrap()) { println!("{:#?}\n", diagnostic); diff --git a/crates/bevy_diagnostic/src/system_profiler.rs b/crates/bevy_diagnostic/src/system_profiler.rs new file mode 100644 index 0000000000..456133b902 --- /dev/null +++ b/crates/bevy_diagnostic/src/system_profiler.rs @@ -0,0 +1,73 @@ +use crate::{Diagnostic, DiagnosticId, Diagnostics}; +use legion::{ + systems::{profiler::Profiler, Res, ResMut}, +}; +use std::{ + collections::HashMap, + sync::{Arc, RwLock}, + time::Instant, borrow::Cow, +}; + +#[derive(Debug)] +struct SystemRunInfo { + start: Instant, + stop: Instant, +} + +#[derive(Default)] +struct SystemProfiles { + diagnostic_id: DiagnosticId, + history: Vec, + current_start: Option, +} + +#[derive(Default)] +pub struct SystemProfiler { + system_profiles: Arc, SystemProfiles>>>, +} + +impl Profiler for SystemProfiler { + fn start(&self, scope: Cow<'static, str>) { + let mut system_profiles = self.system_profiles.write().unwrap(); + let profiles = system_profiles + .entry(scope.clone()) + .or_insert_with(|| SystemProfiles::default()); + + profiles.current_start = Some(Instant::now()); + } + + fn stop(&self, scope: Cow<'static, str>) { + let now = Instant::now(); + let mut system_profiles = self.system_profiles.write().unwrap(); + let profiles = system_profiles.get_mut(&scope).unwrap(); + if let Some(current_start) = profiles.current_start.take() { + profiles.history.push(SystemRunInfo { + start: current_start, + stop: now, + }); + } + } +} + +pub fn profiler_diagnostic_system( + mut diagnostics: ResMut, + system_profiler: Res>, +) { + let system_profiler = system_profiler.downcast_ref::().unwrap(); + let mut system_profiles = system_profiler.system_profiles.write().unwrap(); + for (scope, profiles) in system_profiles.iter_mut() { + if diagnostics.get(profiles.diagnostic_id).is_none() { + diagnostics.add(Diagnostic::new( + profiles.diagnostic_id, + &scope, + 20, + )) + } + for profile in profiles.history.drain(..) { + diagnostics.add_measurement( + profiles.diagnostic_id, + (profile.stop - profile.start).as_secs_f64(), + ); + } + } +} diff --git a/crates/bevy_legion/Cargo.toml b/crates/bevy_legion/Cargo.toml index 8b80812a4e..2e54eee440 100644 --- a/crates/bevy_legion/Cargo.toml +++ b/crates/bevy_legion/Cargo.toml @@ -22,6 +22,7 @@ ffi = ["legion-core/ffi"] serialize = ["legion-core/serialize"] metrics = ["legion-core/metrics"] more-system-fns = ["legion-systems/more-system-fns"] +profiler = ["legion-systems/profiler"] # [workspace] # members = [ diff --git a/crates/bevy_legion/legion_core/Cargo.toml b/crates/bevy_legion/legion_core/Cargo.toml index 81c8089b7d..999d387460 100644 --- a/crates/bevy_legion/legion_core/Cargo.toml +++ b/crates/bevy_legion/legion_core/Cargo.toml @@ -20,7 +20,7 @@ serialize = ["serde"] [dependencies] parking_lot = "0.10" -downcast-rs = "1.0" +downcast-rs = "1.1.1" itertools = "0.9" rayon = { version = "1.2", optional = true } crossbeam-queue = { version = "0.2.0", optional = true } diff --git a/crates/bevy_legion/legion_systems/Cargo.toml b/crates/bevy_legion/legion_systems/Cargo.toml index 14e09f6355..874edffd8c 100644 --- a/crates/bevy_legion/legion_systems/Cargo.toml +++ b/crates/bevy_legion/legion_systems/Cargo.toml @@ -17,12 +17,13 @@ travis-ci = { repository = "TomGillen/legion", branch = "master" } par-iter = ["rayon", "legion-core/par-iter"] par-schedule = ["rayon", "crossbeam-queue"] more-system-fns = [] +profiler = [] [dependencies] legion-core = { path = "../legion_core", version = "0.2.4", default-features = false } legion_fn_system_macro = { path = "../legion_fn_system_macro" } -downcast-rs = "1.0" +downcast-rs = "1.1.1" itertools = "0.9" rayon = { version = "1.2", optional = true } crossbeam-queue = { version = "0.2.0", optional = true } diff --git a/crates/bevy_legion/legion_systems/src/lib.rs b/crates/bevy_legion/legion_systems/src/lib.rs index 1f2af94d4b..e741cfc508 100644 --- a/crates/bevy_legion/legion_systems/src/lib.rs +++ b/crates/bevy_legion/legion_systems/src/lib.rs @@ -1,5 +1,6 @@ pub mod resource; pub mod schedule; +pub mod profiler; mod system; mod system_fn; diff --git a/crates/bevy_legion/legion_systems/src/profiler.rs b/crates/bevy_legion/legion_systems/src/profiler.rs new file mode 100644 index 0000000000..7b0382bdc0 --- /dev/null +++ b/crates/bevy_legion/legion_systems/src/profiler.rs @@ -0,0 +1,24 @@ +use crate::{ + resource::Resources, +}; +use downcast_rs::{impl_downcast, Downcast}; +use std::borrow::Cow; + +pub trait Profiler: Downcast + Send + Sync + 'static { + fn start(&self, scope: Cow<'static, str>); + fn stop(&self, scope: Cow<'static, str>); +} + +pub fn profiler_start(resources: &Resources, scope: Cow<'static, str>) { + if let Some(profiler) = resources.get::>() { + profiler.start(scope); + } +} + +pub fn profiler_stop(resources: &Resources, scope: Cow<'static, str>) { + if let Some(profiler) = resources.get::>() { + profiler.stop(scope); + } +} + +impl_downcast!(Profiler); diff --git a/crates/bevy_legion/legion_systems/src/schedule.rs b/crates/bevy_legion/legion_systems/src/schedule.rs index 574e230cc6..e872a86879 100644 --- a/crates/bevy_legion/legion_systems/src/schedule.rs +++ b/crates/bevy_legion/legion_systems/src/schedule.rs @@ -307,8 +307,12 @@ impl Executor { pub fn run_systems(&mut self, world: &mut World, resources: &mut Resources) { self.systems.iter_mut().for_each(|system| { let system = unsafe { system.get_mut() }; + #[cfg(feature = "profiler")] + crate::profiler::profiler_start(resources, system.name().name()); system.prepare(world); system.run(world, resources); + #[cfg(feature = "profiler")] + crate::profiler::profiler_stop(resources, system.name().name()); }); } @@ -328,8 +332,12 @@ impl Executor { // safety: we have exlusive access to all systems, world and resources here unsafe { let system = self.systems[0].get_mut(); + #[cfg(feature = "profiler")] + crate::profiler::profiler_start(resources, system.name().name()); system.prepare(world); system.run(world, resources); + #[cfg(feature = "profiler")] + crate::profiler::profiler_stop(resources, system.name().name()); }; } _ => { @@ -415,7 +423,11 @@ impl Executor { #[cfg(feature = "par-schedule")] unsafe fn run_recursive(&self, i: usize, world: &World, resources: &Resources) { // safety: the caller ensures nothing else is accessing systems[i] + #[cfg(feature = "profiler")] + crate::profiler::profiler_start(resources, self.systems[i].get().name().name()); self.systems[i].get_mut().run_unsafe(world, resources); + #[cfg(feature = "profiler")] + crate::profiler::profiler_stop(resources, self.systems[i].get().name().name()); self.static_dependants[i].par_iter().for_each(|dep| { if self.awaiting[*dep].fetch_sub(1, Ordering::Relaxed) == 1 { @@ -550,10 +562,20 @@ impl Schedule { ToFlush::System(mut cmd) => cmd.write(world), }); } - Step::ThreadLocalFn(function) => function(world, resources), + Step::ThreadLocalFn(function) => { + #[cfg(feature = "profiler")] + crate::profiler::profiler_start(resources, std::borrow::Cow::Borrowed("thread_local")); + function(world, resources); + #[cfg(feature = "profiler")] + crate::profiler::profiler_stop(resources, std::borrow::Cow::Borrowed("thread_local")); + }, Step::ThreadLocalSystem(system) => { + #[cfg(feature = "profiler")] + crate::profiler::profiler_start(resources, system.name().name()); system.prepare(world); system.run(world, resources); + #[cfg(feature = "profiler")] + crate::profiler::profiler_stop(resources, system.name().name()); if let Some(cmd) = system.command_buffer_mut(world.id()) { waiting_flush.push(ToFlush::System(cmd)); }