performance counters

Cargo.toml

@@ -20,6 +20,9 @@ gilrs = "0.7.4"
 gltf = "0.15.2"
 glyph_brush = "0.7"
 
+[profile.release]
+debug = 1
+
 [[bin]]
 name = "converter"
 path = "build/converter/src/main.rs"

src/game/components.rs

@@ -1,4 +1,4 @@
-use crate::{input::InputState, text::update_text, vulkan::{VulkanRenderer, gameobject::{GameObject, GameObjectHandle, Updatable}}};
+use crate::{input::InputState, text::update_text, vulkan::{PERF_COUNTER_SIZE, VulkanRenderer, gameobject::{GameObject, GameObjectHandle, Updatable}}};
 
 use super::GameState;
 
@@ -7,8 +7,12 @@ pub struct FpsCounter {
 }
 
 impl Updatable for FpsCounter {
-    fn update(&mut self, delta_time: f32, _input: &InputState, game_state: &mut GameState, game_objects: &mut Vec<GameObject>, renderer: &mut VulkanRenderer) {
+    fn update(&mut self, _delta_time: f32, _input: &InputState, game_state: &mut GameState, game_objects: &mut Vec<GameObject>, renderer: &mut VulkanRenderer) {
-        let text = format!("{}ms\n{}fps", delta_time * 1000., 1. / delta_time);
+        let update_duration = renderer.game_data.update_perf_counters.iter().sum::<u128>() / PERF_COUNTER_SIZE as u128;
+        let render_duration = renderer.game_data.render_perf_counters.iter().sum::<u128>() / PERF_COUNTER_SIZE as u128;
+        let other_duration = renderer.game_data.other_perf_counters.iter().sum::<u128>() / PERF_COUNTER_SIZE as u128;
+        let other_variance = renderer.game_data.other_perf_counters.iter().fold(0, |acc, b| acc + (*b as i128 - other_duration as i128) * (*b as i128 - other_duration as i128)) / PERF_COUNTER_SIZE as i128;
+        let text = format!("Update: {:.0}ms\nRender: {:.0}ms\nTotal: {:.0}ms (±{:.1})\nDelta: {:.0}ms", update_duration as f64 / 1000., render_duration as f64 / 1000., other_duration as f64 / 1000., f64::sqrt(other_variance as f64) / 1000., _delta_time * 1000.);
         update_text(self.game_object, &text, 30., renderer, &mut game_state.brush, game_objects)
     }
 }

src/game/mod.rs

@@ -1,4 +1,4 @@
-use std::time::SystemTime;
+use std::time::Instant;
 use cgmath::{Deg, Euler, Quaternion, vec3};
 use glyph_brush::GlyphBrush;
 use winit::event::Event;
@@ -19,6 +19,22 @@ pub mod player;
 mod level;
 mod components;
 
+pub struct GameState {
+    pub paused: bool,
+    pub brush: GlyphBrush<Vec<TextVertex>>,
+    pub test_str: String,
+}
+
+impl GameState {
+    fn new() -> GameState {
+        GameState {
+            brush: create_brush(),
+            paused: false,
+            test_str: "".to_string(),
+        }
+    }
+}
+
 pub struct TestGame {
     pub input: InputState,
     pub player: Player,
@@ -30,12 +46,6 @@ pub struct TestGame {
     pub game_state: GameState,
 }
 
-pub struct GameState {
-    pub paused: bool,
-    pub brush: GlyphBrush<Vec<TextVertex>>,
-    pub test_str: String,
-}
-
 impl Game for TestGame {
     fn get_game_objects(&self) -> &Vec<GameObject> {
         &self.game_objects
@@ -46,6 +56,8 @@ impl Game for TestGame {
     }
 
     fn update(self: &mut Self, renderer: &mut VulkanRenderer) -> ObjectUniformData {
+        let precise_start = Instant::now();
+
         // Input and timing
         self.input.frame_start();
         let time = (renderer.game_data.start_time.elapsed().unwrap().as_micros() as f64 / 1000000.0) as f32;
@@ -84,9 +96,7 @@ impl Game for TestGame {
         }
 
         if self.input.button_down("print_framerate") {
-            println!("{:.0} ms / {:.0} FPS", frame_time * 1000.0, 1.0 / frame_time);
+            println!("{:?}", renderer.game_data.other_perf_counters);
-            print_quat_as_euler(self.player.camera.rotation);
-            println!();
         }
 
         if self.input.button_just_pressed("test") {
@@ -107,6 +117,9 @@ impl Game for TestGame {
         self.last_time = time;
         self.input.frame_end();
 
+        let precise_duration = precise_start.elapsed().as_micros();
+        renderer.game_data.update_perf_counters[renderer.game_data.performance_counter_index] = precise_duration;
+
         ObjectUniformData {
             view: self.player.camera.view.into(),
             projection: self.player.camera.proj.into(),
@@ -132,11 +145,7 @@ impl TestGame {
             texture_index_counter: 0,
             last_time: 0.0,
             components: vec![],
-            game_state: GameState {
+            game_state: GameState::new()
-                brush: create_brush(),
-                paused: false,
-                test_str: "".to_string(),
-            }
         }
     }
 
@@ -180,14 +189,14 @@ impl TestGame {
         }
 
         for doc_image in document.images() {
-            let texture_start_time = SystemTime::now();
+            let texture_start_time = Instant::now();
             
             let texture = vulkan::dds::upload_texture_from_file(&format!("models/textures/{}.dds", doc_image.name().unwrap()), renderer).unwrap();
             renderer.game_data.textures.push(texture);
             self.texture_index_counter += 1;
             
             if self.log_config.mesh_load_info {
-                println!("Uploading texture took {:?}ms", texture_start_time.elapsed().unwrap().as_millis());
+                println!("Uploading texture took {:?}ms", texture_start_time.elapsed().as_millis());
             }
         }
         mesh_handles

src/game/player.rs

@@ -180,7 +180,7 @@ pub fn intersect_triangle(ray_origin: Vector3<f32>, ray_direction: Vector3<f32>,
 }
 
 impl Updatable for Player {
-    fn update(&mut self, delta_time: f32, input: &InputState, game_state: &mut GameState, game_objects: &mut Vec<GameObject>, renderer: &mut VulkanRenderer) {
+    fn update(&mut self, delta_time: f32, input: &InputState, _game_state: &mut GameState, game_objects: &mut Vec<GameObject>, renderer: &mut VulkanRenderer) {
         // Edit mode
         if input.button_just_pressed("toggle_edit") {
             if self.movement_mode == FirstPerson {

src/vulkan/mod.rs

@@ -1,4 +1,4 @@
-use std::sync::Arc;
+use std::{sync::Arc, time::Instant};
 use std::time::SystemTime;
 
 use cgmath::{Matrix4, SquareMatrix};
@@ -44,6 +44,8 @@ const VALIDATION_LAYERS: &[&str] = &[
     "VK_LAYER_KHRONOS_validation",
 ];
 
+pub const PERF_COUNTER_SIZE: usize = 1000;
+
 #[derive(Default, Debug, Clone)]
 pub struct Vertex {
     pub position: [f32; 3],
@@ -113,6 +115,11 @@ pub struct GameData {
     pub meshes: Vec<Mesh<Vertex>>,
     pub meshes_text: Vec<Mesh<TextVertex>>,
     pub textures: Vec<Texture>,
+    pub update_perf_counters: [u128; PERF_COUNTER_SIZE],
+    pub render_perf_counters: [u128; PERF_COUNTER_SIZE],
+    pub other_perf_counters: [u128; PERF_COUNTER_SIZE],
+    pub other_perf_instant: Instant,
+    pub performance_counter_index: usize,
 }
 
 pub(crate) type RendererDescriptorSets = dyn DescriptorSet + Send + Sync;
@@ -151,6 +158,11 @@ impl VulkanRenderer {
             meshes: vec![],
             meshes_text: vec![],
             textures: vec![],
+            update_perf_counters: [0; PERF_COUNTER_SIZE],
+            render_perf_counters: [0; PERF_COUNTER_SIZE],
+            other_perf_counters: [0; PERF_COUNTER_SIZE],
+            performance_counter_index: 0,
+            other_perf_instant: Instant::now(),
         };
 
         // Create basic vulkan instance with layers and info
@@ -333,6 +345,8 @@ impl VulkanRenderer {
     }
 
     pub fn render_loop(self: &mut Self, new_ubo: vs::ty::ObjectUniformData, game_objects: &Vec<GameObject>) {
+        let precise_start = Instant::now();
+
         // cleanup previous frame
         self.previous_frame_end.as_mut().unwrap().cleanup_finished();
 
@@ -423,6 +437,8 @@ impl VulkanRenderer {
                 self.previous_frame_end = Some(Box::new(sync::now(self.device.clone())) as Box<_>);
             }
         };
+
+        self.game_data.render_perf_counters[self.game_data.performance_counter_index] = precise_start.elapsed().as_micros();
     }
 
     pub fn upload_mesh(self: &mut Self, mesh: CPUMesh, original_path: Option<String>) -> usize {
@@ -671,6 +687,9 @@ pub fn start_event_loop(mut renderer: VulkanRenderer, mut game: Box<dyn Game>, e
             Event::RedrawEventsCleared => {
                 let ubo = game.update(&mut renderer);
                 renderer.render_loop(ubo, &game.get_game_objects());
+                renderer.game_data.other_perf_counters[renderer.game_data.performance_counter_index] = renderer.game_data.other_perf_instant.elapsed().as_micros();
+                renderer.game_data.other_perf_instant = Instant::now();
+                renderer.game_data.performance_counter_index = (renderer.game_data.performance_counter_index + 1) % PERF_COUNTER_SIZE;
             },
             _ => {}
         }