1 This is an example of j_calldist.d showing the elapsed times for different 2 types of Java operations. 3 4 This traces activity from all Java processes on the system with hotspot 5 provider support (1.6.0), and produces the output in graphical format, showing 6 a histogram of the amount of time taken by each call. Method calls are only 7 visible when using the flag "+ExtendedDTraceProbes". eg, 8 java -XX:+ExtendedDTraceProbes classfile 9 10 Because of the extensive results returned otherwise, this script will show you 11 a configurable number of results in each section. The default (as in this 12 example) is ten. 13 14 Here we see it tracing the activity of Code/Java/Func_abc. 15 16 # j_calldist.d 17 Tracing... Hit Ctrl-C to end. 18 ^C 19 20 Top 10 elapsed times (us), 21 22 Top 10 exclusive method elapsed times (us), 23 PID=311342, method, sun/net/www/ParseUtil.decode 24 value ------------- Distribution ------------- count 25 128 | 0 26 256 |@@@@@@@@@@@@@ 3 27 512 | 0 28 1024 |@@@@@@@@@@@@@@@@@@@@@@ 5 29 2048 |@@@@ 1 30 4096 | 0 31 32 PID=311342, method, java/net/URLClassLoader.<clinit> 33 value ------------- Distribution ------------- count 34 4096 | 0 35 8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 36 16384 | 0 37 38 PID=311342, method, java/util/jar/JarFile.hasClassPathAttribute 39 value ------------- Distribution ------------- count 40 4096 | 0 41 8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 42 16384 | 0 43 44 PID=311342, method, java/util/zip/ZipFile.read 45 value ------------- Distribution ------------- count 46 4096 | 0 47 8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 48 16384 | 0 49 50 PID=311342, method, sun/nio/cs/US_ASCII.newEncoder 51 value ------------- Distribution ------------- count 52 4 | 0 53 8 |@@@@@@@@@@@@@@@@@@@@ 1 54 16 | 0 55 32 | 0 56 64 | 0 57 128 | 0 58 256 | 0 59 512 | 0 60 1024 | 0 61 2048 | 0 62 4096 | 0 63 8192 |@@@@@@@@@@@@@@@@@@@@ 1 64 16384 | 0 65 66 PID=311342, method, java/util/zip/ZipFile.getInputStream 67 value ------------- Distribution ------------- count 68 8 | 0 69 16 |@@@@@@@@@@@@@@@@@@@@ 1 70 32 | 0 71 64 | 0 72 128 | 0 73 256 | 0 74 512 | 0 75 1024 | 0 76 2048 | 0 77 4096 | 0 78 8192 |@@@@@@@@@@@@@@@@@@@@ 1 79 16384 | 0 80 81 PID=311342, method, sun/nio/cs/US_ASCII.newDecoder 82 value ------------- Distribution ------------- count 83 4 | 0 84 8 |@@@@@@@@@@ 1 85 16 |@@@@@@@@@@@@@@@@@@@@ 2 86 32 | 0 87 64 | 0 88 128 | 0 89 256 | 0 90 512 | 0 91 1024 | 0 92 2048 | 0 93 4096 | 0 94 8192 |@@@@@@@@@@ 1 95 16384 | 0 96 97 PID=311342, method, java/util/HashMap.<init> 98 value ------------- Distribution ------------- count 99 4 | 0 100 8 |@@@@@@@@@@@@@@ 8 101 16 |@@@@@@@@@@@@@@@@ 9 102 32 |@@@@@@@@@ 5 103 64 | 0 104 128 | 0 105 256 | 0 106 512 | 0 107 1024 | 0 108 2048 | 0 109 4096 | 0 110 8192 |@@ 1 111 16384 | 0 112 113 PID=311342, method, java/io/UnixFileSystem.normalize 114 value ------------- Distribution ------------- count 115 4 | 0 116 8 |@ 1 117 16 | 0 118 32 | 0 119 64 |@@@@@@@@@ 8 120 128 |@@@@@@@@@@@@@ 11 121 256 |@@@@@@ 5 122 512 |@@@@@@@@@ 8 123 1024 | 0 124 2048 | 0 125 4096 |@ 1 126 8192 | 0 127 128 PID=311342, method, java/lang/Thread.sleep 129 value ------------- Distribution ------------- count 130 262144 | 0 131 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 132 1048576 | 0 133 134 135 Top 10 inclusive method elapsed times (us), 136 PID=311342, method, java/net/URLClassLoader$1.run 137 value ------------- Distribution ------------- count 138 8192 | 0 139 16384 |@@@@@@@@@@@@@@@@@@@@ 1 140 32768 | 0 141 65536 |@@@@@@@@@@@@@@@@@@@@ 1 142 131072 | 0 143 144 PID=311342, method, java/net/URLClassLoader.findClass 145 value ------------- Distribution ------------- count 146 8192 | 0 147 16384 |@@@@@@@@@@@@@@@@@@@@ 1 148 32768 | 0 149 65536 |@@@@@@@@@@@@@@@@@@@@ 1 150 131072 | 0 151 152 PID=311342, method, sun/misc/URLClassPath.getLoader 153 value ------------- Distribution ------------- count 154 8 | 0 155 16 |@@@ 1 156 32 | 0 157 64 | 0 158 128 | 0 159 256 | 0 160 512 | 0 161 1024 | 0 162 2048 |@@@@@@ 2 163 4096 |@@@@@@@@@@@@@@@@@@@@@@@@@ 8 164 8192 | 0 165 16384 |@@@ 1 166 32768 | 0 167 65536 |@@@ 1 168 131072 | 0 169 170 PID=311342, method, java/lang/ClassLoader.loadClass 171 value ------------- Distribution ------------- count 172 64 | 0 173 128 |@@@@@@@@@ 6 174 256 |@@@@@@@@@@@@@@@@@@@@@@ 15 175 512 |@@@@ 3 176 1024 | 0 177 2048 | 0 178 4096 | 0 179 8192 | 0 180 16384 | 0 181 32768 | 0 182 65536 |@@@@ 3 183 131072 | 0 184 185 PID=311342, method, java/security/AccessController.doPrivileged 186 value ------------- Distribution ------------- count 187 8 | 0 188 16 |@@ 2 189 32 |@ 1 190 64 |@@@@ 4 191 128 |@@@@@@@@@@@@@@@@ 17 192 256 |@ 1 193 512 |@@@@ 4 194 1024 |@@ 2 195 2048 |@ 1 196 4096 |@@@@@@ 6 197 8192 |@ 1 198 16384 |@@ 2 199 32768 | 0 200 65536 |@@ 2 201 131072 | 0 202 203 PID=311342, method, Func_abc.func_c 204 value ------------- Distribution ------------- count 205 262144 | 0 206 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 207 1048576 | 0 208 209 PID=311342, method, Func_abc.func_b 210 value ------------- Distribution ------------- count 211 524288 | 0 212 1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 213 2097152 | 0 214 215 PID=311342, method, java/lang/Thread.sleep 216 value ------------- Distribution ------------- count 217 262144 | 0 218 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 219 1048576 | 0 220 221 PID=311342, method, Func_abc.func_a 222 value ------------- Distribution ------------- count 223 1048576 | 0 224 2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 225 4194304 | 0 226 227 PID=311342, method, Func_abc.main 228 value ------------- Distribution ------------- count 229 1048576 | 0 230 2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 231 4194304 | 0 232 233 The elapsed times section is empty. It would show us anything that is not a 234 Java method - garbage collection for example. However there was nothing of 235 the kind in this example. 236 237 The exclusive method elapsed times show us the time spent in the top ten most 238 time consuming methods, not including time spent in subroutines called by 239 those methods. 240 241 The inclusive method elapsed times show us the time spent in the top ten most 242 time consuming methods including time spent in subroutines called by those 243 methods. 244 245 It is important to pay close attention to the third column, "count" as this 246 will indicate if there were any instances in a particular timeframe, even if 247 the number is too small to show up on the histogram clearly. 248
Indexes created Mon Apr 27 00:23:16 UTC 2026