Plumb time profiler output into tracing (#34238)

* Plumb time profiler output into tracing

Signed-off-by: Delan Azabani <dazabani@igalia.com>

* Enter the span tightly around the callback

Signed-off-by: Delan Azabani <dazabani@igalia.com>

* Use `info_span!()` shorthand

Signed-off-by: Delan Azabani <dazabani@igalia.com>

---------

Signed-off-by: Delan Azabani <dazabani@igalia.com>

components/shared/profile/Cargo.toml

@@ -11,6 +11,9 @@ rust-version.workspace = true
 name = "profile_traits"
 path = "lib.rs"
 
+[features]
+tracing = ["dep:tracing"]
+
 [dependencies]
 base = { workspace = true }
 crossbeam-channel = { workspace = true }
@@ -20,3 +23,4 @@ serde = { workspace = true }
 servo_config = { path = "../../config" }
 signpost = { git = "https://github.com/pcwalton/signpost.git" }
 time_03 = { workspace = true }
+tracing = { workspace = true, optional = true }

components/shared/profile/ipc.rs

@@ -7,8 +7,8 @@ use std::io::Error;
 use ipc_channel::ipc;
 use serde::{Deserialize, Serialize};
 
-use crate::time;
 use crate::time::{ProfilerCategory, ProfilerChan};
+use crate::time_profile;
 
 pub struct IpcReceiver<T>
 where
@@ -23,7 +23,7 @@ where
     T: for<'de> Deserialize<'de> + Serialize,
 {
     pub fn recv(&self) -> Result<T, ipc::IpcError> {
-        time::profile(
+        time_profile!(
             ProfilerCategory::IpcReceiver,
             None,
             self.time_profile_chan.clone(),
@@ -61,7 +61,7 @@ pub struct IpcBytesReceiver {
 
 impl IpcBytesReceiver {
     pub fn recv(&self) -> Result<Vec<u8>, ipc::IpcError> {
-        time::profile(
+        time_profile!(
             ProfilerCategory::IpcBytesReceiver,
             None,
             self.time_profile_chan.clone(),

components/shared/profile/lib.rs

@@ -11,3 +11,17 @@
 pub mod ipc;
 pub mod mem;
 pub mod time;
+
+/// Measure the given callback with the time profiler and (if enabled) tracing.
+///
+/// `$category` must be const, because we use it to derive the span name.
+#[macro_export]
+macro_rules! time_profile {
+    ($category:expr, $meta:expr, $profiler_chan:expr, $($callback:tt)+) => {{
+        #[cfg(feature = "tracing")]
+        let span = tracing::info_span!($category.variant_name(), servo_profiling = true);
+        #[cfg(not(feature = "tracing"))]
+        let span = ();
+        $crate::time::profile($category, $meta, $profiler_chan, span, $($callback)+)
+    }};
+}

components/shared/profile/time.rs

@@ -118,6 +118,71 @@ pub enum ProfilerCategory {
     IpcBytesReceiver = 0x84,
 }
 
+impl ProfilerCategory {
+    pub const fn variant_name(&self) -> &'static str {
+        match self {
+            ProfilerCategory::Compositing => "Compositing",
+            ProfilerCategory::LayoutPerform => "LayoutPerform",
+            ProfilerCategory::LayoutStyleRecalc => "LayoutStyleRecalc",
+            ProfilerCategory::LayoutTextShaping => "LayoutTextShaping",
+            ProfilerCategory::LayoutRestyleDamagePropagation => "LayoutRestyleDamagePropagation",
+            ProfilerCategory::LayoutNonIncrementalReset => "LayoutNonIncrementalReset",
+            ProfilerCategory::LayoutSelectorMatch => "LayoutSelectorMatch",
+            ProfilerCategory::LayoutTreeBuilder => "LayoutTreeBuilder",
+            ProfilerCategory::LayoutDamagePropagate => "LayoutDamagePropagate",
+            ProfilerCategory::LayoutGeneratedContent => "LayoutGeneratedContent",
+            ProfilerCategory::LayoutDisplayListSorting => "LayoutDisplayListSorting",
+            ProfilerCategory::LayoutFloatPlacementSpeculation => "LayoutFloatPlacementSpeculation",
+            ProfilerCategory::LayoutMain => "LayoutMain",
+            ProfilerCategory::LayoutStoreOverflow => "LayoutStoreOverflow",
+            ProfilerCategory::LayoutParallelWarmup => "LayoutParallelWarmup",
+            ProfilerCategory::LayoutDispListBuild => "LayoutDispListBuild",
+            ProfilerCategory::NetHTTPRequestResponse => "NetHTTPRequestResponse",
+            ProfilerCategory::PaintingPerTile => "PaintingPerTile",
+            ProfilerCategory::PaintingPrepBuff => "PaintingPrepBuff",
+            ProfilerCategory::Painting => "Painting",
+            ProfilerCategory::ImageDecoding => "ImageDecoding",
+            ProfilerCategory::ImageSaving => "ImageSaving",
+            ProfilerCategory::ScriptAttachLayout => "ScriptAttachLayout",
+            ProfilerCategory::ScriptConstellationMsg => "ScriptConstellationMsg",
+            ProfilerCategory::ScriptDevtoolsMsg => "ScriptDevtoolsMsg",
+            ProfilerCategory::ScriptDocumentEvent => "ScriptDocumentEvent",
+            ProfilerCategory::ScriptDomEvent => "ScriptDomEvent",
+            ProfilerCategory::ScriptEvaluate => "ScriptEvaluate",
+            ProfilerCategory::ScriptEvent => "ScriptEvent",
+            ProfilerCategory::ScriptFileRead => "ScriptFileRead",
+            ProfilerCategory::ScriptImageCacheMsg => "ScriptImageCacheMsg",
+            ProfilerCategory::ScriptInputEvent => "ScriptInputEvent",
+            ProfilerCategory::ScriptNetworkEvent => "ScriptNetworkEvent",
+            ProfilerCategory::ScriptParseHTML => "ScriptParseHTML",
+            ProfilerCategory::ScriptPlannedNavigation => "ScriptPlannedNavigation",
+            ProfilerCategory::ScriptResize => "ScriptResize",
+            ProfilerCategory::ScriptSetScrollState => "ScriptSetScrollState",
+            ProfilerCategory::ScriptSetViewport => "ScriptSetViewport",
+            ProfilerCategory::ScriptTimerEvent => "ScriptTimerEvent",
+            ProfilerCategory::ScriptStylesheetLoad => "ScriptStylesheetLoad",
+            ProfilerCategory::ScriptUpdateReplacedElement => "ScriptUpdateReplacedElement",
+            ProfilerCategory::ScriptWebSocketEvent => "ScriptWebSocketEvent",
+            ProfilerCategory::ScriptWorkerEvent => "ScriptWorkerEvent",
+            ProfilerCategory::ScriptServiceWorkerEvent => "ScriptServiceWorkerEvent",
+            ProfilerCategory::ScriptParseXML => "ScriptParseXML",
+            ProfilerCategory::ScriptEnterFullscreen => "ScriptEnterFullscreen",
+            ProfilerCategory::ScriptExitFullscreen => "ScriptExitFullscreen",
+            ProfilerCategory::ScriptWebVREvent => "ScriptWebVREvent",
+            ProfilerCategory::ScriptWorkletEvent => "ScriptWorkletEvent",
+            ProfilerCategory::ScriptPerformanceEvent => "ScriptPerformanceEvent",
+            ProfilerCategory::ScriptHistoryEvent => "ScriptHistoryEvent",
+            ProfilerCategory::ScriptPortMessage => "ScriptPortMessage",
+            ProfilerCategory::ScriptWebGPUMsg => "ScriptWebGPUMsg",
+            ProfilerCategory::TimeToFirstPaint => "TimeToFirstPaint",
+            ProfilerCategory::TimeToFirstContentfulPaint => "TimeToFirstContentfulPaint",
+            ProfilerCategory::TimeToInteractive => "TimeToInteractive",
+            ProfilerCategory::IpcReceiver => "IpcReceiver",
+            ProfilerCategory::IpcBytesReceiver => "IpcBytesReceiver",
+        }
+    }
+}
+
 #[derive(Clone, Debug, Deserialize, Eq, Ord, PartialEq, PartialOrd, Serialize)]
 pub enum TimerMetadataFrameType {
     RootWindow,
@@ -130,10 +195,17 @@ pub enum TimerMetadataReflowType {
     FirstReflow,
 }
 
+#[cfg(feature = "tracing")]
+pub type Span = tracing::Span;
+#[cfg(not(feature = "tracing"))]
+pub type Span = ();
+
 pub fn profile<T, F>(
     category: ProfilerCategory,
     meta: Option<TimerMetadata>,
     profiler_chan: ProfilerChan,
+    #[cfg(feature = "tracing")] span: Span,
+    #[cfg(not(feature = "tracing"))] _span: Span,
     callback: F,
 ) -> T
 where
@@ -143,7 +215,11 @@ where
         signpost::start(category as u32, &[0, 0, 0, (category as usize) >> 4]);
     }
     let start_time = CrossProcessInstant::now();
-    let val = callback();
+    let val = {
+        #[cfg(feature = "tracing")]
+        let _enter = span.enter();
+        callback()
+    };
     let end_time = CrossProcessInstant::now();
 
     if opts::get().debug.signpost {