EclipseCon 2020: OSGi Performance

Given at EclipseCon 2020. A number of things has happened since my "Optimising Eclipse Plug-ins" talk at EclipseCon 2016. In this presentation, I'll be providing an update of the kinds of things that cause performance issues in Java code, looking at:

* Memory usage patterns
* Classloading behaviours
* Integrated JFR in Java 11

Presenting ways in which OSGi applications can be written to be more performance sensitive, including how to measure performance with JFR which is integrated with Java 11 tooling.

Given at https://www.eclipsecon.org/2020/sessions/performance-anti-patterns-osgieclipse and the YouTube video is available at https://www.youtube.com/watch?v=0bn5Yvg2kAU

Transcript

1. (c) Alex Blewitt 2020 Performance Anti-Patterns in OSGi and Eclipse Alex Blewitt @alblue
2. (c) Alex Blewitt 2020 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
3. (c) Alex Blewitt 2020 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
4. (c) Alex Blewitt 2020 Diagnose
5. (c) Alex Blewitt 2020 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
6. (c) Alex Blewitt 2020 Class loading and initialisation • Classes are loaded from an archive file or disk • Initialisation runs the <clinit> 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 <pid> GC.class_histogram or GC.class_stats
7. (c) Alex Blewitt 2020 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
8. (c) Alex Blewitt 2020 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
9. (c) Alex Blewitt 2020 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.<init> ,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
10. (c) Alex Blewitt 2020 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
11. (c) Alex Blewitt 2020 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
12. (c) Alex Blewitt 2020 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
13. (c) Alex Blewitt 2020 Java Mission Control Can see when threads are busy and waiting
14. (c) Alex Blewitt 2020 Java Mission Control – measuring IO File I/O operations can be tracked with stack traces
15. (c) Alex Blewitt 2020 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
16. (c) Alex Blewitt 2020 JMC Flame Graphs – Profiling Highlight packages or classes and see flame graphs FlameGraph view shown by Window > Show View > Other
17. (c) Alex Blewitt 2020 JMC Flame Graphs – Memory
18. (c) Alex Blewitt 2020 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
19. (c) Alex Blewitt 2020 Java Flight Recorder – Custom events 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(); } } }
20. (c) Alex Blewitt 2020 Java Flight Recorder – Custom events 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(); } } }
21. (c) Alex Blewitt 2020 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
22. (c) Alex Blewitt 2020 Defer
23. (c) Alex Blewitt 2020 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
24. (c) Alex Blewitt 2020 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
25. (c) Alex Blewitt 2020 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)
26. (c) Alex Blewitt 2020 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<URL> 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 ✅
27. (c) Alex Blewitt 2020 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<T> which is called with the service 563987 ✅
28. (c) Alex Blewitt 2020 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<ILog> log = new ServiceCaller<ILog>(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
29. (c) Alex Blewitt 2020 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 ✅
30. (c) Alex Blewitt 2020 Declarative Services
31. (c) Alex Blewitt 2020 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
32. (c) Alex Blewitt 2020 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)
33. (c) Alex Blewitt 2020 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
34. (c) Alex Blewitt 2020 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 ✅
35. (c) Alex Blewitt 2020 Floptimisations
36. (c) Alex Blewitt 2020 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 ❌
37. (c) Alex Blewitt 2020 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
38. Thank you! Join the conversation: @EclipseCon | #EclipseCon @alblue https://alblue.bandlem.com
39. Evaluate the Sessions Sign in and vote at Eclipsecon.org: -1 0 +1