Java Flight Recorder Continuous Recordings

When we are trying to find performance issues, it is sometimes necessary to do continuous recordings with Java Flight Recorder.

Usually we debug issues in an environment similar to a production setup. That means we don't have a desktop environment and we cannot use Java Mission Control for flight recording.

That also means we need to record & get dumps using command line in servers. We can of course use remote connection methods, but it's more easier to get recordings from the server.

With continuous recordings, we need to figure out how to get dumps. There are few options.
  1. Get a dump when the Java application exits. For this, we need to use dumponexit and dumponexitpath options.
  2. Get a dump manually from JFR.dump diagnostic command via "jcmd"
Note: The "jcmd" command is in $JAVA_HOME/bin. If you use the Oracle Java Installation script for Ubuntu, you can directly use "jcmd" without including  $JAVA_HOME/bin in $PATH.

Enabling Java Flight Recorder and starting a continuous recording


To demonstrate, I will use WSO2 AS 5.2.1. First of all we need to enable Java Flight Recorder in WSO2 AS. Then we will configure it to start a default recording.

$ cd wso2as-5.2.1/bin
$ vi wso2server.sh

In VI editor, press SHIFT+G to go to the end of file. Add following lines in between "-Dfile.encoding=UTF8 \" and "org.wso2.carbon.bootstrap.Bootstrap $*"

    -XX:+UnlockCommercialFeatures \
    -XX:+FlightRecorder \
    -XX:FlightRecorderOptions=defaultrecording=true,disk=true,repository=./tmp,dumponexit=true,dumponexitpath=./ \

As I mentioned in my previous blog post on Java Mission Control, we use the default recording option to start a "Continuous Recording". Please look at java command reference to see the meanings of each Flight Recorder option.

Please note that I'm using disk=true to write a continuous recording to the disk. I'm also using ./tmp directory as the repository, which is the temporary disk storage for JFR recordings.

It's also important to note that the default value of "maxage" is set to 15 minutes.

To be honest, I couldn't exactly figure out how this maxage works. For example, if I set to 1m, I see events for around 20 mins. If I use 10m, I see events for around 40 mins to 1 hour. Then I found an answer in Java Mission Control forum. See the thread Help with maxage / limiting default recording disk usage.

What really happens is that maxage threshold is checked only when a new recording chunk is created. We haven't specified the "maxchunksize" above and the default value of 12MB is used. It might take a considerable time to fill the data and trigger removal of chunks.

If you need infinite recordings, you can set maxage=0 to override the default value.

Getting Periodic Java Flight Recorder Dumps


Let's use "jcmd" to get a Java Flight Recorder Dump. For this, I wrote a simple script (jfrdump)


#!/bin/bash
now=`date +%Y_%m_%d_%H_%M_%S`
if ps -p $1 > /dev/null
then
   echo "$now: The process $1 is running. Getting a JFR dump"
   # Dump
   jcmd $1 JFR.dump recording=0 filename="recording-$now.jfr"
else
   echo "$now: The process $1 is not running. Cannot take a JFR dump"
   exit 1
fi

You can see that I have used "JFR.dump" diagnostic command and the script expects the Java process ID as an argument.

I have used recording id as 0. The reason is that the default recording started from the wso2server.sh has the recording id as 0.

You check JFR recordings via JFR.check diagnostic command.

isuru@isurup-ThinkPad-T530:~/test/wso2as-5.2.1$ jcmd `cat wso2carbon.pid` JFR.check
21674:
Recording: recording=0 name="HotSpot default" maxage=15m (running)


I have also used the date for the recording name, which will help us to have multiple files with the date and time of the dump. Note that the recordings will be saved in the CARBON_HOME directory, which is the working directory for the Java process.

Let's test jfrdump script!

isuru@isurup-ThinkPad-T530:~/test/wso2as-5.2.1$ jfrdump `cat wso2carbon.pid`
2015_02_27_15_02_27: The process 21674 is running. Getting a JFR dump
21674:
Dumped recording 0, 2.3 MB written to:

/home/isuru/test/wso2as-5.2.1/recording-2015_02_27_15_02_27.jfr

Since we have a working script to get a dump, we can use it as a task for Cron.

Edit the crontab.

$ crontab -e

Add following line.

*/15 * * * * (/home/isuru/programs/sh/jfrdump `cat /home/isuru/test/wso2as-5.2.1/wso2carbon.pid`) >> /tmp/jfrdump.log 2>&1

Now you should get a JFR dump every 15 minutes. I used 15 minutes as the maxage is 15 minutes. But you can adjust these values depending on your requirements.

See also: Linux Crontab: 15 Awesome Cron Job Examples

Troubleshooting Tips

  • After you edit wso2server.sh, always run the server once in foreground (./wso2server.sh) to see whether there are issues in script syntax. If the server is running successfully, you can start the server in background.
  • If you want to get a dump at shutdown, do not kill the server forcefully. Always allow the server to gracefully shutdown. Use "./wso2server.sh stop"
  • You may not be able to connect to the server if you are running jcmd with a different user. Unless you own the process, following error might happen with jcmd.
isuru@isurup-ThinkPad-T530:~/test/wso2as-5.2.1$ sudo jcmd `cat wso2carbon.pid` help
[sudo] password for isuru: 
21674:
java.io.IOException: well-known file is not secure
 at sun.tools.attach.LinuxVirtualMachine.checkPermissions(Native Method)
 at sun.tools.attach.LinuxVirtualMachine.<init>(LinuxVirtualMachine.java:117)
 at sun.tools.attach.LinuxAttachProvider.attachVirtualMachine(LinuxAttachProvider.java:63)
 at com.sun.tools.attach.VirtualMachine.attach(VirtualMachine.java:214)
 at sun.tools.jcmd.JCmd.executeCommandForPid(JCmd.java:139)
 at sun.tools.jcmd.JCmd.main(JCmd.java:128)





Comments

Popular posts from this blog

Specifying a custom Event Settings file for Java Flight Recorder

Flame Graphs with Java Flight Recordings

Benchmarking Java Locks with Counters