From 3dfb2520cea904c63d4a75ffb7b42415301ffa35 Mon Sep 17 00:00:00 2001 From: SeanOMik Date: Mon, 1 Apr 2024 12:02:16 -0400 Subject: [PATCH] ecs: add some spans around the system executors --- Cargo.lock | 1 + lyra-ecs/Cargo.toml | 1 + lyra-ecs/src/system/batched.rs | 10 +++++++++- lyra-ecs/src/system/graph.rs | 10 ++++++++++ lyra-game/src/stage.rs | 6 ++++++ 5 files changed, 27 insertions(+), 1 deletion(-) diff --git a/Cargo.lock b/Cargo.lock index 1aeda0f..6ca50aa 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1758,6 +1758,7 @@ dependencies = [ "paste", "rand 0.8.5", "thiserror", + "tracing", ] [[package]] diff --git a/lyra-ecs/Cargo.toml b/lyra-ecs/Cargo.toml index 8068984..78b4861 100644 --- a/lyra-ecs/Cargo.toml +++ b/lyra-ecs/Cargo.toml @@ -15,6 +15,7 @@ anyhow = "1.0.75" thiserror = "1.0.50" paste = "1.0.14" atomic_refcell = "0.1.13" +tracing = "0.1.37" [dev-dependencies] rand = "0.8.5" # used for tests diff --git a/lyra-ecs/src/system/batched.rs b/lyra-ecs/src/system/batched.rs index 73a945c..00de666 100644 --- a/lyra-ecs/src/system/batched.rs +++ b/lyra-ecs/src/system/batched.rs @@ -1,4 +1,5 @@ use lyra_ecs::World; +use tracing::debug_span; use crate::Access; @@ -51,6 +52,9 @@ impl System for BatchedSystem { let mut check_again = false; for criteria in self.criteria.iter_mut() { + let crit_span = debug_span!("criteria"); + let _e = crit_span.enter(); + match criteria.can_run(world, self.criteria_checks) { super::CriteriaSchedule::Yes => {}, super::CriteriaSchedule::No => can_run = false, @@ -65,7 +69,11 @@ impl System for BatchedSystem { } if can_run { - for system in self.systems.iter_mut() { + for (idx, system) in self.systems.iter_mut().enumerate() { + let sys_span = debug_span!("batch", system=tracing::field::Empty); + sys_span.record("system", idx); + let _e = sys_span.enter(); + system.execute(world)?; } } diff --git a/lyra-ecs/src/system/graph.rs b/lyra-ecs/src/system/graph.rs index d6851f8..5282532 100644 --- a/lyra-ecs/src/system/graph.rs +++ b/lyra-ecs/src/system/graph.rs @@ -1,5 +1,7 @@ use std::{collections::{HashMap, VecDeque, HashSet}, ptr::NonNull}; +use tracing::{debug_span, info_span}; + use super::System; use crate::{World, CommandQueue, Commands}; @@ -69,9 +71,14 @@ impl GraphExecutor { let mut possible_errors = Vec::new(); + let sys_span = info_span!("graph_exec", system=tracing::field::Empty); + while let Some(node) = stack.pop_front() { let system = self.systems.get_mut(node.as_str()).unwrap(); + sys_span.record("system", system.name.clone()); + let _e = sys_span.enter(); + if let Err(e) = system.system.execute(world_ptr) .map_err(|e| GraphExecutorError::SystemError(node, e)) { if stop_on_error { @@ -82,6 +89,9 @@ impl GraphExecutor { unimplemented!("Cannot resume topological execution from error"); // TODO: resume topological execution from error } + let deferred_span = debug_span!("deferred_exec"); + let _e = deferred_span.enter(); + if let Err(e) = system.system.execute_deferred(world_ptr) .map_err(|e| GraphExecutorError::Command(e)) { diff --git a/lyra-game/src/stage.rs b/lyra-game/src/stage.rs index 15d79ff..3c5ceb8 100644 --- a/lyra-game/src/stage.rs +++ b/lyra-game/src/stage.rs @@ -1,6 +1,7 @@ use std::{hash::{Hash, DefaultHasher, Hasher}, collections::{HashMap, HashSet, VecDeque}, ptr::NonNull, fmt::Debug}; use lyra_ecs::{system::{GraphExecutor, GraphExecutorError, System}, World}; +use tracing::info_span; #[derive(thiserror::Error, Debug)] pub enum StagedExecutorError { @@ -119,10 +120,15 @@ impl StagedExecutor { self.topological_sort(&mut stack, &mut visited, node)?; } + let stage_span = info_span!("stage_exec", stage=tracing::field::Empty); + let mut errors = vec![]; while let Some(node) = stack.pop_front() { let stage = self.stages.get_mut(&node).unwrap(); + stage_span.record("stage", stage.name.clone()); + let _e = stage_span.enter(); + if let Err(e) = stage.exec.execute(world, stop_on_error) { let e = StagedExecutorError::from_graph_error(stage.name.clone(), e);