diff --git a/Cargo.lock b/Cargo.lock index b6e9c686f7..76a7158afb 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1276,6 +1276,7 @@ dependencies = [ "enso-logger", "enso-optics", "enso-prelude", + "enso-profiler", "enso-shapely", "enso-shortcuts", "enso-types", @@ -1425,6 +1426,26 @@ dependencies = [ "wasm-bindgen", ] +[[package]] +name = "ensogl-example-render-profile" +version = "0.1.0" +dependencies = [ + "enso-frp", + "enso-profiler", + "enso-profiler-data", + "enso-profiler-flame-graph", + "enso-web", + "ensogl-core", + "ensogl-flame-graph", + "ensogl-hardcoded-theme", + "ensogl-text", + "ensogl-text-msdf-sys", + "futures 0.3.21", + "wasm-bindgen", + "wasm-bindgen-futures", + "web-sys", +] + [[package]] name = "ensogl-example-scroll-area" version = "0.1.0" @@ -1497,6 +1518,7 @@ dependencies = [ "ensogl-example-list-view", "ensogl-example-mouse-events", "ensogl-example-profiling-run-graph", + "ensogl-example-render-profile", "ensogl-example-scroll-area", "ensogl-example-shape-system", "ensogl-example-slider", diff --git a/app/gui/src/controller/ide/desktop.rs b/app/gui/src/controller/ide/desktop.rs index fe85268486..06155efbd6 100644 --- a/app/gui/src/controller/ide/desktop.rs +++ b/app/gui/src/controller/ide/desktop.rs @@ -120,48 +120,55 @@ impl API for Handle { impl ManagingProjectAPI for Handle { fn create_new_project(&self, template: Option) -> BoxFuture { - async move { - use model::project::Synchronized as Project; - - let list = self.project_manager.list_projects(&None).await?; - let existing_names: HashSet<_> = - list.projects.into_iter().map(|p| p.name.into()).collect(); - let name = template.clone().unwrap_or_else(|| UNNAMED_PROJECT_NAME.to_owned()); - let name = choose_new_project_name(&existing_names, &name); - let name = ProjectName::new_unchecked(name); - let version = Some(enso_config::engine_version_supported.to_string()); - let action = MissingComponentAction::Install; - - let create_result = - self.project_manager.create_project(&name, &template, &version, &action).await?; - let new_project_id = create_result.project_id; - let project_mgr = self.project_manager.clone_ref(); - let new_project = Project::new_opened(&self.logger, project_mgr, new_project_id); - self.current_project.set(Some(new_project.await?)); - executor::global::spawn(self.notifications.publish(Notification::NewProjectCreated)); - Ok(()) - } - .boxed_local() + self.create_new_project_internal(template).boxed_local() } fn list_projects(&self) -> BoxFuture>> { - async move { - let pm_response = self.project_manager.list_projects(&None).await?; - Ok(pm_response.projects) - } - .boxed_local() + self.list_projects_internal().boxed_local() } fn open_project(&self, id: Uuid) -> BoxFuture { - async move { - let logger = &self.logger; - let project_mgr = self.project_manager.clone_ref(); - let new_project = model::project::Synchronized::new_opened(logger, project_mgr, id); - self.current_project.set(Some(new_project.await?)); - executor::global::spawn(self.notifications.publish(Notification::ProjectOpened)); - Ok(()) - } - .boxed_local() + self.open_project_internal(id).boxed_local() + } +} + +impl Handle { + #[profile(Objective)] + async fn create_new_project_internal(&self, template: Option) -> FallibleResult { + use model::project::Synchronized as Project; + + let list = self.project_manager.list_projects(&None).await?; + let existing_names: HashSet<_> = list.projects.into_iter().map(|p| p.name.into()).collect(); + let name = template.clone().unwrap_or_else(|| UNNAMED_PROJECT_NAME.to_owned()); + let name = choose_new_project_name(&existing_names, &name); + let name = ProjectName::new_unchecked(name); + let version = Some(enso_config::engine_version_supported.to_string()); + let action = MissingComponentAction::Install; + + let create_result = + self.project_manager.create_project(&name, &template, &version, &action).await?; + let new_project_id = create_result.project_id; + let project_mgr = self.project_manager.clone_ref(); + let new_project = Project::new_opened(&self.logger, project_mgr, new_project_id); + self.current_project.set(Some(new_project.await?)); + let notify = self.notifications.publish(Notification::NewProjectCreated); + executor::global::spawn(notify); + Ok(()) + } + + #[profile(Task)] + async fn list_projects_internal(&self) -> FallibleResult> { + Ok(self.project_manager.list_projects(&None).await?.projects) + } + + #[profile(Task)] + async fn open_project_internal(&self, id: Uuid) -> FallibleResult { + let logger = &self.logger; + let project_mgr = self.project_manager.clone_ref(); + let new_project = model::project::Synchronized::new_opened(logger, project_mgr, id); + self.current_project.set(Some(new_project.await?)); + executor::global::spawn(self.notifications.publish(Notification::ProjectOpened)); + Ok(()) } } diff --git a/app/gui/src/controller/project.rs b/app/gui/src/controller/project.rs index 7368133270..72a7c34ebd 100644 --- a/app/gui/src/controller/project.rs +++ b/app/gui/src/controller/project.rs @@ -120,6 +120,7 @@ impl Project { /// warning about unsupported engine version). /// /// Returns the controllers of module and graph which should be displayed in the view. + #[profile(Task)] pub async fn initialize(&self) -> FallibleResult { let project = self.model.clone_ref(); let parser = self.model.parser(); diff --git a/app/gui/src/ide/initializer.rs b/app/gui/src/ide/initializer.rs index cd49674f7f..eeb19c70d3 100644 --- a/app/gui/src/ide/initializer.rs +++ b/app/gui/src/ide/initializer.rs @@ -59,19 +59,23 @@ impl Initializer { /// Initialize all Ide objects and structures (executor, views, controllers, integration etc.) /// and forget them to keep them alive. + #[profile(Task)] pub fn start_and_forget(self) { let executor = setup_global_executor(); - executor::global::spawn(async move { - let ide = self.start().await; + #[profile(Task)] + async fn start_and_forget_internal(self_: Initializer) { + let ide = self_.start().await; web::document .get_element_by_id("loader") .map(|t| t.parent_node().map(|p| p.remove_child(&t).unwrap())); std::mem::forget(ide); - }); + } + executor::global::spawn(start_and_forget_internal(self)); std::mem::forget(executor); } /// Initialize all Ide objects and structures (executor, views, controllers, integration etc.) + #[profile(Task)] pub async fn start(self) -> Result { info!(self.logger, "Starting IDE with the following config: {self.config:?}"); @@ -134,6 +138,7 @@ impl Initializer { /// /// This will setup all required connections to backend properly, according to the /// configuration. + #[profile(Task)] pub async fn initialize_ide_controller(&self) -> FallibleResult { use crate::config::BackendService::*; match &self.config.backend { @@ -166,6 +171,7 @@ impl Initializer { /// Create and configure a new project manager client and register it within the global /// executor. + #[profile(Task)] pub async fn setup_project_manager( &self, endpoint: &str, diff --git a/app/gui/src/lib.rs b/app/gui/src/lib.rs index 83cf03d0cf..0dbb188233 100644 --- a/app/gui/src/lib.rs +++ b/app/gui/src/lib.rs @@ -95,6 +95,9 @@ pub mod prelude { pub use crate::model; pub use crate::model::traits::*; + pub use enso_profiler as profiler; + pub use enso_profiler::prelude::*; + pub use engine_protocol::prelude::BoxFuture; pub use engine_protocol::prelude::StaticBoxFuture; pub use engine_protocol::prelude::StaticBoxStream; @@ -124,7 +127,11 @@ mod examples { #[allow(unused_imports)] use examples::*; +use prelude::profiler; +use prelude::profiler::prelude::*; + /// IDE startup function. +#[profile(Objective)] #[wasm_bindgen] #[allow(dead_code)] pub fn entry_point_ide() { diff --git a/app/gui/src/model/project/synchronized.rs b/app/gui/src/model/project/synchronized.rs index 00c8c81c03..ee1f5a7fbb 100644 --- a/app/gui/src/model/project/synchronized.rs +++ b/app/gui/src/model/project/synchronized.rs @@ -248,6 +248,7 @@ pub struct Project { impl Project { /// Create a new project model. + #[profile(Detail)] pub async fn new( parent: impl AnyLogger, project_manager: Option>, @@ -303,6 +304,7 @@ impl Project { } /// Initializes the json and binary connection to Language Server, and creates a Project Model + #[profile(Detail)] pub async fn new_connected( parent: impl AnyLogger, project_manager: Option>, @@ -337,6 +339,7 @@ impl Project { /// Creates a project model by opening a given project in project_manager, and initializing /// the received json and binary connections. + #[profile(Detail)] pub async fn new_opened( parent: &Logger, project_manager: Rc, diff --git a/app/gui/src/presenter.rs b/app/gui/src/presenter.rs index 1ccf6b461c..194d9854d6 100644 --- a/app/gui/src/presenter.rs +++ b/app/gui/src/presenter.rs @@ -43,45 +43,44 @@ struct Model { impl Model { /// Instantiate a new project presenter, which will display current project in the view. + #[profile(Task)] fn setup_and_display_new_project(self: Rc) { // Remove the old integration first. We want to be sure the old and new integrations will // not race for the view. *self.current_project.borrow_mut() = None; + let project_model = match self.controller.current_project() { + Some(model) => model, + None => return, + }; + self.view.switch_view_to_project(); + // We know the name of new project before it loads. We set it right now to avoid + // displaying a placeholder on the scene during loading. + let project_view = self.view.project(); + let status_bar = self.view.status_bar().clone_ref(); + let breadcrumbs = &project_view.graph().model.breadcrumbs; + breadcrumbs.project_name(project_model.name().to_string()); - if let Some(project_model) = self.controller.current_project() { - self.view.switch_view_to_project(); - // We know the name of new project before it loads. We set it right now to avoid - // displaying placeholder on the scene during loading. - let project_view = self.view.project(); - let status_bar = self.view.status_bar().clone_ref(); - let breadcrumbs = &project_view.graph().model.breadcrumbs; - breadcrumbs.project_name(project_model.name().to_string()); - - let status_notifications = self.controller.status_notifications().clone_ref(); - let ide_controller = self.controller.clone_ref(); - let project_controller = - controller::Project::new(project_model, status_notifications.clone_ref()); - - executor::global::spawn(async move { - match presenter::Project::initialize( - ide_controller, - project_controller, - project_view, - status_bar, - ) - .await - { - Ok(project) => { - *self.current_project.borrow_mut() = Some(project); - } - Err(err) => { - let err_msg = format!("Failed to initialize project: {}", err); - error!(self.logger, "{err_msg}"); - status_notifications.publish_event(err_msg) - } + let status_notifications = self.controller.status_notifications().clone_ref(); + let ide_controller = self.controller.clone_ref(); + let project_controller = controller::Project::new(project_model, status_notifications); + let project_presenter = presenter::Project::initialize( + ide_controller, + project_controller, + project_view, + status_bar, + ); + crate::executor::global::spawn(async move { + match project_presenter.await { + Ok(project) => { + *self.current_project.borrow_mut() = Some(project); } - }); - } + Err(err) => { + let err_msg = format!("Failed to initialize project: {}", err); + error!(self.logger, "{err_msg}"); + self.controller.status_notifications().publish_event(err_msg); + } + } + }); } /// Open a project by name. It makes two calls to Project Manager: one for listing projects and @@ -145,6 +144,7 @@ impl Presenter { /// /// The returned presenter is working and does not require any initialization. The current /// project will be displayed (if any). + #[profile(Task)] pub fn new(controller: controller::Ide, view: ide_view::root::View) -> Self { let logger = Logger::new("Presenter"); let current_project = default(); @@ -164,11 +164,12 @@ impl Presenter { Self { model, network }.init() } + #[profile(Detail)] fn init(self) -> Self { self.setup_status_bar_notification_handler(); self.setup_controller_notification_handler(); - self.set_projects_list_on_welcome_screen(); self.model.clone_ref().setup_and_display_new_project(); + executor::global::spawn(self.clone_ref().set_projects_list_on_welcome_screen()); self } @@ -216,23 +217,19 @@ impl Presenter { }); } - fn set_projects_list_on_welcome_screen(&self) { - let controller = self.model.controller.clone_ref(); - let welcome_view_frp = self.model.view.welcome_screen().frp.clone_ref(); - let logger = self.model.logger.clone_ref(); - crate::executor::global::spawn(async move { - if let Ok(project_manager) = controller.manage_projects() { - match project_manager.list_projects().await { - Ok(projects) => { - let names = projects.into_iter().map(|p| p.name.into()).collect::>(); - welcome_view_frp.set_projects_list(names); - } - Err(err) => { - error!(logger, "Unable to get list of projects: {err}."); - } + #[profile(Detail)] + async fn set_projects_list_on_welcome_screen(self) { + if let Ok(project_manager) = self.model.controller.manage_projects() { + match project_manager.list_projects().await { + Ok(projects) => { + let names = projects.into_iter().map(|p| p.name.into()).collect::>(); + self.model.view.welcome_screen().frp.set_projects_list(names); + } + Err(err) => { + error!(self.model.logger, "Unable to get list of projects: {err}."); } } - }); + } } } diff --git a/app/gui/src/presenter/code.rs b/app/gui/src/presenter/code.rs index b23caf6bdd..8853f7c26d 100644 --- a/app/gui/src/presenter/code.rs +++ b/app/gui/src/presenter/code.rs @@ -70,6 +70,7 @@ pub struct Code { impl Code { /// Constructor. The returned structure works right away and does not need any initialization. + #[profile(Task)] pub fn new(controller: controller::Text, project_view: &view::project::View) -> Self { let network = frp::Network::new("presenter::code"); let view = project_view.code_editor().clone_ref(); diff --git a/app/gui/src/presenter/graph.rs b/app/gui/src/presenter/graph.rs index 94bd2ac9d4..bf44de0ab3 100644 --- a/app/gui/src/presenter/graph.rs +++ b/app/gui/src/presenter/graph.rs @@ -459,6 +459,7 @@ pub struct Graph { impl Graph { /// Create graph presenter. The returned structure is working and does not require any /// initialization. + #[profile(Task)] pub fn new( project: model::Project, controller: controller::ExecutedGraph, @@ -470,6 +471,7 @@ impl Graph { Self { network, model }.init(project_view) } + #[profile(Detail)] fn init(self, project_view: &view::project::View) -> Self { let logger = &self.model.logger; let network = &self.network; diff --git a/app/gui/src/presenter/project.rs b/app/gui/src/presenter/project.rs index 7670f43a57..1bdfe91c2a 100644 --- a/app/gui/src/presenter/project.rs +++ b/app/gui/src/presenter/project.rs @@ -34,6 +34,7 @@ struct Model { } impl Model { + #[profile(Task)] fn new( ide_controller: controller::Ide, controller: controller::Project, @@ -165,6 +166,7 @@ impl Project { /// /// The returned presenter will be already working: it will display the initial main graph, and /// react to all notifications. + #[profile(Task)] pub fn new( ide_controller: controller::Ide, controller: controller::Project, @@ -177,6 +179,7 @@ impl Project { Self { network, model: Rc::new(model) }.init() } + #[profile(Detail)] fn init(self) -> Self { let model = &self.model; let network = &self.network; @@ -271,6 +274,7 @@ impl Project { /// /// This calls the [`controller::Project::initialize`] method and use the initialization result /// to construct working presenter. + #[profile(Task)] pub async fn initialize( ide_controller: controller::Ide, controller: controller::Project, diff --git a/build/run.js b/build/run.js index 61ead9eae4..80135a72b6 100755 --- a/build/run.js +++ b/build/run.js @@ -163,9 +163,25 @@ commands.build.rust = async function (argv) { if (argv.dev) { args.push('--dev') } - if (cargoArgs) { - args.push('--') - } + args.push('--') + // Enable source-file and line number information in the data generated by the `#[profile]` + // macro. + // + // The `profiler` library requires use of a Rust unstable feature, `proc_macro_span`, to be + // able to obtain this information. + // + // The IntelliJ Rust plugin does not support the `proc_macro_span` Rust feature; using it causes + // JetBrains IDEs to become entirely unaware of the items produced by `#[profile]`. + // (See: https://github.com/intellij-rust/intellij-rust/issues/8655) + // + // In order to have line number information in actual usage, but keep everything understandable + // by JetBrains IDEs, we need IntelliJ/CLion to build crates differently from how they are + // built for the application to be run. This is accomplished by gating the use of the unstable + // functionality by a Cargo feature. Cargo features are disabled by default, so when a Rust IDE + // builds crates internally in order to determine macro expansions, it will do so without line + // numbers. When this script is used to build the application, it is not for the purpose of IDE + // macro expansion, so we can safely enable line numbers. + args.push('--features=enso-profiler/line-numbers') await run_cargo('wasm-pack', args) await patch_file(paths.wasm.glue, js_workaround_patcher) await fs.rename(paths.wasm.mainRaw, paths.wasm.main) diff --git a/lib/rust/ensogl/core/Cargo.toml b/lib/rust/ensogl/core/Cargo.toml index 4320d398dc..cbc63d252b 100644 --- a/lib/rust/ensogl/core/Cargo.toml +++ b/lib/rust/ensogl/core/Cargo.toml @@ -21,6 +21,7 @@ enso-generics = { path = "../../generics"} enso-logger = { path = "../../logger"} enso-optics = { path = "../../optics"} enso-prelude = { path = "../../prelude"} +enso-profiler = { path = "../../profiler"} enso-shapely = { path = "../../shapely"} enso-shortcuts = { path = "../../shortcuts" } enso-types = { path = "../../types" } diff --git a/lib/rust/ensogl/core/src/display/world.rs b/lib/rust/ensogl/core/src/display/world.rs index 37b26966bc..14aa1bfbc0 100644 --- a/lib/rust/ensogl/core/src/display/world.rs +++ b/lib/rust/ensogl/core/src/display/world.rs @@ -247,6 +247,9 @@ impl WorldData { display_mode.set(1) } else if key == "Digit2" { display_mode.set(2) + } else if key == "KeyP" { + let log = profiler::internal::take_log(); + web_sys::console::log_1(&log.into()); } } }); diff --git a/lib/rust/ensogl/core/src/lib.rs b/lib/rust/ensogl/core/src/lib.rs index 8e8108583a..abe27b83fa 100644 --- a/lib/rust/ensogl/core/src/lib.rs +++ b/lib/rust/ensogl/core/src/lib.rs @@ -66,6 +66,8 @@ pub mod prelude { pub use enso_logger::DefaultWarningLogger as Logger; pub use enso_logger::*; pub use enso_prelude::*; + pub use enso_profiler as profiler; + pub use enso_profiler::prelude::*; pub use enso_shapely::newtype_prim; pub use enso_shapely::newtype_prim_no_default; pub use enso_shapely::newtype_prim_no_default_no_display; diff --git a/lib/rust/ensogl/example/Cargo.toml b/lib/rust/ensogl/example/Cargo.toml index 8ce61b97f9..109dfa1d56 100644 --- a/lib/rust/ensogl/example/Cargo.toml +++ b/lib/rust/ensogl/example/Cargo.toml @@ -17,6 +17,7 @@ ensogl-example-glyph-system = { path = "glyph-system" } ensogl-example-list-view = { path = "list-view" } ensogl-example-mouse-events = { path = "mouse-events" } ensogl-example-profiling-run-graph = { path = "profiling-run-graph" } +ensogl-example-render-profile = { path = "render-profile" } ensogl-example-scroll-area = { path = "scroll-area" } ensogl-example-shape-system = { path = "shape-system" } ensogl-example-slider = { path = "slider" } diff --git a/lib/rust/ensogl/example/render-profile/Cargo.toml b/lib/rust/ensogl/example/render-profile/Cargo.toml new file mode 100644 index 0000000000..53b980f84c --- /dev/null +++ b/lib/rust/ensogl/example/render-profile/Cargo.toml @@ -0,0 +1,35 @@ +[package] +name = "ensogl-example-render-profile" +version = "0.1.0" +authors = ["Enso Team "] +edition = "2021" + +[lib] +crate-type = ["cdylib", "rlib"] + + +[dependencies] +enso-frp = { path = "../../../frp" } +enso-profiler = { path = "../../../profiler" } +enso-profiler-data = { path = "../../../profiler/data" } +enso-profiler-flame-graph = { path = "../../../profiler/flame-graph" } +enso-web = { path = "../../../web" } +ensogl-core = { path = "../../core" } +ensogl-flame-graph = { path = "../../component/flame-graph" } +ensogl-hardcoded-theme = { path = "../../app/theme/hardcoded" } +ensogl-text = { path = "../../component/text" } +ensogl-text-msdf-sys = { path = "../../component/text/msdf-sys" } +futures = "0.3" +wasm-bindgen = { version = "0.2.58", features = [ "nightly" ] } +wasm-bindgen-futures = "0.4" + +[dependencies.web-sys] +version = "0.3" +features = [ + 'Headers', + 'Request', + 'RequestInit', + 'RequestMode', + 'Response', + 'Window', +] diff --git a/lib/rust/ensogl/example/render-profile/src/lib.rs b/lib/rust/ensogl/example/render-profile/src/lib.rs new file mode 100644 index 0000000000..6f9f1fb0e3 --- /dev/null +++ b/lib/rust/ensogl/example/render-profile/src/lib.rs @@ -0,0 +1,86 @@ +//! Renders profiling data, obtained from a file, as a flame graph. + +#![warn(missing_copy_implementations)] +#![warn(missing_debug_implementations)] +#![warn(missing_docs)] +#![warn(trivial_casts)] +#![warn(trivial_numeric_casts)] +#![warn(unsafe_code)] +#![warn(unused_import_braces)] +#![warn(unused_qualifications)] + +use ensogl_core::prelude::*; +use wasm_bindgen::prelude::*; + +use enso_profiler_data as profiler_data; +use ensogl_core::application; +use ensogl_core::data::color; +use ensogl_core::display; +use ensogl_core::display::navigation::navigator; +use ensogl_core::display::style::theme; +use ensogl_flame_graph as flame_graph; + + + +// =================== +// === Entry Point === +// =================== + +/// Render a graph of a profile file. +#[wasm_bindgen] +#[allow(dead_code)] +pub async fn entry_point_render_profile() { + use ensogl_core::display::object::ObjectOps; + let app = application::Application::new("root"); + let world = &app.display; + let scene = &world.default_scene; + let navigator = navigator::Navigator::new(scene, &scene.camera()); + init_theme(scene); + let data = get_data().await; + let measurements: profiler_data::Measurement = + data.parse().unwrap(); + let flame_graph = flame_graph::FlameGraph::from_data(measurements.into(), &app); + scene.add_child(&flame_graph); + scene.layers.main.add_exclusive(&flame_graph); + world.keep_alive_forever(); + world + .on + .before_frame + .add(move |_time| { + let _keep_alive = &navigator; + let _keep_alive = &flame_graph; + }) + .forget(); +} + +/// Read profile data from a file. The file must be located at `/profile.json` in the root of the +/// directory that will be made available by the webserver, i.e. `enso/dist/content`. +async fn get_data() -> String { + use wasm_bindgen::JsCast; + + let url = "/profile.json"; + let mut opts = web_sys::RequestInit::new(); + opts.method("GET"); + opts.mode(web_sys::RequestMode::Cors); + let request = web_sys::Request::new_with_str_and_init(url, &opts).unwrap(); + request.headers().set("Accept", "application/json").unwrap(); + let window = web_sys::window().unwrap(); + let response = window.fetch_with_request(&request); + let response = wasm_bindgen_futures::JsFuture::from(response).await.unwrap(); + assert!(response.is_instance_of::()); + let response: web_sys::Response = response.dyn_into().unwrap(); + let data = response.text().unwrap(); + let data = wasm_bindgen_futures::JsFuture::from(data).await.unwrap(); + data.as_string().unwrap() +} + +fn init_theme(scene: &display::Scene) { + let theme_manager = theme::Manager::from(&scene.style_sheet); + let theme = theme::Theme::new(); + const COLOR_PATH: &str = "flame_graph_color"; + theme.set(COLOR_PATH, color::Rgb::new(1.0, 45.0 / 255.0, 0.0)); + theme_manager.register("theme", theme); + theme_manager.set_enabled(&["theme".to_string()]); + let style_watch = ensogl_core::display::shape::StyleWatch::new(&scene.style_sheet); + style_watch.get(COLOR_PATH); +} diff --git a/lib/rust/ensogl/example/src/lib.rs b/lib/rust/ensogl/example/src/lib.rs index fcbb977884..9f224e22b4 100644 --- a/lib/rust/ensogl/example/src/lib.rs +++ b/lib/rust/ensogl/example/src/lib.rs @@ -37,6 +37,7 @@ pub use ensogl_example_glyph_system as glyph_system; pub use ensogl_example_list_view as list_view; pub use ensogl_example_mouse_events as mouse_events; pub use ensogl_example_profiling_run_graph as profiling_run_graph; +pub use ensogl_example_render_profile as render_profile; pub use ensogl_example_scroll_area as scroll_area; pub use ensogl_example_shape_system as shape_system; pub use ensogl_example_slider as slider; diff --git a/lib/rust/profiler/Cargo.toml b/lib/rust/profiler/Cargo.toml index 5e3de1682b..7768dc6083 100644 --- a/lib/rust/profiler/Cargo.toml +++ b/lib/rust/profiler/Cargo.toml @@ -13,3 +13,6 @@ enso-web = { path = "../web" } [dev-dependencies] futures = "0.3" + +[features] +line-numbers = ["enso-profiler-macros/lineno"] diff --git a/lib/rust/profiler/data/src/bin/measurements.rs b/lib/rust/profiler/data/src/bin/measurements.rs new file mode 100644 index 0000000000..d19c19f739 --- /dev/null +++ b/lib/rust/profiler/data/src/bin/measurements.rs @@ -0,0 +1,66 @@ +//! Tool that generates human-readable reports from profiling data. +//! +//! # Usage +//! +//! The tool reads a JSON-formatted event log from stdin, and writes a report to stdout. +//! +//! For example: +//! +//! ```console +//! ~/git/enso/data $ cargo run --bin measurements < profile.json | less +//! ``` + +#![feature(test)] +#![deny(unconditional_recursion)] +#![warn(missing_copy_implementations)] +#![warn(missing_debug_implementations)] +#![warn(missing_docs)] +#![warn(trivial_casts)] +#![warn(trivial_numeric_casts)] +#![warn(unsafe_code)] +#![warn(unused_import_braces)] + + +use enso_profiler_data as profiler_data; +use std::io::Read; + +/// Format a [`profiler_data::Interval`] in an easy-to-read way. +fn fmt_interval(interval: profiler_data::Interval) -> String { + let start = interval.start.into_ms(); + let end = interval.end.map(|x| format!("{:.1}", x.into_ms())).unwrap_or_default(); + format!("{:.1}-{}", start, end) +} + +/// Pretty-print a [`profiler_data::Measurement`], including all children, in a way that illustrates +/// the hierarchy of the data. Results will be written to stdout. +fn print_measurement(measurement: &enso_profiler_data::Measurement<()>, i: usize) { + let mut indent = String::new(); + for _ in 0..i { + indent.push_str(" "); + } + println!("{}{}", indent, measurement.label); + match &measurement.lifetime { + profiler_data::Lifetime::Async(profiler_data::AsyncLifetime { active, .. }) => { + println!("{} intervals:", indent); + for active in active { + println!("{} interval: {}", indent, fmt_interval(*active)); + } + } + profiler_data::Lifetime::NonAsync { active } => { + println!("{} interval: {}", indent, fmt_interval(*active)); + } + } + println!("{} children:", indent); + for child in &measurement.children { + print_measurement(child, i + 2); + } +} + +fn main() { + let mut log = String::new(); + std::io::stdin().read_to_string(&mut log).unwrap(); + let app_lifetime: profiler_data::Measurement<()> = log.parse().unwrap(); + for root in app_lifetime.children { + print_measurement(&root, 0); + } +} diff --git a/lib/rust/profiler/data/src/lib.rs b/lib/rust/profiler/data/src/lib.rs index 34f4dac4fa..e49a18fdde 100644 --- a/lib/rust/profiler/data/src/lib.rs +++ b/lib/rust/profiler/data/src/lib.rs @@ -214,9 +214,9 @@ pub struct Measurement { pub lifetime: Lifetime, /// Identifies the profiler's source and scope to the user. pub label: Label, - /// Profilers started by this profiler. + /// Profilers started by this profiler, ordered by time created. pub children: Vec, - /// Metadata attached to this profiler. + /// Metadata attached to this profiler, ordered by time logged. pub metadata: Vec>, } diff --git a/lib/rust/profiler/data/src/parse.rs b/lib/rust/profiler/data/src/parse.rs index 4cdccc3590..f75b4b779d 100644 --- a/lib/rust/profiler/data/src/parse.rs +++ b/lib/rust/profiler/data/src/parse.rs @@ -67,7 +67,8 @@ pub(crate) fn interpret( // Build measurements from accumulated measurement data. let mut measurements: collections::HashMap<_, _> = builders.into_iter().map(|(k, v)| (k, v.build())).collect(); - // Organize measurements into trees. + // Organize measurements into trees. Use reverse chronological order as a convenient topological + // sort (parents are always created before children). let mut root = root_builder.build(); for (id, parent) in order.into_iter().rev() { let child = measurements.remove(&id).unwrap(); @@ -82,9 +83,18 @@ pub(crate) fn interpret( }; parent.push(child); } + // Organize children by creation time. (Previous pass gathered them in reverse order.) + reverse_subtrees(&mut root); Ok(root) } +fn reverse_subtrees(root: &mut crate::Measurement) { + root.children.reverse(); + for child in root.children.iter_mut() { + reverse_subtrees(child); + } +} + // ================= diff --git a/lib/rust/profiler/macros/build.rs b/lib/rust/profiler/macros/build.rs new file mode 100644 index 0000000000..ccfb66e05b --- /dev/null +++ b/lib/rust/profiler/macros/build.rs @@ -0,0 +1,20 @@ +//! Build script for [`enso_profiler_macros`]. This is needed because `profiler_macros` has a +//! profiling level controlled by the value of an environment variable at compile time, and cargo +//! needs to be made aware that changes to the env can invalidate the result of compiling this +//! crate and any dependents. + +#![warn(missing_copy_implementations)] +#![warn(missing_debug_implementations)] +#![warn(missing_docs)] +#![warn(trivial_casts)] +#![warn(trivial_numeric_casts)] +#![warn(unsafe_code)] +#![warn(unused_import_braces)] +#![warn(unused_qualifications)] + +fn main() { + println!("cargo:rerun-if-env-changed=ENSO_MAX_PROFILING_LEVEL"); + // This is a no-op assignment, except it makes cargo aware that the output depends on the env. + let value = std::env::var("ENSO_MAX_PROFILING_LEVEL").unwrap_or_default(); + println!("cargo:rustc-env=ENSO_MAX_PROFILING_LEVEL={}", value); +} diff --git a/lib/rust/profiler/macros/src/lib.rs b/lib/rust/profiler/macros/src/lib.rs index 2e84154fef..573170f317 100644 --- a/lib/rust/profiler/macros/src/lib.rs +++ b/lib/rust/profiler/macros/src/lib.rs @@ -271,33 +271,25 @@ pub fn profile( func.into_token_stream().into() } -fn profile_async(obj_ident: syn::Ident, label: String, func: &mut syn::ItemFn) { - let start_profiler = start_profiler(obj_ident, label, func.sig.asyncness.is_some()); - for s in &mut func.block.stmts { - WrapAwait.visit_stmt_mut(s); - } - let block = &func.block; - let body = quote::quote! {{ - #start_profiler - async move { - profiler::internal::Profiler::resume(&__profiler_scope.0); - let result = #block; - std::mem::drop(__profiler_scope); - result - } - }}; - let output_ty = match &func.sig.output { - syn::ReturnType::Default => quote::quote! { () }, - syn::ReturnType::Type(_, ty) => ty.to_token_stream(), - }; - let output = quote::quote! { - -> impl std::future::Future - }; - func.sig.asyncness = None; - func.sig.output = syn::parse2(output).unwrap(); - func.block = syn::parse2(body).unwrap(); +#[cfg(not(feature = "lineno"))] +/// Decorate the input with file:line info determined by the proc_macro's call site. +fn make_label(ident: &syn::Ident) -> String { + format!("{} (?:?)", ident) } +#[cfg(feature = "lineno")] +/// Decorate the input with file:line info determined by the proc_macro's call site. +fn make_label(ident: &syn::Ident) -> String { + let span = proc_macro::Span::call_site(); + let file = span.source_file().path(); + let path = file.as_path().to_string_lossy(); + let line = span.start().line; + format!("{} ({}:{})", ident, path, line) +} + + +// === profile_sync === + fn profile_sync(obj_ident: syn::Ident, label: String, func: &mut syn::ItemFn) { let start_profiler = start_profiler(obj_ident, label, func.sig.asyncness.is_some()); let block = &func.block; @@ -329,47 +321,217 @@ fn start_profiler( } } -#[cfg(not(feature = "lineno"))] -/// Decorate the input with file:line info determined by the proc_macro's call site. -fn make_label(ident: &syn::Ident) -> String { - format!("{} (?:?)", ident) + +// === profile_async === + +fn profile_async(obj_ident: syn::Ident, label: String, func: &mut syn::ItemFn) { + for s in &mut func.block.stmts { + WrapAwait.visit_stmt_mut(s); + } + let before_async = start_profiler(obj_ident, label, func.sig.asyncness.is_some()); + let start_async = quote::quote! { + profiler::internal::Profiler::resume(&__profiler_scope.0); + }; + let end_async = quote::quote! { + std::mem::drop(__profiler_scope); + }; + wrap_async_fn(func, before_async, start_async, end_async); } -#[cfg(feature = "lineno")] -/// Decorate the input with file:line info determined by the proc_macro's call site. -fn make_label(ident: &syn::Ident) -> String { - let span = proc_macro::Span::call_site(); - let file = span.source_file().path(); - let path = file.as_path().to_string_lossy(); - let line = span.start().line; - format!("{} ({}:{})", ident, path, line) +/// Convert an `async fn` into a `fn` returning a `Future`, implemented with an `async` block. +/// +/// Supports inserting statements before the `async` block is entered, just after entering it, and +/// just before leaving it. (The latter two will be in the same scope). +/// +/// If no statements are inserted, the output will be functionally equivalent to the input +/// (except the output won't `impl Send` even if the original `async fn` did). +fn wrap_async_fn( + func: &mut syn::ItemFn, + before_async: proc_macro2::TokenStream, + start_async: proc_macro2::TokenStream, + end_async: proc_macro2::TokenStream, +) { + let block = &func.block; + let ret_ty = match &func.sig.output { + syn::ReturnType::Default => quote::quote! { () }, + syn::ReturnType::Type(_, ty) => ty.into_token_stream(), + }; + let body = quote::quote! {{ + #before_async + async move { + #start_async + let result: #ret_ty = #block; + #end_async + result + } + }}; + let output_ty = match &func.sig.output { + syn::ReturnType::Default => quote::quote! { () }, + syn::ReturnType::Type(_, ty) => ty.to_token_stream(), + }; + let output_lifetime = syn::Lifetime::new("'__profiler_out", proc_macro2::Span::call_site()); + let lifetimes = explicitize_lifetimes(&mut func.sig); + let output = if lifetimes.is_empty() { + quote::quote! { + -> impl std::future::Future + } + } else { + // Bound all input lifetimes on the output lifetime. + for param in &mut func.sig.generics.params { + if let syn::GenericParam::Lifetime(def) = param { + def.bounds.push(output_lifetime.clone()); + } + } + // Add a definition for the output lifetime. + let lifetime_def = syn::LifetimeDef::new(output_lifetime.clone()); + func.sig.generics.params.insert(0, syn::GenericParam::Lifetime(lifetime_def)); + // Apply the output lifetime to the output. + quote::quote! { + -> impl std::future::Future + #output_lifetime + } + }; + func.sig.asyncness = None; + func.sig.output = syn::parse2(output).unwrap(); + func.block = syn::parse2(body).unwrap(); +} + +/// Make all lifetimes in function signature explicit. +/// +/// Returns the lifetimes used in the function signature. +fn explicitize_lifetimes(sig: &mut syn::Signature) -> Vec { + // Go through the args; find: + // - anonymous lifetime: '_ + // - implicit lifetimes: &foo + // - explicit lifetimes: &'a + // Make all input lifetimes explicit: + // - Use new lifetime explicitly in arg list. + // - Define new lifetime in generic params. + let mut input_transformer = ExplicitizeInputLifetimes::default(); + for input in &mut sig.inputs { + input_transformer.visit_fn_arg_mut(input); + } + let ExplicitizeInputLifetimes { new_lifetimes, existing_lifetimes } = input_transformer; + let mut all_lifetimes = existing_lifetimes; + all_lifetimes.extend_from_slice(&new_lifetimes); + let new_lifetimes = + new_lifetimes.into_iter().map(|lt| syn::GenericParam::Lifetime(syn::LifetimeDef::new(lt))); + sig.generics.params.extend(new_lifetimes); + // There are two cases where output lifetimes may be elided: + // - There's exactly one lifetime in the inputs. + // - There's a receiver with a lifetime. + // If either case occurs, make any implicit output lifetimes explicit. + let default_lifetime = if all_lifetimes.len() == 1 { + Some(all_lifetimes[0].clone()) + } else { + get_receiver_lifetime(sig).cloned() + }; + if let Some(lifetime) = default_lifetime { + ExplicitizeOutputLifetimes { lifetime }.visit_return_type_mut(&mut sig.output); + } + all_lifetimes +} + +#[derive(Default)] +struct ExplicitizeInputLifetimes { + new_lifetimes: Vec, + existing_lifetimes: Vec, +} + +impl ExplicitizeInputLifetimes { + fn gen_lifetime(&mut self) -> syn::Lifetime { + let name = format!("'__profiler{}", self.new_lifetimes.len()); + let new = syn::Lifetime::new(&name, proc_macro2::Span::call_site()); + self.new_lifetimes.push(new.clone()); + new + } + + fn visit_elidable_lifetime(&mut self, lifetime: &mut Option) { + match lifetime { + Some(lifetime) => self.visit_lifetime_mut(lifetime), + None => *lifetime = Some(self.gen_lifetime()), + } + } +} + +impl visit_mut::VisitMut for ExplicitizeInputLifetimes { + // Handles 'x in generic parameters in types of non-self arguments. + fn visit_lifetime_mut(&mut self, lifetime: &mut syn::Lifetime) { + let name = lifetime.ident.to_string(); + if &name == "_" { + *lifetime = self.gen_lifetime(); + } else { + self.existing_lifetimes.push(lifetime.clone()); + } + } + + // Handles &self. + fn visit_receiver_mut(&mut self, receiver: &mut syn::Receiver) { + if let Some((_, lifetime)) = &mut receiver.reference { + self.visit_elidable_lifetime(lifetime); + } + } + + // Handles & in types of non-self arguments. + fn visit_type_reference_mut(&mut self, type_reference: &mut syn::TypeReference) { + self.visit_elidable_lifetime(&mut type_reference.lifetime); + } +} + +struct ExplicitizeOutputLifetimes { + lifetime: syn::Lifetime, +} + +impl visit_mut::VisitMut for ExplicitizeOutputLifetimes { + // Handles 'x in generic parameters in types. + fn visit_lifetime_mut(&mut self, lifetime: &mut syn::Lifetime) { + if &lifetime.ident.to_string() == "_" { + *lifetime = self.lifetime.clone(); + } + } + + // Handles & in types. + fn visit_type_reference_mut(&mut self, type_reference: &mut syn::TypeReference) { + if type_reference.lifetime.is_none() { + type_reference.lifetime = Some(self.lifetime.clone()); + } + } +} + +fn get_receiver_lifetime(sig: &syn::Signature) -> Option<&syn::Lifetime> { + match sig.inputs.first() { + Some(syn::FnArg::Receiver(syn::Receiver { + reference: Some((_, Some(lifetime))), .. + })) => Some(lifetime), + _ => None, + } } struct WrapAwait; impl visit_mut::VisitMut for WrapAwait { fn visit_expr_mut(&mut self, expr: &mut syn::Expr) { - if let syn::Expr::Await(await_) = expr { - let new_expr = wrap_await(await_); - *expr = new_expr; + match expr { + syn::Expr::Await(await_) => *expr = wrap_await(await_), + _ => syn::visit_mut::visit_expr_mut(self, expr), } } } -fn wrap_await(await_: &syn::ExprAwait) -> syn::Expr { - let expr = &await_.base; +fn wrap_await(await_: &mut syn::ExprAwait) -> syn::Expr { + let expr = &mut await_.base; + WrapAwait.visit_expr_mut(expr); assert!( await_.attrs.is_empty(), "#[profile] cannot wrap a function that applies attributes to an .await expression" ); let wrapped = quote::quote! { - { + ({ let future = #expr; profiler::internal::Profiler::pause(&__profiler_scope.0); let result = future.await; profiler::internal::Profiler::resume(&__profiler_scope.0); result - } + }) }; syn::parse2(wrapped).unwrap() } diff --git a/lib/rust/profiler/src/lib.rs b/lib/rust/profiler/src/lib.rs index 7bbc24caef..50fcdd6117 100644 --- a/lib/rust/profiler/src/lib.rs +++ b/lib/rust/profiler/src/lib.rs @@ -167,6 +167,17 @@ use internal::*; +// =============== +// === prelude === +// =============== + +/// Widely-used exports. +pub mod prelude { + pub use crate::profile; +} + + + // ====================== // === MetadataLogger === // ====================== @@ -423,7 +434,7 @@ mod tests { #[profile(Objective)] async fn profiled() -> u32 { let block = async { 4 }; - block.await + block.await + 1 } let future = profiled(); futures::executor::block_on(future); @@ -600,6 +611,45 @@ mod compile_tests { #[profile(Objective)] async fn profiled_async() {} + #[profile(Objective)] + async fn polymorphic_return() -> Box> { + Box::new(23) + } + + #[profile(Objective)] + async fn borrows_input_references_in_output(x: &u32) -> &u32 { + x + } + + #[profile(Objective)] + #[allow(clippy::needless_lifetimes)] + async fn borrows_input_references_in_output_explicitly<'a>(x: &'a u32) -> &'a u32 { + x + } + + #[profile(Objective)] + async fn borrows_input_doesnt_use(_: &u32) -> u32 { + 4 + } + + #[profile(Objective)] + async fn borrows_input_uses(x: &u32) -> u32 { + *x + } + + #[profile(Objective)] + async fn borrows_two_args(x: &u32, y: &u32) -> u32 { + *x + *y + } + + struct Foo(u32); + impl Foo { + #[profile(Objective)] + async fn borrows_self_and_arg(&self, x: &u32) -> u32 { + self.0 + *x + } + } + #[profile(Detail)] #[allow(unsafe_code)] unsafe fn profiled_unsafe() {}