Auto merge of #25810 - Manishearth:xr-profile, r=jdm

Add profiling to WebXR

Fixes https://github.com/servo/webxr/issues/128

Depends on https://github.com/servo/webxr/pull/131

r? @jdm

12 files changed, 95 insertions, 11 deletions

diff --git a/Cargo.lock b/Cargo.lock
index 83d69e12ebc..0aebb0c0e24 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -510,6 +510,7 @@ dependencies = [
  "surfman 0.1.3",
  "surfman-chains 0.2.1",
  "surfman-chains-api",
+ "time",
  "webrender",
  "webrender_api",
  "webrender_traits",
@@ -532,6 +533,7 @@ dependencies = [
  "serde_bytes",
  "servo_config",
  "sparkle",
+ "time",
  "webrender_api",
  "webvr_traits",
  "webxr-api",
@@ -6712,7 +6714,7 @@ dependencies = [
 [[package]]
 name = "webxr"
 version = "0.0.1"
-source = "git+https://github.com/servo/webxr#2841497966d87bbd561f18ea66547dde9b13962f"
+source = "git+https://github.com/servo/webxr#c0c1e794609c992902efbb54fa64404a69b5ddbe"
 dependencies = [
  "bindgen",
  "euclid",
@@ -6733,13 +6735,14 @@ dependencies = [
 [[package]]
 name = "webxr-api"
 version = "0.0.1"
-source = "git+https://github.com/servo/webxr#2841497966d87bbd561f18ea66547dde9b13962f"
+source = "git+https://github.com/servo/webxr#c0c1e794609c992902efbb54fa64404a69b5ddbe"
 dependencies = [
  "euclid",
  "ipc-channel",
  "log",
  "serde",
  "surfman-chains-api",
+ "time",
  "winit",
 ]
 
diff --git a/components/canvas/Cargo.toml b/components/canvas/Cargo.toml
index 7d6c63aae04..0dc4cbe9491 100644
--- a/components/canvas/Cargo.toml
+++ b/components/canvas/Cargo.toml
@@ -15,6 +15,8 @@ canvas2d-azure = ["azure"]
 canvas2d-raqote = ["raqote"]
 webgl_backtrace = ["canvas_traits/webgl_backtrace"]
 no-wgl = ["surfman/sm-no-wgl"]
+xr-profile = ["webxr-api/profile", "time"]
+
 
 [dependencies]
 azure = {git = "https://github.com/servo/rust-azure", optional = true}
@@ -32,6 +34,7 @@ ipc-channel = "0.14"
 log = "0.4"
 num-traits = "0.2"
 raqote = {git = "https://github.com/jrmuizel/raqote", optional = true}
+time = { version = "0.1.0", optional = true }
 pixels = {path = "../pixels"}
 servo_config = {path = "../config"}
 sparkle = "0.1.16"
diff --git a/components/canvas/webgl_thread.rs b/components/canvas/webgl_thread.rs
index 0919ebd387e..186ac043b38 100644
--- a/components/canvas/webgl_thread.rs
+++ b/components/canvas/webgl_thread.rs
@@ -75,6 +75,11 @@ use surfman_chains_api::SwapChainsAPI;
 use webrender_traits::{WebrenderExternalImageRegistry, WebrenderImageHandlerType};
 use webxr_api::SwapChainId as WebXRSwapChainId;
 
+#[cfg(feature = "xr-profile")]
+fn to_ms(ns: u64) -> f64 {
+    ns as f64 / 1_000_000.
+}
+
 struct GLContextData {
     ctx: Context,
     gl: Rc<Gl>,
@@ -329,8 +334,8 @@ impl WebGLThread {
             WebGLMsg::CreateWebXRSwapChain(ctx_id, size, sender) => {
                 let _ = sender.send(self.create_webxr_swap_chain(ctx_id, size));
             },
-            WebGLMsg::SwapBuffers(swap_ids, sender) => {
-                self.handle_swap_buffers(swap_ids, sender);
+            WebGLMsg::SwapBuffers(swap_ids, sender, sent_time) => {
+                self.handle_swap_buffers(swap_ids, sender, sent_time);
             },
             WebGLMsg::DOMToTextureCommand(command) => {
                 self.handle_dom_to_texture(command);
@@ -667,8 +672,16 @@ impl WebGLThread {
     fn handle_swap_buffers(
         &mut self,
         swap_ids: Vec<SwapChainId>,
-        completed_sender: WebGLSender<()>,
+        completed_sender: WebGLSender<u64>,
+        _sent_time: u64,
     ) {
+        #[cfg(feature = "xr-profile")]
+        let start_swap = time::precise_time_ns();
+        #[cfg(feature = "xr-profile")]
+        println!(
+            "WEBXR PROFILING [swap request]:\t{}ms",
+            to_ms(start_swap - _sent_time)
+        );
         debug!("handle_swap_buffers()");
         for swap_id in swap_ids {
             let context_id = swap_id.context_id();
@@ -733,7 +746,17 @@ impl WebGLThread {
             );
         }
 
-        completed_sender.send(()).unwrap();
+        #[allow(unused)]
+        let mut end_swap = 0;
+        #[cfg(feature = "xr-profile")]
+        {
+            end_swap = time::precise_time_ns();
+            println!(
+                "WEBXR PROFILING [swap buffer]:\t{}ms",
+                to_ms(end_swap - start_swap)
+            );
+        }
+        completed_sender.send(end_swap).unwrap();
     }
 
     /// Creates a new WebXR swap chain
diff --git a/components/canvas_traits/Cargo.toml b/components/canvas_traits/Cargo.toml
index 7e0f3a92b2e..9c24bd13aa0 100644
--- a/components/canvas_traits/Cargo.toml
+++ b/components/canvas_traits/Cargo.toml
@@ -12,6 +12,7 @@ path = "lib.rs"
 
 [features]
 webgl_backtrace = []
+xr-profile = ["webxr-api/profile", "time"]
 
 [dependencies]
 crossbeam-channel = "0.4"
@@ -26,6 +27,7 @@ serde = "1.0"
 serde_bytes = "0.11"
 servo_config = {path = "../config"}
 sparkle = "0.1"
+time = { version = "0.1.0", optional = true }
 webrender_api = {git = "https://github.com/servo/webrender"}
 webvr_traits = {path = "../webvr_traits"}
 webxr-api = {git = "https://github.com/servo/webxr", features = ["ipc"]}
diff --git a/components/canvas_traits/webgl.rs b/components/canvas_traits/webgl.rs
index 6d3bd9bdc09..6709137b34e 100644
--- a/components/canvas_traits/webgl.rs
+++ b/components/canvas_traits/webgl.rs
@@ -82,7 +82,11 @@ pub enum WebGLMsg {
         WebGLSender<Option<WebXRSwapChainId>>,
     ),
     /// Performs a buffer swap.
-    SwapBuffers(Vec<SwapChainId>, WebGLSender<()>),
+    ///
+    /// The third field contains the time (in ns) when the request
+    /// was initiated. The u64 in the second field will be the time the
+    /// request is fulfilled
+    SwapBuffers(Vec<SwapChainId>, WebGLSender<u64>, u64),
     /// Frees all resources and closes the thread.
     Exit,
 }
@@ -195,9 +199,23 @@ impl WebGLMsgSender {
             .map(|id| SwapChainId::Framebuffer(self.ctx_id, id))
             .unwrap_or_else(|| SwapChainId::Context(self.ctx_id));
         let (sender, receiver) = webgl_channel()?;
+        #[allow(unused)]
+        let mut time = 0;
+        #[cfg(feature = "xr-profile")]
+        {
+            time = time::precise_time_ns();
+        }
+
         self.sender
-            .send(WebGLMsg::SwapBuffers(vec![swap_id], sender))?;
-        receiver.recv()?;
+            .send(WebGLMsg::SwapBuffers(vec![swap_id], sender, time))?;
+
+        #[allow(unused)]
+        let sent_time = receiver.recv()?;
+        #[cfg(feature = "xr-profile")]
+        println!(
+            "WEBXR PROFILING [swap complete]:\t{}ms",
+            (time::precise_time_ns() - sent_time) as f64 / 1_000_000.
+        );
         Ok(())
     }
 
diff --git a/components/script/Cargo.toml b/components/script/Cargo.toml
index 086b9981302..93813953aac 100644
--- a/components/script/Cargo.toml
+++ b/components/script/Cargo.toml
@@ -22,6 +22,7 @@ js_backtrace = ["backtrace"]
 refcell_backtrace = ["accountable-refcell"]
 uwp = ["js/uwp"]
 vslatestinstalled = ["js/vslatestinstalled"]
+xr-profile = ["webxr-api/profile"]
 
 [build-dependencies]
 phf_codegen = "0.8"
diff --git a/components/script/dom/document.rs b/components/script/dom/document.rs
index 3049d4f0bd6..6ee46bea95b 100644
--- a/components/script/dom/document.rs
+++ b/components/script/dom/document.rs
@@ -2530,11 +2530,17 @@ impl Document {
             return;
         }
 
+        #[allow(unused)]
+        let mut time = 0;
+        #[cfg(feature = "xr-profile")]
+        {
+            time = time::precise_time_ns();
+        }
         let (sender, receiver) = webgl::webgl_channel().unwrap();
         self.window
             .webgl_chan()
             .expect("Where's the WebGL channel?")
-            .send(WebGLMsg::SwapBuffers(dirty_context_ids, sender))
+            .send(WebGLMsg::SwapBuffers(dirty_context_ids, sender, time))
             .unwrap();
         receiver.recv().unwrap();
     }
diff --git a/components/script/dom/xrsession.rs b/components/script/dom/xrsession.rs
index 09aa2c7c854..62d9c15f3d6 100644
--- a/components/script/dom/xrsession.rs
+++ b/components/script/dom/xrsession.rs
@@ -164,10 +164,21 @@ impl XRSession {
         ROUTER.add_route(
             frame_receiver.to_opaque(),
             Box::new(move |message| {
+                #[allow(unused)]
+                let mut frame: Frame = message.to().unwrap();
+                #[cfg(feature = "xr-profile")]
+                {
+                    let received = time::precise_time_ns();
+                    println!(
+                        "WEBXR PROFILING [raf receive]:\t{}ms",
+                        (received - frame.sent_time) as f64 / 1_000_000.
+                    );
+                    frame.sent_time = received;
+                }
                 let this = this.clone();
                 let _ = task_source.queue_with_canceller(
                     task!(xr_raf_callback: move || {
-                        this.root().raf_callback(message.to().unwrap());
+                        this.root().raf_callback(frame);
                     }),
                     &canceller,
                 );
@@ -333,6 +344,13 @@ impl XRSession {
     /// https://immersive-web.github.io/webxr/#xr-animation-frame
     fn raf_callback(&self, mut frame: Frame) {
         debug!("WebXR RAF callback");
+        #[cfg(feature = "xr-profile")]
+        let raf_start = time::precise_time_ns();
+        #[cfg(feature = "xr-profile")]
+        println!(
+            "WEBXR PROFILING [raf queued]:\t{}ms",
+            (raf_start - frame.sent_time) as f64 / 1_000_000.
+        );
 
         // Step 1
         if let Some(pending) = self.pending_render_state.take() {
@@ -389,6 +407,12 @@ impl XRSession {
             self.session.borrow_mut().start_render_loop();
         }
 
+        #[cfg(feature = "xr-profile")]
+        println!(
+            "WEBXR PROFILING [raf execute]:\t{}ms",
+            (time::precise_time_ns() - raf_start) as f64 / 1_000_000.
+        );
+
         // If the canvas element is attached to the DOM, it is now dirty,
         // and we need to trigger a reflow.
         base_layer
diff --git a/components/servo/Cargo.toml b/components/servo/Cargo.toml
index dfe9569c635..29136079e33 100644
--- a/components/servo/Cargo.toml
+++ b/components/servo/Cargo.toml
@@ -39,6 +39,7 @@ webgl_backtrace = [
 vslatestinstalled = ["script/vslatestinstalled"]
 media-dummy = ["servo-media-dummy"]
 media-gstreamer = ["servo-media-gstreamer", "gstreamer"]
+xr-profile = ["canvas/xr-profile", "canvas_traits/xr-profile", "script/xr-profile", "webxr/profile"]
 
 [dependencies]
 background_hang_monitor = {path = "../background_hang_monitor"}
diff --git a/ports/glutin/Cargo.toml b/ports/glutin/Cargo.toml
index 455f0da4b86..a5771518b84 100644
--- a/ports/glutin/Cargo.toml
+++ b/ports/glutin/Cargo.toml
@@ -47,6 +47,7 @@ webdriver = ["libservo/webdriver"]
 webgl_backtrace = ["libservo/webgl_backtrace"]
 webrender_debugger = ["libservo/webrender_debugger"]
 vslatestinstalled = ["libservo/vslatestinstalled"]
+xr-profile = ["libservo/xr-profile"]
 
 [target.'cfg(not(target_os = "android"))'.dependencies]
 backtrace = "0.3"
diff --git a/ports/libsimpleservo/api/Cargo.toml b/ports/libsimpleservo/api/Cargo.toml
index 5f9f7a6a5ed..bbd496eabf6 100644
--- a/ports/libsimpleservo/api/Cargo.toml
+++ b/ports/libsimpleservo/api/Cargo.toml
@@ -54,3 +54,4 @@ webdriver = ["libservo/webdriver"]
 uwp = ["libservo/uwp", "webxr/openxr-api"]
 webgl_backtrace = ["libservo/webgl_backtrace"]
 vslatestinstalled = ["libservo/vslatestinstalled"]
+xr-profile = ["libservo/xr-profile"]
diff --git a/ports/libsimpleservo/capi/Cargo.toml b/ports/libsimpleservo/capi/Cargo.toml
index 06727830b0e..ec1c5ae8f99 100644
--- a/ports/libsimpleservo/capi/Cargo.toml
+++ b/ports/libsimpleservo/capi/Cargo.toml
@@ -49,3 +49,4 @@ uwp = ["simpleservo/uwp"]
 webdriver = ["simpleservo/webdriver"]
 webgl_backtrace = ["simpleservo/webgl_backtrace"]
 vslatestinstalled = ["simpleservo/vslatestinstalled"]
+xr-profile = ["simpleservo/xr-profile"]