Java CPU Flame Graphs

Update (September 14, 2015): Java 8 Update 60 was released on August 18, 2015. There are some recent changes to "perf-map-agent". There is no longer a script named "perf-java" and you should use "bin/create-java-perf-map.sh "

Brendan Gregg shared an exciting news in his Monitorama talk: The "JDK-8068945" is fixed in Java 8 Update 60 Build 19!

Without this fix, it was not possible to see full stack in Java with Linux perf_events and standard JDK (without any patches). For more information, see Brendan's Java CPU Flame Graphs page.

The Problem with Java and Perf


First of all, let's see what's the problem with using current latest Java and perf.

For this example, I used the same program explained in my previous blog post regarding FlameGraphs.

java org.wso2.example.JavaThreadCPUUsage.App

Then I sampled on-CPU functions for Java program using perf. (See Brendan's Perf Examples)

sudo perf record -F 99 -g -p `pgrep -f JavaThreadCPUUsage`

After few seconds, I pressed Ctrl+C to stop recording.

When I tried to list all raw events from "perf.data" using the "sudo perf script" command, I see following message.

Failed to open /tmp/perf-29463.map, continuing without symbols

Perf tries to load Java symbol table from the "/tmp/perf-29463.map" file. The 29463 part in the file name is the PID of the Java program.

Missing these Java symbols is one of the main problems with Java and Perf.  In here, there are actually two specific problems and Brendan has explained those in Java CPU Flame Graphs.

As explained by Brendan, in order to solve these problems, we need to provide Java symbol table for the perf and instruct JVM to preserve frame pointers. This is why we need the fix for  "JDK-8068945".

Generating Java CPU Flame Graphs


I downloaded the latest JDK™ 8u60 Early Access Release, which is "JDK 8u60 Build b24" as of now.

I extracted the JDK to a temp directory in my home. So, my JAVA_HOME is now "~/temp/jdk1.8.0_60".

With this release, I can use the JVM argument "-XX:+PreserveFramePointer" with java command.

~/temp/jdk1.8.0_60/bin/java -XX:+PreserveFramePointer org.wso2.example.JavaThreadCPUUsage.App

Now we need to create the Java symbol file. I found two ways to do that.

  1. Use https://github.com/jrudolph/perf-map-agent
  2. Use https://github.com/coderplay/perfj 

Using perf-map-agent


We need to build "perf-map-agent".

git clone https://github.com/jrudolph/perf-map-agent.git
cd perf-map-agent
export JAVA_HOME=~/temp/jdk1.8.0_60/
sudo apt-get install cmake
cmake .
make

Now we can start a perf recording. (Same command as mentioned above)

sudo perf record -F 99 -g -p `pgrep -f JavaThreadCPUUsage`

Now, run "bin/create-java-perf-map.sh".

bin/create-java-perf-map.sh `pgrep -f JavaThreadCPUUsage` 

This will create the Java symbol file in /tmp.

Please note that the perf-map-agent attaches to the java process. Please use the same JAVA_HOME to make sure there are no errors when attaching to the Java process.

Using perfj


Perfj is a wrapper of linux perf command for java programs. Download the latest release from perfj releases page.

tar -xvf perfj-1.0.tgz
cd perfj-1.0/
sudo -u isuru JAVA_HOME=/home/isuru/temp/jdk1.8.0_60 ./bin/perfj record -F 99 -g -p `pgrep -f JavaThreadCPUUsage`

Please note that I'm using the same user as the java process. This is required as perfj also attaches to the Java process. JAVA_HOME also must be same.

Generating Flame Graph


Now we have perf.data and java symbols to generate the flame graph.

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

When you open the perf.svg in browser, you can see complete stack traces.

Summary


This is a quick blog post on Generating Java CPU Flame Graphs. To create Java symbol file, we can use perfj or perf-map-agent.

When I tested, perfj seems to provide better results.

Here is the flame graph generated with perfj java symbols!

Flame Graph Reset Zoom finish_task_switch (12 samples, 0.60%) tick_sched_handle.isra.16 (2 samples, 0.10%) __run_hrtimer (2 samples, 0.10%) account_process_tick (1 samples, 0.05%) schedule_user (4 samples, 0.20%) perf_event_context_sched_in (4 samples, 0.20%) jni_GetArrayLength (1 samples, 0.05%) java/util/Random:.seedUniquifier in Ljava/util/Random:.init (1 samples, 0.05%) perf_event_context_sched_in (12 samples, 0.60%) pthread_cond_signal@@GLIBC_2.3.2 (3 samples, 0.15%) get_futex_key (1 samples, 0.05%) send_sigqueue (1 samples, 0.05%) sun/security/provider/ByteArrayAccess:.b2iBig64 (4 samples, 0.20%) _ZN7Monitor5IWaitEP6Threadl (8 samples, 0.40%) perf_event_context_sched_in (4 samples, 0.20%) local_apic_timer_interrupt (1 samples, 0.05%) posix_timer_fn (1 samples, 0.05%) common_file_perm (5 samples, 0.25%) pthread_getspecific (1 samples, 0.05%) posix_timer_fn (1 samples, 0.05%) _ZN22PSScavengeKlassClosure8do_klassEP5Klass (1 samples, 0.05%) tick_sched_timer (2 samples, 0.10%) __perf_event_task_sched_in (40 samples, 1.99%) rw_verify_area (10 samples, 0.50%) sys_futex (46 samples, 2.29%) finish_task_switch (64 samples, 3.18%) _ZN14PSRootsClosureILb0EE6do_oopEPP7oopDesc (1 samples, 0.05%) try_to_wake_up (1 samples, 0.05%) cpuacct_account_field (1 samples, 0.05%) hrtimer_wakeup (1 samples, 0.05%) intel_pmu_enable_all (12 samples, 0.60%) pthread_cond_wait@@GLIBC_2.3.2 (64 samples, 3.18%) apparmor_file_permission (5 samples, 0.25%) security_file_permission (8 samples, 0.40%) all (2,010 samples, 100%) enqueue_task (1 samples, 0.05%) jni_fast_GetIntField (2 samples, 0.10%) do_futex (64 samples, 3.18%) handleRead (2 samples, 0.10%) vfs_read (1 samples, 0.05%) finish_task_switch (4 samples, 0.20%) _ZN20ClassLoaderDataGraph7oops_doEP10OopClosureP12KlassClosureb (2 samples, 0.10%) _ZN17HandleMarkCleanerD1Ev (1 samples, 0.05%) x86_pmu_enable (4 samples, 0.20%) __schedule (8 samples, 0.40%) select_idle_sibling (1 samples, 0.05%) pthread_cond_init@plt (1 samples, 0.05%) x86_pmu_enable (4 samples, 0.20%) intel_pmu_enable_all (12 samples, 0.60%) perf_pmu_disable (1 samples, 0.05%) try_to_wake_up (1 samples, 0.05%) sys_futex (3 samples, 0.15%) jlong_disjoint_arraycopy (377 samples, 18.76%) jlong_disjoi.. smp_apic_timer_interrupt (3 samples, 0.15%) __schedule (14 samples, 0.70%) enqueue_entity (1 samples, 0.05%) _ZN7Monitor7TrySpinEP6Thread (1 samples, 0.05%) __lll_unlock_wake (1 samples, 0.05%) futex_wait_queue_me (64 samples, 3.18%) x86_pmu_disable (1 samples, 0.05%) yield_task_fair (1 samples, 0.05%) apic_timer_interrupt (3 samples, 0.15%) place_entity (1 samples, 0.05%) sha_transform (71 samples, 3.53%) smp_apic_timer_interrupt (1 samples, 0.05%) _ZN7Monitor5IWaitEP6Threadl (16 samples, 0.80%) perf_pmu_enable (4 samples, 0.20%) sun/security/provider/SecureRandom:.engineNextBytes in Lsun/security/provider/NativePRNG$RandomIO:.implNextBytes (45 samples, 2.24%) perf_event_task_sched_out (1 samples, 0.05%) do_futex (8 samples, 0.40%) apic_timer_interrupt (4 samples, 0.20%) __sched_yield (1 samples, 0.05%) __perf_event_task_sched_in (4 samples, 0.20%) activate_task (1 samples, 0.05%) try_to_wake_up (1 samples, 0.05%) posix_timer_event (1 samples, 0.05%) __schedule (8 samples, 0.40%) finish_task_switch (4 samples, 0.20%) __run_hrtimer (3 samples, 0.15%) _ZN22ParallelTaskTerminator17offer_terminationEP20TerminatorTerminator (1 samples, 0.05%) retint_careful (5 samples, 0.25%) schedule (14 samples, 0.70%) _ZL10java_startP6Thread (1,988 samples, 98.91%) _ZL10java_startP6Thread __memmove_ssse3_back (1 samples, 0.05%) pick_next_task_fair (1 samples, 0.05%) sys_futex (1 samples, 0.05%) __remove_hrtimer (1 samples, 0.05%) sun/security/provider/ByteArrayAccess:.i2bBig4 in Lsun/security/provider/DigestBase:.engineDigest (1 samples, 0.05%) jshort_disjoint_arraycopy (1 samples, 0.05%) apic_timer_interrupt (1 samples, 0.05%) perf_pmu_enable (8 samples, 0.40%) urandom_read (1 samples, 0.05%) apic_timer_interrupt (3 samples, 0.15%) sun/security/provider/MD5:.implCompress (13 samples, 0.65%) finish_task_switch (4 samples, 0.20%) tick_sched_timer (1 samples, 0.05%) perf_event_context_sched_in (40 samples, 1.99%) wake_up_state (1 samples, 0.05%) ttwu_do_activate.constprop.94 (1 samples, 0.05%) sun/security/provider/DigestBase:.engineUpdate in Lsun/security/provider/DigestBase:.engineDigest (32 samples, 1.59%) timerqueue_add (2 samples, 0.10%) jshort_disjoint_arraycopy (9 samples, 0.45%) futex_wait_queue_me (8 samples, 0.40%) _ZN14TypeArrayKlass15allocate_commonEibP6Thread (4 samples, 0.20%) _ZN17HandleMarkCleanerD1Ev (1 samples, 0.05%) java/lang/String:.getChars in Ljava/util/UUID:.toString (4 samples, 0.20%) _mix_pool_bytes (1 samples, 0.05%) jbyte_disjoint_arraycopy (1 samples, 0.05%) intel_pmu_enable_all (4 samples, 0.20%) ttwu_do_activate.constprop.94 (1 samples, 0.05%) _ZN10PSScavenge16invoke_no_policyEv (13 samples, 0.65%) hrtimer_interrupt (1 samples, 0.05%) perf_event_context_sched_in (12 samples, 0.60%) intel_pstate_timer_func (1 samples, 0.05%) __perf_event_task_sched_in (4 samples, 0.20%) _ZN11AllocTracer33send_allocation_in_new_tlab_eventE11KlassHandlemm (1 samples, 0.05%) sun/security/provider/DigestBase:.engineUpdate in Lorg/wso2/example/JavaThreadCPUUsage/HeavyThread:.run (18 samples, 0.90%) __schedule (5 samples, 0.25%) _raw_spin_lock (1 samples, 0.05%) hrtimer_interrupt (1 samples, 0.05%) __vfs_read (147 samples, 7.31%) __v.. try_to_wake_up (1 samples, 0.05%) intel_pmu_enable_all (64 samples, 3.18%) _ZN10JavaThread3runEv (1,866 samples, 92.84%) _ZN10JavaThread3runEv java (2,010 samples, 100.00%) java sys_futex (8 samples, 0.40%) __pthread_enable_asynccancel (1 samples, 0.05%) perf_event_context_sched_in (8 samples, 0.40%) wake_futex (3 samples, 0.15%) native_write_msr_safe (4 samples, 0.20%) java/security/SecureRandom:.nextBytes in Lorg/wso2/example/JavaThreadCPUUsage/HeavyThread:.run (2 samples, 0.10%) futex_wait (45 samples, 2.24%) enqueue_task (1 samples, 0.05%) __fdget_pos (5 samples, 0.25%) _ZN11OptoRuntime27is_deoptimized_caller_frameEP10JavaThread (1 samples, 0.05%) do_futex (46 samples, 2.29%) perf_event_context_sched_in (8 samples, 0.40%) _ZN9JavaCalls12call_virtualEP9JavaValue6Handle11KlassHandleP6SymbolS5_P6Thread (1,851 samples, 92.09%) _ZN9JavaCalls12call_virtualEP9JavaValue6Handle11KlassHandleP6Symbo.. cpuacct_charge (1 samples, 0.05%) sun/security/provider/NativePRNG$RandomIO:.readFully in Lsun/security/provider/NativePRNG$RandomIO:.implNextBytes (10 samples, 0.50%) irq_exit (1 samples, 0.05%) _ZN8VMThread18evaluate_operationEP12VM_Operation (13 samples, 0.65%) pthread_cond_timedwait@@GLIBC_2.3.2 (14 samples, 0.70%) retint_careful (5 samples, 0.25%) schedule (45 samples, 2.24%) _ZN7Monitor28lock_without_safepoint_checkEv (4 samples, 0.20%) update_min_vruntime (1 samples, 0.05%) hrtimer_interrupt (1 samples, 0.05%) sun/security/provider/DigestBase:.engineUpdate in Lsun/security/provider/DigestBase:.engineDigest (2 samples, 0.10%) wake_up_state (1 samples, 0.05%) __remove_hrtimer (1 samples, 0.05%) perf_pmu_enable (64 samples, 3.18%) __perf_event_task_sched_out (1 samples, 0.05%) system_call_fastpath (12 samples, 0.60%) futex_wait_queue_me (4 samples, 0.20%) enqueue_task (1 samples, 0.05%) java/lang/String:.getChars in Lorg/wso2/example/JavaThreadCPUUsage/HeavyThread:.run (2 samples, 0.10%) idle_cpu (1 samples, 0.05%) enqueue_task (1 samples, 0.05%) [unknown] (176 samples, 8.76%) [unk.. pthread_cond_init@plt (1 samples, 0.05%) pthread_cond_timedwait@@GLIBC_2.3.2 (14 samples, 0.70%) native_write_msr_safe (40 samples, 1.99%) update_process_times (2 samples, 0.10%) local_apic_timer_interrupt (1 samples, 0.05%) pthread_cond_destroy@@GLIBC_2.3.2 (2 samples, 0.10%) __schedule (4 samples, 0.20%) _ZN9StealTask5do_itEP13GCTaskManagerj (5 samples, 0.25%) apparmor_file_permission (1 samples, 0.05%) smp_apic_timer_interrupt (1 samples, 0.05%) sun/security/provider/DigestBase:.engineReset in Lsun/security/provider/DigestBase:.engineUpdate (3 samples, 0.15%) sys_sched_yield (4 samples, 0.20%) __wake_up_common (1 samples, 0.05%) _ZN8VMThread4loopEv (24 samples, 1.19%) _ZN2os14javaTimeMillisEv (1 samples, 0.05%) _ZN7Monitor4waitEblb (8 samples, 0.40%) _ZN5frame16oops_do_internalEP10OopClosureP10CLDClosureP15CodeBlobClosureP11RegisterMapb (1 samples, 0.05%) intel_pmu_enable_all (40 samples, 1.99%) schedule (8 samples, 0.40%) system_call_fastpath (64 samples, 3.18%) pthread_cond_signal@@GLIBC_2.3.2 (1 samples, 0.05%) sun/nio/cs/UTF_8$Encoder:.encode (2 samples, 0.10%) __memmove_ssse3_back (2 samples, 0.10%) dequeue_entity (1 samples, 0.05%) do_futex (3 samples, 0.15%) _ZN19OldToYoungRootsTask5do_itEP13GCTaskManagerj (1 samples, 0.05%) smp_apic_timer_interrupt (1 samples, 0.05%) sun/security/jca/ProviderList:.getProvider in Lsun/security/jca/ProviderList:.getService (1 samples, 0.05%) _ZN20SafepointSynchronize5beginEv (3 samples, 0.15%) local_apic_timer_interrupt (1 samples, 0.05%) deactivate_task (1 samples, 0.05%) select_idle_sibling (1 samples, 0.05%) security_file_permission (1 samples, 0.05%) vma_set_page_prot (1 samples, 0.05%) perf_pmu_enable (4 samples, 0.20%) futex_wake_op (3 samples, 0.15%) smp_apic_timer_interrupt (1 samples, 0.05%) schedule_user (5 samples, 0.25%) fsnotify (1 samples, 0.05%) ctx_sched_out (1 samples, 0.05%) readBytes (194 samples, 9.65%) readB.. sun/security/provider/SHA:.implCompress (30 samples, 1.49%) x86_pmu_enable (8 samples, 0.40%) _ZN20ParallelScavengeHeap19failed_mem_allocateEm (13 samples, 0.65%) native_write_msr_safe (4 samples, 0.20%) __run_hrtimer (2 samples, 0.10%) complete_signal (1 samples, 0.05%) hrtimer_interrupt (1 samples, 0.05%) __perf_event_task_sched_out (1 samples, 0.05%) intel_pmu_enable_all (8 samples, 0.40%) java/lang/String:.getBytes (4 samples, 0.20%) complete_signal (1 samples, 0.05%) _ZN15ThreadRootsTask5do_itEP13GCTaskManagerj (3 samples, 0.15%) __wake_up (2 samples, 0.10%) sys_futex (1 samples, 0.05%) jni_GetObjectField (4 samples, 0.20%) tick_sched_timer (1 samples, 0.05%) send_sigqueue (1 samples, 0.05%) _ZN10PSScavenge6invokeEv (13 samples, 0.65%) __run_hrtimer (1 samples, 0.05%) local_apic_timer_interrupt (3 samples, 0.15%) x86_pmu_enable (64 samples, 3.18%) _ZN7Monitor5IWaitEP6Threadl (67 samples, 3.33%) apic_timer_interrupt (1 samples, 0.05%) sys_futex (4 samples, 0.20%) wake_up_process (1 samples, 0.05%) readBytes (2 samples, 0.10%) x86_pmu_enable (4 samples, 0.20%) run_timer_softirq (1 samples, 0.05%) __schedule (4 samples, 0.20%) __fget (5 samples, 0.25%) x86_pmu_commit_txn (4 samples, 0.20%) _ZN6Thread10muxAcquireEPVlPKc (1 samples, 0.05%) hrtimer_interrupt (1 samples, 0.05%) __vdso_clock_gettime (1 samples, 0.05%) native_write_msr_safe (8 samples, 0.40%) apic_timer_interrupt (1 samples, 0.05%) _ZN12GCTaskThread3runEv (82 samples, 4.08%) _.. wake_futex (1 samples, 0.05%) enqueue_entity (1 samples, 0.05%) cpuacct_charge (1 samples, 0.05%) task_tick_fair (1 samples, 0.05%) _mix_pool_bytes (33 samples, 1.64%) system_call_fastpath (46 samples, 2.29%) native_write_msr_safe (12 samples, 0.60%) timerqueue_del (1 samples, 0.05%) java/lang/Thread:.sleep (68 samples, 3.38%) _ZN7Monitor4waitEblb (8 samples, 0.40%) finish_task_switch (12 samples, 0.60%) schedule (4 samples, 0.20%) _ZN13WatcherThread3runEv (16 samples, 0.80%) java/lang/String:.equals (1 samples, 0.05%) update_curr (1 samples, 0.05%) do_futex (4 samples, 0.20%) smp_apic_timer_interrupt (1 samples, 0.05%) dequeue_task (1 samples, 0.05%) local_apic_timer_interrupt (1 samples, 0.05%) hrtimer_interrupt (1 samples, 0.05%) __run_hrtimer (1 samples, 0.05%) hrtimer_interrupt (1 samples, 0.05%) __mix_pool_bytes (34 samples, 1.69%) _ZN14JNIHandleBlock7oops_doEP10OopClosure (1 samples, 0.05%) _ZN13GCTaskManager8get_taskEj (70 samples, 3.48%) vfs_read (160 samples, 7.96%) vfs.. extract_buf (132 samples, 6.57%) ex.. java/security/MessageDigest$Delegate:.engineUpdate in Lsun/security/provider/NativePRNG$RandomIO:.implNextBytes (7 samples, 0.35%) set_next_entity (1 samples, 0.05%) posix_timer_fn (1 samples, 0.05%) JVM_Sleep (63 samples, 3.13%) intel_pmu_enable_all (4 samples, 0.20%) enqueue_task_fair (1 samples, 0.05%) perf_event_task_sched_out (1 samples, 0.05%) perf_pmu_enable (4 samples, 0.20%) __schedule (1 samples, 0.05%) local_apic_timer_interrupt (2 samples, 0.10%) __libc_read (3 samples, 0.15%) native_write_msr_safe (64 samples, 3.18%) SpinPause (4 samples, 0.20%) sys_futex (64 samples, 3.18%) __schedule (64 samples, 3.18%) mprotect_fixup (1 samples, 0.05%) native_write_msr_safe (4 samples, 0.20%) _ZN2os23serialize_thread_statesEv (2 samples, 0.10%) memset (3 samples, 0.15%) ttwu_do_activate.constprop.94 (1 samples, 0.05%) __fsnotify_parent (1 samples, 0.05%) _ZN10HandleArea7oops_doEP10OopClosure (1 samples, 0.05%) perf_pmu_enable (8 samples, 0.40%) wake_up_state (1 samples, 0.05%) wake_up_state (1 samples, 0.05%) task_tick_fair (2 samples, 0.10%) __GI___mprotect (2 samples, 0.10%) system_call_fastpath (8 samples, 0.40%) _ZN29VM_ParallelGCFailedAllocation4doitEv (13 samples, 0.65%) sys_mprotect (2 samples, 0.10%) smp_apic_timer_interrupt (3 samples, 0.15%) __perf_event_task_sched_in (12 samples, 0.60%) x86_pmu_enable (4 samples, 0.20%) system_call_fastpath (1 samples, 0.05%) activate_task (1 samples, 0.05%) ttwu_do_activate.constprop.94 (1 samples, 0.05%) __perf_event_task_sched_in (64 samples, 3.18%) smp_apic_timer_interrupt (3 samples, 0.15%) __sched_yield (4 samples, 0.20%) schedule_user (1 samples, 0.05%) apic_timer_interrupt (1 samples, 0.05%) futex_wake_op (1 samples, 0.05%) __fget_light (5 samples, 0.25%) enqueue_hrtimer (2 samples, 0.10%) update_cfs_rq_blocked_load (1 samples, 0.05%) __pthread_disable_asynccancel (1 samples, 0.05%) __perf_event_task_sched_in (4 samples, 0.20%) apic_timer_interrupt (1 samples, 0.05%) native_write_msr_safe (12 samples, 0.60%) __run_hrtimer (2 samples, 0.10%) enqueue_task (1 samples, 0.05%) activate_task (1 samples, 0.05%) _ZN18CardTableExtension26scavenge_contents_parallelEP16ObjectStartArrayP12MutableSpaceP8HeapWordP18PSPromotionManagerjj (1 samples, 0.05%) task_curr (1 samples, 0.05%) _raw_spin_lock_irqsave (1 samples, 0.05%) generic_smp_call_function_single_interrupt (4 samples, 0.20%) system_call_fastpath (1 samples, 0.05%) system_call_fastpath (8 samples, 0.40%) __lll_unlock_wake (4 samples, 0.20%) _ZN7Monitor4waitEblb (15 samples, 0.75%) Interpreter (71 samples, 3.53%) update_process_times (1 samples, 0.05%) wake_up_process (1 samples, 0.05%) hrtimer_interrupt (2 samples, 0.10%) smp_call_function_single_interrupt (4 samples, 0.20%) [unknown] (7 samples, 0.35%) org/wso2/example/JavaThreadCPUUsage/HeavyThread:.run (837 samples, 41.64%) org/wso2/example/JavaThreadCP.. __do_softirq (1 samples, 0.05%) jshort_disjoint_arraycopy (5 samples, 0.25%) local_apic_timer_interrupt (1 samples, 0.05%) _ZN11OptoRuntime18new_array_nozero_CEP5KlassiP10JavaThread (5 samples, 0.25%) perf_event_context_sched_in (4 samples, 0.20%) apic_timer_interrupt (2 samples, 0.10%) futex_wait_queue_me (12 samples, 0.60%) rb_erase (1 samples, 0.05%) system_call_fastpath (4 samples, 0.20%) _ZN13CompileBroker20compiler_thread_loopEv (15 samples, 0.75%) __schedule (12 samples, 0.60%) _ZN7Monitor5IWaitEP6Threadl (15 samples, 0.75%) jni_SetByteArrayRegion (4 samples, 0.20%) intel_pmu_enable_all (4 samples, 0.20%) rb_erase (1 samples, 0.05%) sys_futex (12 samples, 0.60%) jshort_disjoint_arraycopy (378 samples, 18.81%) jshort_disjo.. _ZN7Monitor4waitEblb (16 samples, 0.80%) __perf_event_task_sched_in (8 samples, 0.40%) _ZNK8CodeHeap10find_startEPv (1 samples, 0.05%) pthread_cond_wait@@GLIBC_2.3.2 (8 samples, 0.40%) _ZN14JNIHandleBlock15allocate_handleEP7oopDesc (2 samples, 0.10%) perf_event_task_sched_out (1 samples, 0.05%) java/lang/StringCoding:.deref in Ljava/lang/StringCoding:.encode (4 samples, 0.20%) finish_task_switch (40 samples, 1.99%) sys_sched_yield (1 samples, 0.05%) x86_pmu_enable (8 samples, 0.40%) system_call_fastpath (2 samples, 0.10%) call_function_single_interrupt (1 samples, 0.05%) call_function_single_interrupt (4 samples, 0.20%) _ZN17ScavengeRootsTask5do_itEP13GCTaskManagerj (2 samples, 0.10%) _copy_to_user (1 samples, 0.05%) complete_signal (1 samples, 0.05%) _ZL12thread_entryP10JavaThreadP6Thread (1,851 samples, 92.09%) _ZL12thread_entryP10JavaThreadP6Thread tick_sched_handle.isra.16 (1 samples, 0.05%) try_to_wake_up (1 samples, 0.05%) java/nio/HeapByteBuffer:.init in Ljava/lang/StringCoding$StringEncoder:.encode (4 samples, 0.20%) activate_task (1 samples, 0.05%) futex_wake_op (1 samples, 0.05%) do_futex (12 samples, 0.60%) pthread_cond_signal@@GLIBC_2.3.2 (1 samples, 0.05%) dequeue_entity (1 samples, 0.05%) perf_pmu_enable (12 samples, 0.60%) Interpreter (1,851 samples, 92.09%) Interpreter jlong_disjoint_arraycopy (2 samples, 0.10%) update_curr (1 samples, 0.05%) __run_hrtimer (1 samples, 0.05%) _ZN12CompileQueue3getEv (15 samples, 0.75%) __perf_event_task_sched_in (12 samples, 0.60%) __pthread_disable_asynccancel (1 samples, 0.05%) _ZN13CollectedHeap23allocate_from_tlab_slowE11KlassHandleP6Threadm (4 samples, 0.20%) java/util/HashMap:.getNode (1 samples, 0.05%) deactivate_task (1 samples, 0.05%) _ZNK20ParallelScavengeHeap21unsafe_max_tlab_allocEP6Thread (3 samples, 0.15%) _ZN8VMThread3runEv (24 samples, 1.19%) _ZN12VM_Operation8evaluateEv (13 samples, 0.65%) call_timer_fn (1 samples, 0.05%) update_cfs_shares (1 samples, 0.05%) pick_next_task_fair (1 samples, 0.05%) java/lang/AbstractStringBuilder:.init in Ljava/util/UUID:.toString (54 samples, 2.69%) _ZN7Monitor5ILockEP6Thread (4 samples, 0.20%) activate_task (1 samples, 0.05%) scheduler_tick (2 samples, 0.10%) smp_apic_timer_interrupt (1 samples, 0.05%) group_sched_in (4 samples, 0.20%) do_futex (1 samples, 0.05%) __fdget_pos (1 samples, 0.05%) _ZN10JavaThread17thread_main_innerEv (1,866 samples, 92.84%) _ZN10JavaThread17thread_main_innerEv pthread_cond_timedwait@@GLIBC_2.3.2 (46 samples, 2.29%) [unknown] (5 samples, 0.25%) java/lang/String:.substring in Ljava/util/UUID:.toString (3 samples, 0.15%) signal_wake_up_state (1 samples, 0.05%) jshort_arraycopy (2 samples, 0.10%) sun/security/provider/NativePRNG$RandomIO:.access$400 in Lorg/wso2/example/JavaThreadCPUUsage/HeavyThread:.run (1 samples, 0.05%) rcu_note_context_switch (1 samples, 0.05%) dequeue_task_fair (1 samples, 0.05%) system_call_fastpath (170 samples, 8.46%) syst.. hrtimer_interrupt (3 samples, 0.15%) system_call_after_swapgs (4 samples, 0.20%) tick_sched_handle.isra.16 (1 samples, 0.05%) jshort_disjoint_arraycopy (3 samples, 0.15%) perf_event_context_sched_in (4 samples, 0.20%) call_stub (1,851 samples, 92.09%) call_stub jlong_disjoint_arraycopy (3 samples, 0.15%) local_apic_timer_interrupt (1 samples, 0.05%) sun/security/provider/NativePRNG$RandomIO:.access$400 in Lorg/wso2/example/JavaThreadCPUUsage/HeavyThread:.run (833 samples, 41.44%) sun/security/provider/NativeP.. posix_timer_event (1 samples, 0.05%) hrtimer_interrupt (3 samples, 0.15%) enqueue_entity (1 samples, 0.05%) system_call_fastpath (3 samples, 0.15%) dequeue_task_fair (1 samples, 0.05%) perf_pmu_enable (4 samples, 0.20%) _ZN9JavaCalls12call_virtualEP9JavaValue11KlassHandleP6SymbolS4_P17JavaCallArgumentsP6Thread (1,851 samples, 92.09%) _ZN9JavaCalls12call_virtualEP9JavaValue11KlassHandleP6SymbolS4_P17.. native_write_msr_safe (4 samples, 0.20%) do_futex (14 samples, 0.70%) x86_pmu_enable (4 samples, 0.20%) __run_hrtimer (1 samples, 0.05%) select_task_rq_fair (1 samples, 0.05%) system_call (2 samples, 0.10%) _ZN11StringTable17unlink_or_oops_doEP17BoolObjectClosureP10OopClosurePiS4_ (5 samples, 0.25%) __run_hrtimer (1 samples, 0.05%) tick_sched_timer (1 samples, 0.05%) urandom_read (147 samples, 7.31%) ura.. scheduler_tick (1 samples, 0.05%) do_futex (1 samples, 0.05%) __enqueue_entity (1 samples, 0.05%) try_to_wake_up (1 samples, 0.05%) __schedule (4 samples, 0.20%) __vdso_gettimeofday (3 samples, 0.15%) update_process_times (1 samples, 0.05%) extract_entropy_user (142 samples, 7.06%) ext.. intel_pmu_enable_all (4 samples, 0.20%) sys_futex (8 samples, 0.40%) perf_pmu_enable (12 samples, 0.60%) apic_timer_interrupt (1 samples, 0.05%) __perf_event_enable (4 samples, 0.20%) kill_fasync (2 samples, 0.10%) update_stats_wait_end (1 samples, 0.05%) do_futex (1 samples, 0.05%) irq_enter (1 samples, 0.05%) futex_wait (8 samples, 0.40%) irq_exit (1 samples, 0.05%) apic_timer_interrupt (1 samples, 0.05%) apic_timer_interrupt (1 samples, 0.05%) _ZN5frame19oops_interpreted_doEP10OopClosureP10CLDClosurePK11RegisterMapb (1 samples, 0.05%) apic_timer_interrupt (1 samples, 0.05%) copy_user_enhanced_fast_string (3 samples, 0.15%) __schedule (5 samples, 0.25%) sun/security/provider/SHA:.implCompress (2 samples, 0.10%) sun/security/provider/NativePRNG$RandomIO:.access$400 in Lorg/wso2/example/JavaThreadCPUUsage/HeavyThread:.run (1 samples, 0.05%) sun/security/provider/NativePRNG$RandomIO:.implNextBytes (216 samples, 10.75%) sun/se.. account (3 samples, 0.15%) __run_hrtimer (1 samples, 0.05%) local_apic_timer_interrupt (3 samples, 0.15%) schedule (12 samples, 0.60%) pthread_cond_wait@@GLIBC_2.3.2 (4 samples, 0.20%) _ZN7Monitor6unlockEv (1 samples, 0.05%) intel_pstate_set_pstate (1 samples, 0.05%) schedule (8 samples, 0.40%) _ZNK13WatcherThread5sleepEv (16 samples, 0.80%) __fget_light (2 samples, 0.10%) sysret_careful (4 samples, 0.20%) perf_pmu_disable (1 samples, 0.05%) pthread_cond_timedwait@@GLIBC_2.3.2 (8 samples, 0.40%) futex_wait (8 samples, 0.40%) enqueue_task (1 samples, 0.05%) native_write_msr_safe (4 samples, 0.20%) local_apic_timer_interrupt (2 samples, 0.10%) memzero_explicit (1 samples, 0.05%) java/util/HashMap:.hash in Ljava/util/LinkedHashMap:.get (1 samples, 0.05%) smp_apic_timer_interrupt (1 samples, 0.05%) smp_apic_timer_interrupt (1 samples, 0.05%) tick_sched_handle.isra.16 (1 samples, 0.05%) schedule (64 samples, 3.18%) enqueue_task_fair (1 samples, 0.05%) start_thread (1,988 samples, 98.91%) start_thread __mix_pool_bytes (2 samples, 0.10%) __pthread_enable_asynccancel (1 samples, 0.05%) retint_careful (1 samples, 0.05%) _ZN2os14javaTimeMillisEv (3 samples, 0.15%) java/io/FileInputStream:.readBytes (200 samples, 9.95%) java/.. sun/security/provider/SHA:.implDigest in Lsun/security/provider/DigestBase:.engineDigest (1 samples, 0.05%) try_to_wake_up (3 samples, 0.15%) java/lang/StringBuilder:.append in Ljava/security/MessageDigest:.getInstance (1 samples, 0.05%) futex_wait (12 samples, 0.60%) jbyte_disjoint_arraycopy (2 samples, 0.10%) intel_pmu_enable_all (4 samples, 0.20%) jlong_disjoint_arraycopy (1 samples, 0.05%) _new_array_nozero_Java (5 samples, 0.25%) __fsnotify_parent (1 samples, 0.05%) x86_pmu_enable (12 samples, 0.60%) send_sigqueue (1 samples, 0.05%) __schedule (45 samples, 2.24%) java/security/Provider:.checkInitialized in Ljava/security/Provider:.getService (1 samples, 0.05%) x86_pmu_enable (12 samples, 0.60%) sys_futex (14 samples, 0.70%) _ZN10JavaThread7oops_doEP10OopClosureP10CLDClosureP15CodeBlobClosure (3 samples, 0.15%) __vdso_gettimeofday (3 samples, 0.15%) __perf_event_task_sched_in (4 samples, 0.20%) __pthread_mutex_cond_lock (1 samples, 0.05%) perf_pmu_enable (4 samples, 0.20%) send_sigqueue (1 samples, 0.05%) ttwu_do_activate.constprop.94 (1 samples, 0.05%) _ZN2os5sleepEP6Threadlb (60 samples, 2.99%) timerqueue_del (1 samples, 0.05%) wake_up_state (3 samples, 0.15%) sun/security/jca/GetInstance:.getInstance in Lsun/security/jca/GetInstance:.getInstance (1 samples, 0.05%) smp_call_function_single_interrupt (1 samples, 0.05%) intel_pmu_enable_all (4 samples, 0.20%) jshort_disjoint_arraycopy (243 samples, 12.09%) jshort_.. xfer_secondary_pool (1 samples, 0.05%) schedule_user (5 samples, 0.25%) __perf_event_task_sched_in (4 samples, 0.20%) futex_wait (4 samples, 0.20%) perf_event_context_sched_in (64 samples, 3.18%) select_task_rq_fair (1 samples, 0.05%) finish_task_switch (4 samples, 0.20%) jshort_arraycopy (1 samples, 0.05%) futex_wait_queue_me (8 samples, 0.40%) java/lang/AbstractStringBuilder:.init in Ljava/util/UUID:.toString (3 samples, 0.15%) hrtimer_interrupt (2 samples, 0.10%) posix_timer_event (1 samples, 0.05%) wake_up_process (1 samples, 0.05%) try_to_wake_up (1 samples, 0.05%) ttwu_do_activate.constprop.94 (1 samples, 0.05%) _ZN20SafepointSynchronize5blockEP10JavaThread (4 samples, 0.20%) _ZN7Monitor4waitEblb (67 samples, 3.33%) complete_signal (1 samples, 0.05%) native_write_msr_safe (4 samples, 0.20%) finish_task_switch (8 samples, 0.40%) jni_GetObjectField (1 samples, 0.05%) _raw_spin_unlock_irqrestore (1 samples, 0.05%) update_process_times (1 samples, 0.05%) __run_hrtimer (1 samples, 0.05%) _ZN9JavaCalls11call_helperEP9JavaValueP12methodHandleP17JavaCallArgumentsP6Thread (1,851 samples, 92.09%) _ZN9JavaCalls11call_helperEP9JavaValueP12methodHandleP17JavaCallAr.. perf_event_task_tick (1 samples, 0.05%) local_apic_timer_interrupt (1 samples, 0.05%) hrtimer_interrupt (1 samples, 0.05%) _ZN7Monitor5IWaitEP6Threadl (8 samples, 0.40%) java/lang/StringBuilder:.append in Ljava/lang/StringCoding:.encode (4 samples, 0.20%) x86_pmu_enable (40 samples, 1.99%) smp_apic_timer_interrupt (1 samples, 0.05%) java/util/UUID:.randomUUID in Lorg/wso2/example/JavaThreadCPUUsage/HeavyThread:.run (79 samples, 3.93%) enqueue_task_fair (1 samples, 0.05%) activate_task (1 samples, 0.05%) futex_wait (64 samples, 3.18%) native_write_msr_safe (8 samples, 0.40%) __run_hrtimer (1 samples, 0.05%) _ZN9OopMapSet6all_doEPK5framePK11RegisterMapP10OopClosurePFvPP7oopDescSA_ES7_ (1 samples, 0.05%) local_apic_timer_interrupt (1 samples, 0.05%) _ZN13GCTaskManager16execute_and_waitEP11GCTaskQueue (8 samples, 0.40%) enqueue_task_fair (1 samples, 0.05%) futex_wait (14 samples, 0.70%) perf_event_context_sched_in (4 samples, 0.20%) system_call_fastpath (14 samples, 0.70%) futex_wait_queue_me (45 samples, 2.24%) remote_function (4 samples, 0.20%) intel_pmu_enable_all (8 samples, 0.40%) account_user_time (1 samples, 0.05%) smp_apic_timer_interrupt (2 samples, 0.10%) __remove_hrtimer (1 samples, 0.05%) do_futex (8 samples, 0.40%) posix_timer_fn (1 samples, 0.05%) java/security/MessageDigest$Delegate:.engineDigest in Lsun/security/provider/NativePRNG$RandomIO:.implNextBytes (3 samples, 0.15%) signal_wake_up_state (1 samples, 0.05%) futex_wait_queue_me (14 samples, 0.70%) perf_pmu_enable (40 samples, 1.99%) java/io/FileInputStream:.read (200 samples, 9.95%) java/.. scheduler_tick (1 samples, 0.05%) system_call_fastpath (1 samples, 0.05%) update_curr (1 samples, 0.05%) __perf_event_task_sched_in (8 samples, 0.40%) enqueue_task_fair (1 samples, 0.05%) flush_smp_call_function_queue (4 samples, 0.20%) jlong_disjoint_arraycopy (5 samples, 0.25%) hrtimer_wakeup (1 samples, 0.05%) dequeue_task (1 samples, 0.05%) finish_task_switch (8 samples, 0.40%) hrtimer_wakeup (1 samples, 0.05%) x86_pmu_enable (4 samples, 0.20%) apic_timer_interrupt (1 samples, 0.05%) finish_task_switch (4 samples, 0.20%) signal_wake_up_state (1 samples, 0.05%) update_curr (1 samples, 0.05%) system_call_fastpath (1 samples, 0.05%) system_call_fastpath (4 samples, 0.20%) rcu_irq_exit (1 samples, 0.05%) sys_read (168 samples, 8.36%) sys_.. apic_timer_interrupt (1 samples, 0.05%) perf_pmu_enable (4 samples, 0.20%) posix_timer_event (1 samples, 0.05%)

If there are any questions, please ask in comments. 

Comments

karthik said…

I'm profiling the CPU performance using perf_events and generate the FlameGraph. In the FlameGraph stack traces did not show about my struts action class methods. I already enable PreserveFramePointer option in VM arguments and create a perf-map using perf-map-agent . my perf was record other java class methods.But does not record struts2 action class files.
Isuru Perera said…
Hello, the frames may be missing due to inlining. There is a profiler named "Async Profiler". Can you try to get a profile using Async Profiler?

Popular posts from this blog

Specifying a custom Event Settings file for Java Flight Recorder

Flame Graphs with Java Flight Recordings

Benchmarking Java Locks with Counters