Running Java Flight Recorder

There are few ways we can run JFR. For all the examples mentioned below, the sample “highcpu” program is used. The code is available at https://github.com/chrishantha/sample-java-programs/releases/tag/v0.0.1

Using the JFR plugin in JMC

Using the command line

Using the Diagnostic Command

Running JFR from JMC

You can use the Flight Recorder plug-in integrated into JMC to produce a Java Flight Recording. The GUI is very intuitive and you can follow the steps mentioned below in the JMC.

Right click on JVM and select “Start Flight Recording”. If it’s a remote JVM, you will have to create a “JVM Connection” first.

Select the type of recording: Time fixed / Continuous

Select the “Event Settings” template

Modify the event options for the selected flight recording template (Optional)

Modify the event details (Optional)

Running JFR from Command Line

In this section, let’s see how you can start a profiling recording and a continuous recording using command line options.

Please see “Advanced Runtime Options” for more information about all options mentioned in this section.

Starting a Profiling Recording

A “Profiling Recording” is a Time Fixed Recording with profile setting.

To produce a Time Fixed Recording from the command line, you can use “ - XX:StartFlightRecording ” option.

For example:

-XX:StartFlightRecording=delay=20s,duration=60s,name=Test,filename=recording.jfr,settings=profile

Let’s see how to use in “highcpu” sample program. Remember, you need to unlock commercial features and enable the Flight Recorder. You can also enable the non-safepoints debug flag.

Following example shows how to start a Profiling Recording for 60 seconds after 20 seconds of starting the JVM.

sample-java-programs/highcpu$ java -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:StartFlightRecording=delay=20s,duration=60s,name=Test,filename=recording.jfr,settings=profile -jar target/highcpu-0.0.1.jar

As mentioned previously, the setting file is available in $JAVA_HOME/jre/lib/jfr. You can also specify a path if you have a custom settings file. If you want to create a custom settings file and modify the events configuration, please check the blog post on “Specifying a custom Event Settings file for Java Flight Recorder”

If you need to see more Flight Recorder logs, you can use following option to change log level

-XX:FlightRecorderOptions=loglevel=info

Following is the output when running with above option.

sample-java-programs/highcpu$ java -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:StartFlightRecording=delay=20s,duration=60s,name=Test,filename=recording.jfr,settings=profile -XX:FlightRecorderOptions=loglevel=info -jar target/highcpu-0.0.1.jar

[jfr][INFO ][0.000] JFR log level set. Log level now at [INFO ]

[jfr][INFO ][0.085] Using /tmp/2016_11_30_14_07_03_490 as Flight Recorder repository.

Recording 1 scheduled to start in 20 s. The result will be written to: /home/isuru/work/git-projects/sample-java-programs/highcpu/recording.jfr

App [runHashing=true, runSleeping=true, runMath=true, hashingWorkers=6, sleepingWorkers=4, mathWorkers=2, hashDataLength=2000, hashingAlgorithm=SHA-1, exitTimeoutInSeconds=120]

Starting Application...

[jfr][INFO ][20.635] Starting recording [id=1, name=Test, destination=recording.jfr, start=Wed Nov 30 14:07:23 IST 2016, duration=60000ms]

[jfr][INFO ][82.069] Copied 134274993 bytes (before compression) to recording.jfr in 11 chunks

[jfr][INFO ][82.069] Stopped recording [id=1, name=Test, destination=recording.jfr, start=Wed Nov 30 14:07:23 IST 2016, end=Wed Nov 30 14:08:23 IST 2016, duration=60000ms]

Exiting now...

[jfr][INFO ][120.775] Flight Recorder repository deleted

In above output, you can see that JFR is using a temporary directory called “repository”. JFR use that directory to save the recording temporarily in the disk.

Starting a Continuous Recording

You can start a Continuous Recording from the command line using “ -XX:FlightRecorderOptions=defaultrecording=true ”. This is also called “The Default Recording”

As mentioned previously, you can start a Continuous Recording that can later be dumped only if needed.

When you want to run a continuous recording, you have two options to limit the amount of data you need.

Set the maximum size (in bytes) of disk data to keep for the default recording using the maxsize parameter. Set the maximum age of disk data to keep for the default recording using the maxage parameter.

Above two parameters are value only if you set the disk=true parameter.

Please keep in mind that the thresholds are checked only when a new recording chunk is created. You can specify the recording chunk size using maxchunksize parameter. The default value is 12MB . Since the default recording doesn’t have lot of events, it might take a considerable time to fill the data and trigger removal of chunks. For example, if you use maxage=10m , you might get events for around 40 minutes to 1 hour.

See the following example to start a continuous recording with 2 hours of data. The temporary data will be stored in the disk.

-XX:FlightRecorderOptions=defaultrecording=true,disk=true,repository=/tmp,maxage=2h

Let’s use above options with the sample program.

sample-java-programs/highcpu$ java -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:FlightRecorderOptions=defaultrecording=true,disk=true,repository=/tmp,maxage=2h -jar target/highcpu-0.0.1.jar

In order to get a dump from a continuous recording, you need to manually dump using JMC or diagnostic command. You can refer next section to see how diagnostic commands are used.

When you want to dump the recording, you need to specify a new location. The files in the repository are only temporary.

When you enable the default recording, you can also get a dump on exit.

You can use following options to get a flight recording when the program exits.

-XX:FlightRecorderOptions=defaultrecording=true,dumponexit=true,dumponexitpath=/tmp/dumponexit.jfr

Please note that only the default recording can be used with the dumponexit and dumponexitpath parameters

Example:

sample-java-programs/highcpu$ java -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:FlightRecorderOptions=defaultrecording=true,disk=true,repository=/tmp,maxage=2h,dumponexit=true,dumponexitpath=/tmp/dumponexit.jfr,loglevel=info -jar target/highcpu-0.0.1.jar — exit-timeout 10

[jfr][INFO ][0.000] JFR log level set. Log level now at [INFO ]

[jfr][INFO ][0.047] Using /tmp/2016_11_30_14_20_51_983 as Flight Recorder repository.

[jfr][INFO ][0.455] Starting recording [id=0, name=HotSpot default, start=Wed Nov 30 14:20:51 IST 2016, maxAge=7200000ms]

App [runHashing=true, runSleeping=true, runMath=true, hashingWorkers=6, sleepingWorkers=4, mathWorkers=2, hashDataLength=2000, hashingAlgorithm=SHA-1, exitTimeoutInSeconds=10]

Starting Application…

Exiting now…

[jfr][INFO ][10.547] Dump on exit: recording 0 ‘HotSpot default’

[jfr][INFO ][10.563] Starting recording [id=1, name=dump-on-exit-clone-of-0, start=Wed Nov 30 14:20:51 IST 2016]

[jfr][INFO ][10.645] Stopped recording [id=1, name=dump-on-exit-clone-of-0, start=Wed Nov 30 14:20:51 IST 2016, end=Wed Nov 30 14:21:01 IST 2016]

[jfr][INFO ][10.665] Copied 673595 bytes (before compression) to /tmp/dumponexit.jfr in 2 chunks

[jfr][INFO ][10.685] Stopped recording [id=0, name=HotSpot default, start=Wed Nov 30 14:20:51 IST 2016, end=Wed Nov 30 14:21:02 IST 2016, maxAge=7200000ms]

[jfr][INFO ][10.686] Flight Recorder repository deleted

Running JFR using Diagnostic Commands

The “ jcmd ” utility in JDK can be used to send diagnostic command request to the JVM. With jcmd , you can control Java Flight Recordings.

For more details on jcmd syntax and other usage details, see the jcmd command man page.

When you just run jcmd , you will see a list of java processes running in the system.

Let’s run the sample program as follows.

java -jar target/highcpu-0.0.1.jar --hashing-workers 1 --math-workers 1 --sleeping-workers 1 --exit-timeout 0

Following is the output of jcmd .

$ jcmd

3586 target/highcpu-0.0.1.jar --hashing-workers 1 --math-workers 1 --sleeping-workers 1 --exit-timeout 0

3619 sun.tools.jcmd.JCmd

To send diagnostic command requests to the JVM, you can use following syntax.

jcmd <process id/main class> <command> [options]

The help command shows all available commands.

$ jcmd highcpu help

3586:

The following commands are available:

JFR.stop

JFR.start

JFR.dump

JFR.check

VM.native_memory

VM.check_commercial_features

VM.unlock_commercial_features

ManagementAgent.stop

ManagementAgent.start_local

ManagementAgent.start

GC.rotate_log

Thread.print

GC.class_stats

GC.class_histogram

GC.heap_dump

GC.run_finalization

GC.run

VM.uptime

VM.flags

VM.system_properties

VM.command_line

VM.version

help For more information about a specific command use 'help <command>'.

Dynamically Enabling JFR from diagnostic commands

With diagnostic commands, you can dynamically enable flight recorder.

You can use VM.check_commercial_feature command to check whether commercial features are unlocked.

$ jcmd highcpu VM.check_commercial_features

3586:

Commercial Features are locked.

With VM.unlock_commercial_features command, you can unlock commercial features.

See following example for unlocking commercial features.

$ jcmd highcpu VM.unlock_commercial_features

3586:

Commercial Features now unlocked.

If you run the same command again, it will say that commercial features are already unlocked.

When you run the VM.check_commercial_features command again, it will show the status of individual features.

$ jcmd highcpu VM.check_commercial_features

3586:

Commercial Features are unlocked.

Status of individual features:

Java Flight Recorder has not been used.

Resource Management is disabled.

Current Memory Restriction: None (0)

Now you can use the JFR.start diagnostic command to enable the Flight Recorder.

Starting a recording with diagnostic commands

See the following example for starting a Profiling Recording.

jcmd highcpu JFR.start settings=profile delay=20s duration=60s name=Test filename=recording.jfr

For more information about options, try the following command.

jcmd highcpu help JFR.start

You can use JFR.check command to check running Java Flight Recordings.

For example:

$ jcmd highcpu JFR.check

3586:

Recording: recording=1 name="Test" duration=1m filename="recording.jfr" compress=false (running)

If you want to start a Continuous Recording, you can use following command.

jcmd highcpu JFR.start defaultrecording=true

Following is the output of above command.

3586:

Started recording "HotSpot default"

Use JFR.dump recording=0 filename=FILEPATH to copy recording data to file.

When you start a “Default Recording”, the JFR will use “HotSpot default” as the name and its recording number will be always zero.

Dumping Flight Recordings

You can use JFR.dump command to get a JFR dump

See the following example to get a dump from default recording.

jcmd highcpu JFR.dump recording=0 filename=default.jfr

When dumping, you can either specify the recording number or the recording name.

It seems that spaces are not allowed for the recording name when using diagnostic commands. So, you will not be able to get a dump from the default recording using the name. However, if you start any other recording with a name, you can get a dump using the name.

For example, let’s start a Profiling Recording for two hours.

jcmd highcpu JFR.start settings=profile duration=2h name=Profiling

You can get a dump whenever you want.

jcmd highcpu JFR.dump name=Profiling filename=profiling.jfr

Stopping a recording

You can also stop a running recording using JFR.stop command.

For example:

jcmd highcpu JFR.stop name=Profiling

If you want, you can also stop the default recording.