Add opt-in StartupTrace to measure Workbench startup bottlenecks#15
Add opt-in StartupTrace to measure Workbench startup bottlenecks#15
Conversation
There was a problem hiding this comment.
Code Review
This pull request introduces a StartupTrace utility to measure and record the duration of various Eclipse workbench initialization phases. It instruments several key registries and services, such as Workbench, ActionSetRegistry, and ViewRegistry, to capture performance data that is dumped to a CSV file upon JVM shutdown. The review feedback suggests adding a null check for the user.home system property to prevent a potential NullPointerException and improving the CSV escaping logic to correctly handle carriage return characters.
| return; | ||
| } | ||
| try { | ||
| Path dir = Path.of(System.getProperty("user.home"), ".eclipse"); //$NON-NLS-1$ //$NON-NLS-2$ |
There was a problem hiding this comment.
The user.home system property is not guaranteed to be non-null in all environments. If it is null, Path.of(null, ".eclipse") will throw a NullPointerException. It is safer to check for null before proceeding.
| Path dir = Path.of(System.getProperty("user.home"), ".eclipse"); //$NON-NLS-1$ //$NON-NLS-2$ | |
| String userHome = System.getProperty("user.home"); //$NON-NLS-1$ | |
| if (userHome == null) { | |
| return; | |
| } | |
| Path dir = Path.of(userHome, ".eclipse"); //$NON-NLS-1$ |
| if (s == null) { | ||
| return ""; //$NON-NLS-1$ | ||
| } | ||
| if (s.indexOf(',') < 0 && s.indexOf('"') < 0 && s.indexOf('\n') < 0) { |
There was a problem hiding this comment.
The CSV escaping logic should also check for the carriage return character (\r). If a string contains \r but none of the other trigger characters, it will be returned unquoted, which can break the CSV structure in many parsers.
| if (s.indexOf(',') < 0 && s.indexOf('"') < 0 && s.indexOf('\n') < 0) { | |
| if (s.indexOf(',') < 0 && s.indexOf('"') < 0 && s.indexOf('\n') < 0 && s.indexOf('\r') < 0) { |
9cb744a to
80ad9db
Compare
Local-only instrumentation. Enabled via -Declipse.startup.trace=true; no-op otherwise. On JVM shutdown, appends per-phase timings to ~/.eclipse/startup-trace.csv and prints a sorted cumulative-time summary. Instruments Workbench.init() phases, WorkbenchImages.initializeImageRegistry, each ContextFunction.compute first-touch in WorkbenchPlugin.initializeContext (Perspective/View/ActionSet/Intro/Preference/Theme/WorkingSet/Editor), and registry work in ViewRegistry/PerspectiveRegistry/EditorRegistry/ ActionSetRegistry, so the startup critical path can be measured rather than guessed at.
80ad9db to
6eaa1a7
Compare
Delete the local copy at org.eclipse.e4.ui.internal.workbench.StartupTrace and switch all call sites to the platform-provided class introduced by vogella/eclipse.platform#4, so workbench and platform bundles share one run file and one RUN_ID in ~/.eclipse/startup-trace.csv. Each affected bundle already Require-Bundles org.eclipse.core.runtime, so no MANIFEST changes are needed. Discouraged-access is set to warning in the workbench bundles, so no @SuppressWarnings is required either.
Local-only instrumentation, no behavior change. ResourceHandler.loadMostRecentModel is split into five spans (applicationXMI URI resolution, persisted-state load, default model XMI load, plus fragments.process and processor.process inside ModelAssembler.processModel) so the 159 ms total can be attributed to either the XML parse, the fragment extensions, or the processor extensions. E4Application.createDefaultContext is split into root-context creation, core service registration, UI service registration, and an aggregate ContextInjectionFactory.make span with a count suffix so the per-call cost can be estimated. E4Application 'create addons' exposes the extension-registry lookup and the instantiation loop (with a count suffix) separately. Workbench.runUI emits a zero-duration 'startup.complete (marker)' via the new StartupTrace.mark, right before the event loop begins, so true startup wall-time can be computed without the event-loop idle interval that dominates the existing outer total. Same call site also schedules an optional graceful close via -Dstartup.trace.autoExitSeconds=N, enabling unattended batch collection of startup traces (no manual File -> Exit per run).
…ge-deltas
createDefaultContext:
Replace the overall "createDefaultContext/ContextInjectionFactory.make
(count=4)" span (which overlapped its own siblings) with two narrower
spans that wrap only the make() calls inside each parent block:
createDefaultContext/register core services/ContextInjectionFactory.make (count=N)
createDefaultContext/register UI services/ContextInjectionFactory.make (count=N)
The ThreadLocal accumulator is removed in favor of local per-block
counters, keeping a clean parent/child tree with no sibling overlap.
ResourceHandler.loadMostRecentModel:
Sub-divide "merge deltas (if persisted state exists)" into:
handler.loadMostRecentModel/merge deltas/load delta resource
handler.loadMostRecentModel/merge deltas/apply delta (count=N)
loadResource gains an optional phase-prefix parameter; the default
(non-delta) load path passes null and emits no sub-spans.
Adds spans around the pre-workbench phases of IDEApplication.start to show where the 107 ms between Workbench.createDisplay end and ResourcesPlugin.start activation goes: IDEApplication.start (total) IDEApplication.start/initializeProduct IDEApplication.start/checkInstanceLocation IDEApplication.start/promptForWorkspace (only when dialog shown) No behavior change. The already-instrumented createDisplay and createAndRunWorkbench paths are not re-wrapped.
Summary
Adds a small, opt-in startup tracer so we can measure actual bottlenecks in Workbench startup instead of estimating them from code inspection.
org.eclipse.ui.internal.misc.StartupTrace(no-op unless-Declipse.startup.trace=true).~/.eclipse/startup-trace.csv(new file gets a header; subsequent runs append with a distinctrunId) and prints a sorted top-40 cumulative-time summary to stdout.Workbench.init()phases (JFace prefs, EvaluationService, lazy services, activity helper, firstWorkbenchImagestouch, E4 services, intro lookup, default services, fonts, application colors, advisor init, single-click, globalization, NL extensions, image registry init, ShowKeysListener, preStartup, openWindows, restoreWorkbenchState, and overall totals).WorkbenchImages.initializeImageRegistry+ innerdeclareImages.ContextFunction.computefirst-touch inWorkbenchPlugin.initializeContextforPerspectiveRegistry,ViewRegistry,ActionSetRegistry,IntroRegistry,PreferenceManager,ThemeRegistry,WorkingSetManager,WorkingSetRegistry,EditorRegistry.ViewRegistry.postConstructwith sub-spans for pass 1 (categories/sticky) and pass 2 (views) so the double-iteration claim can be quantified.PerspectiveRegistry.postConstruct(read extensions, scan snippets, import/export handler).EditorRegistry.initializeFromStorage(registry read, sort+rebuild).ActionSetRegistry.readFromRegistry(action sets, part associations).The tracer uses only
java.*APIs and is fully gated by aBoolean.getBooleancheck, so with the property unset the cost is one static final boolean read per call site.Usage
Launch Eclipse with:
Exit Eclipse normally so the JVM shutdown hook runs. Data lands at
~/.eclipse/startup-trace.csv, and a summary prints to stdout.Notes
Workbench.init: preserved the original short-circuit ofisClosing() || !advisor.openWindows()soopenWindows()is not invoked when already closing.Test plan
-Pbuild-individual-bundles—mvn clean compile -pl :org.eclipse.ui.workbench -Pbuild-individual-bundles(verified locally).[StartupTrace]output and no CSV file is produced.-Declipse.startup.trace=true; exit; verify~/.eclipse/startup-trace.csvis written and the sorted summary prints to stdout.runId.