Java Mixed-Mode Flame Graphs

Recently, I wrote a blog post on "Java CPU Flame Graphs". That blog post shows how to use Linux perf_events to generate Java Mixed-Mode Flame Graphs.

With Java Profilers, we can get information about Java process only. However with Java Mixed-Mode Flame Graphs, we can see how much CPU time is spent in Java methods, system libraries and the kernel. Mixed-mode means that the Flame Graph shows profile information from both system code paths and Java code paths.

This is sometimes very important to identify performance issues. For more information, see Java in Flames and New JVM Option Enables Generation of Mixed-Mode Flame Graphs

In this blog post, I'm using a sample high cpu consuming Java Program with Java 8 Update 60.

$ mvn -version
Apache Maven 3.3.3 (7994120775791599e205a5524ec3e0dfe41d4a06; 2015-04-22T17:27:37+05:30)
Maven home: /usr/local/apache-maven/apache-maven-3.3.3
Java version: 1.8.0_60, vendor: Oracle Corporation
Java home: /usr/lib/jvm/jdk1.8.0_60/jre
Default locale: en_US, platform encoding: UTF-8
OS name: "linux", version: "3.19.0-28-generic", arch: "amd64", family: "unix"

$ git clone https://github.com/chrishantha/sample-java-programs.git
$ cd sample-java-programs
$ mvn clean install

Java Flame Graph using Java Flight Recorder

 I ran the highcpu program for a minute.

$ java -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:FlightRecorderOptions=defaultrecording=true,settings=profile,disk=true,repository=./tmp,dumponexit=true,dumponexitpath=./ -jar highcpu/target/highcpu-0.0.1-SNAPSHOT.jar --exit-timeout 60

I used my "jfr-flame-graph" software to generate the flame graph.

jfr-flame-graph$ ./run.sh -i -f ../sample-java-programs/hotspot-pid-30716-id-0-2015_09_14_19_01_38.jfr -o /tmp/output.txt
$ cat /tmp/output.txt | ~/performance/brendangregg-git/FlameGraph/flamegraph.pl --width 1680 > /tmp/highcpu-jfr.svg

Java Mixed Mode Flame Graph

I'm using "perf-map-agent". Please build it first as mentioned in README.

I ran the highcpu program with "-XX:+PreserveFramePointer" JVM argument.

$ java -XX:+PreserveFramePointer -jar highcpu/target/highcpu-0.0.1-SNAPSHOT.jar

In another terminal, I started a perf recording for a minute.

$ sudo perf record -F 99 -g -p `pgrep -f highcpu` -- sleep 60

By default, the highcpu Java program runs for 2 minutes and therefore I waited for a minute to create the Java Symbol Map (I did this in another terminal).

$ cd ~/performance/git-projects/perf-map-agent
$ sudo sleep 60;bin/create-java-perf-map.sh `pgrep -f highcpu`

After the perf recording completed and the symbol file created in /tmp, we can generate the Java mixed-mode flame graph


Let's generate the flame graph.

sample-java-programs$ sudo perf script | ~/performance/brendangregg-git/FlameGraph/stackcollapse-perf.pl > /tmp/out.perf-folded
sample-java-programs$ cat /tmp/out.perf-folded | ~/performance/brendangregg-git/FlameGraph/flamegraph.pl --color=java --width 1680  > /tmp/highcpu-perf.svg

Summary

When we compare the Flame Graphs, we can see the importance of Java Mixed Mode Flame Graphs. Since there are system code paths in addition to Java methods, we can clearly see all CPU consuming functions.  For example, in above Mixed Mode Flame Graph, we can see HashingWorker threads also consume more CPU. With Flame Graph generated with JFR, we see that MathWorker threads consume more CPU. Please see the flame-graphs in my GitHub repo.

With perf_events, we can do system profiling. The Java "-XX:+PreserveFramePointer" JVM argument and perf-map-agent help to create the Java Symbol Table for perf. The CPU Mixed-Mode Flame graphs can nicely show all CPU consumers in one visualization.