[oden] Tracing and also actual 60fps

Sleeping is completely and utterly unreliable.

Cargo.lock

@@ -600,6 +600,19 @@ dependencies = [
  "syn 2.0.18",
 ]
 
+[[package]]
+name = "generator"
+version = "0.7.5"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5cc16584ff22b460a382b7feec54b23d2908d858152e5739a120b949293bd74e"
+dependencies = [
+ "cc",
+ "libc",
+ "log",
+ "rustversion",
+ "windows 0.48.0",
+]
+
 [[package]]
 name = "generic-array"
 version = "0.14.7"
@@ -674,7 +687,7 @@ dependencies = [
  "log",
  "thiserror",
  "winapi",
- "windows",
+ "windows 0.44.0",
 ]
 
 [[package]]
@@ -1010,6 +1023,19 @@ version = "0.4.18"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "518ef76f2f87365916b142844c16d8fefd85039bc5699050210a7778ee1cd1de"
 
+[[package]]
+name = "loom"
+version = "0.5.6"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ff50ecb28bb86013e935fb6683ab1f6d3a20016f123c76fd4c27470076ac30f5"
+dependencies = [
+ "cfg-if",
+ "generator",
+ "scoped-tls",
+ "tracing",
+ "tracing-subscriber",
+]
+
 [[package]]
 name = "malloc_buf"
 version = "0.0.6"
@@ -1019,6 +1045,15 @@ dependencies = [
  "libc",
 ]
 
+[[package]]
+name = "matchers"
+version = "0.1.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558"
+dependencies = [
+ "regex-automata",
+]
+
 [[package]]
 name = "memchr"
 version = "2.5.0"
@@ -1184,6 +1219,16 @@ dependencies = [
  "minimal-lexical",
 ]
 
+[[package]]
+name = "nu-ansi-term"
+version = "0.46.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84"
+dependencies = [
+ "overload",
+ "winapi",
+]
+
 [[package]]
 name = "num-bigint"
 version = "0.4.3"
@@ -1328,6 +1373,7 @@ dependencies = [
  "swc_ecma_transforms_base",
  "swc_ecma_transforms_typescript",
  "swc_ecma_visit",
+ "tracy-client",
  "wgpu",
  "winit",
 ]
@@ -1366,6 +1412,12 @@ dependencies = [
  "redox_syscall 0.3.5",
 ]
 
+[[package]]
+name = "overload"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39"
+
 [[package]]
 name = "owned_ttf_parser"
 version = "0.19.0"
@@ -1625,9 +1677,24 @@ checksum = "81ca098a9821bd52d6b24fd8b10bd081f47d39c22778cafaa75a2857a62c6390"
 dependencies = [
  "aho-corasick",
  "memchr",
- "regex-syntax",
+ "regex-syntax 0.7.2",
 ]
 
+[[package]]
+name = "regex-automata"
+version = "0.1.10"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132"
+dependencies = [
+ "regex-syntax 0.6.29",
+]
+
+[[package]]
+name = "regex-syntax"
+version = "0.6.29"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1"
+
 [[package]]
 name = "regex-syntax"
 version = "0.7.2"
@@ -1675,6 +1742,12 @@ dependencies = [
  "windows-sys 0.48.0",
 ]
 
+[[package]]
+name = "rustversion"
+version = "1.0.12"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "4f3208ce4d8448b3f3e7d168a73f5e0c43a61e32930de3bceeccedb388b6bf06"
+
 [[package]]
 name = "ryu"
 version = "1.0.13"
@@ -1772,6 +1845,15 @@ dependencies = [
  "digest",
 ]
 
+[[package]]
+name = "sharded-slab"
+version = "0.1.4"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "900fba806f70c630b0a382d0d825e17a0f19fcd059a2ade1ff237bcddf446b31"
+dependencies = [
+ "lazy_static",
+]
+
 [[package]]
 name = "shlex"
 version = "1.1.0"
@@ -2272,6 +2354,16 @@ dependencies = [
  "syn 2.0.18",
 ]
 
+[[package]]
+name = "thread_local"
+version = "1.1.7"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "3fdd6f064ccff2d6567adcb3873ca630700f00b5ad3f060c25b5dcfd9a4ce152"
+dependencies = [
+ "cfg-if",
+ "once_cell",
+]
+
 [[package]]
 name = "tiny-skia"
 version = "0.8.4"
@@ -2359,6 +2451,56 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "0955b8137a1df6f1a2e9a37d8a6656291ff0297c1a97c24e0d8425fe2312f79a"
 dependencies = [
  "once_cell",
+ "valuable",
+]
+
+[[package]]
+name = "tracing-log"
+version = "0.1.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "78ddad33d2d10b1ed7eb9d1f518a5674713876e97e5bb9b7345a7984fbb4f922"
+dependencies = [
+ "lazy_static",
+ "log",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-subscriber"
+version = "0.3.17"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "30a651bc37f915e81f087d86e62a18eec5f79550c7faff886f7090b4ea757c77"
+dependencies = [
+ "matchers",
+ "nu-ansi-term",
+ "once_cell",
+ "regex",
+ "sharded-slab",
+ "smallvec",
+ "thread_local",
+ "tracing",
+ "tracing-core",
+ "tracing-log",
+]
+
+[[package]]
+name = "tracy-client"
+version = "0.15.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "434ecabbda9f67eeea1eab44d52f4a20538afa3e2c2770f2efc161142b25b608"
+dependencies = [
+ "loom",
+ "once_cell",
+ "tracy-client-sys",
+]
+
+[[package]]
+name = "tracy-client-sys"
+version = "0.21.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "0d99f5fc382239d08b6bf05bb6206a585bfdb988c878f2499081d0f285ef7819"
+dependencies = [
+ "cc",
 ]
 
 [[package]]
@@ -2439,6 +2581,12 @@ dependencies = [
  "percent-encoding",
 ]
 
+[[package]]
+name = "valuable"
+version = "0.1.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d"
+
 [[package]]
 name = "vec_map"
 version = "0.8.2"
@@ -2773,6 +2921,15 @@ dependencies = [
  "windows-targets 0.42.2",
 ]
 
+[[package]]
+name = "windows"
+version = "0.48.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "e686886bc078bc1b0b600cac0147aadb815089b6e4da64016cbd754b6342700f"
+dependencies = [
+ "windows-targets 0.48.0",
+]
+
 [[package]]
 name = "windows-sys"
 version = "0.45.0"

Cargo.toml

@@ -19,5 +19,6 @@ swc_ecma_parser = "0.136.7"
 swc_ecma_transforms_base = "0.129.13"
 swc_ecma_transforms_typescript = "0.179.18"
 swc_ecma_visit = "0.92.5"
+tracy-client = { version = "0.15.2", features = ["enable"] } # TODO: Make conditional
 wgpu = "0.16"
 winit = "0.28"

src/lib.rs

@@ -2,6 +2,7 @@ use bytemuck;
 use std::collections::HashMap;
 use std::sync::mpsc::Receiver;
 use std::time::Instant;
+use tracy_client::{frame_mark, set_thread_name, span};
 use wgpu::util::DeviceExt;
 use winit::{event::*, event_loop::EventLoop, window::Window, window::WindowBuilder};
 
@@ -309,6 +310,7 @@ impl State {
     }
 
     fn render(&mut self, commands: Vec<GraphicsCommand>) -> Result<(), wgpu::SurfaceError> {
+        let _span = span!("context render");
         let output = self.surface.get_current_texture()?;
         let view = output
             .texture
@@ -486,56 +488,77 @@ fn main_thread(state: State, reciever: Receiver<UIEvent>) {
     let mut context = script::ScriptContext::new();
     context.init();
 
+    const SPF: f64 = 1.0 / 60.0;
     loop {
-        while let Ok(event) = reciever.try_recv() {
+        frame_mark();
-            match event.winit {
+        let start = Instant::now();
-                Event::WindowEvent {
-                    ref event,
-                    window_id,
-                } if window_id == state.window().id() => {
-                    if !state.input(event) {
-                        match event {
-                            WindowEvent::CursorMoved { position, .. } => {
-                                state.mouse_x = position.x;
-                                state.mouse_y = position.y;
-                            }
 
-                            WindowEvent::Resized(physical_size) => {
+        {
-                                state.resize(*physical_size);
+            let _span = span!("events");
-                            }
+            while let Ok(event) = reciever.try_recv() {
+                match event.winit {
+                    Event::WindowEvent {
+                        ref event,
+                        window_id,
+                    } if window_id == state.window().id() => {
+                        if !state.input(event) {
+                            match event {
+                                WindowEvent::CursorMoved { position, .. } => {
+                                    state.mouse_x = position.x;
+                                    state.mouse_y = position.y;
+                                }
 
-                            WindowEvent::ScaleFactorChanged { new_inner_size, .. } => {
+                                WindowEvent::Resized(physical_size) => {
-                                // new_inner_size is &&mut so we have to dereference it twice
+                                    state.resize(*physical_size);
-                                state.resize(**new_inner_size);
+                                }
-                            }
 
-                            _ => {}
+                                WindowEvent::ScaleFactorChanged { new_inner_size, .. } => {
+                                    // new_inner_size is &&mut so we have to dereference it twice
+                                    state.resize(**new_inner_size);
+                                }
+
+                                _ => {}
+                            }
                         }
                     }
-                }
 
-                _ => {}
+                    _ => {}
+                }
             }
         }
 
-        context.update();
+        {
-        state.update();
+            let _span = span!("update");
-
+            context.update();
-        match state.render(context.render()) {
+            state.update();
-            Ok(_) => {}
-            // Reconfigure the surface if lost
-            Err(wgpu::SurfaceError::Lost) => state.resize(state.size),
-            // The system is out of memory, we should probably quit
-            Err(wgpu::SurfaceError::OutOfMemory) => panic!("Out of memory"),
-            // All other errors (Outdated, Timeout) should be resolved by the next frame
-            Err(e) => eprintln!("{:?}", e),
         }
 
-        // TODO: FRAME PACING.
+        {
+            let _span = span!("render");
+            match state.render(context.render()) {
+                Ok(_) => {}
+                // Reconfigure the surface if lost
+                Err(wgpu::SurfaceError::Lost) => state.resize(state.size),
+                // The system is out of memory, we should probably quit
+                Err(wgpu::SurfaceError::OutOfMemory) => panic!("Out of memory"),
+                // All other errors (Outdated, Timeout) should be resolved by the next frame
+                Err(e) => eprintln!("{:?}", e),
+            }
+        }
+
+        {
+            let _span = span!("sleep");
+            while start.elapsed().as_secs_f64() < SPF {
+                std::thread::yield_now();
+            }
+        }
     }
 }
 
 pub async fn run() {
+    let _client = tracy_client::Client::start();
+    set_thread_name!("ui thread");
+
     env_logger::init();
     let event_loop = EventLoop::new();
     let window = WindowBuilder::new().build(&event_loop).unwrap();
@@ -544,6 +567,7 @@ pub async fn run() {
     let (sender, reciever) = std::sync::mpsc::channel();
 
     std::thread::spawn(move || {
+        set_thread_name!("game thread");
         main_thread(state, reciever);
     });
 

src/script.rs

@@ -5,6 +5,7 @@ use oden_js::{
 use std::ffi::OsStr;
 use std::sync::mpsc::{channel, Receiver};
 use std::time::Instant;
+use tracy_client::span;
 
 pub mod graphics;
 use graphics::GraphicsCommand;
@@ -99,29 +100,41 @@ impl ScriptContext {
     //       game thread go to fast probably? And to discard whole frames &c.
 
     pub fn init(&mut self) {
+        let _span = span!("script init");
+
         self.init
             .call(&self.context, &[])
             .expect("Exception in init");
     }
 
     pub fn update(&mut self) {
+        let _span = span!("script update");
+
         // Do we update the frame time before of after async completion?
         // Hmmmmm.
         self.time.set_frame_time(Instant::now());
 
         // Tell the runtime to process all pending "jobs". This includes
         // promise completions.
-        self.context
+        {
-            .process_all_jobs()
+            let _span = span!("process jobs");
-            .expect("Error processing async jobs");
+            self.context
+                .process_all_jobs()
+                .expect("Error processing async jobs");
+        }
 
         // Now run the update function.
-        self.update
+        {
-            .call(&self.context, &[])
+            let _span = span!("javascript update");
-            .expect("Exception in update");
+            self.update
+                .call(&self.context, &[])
+                .expect("Exception in update");
+        }
     }
 
     pub fn render(&mut self) -> Vec<graphics::GraphicsCommand> {
+        let _span = span!("script render");
+
         self.draw
             .call(&self.context, &[])
             .expect("Exception in draw");