Parsing Flight Recordings – an Example

This blog post is the third in a series of posts on using unsupported functionality in the Oracle JDK and/or Java Mission Control.

I will use the JMC flight recorder parser in this example, and since the JMC parser is unsupported I’ll just go ahead and use my usual disclaimer:

The following blog entry will describe UNSUPPORTED functionality. This means that relying on the described APIs or functionality may BREAK your code/plugin with any given update of the JDK and/or Mission Control.

I strongly recommend against using these APIs in production code. There will be supported APIs for reading reading recordings eventually and they may be quite different to what I show here. Also note that older versions of the parsers are not guaranteed to be forward compatible with newer versions of the binary format. In short, this is NOT supported and WILL CHANGE!

You may want to first read the introduction to the JFR parsers and about the relational key before continuing.

Ready? Here we go…

A Flight Recording

First off we need a recording to parse. If you have your own favourite recording, you’re all set. If you don’t you can have mine. The recording I linked to is a recording of WLS running the MedRec example app with some load. The benefit of using that recording is that it, aside from the standard events, also contains events provided by the Java API for creating third party events (by the WebLogic Diagnostics Framework). Quite useful events, all bound together using the relational key in various ways. Don’t forget to unzip the recording before use.

The recording is pretty new and really requires a JMC 5.3.0 with the WLS plug-in for the best result. JMC 5.3.0 has not been released yet, but don’t worry; this blog entry will not even require you to start JMC.

That said, since all blog posts require a pretty picture, here is one of the servlet invocations in the recording:
servlets

Looking at Metadata

Let’s first write a little program that lists the available event types and their metadata. Use the knowledge obtained in the JFR parser blog entry to obtain a copy of the JMC Flight Recorder Parser.

Next, use the example below to iterate through the metadata and print out the event type name, all the attributes and the relational key for the the individual attributes:

import java.io.File;
import java.util.Collection;

import com.jrockit.mc.flightrecorder.FlightRecording;
import com.jrockit.mc.flightrecorder.FlightRecordingLoader;
import com.jrockit.mc.flightrecorder.spi.IEventType;
import com.jrockit.mc.flightrecorder.spi.IField;

public class FlightRecorderMetaData {
    public static void main(String[] args) throws ClassNotFoundException {
        FlightRecording recording = FlightRecordingLoader.loadFile(new File("C:\\demo\\wldf.jfr"));

        for (IEventType type : recording.getEventTypes()) {
            System.out.println(type.getName());
            printAttributes(type.getFields());
        }
    }

    private static void printAttributes(Collection<IField> fields) {
        for (IField field : fields) {
            System.out.println(String.format("   %s (relkey: %s)", field.getName(), field.getRelationalKey()));
        }
    }
}

Here is a slightly more convoluted example, printing everything out in a nice tree, also showing how many events were found per event type plus some additional stats. It takes a flight recording as its only argument.

Using the Relational Key

Looking at the metadata for the WLDF recording, it can be seen that a lot of the event attributes provided with the WLDF specific events are actually using the relational key for various different things. There is a relational key for servlet URIs, there is another one for the ECID (Enterprise Context ID) and so on. Let’s say we wanted to find all the events with a relational key for ECID, and then group them on ECID (effectively grouping the events per transaction). That could look something like this:

import java.io.File;
import java.util.ArrayList;
import java.util.Collection;
import java.util.HashMap;
import java.util.LinkedList;
import java.util.List;
import java.util.Map;
import java.util.Map.Entry;

import com.jrockit.mc.flightrecorder.FlightRecording;
import com.jrockit.mc.flightrecorder.FlightRecordingLoader;
import com.jrockit.mc.flightrecorder.spi.IEvent;
import com.jrockit.mc.flightrecorder.spi.IEventType;
import com.jrockit.mc.flightrecorder.spi.IField;
import com.jrockit.mc.flightrecorder.spi.IView;

public class FlightRecorderECID {
    private static final String KEY_ECID = "http://www.oracle.com/fmw/ECID";

    public static void main(String[] args) throws ClassNotFoundException {
        FlightRecording recording = FlightRecordingLoader.loadFile(new File("C:\\demo\\wldf.jfr"));    

        Collection<IEventType> ecidTypes = new LinkedList<>();
        for (IEventType type : recording.getEventTypes()) {
            if (type.getPath().startsWith("wls/")) { // just optimization, can remove
                if (hasECID(type)) {
                    ecidTypes.add(type);                   
                }
            }
        }
       
        IView ecidView = recording.createView();
        ecidView.setEventTypes(ecidTypes);
        Map<String, List<IEvent>> eventMap = buildEventMap(ecidView);
       
        System.out.println("ECIDS:");
        for (Entry<String, List<IEvent>> ecid : eventMap.entrySet()) {
            System.out.println(String.format("%s [%d events]", ecid.getKey(), ecid.getValue().size()));
        }
    }

    private static Map<String, List<IEvent>> buildEventMap(IView ecidView) {
        Map<String, List<IEvent>> map = new HashMap<>();
        for (IEvent event : ecidView) {
            String ecid = getEcid(event);
            if (ecid != null) {
                addToMap(map, ecid, event);
            }
        }
        return map;
    }

    private static void addToMap(Map<String, List<IEvent>> map, String ecid, IEvent event) {
        List<IEvent> eventList = map.get(ecid);
        if (eventList == null) {
            eventList = new ArrayList<>();
            map.put(ecid, eventList);
        }
        eventList.add(event);
    }

    private static String getEcid(IEvent event) {
        IField ecidField = getEcidField(event.getEventType());
        if (ecidField == null) {
            return null;
        }
        return String.valueOf(ecidField.getValue(event));
    }

    private static boolean hasECID(IEventType type) {
        return getEcidField(type) != null;
    }

    private static IField getEcidField(IEventType type) {
        for (IField field : type.getFields()) {
            if (field.isRelational() && KEY_ECID.equals(field.getRelationalKey())) {
                return field;
            }
        }
        return null;
    }
}

The output should look something like this:

8ec006a7-30e9-4fac-be7f-716f42d3cbc8-00000ed0 [1 events]
8ec006a7-30e9-4fac-be7f-716f42d3cbc8-00000237 [45 events]
8ec006a7-30e9-4fac-be7f-716f42d3cbc8-00000236 [2 events]
8ec006a7-30e9-4fac-be7f-716f42d3cbc8-00000d58 [2 events]
8ec006a7-30e9-4fac-be7f-716f42d3cbc8-0000022a [2 events]
8ec006a7-30e9-4fac-be7f-716f42d3cbc8-0000022d [2 events]
8ec006a7-30e9-4fac-be7f-716f42d3cbc8-0000022c [12 events]

Running the same example but using the relational key for URI (http://www.oracle.com/wls/Servlet/servletName) will look something like this:

/console/index.jsp [10 events]
/_async/AsyncResponseService [195 events]
/medrec/registerPatient.action [90 events]
/physician-web/physician/addPrescription.action [448 events]
/console/images/button_bg_mo.png [7 events]
/physician-web/physician/viewPatients.action [432 events]
/medrec/admin/home.action [48 events]
/console/jsp/changemgmt/ChangeManager.jsp [9 events]
/physician-web/physician/createRecord.action [720 events]
/medrec-jaxws-services/PatientFacadeService [275 events]
/medrec-jaxrpc-services/JaxRpcRecordCreationFacadeBroker [235 events]

Conclusion

This blog provided some examples on how to read out metadata from a flight recording and a simple example showing the use of the relational key.

The Relational Key

This blog post explains the relational key – a little piece of event attribute metadata that is used to associate attributes in different event types with each other. This is a quick break in my series of posts about unsupported functionality, the reason for the break being that you will need to be armed with this knowledge for my next instalment in that series. Blinkar

The Relational Key

The relational key is a little piece of event type attribute metadata on the form of an URI. It is normally used as a marker to hint to JMC that it often makes sense to find all events (of different event types) with the same attribute value for attributes with the same relational key. For example, the Java Flight Recorder has quite a lot of different GC events. Almost all of them are related to a certain GC ID. It often makes sense to find all events related to the same GC ID. The picture below lists some common GC events, and their attribute metadata.

metadata

The relational key can be seen in action in how Mission Control presents the alternatives for the Operative Set. If you go to the GC view, pick a garbage collection and open the context menu, you will find that there is an option to add all the events with the same GC ID to the operative set.

gcs

Moving over to the events tab, and selecting to only show the operative set, a range of different events, all associated with that particular garbage collection, can be seen.

associated

Another very useful example is the ECID attribute in the events produced by the WebLogic Diagnostics Framework (see the “Putting it All Together” section of my post about the Operative Set).

 

Conclusion

The relational key is a handy little piece of attribute metadata that is used to give hints to the JMC user interface that different event types are related to each other. It is used by Mission Control to, for example, control what attributes are listed in the Operative Set context menu.

Using the Flight Recorder Parsers

This blog post is the second in a series of posts on using unsupported functionality in the Oracle JDK and/or Java Mission Control.

Just as there is no supported way to add custom events to the Java Flight Recorder (yet), there is even less in terms of programmatic support to read recordings. There are however two different unsupported parsers available. Both are POJO APIs, and except for supportability / future API breakage issues, there is in practice nothing stopping you from using either one to read your recordings.

Disclaimer:

The following blog entry will describe UNSUPPORTED functionality. This means that relying on the described APIs or functionality may BREAK your code/plugin with any given update of the JDK and/or Mission Control.

I strongly recommend against using these APIs in production code. There will be supported APIs for reading reading recordings eventually and they may be quite different. Also note that older versions of the parsers are not guaranteed to be forward compatible with newer versions of the binary format. In short, this is NOT supported and WILL CHANGE!

That said, it can sometimes be quite useful to have programmatic access to flight recorder data. One could, for example, do automatic filtering and/or reporting on recordings, and then use JMC to do detailed analysis on the ones that are flagged as interesting.

The Reference Parser

The reference parser shipped with the Oracle JDK can be likened to a SAX XML parser. It allows you to iterate through the recording, uses little memory, is somewhat limited, and provides a very simple Java model. If your needs are simple, this may be the perfect parser to use. It is available by default in JDK 7u4 and later. The parser API is located in the JDK_HOME/jre/lib/jfr.jar file.

Here is an example snippet that iterates through a recording and prints out the total event count:

import java.io.File;
import java.io.IOException;
import java.util.Iterator;

import oracle.jrockit.jfr.parser.*;

public class JDKParserTest {
    @SuppressWarnings("deprecation")
    public static void main(String[] args) throws IOException {
        File recordingFile = new File("C:\\demo\\wldf.jfr");
        Parser parser = new Parser(recordingFile);
        int count = 0;
        Iterator<ChunkParser> chunkIter = parser.iterator();
        while (chunkIter.hasNext()) {           
            ChunkParser chunkParser = chunkIter.next();
            for (FLREvent event : chunkParser) {
                count++;
                //System.out.println(event.toString());
            }
        }
        parser.close();
        System.out.println("Found " + count + " events");
    }
}   

I will not spend too much time on this parser.

Strengths:

  • Uses little memory
  • Included in the Hotspot JDK (>=7u4)

Weaknesses:

  • Slow
  • Simple model/API

The JMC Parser

If the reference parser is the SAX XML parser equivalent, then the JMC parser is the DOM equivalent. The jar for the parser is easily nicked from the JMC distribution, either from the update site or from the JDK installation. In the JDK, you’ll find the jar containing the JMC flight recorder parser at JDK_HOME/lib/missioncontrol/plugins/com.jrockit.mc.flightrecorder_<version>.jar.

You will also need to add the JDK_HOME/lib/missioncontrol/plugins/com.jrockit.mc.common_<version>.jar to your path.

Here is the equivalent event counting example using the JMC parser:

import java.io.File;

import com.jrockit.mc.flightrecorder.FlightRecording;
import com.jrockit.mc.flightrecorder.FlightRecordingLoader;
import com.jrockit.mc.flightrecorder.spi.IEvent;
import com.jrockit.mc.flightrecorder.spi.IView;

public class FlightRecorderParserTest {
    public static void main(String[] args) throws ClassNotFoundException {
        FlightRecording recording = FlightRecordingLoader.loadFile(new File("C:\\demo\\wldf.jfr"));    
        IView view = recording.createView();

        int count = 0;
        for (IEvent event : view) {
            count++;
        }
        System.out.println("Fount " + count + " events");
    }
}

Strengths:

  • Fast
  • The jar can be used with any JDK (>=6)
  • Rich API
  • Good for complex analysis scenarios

Weaknesses:

  • Builds a Java model of the recording – uses more memory

Summary

This blog post lists two different UNSUPPORTED parsers that can be used to read java flight recordings programmatically from Java. A very simple example showing how to iterate through the events in a recording was shown for both of the parsers.

Creating Custom JFR Events

This blog post is the first in a series of posts on using unsupported functionality in the Oracle JDK and/or Java Mission Control.

Since the 7u40 version of the Oracle JDK, the Java Flight Recorder provides a wealth of information about the operating system, the JVM and the Java application running in the JVM. To make the wealth of information easier to digest, it can often be quite useful to provide some contextual information to the events available from the Flight Recorder. For instance, WebLogic Diagnostics Framework integrates with the Flight Recorder to add information about requests, and there are trial projects that add information about JUnit tests run, JavaFX pulse logger information and more. Having that contextual information makes it much easier to get a good starting point for where you want to study the recording in more detail, for instance homing in on the longest servlet requests taking the longest time to complete.

This blog will show how to use the Flight Recorder Java API to record your own data into the Java Flight Recorder.

Disclaimer:

The following blog entry will describe UNSUPPORTED functionality. This means that relying on the described APIs or functionality may BREAK your code/plugin with any given update of the JDK and/or Mission Control.

I strongly recommend against using these APIs in production code. There will be supported APIs for recording custom events into the Java Flight Recorder eventually and they will likely be quite different. Also note that code using these APIs will require an Oracle JDK >= 7u4, both at compile and run-time. And finally, note that the entire API for recording your own events entered the Oracle JDK deprecated. This is NOT supported, and WILL CHANGE!

That said, I still think it is valuable to share this information since:

  • Sometimes having this ability can mean the difference between solving a problem in a reasonable time and not.
  • This is an API for recording information. If proper care is taken, you can insulate yourself from the effects of not having the API available at runtime. This will never be the kind of API that is critical to the execution of your application. That said, the API and having access to the flight recorder infrastructure can be pretty addictive if you’re interested in production time profiling and diagnostics. Blinkar
  • There are plenty of opportunities where you can use this API to a great advantage without even touching your application code. For example, having an event type for unit tests or maybe coding your own BCI agent to insert the code required to emit events on the fly.
  • Getting some early feedback on these APIs would be quite helpful.

Different Kind of Events

Before we start recording events, we must discuss the different kind of event types available. There are currently four different ones:

    1. Instant events
      These are events with only one time – the time the event occurred.
    2. Requestable events
      These are events with a user configurable period.
    3. Duration events
      These are events that have a start and end time (a duration).
    4. Timed events
      These are duration events with a user configurable threshold. If an event has a duration shorter than the defined threshold, it will not be recorded.

To record events we need to define two things:

    1. A producer
      The producer is basically some metadata and a namespace for your events. In the Java API, you will register your event types with the producer. Once the producer is no longer referenced, your associated event types will be cleared. Do NOT lose the reference to your producer.
    2. One or more event types
      In event types you define the metadata used to describe the events as well as the attributes (data) available.

Defining the Producer

To define a producer, simply instantiate a Producer instance:

Producer myProducer = new Producer("Demo Producer", "A demo event producer.", http://www.example.com/demo/);

The producer is simply defined using a name – the name is what will be shown to the user in the JMC GUI, a description and an identifier. The identifier is on an URI format.

Next we must register the producer:

myProducer.register();

After making sure to keep a reference to the producer, we can start defining the event types.

Defining an Event Type

Event types are defined using a Java class, with annotations used to declare metadata. Step one is to subclass the class appropriate for the kind of event you want, for example a timed event. Next you need to decide what attributes (data) should be available in the events. The following example declares an event type named My Event, with a single attribute named Message:

@EventDefinition(path = "demo/myevent", name = "My Event", description = "An event triggered by doStuff.", stacktrace = true, thread = true)
private class MyEvent extends TimedEvent {
    @ValueDefinition(name = "Message", description = "The logged important stuff.")
    private String text;

    public MyEvent(EventToken eventToken) {
        super(eventToken);
    }

    public void setText(String text) {
        this.text = text;
    }
}

Registering the Event Type

Next you have to register the event type with the producer. The registration method returns something called an event token. Keeping a reference to the event token and using it as an argument to the construction of an event instance is much more efficient than using the default event constructor. Here is how you may go about registering your event:

EventToken myToken = myProducer.addEvent(MyEvent.class);

Emitting Events

Now we’re ready to start emitting our event. This is very easily done:

    1. Construct an instance of the event (or reuse a previous instance, as discussed later).
    2. Call the start method to take the start timestamp.
    3. Set the attributes you wish to set.
    4. Call the end method to take the end timestamp.
    5. Set some more attributes if necessary.
    6. Call the commit method to commit the event to the recording engine.

So this is how it would look in code:

public void doStuff() {
    MyEvent event = new MyEvent(myToken);
    event.begin();
    String importantResultInStuff = "";
    // Generate the string, then set it...
    event.setText(importantResultInStuff);
    event.end();
    event.commit();
}

 

Now, you may come to the conclusion that this will cause an object allocation for each event. If you would rather not allocate a new object for each event, you can reuse one of them, like this:

private MyEvent event = new MyEvent(myToken);
public void doStuffReuse() {
    event.reset();
    event.begin();
    String importantResultInStuff = "";
    // Generate the string, then set it...
    event.setText(importantResultInStuff);
    event.end();
    event.commit();
}

(The only difference is that you need to remember to reset the event between each invocation.)

Conclusion

There is a Java API for adding events to the Java Flight Recorder available in the Oracle JDK since 7u4. It is NOT SUPPORTED, and it will change. That said, it can be quite useful for providing contextual information to the rest of the data provided.

I am very interested in feedback on this API. Such feedback will be fed back into a future, officially supported, API.