253 lines
14 KiB
Plaintext
253 lines
14 KiB
Plaintext
This is an example of j_cpudist.d showing the elapsed times for different
|
|
types of Java operations.
|
|
|
|
This traces activity from all Java processes on the system with hotspot
|
|
provider support (1.6.0), and produces the output in graphical format, showing
|
|
a histogram of the amount of time taken by each call. Method calls are only
|
|
visible when using the flag "+ExtendedDTraceProbes". eg,
|
|
java -XX:+ExtendedDTraceProbes classfile
|
|
|
|
Because of the extensive results returned otherwise, this script will show you
|
|
a configurable number of results in each section. The default (as in this
|
|
example) is ten.
|
|
|
|
Here we see it tracing the activity of Code/Java/Func_abc.
|
|
|
|
# j_cpudist.d
|
|
Tracing... Hit Ctrl-C to end.
|
|
^C
|
|
|
|
Top 10 on-CPU times (us),
|
|
|
|
Top 10 exclusive method on-CPU times (us),
|
|
PID=311364, method, java/lang/AbstractStringBuilder.append
|
|
value ------------- Distribution ------------- count
|
|
0 | 0
|
|
1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 382
|
|
2 |@@@@@@@@@@@ 151
|
|
4 |@ 13
|
|
8 | 1
|
|
16 | 1
|
|
32 | 1
|
|
64 | 0
|
|
|
|
PID=311364, method, java/util/Arrays.copyOf
|
|
value ------------- Distribution ------------- count
|
|
1 | 0
|
|
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 68
|
|
4 |@@@@@@@ 15
|
|
8 | 0
|
|
16 | 0
|
|
32 | 1
|
|
64 | 1
|
|
128 | 0
|
|
256 |@ 2
|
|
512 | 0
|
|
|
|
PID=311364, method, java/io/UnixFileSystem.normalize
|
|
value ------------- Distribution ------------- count
|
|
1 | 0
|
|
2 |@ 1
|
|
4 | 0
|
|
8 |@@@@@@@@@@@ 9
|
|
16 |@@@@@@@@@@@@@@ 12
|
|
32 |@@@@@@ 5
|
|
64 |@@@@@@@ 6
|
|
128 |@ 1
|
|
256 | 0
|
|
|
|
PID=311364, method, java/io/File.<clinit>
|
|
value ------------- Distribution ------------- count
|
|
512 | 0
|
|
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
2048 | 0
|
|
|
|
PID=311364, method, sun/misc/URLClassPath$JarLoader.getJarFile
|
|
value ------------- Distribution ------------- count
|
|
512 | 0
|
|
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
2048 | 0
|
|
|
|
PID=311364, method, java/io/FilePermission$1.run
|
|
value ------------- Distribution ------------- count
|
|
1 | 0
|
|
2 |@@@@@@@@@@@@@@@@@@@@ 2
|
|
4 |@@@@@@@@@@ 1
|
|
8 | 0
|
|
16 | 0
|
|
32 | 0
|
|
64 | 0
|
|
128 | 0
|
|
256 | 0
|
|
512 | 0
|
|
1024 |@@@@@@@@@@ 1
|
|
2048 | 0
|
|
|
|
PID=311364, method, java/lang/StringBuilder.append
|
|
value ------------- Distribution ------------- count
|
|
1 | 0
|
|
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 526
|
|
4 | 2
|
|
8 | 0
|
|
16 | 4
|
|
32 | 1
|
|
64 | 0
|
|
|
|
PID=311364, method, java/lang/String.<init>
|
|
value ------------- Distribution ------------- count
|
|
1 | 0
|
|
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 162
|
|
4 |@@ 10
|
|
8 | 0
|
|
16 | 0
|
|
32 | 0
|
|
64 | 1
|
|
128 | 0
|
|
256 | 1
|
|
512 | 0
|
|
1024 | 1
|
|
2048 | 0
|
|
|
|
PID=311364, method, java/lang/String.charAt
|
|
value ------------- Distribution ------------- count
|
|
0 | 0
|
|
1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1953
|
|
2 | 3
|
|
4 | 1
|
|
8 | 1
|
|
16 | 2
|
|
32 | 0
|
|
|
|
PID=311364, method, java/lang/System.initializeSystemClass
|
|
value ------------- Distribution ------------- count
|
|
1024 | 0
|
|
2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
4096 | 0
|
|
|
|
|
|
Top 10 inclusive method on-CPU times (us),
|
|
PID=311364, method, sun/misc/Launcher$ExtClassLoader.<init>
|
|
value ------------- Distribution ------------- count
|
|
8192 | 0
|
|
16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
32768 | 0
|
|
|
|
PID=311364, method, sun/misc/Launcher$ExtClassLoader.getExtClassLoader
|
|
value ------------- Distribution ------------- count
|
|
8192 | 0
|
|
16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
32768 | 0
|
|
|
|
PID=311364, method, sun/misc/Launcher$ExtClassLoader.getExtURLs
|
|
value ------------- Distribution ------------- count
|
|
8192 | 0
|
|
16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
32768 | 0
|
|
|
|
PID=311364, method, sun/misc/Launcher.<clinit>
|
|
value ------------- Distribution ------------- count
|
|
8192 | 0
|
|
16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
32768 | 0
|
|
|
|
PID=311364, method, sun/misc/Launcher.<init>
|
|
value ------------- Distribution ------------- count
|
|
8192 | 0
|
|
16384 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
32768 | 0
|
|
|
|
PID=311364, method, java/lang/ClassLoader.loadClassInternal
|
|
value ------------- Distribution ------------- count
|
|
32 | 0
|
|
64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 6
|
|
128 |@@@@@@@@@ 2
|
|
256 | 0
|
|
512 | 0
|
|
1024 | 0
|
|
2048 | 0
|
|
4096 | 0
|
|
8192 | 0
|
|
16384 |@@@@ 1
|
|
32768 | 0
|
|
|
|
PID=311364, method, sun/misc/Launcher$AppClassLoader.loadClass
|
|
value ------------- Distribution ------------- count
|
|
32 | 0
|
|
64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 6
|
|
128 |@@@@@@@@@ 2
|
|
256 | 0
|
|
512 | 0
|
|
1024 | 0
|
|
2048 | 0
|
|
4096 | 0
|
|
8192 | 0
|
|
16384 |@@@@ 1
|
|
32768 | 0
|
|
|
|
PID=311364, method, sun/misc/URLClassPath.getLoader
|
|
value ------------- Distribution ------------- count
|
|
2 | 0
|
|
4 |@@@ 1
|
|
8 | 0
|
|
16 | 0
|
|
32 | 0
|
|
64 | 0
|
|
128 | 0
|
|
256 |@@@ 1
|
|
512 |@@@@@@@@@@@@@@@@@@@@@@ 7
|
|
1024 |@@@@@@ 2
|
|
2048 | 0
|
|
4096 |@@@ 1
|
|
8192 |@@@ 1
|
|
16384 | 0
|
|
|
|
PID=311364, method, java/lang/ClassLoader.loadClass
|
|
value ------------- Distribution ------------- count
|
|
16 | 0
|
|
32 |@@@@@@@@@ 6
|
|
64 |@@@@@@@@@@@@@@@@@@@@@ 14
|
|
128 |@@@@@@ 4
|
|
256 | 0
|
|
512 | 0
|
|
1024 | 0
|
|
2048 | 0
|
|
4096 | 0
|
|
8192 |@ 1
|
|
16384 |@@@ 2
|
|
32768 | 0
|
|
|
|
PID=311364, method, java/security/AccessController.doPrivileged
|
|
value ------------- Distribution ------------- count
|
|
2 | 0
|
|
4 |@ 1
|
|
8 |@@@@ 4
|
|
16 |@@@@@@@@@@ 11
|
|
32 |@@@@@@@@@@ 11
|
|
64 | 0
|
|
128 |@@@ 3
|
|
256 |@ 1
|
|
512 |@@@@@ 5
|
|
1024 |@@ 2
|
|
2048 |@ 1
|
|
4096 |@ 1
|
|
8192 |@@ 2
|
|
16384 |@ 1
|
|
32768 | 0
|
|
|
|
The elapsed times section is empty. It would show us anything that is not a
|
|
Java method - garbage collection for example. However there was nothing of
|
|
the kind in this example.
|
|
|
|
The exclusive method elapsed times show us the time spent on-CPU by the most
|
|
time consuming methods, not including time spent in subroutines called by
|
|
those methods.
|
|
|
|
The inclusive method elapsed times show us the time spent on-CPU by the top
|
|
ten most time consuming methods including time spent in subroutines called by
|
|
those methods.
|
|
|
|
It is important to pay close attention to the third column, "count" as this
|
|
will indicate if there were any instances in a particular timeframe, even if
|
|
the number is too small to show up on the histogram clearly.
|
|
|