Tracing Eclipse components. This article describes how to trace and perform performance analysis on Eclipse plug-ins and RCP applications.
1. Eclipse Performance
This article gives pointers how to analyze Eclipse performance issues.
One of the things not covered in detail is the creation of performance traces via the PerformanceStats class.
See Gathering performance statistics for more details.
2. Monitoring the interactive UI performance with the UI freeze monitor
The Eclipse IDE includes an interactive UI performance measurement feature.
You can activate this tracing via

If activated, a stack trace is written to the Error view, in case a UI freeze occurs.

You should report such freezes to https://bugs.eclipse.org/ to that the team can fix these.
3. Yourkit
3.1. What is Yourkit?
Yourkit is a commercial tool for performance tracing and analysis. You require a license to use it but Yourkit offers free licencses to Open Source projects.
To install Yourkit, you need to download if from Yourkit download. Depending your platform you can the installer (Windows) or extract the compressed archive to your system.
On Linux extract it to a folder of your choice. In this folder you find the script bin/profiler.sh to start Yourkit. The Yourkit tooling starts and ask you for the license key and with which IDE it should integrate.
3.2. Using Yourkit to trace Eclipse
To trace IDE tools like Eclipse you need to remove the filter flag.

Also remove the filter for Eclipse packages.

3.3. Using Yourkit from the IDE
To use Yourkit from Eclipse you need to install the Yourkit plug-ins. A description can be found here: https://www.yourkit.com/docs/java/help/complete_eclipse35.jsp
Afterwards, you have a new launch configuration available in Eclipse.

To trace for example the startup time of Eclipse, enable the Trace option and start Eclipse.

3.4. Stopping and starting a trace
To stop a trace and to create a snapshot that can be analyzed press the save button.

To start tracing again use start button.

3.5. Reading the performance trace
Once you created and open a performance trace you typically want to find the bottleneck or see the improved runtime of your changed code.
To see bottleneck for a certain thread, open the Call tree - By thread, you may have to click the Calculate button in the bottom part. Select your thread, and sort the methods by Own time. Try to find things that are slow and in your responsibility.

If you are looking for an improvement in a certain method, you can use the Filter button to find this method.

4. Using the build-in tracing facilities of Eclipse
4.1. Using tracing for your IDE
Eclipse provides a tracing facility that can be activated on demand. If activated, additional plug-in informations are written to the console at runtime.
You activate tracing via the -debug start parameter.
Eclipse looks now, by default, for a file called .options in the Eclipse install directory.
The file must contain one key=value pair per line.
If the plug-in prepared that you can see the tracing option in the preference settings. It is possible to active these tracing options at runtime. The Eclipse IDE preferences as depicted in the following screenshot.

These tracing options are available for a launch configuration.
4.2. Example: Tracing the startup time of plug-ins
In this example, you will trace the start time of each plug-in during startup.
For this, create a .options in your Eclipse installation directory with the following content.
# turn on debugging for the org.eclipse.core plugin.
org.eclipse.osgi/debug=true
# turn on execution time of the activator for the plug-ins
org.eclipse.osgi/debug/bundleTime=true
# turn on total execution time of the plug-ins
org.eclipse.osgi/debug/bundleStartTime=true
Start Eclipse via the following command line.
./eclipse -debug
|
You can specify the location of the options file as a URL or a file-system path after the -debug argument. |
In this example, the Starting application timestamp describes when OSGi is done with its initialization. The Application Started tells you when the application has been started. Afterwards, you can extract the information which interest you the most. For the above example, the following is a small shell script this extracts the time of the activator of each bundle . It sorts the bundles by this time.
# start Eclipse with at test workspace while piping the output into a file
./eclipse -debug -data ~/test > trace.txt
# get total start time
echo "Total startup time" > tracefinal.txt
grep "for total start time" trace.txt | awk '{print $1 " " $13}' |sort -nr >> tracefinal.txt
echo "" >> tracefinal.txt
echo "Activator times" >> tracefinal.txt
# extract the activation time
grep "to load and start the activator" trace.txt |awk '{print $1 " " $10}'| sort -nr >> tracefinal.txt
4.2.1. Example: Tracing the resource plug-in
The following is another example for an .option file in which you trace the resources.
# turn on debugging for the org.eclipse.core.resources plugin.
org.eclipse.core.resources/debug=true
# monitor builders and gather time statistics etc.
org.eclipse.core.resources/perf/builders=10000
# monitor resource change listeners and gather time statistics etc.
org.eclipse.core.resources/perf/listeners=500
# monitor workspace snapshot and gather time statistics etc.
org.eclipse.core.resources/perf/snapshot=1000
# monitor workspace snapshot and gather time statistics etc.
org.eclipse.core.resources/perf/save.participants=500
# debug build failure cases such as failure to retrieve deltas.
org.eclipse.core.resources/build/failure=true
# reports the cause of autobuild interruption
org.eclipse.core.resources/build/interrupt=true
# reports the start and end of all builder invocations
org.eclipse.core.resources/build/invoking=true
# reports the start and end of build delta calculations
org.eclipse.core.resources/build/delta=true
# for incremental builds, displays which builder is being run
# and because of changes in which project.
org.eclipse.core.resources/build/needbuild=true
# prints a stack trace every time an operation finishes that requires a
build
org.eclipse.core.resources/build/needbuildstack=true
# prints a stack trace every time a build API method is called
org.eclipse.core.resources/build/stacktrace=false
# report debug of workspace auto-refresh
org.eclipse.core.resources/refresh=true
4.2.2. Implement tracing for your plug-in
Can you implement tracing for your custom plug-in, see
Using Eclipse Tracing API. To add your tracing options to the preference page, to allow users to turn them on at run time, use
extension point the org.eclipse.ui.trace.traceComponents.
See TracingPreferencePage for the implementation of this.
4.2.3. Example: Tracing for key bindings
The tracing functionality of Eclipse allows to you trace which command is associated with a certain key binding. The following listing contains the trace options to enable that.
# turn on debugging for the org.eclipse.core.resources plugin.
org.eclipse.ui/debug=true
org.eclipse.ui/trace/keyBindings
org.eclipse.ui/trace/keyBindings.verbose
5. Finding UI freezes by sampling thread dumps
5.1. Why one thread dump is not enough
If the IDE freezes, the obvious reaction is to take a single thread dump with jstack or jcmd and read the main thread, which is the UI thread.
That tells you what the UI thread was doing at one instant, and nothing about how long it stayed there.
A frame that looks alarming may be a fast call you happened to catch, and the real cost may sit in a caller that appears in every dump.
Taking many dumps in a row solves this. If the same call appears in twenty consecutive samples, it is the freeze. If it appears once, it is noise. This is the poor man’s profiler, and for a freeze that lasts seconds it is as good as a real profiler while needing nothing but a JDK.
Reading the leaf frames tells you which kind of problem you have.
Leaf frames that keep changing while a caller stays put mean the code is grinding through work, for example resolving a target platform.
A leaf frame that never changes means the thread is blocked, and the - locked lines in the dump tell you on which monitors.
5.2. Prerequisites
You need jcmd from a JDK, which the JVM that runs your IDE already provides.
If jcmd is not on the PATH, use the absolute path to the JVM named by the -vm entry in your eclipse.ini.
The scripts below assume exactly one running Eclipse, so that the process id is unambiguous.
|
Do not paste multi-line PowerShell blocks into the console. A blank line inside an open block ends the input early and the remaining lines produce syntax errors. Save the scripts to a file and run the file. |
5.3. Sampling a full IDE startup
The following script starts Eclipse, samples the main thread while it comes up, writes every dump to a file and prints a summary.
Save it as profile-eclipse-startup.ps1.
param(
[Parameter(Mandatory=$true)][string]$EclipseExe,
[string]$Data,
[int]$DurationSec = 20,
[int]$IntervalMs = 500,
[string]$Out = (Join-Path $PWD 'eclipse-startup-stacks.txt')
)
if (Get-Process eclipse -ErrorAction SilentlyContinue) {
throw "An eclipse process is already running, close it first"
}
$outDir = Split-Path -Parent $Out
if ($outDir -and -not (Test-Path $outDir)) {
New-Item -ItemType Directory -Path $outDir -Force | Out-Null
}
Write-Host "Writing stacks to $Out"
$launchArgs = @()
if ($Data) { $launchArgs += @('-data', $Data) }
Remove-Item $Out -ErrorAction SilentlyContinue
$proc = if ($launchArgs.Count) {
Start-Process -FilePath $EclipseExe -ArgumentList $launchArgs -PassThru
} else {
Start-Process -FilePath $EclipseExe -PassThru
}
$epid = $proc.Id
Write-Host "Started PID $epid, sampling for $DurationSec s every $IntervalMs ms"
$sw = [System.Diagnostics.Stopwatch]::StartNew()
$n = 0
$captured = 0
while ($sw.Elapsed.TotalSeconds -lt $DurationSec) {
if ($proc.HasExited) { Write-Warning "eclipse exited after $([int]$sw.Elapsed.TotalSeconds) s"; break }
$n++
$dump = & jcmd $epid Thread.print 2>&1
if ($LASTEXITCODE -eq 0) {
$captured++
"===== sample $n t=$([int]$sw.Elapsed.TotalMilliseconds)ms =====" | Add-Content $Out -Encoding utf8
$dump | Add-Content $Out -Encoding utf8
}
Start-Sleep -Milliseconds $IntervalMs
}
Write-Host "$captured of $n attach attempts succeeded"
if ($captured -eq 0) {
Write-Warning "Could not attach. Check whether the JVM runs in a separate process: Get-Process java,javaw"
return
}
$lines = Get-Content $Out
$stacks = @(); $cur = $null; $curLabel = $null
foreach ($l in $lines) {
if ($l -like '===== sample*') { $curLabel = ($l -replace '=','').Trim(); continue }
if ($l -like '"main"*') { $cur = [System.Collections.ArrayList]::new(); continue }
if ($null -ne $cur) {
if ($l.Trim() -eq '') {
$stacks += [pscustomobject]@{ Label = $curLabel; Frames = $cur }
$cur = $null
continue
}
[void]$cur.Add($l.Trim())
}
}
Write-Host ""
Write-Host "$($stacks.Count) samples of the main thread"
$inResolve = @($stacks | Where-Object { $_.Frames -match 'PluginModelManager\.initializeTable' }).Count
Write-Host "$inResolve of them inside PluginModelManager.initializeTable"
Write-Host ""
Write-Host "Timeline:"
foreach ($s in $stacks) {
$f = $s.Frames | Where-Object {
$_ -match 'org\.eclipse\.pde|org\.eclipse\.ui\.part|org\.eclipse\.ui\.internal'
} | Select-Object -First 1
if (-not $f -and $s.Frames.Count -gt 1) { $f = $s.Frames[1] }
"{0,-26} {1}" -f $s.Label, $f
}
Write-Host ""
Write-Host "Most frequent triggering frame:"
$stacks | ForEach-Object {
$f = $_.Frames | Where-Object {
$_ -match 'org\.eclipse\.pde\.internal\.ui|org\.eclipse\.ui\.part'
} | Select-Object -First 1
if ($f) { $f } else { '(no PDE UI frame)' }
} | Group-Object | Sort-Object Count -Descending | Format-Table Count, Name -AutoSize
Write-Host "Hottest leaf frames:"
$stacks | Where-Object { $_.Frames.Count -gt 1 } | ForEach-Object { $_.Frames[1] } |
Group-Object | Sort-Object Count -Descending | Select-Object -First 15 |
Format-Table Count, Name -AutoSize
Run it with the installation and the workspace you want to investigate.
powershell -ExecutionPolicy Bypass -File .\profile-eclipse-startup.ps1 `
-EclipseExe "C:\eclipse\eclipse.exe" -Data "C:\ws\my-workspace"
The script accepts -DurationSec and -IntervalMs to widen or tighten the window, -ProcessId if you must attach to an IDE it did not start itself, and -Out to place the dump file somewhere other than the current directory.
It prints three things. The timeline shows one line per sample with the elapsed time and the most interesting frame, which is where you see a block as a run of identical lines. The triggering frame table counts which UI code led into the expensive work. The leaf frame table shows where the time was actually burned.
5.4. Reading the full stack of a sample
The summary deliberately prints one frame per sample so that the timeline stays readable.
Once you know which sample interests you, this second script prints its complete main stack.
Save it as show-blocking-stack.ps1.
param(
[string]$File = (Join-Path $PWD 'eclipse-startup-stacks.txt'),
[string]$Match = 'AbstractBundleContainer\.resolve',
[int]$Count = 1
)
if (-not (Test-Path $File)) { throw "No such file: $File" }
$lines = Get-Content $File
$stacks = @(); $cur = $null; $lbl = $null
foreach ($l in $lines) {
if ($l -like '===== sample*') { $lbl = ($l -replace '=','').Trim(); continue }
if ($l -like '"main"*') { $cur = [System.Collections.ArrayList]::new(); continue }
if ($null -ne $cur) {
if ($l.Trim() -eq '') {
$stacks += [pscustomobject]@{ Label = $lbl; Frames = $cur }
$cur = $null
continue
}
[void]$cur.Add($l.Trim())
}
}
$hits = @($stacks | Where-Object { $_.Frames -match $Match })
Write-Host "$($hits.Count) of $($stacks.Count) samples match '$Match'"
foreach ($s in ($hits | Select-Object -First $Count)) {
Write-Host ""
Write-Host "----- $($s.Label) -----"
$s.Frames
}
By default it prints the first sample whose stack matches a regular expression.
powershell -ExecutionPolicy Bypass -File .\show-blocking-stack.ps1
# filter for a specific caller instead
.\show-blocking-stack.ps1 -Match 'PDELabelProvider\.getObjectText'
# print two samples, to check the stack is stable rather than progressing
.\show-blocking-stack.ps1 -Count 2
It reports how many samples matched before printing, so a count of zero tells you the filter missed rather than leaving you with an empty result.
5.5. Example: an eight second freeze during startup
Sampling an IDE startup every 500 ms produced this timeline.
sample 15 t11544ms at org.eclipse.ui.internal.e4.compatibility.CompatibilityPart.createPartControl
sample 16 t12308ms at org.eclipse.pde.internal.ui.editor.PDEProjectionViewer.<init>
sample 17 t13147ms at org.eclipse.pde.internal.core.target.AbstractBundleContainer.resolve
sample 18 t13984ms at org.eclipse.pde.internal.core.target.AbstractBundleContainer.resolve
sample 19 t14805ms at org.eclipse.pde.internal.core.target.AbstractBundleContainer.resolve
...
sample 26 t20495ms at org.eclipse.pde.internal.core.ExternalFeatureModelManager.createModel
sample 27 t21317ms at org.eclipse.ui.internal.Workbench.lambda$3
Ten consecutive samples in target platform resolution, roughly eight seconds of frozen UI, and the triggering frame table attributed all of them to a single method. The full stack of sample 17 showed the whole chain: a Category Definition editor restored from the previous session set the input of its tree viewer, the label provider was asked for the text of a feature entry, and answering that required resolving the target platform.
This is worth stating as a rule. A label provider is called on the UI thread for every visible row, so it must never ask a question whose answer can require resolving the target platform. The sampling approach is what turns a vague "the IDE hangs on startup" into that one-sentence diagnosis.
|
On Linux and macOS the same technique is a shell loop.
|
6. Eclipse tracing and performance tools resources
6.1. vogella Java example code
If you need more assistance we offer Online Training and Onsite training as well as consulting