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