Several years ago, I gave a presentation at EclipseCon 2016 on “Optimising Eclipse Plug-ins” in which I talked about a few different ways of making Eclipse faster, at least from a start-up and memory usage perspective.
The presentation wasn’t recorded, but is available on SpeakerDeck as well as a narrated copy I recorded subsequently at Vimeo.
One of the techniques I discussed was using Java Flight Recorder as a means to
record how long bundles take to start up, since the main cost of starting up
Eclipse (or other OSGi applications) is how long it takes for the bundles to
move into the STARTED state. Bundles that have a Bundle-Activator can slow
this down, and since the majority of OSGi frameworks have a means to start up
bundles sequentially, can lead to a lesser user experience.
At the original time of writing, JFR was still a commercial feature (requiring
-XX:+UnlockCommercialFeatures setting and the wrath of licensing) in Java 8,
and the API was evolving in Java 9 and onwards. However, now that Java 11 has
been released, we have a free (both as in beer and in speech) implementation
that we can code against in order to work as expected.
A number of API changes meant that the code needed some TLC, and so I recently
uploaded a
new version
of the JFRBundleListener project to GitHub. The project can be downloaded and
installed into an OSGi runtime (or Eclipse application) to find out where the
start-up costs lie. At the present time, I have not published it anywhere for
binary consumption.
The README.md contains more information about how to use it, but the TL;DR is:
- Build and install the bundle with a low start level (e.g. 1) so that it tracks all subsequent bundle activation
- Start your OSGi framework or Eclipse application with the magic invocation to
start JFR recording, e.g.
-XX:StartFlightRecording=filename=/tmp/dump.jfr,dumponexit=true,disk=true - Load and inspect the recording into Java Mission Control, or use the embedded
java -jar JFRBundleListener.jar < /tmp/dump.jfr > /tmp/stacks.txtto generate a stacks list that can be processed by FlameGraph.pl - Use Brendan Gregg’s flamegraph tool to create an interactive SVG
flamegraph.pl --hash --countname ms < /tmp/stacks.txt > /tmp/bundles.svg
The resulting SVG looks something like this:
Custom JFR events
The API for interacting with JFR has improved significantly since its first inception in Java 8. I am looking forward to the backport of Java 11 to Java 8 to improve the experience significantly there.
To create a custom event, subclass the jdk.jfr.Event class. Provided that it
has public fields of a known Java primitive or String, it will be written out
when commanded. The
JFRBundleEvent
class is used to surface an OSGi BundleEvent, and so persists pertinent data
to the JFRBundleEvent class upon creation.
These are created when receiving (synchronous) events with the
SynchronousBundleListener implemented in the
JFRBundleListener
class. To mark a span, the event has begin() called at the start of a bundle
coming on-line, and end() once it has finished. The commit() ensures that
this bundle event is recorded; provided that the commit() occurs at some
point later, and that the object is not reused in the meantime, it could be
done at a later time.
The event information is recorded with specific key fields; they are identified
using the field name in the class, or the one specified with the @Name
annotation as defined in the event itself. For simplicity, I have chosen the
OSGi bundle headers as the identifiers in the event, which may make
post-processing it easier.
Processing JFR files
Similarly, the API for processing a JFR file has become significantly better.
There is a helper method RecordingFile.readAllEvents() which translates a
dump file at a given path into a list of RecordedEvent objects, or it can be
used as an iterator to read through all events.
Events are identified by type; if not specified then the fully qualified name of the event class is used. This makes it easy to filter out specific events from the log, although it may be desirable that they are combined with other JFR events (e.g. thread sleeping, class loading, garbage collections etc.) in the log.
The
JFRFlameGraph
implementation provides a means to go through the log file, and generate a
stack of bundle startup to allow for investigation as to why something is taken
so long.
It prunes the list of events in the JFR recording to only include those
JFRBundleEvent of interest, and then builds up a sorted data structure based
on the earliest start-up time recorded. These are then interactively popped off
to write out events before the end time, so that the resulting file contains a
list of the bundles starting up:
1 2 3 4 5 6 7 8 9 | |
These can then be post-processed with FlameGraph.pl to generate the interactive SVG above.
The code prepends the Java thread name to the stack shown; this allows some
threads (such as background Worker-n threads) to be ignored, while focussing
on specific threads (such as the main thread and the Start-Level...
thread). Since the SVG is interactive, clicking on the thread name will focus
the view on just those bundles, which may provide more detailed analysis.
Summary
Java Flight Recorder is available as open source in Java 11, and can be used to export timing information using a custom event format. With sufficient post-processing of the data, it can generate flame graphs that can be more expressive than just looking at numbers.
The API for programmatically interacting with JFR recordings has been significantly improved, and being able to log timely information in conjunction with other events can be a significant bonus in performance analysis.