Add frame trace points

src/main.rs

@@ -202,9 +202,13 @@ fn main() {
                 .unwrap();
             let command_buffer = cmd_buffer_builder.build().unwrap();
 
-            future
+            let res = future
                 .then_execute(vk.queue().clone(), command_buffer)
-                .unwrap()
+                .unwrap();
+
+            vk.frame_tracer().trace("Render pass 1 command send");
+
+            res
         },
     );
 }

src/render/context.rs

@@ -26,7 +26,7 @@ use winit::{
 
 use crate::error::EngineError;
 
-use super::{event::RenderEvent, FrameTimer};
+use super::{event::RenderEvent, FrameTimer, FrameTracer};
 
 pub struct VulkanContext {
     #[allow(dead_code)]
@@ -41,6 +41,8 @@ pub struct VulkanContext {
 
     surface: Arc<Surface<Window>>,
     viewport: Viewport,
+
+    frame_tracer: FrameTracer,
 }
 
 impl VulkanContext {
@@ -135,9 +137,15 @@ impl VulkanContext {
             render_pass,
             framebuffers,
             viewport,
+
+            frame_tracer: FrameTracer::new()
         })
     }
 
+    pub fn frame_tracer(&mut self) -> &mut FrameTracer {
+        &mut self.frame_tracer
+    }
+
     pub fn run<
         T: GpuFuture + 'static,
         EventHandler: 'static + FnMut(RenderEvent, &mut ControlFlow),
@@ -173,11 +181,13 @@ impl VulkanContext {
                     recreate_swapchain = true;
                 }
                 Event::RedrawEventsCleared => {
+                    self.frame_tracer.reset();
                     previous_frame_end
                         .as_mut()
                         .take()
                         .unwrap()
                         .cleanup_finished();
+                    self.frame_tracer.trace("Previous frame cleanup");
 
                     if recreate_swapchain {
                         let size = self.recreate_swapchain().unwrap();
@@ -199,6 +209,8 @@ impl VulkanContext {
                         recreate_swapchain = true;
                     }
 
+                    self.frame_tracer.trace("Acquire next frame");
+
                     let future = previous_frame_end.take().unwrap().join(acquire_future);
                     let framebuffer = self.framebuffers[image_num].clone();
                     let future = render_handler(&mut self, future, framebuffer)
@@ -225,9 +237,12 @@ impl VulkanContext {
                         }
                     }
 
+                    self.frame_tracer.trace("Frame finish");
+
                     frame_timer.frame_done();
                     if frame_timer.update() {
                         log::debug!("{} frames/s", frame_timer.fps());
+                        log::debug!("{:?}", self.frame_tracer.timings());
                     }
                 }
                 _ => (),

src/render/mod.rs

@@ -1,4 +1,4 @@
-use std::time::Instant;
+use std::time::{Instant, Duration};
 
 pub mod context;
 pub mod shaders;
@@ -11,6 +11,11 @@ pub struct FrameTimer {
     counter: u64
 }
 
+pub struct FrameTracer {
+    frame_start: Option<Instant>,
+    trace_points: Vec<(String, Instant)>,
+}
+
 impl FrameTimer {
     pub fn new() -> Self {
         Self {
@@ -43,3 +48,29 @@ impl FrameTimer {
         self.frames_per_second
     }
 }
+
+impl FrameTracer {
+    pub const fn new() -> Self {
+        Self {
+            frame_start: None,
+            trace_points: vec![]
+        }
+    }
+
+    pub fn reset(&mut self) {
+        self.frame_start = Some(Instant::now());
+        self.trace_points.clear();
+    }
+
+    pub fn trace(&mut self, name: &str) {
+        self.trace_points.push((name.to_owned(), Instant::now()));
+    }
+
+    pub fn timings(&self) -> Vec<(String, Duration)> {
+        if let Some(start) = self.frame_start {
+            self.trace_points.iter().map(|point| (point.0.clone(), point.1 - start)).collect()
+        } else {
+            vec![]
+        }
+    }
+}