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
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.