tracing info/debug changes

Cargo.toml

@@ -14,7 +14,7 @@ ash-window = "0.13.0"
 glam = {version = "0.29.0", features = ["bytemuck"]}
 thiserror = "2.0"
 tracing = "0.1.40"
-tracing-subscriber = "0.3.18"
+tracing-subscriber = {version ="0.3.18", features = ["env-filter"]}
 vk-mem = "0.4.0"
 vk-sync = "0.1.6"
 tinyvec = "1.8"

crates/game/src/main.rs

@@ -1,4 +1,4 @@
-use std::{collections::BTreeMap, time::Instant};
+use std::collections::BTreeMap;
 
 use renderer::Renderer;
 use tracing::info;
@@ -57,7 +57,7 @@ impl WinitState {
 
     fn handle_draw_request(&mut self, window_id: WindowId) {
         _ = window_id;
-        info!(
+        tracing::debug!(
             window_id = u64::from(window_id),
             "TODO: implement draw request {}ms",
             self.last_redraw.elapsed().as_millis()
@@ -138,13 +138,13 @@ impl WinitState {
 
 impl ApplicationHandler for WinitState {
     fn resumed(&mut self, event_loop: &winit::event_loop::ActiveEventLoop) {
-        tracing::info!("winit::resumed");
+        tracing::debug!("winit::resumed");
 
         self.create_window(event_loop);
     }
 
     fn about_to_wait(&mut self, event_loop: &winit::event_loop::ActiveEventLoop) {
-        tracing::info!("winit::about_to_wait");
+        tracing::trace!("winit::about_to_wait");
         for (&window, &resize) in self.last_resize_events.clone().iter() {
             self.handle_final_resize(window, resize);
         }

crates/renderer/Cargo.toml

@@ -6,7 +6,7 @@ edition = "2021"
 [dependencies]
 tinyvec = {workspace = true}
 rand = {workspace = true}
-tokio = {workspace = true, features = ["rt", "sync"]}
+# tokio = {workspace = true, features = ["rt", "sync"]}
 dyn-clone = "1"
 anyhow = "1.0.89"
 ash = "0.38.0"
@@ -14,13 +14,10 @@ ash-window = "0.13.0"
 glam = {workspace = true}
 thiserror = {workspace = true} 
 tracing = "0.1.40"
-tracing-subscriber = "0.3.18"
 vk-mem = "0.4.0"
-vk-sync = "0.1.6"
 crossbeam = "0.8.4"
 parking_lot = "0.12.3"
 smol.workspace = true
-tracing-test = "0.2.5"
 
 raw-window-handle = { workspace = true }
 egui = { workspace = true , features = ["bytemuck"]}
@@ -28,3 +25,6 @@ egui_winit_platform = { workspace = true }
 bytemuck = { version = "1.21.0", features = ["derive"] }
 indexmap = "2.7.0"
 itertools = "0.14.0"
+
+[dev-dependencies]
+tracing-test = "0.2.5"

crates/renderer/src/commands.rs

@@ -394,7 +394,7 @@ impl SingleUseCommand {
         self.pool.queue().with_locked(|queue| unsafe {
             self.device.dev().queue_submit(queue, &[submit_info], fence)
         })?;
-        tracing::info!(
+        tracing::trace!(
             "submitted queue {:?} and fence {:?}",
             self.pool.queue(),
             fence

crates/renderer/src/lib.rs

@@ -34,7 +34,6 @@ use ash::{
 use dyn_clone::DynClone;
 use rand::{Rng, SeedableRng};
 use raw_window_handle::RawDisplayHandle;
-use tracing::info;
 
 mod buffers;
 mod commands;
@@ -562,7 +561,7 @@ impl Drop for Swapchain {
     fn drop(&mut self) {
         unsafe {
             _ = self.device.wait_queue_idle(self.device.present_queue());
-            info!("dropping swapchain {:?}", self.swapchain);
+            tracing::debug!("dropping swapchain {:?}", self.swapchain);
             for view in &self.image_views {
                 self.device.dev().destroy_image_view(*view, None);
             }
@@ -839,7 +838,7 @@ impl Swapchain {
                 .collect::<VkResult<Vec<_>>>()?
         };
 
-        tracing::info!("fences: {fences:?}");
+        tracing::debug!("fences: {fences:?}");
 
         Ok(Self {
             instance,
@@ -894,7 +893,7 @@ impl Swapchain {
             )
             .unwrap() as usize;
 
-        tracing::info!(frame, "acquiring image for frame {frame}");
+        tracing::debug!(frame, "acquiring image for frame {frame}");
 
         async move {
             let fence = self.fences[frame].clone();
@@ -2256,7 +2255,7 @@ impl<W> Renderer<W> {
                     );
                     self.texture_handler
                         .insert_image_with_id(id, texture.clone());
-                    info!("new texture for egui: {egui_id:?} -> {id:?}");
+                    tracing::debug!("new texture for egui: {egui_id:?} -> {id:?}");
                 }
 
                 (staging, texture)
@@ -2515,18 +2514,10 @@ impl<W> Renderer<W> {
     {
         let dev = self.vulkan.device.clone();
         let pool = commands::SingleUseCommandPool::new(dev.clone(), dev.graphics_queue().clone())?;
-        let now = Instant::now();
-
-        //unsafe { dev.dev().device_wait_idle()? };
 
         if let Some(ctx) = self.window_contexts.get(window) {
-            let now = Instant::now();
             let (frame, suboptimal) =
                 smol::block_on(ctx.current_swapchain.read().clone().acquire_image())?;
-            eprintln!(
-                "image acquisition: {}ms",
-                now.elapsed().as_micros() as f32 / 1e3
-            );
 
             if suboptimal {
                 tracing::warn!(
@@ -2645,7 +2636,7 @@ impl<W> Renderer<W> {
 
                 Result::Ok(cmd)
             })?;
-            let now = Instant::now();
+
             let future = cmd.submit_async(
                 Some((frame.acquire, vk::PipelineStageFlags::TRANSFER)),
                 Some(frame.release),
@@ -2658,7 +2649,6 @@ impl<W> Renderer<W> {
             let wait = Some(frame.release);
             frame.present(wait)?;
             future.block()?;
-            eprintln!("frametime: {}ms", now.elapsed().as_micros() as f32 / 1e3);
 
             egui_ctx.map(|ctx| {
                 for id in ctx.textures_to_free {
@@ -2667,7 +2657,6 @@ impl<W> Renderer<W> {
             });
         }
 
-        info!("debug_draw: {}ms", now.elapsed().as_micros() as f32 / 1e3);
         Ok(())
     }
 

crates/renderer/src/sync.rs

@@ -64,10 +64,10 @@ impl SyncThreadpool {
 
                 impl SyncThread {
                     fn run(self, barrier: Arc<std::sync::Barrier>) {
-                        tracing::info!("spawned new sync thread");
+                        tracing::trace!("spawned new sync thread");
                         barrier.wait();
                         while let Ok((sync, waker)) = self.rx.recv_timeout(self.thread_dies_after) {
-                            tracing::info!("received ({:?}, {:?})", sync, waker);
+                            tracing::trace!("received ({:?}, {:?})", sync, waker);
                             loop {
                                 let wait_result = match &sync {
                                     SyncPrimitive::Fence(fence) => {
@@ -287,7 +287,7 @@ impl Future for FenceFuture<'_> {
         cx: &mut std::task::Context<'_>,
     ) -> std::task::Poll<Self::Output> {
         if self.fence.is_signaled() {
-            tracing::info!("fence ({:?}) is signaled", self.fence);
+            tracing::trace!("fence ({:?}) is signaled", self.fence);
             _ = self.fence.reset();
             std::task::Poll::Ready(())
         } else {