A Closer Look at JFR Streaming

By Marcus Hirt and JP Bempel

Since JDK 14 there is a new JFR kid on the block – JFR streaming. 🙂 This blog post will discuss some of the things that you can do with JFR streaming, as well as some of the things you may want to avoid.

An Introduction to JFR Streaming

In the most recent version of the JDK a new JFR-related feature was introduced – JFR streaming. It is a feature allowing a developer to subscribe to select JFR data and to decide what to do with that data in the host process. JFR events can also be consumed from a separate process by pointing to the file repo of a separate JVM process – the mechanism is the same.

The JFR streaming works by allowing the reading from the JFR file whilst it is being written, the emissions to disk happening more frequently (usually every seconds, or when the in memory buffers are full) than during your normal flight recordings, where the data is emitted when the in-memory buffers are full. It does not support streaming directly from in-memory buffers, and the events are not delivered synchronously when they are occurring in the JVM.

The new functionality mostly resides in jdk.jfr.consumer. This is how you would open an event stream and start consuming the CPU load with 1 second intervals and the monitor class when blocked to enter a monitor for 10 ms:

try (var rs = new RecordingStream()) {
  rs.enable("jdk.CPULoad").withPeriod(Duration.ofSeconds(1));
  rs.enable("jdk.JavaMonitorEnter").withThreshold(Duration.ofMillis(10));
  rs.onEvent("jdk.CPULoad", event -> {
    System.out.println(event.getFloat("machineTotal"));
  });
  rs.onEvent("jdk.JavaMonitorEnter", event -> {
    System.out.println(event.getClass("monitorClass"));
  });
  rs.start();
}

The RecordingStream is what you would use to control what is gathered from within the Java process, effectively also controlling the recorder.

Here is another example using the default recording template, and printing out the information for garbage collection events, cpu load and the JVM information:

Configuration c = Configuration.getConfiguration("default");
 try (var rs = new RecordingStream(c)) {
     rs.onEvent("jdk.GarbageCollection", System.out::println);
     rs.onEvent("jdk.CPULoad", System.out::println);
     rs.onEvent("jdk.JVMInformation", System.out::println);
     rs.start();
   }
 }

The EventStream class can be used together with the standard flight recorder mechanisms to gather information from ongoing recordings, even ones being done in separate processes or an already recorded file. Here is an example using the EventStream to get some other attributes of the CPU load and information from garbage collections from within the Java process (needs an ongoing recording):

try (var es = EventStream.openRepository()) {
   es.onEvent("jdk.CPULoad", event -> {
     System.out.println("CPU Load " + event.getEndTime());
     System.out.println(" Machine total: " + 100 * event.getFloat("machineTotal") + "%");
     System.out.println(" JVM User: " + 100 * event.getFloat("jvmUser") + "%");
     System.out.println(" JVM System: " + 100 * event.getFloat("jvmSystem") + "%");
     System.out.println();
   });
   es.onEvent("jdk.GarbageCollection", event -> {
     System.out.println("Garbage collection: " + event.getLong("gcId"));
     System.out.println(" Cause: " + event.getString("cause"));
     System.out.println(" Total pause: " + event.getDuration("sumOfPauses"));
     System.out.println(" Longest pause: " + event.getDuration("longestPause"));
     System.out.println();
   });
   es.start();
 }

This is the EventStream interface used to consume and filter an event stream:

public interface EventStream extends AutoCloseable {
  public static EventStream openRepository();
  public static EventStream openRepository(Path directory);
  public static EventStream openFile(Path file);

  void setStartTime(Instant startTime);
  void setEndTime(Instant endTime);
  void setOrdered(boolean ordered);
  void setReuse(boolean reuse);

  void onEvent(Consumer handler);
  void onEvent(String eventName, Consumer<RecordedEvent> handler);
  void onClose(Runnable handler);
  void onError(Runnable handler);
  void remove(Object handler);
  void start();
  void startAsync();
  void awaitTermination();
  void awaitTermination(Duration duration);
  void close();
}

The open* methods allow you to open a specific file or a specific file repository (for example from a different process). The set* methods allow you to filter on time and to select if you want to enforce that the events are delivered in time order. You can also allow the reuse of the event object that gets delivered, to get the memory pressure down a bit.

The onEvent* allows you to register a consumer for handling the events, either all of the events or by event name (type). The start method kicks off the processing in the current thread, startAsync is a convenience method for kicking off the process in a single separate thread.

Where to use streaming

There are several advantages to JFR event streaming. It is a great way to access JFR data for monitoring purposes. You get access to detailed information that was previously unavailable to you, even from different processes, should you want to.

Here are some examples:

  • Directly send monitoring data to your favourite monitoring service
    For example streaming select metrics over to Datadog. 😉 Not that you would need to – we already derive interesting performance metrics from the (full) flight recordings we capture. We even track complex metrics like top hottest methods, or top allocations sites, over time, using what we internally call high cardinality metrics.
  • Pre-aggregating data before sending it off
    For example, you could get the CPU load every second, and then every five minutes roll it up to an average, median, min, max and a standard deviation, not having to send every single entry.
  • Act on profiling data in-process
    You could, for example, make decisions for controlling the normal flight recordings given some statistics you track, like enabling certain events when it looks like it could be interesting.
  • Expose JFR data through other management APIs
    For example, adding an MBean exposing select JFR data over JMX.
    That said, there might be an API to directly connect to an MBeanServerConnection directly in the future[1]:

    MBeanServerConnection conn = connect(host, port);
    try (EventStream es = new RemoteRecordingStream(conn)) {
      es.onEvent("jdk.GarbageCollection", e -> ... );
      es.onEvent("jdk.ExceptionThrown". e -> ...);
      es.onEvent("jdk.JavaMonitorBlocked", e-> ...);
      es.start();
    }
    

It also allows you to skip the metadata part of a normal flight recording. The metadata in JFR contains the information about what was recorded, so that you can parse and view data that you may not even know about beforehand. In the case of monitoring a few well known data points, this is redundant information to keep sending over and over again.

Erik Gahlin has a neat example for producing health reports using JFR streaming, displaying pre-aggregation of the top frames for execution samples and allocation, as well as doing stats for some common data points, like GC metrics and CPU load.

Where Not to Use Streaming

This is from JEP-349[2], the JEP where JFR streaming was introduced:

To consume the data today, a user must start a recording, stop it, dump the contents to disk and then parse the recording file. This works well for application profiling, where typically at least a minute of data is being recorded at a time, but not for monitoring purposes.

Let’s explore why the JEP differentiates between monitoring and profiling. Some events in JFR are simple data points in time. Some are more complex, containing plenty of constants. For example stack traces. JFR takes great care to record these complex data structures in a binary format that doesn’t take a lot of processing time to produce, and which is still compact.

Some of the JFR events occur quite frequently – for example, a typical one minute recording of data can contain hundreds of thousands of events. The file size for such a recording is typically only a couple of MB large. There is a mix of techniques used to keep the size down, such as using constant pools to ensure that information like method names are not repeated, LEB128 encoding of integers etc.

For profiling you typically want quite a few of these events enabled. JFR was built to emit this data at a very low overhead, and the data is eminently useful to get detailed information about things like why your thread is halting. For example, the stack trace to a place where your code had to wait to enter a monitor, complete with the class of the monitor waited on, the exact duration of the wait, which thread was holding on to the monitor (making you not able to enter), the monitor address and more. Not only that, there may have been other events providing context about what was going on in that thread at the time of the monitor enter, shining further light on what was going on. Events that you may not even know about.

If using JFR streaming for profiling, you would spend a lot of effort either naively sending constant information over and over again in an inefficient way (say, serializing all of it to JSon), or trying to spend a lot of effort reproducing the JFR format (introducing your own constant pools etc).

For example, the RecordedEvent class contains a method to get the RecordedStackTrace, which is a List of RecordedFrame. For each event you would walk through, the in-memory object model would be created.

You can externalize some of that cost, i.e. how the process you are monitoring is affected, by using another process to read the data as described above. That would, for example, lessen the allocation pressure in the process you’re monitoring. That is great, for example if you have a very latency sensitive process. That said, you have now created another Java process and put the costs over there (including the cpu overhead of dealing with the memory pressure as well as the memory overhead of running another JVM), typically on the same host. If you can afford to dedicate the memory and pin the event stream reader process to its own processor (cpu affinity), this can be a good solution though. Note that the same can be done for normal flight recordings, i.e. you can stream the recorded data directly from the file repository from a separate process.

Benchmarks of Using JFR Streaming Wrongly

For laughs and giggles, here are some benchmarks using just standard JFR to get all the data in the profiling template, compared to getting the equivalent information and serializing it to a JSon-like format using JFR Streaming. In other words, abusing JFR Streaming as a streaming replacement for getting the full JFR dataset. This is of course not what you should be using JFR Streaming for, but exemplifies how wrong you can land if you use the technology in a way it was never intended. We’ll look at the latency of http requests, the CPU time spent and the allocation pressure. We’ll also look at the size of the payload of information extracted. The benchmark is admittedly being a bit extra mean as well, to explore edge cases.

Note that this is a simplified example – we’re not even bothering with extracting the full stacktrace information and re-encoding it for streaming, whilst the JFRs in comparison already contain the full stack traces for all events efficiently encoded in constant pools. We could trade (even more) CPU for trying to bring the streamed data back to a JFR style format with constant pools again before storing/sending it. For serialization we’re simply doing toString() on the event objects, which gives us the events in a JSon-like format with only the top five frames of the stack trace. Including the full stack traces would add quite a bit more overhead to the streaming example.

The benchmark is available in this GitHub repository. It is based on the standard PetClinic application with some modifications to make it relevant to measure overhead in general.

Note: We are using an early access version of OpenJDK 15 in the benchmarks, since we discovered a bug whilst building this benchmark. See JDK-8245120.

The first chart shows the impact on http request latencies:

Note: Y-axis is in log scale to magnify the difference.

Next chart shows the CPU consumption. We measure in ticks from /proc/<pid>/stat at the end of the benchmark. This way we have a unique number easy to compare with other runs. It represents the CPU consumed when threads were scheduled on the CPU.

 

The following chart is the total amount of heap allocated during the benchmark. Numbers were extracted from GC logs.

The final chart represents the size of extracted information, as described above:

Note that the JFR file contains the full stacktraces, and that the jfr-streaming one is limited to the top 5 frames.

So what is the conclusion of these benchmarks? Not much, except for: “don’t use technology for things it was never intended for”. 😉

Summary

  • JFR streaming is a great new way to expose JFR data for monitoring purposes.
  • JFR streaming is available from JDK 14 and above.
  • JFR streaming is complementary to the already existing JFR APIs, which remains the go-to way to use JFR for low-overhead detailed information (i.e. profiling / execution tracing).
  • Knowing where and how to use JFR streaming is key to avoiding sad pandas.

[1]:https://www.reddit.com/r/java/comments/e97vos/jfr_event_streaming_with_jdk_14_in_outprocess/faiapm8/

[2]:https://openjdk.java.net/jeps/349

Fantastic JVMs and Where to Find Them

Since you’re reading this blog, chances are that you’re writing software which will eventually run on a JVM. Most of you are using the Java language. Many of you are using a variety of other languages that target the JVM, such as Scala, Kotlin, Clojure, Groovy, (J)Ruby etc. Eventually you’ll need to decide on which JDK/JRE to deploy your software on in production. This is much easier said than done. There are quite a few different vendors out there, providing support and taking responsibility for the binaries they produce. They can have different support lengths for specific versions, and whereas you can sometimes find a vendor providing extended support for a version that has been officially end-of-lifed at Oracle, you may not find builds with the latest fixes in them publicly available. You’ll need to get those directly from the vendor.

After trying to figure out what’s what, I thought I’d simply write a blog post on the various JDKs available out there. This is especially important, since you might be consuming your JDK from a container provided by a third party, e.g. Docker Hub, and you may not know exactly what you’re getting[1].

Release Version Chicken Race

Typically most companies will require that you keep your dependencies up-to-date. For example, if you’ve written something with a dependency on Tomcat, you are pretty likely to keep your dependencies up-to-date. GitHub may even warn you if you’re running with a version that has known security implications. However, not everyone is keeping their JDKs/JVMs up-to-date. Which is funny, in a way, since everything you’ll be running could be affected.

Let’s take the Oracle JDK as an example. JDK 7 was GA in July 2011. Publicly available updates and fixes ceased in April 2015. Oracle’s Premier Support ended in July 2019, and even the Extended Support ends 2022.

Let’s say you’re running on JDK 7. If you got your JDKs from Oracle, without a support contract chances are that the latest version of JDK 7 you got was built in 2015. You are now five (5!) years behind on critical security patches.

In other words, if you’re still running your software on JDK 7, you may want to at least begin upgrading to 8. JDK 7 is dying and support is being dropped left and right. If you aren’t buying support and have someone provide you with (security) patches, you might want to accelerate the effort. Also, this particular upgrade (7->8) should be relatively painless – in most cases it will be a drop in replacement. Now, if you’re not running a JDK 7 with the latest patches (sanity check – was the JDK at least built this year?), you may not only be missing out on bug fixes, but you may also be missing out on security patches[2]!

The same arguments could be made for JDK 8 as well, on a slightly pushed out time-line. The good news is that there are still public (and free) updates coming from the OpenJDK 8 maintenance project. That said, there are plenty of advantages for upgrading to JDK 11+, better performance being one of them.

Now, when the new, faster, release schedule was announced, Oracle announced that every 3 years, there would be an LTS (Long Term Support) version of Java. The releases in between the LTS releases would only be supported until the next release came out. Most vendors have adopted the same support scheme, which means that, at the time of writing, you should not be running ANYTHING on JDK 9,10,12 and 13 (unless you’re using Azul distributions, see [3]). They are not supported. Running them will only mean that you are lacking bug- and security fixes. To take a somewhat arbitrary example – if you stopped upgrading JDK 8 after 8u74, you are literally lacking thousands of fixes.

At the time of writing this blog, the new CPU (Critical Patch Update) releases have just been published, and these are the releases you should be running in July 2020 (sooner rather than later):

  • JDK 8u262
  • JDK 11.0.8
  • JDK 13.0.4 [3]
  • JDK 14.0.2

If you’re running anything else in production, without a support contract, it could be argued you’re not doing things quite right.

What’s what?

OpenJDK, being open sourced, has builds provided by plenty of vendors. Here is a non-exhaustive list of some vendors shipping supported versions of OpenJDK (in alphabetical order, distribution(s) in parenthesis):

These providers usually ship distributions with pretty much the same bits from the OpenJDK repository, sometimes differing by what features are enabled, for example like a GC (Shenandoah / Red Hat), or by adding proprietary features like a new compiler (Falcon / Azul (Zing)). Some vendors have a free distribution (e.g. Oracle OpenJDK, Azul Zulu) and one that requires a commercial license (Oracle JDK, Azul Zing). Which vendor and distribution you should select depends on your demands – e.g. which vendor can provide reliable support to you (Oracle is one of the biggest contributors to OpenJDK), or which one provides the feature you need at a price point you can afford (e.g. JDK Flight Recorder on JDK 8 without the need for a commercial license, or support for a specific GC or compiler).

There are also upstream builds, not supported by anyone, built on Red Hat infrastructure and hosted by AdoptOpenJDK. For example, if you get a JDK 8 from Docker Hub (openjdk/jdk8u252, openjdk/jdk8), that is what you would get.

Where to get JFR – Public Service Announcement

As you probably know, JDK Flight Recorder, a technology close to my heart, has been backported to JDK 8. Since we’re talking about where to get your JVMs and versions, I thought I’d include a small table for which provider will be including JFR in what version of their JDK 8 builds.

Vendor First JDK 8 Version with JFR Release Date Docker Image
Azul (Zulu) u212* (u262+ recommended) 2019-04-16 azul/zulu-openjdk/8
AdoptOpenJDK u262 2020-07-16 adoptopenjdk/8u262
Red Hat u262 2020-07-15 In Fedora and RHEL
Amazon (Corretto) u262 2020-07-14 amazoncorretto:8u262
Bell-Soft (Liberica) u262 (separate binary) 2020-07-14 N/A
Upstream builds [4] u272 2020-10-20 openjdk/jdk8u272, openjdk/jdk8

Summary

  • Use the latest version of an LTS which is still supported, or the latest version
  • Use a supported build in production (even if you haven’t bought support)

Thanks to Mario Torre, JP Bempel and Gil Tene for feedback!

[1]: Mystery meat OpenJDK builds strike again: https://mail.openjdk.java.net/pipermail/jdk8u-dev/2019-May/009330.html

[2]: To check the vulnerabilities you may be exposed to, see e.g. https://www.cvedetails.com/version-list/93/19116/1/Oracle-JDK.html?sha=b856721542b66953c859bd95be067255dd4c6098&order=1&trc=188

[3]: Upstream JDK 13u is being supported, and Azul has announced 13 to be “Medium Term“ supported – you can keep getting updates for JDK 13 for Azul distributions.

[4]: These are built by Red Hat and hosted by AdoptOpenJDK, and are different from Red Hat’s and AdoptOpenJDK’s supported builds.

The “Best of the JDK” Tournament

Over the last few weeks, there has been a knock-out tournament raging on Twitter, where various Java technologies have battled out which JDK technology is the best. It’s all part of the activities taking place around the celebration of Java turning 25 years. And boy, have those years been interesting.

Like many languages in use today, Java started out with a simple interpreter. That is, by the way, how Java got a reputation for being slow. Today, Java peak performance can surpass that of statically compiled languages, owing to optimizations only possible when runtime information is available. But I digress

As many of you know, I started out co-founding a company named Appeal – the company that created the JRockit JVM. We did quite a few cool things during that time; some of them relevant to the knock-out competition. We built the world’s first JVM management console, mostly since the application to become a Java licensee (so that JRockit could become a Sun certified JVM) required us to state a value-add. Our original application stated “better performance”, and was summarily turned down. 😉 With the work on the management console we eventually consolidated an API to monitor and manage the JVM – JMAPI (the JRockit Management API), which later inspired – and was superseded by – JSR-174 (java.lang.management)[1].

We also built a tool we called JRA (JRockit Runtime Analyzer). It really started out as a tool for finding out how the JVM was performing at customer installations – we needed information to better understand how to improve the JVM for real world usage. Customers, quite understandably, refused to let us borrow their applications to run them in our labs. To make it easy for them to understand and verify the data they were sharing, it was all emitted as text (XML). It didn’t take long for customers to see us use the tool and the (accidental) value it brought for optimizing their applications – was the tool perhaps for sale? As a startup, we of course said yes, and made it into a product. When we later introduced the JRockit DetGC (deterministic GC), there was a need to be able to prove that the GC was keeping the latency contract, and show where in the customer code any thread halts were caused (e.g. due to bad synchronization). So the JRockit Runtime Analyzer was extended with LAT (the Latency Analysis Tool), which now introduced a binary artifact for the latency data for better data density and less serialization cost. In the end the JRA and LAT was unified into a single model – JFR (JRockit Flight Recorder, later Java Flight Recorder, and finally re-dubbed into JDK Flight Recorder when it was open sourced). We also created an impossibly cool on-line memory analysis tool (which was sadly never ported to hotspot), together with a slew of other little tools and utilities.

The good old JMC memleak tool

Some of these tools converged into Java Mission Control, which became the hub for the cool tools we were developing.

JMC Logo

I was happily surprised to see JDK Mission Control included in the “Best of the JDK” feature face off. I was doing little dad-dances (to the embarrassment of my kids) in total astonishment when JDK Mission Control got up against the runtime and language features and ultimately won the whole thing.

Competition Results

Tech Poetry Throw-Down

One of the best parts of this whole competition was when Erik Costlow wrote some poetry in support of JDK Mission Control. This sparked an epic tech-poetry throw-down with little poems in favour of various Java technologies.

Here are a few of my favourites entries for JMC & JFR (in no particular order):

Of JDK Mission Control

whose benefits I will extol:

It watches performance

while still in conformance

So therefore it should win this poll.

  – @costlow

(The one which started the it all)

2 am in the morning, my mobile chimed,

The war room conf call had to be primed.

JVM’s are down, the helpdesk said,

Touch troubleshooting road ahead.

CPU? GC? Bad Code?, the questions abound,

The root cause was far from being found.

Tumultuous voiced from Dev to Ops, each one declaring the were clean

No path to the solution was to be seen.

With a prayer, I fired up the Java Flight Recorder,

Hoping this would restore some war room order.

Lo! And behold, the histogram revealed

‘Twas a code deadlock, the system could yet be healed!

Helpful NullPointer messages, I hear you say,

Who will alert you whilst you are away?

  – @perfclarity

To see or not to see (perf data)

That is the question (mission control answers).

Whether ‘tis nobler in the code

To suffer the zings and harrows of outrageous finger pointing

Or to stream events and by analyzing, end it

  – @costlow

I have never

had to deal

with NullPointer

Exceptions

and which

many people want

to have

better messages

Forgive me

but my vote goes to JMC

it is so sweet

and so cold

  – @stuartmarks

To think that I could ever see

A tool so lovely: JMC

A tool that streams events all day

Yet still performs without delay.

  – @costlow

If you need to control a mission

OpenJDK had an omission

And then JMC

Was suddenly free

Without even rights of rescission

  – @stuartmarks

So much value inside JMC

Yet usage was low, tis it wasn’t free

But low and behold

Oracle open sourced it in whole

And now productivity is as easy can be

  – @Sharat_Chander

As I stream through the events of my workload perf pain

I take a look post 8 life and realize this tool should reign

‘cause that’s just perfect for a coder like me

You know we love fancy things like JDK MC

Been spendin’ most our lives livin’ in a coder’s paradise

@costlow

Here are a few of my favourites for the other technologies:

Null pointer exception

Is a old familiar friend

And she wants to be

more helpful again

With deep information

I can only begin to extol

Love for NPE

For she should win

this Java poll

  – @manicode

There was a NullPointerException

Whose message needs amplification

To the VM some hacks

Add the relevant facts

And no longer is it an obsession

  – @stuartmarks

As I try to decipher my NPE in grails

The Greater Sage-Grouse wanders the sage brush

The grouse and I are one

For I can’t decipher less helpful NPE’s in grails

Any more than the sage-grouse knows why it wanders the sagebrush

  – @manicode

I’m on a boat motherf$%^r take a look at me

Straight floatin’ on a boat debugging NPE

Busting five knots, wind whipping out my coat

You can’t stop me motherf$%^r cause I’m debugging on a boat

  – @manicode

The usability of NullPointerExceptions

have historically been an issue

by adding static code to dynamic exceptions

our problems we can diffuse

Let go of your stack trace debugging hate

And vote for JEP Three Fifty Eight!

  – @manicode

Many thanks to @costlow, @manicode, @stuartmarks, @perfclarity and @Sharat_Chander for all the laughs! 🙂

Thanks!

Yes, I know this is a silly little Twitter competition. But, if nothing else, this silly little competition provides an excellent opportunity for me to give some overdue thanks:

  • Plenty of thanks and love to all of the users of JMC out there, using JMC to solve tricky problems in production systems on a daily basis.
  • Many thanks to everyone who voted for JMC. I didn’t think a tool would stand a chance against language and runtime features.
  • Huge thanks to all the developers on the JDK Mission Control team, and to all the developers on the JDK serviceability team. You’re a really awesome bunch, and it’s a privilege for me to be working with you.
  • Major kudos to Oracle for open sourcing JDK Mission Control and JDK Flight Recorder.
  • Many thanks to the main sponsors of the development of JDK Mission Control:

JRockit and Duke hanging

[1]: Sadly, not all of the features in JMAPI got rolled into the standardized API. JMAPI could, for example, change the CPU affinity of the JVM process on the fly, dynamically change the heap size target, and independently (and dynamically) switch the GC to use a nursery or not as well as switch between concurrent and parallel mark and/or sweep phases. Of course differences in GC capabilities etc required the standardized API to be limited to what made sense to most runtimes. That said, I’m still kinda bummed that it became a JMX API (java.lang.management depending on the javax.management specification), instead of a pure local Java API, which could also have been exposed through JMX. See, for example, the JFR APIs, where there is a local API and also a JMX API.