DTT/Examples/j_profile_example.txt

The following are examples of j_profile.d.

This script samples on-CPU stack traces and prints them with Java
translations.  With DTrace, as well as tracing events, you can also sample
them.  Each approach has its own advantages and disadvantages and you are
encouraged to try both when investigating performance issues (especially
tracing).  Sampling is inaccurate and can miss events, yet is a quick and
easy way to discover a certain set of performance issues involving on-CPU
load.

This script samples at 101 Hertz, printing out the 25 most frequently seen
stack traces down to 10 lines deep. All of these values can be tweaked in
the script.

Here we run the script on Code/Java/Func_loop.  The argument fed to the script
is the PID of the Java program we wish to investigate.  Here the raw output is
show, then again after filtering using c++filt.

# j_profile.d -p 1312
Sampling 10-level stacks at 101 Hertz... Hit Ctrl-C to end.
^C

Top 25 most frequently sampled stacks,


              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
              libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
              libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
              libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               30

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
              libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
              libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
              libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               31

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
              libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
              libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
              libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               32

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
              libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
              libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
              libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               33

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
              libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
              libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
              libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               41

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
              libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
              libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
              libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               72

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
              libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
              libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
              libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
              116


The most frequent stacks had Func_loop.func_c() on CPU, with a stack trace
showing func_b() and func_a() - as expected from the source to Func_loop.java.


Now passing that output through c++filt to translate the compiled C++ symbols
of the JVM.

# j_profile.d -p 1312 -o out.j_profile
# c++filt out.j_profile
Sampling 10-level stacks at 101 Hertz... Hit Ctrl-C to end.

Top 25 most frequently sampled stacks,


              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
              libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
              libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
              libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               10

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
              libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
              libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
              libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               13

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
              libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
              libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
              libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               19

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
              libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
              libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
              libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               21

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
              libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
              libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
              libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               29

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
              libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
              libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
              libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               53

              Func_loop.func_c()V
              Func_loop.func_b()V
              Func_loop.func_a()V
              Func_loop.main([Ljava/lang/String;)V
              StubRoutines (1)
              libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
              libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
              libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
              libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
              libjvm.so`jni_CallStaticVoidMethod+0x15d
               74