From 49634f60417aa0df7aa68a478a44f46820f4b7e9 Mon Sep 17 00:00:00 2001 From: localcc Date: Wed, 12 Nov 2025 15:31:20 +0100 Subject: [PATCH] Miniprofiler (#42385) Release Notes: - Added hang detection and a built in performance profiler --- Cargo.lock | 29 +- Cargo.toml | 2 + crates/gpui/Cargo.toml | 2 + crates/gpui/src/executor.rs | 55 ++- crates/gpui/src/gpui.rs | 2 + crates/gpui/src/platform.rs | 28 +- crates/gpui/src/platform/linux/dispatcher.rs | 119 +++++- .../src/platform/linux/headless/client.rs | 5 +- crates/gpui/src/platform/linux/platform.rs | 8 +- .../gpui/src/platform/linux/wayland/client.rs | 37 +- crates/gpui/src/platform/linux/x11/client.rs | 34 +- crates/gpui/src/platform/mac/dispatcher.rs | 148 ++++++- crates/gpui/src/platform/test/dispatcher.rs | 33 +- .../gpui/src/platform/windows/dispatcher.rs | 97 ++++- crates/gpui/src/platform/windows/events.rs | 4 +- crates/gpui/src/platform/windows/platform.rs | 16 +- crates/gpui/src/platform/windows/window.rs | 5 +- crates/gpui/src/profiler.rs | 218 ++++++++++ crates/miniprofiler_ui/Cargo.toml | 23 + crates/miniprofiler_ui/LICENSE-GPL | 1 + crates/miniprofiler_ui/src/miniprofiler_ui.rs | 393 ++++++++++++++++++ crates/paths/src/paths.rs | 6 + crates/remote_server/src/unix.rs | 1 + crates/repl/src/repl.rs | 8 +- crates/zed/Cargo.toml | 2 + crates/zed/src/main.rs | 9 +- crates/zed/src/reliability.rs | 97 ++++- crates/zed_actions/src/lib.rs | 2 + 28 files changed, 1282 insertions(+), 102 deletions(-) create mode 100644 crates/gpui/src/profiler.rs create mode 100644 crates/miniprofiler_ui/Cargo.toml create mode 120000 crates/miniprofiler_ui/LICENSE-GPL create mode 100644 crates/miniprofiler_ui/src/miniprofiler_ui.rs diff --git a/Cargo.lock b/Cargo.lock index 84ca9fbc10ddf4d2b72564167d90acbeb04669c2..6f665286ad2a47e345d6c43f9c296af01c423c64 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -6248,7 +6248,7 @@ dependencies = [ "futures-core", "futures-sink", "nanorand", - "spin", + "spin 0.9.8", ] [[package]] @@ -7287,6 +7287,7 @@ dependencies = [ "calloop", "calloop-wayland-source", "cbindgen", + "circular-buffer", "cocoa 0.26.0", "cocoa-foundation 0.2.0", "collections", @@ -7342,6 +7343,7 @@ dependencies = [ "slotmap", "smallvec", "smol", + "spin 0.10.0", "stacksafe", "strum 0.27.2", "sum_tree", @@ -9072,7 +9074,7 @@ version = "1.5.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "bbd2bcb4c963f2ddae06a2efc7e9f3591312473c50c6685e1f298068316e66fe" dependencies = [ - "spin", + "spin 0.9.8", ] [[package]] @@ -10014,6 +10016,18 @@ version = "0.2.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "68354c5c6bd36d73ff3feceb05efa59b6acb7626617f4962be322a825e61f79a" +[[package]] +name = "miniprofiler_ui" +version = "0.1.0" +dependencies = [ + "gpui", + "serde_json", + "smol", + "util", + "workspace", + "zed_actions", +] + [[package]] name = "miniz_oxide" version = "0.8.9" @@ -15854,6 +15868,15 @@ dependencies = [ "lock_api", ] +[[package]] +name = "spin" +version = "0.10.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d5fe4ccb98d9c292d56fec89a5e07da7fc4cf0dc11e156b41793132775d3e591" +dependencies = [ + "lock_api", +] + [[package]] name = "spirv" version = "0.3.0+sdk-1.3.268.0" @@ -21165,6 +21188,7 @@ dependencies = [ "breadcrumbs", "call", "channel", + "chrono", "clap", "cli", "client", @@ -21222,6 +21246,7 @@ dependencies = [ "menu", "migrator", "mimalloc", + "miniprofiler_ui", "nc", "nix 0.29.0", "node_runtime", diff --git a/Cargo.toml b/Cargo.toml index 8511bd8d21d79a854453434827767eaca4adf3d8..c6471cd043152ca9c52cee671e3d494ab15be81a 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -110,6 +110,7 @@ members = [ "crates/menu", "crates/migrator", "crates/mistral", + "crates/miniprofiler_ui", "crates/multi_buffer", "crates/nc", "crates/net", @@ -341,6 +342,7 @@ menu = { path = "crates/menu" } migrator = { path = "crates/migrator" } mistral = { path = "crates/mistral" } multi_buffer = { path = "crates/multi_buffer" } +miniprofiler_ui = { path = "crates/miniprofiler_ui" } nc = { path = "crates/nc" } net = { path = "crates/net" } node_runtime = { path = "crates/node_runtime" } diff --git a/crates/gpui/Cargo.toml b/crates/gpui/Cargo.toml index 6523bbe526848c15053a4bad45dce208a5ecd7e0..a6649f011d42410671bc7e317a3492803418cc2a 100644 --- a/crates/gpui/Cargo.toml +++ b/crates/gpui/Cargo.toml @@ -138,6 +138,8 @@ waker-fn = "1.2.0" lyon = "1.0" libc.workspace = true pin-project = "1.1.10" +circular-buffer.workspace = true +spin = "0.10.0" [target.'cfg(target_os = "macos")'.dependencies] block = "0.1" diff --git a/crates/gpui/src/executor.rs b/crates/gpui/src/executor.rs index 86cd7451fb3559ffd7da4001bdf6f6bd121e8b39..feeac47e01b3ba4a680b4a159ba0f6d09f66375f 100644 --- a/crates/gpui/src/executor.rs +++ b/crates/gpui/src/executor.rs @@ -1,4 +1,4 @@ -use crate::{App, PlatformDispatcher}; +use crate::{App, PlatformDispatcher, RunnableMeta, RunnableVariant}; use async_task::Runnable; use futures::channel::mpsc; use smol::prelude::*; @@ -62,7 +62,7 @@ enum TaskState { Ready(Option), /// A task that is currently running. - Spawned(async_task::Task), + Spawned(async_task::Task), } impl Task { @@ -146,6 +146,7 @@ impl BackgroundExecutor { } /// Enqueues the given future to be run to completion on a background thread. + #[track_caller] pub fn spawn(&self, future: impl Future + Send + 'static) -> Task where R: Send + 'static, @@ -155,6 +156,7 @@ impl BackgroundExecutor { /// Enqueues the given future to be run to completion on a background thread. /// The given label can be used to control the priority of the task in tests. + #[track_caller] pub fn spawn_labeled( &self, label: TaskLabel, @@ -166,14 +168,20 @@ impl BackgroundExecutor { self.spawn_internal::(Box::pin(future), Some(label)) } + #[track_caller] fn spawn_internal( &self, future: AnyFuture, label: Option, ) -> Task { let dispatcher = self.dispatcher.clone(); - let (runnable, task) = - async_task::spawn(future, move |runnable| dispatcher.dispatch(runnable, label)); + let location = core::panic::Location::caller(); + let (runnable, task) = async_task::Builder::new() + .metadata(RunnableMeta { location }) + .spawn( + move |_| future, + move |runnable| dispatcher.dispatch(RunnableVariant::Meta(runnable), label), + ); runnable.schedule(); Task(TaskState::Spawned(task)) } @@ -374,10 +382,13 @@ impl BackgroundExecutor { if duration.is_zero() { return Task::ready(()); } - let (runnable, task) = async_task::spawn(async move {}, { - let dispatcher = self.dispatcher.clone(); - move |runnable| dispatcher.dispatch_after(duration, runnable) - }); + let location = core::panic::Location::caller(); + let (runnable, task) = async_task::Builder::new() + .metadata(RunnableMeta { location }) + .spawn(move |_| async move {}, { + let dispatcher = self.dispatcher.clone(); + move |runnable| dispatcher.dispatch_after(duration, RunnableVariant::Meta(runnable)) + }); runnable.schedule(); Task(TaskState::Spawned(task)) } @@ -483,24 +494,29 @@ impl ForegroundExecutor { } /// Enqueues the given Task to run on the main thread at some point in the future. + #[track_caller] pub fn spawn(&self, future: impl Future + 'static) -> Task where R: 'static, { let dispatcher = self.dispatcher.clone(); + let location = core::panic::Location::caller(); #[track_caller] fn inner( dispatcher: Arc, future: AnyLocalFuture, + location: &'static core::panic::Location<'static>, ) -> Task { - let (runnable, task) = spawn_local_with_source_location(future, move |runnable| { - dispatcher.dispatch_on_main_thread(runnable) - }); + let (runnable, task) = spawn_local_with_source_location( + future, + move |runnable| dispatcher.dispatch_on_main_thread(RunnableVariant::Meta(runnable)), + RunnableMeta { location }, + ); runnable.schedule(); Task(TaskState::Spawned(task)) } - inner::(dispatcher, Box::pin(future)) + inner::(dispatcher, Box::pin(future), location) } } @@ -509,14 +525,16 @@ impl ForegroundExecutor { /// Copy-modified from: /// #[track_caller] -fn spawn_local_with_source_location( +fn spawn_local_with_source_location( future: Fut, schedule: S, -) -> (Runnable<()>, async_task::Task) + metadata: M, +) -> (Runnable, async_task::Task) where Fut: Future + 'static, Fut::Output: 'static, - S: async_task::Schedule<()> + Send + Sync + 'static, + S: async_task::Schedule + Send + Sync + 'static, + M: 'static, { #[inline] fn thread_id() -> ThreadId { @@ -564,7 +582,11 @@ where location: Location::caller(), }; - unsafe { async_task::spawn_unchecked(future, schedule) } + unsafe { + async_task::Builder::new() + .metadata(metadata) + .spawn_unchecked(move |_| future, schedule) + } } /// Scope manages a set of tasks that are enqueued and waited on together. See [`BackgroundExecutor::scoped`]. @@ -594,6 +616,7 @@ impl<'a> Scope<'a> { } /// Spawn a future into this scope. + #[track_caller] pub fn spawn(&mut self, f: F) where F: Future + Send + 'a, diff --git a/crates/gpui/src/gpui.rs b/crates/gpui/src/gpui.rs index 098c0780b2cc52c4dbfff4f65c8b59277fd9fa84..bc70362047d7826519f6f7c734b7c5a84281b31f 100644 --- a/crates/gpui/src/gpui.rs +++ b/crates/gpui/src/gpui.rs @@ -30,6 +30,7 @@ mod keymap; mod path_builder; mod platform; pub mod prelude; +mod profiler; mod scene; mod shared_string; mod shared_uri; @@ -87,6 +88,7 @@ use key_dispatch::*; pub use keymap::*; pub use path_builder::*; pub use platform::*; +pub use profiler::*; pub use refineable::*; pub use scene::*; pub use shared_string::*; diff --git a/crates/gpui/src/platform.rs b/crates/gpui/src/platform.rs index decdc547353f9290b710b337c7dd99cdae188918..04ae4480faf08015f6e4b6e62e7210b55997e3d4 100644 --- a/crates/gpui/src/platform.rs +++ b/crates/gpui/src/platform.rs @@ -40,8 +40,8 @@ use crate::{ DEFAULT_WINDOW_SIZE, DevicePixels, DispatchEventResult, Font, FontId, FontMetrics, FontRun, ForegroundExecutor, GlyphId, GpuSpecs, ImageSource, Keymap, LineLayout, Pixels, PlatformInput, Point, RenderGlyphParams, RenderImage, RenderImageParams, RenderSvgParams, Scene, ShapedGlyph, - ShapedRun, SharedString, Size, SvgRenderer, SystemWindowTab, Task, TaskLabel, Window, - WindowControlArea, hash, point, px, size, + ShapedRun, SharedString, Size, SvgRenderer, SystemWindowTab, Task, TaskLabel, TaskTiming, + ThreadTaskTimings, Window, WindowControlArea, hash, point, px, size, }; use anyhow::Result; use async_task::Runnable; @@ -559,14 +559,32 @@ pub(crate) trait PlatformWindow: HasWindowHandle + HasDisplayHandle { } } +/// This type is public so that our test macro can generate and use it, but it should not +/// be considered part of our public API. +#[doc(hidden)] +#[derive(Debug)] +pub struct RunnableMeta { + /// Location of the runnable + pub location: &'static core::panic::Location<'static>, +} + +#[doc(hidden)] +pub enum RunnableVariant { + Meta(Runnable), + Compat(Runnable), +} + /// This type is public so that our test macro can generate and use it, but it should not /// be considered part of our public API. #[doc(hidden)] pub trait PlatformDispatcher: Send + Sync { + fn get_all_timings(&self) -> Vec; + fn get_current_thread_timings(&self) -> Vec; fn is_main_thread(&self) -> bool; - fn dispatch(&self, runnable: Runnable, label: Option); - fn dispatch_on_main_thread(&self, runnable: Runnable); - fn dispatch_after(&self, duration: Duration, runnable: Runnable); + fn dispatch(&self, runnable: RunnableVariant, label: Option); + fn dispatch_on_main_thread(&self, runnable: RunnableVariant); + fn dispatch_after(&self, duration: Duration, runnable: RunnableVariant); + fn now(&self) -> Instant { Instant::now() } diff --git a/crates/gpui/src/platform/linux/dispatcher.rs b/crates/gpui/src/platform/linux/dispatcher.rs index 9ca1f76fd6996ffbd376d8254cbbe63a1c8d8fd0..c300109ffe32b3537acbbca47b4c39674cad2fd1 100644 --- a/crates/gpui/src/platform/linux/dispatcher.rs +++ b/crates/gpui/src/platform/linux/dispatcher.rs @@ -1,5 +1,7 @@ -use crate::{PlatformDispatcher, TaskLabel}; -use async_task::Runnable; +use crate::{ + GLOBAL_THREAD_TIMINGS, PlatformDispatcher, RunnableVariant, THREAD_TIMINGS, TaskLabel, + TaskTiming, ThreadTaskTimings, +}; use calloop::{ EventLoop, channel::{self, Sender}, @@ -13,20 +15,20 @@ use util::ResultExt; struct TimerAfter { duration: Duration, - runnable: Runnable, + runnable: RunnableVariant, } pub(crate) struct LinuxDispatcher { - main_sender: Sender, + main_sender: Sender, timer_sender: Sender, - background_sender: flume::Sender, + background_sender: flume::Sender, _background_threads: Vec>, main_thread_id: thread::ThreadId, } impl LinuxDispatcher { - pub fn new(main_sender: Sender) -> Self { - let (background_sender, background_receiver) = flume::unbounded::(); + pub fn new(main_sender: Sender) -> Self { + let (background_sender, background_receiver) = flume::unbounded::(); let thread_count = std::thread::available_parallelism() .map(|i| i.get()) .unwrap_or(1); @@ -40,7 +42,36 @@ impl LinuxDispatcher { for runnable in receiver { let start = Instant::now(); - runnable.run(); + let mut location = match runnable { + RunnableVariant::Meta(runnable) => { + let location = runnable.metadata().location; + let timing = TaskTiming { + location, + start, + end: None, + }; + Self::add_task_timing(timing); + + runnable.run(); + timing + } + RunnableVariant::Compat(runnable) => { + let location = core::panic::Location::caller(); + let timing = TaskTiming { + location, + start, + end: None, + }; + Self::add_task_timing(timing); + + runnable.run(); + timing + } + }; + + let end = Instant::now(); + location.end = Some(end); + Self::add_task_timing(location); log::trace!( "background thread {}: ran runnable. took: {:?}", @@ -72,7 +103,36 @@ impl LinuxDispatcher { calloop::timer::Timer::from_duration(timer.duration), move |_, _, _| { if let Some(runnable) = runnable.take() { - runnable.run(); + let start = Instant::now(); + let mut timing = match runnable { + RunnableVariant::Meta(runnable) => { + let location = runnable.metadata().location; + let timing = TaskTiming { + location, + start, + end: None, + }; + Self::add_task_timing(timing); + + runnable.run(); + timing + } + RunnableVariant::Compat(runnable) => { + let timing = TaskTiming { + location: core::panic::Location::caller(), + start, + end: None, + }; + Self::add_task_timing(timing); + + runnable.run(); + timing + } + }; + let end = Instant::now(); + + timing.end = Some(end); + Self::add_task_timing(timing); } TimeoutAction::Drop }, @@ -96,18 +156,53 @@ impl LinuxDispatcher { main_thread_id: thread::current().id(), } } + + pub(crate) fn add_task_timing(timing: TaskTiming) { + THREAD_TIMINGS.with(|timings| { + let mut timings = timings.lock(); + let timings = &mut timings.timings; + + if let Some(last_timing) = timings.iter_mut().rev().next() { + if last_timing.location == timing.location { + last_timing.end = timing.end; + return; + } + } + + timings.push_back(timing); + }); + } } impl PlatformDispatcher for LinuxDispatcher { + fn get_all_timings(&self) -> Vec { + let global_timings = GLOBAL_THREAD_TIMINGS.lock(); + ThreadTaskTimings::convert(&global_timings) + } + + fn get_current_thread_timings(&self) -> Vec { + THREAD_TIMINGS.with(|timings| { + let timings = timings.lock(); + let timings = &timings.timings; + + let mut vec = Vec::with_capacity(timings.len()); + + let (s1, s2) = timings.as_slices(); + vec.extend_from_slice(s1); + vec.extend_from_slice(s2); + vec + }) + } + fn is_main_thread(&self) -> bool { thread::current().id() == self.main_thread_id } - fn dispatch(&self, runnable: Runnable, _: Option) { + fn dispatch(&self, runnable: RunnableVariant, _: Option) { self.background_sender.send(runnable).unwrap(); } - fn dispatch_on_main_thread(&self, runnable: Runnable) { + fn dispatch_on_main_thread(&self, runnable: RunnableVariant) { self.main_sender.send(runnable).unwrap_or_else(|runnable| { // NOTE: Runnable may wrap a Future that is !Send. // @@ -121,7 +216,7 @@ impl PlatformDispatcher for LinuxDispatcher { }); } - fn dispatch_after(&self, duration: Duration, runnable: Runnable) { + fn dispatch_after(&self, duration: Duration, runnable: RunnableVariant) { self.timer_sender .send(TimerAfter { duration, runnable }) .ok(); diff --git a/crates/gpui/src/platform/linux/headless/client.rs b/crates/gpui/src/platform/linux/headless/client.rs index da54db371033bac53e2ac3324306fa86eb57fb57..33f1bb17e3230d0b9c9b2c53bcd0603a9cc7f22c 100644 --- a/crates/gpui/src/platform/linux/headless/client.rs +++ b/crates/gpui/src/platform/linux/headless/client.rs @@ -31,7 +31,10 @@ impl HeadlessClient { handle .insert_source(main_receiver, |event, _, _: &mut HeadlessClient| { if let calloop::channel::Event::Msg(runnable) = event { - runnable.run(); + match runnable { + crate::RunnableVariant::Meta(runnable) => runnable.run(), + crate::RunnableVariant::Compat(runnable) => runnable.run(), + }; } }) .ok(); diff --git a/crates/gpui/src/platform/linux/platform.rs b/crates/gpui/src/platform/linux/platform.rs index 322f5d76110ee36e3cfdf26449bbec85c3d51af5..6c2d13d2e78f003a950e5c1dc135b503ae6d4087 100644 --- a/crates/gpui/src/platform/linux/platform.rs +++ b/crates/gpui/src/platform/linux/platform.rs @@ -15,7 +15,6 @@ use std::{ }; use anyhow::{Context as _, anyhow}; -use async_task::Runnable; use calloop::{LoopSignal, channel::Channel}; use futures::channel::oneshot; use util::ResultExt as _; @@ -26,7 +25,8 @@ use crate::{ Action, AnyWindowHandle, BackgroundExecutor, ClipboardItem, CursorStyle, DisplayId, ForegroundExecutor, Keymap, LinuxDispatcher, Menu, MenuItem, OwnedMenu, PathPromptOptions, Pixels, Platform, PlatformDisplay, PlatformKeyboardLayout, PlatformKeyboardMapper, - PlatformTextSystem, PlatformWindow, Point, Result, Task, WindowAppearance, WindowParams, px, + PlatformTextSystem, PlatformWindow, Point, Result, RunnableVariant, Task, WindowAppearance, + WindowParams, px, }; #[cfg(any(feature = "wayland", feature = "x11"))] @@ -105,8 +105,8 @@ pub(crate) struct LinuxCommon { } impl LinuxCommon { - pub fn new(signal: LoopSignal) -> (Self, Channel) { - let (main_sender, main_receiver) = calloop::channel::channel::(); + pub fn new(signal: LoopSignal) -> (Self, Channel) { + let (main_sender, main_receiver) = calloop::channel::channel::(); #[cfg(any(feature = "wayland", feature = "x11"))] let text_system = Arc::new(crate::CosmicTextSystem::new()); diff --git a/crates/gpui/src/platform/linux/wayland/client.rs b/crates/gpui/src/platform/linux/wayland/client.rs index fd4d9fb2b31bfa04fe1ecc7d192db11f997d8d59..9a9ec213edd27d9ab7ac2e1437f408ac7d78f08e 100644 --- a/crates/gpui/src/platform/linux/wayland/client.rs +++ b/crates/gpui/src/platform/linux/wayland/client.rs @@ -71,7 +71,6 @@ use super::{ window::{ImeInput, WaylandWindowStatePtr}, }; -use crate::platform::{PlatformWindow, blade::BladeContext}; use crate::{ AnyWindowHandle, Bounds, Capslock, CursorStyle, DOUBLE_CLICK_INTERVAL, DevicePixels, DisplayId, FileDropEvent, ForegroundExecutor, KeyDownEvent, KeyUpEvent, Keystroke, LinuxCommon, @@ -80,6 +79,10 @@ use crate::{ PlatformInput, PlatformKeyboardLayout, Point, SCROLL_LINES, ScrollDelta, ScrollWheelEvent, Size, TouchPhase, WindowParams, point, px, size, }; +use crate::{ + LinuxDispatcher, RunnableVariant, TaskTiming, + platform::{PlatformWindow, blade::BladeContext}, +}; use crate::{ SharedString, platform::linux::{ @@ -491,7 +494,37 @@ impl WaylandClient { move |event, _, _: &mut WaylandClientStatePtr| { if let calloop::channel::Event::Msg(runnable) = event { handle.insert_idle(|_| { - runnable.run(); + let start = Instant::now(); + let mut timing = match runnable { + RunnableVariant::Meta(runnable) => { + let location = runnable.metadata().location; + let timing = TaskTiming { + location, + start, + end: None, + }; + LinuxDispatcher::add_task_timing(timing); + + runnable.run(); + timing + } + RunnableVariant::Compat(runnable) => { + let location = core::panic::Location::caller(); + let timing = TaskTiming { + location, + start, + end: None, + }; + LinuxDispatcher::add_task_timing(timing); + + runnable.run(); + timing + } + }; + + let end = Instant::now(); + timing.end = Some(end); + LinuxDispatcher::add_task_timing(timing); }); } } diff --git a/crates/gpui/src/platform/linux/x11/client.rs b/crates/gpui/src/platform/linux/x11/client.rs index 5b0be84b2fc08d220800271a402496e5ba487b15..32f50cdf5d9d9439909c7ecaf35df0d75a9c9eae 100644 --- a/crates/gpui/src/platform/linux/x11/client.rs +++ b/crates/gpui/src/platform/linux/x11/client.rs @@ -1,4 +1,4 @@ -use crate::{Capslock, xcb_flush}; +use crate::{Capslock, LinuxDispatcher, RunnableVariant, TaskTiming, xcb_flush}; use anyhow::{Context as _, anyhow}; use ashpd::WindowIdentifier; use calloop::{ @@ -313,7 +313,37 @@ impl X11Client { // events have higher priority and runnables are only worked off after the event // callbacks. handle.insert_idle(|_| { - runnable.run(); + let start = Instant::now(); + let mut timing = match runnable { + RunnableVariant::Meta(runnable) => { + let location = runnable.metadata().location; + let timing = TaskTiming { + location, + start, + end: None, + }; + LinuxDispatcher::add_task_timing(timing); + + runnable.run(); + timing + } + RunnableVariant::Compat(runnable) => { + let location = core::panic::Location::caller(); + let timing = TaskTiming { + location, + start, + end: None, + }; + LinuxDispatcher::add_task_timing(timing); + + runnable.run(); + timing + } + }; + + let end = Instant::now(); + timing.end = Some(end); + LinuxDispatcher::add_task_timing(timing); }); } } diff --git a/crates/gpui/src/platform/mac/dispatcher.rs b/crates/gpui/src/platform/mac/dispatcher.rs index c72f791f850469287cf66021558032902982ccec..8a2f42234eea960669cb212853c437ec680a7fd7 100644 --- a/crates/gpui/src/platform/mac/dispatcher.rs +++ b/crates/gpui/src/platform/mac/dispatcher.rs @@ -2,7 +2,11 @@ #![allow(non_camel_case_types)] #![allow(non_snake_case)] -use crate::{PlatformDispatcher, TaskLabel}; +use crate::{ + GLOBAL_THREAD_TIMINGS, PlatformDispatcher, RunnableMeta, RunnableVariant, THREAD_TIMINGS, + TaskLabel, TaskTiming, ThreadTaskTimings, +}; + use async_task::Runnable; use objc::{ class, msg_send, @@ -12,7 +16,7 @@ use objc::{ use std::{ ffi::c_void, ptr::{NonNull, addr_of}, - time::Duration, + time::{Duration, Instant}, }; /// All items in the generated file are marked as pub, so we're gonna wrap it in a separate mod to prevent @@ -29,47 +33,155 @@ pub(crate) fn dispatch_get_main_queue() -> dispatch_queue_t { pub(crate) struct MacDispatcher; impl PlatformDispatcher for MacDispatcher { + fn get_all_timings(&self) -> Vec { + let global_timings = GLOBAL_THREAD_TIMINGS.lock(); + ThreadTaskTimings::convert(&global_timings) + } + + fn get_current_thread_timings(&self) -> Vec { + THREAD_TIMINGS.with(|timings| { + let timings = &timings.lock().timings; + + let mut vec = Vec::with_capacity(timings.len()); + + let (s1, s2) = timings.as_slices(); + vec.extend_from_slice(s1); + vec.extend_from_slice(s2); + vec + }) + } + fn is_main_thread(&self) -> bool { let is_main_thread: BOOL = unsafe { msg_send![class!(NSThread), isMainThread] }; is_main_thread == YES } - fn dispatch(&self, runnable: Runnable, _: Option) { + fn dispatch(&self, runnable: RunnableVariant, _: Option) { + let (context, trampoline) = match runnable { + RunnableVariant::Meta(runnable) => ( + runnable.into_raw().as_ptr() as *mut c_void, + Some(trampoline as unsafe extern "C" fn(*mut c_void)), + ), + RunnableVariant::Compat(runnable) => ( + runnable.into_raw().as_ptr() as *mut c_void, + Some(trampoline_compat as unsafe extern "C" fn(*mut c_void)), + ), + }; unsafe { dispatch_async_f( dispatch_get_global_queue(DISPATCH_QUEUE_PRIORITY_HIGH.try_into().unwrap(), 0), - runnable.into_raw().as_ptr() as *mut c_void, - Some(trampoline), + context, + trampoline, ); } } - fn dispatch_on_main_thread(&self, runnable: Runnable) { - unsafe { - dispatch_async_f( - dispatch_get_main_queue(), + fn dispatch_on_main_thread(&self, runnable: RunnableVariant) { + let (context, trampoline) = match runnable { + RunnableVariant::Meta(runnable) => ( runnable.into_raw().as_ptr() as *mut c_void, - Some(trampoline), - ); + Some(trampoline as unsafe extern "C" fn(*mut c_void)), + ), + RunnableVariant::Compat(runnable) => ( + runnable.into_raw().as_ptr() as *mut c_void, + Some(trampoline_compat as unsafe extern "C" fn(*mut c_void)), + ), + }; + unsafe { + dispatch_async_f(dispatch_get_main_queue(), context, trampoline); } } - fn dispatch_after(&self, duration: Duration, runnable: Runnable) { + fn dispatch_after(&self, duration: Duration, runnable: RunnableVariant) { + let (context, trampoline) = match runnable { + RunnableVariant::Meta(runnable) => ( + runnable.into_raw().as_ptr() as *mut c_void, + Some(trampoline as unsafe extern "C" fn(*mut c_void)), + ), + RunnableVariant::Compat(runnable) => ( + runnable.into_raw().as_ptr() as *mut c_void, + Some(trampoline_compat as unsafe extern "C" fn(*mut c_void)), + ), + }; unsafe { let queue = dispatch_get_global_queue(DISPATCH_QUEUE_PRIORITY_HIGH.try_into().unwrap(), 0); let when = dispatch_time(DISPATCH_TIME_NOW as u64, duration.as_nanos() as i64); - dispatch_after_f( - when, - queue, - runnable.into_raw().as_ptr() as *mut c_void, - Some(trampoline), - ); + dispatch_after_f(when, queue, context, trampoline); } } } extern "C" fn trampoline(runnable: *mut c_void) { + let task = + unsafe { Runnable::::from_raw(NonNull::new_unchecked(runnable as *mut ())) }; + + let location = task.metadata().location; + + let start = Instant::now(); + let timing = TaskTiming { + location, + start, + end: None, + }; + + THREAD_TIMINGS.with(|timings| { + let mut timings = timings.lock(); + let timings = &mut timings.timings; + if let Some(last_timing) = timings.iter_mut().rev().next() { + if last_timing.location == timing.location { + return; + } + } + + timings.push_back(timing); + }); + + task.run(); + let end = Instant::now(); + + THREAD_TIMINGS.with(|timings| { + let mut timings = timings.lock(); + let timings = &mut timings.timings; + let Some(last_timing) = timings.iter_mut().rev().next() else { + return; + }; + last_timing.end = Some(end); + }); +} + +extern "C" fn trampoline_compat(runnable: *mut c_void) { let task = unsafe { Runnable::<()>::from_raw(NonNull::new_unchecked(runnable as *mut ())) }; + + let location = core::panic::Location::caller(); + + let start = Instant::now(); + let timing = TaskTiming { + location, + start, + end: None, + }; + THREAD_TIMINGS.with(|timings| { + let mut timings = timings.lock(); + let timings = &mut timings.timings; + if let Some(last_timing) = timings.iter_mut().rev().next() { + if last_timing.location == timing.location { + return; + } + } + + timings.push_back(timing); + }); + task.run(); + let end = Instant::now(); + + THREAD_TIMINGS.with(|timings| { + let mut timings = timings.lock(); + let timings = &mut timings.timings; + let Some(last_timing) = timings.iter_mut().rev().next() else { + return; + }; + last_timing.end = Some(end); + }); } diff --git a/crates/gpui/src/platform/test/dispatcher.rs b/crates/gpui/src/platform/test/dispatcher.rs index 017c29bfb558f77874a9729a52b518d9d41fb256..fc01d112d9d4198d0f06c370e5feb1193b29c677 100644 --- a/crates/gpui/src/platform/test/dispatcher.rs +++ b/crates/gpui/src/platform/test/dispatcher.rs @@ -1,5 +1,4 @@ -use crate::{PlatformDispatcher, TaskLabel}; -use async_task::Runnable; +use crate::{PlatformDispatcher, RunnableVariant, TaskLabel}; use backtrace::Backtrace; use collections::{HashMap, HashSet, VecDeque}; use parking::Unparker; @@ -26,10 +25,10 @@ pub struct TestDispatcher { struct TestDispatcherState { random: StdRng, - foreground: HashMap>, - background: Vec, - deprioritized_background: Vec, - delayed: Vec<(Duration, Runnable)>, + foreground: HashMap>, + background: Vec, + deprioritized_background: Vec, + delayed: Vec<(Duration, RunnableVariant)>, start_time: Instant, time: Duration, is_main_thread: bool, @@ -175,7 +174,13 @@ impl TestDispatcher { let was_main_thread = state.is_main_thread; state.is_main_thread = main_thread; drop(state); - runnable.run(); + + // todo(localcc): add timings to tests + match runnable { + RunnableVariant::Meta(runnable) => runnable.run(), + RunnableVariant::Compat(runnable) => runnable.run(), + }; + self.state.lock().is_main_thread = was_main_thread; true @@ -268,6 +273,14 @@ impl Clone for TestDispatcher { } impl PlatformDispatcher for TestDispatcher { + fn get_all_timings(&self) -> Vec { + Vec::new() + } + + fn get_current_thread_timings(&self) -> Vec { + Vec::new() + } + fn is_main_thread(&self) -> bool { self.state.lock().is_main_thread } @@ -277,7 +290,7 @@ impl PlatformDispatcher for TestDispatcher { state.start_time + state.time } - fn dispatch(&self, runnable: Runnable, label: Option) { + fn dispatch(&self, runnable: RunnableVariant, label: Option) { { let mut state = self.state.lock(); if label.is_some_and(|label| state.deprioritized_task_labels.contains(&label)) { @@ -289,7 +302,7 @@ impl PlatformDispatcher for TestDispatcher { self.unpark_last(); } - fn dispatch_on_main_thread(&self, runnable: Runnable) { + fn dispatch_on_main_thread(&self, runnable: RunnableVariant) { self.state .lock() .foreground @@ -299,7 +312,7 @@ impl PlatformDispatcher for TestDispatcher { self.unpark_last(); } - fn dispatch_after(&self, duration: std::time::Duration, runnable: Runnable) { + fn dispatch_after(&self, duration: std::time::Duration, runnable: RunnableVariant) { let mut state = self.state.lock(); let next_time = state.time + duration; let ix = match state.delayed.binary_search_by_key(&next_time, |e| e.0) { diff --git a/crates/gpui/src/platform/windows/dispatcher.rs b/crates/gpui/src/platform/windows/dispatcher.rs index f60d6bd884d7bfe6b313a7ca555067991172fe31..f543202e77c75acfd007d632b2023317dcba43b6 100644 --- a/crates/gpui/src/platform/windows/dispatcher.rs +++ b/crates/gpui/src/platform/windows/dispatcher.rs @@ -1,10 +1,9 @@ use std::{ sync::atomic::{AtomicBool, Ordering}, thread::{ThreadId, current}, - time::Duration, + time::{Duration, Instant}, }; -use async_task::Runnable; use flume::Sender; use util::ResultExt; use windows::{ @@ -18,12 +17,13 @@ use windows::{ }; use crate::{ - HWND, PlatformDispatcher, SafeHwnd, TaskLabel, WM_GPUI_TASK_DISPATCHED_ON_MAIN_THREAD, + GLOBAL_THREAD_TIMINGS, HWND, PlatformDispatcher, RunnableVariant, SafeHwnd, THREAD_TIMINGS, + TaskLabel, TaskTiming, ThreadTaskTimings, WM_GPUI_TASK_DISPATCHED_ON_MAIN_THREAD, }; pub(crate) struct WindowsDispatcher { pub(crate) wake_posted: AtomicBool, - main_sender: Sender, + main_sender: Sender, main_thread_id: ThreadId, platform_window_handle: SafeHwnd, validation_number: usize, @@ -31,7 +31,7 @@ pub(crate) struct WindowsDispatcher { impl WindowsDispatcher { pub(crate) fn new( - main_sender: Sender, + main_sender: Sender, platform_window_handle: HWND, validation_number: usize, ) -> Self { @@ -47,42 +47,115 @@ impl WindowsDispatcher { } } - fn dispatch_on_threadpool(&self, runnable: Runnable) { + fn dispatch_on_threadpool(&self, runnable: RunnableVariant) { let handler = { let mut task_wrapper = Some(runnable); WorkItemHandler::new(move |_| { - task_wrapper.take().unwrap().run(); + Self::execute_runnable(task_wrapper.take().unwrap()); Ok(()) }) }; ThreadPool::RunWithPriorityAsync(&handler, WorkItemPriority::High).log_err(); } - fn dispatch_on_threadpool_after(&self, runnable: Runnable, duration: Duration) { + fn dispatch_on_threadpool_after(&self, runnable: RunnableVariant, duration: Duration) { let handler = { let mut task_wrapper = Some(runnable); TimerElapsedHandler::new(move |_| { - task_wrapper.take().unwrap().run(); + Self::execute_runnable(task_wrapper.take().unwrap()); Ok(()) }) }; ThreadPoolTimer::CreateTimer(&handler, duration.into()).log_err(); } + + #[inline(always)] + pub(crate) fn execute_runnable(runnable: RunnableVariant) { + let start = Instant::now(); + + let mut timing = match runnable { + RunnableVariant::Meta(runnable) => { + let location = runnable.metadata().location; + let timing = TaskTiming { + location, + start, + end: None, + }; + Self::add_task_timing(timing); + + runnable.run(); + + timing + } + RunnableVariant::Compat(runnable) => { + let timing = TaskTiming { + location: core::panic::Location::caller(), + start, + end: None, + }; + Self::add_task_timing(timing); + + runnable.run(); + + timing + } + }; + + let end = Instant::now(); + timing.end = Some(end); + + Self::add_task_timing(timing); + } + + pub(crate) fn add_task_timing(timing: TaskTiming) { + THREAD_TIMINGS.with(|timings| { + let mut timings = timings.lock(); + let timings = &mut timings.timings; + + if let Some(last_timing) = timings.iter_mut().rev().next() { + if last_timing.location == timing.location { + last_timing.end = timing.end; + return; + } + } + + timings.push_back(timing); + }); + } } impl PlatformDispatcher for WindowsDispatcher { + fn get_all_timings(&self) -> Vec { + let global_thread_timings = GLOBAL_THREAD_TIMINGS.lock(); + ThreadTaskTimings::convert(&global_thread_timings) + } + + fn get_current_thread_timings(&self) -> Vec { + THREAD_TIMINGS.with(|timings| { + let timings = timings.lock(); + let timings = &timings.timings; + + let mut vec = Vec::with_capacity(timings.len()); + + let (s1, s2) = timings.as_slices(); + vec.extend_from_slice(s1); + vec.extend_from_slice(s2); + vec + }) + } + fn is_main_thread(&self) -> bool { current().id() == self.main_thread_id } - fn dispatch(&self, runnable: Runnable, label: Option) { + fn dispatch(&self, runnable: RunnableVariant, label: Option) { self.dispatch_on_threadpool(runnable); if let Some(label) = label { log::debug!("TaskLabel: {label:?}"); } } - fn dispatch_on_main_thread(&self, runnable: Runnable) { + fn dispatch_on_main_thread(&self, runnable: RunnableVariant) { match self.main_sender.send(runnable) { Ok(_) => { if !self.wake_posted.swap(true, Ordering::AcqRel) { @@ -111,7 +184,7 @@ impl PlatformDispatcher for WindowsDispatcher { } } - fn dispatch_after(&self, duration: Duration, runnable: Runnable) { + fn dispatch_after(&self, duration: Duration, runnable: RunnableVariant) { self.dispatch_on_threadpool_after(runnable, duration); } } diff --git a/crates/gpui/src/platform/windows/events.rs b/crates/gpui/src/platform/windows/events.rs index cc17f19bcfac86a6f8ac31ec1059d76c24e79695..f80348fdc1f88aedc1231d6579c82af4c76f3c34 100644 --- a/crates/gpui/src/platform/windows/events.rs +++ b/crates/gpui/src/platform/windows/events.rs @@ -239,7 +239,7 @@ impl WindowsWindowInner { fn handle_timer_msg(&self, handle: HWND, wparam: WPARAM) -> Option { if wparam.0 == SIZE_MOVE_LOOP_TIMER_ID { for runnable in self.main_receiver.drain() { - runnable.run(); + WindowsDispatcher::execute_runnable(runnable); } self.handle_paint_msg(handle) } else { @@ -1142,8 +1142,10 @@ impl WindowsWindowInner { require_presentation: false, force_render, }); + self.state.borrow_mut().callbacks.request_frame = Some(request_frame); unsafe { ValidateRect(Some(handle), None).ok().log_err() }; + Some(0) } diff --git a/crates/gpui/src/platform/windows/platform.rs b/crates/gpui/src/platform/windows/platform.rs index b1d0c80ffc997976be2ee1b557ca2ea86e46ee3d..d845c9520f736d06a6cee637328871af7e329241 100644 --- a/crates/gpui/src/platform/windows/platform.rs +++ b/crates/gpui/src/platform/windows/platform.rs @@ -8,7 +8,6 @@ use std::{ use ::util::{ResultExt, paths::SanitizedPath}; use anyhow::{Context as _, Result, anyhow}; -use async_task::Runnable; use futures::channel::oneshot::{self, Receiver}; use itertools::Itertools; use parking_lot::RwLock; @@ -46,7 +45,7 @@ struct WindowsPlatformInner { raw_window_handles: std::sync::Weak>>, // The below members will never change throughout the entire lifecycle of the app. validation_number: usize, - main_receiver: flume::Receiver, + main_receiver: flume::Receiver, dispatcher: Arc, } @@ -93,7 +92,7 @@ impl WindowsPlatform { OleInitialize(None).context("unable to initialize Windows OLE")?; } let directx_devices = DirectXDevices::new().context("Creating DirectX devices")?; - let (main_sender, main_receiver) = flume::unbounded::(); + let (main_sender, main_receiver) = flume::unbounded::(); let validation_number = if usize::BITS == 64 { rand::random::() as usize } else { @@ -794,7 +793,7 @@ impl WindowsPlatformInner { fn run_foreground_task(&self) -> Option { loop { for runnable in self.main_receiver.drain() { - runnable.run(); + WindowsDispatcher::execute_runnable(runnable); } // Someone could enqueue a Runnable here. The flag is still true, so they will not PostMessage. @@ -805,7 +804,8 @@ impl WindowsPlatformInner { match self.main_receiver.try_recv() { Ok(runnable) => { let _ = dispatcher.wake_posted.swap(true, Ordering::AcqRel); - runnable.run(); + + WindowsDispatcher::execute_runnable(runnable); continue; } _ => { @@ -873,7 +873,7 @@ pub(crate) struct WindowCreationInfo { pub(crate) windows_version: WindowsVersion, pub(crate) drop_target_helper: IDropTargetHelper, pub(crate) validation_number: usize, - pub(crate) main_receiver: flume::Receiver, + pub(crate) main_receiver: flume::Receiver, pub(crate) platform_window_handle: HWND, pub(crate) disable_direct_composition: bool, pub(crate) directx_devices: DirectXDevices, @@ -883,8 +883,8 @@ struct PlatformWindowCreateContext { inner: Option>>, raw_window_handles: std::sync::Weak>>, validation_number: usize, - main_sender: Option>, - main_receiver: Option>, + main_sender: Option>, + main_receiver: Option>, directx_devices: Option, dispatcher: Option>, } diff --git a/crates/gpui/src/platform/windows/window.rs b/crates/gpui/src/platform/windows/window.rs index 4b89fcffb39d9bfbc0734977cec16a00984f5c9a..241293f0caa6c13de350c8b2fc44cb9d5abd82ec 100644 --- a/crates/gpui/src/platform/windows/window.rs +++ b/crates/gpui/src/platform/windows/window.rs @@ -12,7 +12,6 @@ use std::{ use ::util::ResultExt; use anyhow::{Context as _, Result}; -use async_task::Runnable; use futures::channel::oneshot::{self, Receiver}; use raw_window_handle as rwh; use smallvec::SmallVec; @@ -70,7 +69,7 @@ pub(crate) struct WindowsWindowInner { pub(crate) executor: ForegroundExecutor, pub(crate) windows_version: WindowsVersion, pub(crate) validation_number: usize, - pub(crate) main_receiver: flume::Receiver, + pub(crate) main_receiver: flume::Receiver, pub(crate) platform_window_handle: HWND, } @@ -357,7 +356,7 @@ struct WindowCreateContext { windows_version: WindowsVersion, drop_target_helper: IDropTargetHelper, validation_number: usize, - main_receiver: flume::Receiver, + main_receiver: flume::Receiver, platform_window_handle: HWND, appearance: WindowAppearance, disable_direct_composition: bool, diff --git a/crates/gpui/src/profiler.rs b/crates/gpui/src/profiler.rs new file mode 100644 index 0000000000000000000000000000000000000000..4e3f00c412cd19c8269497ff292ce9dbdd785fbe --- /dev/null +++ b/crates/gpui/src/profiler.rs @@ -0,0 +1,218 @@ +use std::{ + cell::LazyCell, + hash::Hasher, + hash::{DefaultHasher, Hash}, + sync::Arc, + thread::ThreadId, + time::Instant, +}; + +use serde::{Deserialize, Serialize}; + +#[doc(hidden)] +#[derive(Debug, Copy, Clone)] +pub struct TaskTiming { + pub location: &'static core::panic::Location<'static>, + pub start: Instant, + pub end: Option, +} + +#[doc(hidden)] +#[derive(Debug, Clone)] +pub struct ThreadTaskTimings { + pub thread_name: Option, + pub thread_id: ThreadId, + pub timings: Vec, +} + +impl ThreadTaskTimings { + pub(crate) fn convert(timings: &[GlobalThreadTimings]) -> Vec { + timings + .iter() + .filter_map(|t| match t.timings.upgrade() { + Some(timings) => Some((t.thread_id, timings)), + _ => None, + }) + .map(|(thread_id, timings)| { + let timings = timings.lock(); + let thread_name = timings.thread_name.clone(); + let timings = &timings.timings; + + let mut vec = Vec::with_capacity(timings.len()); + + let (s1, s2) = timings.as_slices(); + vec.extend_from_slice(s1); + vec.extend_from_slice(s2); + + ThreadTaskTimings { + thread_name, + thread_id, + timings: vec, + } + }) + .collect() + } +} + +/// Serializable variant of [`core::panic::Location`] +#[derive(Debug, Copy, Clone, Serialize, Deserialize)] +pub struct SerializedLocation<'a> { + /// Name of the source file + pub file: &'a str, + /// Line in the source file + pub line: u32, + /// Column in the source file + pub column: u32, +} + +impl<'a> From<&'a core::panic::Location<'a>> for SerializedLocation<'a> { + fn from(value: &'a core::panic::Location<'a>) -> Self { + SerializedLocation { + file: value.file(), + line: value.line(), + column: value.column(), + } + } +} + +/// Serializable variant of [`TaskTiming`] +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct SerializedTaskTiming<'a> { + /// Location of the timing + #[serde(borrow)] + pub location: SerializedLocation<'a>, + /// Time at which the measurement was reported in nanoseconds + pub start: u128, + /// Duration of the measurement in nanoseconds + pub duration: u128, +} + +impl<'a> SerializedTaskTiming<'a> { + /// Convert an array of [`TaskTiming`] into their serializable format + /// + /// # Params + /// + /// `anchor` - [`Instant`] that should be earlier than all timings to use as base anchor + pub fn convert(anchor: Instant, timings: &[TaskTiming]) -> Vec> { + let serialized = timings + .iter() + .map(|timing| { + let start = timing.start.duration_since(anchor).as_nanos(); + let duration = timing + .end + .unwrap_or_else(|| Instant::now()) + .duration_since(timing.start) + .as_nanos(); + SerializedTaskTiming { + location: timing.location.into(), + start, + duration, + } + }) + .collect::>(); + + serialized + } +} + +/// Serializable variant of [`ThreadTaskTimings`] +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct SerializedThreadTaskTimings<'a> { + /// Thread name + pub thread_name: Option, + /// Hash of the thread id + pub thread_id: u64, + /// Timing records for this thread + #[serde(borrow)] + pub timings: Vec>, +} + +impl<'a> SerializedThreadTaskTimings<'a> { + /// Convert [`ThreadTaskTimings`] into their serializable format + /// + /// # Params + /// + /// `anchor` - [`Instant`] that should be earlier than all timings to use as base anchor + pub fn convert( + anchor: Instant, + timings: ThreadTaskTimings, + ) -> SerializedThreadTaskTimings<'static> { + let serialized_timings = SerializedTaskTiming::convert(anchor, &timings.timings); + + let mut hasher = DefaultHasher::new(); + timings.thread_id.hash(&mut hasher); + let thread_id = hasher.finish(); + + SerializedThreadTaskTimings { + thread_name: timings.thread_name, + thread_id, + timings: serialized_timings, + } + } +} + +// Allow 20mb of task timing entries +const MAX_TASK_TIMINGS: usize = (20 * 1024 * 1024) / core::mem::size_of::(); + +pub(crate) type TaskTimings = circular_buffer::CircularBuffer; +pub(crate) type GuardedTaskTimings = spin::Mutex; + +pub(crate) struct GlobalThreadTimings { + pub thread_id: ThreadId, + pub timings: std::sync::Weak, +} + +pub(crate) static GLOBAL_THREAD_TIMINGS: spin::Mutex> = + spin::Mutex::new(Vec::new()); + +thread_local! { + pub(crate) static THREAD_TIMINGS: LazyCell> = LazyCell::new(|| { + let current_thread = std::thread::current(); + let thread_name = current_thread.name(); + let thread_id = current_thread.id(); + let timings = ThreadTimings::new(thread_name.map(|e| e.to_string()), thread_id); + let timings = Arc::new(spin::Mutex::new(timings)); + + { + let timings = Arc::downgrade(&timings); + let global_timings = GlobalThreadTimings { + thread_id: std::thread::current().id(), + timings, + }; + GLOBAL_THREAD_TIMINGS.lock().push(global_timings); + } + + timings + }); +} + +pub(crate) struct ThreadTimings { + pub thread_name: Option, + pub thread_id: ThreadId, + pub timings: Box, +} + +impl ThreadTimings { + pub(crate) fn new(thread_name: Option, thread_id: ThreadId) -> Self { + ThreadTimings { + thread_name, + thread_id, + timings: TaskTimings::boxed(), + } + } +} + +impl Drop for ThreadTimings { + fn drop(&mut self) { + let mut thread_timings = GLOBAL_THREAD_TIMINGS.lock(); + + let Some((index, _)) = thread_timings + .iter() + .enumerate() + .find(|(_, t)| t.thread_id == self.thread_id) + else { + return; + }; + thread_timings.swap_remove(index); + } +} diff --git a/crates/miniprofiler_ui/Cargo.toml b/crates/miniprofiler_ui/Cargo.toml new file mode 100644 index 0000000000000000000000000000000000000000..bb508a188e91d2169cca61845e21905aae2c97e3 --- /dev/null +++ b/crates/miniprofiler_ui/Cargo.toml @@ -0,0 +1,23 @@ +[package] +name = "miniprofiler_ui" +version = "0.1.0" +publish.workspace = true +edition.workspace = true +license = "GPL-3.0-or-later" + +[lints] +workspace = true + +[lib] +path = "src/miniprofiler_ui.rs" + +[dependencies] +gpui.workspace = true +zed_actions.workspace = true +workspace.workspace = true +util.workspace = true +serde_json.workspace = true +smol.workspace = true + +[dev-dependencies] +gpui = { workspace = true, features = ["test-support"] } diff --git a/crates/miniprofiler_ui/LICENSE-GPL b/crates/miniprofiler_ui/LICENSE-GPL new file mode 120000 index 0000000000000000000000000000000000000000..89e542f750cd3860a0598eff0dc34b56d7336dc4 --- /dev/null +++ b/crates/miniprofiler_ui/LICENSE-GPL @@ -0,0 +1 @@ +../../LICENSE-GPL \ No newline at end of file diff --git a/crates/miniprofiler_ui/src/miniprofiler_ui.rs b/crates/miniprofiler_ui/src/miniprofiler_ui.rs new file mode 100644 index 0000000000000000000000000000000000000000..b3dab02058651177fbcbc53453d8f451dcdcf8a3 --- /dev/null +++ b/crates/miniprofiler_ui/src/miniprofiler_ui.rs @@ -0,0 +1,393 @@ +use std::{ + ops::Range, + path::PathBuf, + time::{Duration, Instant}, +}; + +use gpui::{ + App, AppContext, Context, Entity, Hsla, InteractiveElement, IntoElement, ParentElement, Render, + ScrollHandle, SerializedTaskTiming, StatefulInteractiveElement, Styled, Task, TaskTiming, + TitlebarOptions, WindowBounds, WindowHandle, WindowOptions, div, prelude::FluentBuilder, px, + relative, size, +}; +use util::ResultExt; +use workspace::{ + Workspace, + ui::{ + ActiveTheme, Button, ButtonCommon, ButtonStyle, Checkbox, Clickable, ToggleState, + WithScrollbar, h_flex, v_flex, + }, +}; +use zed_actions::OpenPerformanceProfiler; + +pub fn init(startup_time: Instant, cx: &mut App) { + cx.observe_new(move |workspace: &mut workspace::Workspace, _, _| { + workspace.register_action(move |workspace, _: &OpenPerformanceProfiler, window, cx| { + let window_handle = window + .window_handle() + .downcast::() + .expect("Workspaces are root Windows"); + open_performance_profiler(startup_time, workspace, window_handle, cx); + }); + }) + .detach(); +} + +fn open_performance_profiler( + startup_time: Instant, + _workspace: &mut workspace::Workspace, + workspace_handle: WindowHandle, + cx: &mut App, +) { + let existing_window = cx + .windows() + .into_iter() + .find_map(|window| window.downcast::()); + + if let Some(existing_window) = existing_window { + existing_window + .update(cx, |profiler_window, window, _cx| { + profiler_window.workspace = Some(workspace_handle); + window.activate_window(); + }) + .log_err(); + return; + } + + let default_bounds = size(px(1280.), px(720.)); // 16:9 + + cx.open_window( + WindowOptions { + titlebar: Some(TitlebarOptions { + title: Some("Profiler Window".into()), + appears_transparent: false, + traffic_light_position: None, + }), + focus: true, + show: true, + is_movable: true, + kind: gpui::WindowKind::Normal, + window_background: cx.theme().window_background_appearance(), + window_decorations: None, + window_min_size: Some(default_bounds), + window_bounds: Some(WindowBounds::centered(default_bounds, cx)), + ..Default::default() + }, + |_window, cx| ProfilerWindow::new(startup_time, Some(workspace_handle), cx), + ) + .log_err(); +} + +enum DataMode { + Realtime(Option>), + Snapshot(Vec), +} + +struct TimingBar { + location: &'static core::panic::Location<'static>, + start: Instant, + end: Instant, + color: Hsla, +} + +pub struct ProfilerWindow { + startup_time: Instant, + data: DataMode, + include_self_timings: ToggleState, + autoscroll: bool, + scroll_handle: ScrollHandle, + workspace: Option>, + _refresh: Option>, +} + +impl ProfilerWindow { + pub fn new( + startup_time: Instant, + workspace_handle: Option>, + cx: &mut App, + ) -> Entity { + let entity = cx.new(|cx| ProfilerWindow { + startup_time, + data: DataMode::Realtime(None), + include_self_timings: ToggleState::Unselected, + autoscroll: true, + scroll_handle: ScrollHandle::new(), + workspace: workspace_handle, + _refresh: Some(Self::begin_listen(cx)), + }); + + entity + } + + fn begin_listen(cx: &mut Context) -> Task<()> { + cx.spawn(async move |this, cx| { + loop { + let data = cx + .foreground_executor() + .dispatcher + .get_current_thread_timings(); + + this.update(cx, |this: &mut ProfilerWindow, cx| { + let scroll_offset = this.scroll_handle.offset(); + let max_offset = this.scroll_handle.max_offset(); + this.autoscroll = -scroll_offset.y >= (max_offset.height - px(5.0)); + + this.data = DataMode::Realtime(Some(data)); + + if this.autoscroll { + this.scroll_handle.scroll_to_bottom(); + } + + cx.notify(); + }) + .ok(); + + // yield to the executor + cx.background_executor() + .timer(Duration::from_micros(1)) + .await; + } + }) + } + + fn get_timings(&self) -> Option<&Vec> { + match &self.data { + DataMode::Realtime(data) => data.as_ref(), + DataMode::Snapshot(data) => Some(data), + } + } + + fn render_timing( + &self, + value_range: Range, + item: TimingBar, + cx: &App, + ) -> impl IntoElement { + let time_ms = item.end.duration_since(item.start).as_secs_f32() * 1000f32; + + let remap = value_range + .end + .duration_since(value_range.start) + .as_secs_f32() + * 1000f32; + + let start = (item.start.duration_since(value_range.start).as_secs_f32() * 1000f32) / remap; + let end = (item.end.duration_since(value_range.start).as_secs_f32() * 1000f32) / remap; + + let bar_width = end - start.abs(); + + let location = item + .location + .file() + .rsplit_once("/") + .unwrap_or(("", item.location.file())) + .1; + let location = location.rsplit_once("\\").unwrap_or(("", location)).1; + + let label = format!( + "{}:{}:{}", + location, + item.location.line(), + item.location.column() + ); + + h_flex() + .gap_2() + .w_full() + .h(px(32.0)) + .child( + div() + .w(px(200.0)) + .flex_shrink_0() + .overflow_hidden() + .child(div().text_ellipsis().child(label)), + ) + .child( + div() + .flex_1() + .h(px(24.0)) + .bg(cx.theme().colors().background) + .rounded_md() + .p(px(2.0)) + .relative() + .child( + div() + .absolute() + .h_full() + .rounded_sm() + .bg(item.color) + .left(relative(start.max(0f32))) + .w(relative(bar_width)), + ), + ) + .child( + div() + .min_w(px(60.0)) + .flex_shrink_0() + .text_right() + .child(format!("{:.1}ms", time_ms)), + ) + } +} + +impl Render for ProfilerWindow { + fn render( + &mut self, + window: &mut gpui::Window, + cx: &mut gpui::Context, + ) -> impl gpui::IntoElement { + v_flex() + .id("profiler") + .w_full() + .h_full() + .gap_2() + .bg(cx.theme().colors().surface_background) + .text_color(cx.theme().colors().text) + .child( + h_flex() + .w_full() + .justify_between() + .child( + h_flex() + .gap_2() + .child( + Button::new( + "switch-mode", + match self.data { + DataMode::Snapshot { .. } => "Resume", + DataMode::Realtime(_) => "Pause", + }, + ) + .style(ButtonStyle::Filled) + .on_click(cx.listener( + |this, _, _window, cx| { + match &this.data { + DataMode::Realtime(Some(data)) => { + this._refresh = None; + this.data = DataMode::Snapshot(data.clone()); + } + DataMode::Snapshot { .. } => { + this._refresh = Some(Self::begin_listen(cx)); + this.data = DataMode::Realtime(None); + } + _ => {} + }; + cx.notify(); + }, + )), + ) + .child( + Button::new("export-data", "Save") + .style(ButtonStyle::Filled) + .on_click(cx.listener(|this, _, _window, cx| { + let Some(workspace) = this.workspace else { + return; + }; + + let Some(data) = this.get_timings() else { + return; + }; + let timings = + SerializedTaskTiming::convert(this.startup_time, &data); + + let active_path = workspace + .read_with(cx, |workspace, cx| { + workspace.most_recent_active_path(cx) + }) + .log_err() + .flatten() + .and_then(|p| p.parent().map(|p| p.to_owned())) + .unwrap_or_else(|| PathBuf::default()); + + let path = cx.prompt_for_new_path( + &active_path, + Some("performance_profile.miniprof"), + ); + + cx.background_spawn(async move { + let path = path.await; + let path = + path.log_err().and_then(|p| p.log_err()).flatten(); + + let Some(path) = path else { + return; + }; + + let Some(timings) = + serde_json::to_string(&timings).log_err() + else { + return; + }; + + smol::fs::write(path, &timings).await.log_err(); + }) + .detach(); + })), + ), + ) + .child( + Checkbox::new("include-self", self.include_self_timings) + .label("Include profiler timings") + .on_click(cx.listener(|this, checked, _window, cx| { + this.include_self_timings = *checked; + cx.notify(); + })), + ), + ) + .when_some(self.get_timings(), |div, e| { + if e.len() == 0 { + return div; + } + + let min = e[0].start; + let max = e[e.len() - 1].end.unwrap_or_else(|| Instant::now()); + div.child( + v_flex() + .id("timings.bars") + .overflow_scroll() + .w_full() + .h_full() + .gap_2() + .track_scroll(&self.scroll_handle) + .on_scroll_wheel(cx.listener(|this, _, _, _cx| { + let scroll_offset = this.scroll_handle.offset(); + let max_offset = this.scroll_handle.max_offset(); + this.autoscroll = -scroll_offset.y >= (max_offset.height - px(5.0)); + })) + .children( + e.iter() + .filter(|timing| { + timing + .end + .unwrap_or_else(|| Instant::now()) + .duration_since(timing.start) + .as_millis() + >= 1 + }) + .filter(|timing| { + if self.include_self_timings.selected() { + true + } else { + !timing.location.file().ends_with("miniprofiler_ui.rs") + } + }) + .enumerate() + .map(|(i, timing)| { + self.render_timing( + max.checked_sub(Duration::from_secs(10)).unwrap_or(min) + ..max, + TimingBar { + location: timing.location, + start: timing.start, + end: timing.end.unwrap_or_else(|| Instant::now()), + color: cx.theme().accents().color_for_index(i as u32), + }, + cx, + ) + }), + ), + ) + .vertical_scrollbar_for(self.scroll_handle.clone(), window, cx) + }) + } +} diff --git a/crates/paths/src/paths.rs b/crates/paths/src/paths.rs index a4c8f2424967cc3e0c4c2a76650811a7639ef5cb..7b5188b0f2b0db1c8b20876e6284209ce91fee6e 100644 --- a/crates/paths/src/paths.rs +++ b/crates/paths/src/paths.rs @@ -155,6 +155,12 @@ pub fn temp_dir() -> &'static PathBuf { }) } +/// Returns the path to the hang traces directory. +pub fn hang_traces_dir() -> &'static PathBuf { + static LOGS_DIR: OnceLock = OnceLock::new(); + LOGS_DIR.get_or_init(|| data_dir().join("hang_traces")) +} + /// Returns the path to the logs directory. pub fn logs_dir() -> &'static PathBuf { static LOGS_DIR: OnceLock = OnceLock::new(); diff --git a/crates/remote_server/src/unix.rs b/crates/remote_server/src/unix.rs index 729758c0d16c05d625b2836de66cdc4578f852d3..c51b93d4554aca86d13cefeb9dd4aaadacda399c 100644 --- a/crates/remote_server/src/unix.rs +++ b/crates/remote_server/src/unix.rs @@ -321,6 +321,7 @@ fn init_paths() -> anyhow::Result<()> { paths::languages_dir(), paths::logs_dir(), paths::temp_dir(), + paths::hang_traces_dir(), paths::remote_extensions_dir(), paths::remote_extensions_uploads_dir(), ] diff --git a/crates/repl/src/repl.rs b/crates/repl/src/repl.rs index be6491d9cdc61ec4b2a9f9fe950f8da00d0fb691..db21e198cc726df306bd94503615aa8633e0cbd6 100644 --- a/crates/repl/src/repl.rs +++ b/crates/repl/src/repl.rs @@ -12,7 +12,7 @@ mod session; use std::{sync::Arc, time::Duration}; use async_dispatcher::{Dispatcher, Runnable, set_dispatcher}; -use gpui::{App, PlatformDispatcher}; +use gpui::{App, PlatformDispatcher, RunnableVariant}; use project::Fs; pub use runtimelib::ExecutionState; @@ -45,11 +45,13 @@ fn zed_dispatcher(cx: &mut App) -> impl Dispatcher { // other crates in Zed. impl Dispatcher for ZedDispatcher { fn dispatch(&self, runnable: Runnable) { - self.dispatcher.dispatch(runnable, None) + self.dispatcher + .dispatch(RunnableVariant::Compat(runnable), None); } fn dispatch_after(&self, duration: Duration, runnable: Runnable) { - self.dispatcher.dispatch_after(duration, runnable); + self.dispatcher + .dispatch_after(duration, RunnableVariant::Compat(runnable)); } } diff --git a/crates/zed/Cargo.toml b/crates/zed/Cargo.toml index 8b641dd8ce1f769dbc517f06e0a4e5824a61380c..722880ca1bad7552490dd67e6f34f9b0d509848f 100644 --- a/crates/zed/Cargo.toml +++ b/crates/zed/Cargo.toml @@ -97,6 +97,7 @@ markdown.workspace = true markdown_preview.workspace = true menu.workspace = true migrator.workspace = true +miniprofiler_ui.workspace = true mimalloc = { version = "0.1", optional = true } nc.workspace = true nix = { workspace = true, features = ["pthread", "signal"] } @@ -166,6 +167,7 @@ zeta.workspace = true zeta2.workspace = true zlog.workspace = true zlog_settings.workspace = true +chrono.workspace = true [target.'cfg(target_os = "windows")'.dependencies] windows.workspace = true diff --git a/crates/zed/src/main.rs b/crates/zed/src/main.rs index 14e718ec2457b7d0f49c60cbc923cc7f215f9a15..a2e0c449e982594d7197da355ff4720c4da87163 100644 --- a/crates/zed/src/main.rs +++ b/crates/zed/src/main.rs @@ -37,7 +37,8 @@ use std::{ io::{self, IsTerminal}, path::{Path, PathBuf}, process, - sync::Arc, + sync::{Arc, OnceLock}, + time::Instant, }; use theme::{ActiveTheme, GlobalTheme, ThemeRegistry}; use util::{ResultExt, TryFutureExt, maybe}; @@ -162,7 +163,11 @@ fn fail_to_open_window(e: anyhow::Error, _cx: &mut App) { } } +pub static STARTUP_TIME: OnceLock = OnceLock::new(); + pub fn main() { + STARTUP_TIME.get_or_init(|| Instant::now()); + #[cfg(unix)] util::prevent_root_execution(); @@ -637,6 +642,7 @@ pub fn main() { zeta::init(cx); inspector_ui::init(app_state.clone(), cx); json_schema_store::init(cx); + miniprofiler_ui::init(*STARTUP_TIME.get().unwrap(), cx); cx.observe_global::({ let http = app_state.client.http_client(); @@ -1226,6 +1232,7 @@ fn init_paths() -> HashMap> { paths::database_dir(), paths::logs_dir(), paths::temp_dir(), + paths::hang_traces_dir(), ] .into_iter() .fold(HashMap::default(), |mut errors, path| { diff --git a/crates/zed/src/reliability.rs b/crates/zed/src/reliability.rs index dcabe93aab4ff35de44b77b87eb8495f537564fe..5a45c0c558389cd9d2aff02efaed5753bdb5d1f2 100644 --- a/crates/zed/src/reliability.rs +++ b/crates/zed/src/reliability.rs @@ -1,17 +1,22 @@ use anyhow::{Context as _, Result}; use client::{TelemetrySettings, telemetry::MINIDUMP_ENDPOINT}; use futures::AsyncReadExt; -use gpui::{App, AppContext as _}; +use gpui::{App, AppContext as _, SerializedThreadTaskTimings}; use http_client::{self, HttpClient, HttpClientWithUrl}; +use log::info; use project::Project; use proto::{CrashReport, GetCrashFilesResponse}; use reqwest::multipart::{Form, Part}; use settings::Settings; use smol::stream::StreamExt; -use std::{ffi::OsStr, fs, sync::Arc}; +use std::{ffi::OsStr, fs, sync::Arc, thread::ThreadId, time::Duration}; use util::ResultExt; +use crate::STARTUP_TIME; + pub fn init(http_client: Arc, installation_id: Option, cx: &mut App) { + monitor_hangs(cx); + #[cfg(target_os = "macos")] monitor_main_thread_hangs(http_client.clone(), installation_id.clone(), cx); @@ -272,6 +277,94 @@ pub fn monitor_main_thread_hangs( .detach() } +fn monitor_hangs(cx: &App) { + let main_thread_id = std::thread::current().id(); + + let foreground_executor = cx.foreground_executor(); + let background_executor = cx.background_executor(); + + // 3 seconds hang + let (mut tx, mut rx) = futures::channel::mpsc::channel(3); + foreground_executor + .spawn(async move { while (rx.next().await).is_some() {} }) + .detach(); + + background_executor + .spawn({ + let background_executor = background_executor.clone(); + async move { + let mut hang_time = None; + + let mut hanging = false; + loop { + background_executor.timer(Duration::from_secs(1)).await; + match tx.try_send(()) { + Ok(_) => { + hang_time = None; + hanging = false; + continue; + } + Err(e) => { + let is_full = e.into_send_error().is_full(); + if is_full && !hanging { + hanging = true; + hang_time = Some(chrono::Local::now()); + } + + if is_full { + save_hang_trace( + main_thread_id, + &background_executor, + hang_time.unwrap(), + ); + } + } + } + } + } + }) + .detach(); +} + +fn save_hang_trace( + main_thread_id: ThreadId, + background_executor: &gpui::BackgroundExecutor, + hang_time: chrono::DateTime, +) { + let thread_timings = background_executor.dispatcher.get_all_timings(); + let thread_timings = thread_timings + .into_iter() + .map(|mut timings| { + if timings.thread_id == main_thread_id { + timings.thread_name = Some("main".to_string()); + } + + SerializedThreadTaskTimings::convert(*STARTUP_TIME.get().unwrap(), timings) + }) + .collect::>(); + + let trace_path = paths::hang_traces_dir().join(&format!( + "hang-{}.miniprof", + hang_time.format("%Y-%m-%d_%H-%M-%S") + )); + + let Some(timings) = serde_json::to_string(&thread_timings) + .context("hang timings serialization") + .log_err() + else { + return; + }; + + std::fs::write(&trace_path, timings) + .context("hang trace file writing") + .log_err(); + + info!( + "hang detected, trace file saved at: {}", + trace_path.display() + ); +} + pub async fn upload_previous_minidumps( http: Arc, installation_id: Option, diff --git a/crates/zed_actions/src/lib.rs b/crates/zed_actions/src/lib.rs index c0739c74c7ac6c103e34c7a2cd730096503ef565..f00b2a7bfd3371359659f310a37ee36ef75b04f5 100644 --- a/crates/zed_actions/src/lib.rs +++ b/crates/zed_actions/src/lib.rs @@ -65,6 +65,8 @@ actions!( OpenLicenses, /// Opens the telemetry log. OpenTelemetryLog, + /// Opens the performance profiler. + OpenPerformanceProfiler, ] );