JFR Event Stream Stop - Sip of Java
Billy Korando on April 24, 2023JDK Flight Recorder, JFR, received several updates with the release of JDK 20. The most significant change was to the Event Streams API. Let’s take a look at these changes and how to use them in our applications.
New JFR Events
As is typical with every JDK release, several new JFR events were added, and JDK 20 is no different. Three new JFR events were added, bringing the total number of pre-defined events to 177. The added events were:
- jdk.InitialSecurityProperty (JDK-8292177)
- jdk.SecurirtyProviderService (JDK-8294239)
- jdk.JITRestart (JDK-8289524)
stop()
Added to JFR Event Stream API
The JFR Event Stream API was added in JDK 14 with JEP 349. The JFR Event Stream API provides several valuable features; programmatic access to JFR events, a near real-time view into an application’s and the JVM’s internals, and the ability to use JFR in automated tests. It’s this last item where the new .stop()
method will see a particular benefit. To understand the benefit of .stop()
, let’s first review how JFR could be used in automated testing in JDK 19 and earlier.
JFR in Automated Testing Prior to JDK 20
While JFR could be used in automated testing, it wasn’t exactly straightforward and came with a lot of visual noise, as seen in the below example:
SampleApplication sampleApplication = new SampleApplication();
@Name("TestEvent") class TestEvent extends Event {}
@Test
public void testDoStuff() throws Exception {
List<RecordedEvent> recordedEvents = new ArrayList<>();
try (RecordingStream rs = new RecordingStream();) {
rs.onEvent("TestEvent", e -> rs.close());
rs.onEvent("MyEvent", recordedEvents::add);
rs.startAsync();
TestEvent testEvent = new TestEvent();
sampleApplication.doStuff();
testEvent.commit();
rs.awaitTermination();
}
for (RecordedEvent recordedEvent : recordedEvents) {
if(recordedEvent.getValue("value").equals("testValue")) {
return;
}
}
fail("A MyEvent event wasn't found!");
}
While there would be several different paths to using JFR in automated testing, the above example would be among the most efficient in minimizing test execution time while ensuring JFR events the developer was looking for were being captured. Still, this example comes with much visual noise and isn’t straightforward.
Signaling Event
One of the first annoying bits is a developer would need to create a “signaling” event that was used as a signal in the test to close the stream. In the above example, this is being done by TestEvent
. The only purpose of this event is to signal when the code under test has finished executing, seen by the line testEvent.commit();
after the method under test; sampleApplication.doStuff();
.
Closing the Stream
The other purpose of the signaling event, TestEvent
, is also to be a trigger to close the JFR stream, done with the line rs.onEvent("TestEvent", e -> rs.close());
. Which is essentially telling the stream to close when TestEvent
is added to the stream.
Pausing Execution
A signaling event and closing the stream are necessary because events aren’t written to a JFR Event Stream right when they occur. This is why I used the phrase earlier of near real-time as events are only flushed to the stream about once a second. However, that isn’t a guarantee, as a JFR Event Stream could be blocked waiting for system resources or just having many events to write. So a simple Thread.sleep()
wouldn’t reliably work. Instead, the rs.awaitTermination();
is used to pause the execution of the test until the stream is closed by rs.onEvent("TestEvent", e -> rs.close());
.
In practice, this often adds about a second to the execution time of the test. Individually, that doesn’t mean much, but if JFR is being used in many automated tests, those additional seconds can add significant execution time to a test suite.
Luckily this is all a thing of the past with stop()
.
The Great Simplification with .stop()
The equivalent automated test to the above example written using .stop()
looks like this:
SampleApplication sampleApplication = new SampleApplication();
@Test
public void testDoStuff() throws Exception {
List<RecordedEvent> recordedEvents = new ArrayList<>();
try (RecordingStream rs = new RecordingStream();) {
rs.onEvent("MyEvent", recordedEvents::add);
rs.startAsync();
sampleApplication.doStuff("testValue");
rs.stop();
}
//Assert here
for (RecordedEvent recordedEvent : recordedEvents) {
if(recordedEvent.getValue("captureArgument").equals("testValue")) {
return;
}
}
fail("A MyEvent event wasn't found!");
}
Beyond the obvious benefits of greatly simplifying the writing of the test, removing the need for a signaling event that closes the JFR Stream, and pausing execution to wait for the stream to close, the test executes much faster as well. When rs.stop()
is called, this immediately flushes all events to the stream and closes it. There is no longer a roughly one-second pause as the test waits for events to be flushed.
Additional Reading
InitialSecurityProperty JFR event (JBS Issue)
Release Note: New JFR Event: jdk.SecurityProviderService (JBS Issue)
Add JFR JIT restart event (JBS Issue)
Happy coding!