game: some profiling improvements

Cargo.lock

@@ -56,6 +56,15 @@ dependencies = [
  "zerocopy",
 ]
 
+[[package]]
+name = "aho-corasick"
+version = "1.1.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8e60d3430d3a69478ad0993f19238d2df97c507009a52b3c10addcd7f6bcb916"
+dependencies = [
+ "memchr",
+]
+
 [[package]]
 name = "allocator-api2"
 version = "0.2.16"
@@ -1087,6 +1096,19 @@ dependencies = [
  "byteorder",
 ]
 
+[[package]]
+name = "generator"
+version = "0.7.5"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5cc16584ff22b460a382b7feec54b23d2908d858152e5739a120b949293bd74e"
+dependencies = [
+ "cc",
+ "libc",
+ "log",
+ "rustversion",
+ "windows 0.48.0",
+]
+
 [[package]]
 name = "generic-array"
 version = "0.14.7"
@@ -1747,6 +1769,19 @@ dependencies = [
  "value-bag",
 ]
 
+[[package]]
+name = "loom"
+version = "0.7.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "7e045d70ddfbc984eacfa964ded019534e8f6cbf36f6410aee0ed5cefa5a9175"
+dependencies = [
+ "cfg-if",
+ "generator",
+ "scoped-tls",
+ "tracing",
+ "tracing-subscriber",
+]
+
 [[package]]
 name = "lyra-ecs"
 version = "0.1.0"
@@ -1804,6 +1839,7 @@ dependencies = [
  "tracing-appender",
  "tracing-log 0.1.4",
  "tracing-subscriber",
+ "tracing-tracy",
  "uuid",
  "wgpu",
  "winit",
@@ -1914,6 +1950,15 @@ dependencies = [
  "libc",
 ]
 
+[[package]]
+name = "matchers"
+version = "0.1.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558"
+dependencies = [
+ "regex-automata 0.1.10",
+]
+
 [[package]]
 name = "memchr"
 version = "2.7.1"
@@ -2655,6 +2700,50 @@ dependencies = [
  "bitflags 1.3.2",
 ]
 
+[[package]]
+name = "regex"
+version = "1.10.4"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "c117dbdfde9c8308975b6a18d71f3f385c89461f7b3fb054288ecf2a2058ba4c"
+dependencies = [
+ "aho-corasick",
+ "memchr",
+ "regex-automata 0.4.6",
+ "regex-syntax 0.8.3",
+]
+
+[[package]]
+name = "regex-automata"
+version = "0.1.10"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132"
+dependencies = [
+ "regex-syntax 0.6.29",
+]
+
+[[package]]
+name = "regex-automata"
+version = "0.4.6"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "86b83b8b9847f9bf95ef68afb0b8e6cdb80f498442f5179a29fad448fcc1eaea"
+dependencies = [
+ "aho-corasick",
+ "memchr",
+ "regex-syntax 0.8.3",
+]
+
+[[package]]
+name = "regex-syntax"
+version = "0.6.29"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1"
+
+[[package]]
+name = "regex-syntax"
+version = "0.8.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "adad44e29e4c806119491a7f06f03de4d1af22c3a680dd47f1e6e179439d1f56"
+
 [[package]]
 name = "remove_dir_all"
 version = "0.5.3"
@@ -2758,6 +2847,12 @@ dependencies = [
  "base64 0.21.5",
 ]
 
+[[package]]
+name = "rustversion"
+version = "1.0.15"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "80af6f9131f277a45a3fba6ce8e2258037bb0477a67e610d3c1fe046ab31de47"
+
 [[package]]
 name = "ryu"
 version = "1.0.16"
@@ -3355,14 +3450,49 @@ version = "0.3.18"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "ad0f048c97dbd9faa9b7df56362b8ebcaa52adb06b498c050d2f4e32f90a7a8b"
 dependencies = [
+ "matchers",
  "nu-ansi-term",
+ "once_cell",
+ "regex",
  "sharded-slab",
  "smallvec",
  "thread_local",
+ "tracing",
  "tracing-core",
  "tracing-log 0.2.0",
 ]
 
+[[package]]
+name = "tracing-tracy"
+version = "0.11.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "6024d04f84a69fd0d1dc1eee3a2b070bd246530a0582f9982ae487cb6c703614"
+dependencies = [
+ "tracing-core",
+ "tracing-subscriber",
+ "tracy-client",
+]
+
+[[package]]
+name = "tracy-client"
+version = "0.17.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "59fb931a64ff88984f86d3e9bcd1ae8843aa7fe44dd0f8097527bc172351741d"
+dependencies = [
+ "loom",
+ "once_cell",
+ "tracy-client-sys",
+]
+
+[[package]]
+name = "tracy-client-sys"
+version = "0.22.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "9d104d610dfa9dd154535102cc9c6164ae1fa37842bc2d9e83f9ac82b0ae0882"
+dependencies = [
+ "cc",
+]
+
 [[package]]
 name = "try-lock"
 version = "0.2.5"
@@ -3803,6 +3933,15 @@ dependencies = [
  "windows-targets 0.42.2",
 ]
 
+[[package]]
+name = "windows"
+version = "0.48.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "e686886bc078bc1b0b600cac0147aadb815089b6e4da64016cbd754b6342700f"
+dependencies = [
+ "windows-targets 0.48.5",
+]
+
 [[package]]
 name = "windows"
 version = "0.52.0"

lyra-game/Cargo.toml

@@ -11,11 +11,14 @@ lyra-math = { path = "../lyra-math" }
 lyra-scene = { path = "../lyra-scene" }
 
 winit = "0.28.1"
+wgpu = "0.15.1"
+
 tracing = "0.1.37"
 tracing-subscriber = { version = "0.3.16", features = [ "tracing-log" ] }
 tracing-log = "0.1.3"
 tracing-appender = "0.2.2"
-wgpu = "0.15.1"
+tracing-tracy = { version = "0.11.0", optional = true }
+
 async-std = { version = "1.12.0", features = [ "unstable", "attributes" ] }
 cfg-if = "1"
 bytemuck = { version = "1.12", features = [ "derive" ] }
@@ -30,3 +33,6 @@ quote = "1.0.29"
 uuid = { version = "1.5.0", features = ["v4", "fast-rng"] }
 itertools = "0.11.0"
 thiserror = "1.0.56"
+
+[features]
+tracy = ["dep:tracing-tracy"]

lyra-game/src/game.rs

@@ -3,7 +3,7 @@ use std::{sync::Arc, collections::VecDeque, ptr::NonNull};
 use async_std::task::block_on;
 
 use lyra_ecs::{World, system::{System, IntoSystem}};
-use tracing::{info, error, Level};
+use tracing::{error, info, Level};
 use tracing_appender::non_blocking;
 use tracing_subscriber::{
     layer::SubscriberExt,
@@ -344,15 +344,22 @@ impl Game {
     pub async fn run(&mut self) {
         // init logging
         let (stdout_layer, _stdout_nb) = non_blocking(std::io::stdout());
-        tracing_subscriber::registry()
+        {
-            .with(fmt::layer().with_writer(stdout_layer))
+            let t = tracing_subscriber::registry()
-            .with(filter::Targets::new()
+                .with(fmt::layer().with_writer(stdout_layer));
-                // done by prefix, so it includes all lyra subpackages
+
-                .with_target("lyra", Level::DEBUG)
+            #[cfg(feature = "tracy")]
-                .with_target("wgpu", Level::WARN)
+            t.with(tracing_tracy::TracyLayer::default());
-                .with_target("winit", Level::DEBUG)
+
-                .with_default(Level::INFO))
+            t.with(filter::Targets::new()
-            .init();
+                    // done by prefix, so it includes all lyra subpackages
+                    .with_target("lyra", Level::DEBUG)
+                    .with_target("wgpu", Level::WARN)
+                    .with_target("winit", Level::DEBUG)
+                    .with_default(Level::INFO))
+                .init();
+        }
+        
 
         let world = self.world.take().unwrap_or_default();
 

lyra-game/src/render/light_cull_compute.rs

@@ -1,6 +1,7 @@
 use std::{borrow::Cow, mem, rc::Rc};
 
 use glam::UVec2;
+use tracing::instrument;
 use wgpu::{util::DeviceExt, ComputePipeline};
 use winit::dpi::PhysicalSize;
 
@@ -202,6 +203,7 @@ impl LightCullCompute {
         }
     }
 
+    #[instrument(skip(self))]
     pub fn update_screen_size(&mut self, size: PhysicalSize<u32>) {
         self.screen_size_buffer.write_buffer(&self.queue, 0,
             &[UVec2::new(size.width, size.height)]);
@@ -212,7 +214,9 @@ impl LightCullCompute {
         self.light_indices_grid = Self::create_grid(&self.device, self.workgroup_size);
     }
 
+    #[instrument(skip(self, camera_buffers, lights_buffers, depth_texture))]
     pub fn compute(&mut self, camera_buffers: &BufferWrapper, lights_buffers: &LightUniformBuffers, depth_texture: &RenderTexture) {
+        self.cleanup();
         let mut encoder = self.device.create_command_encoder(&wgpu::CommandEncoderDescriptor {
             label: Some("LightCullCompute"),
         });
@@ -234,8 +238,7 @@ impl LightCullCompute {
         }
 
         self.queue.submit(std::iter::once(encoder.finish()));
-        self.device.poll(wgpu::Maintain::Wait);
+        //self.device.poll(wgpu::Maintain::Wait);
-        self.cleanup();
     }
 
     pub fn cleanup(&mut self) {

lyra-game/src/render/renderer.rs

@@ -12,7 +12,7 @@ use lyra_ecs::{Entity, Tick};
 use lyra_ecs::query::{Entities, TickOf};
 use lyra_ecs::World;
 use lyra_scene::{SceneGraph, WorldTransform};
-use tracing::{debug, warn};
+use tracing::{debug, instrument, warn};
 use uuid::Uuid;
 use wgpu::{BindGroupLayout, Limits};
 use wgpu::util::DeviceExt;
@@ -113,6 +113,7 @@ pub struct BasicRenderer {
 }
 
 impl BasicRenderer {
+    #[instrument(skip(window))]
     pub async fn create_with_window(window: Arc<Window>) -> BasicRenderer {
         let size = window.inner_size();
 
@@ -260,6 +261,7 @@ impl BasicRenderer {
     }
 
     /// Checks if the mesh buffers in the GPU need to be updated.
+    #[instrument(skip(self, _entity, meshh))]
     fn check_mesh_buffers(&mut self, _entity: Entity, meshh: &ResHandle<Mesh>) {
         let mesh_uuid = meshh.uuid();
 
@@ -299,6 +301,7 @@ impl BasicRenderer {
         }
     }
 
+    #[instrument(skip(self, mesh))]
     fn create_vertex_index_buffers(&mut self, mesh: &Mesh) -> (BufferStorage, Option<(wgpu::IndexFormat, BufferStorage)>) {
         let positions = mesh.position().unwrap();
         let tex_coords: Vec<glam::Vec2> = mesh.tex_coords().cloned()
@@ -348,6 +351,7 @@ impl BasicRenderer {
         ( vertex_buffer, indices )
     }
 
+    #[instrument(skip(self, mesh))]
     fn create_mesh_buffers(&mut self, mesh: &Mesh) -> MeshBufferStorage {
         let (vertex_buffer, buffer_indices) = self.create_vertex_index_buffers(mesh);
 
@@ -374,6 +378,7 @@ impl BasicRenderer {
     }
 
     /// Processes the mesh for the renderer, storing and creating buffers as needed. Returns true if a new mesh was processed.
+    #[instrument(skip(self, transform, mesh, entity))]
     fn process_mesh(&mut self, entity: Entity, transform: Transform, mesh: &Mesh, mesh_uuid: Uuid) -> bool {
         let _ = transform;
         /* if self.transform_buffers.should_expand() {
@@ -394,6 +399,7 @@ impl BasicRenderer {
         } else { false }
     }
 
+    #[instrument(skip(self, now, transform, entity))]
     fn interpolate_transforms(&mut self, now: Instant, last_epoch: Tick, entity: Entity, transform: &Transform, transform_epoch: Tick) -> Transform {
         let cached = match self.entity_last_transforms.get_mut(&entity) {
             Some(last) if transform_epoch == last_epoch => {
@@ -429,6 +435,7 @@ impl BasicRenderer {
 }
 
 impl Renderer for BasicRenderer {
+    #[instrument(skip(self, main_world))]
     fn prepare(&mut self, main_world: &mut World) {
         let last_epoch = main_world.current_tick();
         let now_inst = Instant::now();
@@ -526,6 +533,7 @@ impl Renderer for BasicRenderer {
         self.light_buffers.update_lights(&self.queue, last_epoch, main_world);
     }
 
+    #[instrument(skip(self))]
     fn render(&mut self) -> Result<(), wgpu::SurfaceError> {
         let output = self.surface.get_current_texture()?;
         let view = output.texture.create_view(&wgpu::TextureViewDescriptor::default());
@@ -626,6 +634,7 @@ impl Renderer for BasicRenderer {
         Ok(())
     }
 
+    #[instrument(skip(self))]
     fn on_resize(&mut self, new_size: winit::dpi::PhysicalSize<u32>) {
         if new_size.width > 0 && new_size.height > 0 {
             self.size = new_size;

lyra-game/src/render/transform_buffer_storage.rs

@@ -1,6 +1,7 @@
 use std::{collections::{HashMap, VecDeque}, hash::{BuildHasher, DefaultHasher, Hash, Hasher, RandomState}, num::NonZeroU64};
 
 use lyra_ecs::Entity;
+use tracing::instrument;
 use uuid::Uuid;
 use wgpu::Limits;
 
@@ -212,6 +213,7 @@ impl TransformBuffers {
     /// 
     /// # Panics
     /// Panics if the `entity_group` is not already inside of the buffers.
+    #[instrument(skip(self, queue, limits, entity_group, transform, normal_matrix))]
     pub fn update_transform(&mut self, queue: &wgpu::Queue, limits: &Limits, entity_group: TransformGroup, transform: glam::Mat4, normal_matrix: glam::Mat3) -> TransformIndex {
         let index = *self.groups.get(entity_group.into())
             .expect("Use 'push_transform' for new entities");
@@ -228,6 +230,7 @@ impl TransformBuffers {
     }
 
     /// Push a new transform into the buffers.
+    #[instrument(skip(self, queue, limits, entity_group, transform, normal_matrix))]
     pub fn push_transform(&mut self, queue: &wgpu::Queue, limits: &Limits, entity_group: TransformGroup, transform: glam::Mat4, normal_matrix: glam::Mat3) -> TransformIndex {
         self.groups.insert(entity_group.into(), || {
             // this closure is only called when there are no values that can be reused,
@@ -264,6 +267,7 @@ impl TransformBuffers {
     /// Update an existing transform group or if its not existing yet, pushes it to the buffer.
     /// 
     /// Returns: the index that the transform is at in the buffers.
+    #[instrument(skip(self, queue, limits, group, transform_fn))]
     pub fn update_or_push<F>(&mut self, queue: &wgpu::Queue, limits: &Limits, group: TransformGroup, transform_fn: F) -> TransformIndex
         where F: Fn() -> (glam::Mat4, glam::Mat3)
     {   
@@ -279,6 +283,7 @@ impl TransformBuffers {
     /// 
     /// This object has a chain of uniform buffers, when the buffers are expanded, a new
     /// "chain-link" is created.
+    #[instrument(skip(self, device))]
     pub fn expand_buffers(&mut self, device: &wgpu::Device) {
         let limits = device.limits();
         let max_buffer_sizes = self.max_transform_count as u64 * limits.min_uniform_buffer_offset_alignment as u64;