From ab5deb4030fb35e6fb3fa37a3e7e6bd8500ed782 Mon Sep 17 00:00:00 2001 From: Jonathan Schwender <55576758+jschwe@users.noreply.github.com> Date: Thu, 23 Apr 2026 11:18:28 +0200 Subject: [PATCH] profile: Add initial trace event (#44443) Adds a profiling event at the startup of servoshell, right after initializing the tracing subsystem. To support this, add macro abstractions for tracing events. The existing span (macros) have a start and an end, but for one-off events, we don't need a span and hence it make sense to also add the event macros. The new event at startup is useful when measuring / optimizing general startup time. Adding a timestamp as field, allows us to ground the measurement and compare it against time measured outside of servo, regardless of how the profiling backend (tracing-perfetto, tracing-hitrace, future backends) save timestamps. Testing: Build-testing: the HarmonyOS build enables the tracing feature. On other platforms this is not the case in CI. --------- Signed-off-by: Jonathan Schwender --- components/servo/lib.rs | 4 ++ components/shared/profile/lib.rs | 64 ++++++++++++++++++++++++++++++++ ports/servoshell/egl/ohos/mod.rs | 3 +- ports/servoshell/lib.rs | 14 +++++++ 4 files changed, 84 insertions(+), 1 deletion(-) diff --git a/components/servo/lib.rs b/components/servo/lib.rs index d4b2af4b5e6..4e15ea1a08a 100644 --- a/components/servo/lib.rs +++ b/components/servo/lib.rs @@ -48,6 +48,10 @@ pub use paint::WebRenderDebugOption; pub use paint_api::rendering_context::{ OffscreenRenderingContext, RenderingContext, SoftwareRenderingContext, WindowRenderingContext, }; +// Expose our profile traits for servoshell, so we can instrument code there, but don't +// add it as an official API. +#[doc(hidden)] +pub use profile_traits; // This should be replaced with an API on ServoBuilder. // See . pub use resources; diff --git a/components/shared/profile/lib.rs b/components/shared/profile/lib.rs index d69b89037a9..2cdd936a9f2 100644 --- a/components/shared/profile/lib.rs +++ b/components/shared/profile/lib.rs @@ -52,6 +52,19 @@ macro_rules! __profiling_span { }}; } +#[doc(hidden)] +#[macro_export] +macro_rules! __profiling_event { + ($backend_macro:ident, $event_name:literal $(, $($fields:tt)+)?) => {{ + #[cfg(feature = "tracing")] + $crate::servo_tracing::$backend_macro!( + name: $event_name, + servo_profiling = true + $(, $($fields)+)? + ); + }}; +} + /// Provides API compatible dummies for the tracing-rs APIs we use /// if tracing is disabled. Hence, nothing will be traced pub mod dummy_tracing { @@ -172,5 +185,56 @@ macro_rules! info_span { }; } +/// Emit an event at the trace level +/// +/// This macro creates an Event for the purpose of instrumenting code to measure +/// the execution time between events. +/// +/// If the `tracing` feature (of the crate using this macro) is disabled, this +/// macro expands to nothing. +/// +/// Attention: This macro requires the user crate to have a `tracing` feature, +/// which can be used to disable the effects of this macro. +#[macro_export] +macro_rules! trace_event { + ($event_name:literal $(, $($fields:tt)+)?) => { + $crate::__profiling_event!(trace, $event_name $(, $($fields)+)?) + }; +} + +/// Emit an event at the debug level +/// +/// This macro creates an Event for the purpose of instrumenting code to measure +/// the execution time between events. +/// +/// If the `tracing` feature (of the crate using this macro) is disabled, this +/// macro expands to nothing. +/// +/// Attention: This macro requires the user crate to have a `tracing` feature, +/// which can be used to disable the effects of this macro. +#[macro_export] +macro_rules! debug_event { + ($event_name:literal $(, $($fields:tt)+)?) => { + $crate::__profiling_event!(debug, $event_name $(, $($fields)+)?) + }; +} + +/// Emit an event at the info level +/// +/// This macro creates an Event for the purpose of instrumenting code to measure +/// the execution time between events. +/// +/// If the `tracing` feature (of the crate using this macro) is disabled, this +/// macro expands to nothing. +/// +/// Attention: This macro requires the user crate to have a `tracing` feature, +/// which can be used to disable the effects of this macro. +#[macro_export] +macro_rules! info_event { + ($event_name:literal $(, $($fields:tt)+)?) => { + $crate::__profiling_event!(info, $event_name $(, $($fields)+)?) + }; +} + #[cfg(feature = "tracing")] pub use tracing as servo_tracing; diff --git a/ports/servoshell/egl/ohos/mod.rs b/ports/servoshell/egl/ohos/mod.rs index 7e25ad76fd0..e44850c35ef 100644 --- a/ports/servoshell/egl/ohos/mod.rs +++ b/ports/servoshell/egl/ohos/mod.rs @@ -260,6 +260,8 @@ fn init_app( ArgumentParsingResult::ErrorParsing => std::process::exit(1), }; + crate::init_tracing(servoshell_preferences.tracing_filter.as_deref()); + if native_values.device_type == ohos_deviceinfo::OhosDeviceType::Phone { preferences.set_value("viewport_meta_enabled", PrefValue::Bool(true)); } @@ -272,7 +274,6 @@ fn init_app( } } - crate::init_tracing(servoshell_preferences.tracing_filter.as_deref()); #[cfg(target_env = "ohos")] crate::egl::ohos::set_log_filter(servoshell_preferences.log_filter.as_deref()); diff --git a/ports/servoshell/lib.rs b/ports/servoshell/lib.rs index 3645adcdb20..8dfbb8c669d 100644 --- a/ports/servoshell/lib.rs +++ b/ports/servoshell/lib.rs @@ -96,6 +96,20 @@ pub fn init_tracing(filter_directives: Option<&str>) { // tracing::subscriber::set_global_default(subscriber) .expect("Failed to set tracing subscriber"); + + // Capture a first event, including the explicit wallclock time. + // The event itself is useful when investigating startup time. + // `wallclock_ns` allows us to ground the time, so we can compare + // against an external timestamp from before starting servoshell. + // In practice, the perfetto timestamp seems to be the same, but + // we shouldn't assume this, since different backends may behave differently. + servo::profile_traits::info_event!( + "servoshell::startup_tracing_initialized", + wallclock_ns = std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH) + .map(|duration| duration.as_nanos() as u64) + .unwrap_or(0) + ); } }