cddl/contrib/dtracetoolkit/Examples/j_profile_example.txt

   1 The following are examples of j_profile.d.
   2
   3 This script samples on-CPU stack traces and prints them with Java
   4 translations.  With DTrace, as well as tracing events, you can also sample
   5 them.  Each approach has its own advantages and disadvantages and you are
   6 encouraged to try both when investigating performance issues (especially
   7 tracing).  Sampling is inaccurate and can miss events, yet is a quick and
   8 easy way to discover a certain set of performance issues involving on-CPU
   9 load.
  10
  11 This script samples at 101 Hertz, printing out the 25 most frequently seen
  12 stack traces down to 10 lines deep. All of these values can be tweaked in
  13 the script.
  14
  15 Here we run the script on Code/Java/Func_loop.  The argument fed to the script
  16 is the PID of the Java program we wish to investigate.  Here the raw output is
  17 show, then again after filtering using c++filt.
  18
  19 # j_profile.d -p 1312
  20 Sampling 10-level stacks at 101 Hertz... Hit Ctrl-C to end.
  21 ^C
  22
  23 Top 25 most frequently sampled stacks,
  24
  25
  26               Func_loop.func_c()V
  27               Func_loop.func_b()V
  28               Func_loop.func_a()V
  29               Func_loop.main([Ljava/lang/String;)V
  30               StubRoutines (1)
  31               libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
  32               libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
  33               libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
  34               libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
  35               libjvm.so`jni_CallStaticVoidMethod+0x15d
  36                30
  37
  38               Func_loop.func_c()V
  39               Func_loop.func_b()V
  40               Func_loop.func_a()V
  41               Func_loop.main([Ljava/lang/String;)V
  42               StubRoutines (1)
  43               libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
  44               libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
  45               libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
  46               libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
  47               libjvm.so`jni_CallStaticVoidMethod+0x15d
  48                31
  49
  50               Func_loop.func_c()V
  51               Func_loop.func_b()V
  52               Func_loop.func_a()V
  53               Func_loop.main([Ljava/lang/String;)V
  54               StubRoutines (1)
  55               libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
  56               libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
  57               libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
  58               libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
  59               libjvm.so`jni_CallStaticVoidMethod+0x15d
  60                32
  61
  62               Func_loop.func_c()V
  63               Func_loop.func_b()V
  64               Func_loop.func_a()V
  65               Func_loop.main([Ljava/lang/String;)V
  66               StubRoutines (1)
  67               libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
  68               libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
  69               libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
  70               libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
  71               libjvm.so`jni_CallStaticVoidMethod+0x15d
  72                33
  73
  74               Func_loop.func_c()V
  75               Func_loop.func_b()V
  76               Func_loop.func_a()V
  77               Func_loop.main([Ljava/lang/String;)V
  78               StubRoutines (1)
  79               libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
  80               libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
  81               libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
  82               libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
  83               libjvm.so`jni_CallStaticVoidMethod+0x15d
  84                41
  85
  86               Func_loop.func_c()V
  87               Func_loop.func_b()V
  88               Func_loop.func_a()V
  89               Func_loop.main([Ljava/lang/String;)V
  90               StubRoutines (1)
  91               libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
  92               libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
  93               libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
  94               libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
  95               libjvm.so`jni_CallStaticVoidMethod+0x15d
  96                72
  97
  98               Func_loop.func_c()V
  99               Func_loop.func_b()V
 100               Func_loop.func_a()V
 101               Func_loop.main([Ljava/lang/String;)V
 102               StubRoutines (1)
 103               libjvm.so`__1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x1a3
 104               libjvm.so`__1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_+0x27
 105               libjvm.so`__1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_+0x2f
 106               libjvm.so`__1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_+0x1df
 107               libjvm.so`jni_CallStaticVoidMethod+0x15d
 108               116
 109
 110
 111 The most frequent stacks had Func_loop.func_c() on CPU, with a stack trace
 112 showing func_b() and func_a() - as expected from the source to Func_loop.java.
 113
 114
 115 Now passing that output through c++filt to translate the compiled C++ symbols
 116 of the JVM.
 117
 118 # j_profile.d -p 1312 -o out.j_profile
 119 # c++filt out.j_profile
 120 Sampling 10-level stacks at 101 Hertz... Hit Ctrl-C to end.
 121
 122 Top 25 most frequently sampled stacks,
 123
 124
 125               Func_loop.func_c()V
 126               Func_loop.func_b()V
 127               Func_loop.func_a()V
 128               Func_loop.main([Ljava/lang/String;)V
 129               StubRoutines (1)
 130               libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
 131               libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
 132               libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
 133               libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
 134               libjvm.so`jni_CallStaticVoidMethod+0x15d
 135                10
 136
 137               Func_loop.func_c()V
 138               Func_loop.func_b()V
 139               Func_loop.func_a()V
 140               Func_loop.main([Ljava/lang/String;)V
 141               StubRoutines (1)
 142               libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
 143               libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
 144               libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
 145               libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
 146               libjvm.so`jni_CallStaticVoidMethod+0x15d
 147                13
 148
 149               Func_loop.func_c()V
 150               Func_loop.func_b()V
 151               Func_loop.func_a()V
 152               Func_loop.main([Ljava/lang/String;)V
 153               StubRoutines (1)
 154               libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
 155               libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
 156               libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
 157               libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
 158               libjvm.so`jni_CallStaticVoidMethod+0x15d
 159                19
 160
 161               Func_loop.func_c()V
 162               Func_loop.func_b()V
 163               Func_loop.func_a()V
 164               Func_loop.main([Ljava/lang/String;)V
 165               StubRoutines (1)
 166               libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
 167               libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
 168               libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
 169               libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
 170               libjvm.so`jni_CallStaticVoidMethod+0x15d
 171                21
 172
 173               Func_loop.func_c()V
 174               Func_loop.func_b()V
 175               Func_loop.func_a()V
 176               Func_loop.main([Ljava/lang/String;)V
 177               StubRoutines (1)
 178               libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
 179               libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
 180               libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
 181               libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
 182               libjvm.so`jni_CallStaticVoidMethod+0x15d
 183                29
 184
 185               Func_loop.func_c()V
 186               Func_loop.func_b()V
 187               Func_loop.func_a()V
 188               Func_loop.main([Ljava/lang/String;)V
 189               StubRoutines (1)
 190               libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
 191               libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
 192               libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
 193               libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
 194               libjvm.so`jni_CallStaticVoidMethod+0x15d
 195                53
 196
 197               Func_loop.func_c()V
 198               Func_loop.func_b()V
 199               Func_loop.func_a()V
 200               Func_loop.main([Ljava/lang/String;)V
 201               StubRoutines (1)
 202               libjvm.so`void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x1a3
 203               libjvm.so`void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x27
 204               libjvm.so`void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*)+0x2f
 205               libjvm.so`void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*)+0x1df
 206               libjvm.so`jni_CallStaticVoidMethod+0x15d
 207                74
 208
 209