Java flight recorder

Java Flight Recorder options not working and file is stored only in the end of the duration setting

I have a Java process and I start it (as suggested here : parameters for FR) with the options :

-XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:StartFlightRecording=duration=2m,filename=myflightrecord.jfr -XX:FlightRecorderOptions=maxsize=100k,maxage=1m

in order to have Flight Recorder information.

I would expect that the maxage=1m would give me only one minute of record, and maxsize=100k the file size wouldnt be larger than 100Kb, but none of them does work as expected.

Another problem that I encounter is that I want the file to be stored every amount of time, lets suppose every one minute. But the file «myflightrecord.jfr» is empty until the duration is reached (2minutes in the example).

Is there any way to make the Flight recorder flush before the end of the duration?

ps: The version of Java I am using is JDK1.8.0_45

2 Answers 2

The maxage and maxsize options only apply when you have a continuous recording (= have not set duration). I also think that they are only guidelines, not exact limits.

If you want to get the data flushed to disk for a continuous recording, you can set disk=true, and if you want to specify where the data should end up, you can set repository=path (I believe the data will only be flushed to disk when the the in memory buffers are full, I’m not sure if it’s when the thread local buffers are full, or when the global buffers are full, see slide 13 in this slidedeck for a picture describing this: http://www.slideshare.net/marcushirt/java-mission-control-java-flight-recorder-deep-dive)

See https://docs.oracle.com/javase/8/docs/technotes/tools/windows/java.html XX:FlightRecorderOptions for more info. You can check the threadbuffersize and globalbuffersize as well.

I know the valid combinations of flags have varied a bit, so the documentation might not be entirely up to date.

Kire Haglin can correct me where I’ve misunderstood things.

This is for JDK 7 and JDK 8 (Hotspot), and JDK 5 and 6 (JRockit).

First, maxsize and maxage only works if you have a disk based recording, since the parameters controls how much data to keep on disk.

If you have an in-memory recording (defaultrecording=true,disk=false), the size of the memory buffers depends on the number of threads that are in use, how much memory each thread is allowed to use, number of global buffers etc.

Flight Recorder was designed for large servers with GB of memory and TB of disk, so I don’t think the JVM will be able to respect the number you provided, i.e. a single event could be larger than 100 kb, but typically they are about 50-150 bytes.

Second, the name of the parameters (maxsize and maxage) are misleading. It’s not the maximum size/age, but the threshold at which the JVM will remove a log file when they are rotated, which typically happens every 12 MB. To minimize overhead the JVM doesn’t stop all the threads immediately when the threshold is met, which means data spills over so in reality it is 12-15 MB. If the system is highly saturated, it could be a lot more, think 30-40 MB.

So setting the maxsize to 100k will not work, you will always get at least 12 Mb,

If you set the maxage to 1 minute you will get data for at least one minute, perhaps more if it can fit in the size of about one log file, 12-15 Mb.

If you have an in-memory recording, the data is copied from the memory buffers to disk when the recording ends. That’s why your file is empty. If you want Flight Recorder to write continuously to disk, you should set disk=true.

Using Java Flight Recorder With OpenJDK 11

Want to learn how to use the Java Flight Recorder with OpenJDK 11? Check out this post to learn more about using the Java Flight Recorder and Java Mission Control.

Join the DZone community and get the full member experience.

Java Flight Recorder (JFR) used to be a commercial add-on of the Oracle JDK. As it’s been open sourced along with Java Mission Control, everyone using OpenJDK 11 can now troubleshoot their Java apps with this excellent tool for free of charge. JFR, previous proprietary solution, might be lesser known for those relying on previous versions of OpenJDK. Therefore, I thought it was worth writing a fresh post on using JFR with OpenJDK 11.

Overview

About the Java Flight Recorder

JFR is a profiling tool used to gather diagnostics and profiling data from a running Java application. Its performance overhead is negligible and that’s usually below 1 percent. For short running apps, this overhead might be above that because JFR requires some warm-up time on the start.

Diagnosing faulty apps with JFR might shorten resolution times significantly. An anomaly can be seen from its first emergence as it unfolds and, finally, until that point when it causes the application to die. Of course, not all of the issues are that severe. JFR collects data about the running threads, GC cycles, locks, sockets, memory usage, and a lot more.

Java Flight Recorder Went Open Source

As I mentioned in the intro, this one used to be a proprietary feature of the Oracle JDK, and officially, it was only available for paying, Oracle customers. In practice, you could enable it with the -XX:+UnlockCommercialFeatures -XX:+FlightRecorder flags, and earlier JVMs wouldn’t enforce having a license key or anything else like that.

Mark Reinhold at Oracle wanted to move Java forward faster and took inspiration from some Linux operating systems that have a release cadence of six months. I think he might have thought of Ubuntu, although he didn’t mention that specifically. Nevertheless, Java SE, since version 9, has got a predictable six-month release cycle.

To make a long story short, in order to achieve shorter release times, they’re now working on a single code base that made Oracle JDK and OpenJDK builds interchangeable. Eventually, starting with Java 11, Oracle provides JDK releases under the open-source GPL and a commercial license. If you are used to getting Oracle JDK binaries for free, download OpenJDK builds instead, they’re functionally identical.

As a consequence, JFR is now open source and simplifying the release process with a single code base renders the OpenJDK more appealing to developers.

JFR Packaging Differences

Oracle JDK 11 emits a warning when using the -XX:+UnlockCommercialFeatures option, whereas OpenJDK doesn’t recognize this option and reports an error.

Java Mission Control Was Also Open Sourced

JMC is a client tool used to open the production time performance and diagnostic recordings JFR produced. JMC also delivers other features, such as a JMX console and a heap dump analyzer. Oracle JDK releases from 7 to 10 contain JMC, but it has been separated and is now available as a separate download.

JMC has was recently open sourced, which means that the whole toolset (JFR + JMC) are available to anyone using OpenJDK 11. At the time of writing, the first open source JMC version 7 hadn’t reached GA yet, but early access builds were provided.

Using the Flight Recorder

I haven’t been using JFR in production continuously, because that would have been a violation of Oracle JDK’s license. For development, everything can be used according to the best knowledge of mine. Thus, folks on Oracle JDK – without having a support contract – were slated to end up with having to reproduce performance issues locally on their development machines.

Let’s look at some code. This is going to be a simple demonstration of the basics of the Java Flight Recorder. I created a little trouble on purpose to give us something to debug.

For showcasing a classical OOME, we could just add new objects to a collection. I chose this one because I see this particular pattern frequently in production. That is, there are two (or more) components and some of them produce new objects and some of them consume those objects. The issue stems from the fact that the capacity of that internal buffer, through which components communicate, is potentially unbounded.

When I say potentially unbounded, I mean that the buffer size multiplied by the size of an average objec is that large. After some time, it simply eats up all the heap space. Often, that takes hours, days, or a week maybe, but OutOfMemoryError will happen eventually.

Developers often think that seeing OutOfMemoryError in the logs surely reflects a programming error and a memory leak. Sometimes, heap dump analyzes, confirms, or confutes that with certainty, but there are cases when it isn’t black or white and you simply cannot tell. JFR with historical data comes to the resource in those cases.

Enable JFR

We can expect an OutOfMemoryError from the short program above and it takes some time, but it’s going to happen. With JFR, we can look into the time course and characteristics of the error with full details on GC times, CPU usage, and other things.

I’m using these debugging settings in production. In this sense, these JVM arguments also serve as a note for myself. When I need them, I’ll find them here.

What’s most important for the JFR is the highlighted part (lines 5-11). By default, neither the maximum size of the recording nor the maximum age or recorded data are limited. I experimented with various settings and applied both maxage and maxsize , which proved useful. In earlier JDK versions, JFR had more settings, but they simplified them in JDK 11.

I’d like to bring your attention to the dumponexit option. Under normal circumstances, the recording is written to disk whenever capturing data is stopped. That naturally happens when JVM terminates. According to my experiences, however, when termination is abnormal, for example, when heap space runs short, then the recording might be zero bytes in size. Although the documentation of JFR settings isn’t very clear on what difference dumponexit has, I observed that applying it is advantageous for capturing data from troubled JVMs.

JFR comes with two factory-made profiles ( default and profile ), and they define what events should be persisted to captured recordings. When the settings options aren’t specified, the default profile is used. In this example, I used the more extensive profile event definition and also enabled tracking the path to GC roots. These impose higher overhead over the running JVM, and I wouldn’t advise to use them in production.

Capturing Recordings On-Demand

Performance data is written to disk whenever the JVM exists, however, recordings can be exported on-demand at any given time with the JCMD utility. The JFR.check command returns details about a running recording.

Other than that, JFR.dump allows you to export whatever has been recorded without having to wait for a running JVM terminate or stop a recording.

There are other troubleshooting options the JCMD utility provides.

Analyzing JFR Recordings

As I mentioned before, JMC has to be downloaded separately. Although it’s an early access release only, I found it fully usable without experiencing major glitches. In JMC 6, the Automated Analysis Results screen is added to help engineers diagnose issues quicker. I’ve been using an older JMC 5.5 release and found this one useful. It provides useful tips, indeed. It’s correctly identified OOMEGenerator$Producer as the source or large objects being generated, and it also advises to balance allocation rate among threads.

Java Mission Control 7 – Automated Analysis Results

The memory view is okay from the point of view that it provides a graph of heap usage, but for some reason, numbers from the object histogram list are missing. As older releases of JMC cannot open this recording, I don’t know how this one would look like. I think this might be a bug.

Java Mission Control 7 – Memory

Seeing the GC pause times along with heap size allocation changes is useful too, but in older JMC releases, this one looked better:

Java Mission Control 7 – Garbage Collections

Caveats

• JFR recordings aren’t backward compatible recordings produced by OpenJDK 11 aren’t backward compatible and older JMC releases (tried 5.5 and 6) wouldn’t open them.
• JMC 7 is still an early access release functionality might change in GA, and some bugs might lurk here and there.
• There’s a bug in the official Docker image that prevents the JVM from starting when JFR is enabled.
• JMC 7 isn’t able to analyze HPROF files, although OpenJDK’s Wiki states that it’s able a to do that.

Conclusion

Java Flight Recorder (JFR) is a profiling tool used to gather diagnostics and profiling data from a running Java application. It collects data about the running threads, GC cycles, locks, sockets, memory usage, and about a lot more. JFR along with Java Mission Control, which is a tool for analyzing recordings that have been open sourced and aren’t proprietary products of Oracle any longer. That move by Oracle renders OpenJDK more appealing to developers.

Java Mission Control isn’t bundled with the JDK as of version 11, but it’s available as a separate download.

With a dummy application, we generated an OutOfMemoryError on purpose, captured a heap dump and a JFR recording, and analyzed the latter with JMC.

JFR and JMC are new to the OpenJDK’s open-source space, and OpenJDK 11 is also very recent at the time of writing. Therefore, some time must pass to allow these tools to mature.

Java Flight Recorder

Java Flight Recorder (JFR) is a monitoring tool that collects information about the events (pieces of data) in a particular instant of time in a Java Virtual Machine during the execution of an application.

Enable JFR for Oracle JDK 8 or later

Java Flight Recorder works on Oracle JDK builds starting from version 8 (providing that you have enabled commercial features) and on any JDK build starting from version 11.

To enable commercial features:

From the main menu, select Run | Edit Configurations and from the list on the left, select the run configuration that you want to analyze with JFR.

On the Configuration tab, expand the Environment section.

To the VM options field, add the following line: -XX:+UnlockCommercialFeatures .

The flag unlocks commercial features that are the products Oracle Java SE Advanced or Oracle Java SE Suite. Before enabling them, read Oracle Binary Code License Agreement for the JAVA SE Platform Products carefully.

Apply the changes and close the dialog.

JFR configurations

There are two pre-installed configurations: Default and Profile . The Default configuration has low overhead (about 1%). That’s why it works well for continuous profiling. The Profile configuration has overhead about 2% and can be used for more detailed application profiling.

These configurations cover most use cases. However, you can create and upload your own settings by means of Java Mission Control .

Create a new JFR configuration

Run Java Mission Control that you can find in JAVA_HOME/bin/jmc or download from builds.shipilev.net.

From the Java Mission Control main menu, select Window | Flight Recording Template Manager.

Click Import Files on the panel on the right and select one of the pre-installed configurations in the .jfc format:

For Java 10 and earlier: JAVA_HOME/jre/lib/jfr/

For Java 11 and later: JAVA_HOME/Contents/Home/lib/jfr/

Select Edit | Advanced , change the necessary settings, and click OK .

In the Flight Recording Template Manager dialog, click Export File .

Specify another name for the new settings file and change its location if necessary. Click Save .

For more information on how to configure custom settings, refer to Controlling Recording Data by Using Templates.

The default JAVA_HOME path on Windows: C:Program FilesJava , on macOS: /Library/Java/JavaVirtualMachines .

Load the custom configuration to the > In the Settings/Preferences dialog Ctrl+Alt+S , select Build, Execution, Deployment | Java Profiler .

Select the Java Flight Recorder profiling configuration to which you want to load your custom settings or create a new configuration by clicking .

In the Profiling Settings area, select the Custom settings file option and click .

Specify the path to the custom settings file and click Open .

Apply the changes and close the Settings/Preferences dialog.

Profile your application with JFR

Use any of the following options to analyze your application:

Click

From the main menu, select Run | Run with Profiler and then select the necessary configuration ( Run ‘run configuration name’ with ‘configuration name’ ).

When the profiling data is ready, you will see a confirmation popup together with the Profiler tool window bar. Click this bar to open the Profiler tool window or go to View | Tool Windows | Profiler if you don’t use tool window bars.

Диагностика утечек памяти в Java

Инструменты

Для успешной диагностики нам понадобятся два инструмента: Java Mission Control (jmc) и Eclipse Memory Analyzer. Вобщем-то можно обойтись только Memory Analyzer, но с JMC картина будет более полной.

• JMC входит в состав JDK (начиная с 1.7)
• Memory Analyzer может быть загружен отсюда: MAT

Анализ использования памяти

Прежде всего, нужно запустить приложение со следующими флагами JVM:
-XX:+UnlockCommercialFeatures
-XX:+FlightRecorder

Не используйте эти опции на production системе без приобретения специальной лицензии Oracle!

Эти опции позволят запустить Flight Recorder – утилита, которая поможет собрать информацию об использовании памяти (и много другой важной информации) во время выполнения программы. Я не буду описывать здесь как запустить Flight Recorder, эта информация легко гуглится. В моем случае было достаточно запустить FR на 10-11 минут.

Рассмотрим следующий рисунок, на котором показана классическая «пила» памяти, а так же важный сигнал, что что-то не так с использованием памяти:

Можно увидеть, что после каждого цикла очистки памяти, heap все больше заполняется, я выделил это желтым треугольником. «Пила» все время как бы ползет вверх. Это значит, что какие-то объекты не достижимы для очистки и накапливаются в old space, что со временем приведет к переполнению этой области памяти.

Выявление утечки

Следующим шагом нужно выявить, что именно не доступно для очистки и в этом нам поможет Memory Analyzer. Прежде всего, нужно загрузить в программу heap dump работающего приложения с предполагаемой утечкой памяти. Это можно сделать с помощью «File → Acquire Heap Dump». После загрузки в диалоге «Getting Started Wizard» выбрать «Leak Suspects Report» после этого откроется краткий обзор возможных утечек памяти:

Если вернуться на вкладку «Overview» и выбрать «Dominator Tree», то можно увидеть более подробную картину:

Дерево показывает структуру «тяжелого» объекта, а так же размер его полей (по типу). Можно видеть, что одно из полей объекта MasterTenant занимает более 45% памяти.

Устранение утечки

Имея результат анализа из предыдущего пункта, следующим шагом идет устранение накапливания объектом памяти. Тут все сильно зависит от конкретного кода. Общая рекоменация – нужно найти и проанализировать все места, где происходит инициализация или изменение соответствующего поля или полей, чтобы понять механизм накапливания памяти. В моем случае в коллекцию постоянно добавлялись записи из множества (около 150) потоков при определенных условиях.

После находжения и устранения утечки, не лишним будет пройти все шаги снова, проанализировать память и отчет Memory Analyzer, чтобы убедиться что фикс помог.