Creating Flight Recordings

With the Hotspot JDK 7u40 there is a nifty new tool called Java Mission Control. Users of the nifty old tool JRockit Mission Control will recognize a lot of the features. This particular blog entry focuses on the Java Flight Recorder and various ways you can go about to create a flight recording.

In the last blog entry about the method profiler I showed that Mission Control can be quite useful for profiling production systems. However, I only showed one way to produce the actual recording.

There are several different ways to produce a recording, all of them useful in a certain context. But before we get into that, we should first discuss the two different kinds of recordings.

Continuous Recordings

Continuous recordings are not only very hard to spell, they are also very common in production systems. Well, if Java Flight Recorder will be used anything like the JRockit equivalent, at least they will be. Continuous recordings have no end time and will keep recording until the JVM shuts down, or someone tells it to end. This kind of recording can be dumped at any point in time when access to the data being recorded is needed.

Time Fixed Recordings

Also known as profiling recordings, these recordings run for a fixed amount of time and then automatically end themselves. These typically use templates that enable costlier events, since the performance penalty will only be suffered for a limited duration of time.

Note that it is perfectly feasible to have several recordings running in parallel. It is even quite common. Which brings me to the first quirkiness of the Java Flight Recorder: Recordings active at the same time share the same buffers!

It may be easier to consider recordings to be named sets of Event Type settings, i.e. settings of what to record, that are being pushed and popped from the recording engine. At any given time, the union of the settings dictates what will be recorded.

Here is an example:
A continuous recording R0 is started at T0 with settings S0. After a while, a time fixed recording R1 is started at T1 with settings S1, where S1 ⊃ S0. The time fixed recording R1 ends at T2. This is what will be recorded:

Time Settings
T0→T1 S0
T1→T2 S0 ∪ S1
>T2 S0

Note that this means that if you dump the continuous recording R0 for a time range intersecting [T1,T2], you will actually find that you are getting information in your “recording” that you did not ask for in the settings (S0). All this in the name of performance. Blinkar Once T2 arrives, the settings for R1 will be popped, and we’re back to just recording S0.

Now, one last reminder before getting back to the actual recording:

The 1st Rule of Flight Recording*
Thou Shalt Never Forget to Start Your JVM with
-XX:+UnlockCommercialFeatures -XX:+FlightRecorder

RAmen!
(* Only required in HotSpot. With JRockit, no command line flags are required.)

Creating a Recording from Within Mission Control

This is probably the easiest way to produce a recording, since you get help both with connecting to the JVM from which you want the recording, and a nice wizard that helps you to select what to record. I went through the recording wizard in the blog entry about the method profiler, so I will not repeat that here. I will just note that the template settings that you arrive at can be exported from Mission Control, and then stored server side so that anyone connecting to that JVM though Mission Control will have access to it. Simply create a recording with the settings you would like to store, next go to the Template Manager, select the template marked as “ – last saved” and hit Export. Then put the exported file in the jre/lib/jfr folder of the JVM where you want to make the template available.

Creating a Recording Using Command Line Arguments

This is quite useful when you want to record the start up behaviour of an application, or when you want to make sure that your application always starts with a continuous recording running. Since I am a staunch believer of examples, I’ll simply give three examples.

Here is an example of how to start a one minute time fixed recording, 20 seconds after the JVM has started, using the profile template :
-XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:StartFlightRecording=delay=20s,duration=60s,name=MyRecording,filename=C:\demo\myrecording.jfr,settings=profile

Note that the settings parameter either takes a path to a template, or the name of a template which must be available in the jre/lib/jfr folder of the JVM.

Here is an example on how to start a continuous recording, using the default template:
-XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:StartFlightRecording=name=MyRecording,settings=default

Note that in the second example we do not specify any file name. The data will need to be dumped on request, either using Mission Control or jcmd, or possibly by using the dump-on-exit parameters to make the JVM dump the recording when exiting the JVM, like this:
-XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:FlightRecorderOptions=defaultrecording=true,dumponexit=true,dumponexitpath=c:\demo\dumponexit.jfr

For more information on the available parameters, see the Java Command Line Reference.

Creating a Recording Using JCMD

You can also control the Flight Recorder even after you have started the java process (as long as you adhere to the 1st Rule of Flight Recording) using JCMD. The JCMD utility is in the JAVA_HOME/bin folder and allows you to enumerate the locally running Java processes, and send commands to them. Just running jcmd will list the running Java processes and their PIDs:

C:\Java\jmc5.2labs>jcmd
4711 LoadAndDeadlock
1276 sun.tools.jcmd.JCmd

To query a certain JVM for the available commands, use “help”:


C:\Java\jmc5.2labs>jcmd 7484 help
7484:
The following commands are available:
JFR.stop
JFR.start
JFR.dump
JFR.check
VM.native_memory
VM.commercial_features
ManagementAgent.stop
ManagementAgent.start_local
ManagementAgent.start
Thread.print
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>'.

Here is an example which starts a continuous recording from the command line using JCMD (assuming that the PID of the Java process you want to record on is 4711):

C:\Java\jmc5.2labs>jcmd 7484 JFR.start name=MyRecording settings=default
4711: Started recording 1. No limit (duration/maxsize/maxage) in use.

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

The JFR.check command can be used to check the status of the recordings:

C:\Java\jmc5.2labs>jcmd 4711 JFR.check
4711:
Recording: recording=1 name="MyRecording" (running)

To dump the recording:

C:\Java\jmc5.2labs>jcmd 4711 JFR.dump name=MyRecording filename=C:\demo\jcmddump .jfr
4711:
Dumped recording "MyRecording", 180.3 MB written to:

C:\demo\jcmddump.jfr

Then you can just drag and drop the resulting file into Mission Control to view the contents:

 pretty
(No blog post is complete without a Pretty Picture™.)

Further reading and useful links

Related Blogs:
Java Mission Control Finally Released
My JavaOne 2013 Sessions
Low Overhead Method Profiling with Mission Control

The Mission Control home page:
http://oracle.com/missioncontrol

Mission Control Base update site for Eclipse:
http://download.oracle.com/technology/products/missioncontrol/updatesites/base/5.2.0/eclipse/

Mission Control Experimental update site (Mission Control plug-ins):
http://download.oracle.com/technology/products/missioncontrol/updatesites/experimental/5.2.0/eclipse/

The Mission Control Facebook Community Page (not kidding):
http://www.facebook.com/pages/Java-Mission-Control/275169442493206

Mission Control on Twitter:
@javamissionctrl

Me on Twitter:
@hirt

54 Responses to "Creating Flight Recordings"

  1. Mike says:

    Markus, thank you for your great work on JFR and useful posts popularizing Flight Recordings.
    We are all waiting for you at JavaOne 2014 in Russia and new edition of your book “Oracle JRockit: The Definitive Guide”!

  2. Marcus says:

    Thanks Mike! I don’t think there will be a new edition of Oracle JRockit: The Definitive Guide, but there might be something else on the way. 😉

  3. Bill says:

    Hi,

    Thanks for your great postings about using Hotspot together with JMC! I have one remark. I think there are some options missing in your example where you outline how to make the JVM dump a contiuous recording when exiting. I have to use at least the following options:


    -XX:+UnlockCommercialFeatures
    -XX:+FlightRecorder
    -XX:StartFlightRecording=name=default,settings=default
    -XX:FlightRecorderOptions=dumponexit=true,dumponexitpath=C:\jmc\finished\dump.jfr,defaultrecording=true,disk=true,repository=C:\jmc\temp\

    Best regards,
    Bill

  4. Marcus says:

    Quite true Bill! The defaultrecording parameter must be set!

  5. This looks fantastic!
    Where could I get some information about how to start a session on-demand? (instead of all the boot-time arguments or with the jcmd command-line tool)

    We have a javaagent that monitors JVMs and I’m wondering if, assuming we could talk to this agent in some fashion, we could tell it “start now, run for 60 seconds,…, dump the output to /tmp/foo.jfr”?

    Also, is there any information about how to parse and interpret the eventual dump with the collected info?

    Thank you!

  6. Marcus says:

    Hi Otis!

    In JDK 8 there is an MBean allowing you to execute diagnostic (jcmd) commands. I’ll write a blog on using it once JDK 8 is out. There is currently no supported way to parse recordings, but I may write a blog on how to use the Mission Control parser to do it (after JavaOne, too busy now).

    Kind regards,
    Marcus

  7. Bill says:

    Hello Marcus,

    I want to profile a program which takes some time to run (approx. 24h). I have already enabled continuous recordings successfully. The recordings are written to disk. The JVM start-up parameters which I use are outlined in my previous post (Friday, September 13, 2013).

    The problem is, that the recording only contains data from approx. the last three hours of the program run. Is there something like a -maxRecordingDuration for the Java Flight Recorder?

    Kind regards,
    Bill

  8. Marcus says:

    Yep, but I don’t recall it defaulting to anything other than unlimited. There is also a size limit that can be set, but again I don’t think it’s set to anything other than unlimited by default. Please ask in the official JMC forum, and I’m sure that someone will help. (And if no one bites, I promise to take a look myself.)

  9. Bill says:

    Hello Marcus,

    I found a solution for my problem posted on September 30, 2013 at 11:00.

    The documentation says that {{{maxage}}} and {{{maxsize}}} default to values which result in unlimited continuous recordings. This is not true. You have to set this parameters explicitely. Otherwise the recordings contain only data for the last few hours. This is true as of Java 7u40.

  10. John says:

    What are the license implications of using “-XX:+UnlockCommercialFeatures” in the JDK ? Any docs/links ?

  11. admin says:

    You may not use commercial features in production without obtaining a license from Oracle.
    http://www.oracle.com/technetwork/java/javase/terms/license/index.html

    (Disclaimer: I’m a techie so you should probably ask someone else.)

    Kind regards,
    Marcus

  12. admin says:

    Great that you found a solution! Not so great that the docs aren’t up to date. I will forward this information (i.e. create a bug report).

    Kind regards,
    Marcus

  13. Zim says:

    Hi Marcus, I went through some of your recordings. Being very new to performance monitoring and handling JRMC initially is a pretty big deal, but interesting nonetheless. The question I wanted to ask is that, what options and MBeans related to the JRockit JVM can I change during Runtime (during a flight recording), other than just GC strategies and heap size. I’ve been exploring but can’t quite come up with more. Appreciate your help.

    -Zim

  14. metin says:

    Thank you for your useful article.
    When I finished flight recording I can not open file. The problem is :

    Could not load events from flight_recording_2013-12-11_11_15_09.jfr
    java.lang.IllegalArgumentException: com.sun.org.apache.bcel.internal.generic.ClassGenException: Illegal opcode detected.
    What may be my problem?

  15. admin says:

    Not sure. I haven’t seen that before. Can you send me the recording?

    Kind regards,
    Marcus

  16. admin says:

    Hi Zim,

    JRockit is no longer in active development. That said, on the MBean API side of things, there are some interesting things you could do with JRockit (such as changing GC strategy dynamically and changing the target heap size), that you cannot do with HotSpot. And yes, there are a few other things, such as counting method invocations and seeing method invocation times on a per method basis. Also, the on-line Memleak Analysis Tool that was available for JRockit is not yet available for HotSpot. That said, HotSpot is our base platform going forward. If you want to check on our progress with the convergence between the JRockit and HotSpot platforms, download 7u40 and have a look at Java Mission Control.

    Also, just wanted to point out that the Flight Recorder and the JMX Console are two different things. If you haven’t played with the Flight Recorder yet, you’re in for a treat. 🙂

    Kind regards,
    Marcus

  17. metin says:

    Hi Marcus;
    My record file is there : https://drive.google.com/folderview?id=0ByhJGUfO_djHNm9YMnZOWDZVWGM&usp=sharing

    Thak you so much,
    Metin

  18. Marcus says:

    Hi Metin,

    Your file opens just fine for me. Which version of the JMC client are you trying to use to open the file?

    Kind regards,
    Marcus

  19. AN says:

    Hi

    Does this feature work in OpenJDK Hotspot VM? I seem to be getting unrecognized vm option error for -XX:+UnlockCommercialFeatures

  20. Marcus says:

    The Java Flight Recorder features requires the Oracle JDK.

  21. Gster says:

    got the same problem as metin.

    Could not load events from my_flight{record_file_path.jfr
    com.jrockit.mc.flightrecorder.internal.parser.binary.InvalidFlrFileException

  22. Sebastian says:

    Hi Markus,
    thanks for all your work. I have a question regarding a lot of Methods which are shown as “Unknown” in the Call Tree View. I am a beginner in Profiling and have no clue what could be an explanation.
    I found a setence in the JFR Runtime Guide which could be connected but I don’t understand it fully:
    “In some cases, the JVM drops the event order to ensure that it does not crash. Any data that cannot be written fast enough to disk is discarded.” Is there somewhere a further explanation on that?
    Here a picture of my profiling file:
    http://www.directupload.net/file/d/3830/7a8cf6cc_png.htm

  23. Marcus says:

    Hi Sebastian,

    If the pressure on the recording engine is too high, it will prefer dropping data to halt the runtime. This is for performance reasons. That said, I’ve never seen this happening in a real life recording. Also, JFR will emit special buffer lost events to indicate that data was lost, so you should be able to see this in your recording.

    Also, for your unknown methods, did you try this: http://hirt.se/blog/?p=609

    Kind regards,
    Marcus

  24. Sebastian says:

    Hi Markus,
    thanks for your fast reply! In my JFR-File I don’t see any buffer lost events. (Where and how would I see them?)
    I used the following parameters: -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints -XX:FlightRecorderOptions=defaultrecording=true,dumponexit=true,dumponexitpath=javaFlightRecording.jfr
    I started the recording the same program again without changing anything and I got a totally different picture. But still there are a few unclassifiable and unknown methods. Here is a picture:
    http://www.directupload.net/file/d/3831/xs7eqev4_png.htm
    Is there anything I can do about it?

    Furthermore, I recognized that the total Sample Count is around 400 in 8 minutes. In a simple program (calculating Fibonacci numbers recursivly) for testing JFR I wrote, I got a Sample Count of around 500 in only 18 seconds. This makes me wonder, since I thought the Samples are like cuts through the JVM in always the same pulse. I expected that an 8 minute recording must have considerably more Samples than an 18 second recording.
    Do you have an explanation for me? Thanks in advance!

  25. Marcus says:

    Hi Sebastian,

    If you have very little load on your machine, there will be very few samples. The method profiler is sampling threads busy doing something, i.e. contributing to the load of the machine. Halted threads will not contribute. If you do not have high CPU saturation caused by the JVM process, the method profiling information is of less interest.

    Which exact version are you running on? There was a bug introduced in JDK 7u60 (https://bugs.openjdk.java.net/browse/JDK-8038497), which is resolved in JDK 7u80.

    Kind regards,
    Marcus

  26. Sebastian says:

    Hi Marcus (sorry for the previous spelling mistakes in your name -.-),
    I am running on version 1.7.0_71-b14 locally (Win7) and on the Jenkins server (Linux) where I also integrated JFR I am running on 1.7.0_65-b33.
    What effect does the bug you posted have on the samples? Unfortunately the description to the bug is missing. Is this bug limited to the OpenJDK or does it affect the OracleJDK as well? (There is a difference I thought…)
    Furthermore, I have seen that there is a bug which shall lead to fewer samples which is referenced to here: https://community.oracle.com/thread/2579717 (Q: Why do I get a lot fewer method samples then I expected?) Is this the same bug you have been talking about?

    Thanks in advance!

  27. Marcus says:

    IIRC there are two bugs. One can give you less samples than you would expect, and one can give you a timestamp offset between event types using different ways of retrieving timestamps. As far as I can tell, the former should be fixed in 7u60, and the latter in 7u80. If you have a high JVM process load, you should get enough sample points.

  28. Sebastian says:

    Hi Markus,
    once again I have a question regarding the Method Samples. Is there a possibility to change the Method Sampling interval to below 10 ms?

    In the “Flight Recording Template Manager” of JMC I can choose three levels of Method Sampling: Off, Normal and Maximum, where Maximum is connected to the value “10 ms” in the Template-XML-File.

    999 d
    20 ms
    10 ms

    true
    10 ms

    When I manually change this value 10 ms – either through the GUI in the “Advanced” window of the Flight Recording Template Manager or directly in the template-XML-File – I see the following behaviour:
    A value above 10 ms works as expected. The sum of the samples went down.
    With a value below 10 ms the Flight Recorder does not record anything anymore. The created dump file is of the size 30 kb and when I open it with JMC I get the message “This Flight Recording has no Recording Settings events.”.

    I turned off the other options in the Template-File (Garbage Collector, Compiler, Thread Dump and Exceptions). The JVM-Parameter I used are the following: -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints -XX:StartFlightRecording=settings=$WORKSPACE/jfrSettings.jfc,defaultrecording=true -XX:FlightRecorderOptions=dumponexit=true,stackdepth=512,dumponexitpath=$WORKSPACE/reports/

    Thanks for your help!

  29. Marcus says:

    Hi Sebastian,

    Which version were you running?

    Kind regards,
    Marcus

  30. Marcus says:

    A member of the serviceability team said the current implementation has a limit at 10ms. Seems there is a limit in the OS timer task they are currently using.

  31. James Donaldson says:

    Thank you so much for this documentation. I am running a POJO java application on Linux and was unable to connect to Flight Recorder on my PC. The “Creating a Recording Using Command Line Arguments” section allowed me to profile the app. Need to process 50 million records in less than an hour and had a performance issue that was not scaling. No matter how many threads the performance did not improve due to blocking by PrintStream (System.err.println). You saved me! Now that we know the problem there are several easy solutions to fix it and restore the scalability of this app.

  32. Marcus says:

    Glad we could help! 🙂

    /M

  33. Sattish says:

    Hi Marcus,

    While trying to record a session using Flight recorder, i am experiencing a error related to loading of SAXParserFactory

    Provider com.ebay.raptor.xmlfactorywrapper.SAXParserFactoryWrapper not found

    But i was able to connect to JMX console and able to gather all JVM metrics

    Platform :
    JDK used in client side 1.8 update 60 on windows 7
    Server Side JDK 1.7 update 40 on Redhat 5.2 linux platform
    Tomct Servlet Container

    Tried adding this system parameter to the JVM options
    Djavax.xml.parsers.SAXParserFactory=com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl
    But still the same error

    Could you please review and let me know how we can handle this

    Thanks
    sattish.

  34. Marcus says:

    Hmmm. -Djavax.xml.parsers.SAXParserFactory=com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl should do the trick. Check your recording to verify that the system property really was set.

  35. Sattish says:

    Hi Marcus,

    I tried by setting this property option in JVM arguments but still the same but things worked well when i used Java 1.7 update 45. Not sure whats the difference between 1.7.0_45 with 1.8.0_60

    Thanks
    sattish.

  36. Jan Luehe says:

    Hi Marcus, would it be possible to make the “filename” argument to JFR.dump optional, and have the recording output to stdout if “filename” was missing? We are profiling a Java application that is running inside a Docker container, and would like to avoid having to store the recording inside the container.

    Thanks for any insight you may have.

    Regards,

    Jan

  37. Manish says:

    Hi Everyone,

    I have .jfr file which I want to open using command-line in windows/linux machine. I tried it by giving command e.g. d:\JRMC\bin>jrmc ABC.jfr
    But using this command JRMC application opened but my jfr file “ABC.jfr” is not got opened in JRMC.

    Please let me know how to open jfr file using command line?

    Thanks,
    Manish

  38. admin says:

    I don’t remember if this was the same in jrmc, but with jmc you can do jmc -open ABC.jfr.

  39. Prithvi says:

    Hi Marcus,

    I enabled JFR today on my weblogic 12.2.1.2 (running on Linux) by adding the below parameter to setDomainEnv.sh file.

    JAVA_PROPERTIES=”${JAVA_PROPERTIES} -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:FlightRecorderOptions=repository=/u04/test/jfrlogs”
    export JAVA_PROPERTIES

    After restart I’m able to start the recording using jcmd JFR.start, however, the file is not getting created in the repository location that I have specified. Am I missing anything here? Can you please suggest.

    jcmd 31039 JFR.start duration=30s filename=test_critical.jfr
    31039:
    Started recording 13. The result will be written to:
    //test_critical.jfr

  40. Marcus says:

    The repository location is used by jfr internally, for example when maxage or maxsize is used. It is not the folder where your files will be emitted when done. Have you tried specifying an absolute path for your filename?

  41. Prithvi says:

    Thanks Marcus for your reply.
    Yes when I explicitly mention the file location, it creates the jrf file there. But I thought repository parameter helps me to set a default location for jfr file even when I run the record manually. Isn’t that the case?

  42. Marcus says:

    The repository location is internal to the workings of JFR. It is where the JVM will keep data when chunks are emitted to disk.

  43. Prithvi says:

    Thank you Marcus for the clarification.

  44. Roy Zhang says:

    Hi Marcus,

    I add JFR in java start up opts, and I define dumponexit, so will JFR dump all the data from the beginning when exit JVM?

    Thanks,
    Roy

  45. Marcus says:

    Hi Roy,

    That depends on how you’ve configured JFR. If you’ve configured JFR to go to disk and set the limits to suitable value (IMHO you should always have a reasonable limit that makes sense, either size or time or both) that covers the entire run, then yes, it normally would. See the JVM documentation for more information on the JVM flags.

    Also, the JVM can crash so that the final copy of the information does not get dumped to a single file at the target destination. Luckily the files in the repository (normally in tmp) are all self contained JFR chunks, and can still be read and used.

  46. Phil says:

    Hi Marcus

    In your comments to Roy, you mentioned

    “Luckily the files in the repository (normally in tmp) are all self contained JFR chunks, and can still be read and used”

    Are you referring to the part file JFR generates to the repository directory? if so how can the part files be read and used?

    Thanks

    Phil

  47. Marcus says:

    Partially written chunks are harder to do much with, but not impossible. But a fully written chunk is in itself a little flight recording, and can be opened as such. The repository will normally contain such little .jfr files, one .part file (which is the currently worked upon chunk) and a zero sized placeholder .jfr file for when the .part file is completed.

  48. Phil says:

    We have been thrown at the deep end of investigating a sudden JVM termination (killed by a wrapper process), all we’ve left with is a part file of JFR, i.e. a chunk that didn’t get the chance to be fully written to jfr file. The part file seems to be in a binary format, it’s much appreciated if you could share some docs or online references regarding parsing part file of JFR if there’re any.

    Thanks

  49. Marcus says:

    Not easy to do much unless you have a full chunk. The metadata describing the binary contents are written towards the end of the chunk (at least for versions up to and including JDK 11), and without that metadata, the binary information cannot be parsed. You could perhaps manually use the metadata from a previous chunk, and try to patch up the part file, but that requires luck, trial and error, and quite likely running the parser in debug mode to figure out what to patch and where.

  50. Erdinc Taskin says:

    I got same problem with Metin as follows. I found that error due to operation system (for me MacOs) language is Turkish. When change OS language as English problem has been resolved.

    java.lang.IllegalArgumentException: com.sun.org.apache.bcel.internal.generic.ClassGenException: Illegal opcode detected.

Leave a Reply

Your email address will not be published. Required fields are marked *