Context Switch Analysis

PerfJ is only work on new versions of JDK with frame pointer preserved.

Copy or download the [ContextSwitchTest] (https://github.com/coderplay/perfj/blob/master/examples/ContextSwitchTest.java) to you local machine

wget https://raw.githubusercontent.com/coderplay/perfj/master/examples/ContextSwitchTest.java

Compile it

javac –cp . ContextSwitchTest.java

Run it with PreserveFramePointer enabled

java -XX:+PreserveFramePointer ContextSwitchTest

After that, run perfj

bin/perfj record -e sched:sched_switch -F 99 -g -p `pgrep -f ContextSwitchTest`

After a while use Ctrl+C to terminate the profiling. We will see a perf.data as well as /tmp/perf-$pid.map are generated by perfj on local disk. Finally, show the result

bin/perfj report --stdio

Below is an example result

[sudo] password for mzhou:
# ========
# captured on: Mon Jun  8 16:54:55 2015
# hostname : mzhou-server
# os release : 3.13.0-49-generic
# perf version : 3.13.11-ckt17
# arch : x86_64
# nrcpus online : 8
# nrcpus avail : 8
# cpudesc : Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz
# cpuid : GenuineIntel,6,60,3
# total memory : 32887248 kB
# cmdline : /usr/lib/linux-tools-3.13.0-49/perf record -e sched:sched_switch -F 99 -g -p 28241
# event : name = sched:sched_switch, type = 2, config = 0x130, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, excl_host = 0, excl_guest = 1, precise_ip = 0, attr_mmap2 = 0, attr_mmap  = 1, attr_mmap_data = 0
# HEADER_CPU_TOPOLOGY info available, use -I to display
# HEADER_NUMA_TOPOLOGY info available, use -I to display
# pmu mappings: cpu = 4, software = 1, tracepoint = 2, breakpoint = 5
# ========
#
# Samples: 197K of event 'sched:sched_switch'
# Event count (approx.): 197547
#
# Overhead  Command      Shared Object          Symbol
# ........  .......  .................  ..............
#
   100.00%     java  [kernel.kallsyms]  [k] __schedule
               |
               --- __schedule
                  |
                  |--99.97%-- schedule
                  |          futex_wait_queue_me
                  |          futex_wait
                  |          do_futex
                  |          sys_futex
                  |          system_call_fastpath
                  |          |
                  |          |--99.96%-- pthread_cond_wait@@GLIBC_2.3.2
                  |          |          Unsafe_Park
                  |          |          Lsun/misc/Unsafe;.park
                  |          |          LContextSwitchTest$WorkerThread;.run
                  |          |          call_stub
                  |          |          JavaCalls::call_helper(JavaValue*, methodHandle*, JavaCallArguments*, Thread*)
                  |          |          JavaCalls::call_virtual(JavaValue*, KlassHandle, Symbol*, Symbol*, JavaCallArguments*, Thread*)
                  |          |          JavaCalls::call_virtual(JavaValue*, Handle, KlassHandle, Symbol*, Symbol*, Thread*)
                  |          |          thread_entry(JavaThread*, Thread*)
                  |          |          JavaThread::thread_main_inner()
                  |          |          java_start(Thread*)
                  |          |          start_thread
                  |           --0.04%-- [...]
                   --0.03%-- [...]



#
# (For a higher level overview, try: perf report --sort comm,dso)
#

Now that you can see the Java/JVM methods rather than hexadecimal addresses.