-
Notifications
You must be signed in to change notification settings - Fork 133
/
Copy pathj_cpudist_example.txt
252 lines (221 loc) · 14.3 KB
/
j_cpudist_example.txt
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
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.