EclipseCon 2020: OSGi Performance

(c) Alex Blewitt 2020
Performance Anti-Patterns
in OSGi and Eclipse
Alex Blewitt @alblue

View Slide

Optimising Eclipse Plug-ins
● In EclipseCon 2016 I discussed Optimising Eclipse Plug-ins
● Before I ate the apple that put me out of action for four years …
● Several things have changed since then
● Async Profiler was released in October 2017 (macOS + Linux)
● Java 11 was released, with Flight Recorder open-sourced
● JMC 7.1 added a flame graph view
● Many performance bugs were fixed

View Slide

Diagnose, Defer, DS
● Diagnose
● How to find where performance problems like
● Defer
● Reduce computation (especially on main thread)
● Declarative Services
● Migrate to DS for modular architecture

View Slide

Diagnose

View Slide

Diagnose
● What kind of problems are we looking for?
● Loading unnecessary classes or instantiating unnecessary objects
● DNS network resolutions (particularly on main thread)
● Slow loading of files from disk
● What tools are there to help find them?
● jcmd and -Xlog
● Async Profiler
● Java Flight Recorder

View Slide

Class loading and initialisation
● Classes are loaded from an archive file or disk
● Initialisation runs the on the class, which may load other classes
● Parameters mentioned in the classfile are loaded as they are called
● Reflective access causes all method signature types to be loaded
● Debug with -Xlog:class* or -Xlog:class*=debug (-verbose:class)
● Also use jcmd GC.class_histogram or GC.class_stats

View Slide

DNS lookups
● Calls to InetAddress.getAllByName can be suspicious
● Could be caused by network-loading a resource
● Also possible with URL.equals() calls
● Calls URLStreamHandler.hostsEqual() for http/s URLs
● Not called if host component is empty
● Can run in debug mode with breakpoint, but this is slow

View Slide

Async Profiler
● Async Profiler is one of the best profilers for JVMs on Linux and macOS
● Loads as an agent, either injected after the start or at startup
● Exports events through circular buffer to file
● Built-in support for generating flamegraphs
● Different event types (cpu, alloc, lock, cache-misses)
● Can instrument single Java methods as well
https://github.com/jvm-profiling-tools/async-profiler

View Slide

Async Profiler
% java -agentpath:/path/to/build/libasyncProfiler.so=start
,file=out.txt
,event=java.net.InetAddress.getAllByName
ExampleApplication
% java -agentpath:/path/to/build/libasyncProfiler.so=start
,file=out.svg
,event=java.lang.Integer.
,exclude=java.lang.Integer.valueOf
ExampleApplication
Load and start agent at boot (can be in eclipse.ini)
Write text
summary to
out.txt
Look for calls to InetAddress.getAllByName
Write
flamegraph
summary to
out.svg
Look for new Integer() calls
Unless they're coming
from valueOf
568048

View Slide

Async Profiler
● Can connect to running applications on the same host
● Profile with 'cpu', 'alloc', 'lock', 'wall', 'itimer' or (Linux) perf event
● Use Java attach mechanism, can supply PID or JPS name
% profiler.sh -e cpu -d 10 -t -o out.svg ExampleApplication
Write flamegraph summary to out.svg
Capture CPU utilisation for 10 seconds Summarise threads independently
As reported by JPS
568052
568053
Would be nice to
do this via JDT

View Slide

Java Flight Recorder
● Bundled with Java 11 onwards, no commercial license required
● Capture recordings to JFR files, analyse them on a client host
● Low overhead for use in production systems
● Complex to configure (requires XML profile)
● Can be confusing to understand
● JMC no longer available in JDK downloads – but AdoptOpenJDK has it

View Slide

Running Java Flight Recorder
● Like Async Profiler, can launch at startup or attach at runtime
● Settings are loaded from default.jfc, profile.jfc, or user supplied file
● Can configure settings in Java Mission Control
● Threshold for network access, file access 10ms by default
% java -XX:StartFlightRecording=filename=/tmp/dump.jfr,
dumponexit=true,
duration=60s,
settings=default.jfc

View Slide

Java Mission Control
Can see when threads are busy and waiting

View Slide

Java Mission Control – measuring IO
File I/O
operations
can be
tracked
with stack
traces

View Slide

JMC Flame Graphs
● New addition to JMC 7.1
● Summarises method profiling and stack traces as a FlameGraph view
● Requires profiling information collected from profile.jfc
● Different levels available: normal (20ms), high (10ms), ludicrous (1ms)
● Sampling processor, so will capture at a specific rate
-XX:StartFlightRecording=filename=/tmp/dump.jfr,
dumponexit=true,
settings=profile.jfc

View Slide

JMC Flame Graphs – Profiling
Highlight packages
or classes and see
flame graphs FlameGraph view
shown by Window >
Show View > Other

View Slide

JMC Flame Graphs – Memory

View Slide

Java Flight Recorder – Custom events
● The event mechanism is now standardised and can be used for custom types
● Can use it to record events (durations or signposts) into JFR stream
● Useful for time-boxing events afterwards e.g. bundle start-up time
● Module jdk.jfr in Java 11+ but is separate module from java.base
● Can programmatically consume flame graph afterwards to post-process it
● Module jdk.jfr.consumer can be used for parsing/processing events

View Slide

import jdk.jfr.*;
@Category("Eclipse")
@Label("EclipseCon Presentation")
public class PresentationRating extends Event {
@Label("Presentation")
public String url;
@Label("Rating")
public int rating;
public static void rateEvent(String url, int rating) {
PresentationRating example = new PresentationRating();
example.url = url;
example.rating = rating;
if (example.shouldCommit()) {
example.commit();
}
}
}

View Slide

import jdk.jfr.*;
@Category("Eclipse")
@Label("EclipseCon Timing")
public class PresentationTiming extends Event {
@Label("Presentation")
public String url;
public static void timeEvent(String url, Runnable deck) {
PresentationTiming example = new PresentationTiming();
example.url = url;
example.begin();
deck.run();
if (example.shouldCommit()) {
example.commit();
}
}
}

View Slide

Measuring Bundle-Activator start-up time
https://alblue.bandlem.com/2020/02/jfr-bundle-listener.html
https://github.com/alblue/com.bandlem.osgi.jfrbundlelistener
~1s on my machine

View Slide

Defer

View Slide

Deferring work until needed
● The easiest work is not doing work that isn't required
● Loading classes/images that are not used
● DS (or any Method.lookup) loads all types in method signatures
● Aggressively starting work in Activators that are wiring up the application
● Rebuilding caches before they are used for the first time
● Trade-off: having out-of-the-box everything vs fast start and amortised costs

View Slide

Looking up images asynchronously
● Most images provided by a plug-in aren't used
● URLDescriptor allows the image to be represented without loading
● However, mechanism to find it looks up content from disk
● Allows for $nl$ and $os$ to select different images based on region
● Repeated hits on filesystem (or jar traversal) to find exact URL
● ImageDescriptor.createFromURLSupplier allows this to be deferred

View Slide

Using ImageDescriptor.createFromURL ❌
private final static void declareRegistryImage(String key, String path) {
ImageDescriptor desc = ImageDescriptor.getMissingImageDescriptor();
Bundle bundle = Platform.getBundle(DebugUIPlugin.getUniqueIdentifier());
URL url = null;
if (bundle != null) {
url = FileLocator.find(bundle, new Path(path), null);
if (url != null) {
desc = ImageDescriptor.createFromURL(url);
}
imageRegistry.put(key, desc);
}
}
FileLocator searches a variety of locations on
disk to find the URL
Using FrameworkUtil.getBundle(class) is
more efficient than Platform.getBundle(string)

View Slide

Using ImageDescriptor.createFromURLSupplier ✅
private final static void declareRegistryImage(String key, String path) {
Bundle bundle = FrameworkUtil.getBundle(DebugPluginImages.class);
if (bundle == null) {
imageRegistry.put(key, ImageDescriptor.getMissingImageDescriptor());
} else {
imageRegistry.put(key,
ImageDescriptor.createFromURLSupplier(true,
() -> FileLocator.find(bundle, new Path(path), null)));
}
}
FileLocator lambda is a Supplier
which is called the first time the image is required
The true argument means use the missing
descriptor image if necessary
Having the lambda as final parameter allows
spanning multiple lines easily
564082 ✅

View Slide

Service Caller – single shot use case
● Sometimes operations only need to be done once
● Closing the splash screen, logging exceptional circumstances
● Wiring up a dynamic dependency for the cold case may not be worth it
● ServiceCaller provides a one-shot way of calling code
● Like ServiceTracker, but easier to use and avoids eager DS
org.eclipse.core.runtime.ServiceCaller
ServiceCaller.callOnce(MyClass.class, ILog.class, (logger)
-> logger.info("All systems go!"));
https://alblue.bandlem.com/2020/07/why-servicecaller-is-better.html
ServiceCaller takes a lambda is a
Consumer which is called with the service
563987 ✅

View Slide

Service Caller – multi shot use case
● ServiceCaller instances can also be cached
● When created, stores the calling class and target type
● Provides execution with a call method and an unget to release
org.eclipse.core.runtime.ServiceCaller
static final ServiceCaller log =
new ServiceCaller(MyClass.class, ILog.class);
static void info(String msg) {
log.call(logger -> logger.info(msg));
}
https://alblue.bandlem.com/2020/07/why-servicecaller-is-better.html
Provides a simple way to migrate from
Activator-heavy code in existing classes

View Slide

Debugging
● Many plugins have a 'debug' mode for exporting extra details
● No need to eagerly consult this until first needed, if not dynamically
static class DebuggingHolder {
static final boolean DEBUGGING;
private static final String OPTION_DEBUG_FLAG = "my/debug";
static {
boolean[] debugging = { false };
ServiceCaller.callOnce(DebuggingHolder.class,
DebugOptions.class, debugOptions -> { debugging[0] =
debugOptions.getBooleanOption(OPTION_DEBUG_FLAG, false);
});
DEBUGGING = debugging[0];
}
}
public void doSomething() {
if (DebuggingHolder.DEBUGGING) {
System.err.println("Debug content");
}
}
Inner class prevents initialisation until needed
First time evaluation causes resolution of flag
Better to use a
DS component
and inject
DebugOptions
564062 ✅

View Slide

Declarative Services

View Slide

Jobs as DS components
● Several slowdowns caused by an Activator to kick-start a Job at startup
● Causes many classes to be load at bundle start time
● Job can be left running after bundle is stopped leading to bundle leak
● Can define the Job with a DS component instead
● Starts automatically, not (necessarily) running on main thread
● Stopping/disabling component stop the job automatically

View Slide

Job as DS component
@Component
public class DSComponentJob extends Job {
public DSComponentJob() {
super("Example DS Component Job");
setUser(true);
}
@Activate
void start() {
schedule();
}
@Deactivate
void stop() {
cancel();
}
@Override
protected IStatus run(IProgressMonitor monitor) {
while(!monitor.isCanceled()) {
…
}
return Status.OK_STATUS;
}
}
Creates a file OSGI-INF/DSComponent.xml
Called when component is
activated (started)
Called when component is
deactivated (stopped)

View Slide

ResourceChangeListeners on demand
@Component
public class DSResourceListenerOld {
@Reference
IWorkspace workspace;
private IResourceChangeListener listener;
public DSResourceListenerOld() {
listener = this::resourceChanged;
}
@Activate
void start() {
workspace.addResourceChangeListener(listener);
}
@Deactivate
void stop() {
workspace.removeResourceChangeListener(listener);
}
public void resourceChanged(IResourceChangeEvent event) {
System.out.println(event.getResource());
}
}
Waits until workspace is
available before enabling
Uses method reference for
resourceChanged event
Adds/removes when
activated/deactivated

View Slide

DS components on demand – since Eclipse 4.16/2020
@Component
public class DSResourceListenerNew implements IResourceChangeListener {
@Reference
IWorkspace workspace;
public void resourceChanged(IResourceChangeEvent event) {
System.out.println(event.getResource());
}
}
Automatically publishes
IResourceChangeListener
ResourceChangeListenerRegistrar in core
resources automatically registers instance
Can specify an event mask with
@Component(property={"event.mask=1"}) 564876 ✅

View Slide

Floptimisations

View Slide

Floptimisations
● Also known as Pessimisations
● Removing XML whitespace from P2
○ Shrunk size of artifacts.xml by 15%
○ Reduced time-to-parse XML by 20%
○ But! Caused regressions elsewhere
○ Internal references re-used P2's XML writer
○ Some code processed XML line-by-line with BufferedReader.readLine()
477007 ❌

View Slide

Recommendations
● Instrument code with JFR that depends on Java 11+
● Download and experiment with Async Profiler
● Move out Jobs and ResourceChangeListeners from Activators to DS
● Replace references from Platform.getBundle to FrameworkUtil.getBundle
● Minimise exposure of internal implementation details to other clients
● Avoid processing XML line-by-line where possible

View Slide

Thank you!
Join the conversation:
@EclipseCon | #EclipseCon
@alblue
https://alblue.bandlem.com

View Slide

Evaluate the Sessions
Sign in and vote at Eclipsecon.org:
-1 0 +1

View Slide

EclipseCon 2020: OSGi Performance

EclipseCon 2020: OSGi Performance

alblue

More Decks by alblue

Other Decks in Technology

Featured

Transcript