Skip to content

Instrument workspace/runtime startup with StartupTrace#4

Open
vogella wants to merge 2 commits into
masterfrom
startup-trace-instrumentation
Open

Instrument workspace/runtime startup with StartupTrace#4
vogella wants to merge 2 commits into
masterfrom
startup-trace-instrumentation

Conversation

@vogella
Copy link
Copy Markdown
Owner

@vogella vogella commented Apr 21, 2026

Summary

Adds StartupTrace.begin/record spans around the key platform startup paths so local profiling builds can attribute startup cost to individual phases instead of estimating from code inspection.

Instrumented phases

  • Workspace.open (total) with sub-spans for setExplicitWorkspaceEncoding, initializePreferenceLookupOrder, inner startup, notification-manager restart, and crash-recovery refresh.
  • Workspace.startup — an individual span per manager (WorkManager, FileSystemResourceManager, PathVariableManager, NatureManager, FilterTypeManager, BuildManager, NotificationManager, MarkerManager, SaveManager, PropertyManager2, CharsetManager, ContentDescriptionManager, RefreshManager, AliasManager) plus a total span.
  • SaveManager.restore — sub-spans for restoreMasterTable, restoreTree, restoreSnapshots, restoreMarkers, restoreSyncInfo, restoreMetaInfo, and the per-project Project.startup loop.
  • InternalPlatform.start — total + sub-spans for openOSGiTrackers, processCommandLine, initializeDebugFlags, initializeAuthorizationHandler, initializeSSLContext, startServices.
  • openOSGiTrackers — an individual span per each of the 13 ServiceTracker.open calls.

Dependency

Requires org.eclipse.core.internal.runtime.StartupTrace in org.eclipse.equinox.common. See the companion PR in vogella/equinox. Until that bundle is installed into the local target platform, this branch will not compile downstream bundles via -Pbuild-individual-bundles (Tycho's baseline-replace silently substitutes upstream artifacts).

Scope

Local-only tracing build. Not intended for upstream merge.

Test plan

  • Build equinox.common companion PR and install into local target platform (or import via PDE).
  • Launch the IDE, exercise workspace open on a real project set, exit cleanly.
  • Verify ~/.eclipse/startup-trace.csv contains rows from Workspace/SaveManager/InternalPlatform under a single runId.
  • Confirm the stdout top-40 summary lists the instrumented phases.

Copy link
Copy Markdown

@gemini-code-assist gemini-code-assist Bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review

This pull request introduces performance instrumentation using the StartupTrace utility across key initialization and restoration methods in SaveManager, Workspace, and InternalPlatform. The review feedback identifies several opportunities to improve the robustness of this instrumentation, specifically by using try-finally blocks to ensure that trace records are captured even when exceptions occur. Additionally, there is a recommendation to maintain consistent naming conventions for trace identifiers in InternalPlatform to match the patterns used in other components.

Comment on lines +2388 to +2394
StartupTrace.record("Workspace.open/crashRecoveryRefresh", tRefresh); //$NON-NLS-1$
StartupTrace.record("Workspace.open", tOpen); //$NON-NLS-1$
//don't fail entire open if refresh failed, just report as warning
return new ResourceStatus(IResourceStatus.INTERNAL_ERROR, IPath.ROOT,
Messages.resources_errorMultiRefresh, e);
}
StartupTrace.record("Workspace.open/crashRecoveryRefresh", tRefresh); //$NON-NLS-1$
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

medium

The recording of the Workspace.open and Workspace.open/crashRecoveryRefresh spans is inconsistent and contains duplication.

  1. tOpen is recorded manually in the RuntimeException catch block (line 2389) and at the end of the method (line 2399), but it is missed if a CoreException is thrown earlier (e.g., during startup() at line 2376).
  2. tRefresh is recorded twice: once in the catch block (line 2388) and once after the try block (line 2394).

Consider wrapping the method body in a try-finally block for tOpen, and using a try-finally for the refresh logic. This ensures all spans are recorded regardless of how the method exits, matching the robust pattern used in SaveManager.restore() and Workspace.startup().

Comment on lines +708 to +732
long tStart = StartupTrace.begin();
this.context = runtimeContext;
this.fwkWiring = runtimeContext.getBundle(Constants.SYSTEM_BUNDLE_LOCATION).adapt(FrameworkWiring.class);
long tTrackers = StartupTrace.begin();
openOSGiTrackers();
StartupTrace.record("InternalPlatform.start/openOSGiTrackers", tTrackers); //$NON-NLS-1$
splashEnded = false;
long tCmdLine = StartupTrace.begin();
processCommandLine(getEnvironmentInfoService().getNonFrameworkArgs());
StartupTrace.record("InternalPlatform.start/processCommandLine", tCmdLine); //$NON-NLS-1$
long tDebug = StartupTrace.begin();
initializeDebugFlags();
StartupTrace.record("InternalPlatform.start/initializeDebugFlags", tDebug); //$NON-NLS-1$
initialized = true;
stopped = false;
long tAuth = StartupTrace.begin();
initializeAuthorizationHandler();
StartupTrace.record("InternalPlatform.start/initializeAuthorizationHandler", tAuth); //$NON-NLS-1$
long tSsl = StartupTrace.begin();
initializeSSLContext();
StartupTrace.record("InternalPlatform.start/initializeSSLContext", tSsl); //$NON-NLS-1$
long tSvc = StartupTrace.begin();
startServices();
StartupTrace.record("InternalPlatform.start/startServices", tSvc); //$NON-NLS-1$
StartupTrace.record("InternalPlatform.start", tStart); //$NON-NLS-1$
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

medium

The InternalPlatform.start span is only recorded at the very end of the method. If an unchecked exception occurs during startup, the trace will be lost. For better reliability in profiling, consider wrapping the method body in a try-finally block to ensure StartupTrace.record is always called, consistent with the implementation in SaveManager.restore().

Comment on lines 749 to 790
private void openOSGiTrackers() {
long t;
t = StartupTrace.begin();
instanceLocation = createOpenTracker(Location.INSTANCE_FILTER);
StartupTrace.record("openOSGiTrackers/instanceLocation", t); //$NON-NLS-1$
t = StartupTrace.begin();
userLocation = createOpenTracker(Location.USER_FILTER);
StartupTrace.record("openOSGiTrackers/userLocation", t); //$NON-NLS-1$
t = StartupTrace.begin();
configurationLocation = createOpenTracker(Location.CONFIGURATION_FILTER);
StartupTrace.record("openOSGiTrackers/configurationLocation", t); //$NON-NLS-1$
t = StartupTrace.begin();
installLocation = createOpenTracker(Location.INSTALL_FILTER);
StartupTrace.record("openOSGiTrackers/installLocation", t); //$NON-NLS-1$
t = StartupTrace.begin();
logTracker = createOpenTracker(FrameworkLog.class);
StartupTrace.record("openOSGiTrackers/FrameworkLog", t); //$NON-NLS-1$
t = StartupTrace.begin();
platformTracker = createOpenTracker(PlatformAdmin.class);
StartupTrace.record("openOSGiTrackers/PlatformAdmin", t); //$NON-NLS-1$
t = StartupTrace.begin();
contentTracker = createOpenTracker(IContentTypeManager.class);
StartupTrace.record("openOSGiTrackers/IContentTypeManager", t); //$NON-NLS-1$
t = StartupTrace.begin();
preferencesTracker = createOpenTracker(IPreferencesService.class);
StartupTrace.record("openOSGiTrackers/IPreferencesService", t); //$NON-NLS-1$
t = StartupTrace.begin();
groupProviderTracker = createOpenTracker("(objectClass=" + IBundleGroupProvider.class.getName() + ")"); //$NON-NLS-1$ //$NON-NLS-2$
StartupTrace.record("openOSGiTrackers/IBundleGroupProvider", t); //$NON-NLS-1$
t = StartupTrace.begin();
logReaderTracker = createOpenTracker(ExtendedLogReaderService.class);
StartupTrace.record("openOSGiTrackers/ExtendedLogReaderService", t); //$NON-NLS-1$
t = StartupTrace.begin();
extendedLogTracker = createOpenTracker(ExtendedLogService.class);
StartupTrace.record("openOSGiTrackers/ExtendedLogService", t); //$NON-NLS-1$
t = StartupTrace.begin();
environmentTracker = createOpenTracker(EnvironmentInfo.class);
StartupTrace.record("openOSGiTrackers/EnvironmentInfo", t); //$NON-NLS-1$
t = StartupTrace.begin();
debugTracker = createOpenTracker(DebugOptions.class);
StartupTrace.record("openOSGiTrackers/DebugOptions", t); //$NON-NLS-1$
}
Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

medium

The trace names in openOSGiTrackers are missing the InternalPlatform. class prefix. This is inconsistent with the naming convention used in other instrumented areas like Workspace.startup/... and SaveManager.restore/.... Adding the prefix will make the trace logs more consistent and easier to aggregate.

	private void openOSGiTrackers() {
		long t;
		t = StartupTrace.begin();
		instanceLocation = createOpenTracker(Location.INSTANCE_FILTER);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/instanceLocation", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		userLocation = createOpenTracker(Location.USER_FILTER);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/userLocation", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		configurationLocation = createOpenTracker(Location.CONFIGURATION_FILTER);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/configurationLocation", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		installLocation = createOpenTracker(Location.INSTALL_FILTER);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/installLocation", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		logTracker = createOpenTracker(FrameworkLog.class);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/FrameworkLog", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		platformTracker = createOpenTracker(PlatformAdmin.class);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/PlatformAdmin", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		contentTracker = createOpenTracker(IContentTypeManager.class);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/IContentTypeManager", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		preferencesTracker = createOpenTracker(IPreferencesService.class);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/IPreferencesService", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		groupProviderTracker = createOpenTracker("(objectClass=" + IBundleGroupProvider.class.getName() + ")"); //$NON-NLS-1$ //$NON-NLS-2$
		StartupTrace.record("InternalPlatform.openOSGiTrackers/IBundleGroupProvider", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		logReaderTracker = createOpenTracker(ExtendedLogReaderService.class);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/ExtendedLogReaderService", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		extendedLogTracker = createOpenTracker(ExtendedLogService.class);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/ExtendedLogService", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		environmentTracker = createOpenTracker(EnvironmentInfo.class);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/EnvironmentInfo", t); //$NON-NLS-1$
		t = StartupTrace.begin();
		debugTracker = createOpenTracker(DebugOptions.class);
		StartupTrace.record("InternalPlatform.openOSGiTrackers/DebugOptions", t); //$NON-NLS-1$
	}

@vogella vogella force-pushed the startup-trace-instrumentation branch from 669bc7f to 300881a Compare April 21, 2026 17:32
vogella added a commit to vogella/eclipse.platform.ui that referenced this pull request Apr 21, 2026
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.
The class Javadoc claimed "There are currently five different types of
resource change events" but the bullet list immediately below it
enumerates six (PRE_BUILD, POST_BUILD, POST_CHANGE, PRE_CLOSE, PRE_DELETE,
PRE_REFRESH). The count drifted when PRE_REFRESH was added and would
drift again whenever a new type is introduced, so replace the count with
"The following types of resource change events are reported:".
vogella added a commit to vogella/eclipse.platform.ui that referenced this pull request May 18, 2026
Two complementary tracers, both writing CSV summaries on JVM shutdown,
so we can measure where Workbench startup and renderer execution
actually spend time.

StartupTrace (opt-in via -Declipse.startup.trace=true), reuses the
shared StartupTrace from org.eclipse.core.internal.runtime so workbench
and platform bundles share one ~/.eclipse/startup-trace.csv and one
RUN_ID. Instrumentation points cover Workbench.init phases, E4
application bootstrap, ResourceHandler, ModelAssembler,
IDEApplication.start, and the first-touch of context functions in
WorkbenchPlugin (PerspectiveRegistry, ViewRegistry, ActionSetRegistry,
IntroRegistry, PreferenceManager, ThemeRegistry, WorkingSetManager,
WorkingSetRegistry, EditorRegistry). With the property unset the cost
is one static-final boolean read per call site.

RendererPerfTracer is always active in this debug build and writes to
~/renderer-perf-trace.csv (configurable via
-Declipse.renderer.perf.trace.file=<path>). It covers 14 hotspots
across AreaRenderer, MenuManagerRenderer, MenuManagerRendererFilter,
PerspectiveStackRenderer, SashRenderer, StackRenderer,
ToolBarManagerRenderer, ToolControlRenderer, ToolItemUpdater, and
WBWRenderer, with a persistent writer, shutdown hook, and daemon
flusher. The H10 showTab probe is split into separate lazy-create and
reparent paths.

docs/performance.md documents both tracers, the captured trace
sessions, and the analysis approach.

Not intended for upstream merge; depends on
vogella/eclipse.platform#4 for org.eclipse.core.internal.runtime.StartupTrace.
vogella added a commit to vogella/eclipse.platform.ui that referenced this pull request May 18, 2026
Three layers of tracing emit CSV summaries on JVM shutdown, so we can
measure where Workbench startup, renderer execution, and runtime UI
events actually spend time.

StartupTrace (opt-in via -Declipse.startup.trace=true) reuses the
shared StartupTrace from org.eclipse.core.internal.runtime so workbench
and platform bundles share one ~/.eclipse/startup-trace.csv and one
runId. Instrumentation points cover Workbench.init phases, E4
application bootstrap, ResourceHandler, ModelAssembler,
IDEApplication.start, and the first-touch of context functions in
WorkbenchPlugin (PerspectiveRegistry, ViewRegistry, ActionSetRegistry,
IntroRegistry, PreferenceManager, ThemeRegistry, WorkingSetManager,
WorkingSetRegistry, EditorRegistry). With the property unset the cost
is one static-final boolean read per call site.

The same StartupTrace channel also captures runtime UI hotspots:
- DisplayEventProbe installs SWT.PreEvent/SWT.PostEvent listeners on
  the workbench Display and records any event whose dispatch exceeds
  16 ms, keyed by SWT event type (Paint, Selection, MouseDown, etc.).
- WorkbenchLabelProvider.getText/getImage are bracketed so cumulative
  label-provider cost shows up per viewer refresh.
- AbstractCSSEngine.applyStyles records the outermost call (depth
  counter avoids inflating the CSV with every recursive child).

RendererPerfTracer is always active in this debug build and writes to
~/renderer-perf-trace.csv (configurable via
-Declipse.renderer.perf.trace.file=<path>). It covers 14 hotspots
across AreaRenderer, MenuManagerRenderer, MenuManagerRendererFilter,
PerspectiveStackRenderer, SashRenderer, StackRenderer,
ToolBarManagerRenderer, ToolControlRenderer, ToolItemUpdater, and
WBWRenderer, with a persistent writer, shutdown hook, and daemon
flusher. The H10 showTab probe is split into separate lazy-create and
reparent paths.

docs/performance.md documents both tracers, the captured trace
sessions, and the analysis approach.

Not intended for upstream merge; depends on vogella/eclipse.platform#4
for org.eclipse.core.internal.runtime.StartupTrace.
@vogella vogella force-pushed the startup-trace-instrumentation branch 2 times, most recently from cc60b7f to de2afcd Compare May 18, 2026 14:36
Adds org.eclipse.core.internal.runtime.StartupTrace, a java-only,
always-on span recorder that drains buffered entries to
~/.eclipse/startup-trace.csv on a 2-second periodic daemon, on explicit
flush() calls, and on a JVM shutdown hook. Prints a diagnostic line on
every successful write and a top-40 cumulative-time summary at shutdown.
Single shared queue and runId across every caller, so contributions from
any bundle that Require-Bundles core.runtime land in one CSV per run.

The class lives in core.runtime rather than equinox.common so that its
inclusion in the built jar is not defeated by Tycho baseline-replace.

The CSV is truncated and rewritten on the first flush of each JVM, so
every Eclipse startup produces a fresh single-run file. The trace also
freezes when StartupTrace.mark(END_OF_STARTUP_MARK) is recorded: the
periodic daemon is stopped, the queue is drained one last time, and all
further begin/record/mark calls become no-ops. The eclipse.platform.ui
follow-up emits this checkpoint once control returns to the SWT event
loop, so the CSV contains only startup activity, not steady-state.

When the CSV is first written, an AI analysis prompt is emitted above
the column header (each line prefixed with '# ' so the body is still
filterable as 'grep -v ^# startup-trace.csv'). The prompt instructs a
large-context model (e.g. Gemini) to fold the raw rows into a per-run
Markdown summary suitable as input for a second AI doing bottleneck
analysis: top phases, hot leaves, parent-vs-children gaps, outliers,
and cross-run variance. Lets the file be copy-pasted directly into the
AI engine without any extra context.

API:
 - StartupTrace.begin() / record(name, t0) for timed spans
 - StartupTrace.mark(name) for zero-duration checkpoints
 - StartupTrace.END_OF_STARTUP_MARK sentinel: passing this name to
   mark() freezes the trace

Instrumented call sites:

 - InternalPlatform.start with sub-spans for openOSGiTrackers (one per
   ServiceTracker.open), processCommandLine, initializeDebugFlags,
   initializeAuthorizationHandler, initializeSSLContext (TrustManager
   init, KeyManager init, SSLContext.getDefault), startServices.
 - ResourcesPlugin.start (total) with sub-spans for super.start,
   registerDebugOptions, openInstanceLocationTracker. The tracker span
   is further sub-divided into open instance Location, new Workspace,
   and register workspace with platform.
 - Workspace.open with sub-spans for setExplicitWorkspaceEncoding,
   initializePreferenceLookupOrder, inner startup, notification-manager
   restart, and crash-recovery refresh.
 - Workspace.startup: individual span per manager (WorkManager,
   FileSystemResourceManager, PathVariableManager, NatureManager,
   FilterTypeManager, BuildManager, NotificationManager, MarkerManager,
   SaveManager, PropertyManager2, CharsetManager,
   ContentDescriptionManager, RefreshManager, AliasManager).
 - SaveManager.restore with sub-spans for restoreMasterTable,
   restoreTree (open DataInputStream, readTree), restoreSnapshots,
   restoreMarkers (readSnapshot, per-project readDelta loop),
   restoreSyncInfo, restoreMetaInfo (per-project loadMetaInfo loop),
   and the per-project Project.startup loop.

Local-only; not intended for upstream merge.
@vogella vogella force-pushed the startup-trace-instrumentation branch from de2afcd to dade073 Compare May 18, 2026 14:53
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant