take optional wait semaphore when presenting

no longer assume that frame.release is necessarily signaled.
this previously caused a hang in the async_swapchain_acquiring test.

crates/game/src/main.rs

@@ -1,4 +1,4 @@
-use std::collections::BTreeMap;
+use std::{collections::BTreeMap, time::Instant};
 
 use renderer::Renderer;
 use tracing::info;
@@ -23,6 +23,7 @@ struct WinitState {
     window_attrs: WindowAttributes,
     windows2: BTreeMap<WindowId, WindowState>,
     renderer: Renderer<WindowId>,
+    last_redraw: std::time::Instant,
 }
 
 impl WinitState {
@@ -38,6 +39,7 @@ impl WinitState {
                 .with_inner_size(LogicalSize::new(Self::BASE_WIDTH, Self::BASE_HEIGHT)),
             // TODO: pass down this error and add some kind of error handling UI or dump
             renderer: Renderer::new(display.as_raw()).expect("renderer"),
+            last_redraw: std::time::Instant::now(),
         }
     }
 
@@ -57,8 +59,10 @@ impl WinitState {
         _ = window_id;
         info!(
             window_id = u64::from(window_id),
-            "TODO: implement draw request"
+            "TODO: implement draw request {}ms",
+            self.last_redraw.elapsed().as_millis()
         );
+        self.last_redraw = std::time::Instant::now();
         if let Some(window) = self.windows2.get_mut(&window_id) {
             // egui
 
@@ -66,14 +70,14 @@ impl WinitState {
             window.demo_app.ui(&window.egui_platform.context());
             let output = window.egui_platform.end_pass(Some(&window.window));
 
-            let egui_state = self
+            self.renderer
-                .renderer
                 .draw_egui(&window.egui_platform.context(), output)
                 .unwrap();
 
             // rendering
             self.renderer
-                .debug_draw(&window_id, || { // window.window.pre_present_notify()
+                .debug_draw(&window_id, || {
+                    window.window.pre_present_notify();
                 })
                 .expect("drawing");
             window.window.request_redraw();
@@ -144,6 +148,10 @@ impl ApplicationHandler for WinitState {
         for (&window, &resize) in self.last_resize_events.clone().iter() {
             self.handle_final_resize(window, resize);
         }
+        // let window_ids = self.windows2.keys().cloned().collect::<Vec<_>>();
+        // for window in window_ids {
+        //     self.handle_draw_request(window);
+        // }
         self.last_resize_events.clear();
 
         if self.windows2.is_empty() {

crates/renderer/src/commands.rs

@@ -43,6 +43,16 @@ impl SingleUseCommandPool {
         }))
     }
 
+    #[allow(dead_code)]
+    pub fn reset(&self) -> VkResult<()> {
+        unsafe {
+            self.pool.with_locked(|pool| {
+                self.device
+                    .dev()
+                    .reset_command_pool(*pool, vk::CommandPoolResetFlags::empty())
+            })
+        }
+    }
     pub fn alloc(self: &Arc<Self>) -> VkResult<SingleUseCommand> {
         SingleUseCommand::new(self.device.clone(), self.clone())
     }

crates/renderer/src/lib.rs

@@ -18,6 +18,7 @@ use std::{
         atomic::{AtomicU32, AtomicU64},
         Arc,
     },
+    time::Instant,
 };
 
 use egui::Color32;
@@ -623,8 +624,8 @@ pub struct SwapchainFrame {
 }
 
 impl SwapchainFrame {
-    fn present(self) -> Result<()> {
+    fn present(self, wait: Option<vk::Semaphore>) -> Result<()> {
-        self.swapchain.clone().present(self)
+        self.swapchain.clone().present(self, wait)
     }
 }
 
@@ -939,11 +940,14 @@ impl Swapchain {
         }
     }
 
-    fn present(&self, frame: SwapchainFrame) -> Result<()> {
+    fn present(&self, frame: SwapchainFrame, wait: Option<vk::Semaphore>) -> Result<()> {
         let swpchain = self.swapchain.lock();
         let queue = self.device.present_queue().lock();
 
-        let wait_semaphores = [frame.release];
+        let wait_semaphores = wait
+            .as_ref()
+            .map(|sema| core::slice::from_ref(sema))
+            .unwrap_or_default();
 
         // TODO: make this optional for devices with no support for present_wait/present_id
         let present_id = self
@@ -955,7 +959,7 @@ impl Swapchain {
         let present_info = vk::PresentInfoKHR::default()
             .image_indices(core::slice::from_ref(&frame.index))
             .swapchains(core::slice::from_ref(&swpchain))
-            .wait_semaphores(&wait_semaphores)
+            .wait_semaphores(wait_semaphores)
             .push_next(&mut present_id);
 
         // call winits pre_present_notify here
@@ -2323,9 +2327,6 @@ impl<W> Renderer<W> {
             textures_indices.push(idx as u32);
         }
 
-        eprintln!("{:?}", self.egui_state.textures);
-        eprintln!("{draw_calls:?}");
-
         let num_draw_calls = draw_calls.len();
         let device = self.vulkan.device.clone();
         let (draw_staging, vertices, indices, draw_calls, texture_ids) = {
@@ -2523,16 +2524,19 @@ impl<W> Renderer<W> {
         W: core::hash::Hash + Eq + Borrow<K>,
     {
         let dev = self.vulkan.device.clone();
-
-        unsafe { dev.dev().device_wait_idle()? };
-
         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 cmd = pool.alloc()?;
+            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!(
@@ -2541,25 +2545,14 @@ impl<W> Renderer<W> {
                 );
             }
 
-            // let image = images::Image2D::new_exclusive(
-            //     self.vulkan.alloc.clone(),
-            //     extent,
-            //     1,
-            //     1,
-            //     vk::Format::R8G8B8A8_UNORM,
-            //     vk::ImageTiling::OPTIMAL,
-            //     vk::ImageUsageFlags::TRANSFER_SRC,
-            //     vk_mem::MemoryUsage::AutoPreferDevice,
-            //     vk_mem::AllocationCreateFlags::empty(),
-            // )?;
-
-            // let view = image.view(&dev, vk::ImageAspectFlags::COLOR)?;
-
             let [r, g, b] = rand::prelude::StdRng::seed_from_u64(ctx.surface.surface.as_raw())
                 .gen::<[f32; 3]>();
             let clear_color = Rgba([r, g, b, 1.0]);
 
-            {
+            let egui_ctx = self.egui_state.render_state.take();
+
+            let cmd = util::timed("record command buffer", || {
+                let cmd = pool.alloc()?;
                 cmd.image_barrier(
                     frame.image,
                     vk::ImageAspectFlags::COLOR,
@@ -2590,7 +2583,6 @@ impl<W> Renderer<W> {
                     None,
                 );
 
-                let egui_ctx = self.egui_state.render_state.take();
                 if let Some(ctx) = egui_ctx.as_ref() {
                     _ = &ctx.texture_ids;
 
@@ -2661,29 +2653,31 @@ impl<W> Renderer<W> {
                     None,
                 );
 
-                let future = cmd.submit_async(
+                Result::Ok(cmd)
-                    Some((frame.acquire, vk::PipelineStageFlags::TRANSFER)),
+            })?;
-                    Some(frame.release),
+            let now = Instant::now();
-                    Arc::new(sync::Fence::create(dev.clone())?),
+            let future = cmd.submit_async(
-                )?;
+                Some((frame.acquire, vk::PipelineStageFlags::TRANSFER)),
+                Some(frame.release),
+                Arc::new(sync::Fence::create(dev.clone())?),
+            )?;
 
-                // call pre_present_notify
+            // call pre_present_notify
-                pre_present_cb();
+            pre_present_cb();
 
-                frame.present()?;
+            let wait = Some(frame.release);
-                future.block()?;
+            frame.present(wait)?;
+            future.block()?;
+            eprintln!("frametime: {}ms", now.elapsed().as_micros() as f32 / 1e3);
 
-                egui_ctx.map(|ctx| {
+            egui_ctx.map(|ctx| {
-                    for id in ctx.textures_to_free {
+                for id in ctx.textures_to_free {
-                        self.texture_handler.remove_texture(id);
+                    self.texture_handler.remove_texture(id);
-                    }
+                }
-                });
+            });
-
-                // wait for idle here is unnecessary.
-                // dev.dev().device_wait_idle();
-            }
         }
 
+        info!("debug_draw: {}ms", now.elapsed().as_micros() as f32 / 1e3);
         Ok(())
     }
 
@@ -3337,16 +3331,19 @@ mod test_swapchain {
     #[tracing_test::traced_test]
     #[test]
     fn async_swapchain_acquiring() {
-        let (_vk, ctx) = create_headless_vk().expect("init");
+        let (_vlk, ctx) = create_headless_vk().expect("init");
         let ctx = Arc::new(ctx);
-        let (rx, handle) = ctx.images();
+        let (rx, handle) = ctx.clone().images();
+
+        eprintln!("hello world!");
 
         let mut count = 0;
         loop {
             let now = std::time::Instant::now();
             let frame = rx.recv_blocking().expect("recv");
-            _ = frame.present();
+
-            tracing::info!("mspf: {}ms", now.elapsed().as_secs_f64() / 1000.0);
+            _ = frame.present(None);
+            tracing::info!("mspf: {:.3}ms", now.elapsed().as_micros() as f32 / 1e3);
             count += 1;
             if count > 1000 {
                 smol::block_on(handle.cancel());

crates/renderer/src/util.rs

@@ -323,3 +323,11 @@ pub fn hash_f32<H: std::hash::Hasher>(state: &mut H, f: f32) {
         std::num::FpCategory::Subnormal | std::num::FpCategory::Normal => f.to_bits().hash(state),
     }
 }
+
+pub fn timed<T, F: FnOnce() -> T>(label: &str, f: F) -> T {
+    let now = std::time::Instant::now();
+    let out = f();
+    tracing::info!("{label}: {}ms", now.elapsed().as_micros() as f32 / 1e3);
+
+    out
+}