Add frame timings

app/Cargo.toml

@@ -34,6 +34,7 @@ ambient_water = { path = "../crates/water" , version = "0.3.2-dev" }
 ambient_client_shared = { path = "../crates/client_shared/" , version = "0.3.2-dev" }
 ambient_package_semantic_native = { path = "../crates/package_semantic_native" , version = "0.3.2-dev" }
 ambient_settings = { path = "../crates/settings" , version = "0.3.2-dev" }
+ambient_timings = { path = "../crates/timings" , version = "0.3.2-dev" }
 
 ambient_element = { path = "../shared_crates/element" , version = "0.3.2-dev" }
 ambient_package = { path = "../shared_crates/package" , version = "0.3.2-dev" }

app/src/client/mod.rs

@@ -6,6 +6,7 @@ use ambient_cameras::UICamera;
 use ambient_client_shared::game_view::GameView;
 use ambient_core::{
     asset_cache, gpu, runtime,
+    timing::TimingEventType,
     window::{window_ctl, ExitStatus, WindowCtl},
 };
 use ambient_ecs::{Entity, SystemGroup};
@@ -408,7 +409,11 @@ fn systems() -> SystemGroup {
             Box::new(ambient_sky::systems()),
             Box::new(ambient_water::systems()),
             Box::new(ambient_gizmos::client_systems()),
-            Box::new(wasm::systems()),
+            Box::new(ambient_timings::wrap_system(
+                wasm::systems(),
+                TimingEventType::ScriptingStarted,
+                TimingEventType::ScriptingFinished,
+            )),
             Box::new(ambient_client_shared::player::systems_final()),
         ],
     )

crates/app/Cargo.toml

@@ -26,6 +26,7 @@ ambient_model = { path = "../model" , version = "0.3.2-dev" }
 ambient_animation = { path = "../animation" , version = "0.3.2-dev" }
 ambient_procedurals = { path = "../procedurals" , version = "0.3.2-dev" }
 ambient_settings = { path = "../settings" , version = "0.3.2-dev" }
+ambient_timings = { path = "../timings" , version = "0.3.2-dev" }
 
 ambient_element = { path = "../../shared_crates/element" , version = "0.3.2-dev" }
 

crates/app/src/lib.rs

@@ -9,7 +9,7 @@ use ambient_core::{
     camera::camera_systems,
     frame_index,
     hierarchy::dump_world_hierarchy_to_user,
-    name, performance_samples, refcount_system, remove_at_time_system, runtime,
+    name, performance_samples, refcount_system, remove_at_time_system, runtime, timing,
     transform::TransformSystem,
     window::{
         cursor_position, get_window_sizes, window_logical_size, window_physical_size,
@@ -75,6 +75,7 @@ pub fn init_all_components() {
     ambient_cameras::init_all_components();
     renderers::init_components();
     ambient_procedurals::init_components();
+    ambient_timings::init_components();
 }
 
 pub fn gpu_world_sync_systems(gpu: Arc<Gpu>) -> SystemGroup<GpuWorldSyncEvent> {
@@ -96,6 +97,7 @@ pub fn world_instance_systems(full: bool) -> SystemGroup {
     SystemGroup::new(
         "world_instance",
         vec![
+            Box::new(ambient_timings::on_started_timing_system()),
             Box::new(ClientTimeResourcesSystem::new()),
             Box::new(async_ecs_systems()),
             remove_at_time_system(),
@@ -123,6 +125,8 @@ pub fn world_instance_systems(full: bool) -> SystemGroup {
             Box::new(bounding_systems()),
             Box::new(camera_systems()),
             Box::new(ambient_procedurals::client_systems()),
+            Box::<ambient_timings::ProcessTimingEventsSystem>::default(),
+            Box::new(ambient_timings::on_finished_timing_system()),
         ],
     )
 }
@@ -135,6 +139,7 @@ pub struct AppResources {
     window_physical_size: UVec2,
     window_logical_size: UVec2,
     window_scale_factor: f64,
+    timings_reporter: timing::Reporter,
 }
 
 impl AppResources {
@@ -147,6 +152,7 @@ impl AppResources {
             window_physical_size: *world.resource(ambient_core::window::window_physical_size()),
             window_logical_size: *world.resource(ambient_core::window::window_logical_size()),
             window_scale_factor: *world.resource(ambient_core::window::window_scale_factor()),
+            timings_reporter: world.resource(timing::reporter()).clone(),
         }
     }
 }
@@ -187,6 +193,8 @@ pub fn world_instance_resources(resources: AppResources) -> Entity {
         .with(ambient_core::window::window_ctl(), resources.ctl_tx)
         .with(procedural_storage(), ProceduralStorage::new())
         .with(focus(), Default::default())
+        .with(timing::reporter(), resources.timings_reporter)
+        .with(ambient_timings::samples(), Default::default())
 }
 
 pub struct AppBuilder {
@@ -514,6 +522,7 @@ impl AppBuilder {
             window_physical_size,
             window_logical_size,
             window_scale_factor,
+            timings_reporter: Default::default(),
         };
 
         let resources = world_instance_resources(app_resources);
@@ -543,6 +552,7 @@ impl AppBuilder {
         let mut window_event_systems = SystemGroup::new(
             "window_event_systems",
             vec![
+                Box::new(ambient_timings::InputTimingSystem),
                 Box::new(assets_camera_systems()),
                 Box::new(ambient_input::event_systems()),
                 Box::new(renderers::systems()),

crates/core/src/lib.rs

@@ -22,6 +22,7 @@ pub mod camera;
 
 pub mod hierarchy;
 pub mod player;
+pub mod timing;
 pub mod transform;
 pub mod window;
 
@@ -78,6 +79,7 @@ pub fn init_all_components() {
     async_ecs::init_components();
     ambient_gpu_ecs::init_components();
     camera::init_components();
+    timing::init_components();
     transform::init_components();
     transform::init_gpu_components();
     bounding::init_components();

crates/core/src/timing.rs

@@ -0,0 +1,115 @@
+use std::sync::atomic::AtomicBool;
+
+use ambient_ecs::{components, Debuggable, Resource};
+use ambient_sys::time::Instant;
+
+static ENABLED: AtomicBool = AtomicBool::new(false);
+
+pub fn set_enabled(enabled: bool) {
+    ENABLED.store(enabled, std::sync::atomic::Ordering::Relaxed);
+}
+
+/// Frame events being timed (in order!)
+#[derive(Clone, Copy, Debug, PartialEq, Eq, PartialOrd, Ord)]
+pub enum TimingEventType {
+    Input,
+    ScriptingStarted,
+    ScriptingFinished,
+    ClientSystemsStarted,
+    ClientSystemsFinished,
+    DrawingWorld,
+    DrawingUI,
+    SubmittingGPUCommands,
+    RenderingFinished,
+}
+impl TimingEventType {
+    pub const COUNT: usize = Self::last().idx() + 1;
+
+    pub const fn last() -> Self {
+        Self::RenderingFinished
+    }
+
+    pub const fn idx(self) -> usize {
+        self as usize
+    }
+
+    pub const fn from_usize(idx: usize) -> Option<Self> {
+        match idx {
+            0 => Some(Self::Input),
+            1 => Some(Self::ScriptingStarted),
+            2 => Some(Self::ScriptingFinished),
+            3 => Some(Self::ClientSystemsStarted),
+            4 => Some(Self::ClientSystemsFinished),
+            5 => Some(Self::DrawingWorld),
+            6 => Some(Self::DrawingUI),
+            7 => Some(Self::SubmittingGPUCommands),
+            8 => Some(Self::RenderingFinished),
+            _ => None,
+        }
+    }
+}
+
+#[derive(Clone, Copy, Debug)]
+pub struct TimingEvent {
+    pub event_type: TimingEventType,
+    pub time: Instant,
+}
+impl From<TimingEventType> for TimingEvent {
+    fn from(event_type: TimingEventType) -> Self {
+        Self {
+            event_type,
+            time: Instant::now(),
+        }
+    }
+}
+
+#[derive(Clone, Debug)]
+pub struct Reporter {
+    sender: flume::Sender<TimingEvent>,
+    receiver: flume::Receiver<TimingEvent>,
+}
+impl Default for Reporter {
+    fn default() -> Self {
+        let (sender, receiver) = flume::unbounded();
+        Self { sender, receiver }
+    }
+}
+impl Reporter {
+    pub fn report_event(&self, event: impl Into<TimingEvent>) {
+        if ENABLED.load(std::sync::atomic::Ordering::Relaxed) {
+            self.sender.send(event.into()).ok();
+        }
+    }
+
+    pub fn reporter(&self) -> ThinReporter {
+        if ENABLED.load(std::sync::atomic::Ordering::Relaxed) {
+            ThinReporter::Enabled(self.sender.clone())
+        } else {
+            ThinReporter::Disabled
+        }
+    }
+
+    pub fn try_iter(&self) -> impl Iterator<Item = TimingEvent> + '_ {
+        self.receiver.try_iter()
+    }
+}
+
+pub enum ThinReporter {
+    Disabled,
+    Enabled(flume::Sender<TimingEvent>),
+}
+impl ThinReporter {
+    pub fn report_event(&self, event: impl Into<TimingEvent>) {
+        match self {
+            Self::Disabled => {}
+            Self::Enabled(sender) => {
+                sender.send(event.into()).ok();
+            }
+        }
+    }
+}
+
+components!("timing", {
+    @[Debuggable, Resource]
+    reporter: Reporter,
+});

crates/debugger/Cargo.toml

@@ -17,6 +17,7 @@ ambient_gizmos = { path = "../gizmos", version = "0.3.2-dev" }
 ambient_rpc = { path = "../rpc", version = "0.3.2-dev" }
 ambient_network = { path = "../network", version = "0.3.2-dev" }
 ambient_sys = { path = "../sys", version = "0.3.2-dev" }
+ambient_timings = { path = "../timings", version = "0.3.2-dev" }
 
 ambient_std = { path = "../../shared_crates/std", version = "0.3.2-dev" }
 ambient_element = { path = "../../shared_crates/element", version = "0.3.2-dev" }

crates/debugger/src/lib.rs

@@ -7,7 +7,7 @@ use ambient_core::{
     hierarchy::{dump_world_hierarchy, dump_world_hierarchy_to_user},
     main_scene, performance_samples,
     player::local_user_id,
-    runtime,
+    runtime, timing,
 };
 use ambient_ecs::{query, World};
 use ambient_element::{
@@ -114,13 +114,25 @@ impl Measurement {
 impl std::fmt::Display for Measurement {
     fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
         f.write_str("min: ")?;
-        Debug::fmt(&self.min, f)?;
+        if self.min == Duration::MAX {
+            f.write_str("N/A")?;
+        } else {
+            Debug::fmt(&self.min, f)?;
+        }
         f.write_str(" max: ")?;
-        Debug::fmt(&self.max, f)?;
+        if self.max == Duration::ZERO {
+            f.write_str("N/A")?;
+        } else {
+            Debug::fmt(&self.max, f)?;
+        }
         f.write_str(" avg: ")?;
         Debug::fmt(&self.avg(), f)?;
         f.write_str(" current: ")?;
-        Debug::fmt(&self.current, f)?;
+        if self.current == Duration::ZERO {
+            f.write_str("N/A")?;
+        } else {
+            Debug::fmt(&self.current, f)?;
+        }
 
         Ok(())
     }
@@ -130,6 +142,7 @@ impl std::fmt::Display for Measurement {
 pub fn AppStatsView(hooks: &mut Hooks) -> Element {
     let (measurements, set_measurements) =
         use_state(hooks, (Measurement::new(), Measurement::new()));
+    let (input_to_rendered, set_input_to_rendered) = use_state(hooks, Measurement::new());
 
     use_frame(hooks, move |w| {
         let samples = w.resource(performance_samples());
@@ -143,12 +156,23 @@ pub fn AppStatsView(hooks: &mut Hooks) -> Element {
             external_time.apply(sample.external_time);
         }
 
-        set_measurements((frame_time, external_time))
+        set_measurements((frame_time, external_time));
+
+        timing::set_enabled(true);
+        let timings = w.resource(ambient_timings::samples());
+        let mut input_to_rendered = Measurement::new();
+        for frame_timing in timings {
+            if let Some(time) = frame_timing.input_to_rendered() {
+                input_to_rendered.apply(time);
+            }
+        }
+        set_input_to_rendered(input_to_rendered);
     });
 
     FlowColumn::el(vec![
         Text::el(format!("Frame time    {:<8.1}", measurements.0)),
         Text::el(format!("External time {:<8.1}", measurements.1)),
+        Text::el(format!("Input-Rendered time {:<8.1}", input_to_rendered)),
     ])
 }
 

crates/gpu_ecs/src/sync.rs

@@ -11,7 +11,7 @@ use crate::gpu;
 use gpu::gpu::Gpu;
 
 /// GpuWorld sync/update systems need to run immediately after the GpuWorld has updated it's layout,
-/// so by forcing them to use this even we can make sure they're all in order
+/// so by forcing them to use this event we can make sure they're all in order
 pub struct GpuWorldSyncEvent;
 
 pub struct ArchChangeDetection {

crates/network/Cargo.toml

@@ -24,7 +24,6 @@ ambient_element = { path = "../../shared_crates/element", version = "0.3.2-dev"
 ambient_app = { path = "../app", version = "0.3.2-dev" }
 ambient_world_audio = { path = "../world_audio", version = "0.3.2-dev" }
 
-
 rustls-native-certs = { workspace = true, optional = true }
 
 as-any = { workspace = true }