enso-org/enso
1
1
Fork 0
mirror of https://github.com/enso-org/enso.git synced 2024-11-25 21:25:20 +03:00
Code Issues Projects Releases Wiki Activity
wip/farmaazon/fix-integration-test
enso/docs/profiler/engine-startup.md
Dmitry Bushev 53d1f727da
Always create events log when profiling (#8337) 
Changelog:
- update: always create an event log next to the profiling file when the engine is started with the `--profiling-path` flag
- remove: `--profiling-events-log-path` flag
2023-11-20 16:01:25 +00:00

2.0 KiB
Raw Permalink Blame History

Summary

One of the main objectives to deliver satisfactory user experience when using Enso is to be fast when getting ready to work. This requires the engine to initialize all services the IDE needs in proper order and to make sure the essential ones are ready as quickly as possible. In short - to start fast. This document describes how to measure, record and analyze the startup of the Enso engine.

Collecting the data

Via the Project Manager

Start project-manager with following options to record first 20s of the Enso engine startup sequence:

$ project-manager --profiling-path=start.npss --profiling-time=20

Let the IDE connect to just launched project-manager - e.g. start the IDE with --no-backed option. Once the start.log and start.npss files are generated (next to each other), open them in GraalVM's VisualVM:

$ graalvm/bin/jvisualvm --openfile start.npss

Use VisualVM to analyze to recorded data.

Via the runner

Runner executable also supports the profiling with the --profiling-path option. For example, you can run the Enso project with the profiling enabled:

$ enso --profiling-path=/tmp/run.npss --run ~/enso/project/New_Project_1

And then open it in the VisualVM:

$ visualvm --openfile /tmp/run.npss

Interactively Analyze

VisualVM offers two timelines. A "stackdepth" one and also "UI Actions" line. Hovering over boxes in "UI Actions" shows the messages describing what happens in the engine - what has been logged into start.log. One can then select an interval and get profiling information for that interval:

VisualVM

This picture shows that 2.7s is spend in EnsoCompiledJob task. Overall the goal is to log enough information to help us navigate thru the long startup sequence. Select appropriate interval based on the displayed UI Actions - e.g. logged events - and analyze what has happened there based on the sampling of JVM stack traces.