New features of JDK 14: jfr, JMC and jfr event flow

brief introduction

Java flight recorder (jfr) is a diagnostic and performance analysis tool for the JVM. It can collect data about the JVM and the Java applications running on it. Jfr is integrated into the JVM, so jfr has little impact on the performance of the JVM. We can use it safely.

Generally speaking, when using the default configuration, the performance impact is less than 1%.

Jfr has a long history. As early as when oracleacquired bea in 2008. Jfr generally works with JMC (Java mission control).

Jfr is a low overhead analysis engine based on events, with a high-performance back-end, which can write events in binary format, and JMC is a GUI tool for checking the data files created by jfr.

These tools first appeared in BEA's JRockit JVM and were finally transplanted to Oracle JDK. At first, jfr was a commercial version, but in jdk11, jfr and JMC were completely open source, which means that we can also use it in non-commercial cases.

Today's JDK 14 introduces a new jfr feature called jfr event streaming, which we will explain in detail in this article.

Let's introduce jfr and JMC first.

JFR

Above, we briefly introduce jfr. Jfr is a JVM tuning tool that provides data for subsequent JMC analysis by constantly collecting various events in the JVM and Java applications.

Event is composed of three parts: timestamp, event name and data. At the same time, jfr will also handle three types of events: events lasting for a period of time, events triggered immediately and sampled events.

In order to ensure the latest impact on performance, please select the event type you need when using jfr.

After jfr collects events from the JVM, it writes them into a small thread local cache, then flushes them into a global memory cache, and finally writes the data in the cache to disk.

Or you can configure jfr not to write to disk, but only part of the events information will be saved in the cache. This is why there is jdk14 JEP 349.

There are many ways to open jfr. Here we focus on the following two ways:

-XX:StartFlightRecording:<options>

The format of startup command line parameters is as described above.

Jfr can obtain more than 100 different types of metadata. If you want us to specify these metadata one by one, it will be a very big function. So JDK has provided us with two default profiles: default jfc and profile. jfc。

Where default JFC is the default record level and has little impact on JVM performance. It is suitable for most ordinary applications. And profile JFC contains more details, which will have more impact on performance.

If you don't want to use the default two JFC files, you can also create them according to your own needs.

Here is a more complete command line parameter:

-XX:StartFlightRecording:disk=true,filename=/tmp/customer.jfr,maxage=5h,settings=profile

The above command will create a profile information file with a maximum age of 5h.

Adding parameters on the command line is still too troublesome. If we want to add jfr dynamically, we can use the jcmd command.

jcmd <pid> JFR.start name=custProfile settings=default
jcmd <pid> JFR.dump filename=custProfile.jfr
jcmd <pid> JFR.stop

The above command starts jfr in a running JVM and dumps the statistical results to a file.

Custprofile Jfr is a binary file. In order to analyze it, we need the supporting tool JMC with jfr.

JMC

JDK mission control is a tool suite for managing, monitoring, profiling, and troubleshooting Java applications.

In jdk14, JMC is released separately from JDK. We can download it and install it.

Let's start a program to test jfr.

@Slf4j
public class ThreadTest {

    public static void main(String[] args) {
        ExecutorService executorService= Executors.newFixedThreadPool(10);
        Runnable runnable= ()->{
            while(true){
                log.info(Thread.currentThread().getName());
                try {
                    Thread.sleep(500);
                } catch (InterruptedException e) {
                    log.error(e.getMessage(),e);
                }
            }
        };

        for(int i=0; i<10; i++){
            executorService.submit(runnable);
        }
    }
}

A very simple program starts 10 threads. We start this program.

Then go to the JMC interface:

We can see the threadtest program running on the machine on the left side of the interface.

Click MBean server to see the panel information of the Java program, including CPU and stack information.

There are seven tabs below: overview, MBean browser, trigger, system, memory, thread, and diagnostic commands.

Through the following tabs, we can get more detailed information about the Java program, and through triggers and diagnostic commands, we can also send commands to the JVM of the target Java program.

JMC is very powerful and has many functions. You can experience the specific details by yourself.

Because this article is mainly about JFRS, we will explain how to create and analyze JFRS in JMC.

Create jfr

Under the MBean server on the right is the flight recorder, which is our target.

Click flight recorder:

We can start creating a jfr.

The target file is the generation address of jfr. You can choose any name. The recording time indicates how long the jfr needs to be recorded.

Click Next:

In this step, you can select more detailed JVM parameters.

Click Next:

Here, we can select the profile event option to monitor. You can choose according to your needs.

Finally, click Finish to create jfr.

Analyze jfr

Our jfr records the profile for 1 minute. After 1 minute, we can see that the target jfr file is generated.

After generating jfr, JMC will automatically open the generated jfr file, and we will get an outline view.

It contains Java applications, JVM internal environment and event browser.

The events we monitored within 1 minute are listed in the event browser.

Jfr event

JMC is easy to use, but it will be cumbersome to listen to jfr files one by one. Next, let's introduce how to write code to listen to jfr events.

As shown in the figure above, if we want to obtain the information of "class loading statistics" through the program, we can do so.

On the right side of the figure above is the specific information. We can see that it mainly contains three fields: start time, loaded class count and unloaded class count.

Our idea is to use JDK jfr. consumer. Recordingfile reads the generated jfr file, and then parses the data in the file.

The corresponding codes are as follows:

@Slf4j
public class JFREvent {

    private static Predicate<RecordedEvent> testMaker(String s) {
        return e -> e.getEventType().getName().startsWith(s);
    }

    private static final Map<Predicate<RecordedEvent>,Function<RecordedEvent,Map<String,String>>> mappers =
            Map.of(testMaker("jdk.ClassLoadingStatistics"),ev -> Map.of("start",""+ ev.getStartTime(),"Loaded Class Count",""+ ev.getLong("loadedClassCount"),"Unloaded Class Count",""+ ev.getLong("unloadedClassCount")
                    ));

    @Test
    public void readJFRFile() throws IOException {
        RecordingFile recordingFile = new RecordingFile(Paths.get("/Users/flydean/flight_recording_1401comflydeaneventstreamThreadTest21710.jfr"));
        while (recordingFile.hasMoreEvents()) {
            var event = recordingFile.readEvent();
            if (event != null) {
                var details = convertEvent(event);
                if (details == null) {
                    // details为空
                } else {
                    // 打印目标
                    log.info("{}",details);
                }
            }
        }
    }

    public Map<String,String> convertEvent(final RecordedEvent e) {
        for (var ent : mappers.entrySet()) {
            if (ent.getKey().test(e)) {
                return ent.getValue().apply(e);
            }
        }
        return null;
    }
}

Note that in the convertevent method, we convert the event read from the file into a map object.

When building the map, we first judge whether the event name is the JDK we need Classloadingstatistics, and then convert other fields in the event. Final output.

Operation results:

{start=2020-04-29T02:18:41.770618136Z,Loaded Class Count=2861,Unloaded Class Count=0}
...

You can see that the output result is the same as that on the interface.

Jfr event flow

After talking so much, we finally come to what we want to talk about today: jfr event flow.

In the above jfr event, we need to read the jfr file for analysis. However, documents are dead and people are alive. It is too complicated to form jfr documents for every analysis. A programmer can't stand it.

In the jfr event flow, we can listen to the changes of events and handle them in the program accordingly. In this way, you can listen for event changes without generating jfr files.

    public static void main(String[] args) throws IOException,ParseException {
        //default or profile 两个默认的profiling configuration files
        Configuration config = Configuration.getConfiguration("default");
        try (var es = new RecordingStream(config)) {
            es.onEvent("jdk.GarbageCollection",System.out::println);
            es.onEvent("jdk.cpuLoad",System.out::println);
            es.onEvent("jdk.JVMInformation",System.out::println);
            es.setMaxAge(Duration.ofSeconds(10));
            es.start();
        }
    }

Look at the example above. We passed configuration Getconfiguration ("default") gets the default configuration.

Then, the default recordingstream is built. Through the onevent method, we process the corresponding event.