Implement basic profilng output

src/context.rs

@@ -1,6 +1,7 @@
 use std::sync::Arc;
 
 use thiserror::Error;
+use wgpu_profiler::{GpuProfiler, GpuProfilerSettings, GpuTimerQueryResult};
 use winit::{
     dpi::PhysicalSize,
     error::{EventLoopError, OsError},
@@ -9,7 +10,13 @@ use winit::{
     window::{Window, WindowBuilder},
 };
 pub trait Pass {
-    fn execute(&self, encoder: &mut wgpu::CommandEncoder, view: &wgpu::TextureView);
+    fn execute(
+        &self,
+        profiler: &GpuProfiler,
+        device: &wgpu::Device,
+        encoder: &mut wgpu::CommandEncoder,
+        view: &wgpu::TextureView,
+    );
 }
 
 #[derive(Error, Debug)]
@@ -28,6 +35,8 @@ pub enum ContextError {
     Os(#[from] OsError),
     #[error("Render failed: {0}")]
     Render(#[from] wgpu::SurfaceError),
+    #[error("Profiler creation failed: {0}")]
+    Profiler(#[from] wgpu_profiler::CreationError),
 }
 
 pub struct Context<'window> {
@@ -39,6 +48,8 @@ pub struct Context<'window> {
     pub adapter: wgpu::Adapter,
     pub device: wgpu::Device,
     pub queue: wgpu::Queue,
+    pub profiler: GpuProfiler,
+    pub latest_profiler_results: Option<Vec<GpuTimerQueryResult>>,
 }
 
 impl<'window> Context<'window> {
@@ -100,6 +111,9 @@ impl<'window> Context<'window> {
         };
         surface.configure(&device, &surface_config);
 
+        log::info!("Creating GPU profiler...");
+        let profiler = GpuProfiler::new(GpuProfilerSettings::default())?;
+
         Ok(Self {
             window,
             instance,
@@ -109,6 +123,8 @@ impl<'window> Context<'window> {
             adapter,
             device,
             queue,
+            profiler,
+            latest_profiler_results: None,
         })
     }
 
@@ -144,7 +160,7 @@ impl<'window> Context<'window> {
         handled
     }
 
-    pub fn render(&self, passes: &[Box<dyn Pass>]) -> Result<(), ContextError> {
+    pub fn render(&mut self, passes: &[Box<dyn Pass>]) -> Result<(), ContextError> {
         let frame = self.surface.get_current_texture()?;
         let view = frame
             .texture
@@ -157,12 +173,22 @@ impl<'window> Context<'window> {
             });
 
         for pass in passes.iter() {
-            pass.execute(&mut encoder, &view);
+            pass.execute(&self.profiler, &self.device, &mut encoder, &view);
         }
 
+        self.profiler.resolve_queries(&mut encoder);
+
         self.queue.submit(Some(encoder.finish()));
         frame.present();
 
+        // Signal to the profiler that the frame is finished.
+        self.profiler.end_frame().unwrap();
+        // Query for oldest finished frame (this is almost certainly not the one we just submitted!) and display results in the command line.
+        self.latest_profiler_results = self
+            .profiler
+            .process_finished_frame(self.queue.get_timestamp_period());
+        console_output(&self.latest_profiler_results);
+
         Ok(())
     }
 }
@@ -238,3 +264,28 @@ impl ContextBuilder {
         Ok((context, event_loop))
     }
 }
+
+fn scopes_to_console_recursive(results: &[GpuTimerQueryResult], indentation: u32) {
+    for scope in results {
+        if indentation > 0 {
+            print!("{:<width$}", "|", width = 4);
+        }
+
+        println!(
+            "{:.3}μs - {}",
+            (scope.time.end - scope.time.start) * 1000.0 * 1000.0,
+            scope.label
+        );
+
+        if !scope.nested_queries.is_empty() {
+            scopes_to_console_recursive(&scope.nested_queries, indentation + 1);
+        }
+    }
+}
+
+fn console_output(results: &Option<Vec<GpuTimerQueryResult>>) {
+    print!("\x1B[2J\x1B[1;1H"); // Clear terminal and put cursor to first row first column
+    if let Some(results) = results {
+        scopes_to_console_recursive(results, 0);
+    }
+}

src/lib.rs

@@ -12,4 +12,4 @@ pub use self::{
     texture::{Texture, TextureBuilder},
 };
 
-pub use {wgpu, winit};
+pub use {wgpu, wgpu_profiler, winit};