author | alanb |
Fri, 02 Nov 2012 15:50:11 +0000 | |
changeset 14342 | 8435a30053c1 |
parent 10292 | ed7db6a12c2a |
permissions | -rw-r--r-- |
2 | 1 |
/* |
14342
8435a30053c1
7197491: update copyright year to match last edit in jdk8 jdk repository
alanb
parents:
10292
diff
changeset
|
2 |
* Copyright (c) 2003, 2011, Oracle and/or its affiliates. All rights reserved. |
2 | 3 |
* |
4 |
* Redistribution and use in source and binary forms, with or without |
|
5 |
* modification, are permitted provided that the following conditions |
|
6 |
* are met: |
|
7 |
* |
|
8 |
* - Redistributions of source code must retain the above copyright |
|
9 |
* notice, this list of conditions and the following disclaimer. |
|
10 |
* |
|
11 |
* - Redistributions in binary form must reproduce the above copyright |
|
12 |
* notice, this list of conditions and the following disclaimer in the |
|
13 |
* documentation and/or other materials provided with the distribution. |
|
14 |
* |
|
5506 | 15 |
* - Neither the name of Oracle nor the names of its |
2 | 16 |
* contributors may be used to endorse or promote products derived |
17 |
* from this software without specific prior written permission. |
|
18 |
* |
|
19 |
* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS |
|
20 |
* IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, |
|
21 |
* THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR |
|
22 |
* PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR |
|
23 |
* CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, |
|
24 |
* EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, |
|
25 |
* PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR |
|
26 |
* PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF |
|
27 |
* LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING |
|
28 |
* NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS |
|
29 |
* SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. |
|
30 |
*/ |
|
31 |
||
10292
ed7db6a12c2a
7067811: Update demo/sample code to state it should not be used for production
nloodin
parents:
5506
diff
changeset
|
32 |
/* |
ed7db6a12c2a
7067811: Update demo/sample code to state it should not be used for production
nloodin
parents:
5506
diff
changeset
|
33 |
* This source code is provided to illustrate the usage of a given feature |
ed7db6a12c2a
7067811: Update demo/sample code to state it should not be used for production
nloodin
parents:
5506
diff
changeset
|
34 |
* or technique and has been deliberately simplified. Additional steps |
ed7db6a12c2a
7067811: Update demo/sample code to state it should not be used for production
nloodin
parents:
5506
diff
changeset
|
35 |
* required for a production-quality application, such as security checks, |
ed7db6a12c2a
7067811: Update demo/sample code to state it should not be used for production
nloodin
parents:
5506
diff
changeset
|
36 |
* input validation and proper error handling, might not be present in |
ed7db6a12c2a
7067811: Update demo/sample code to state it should not be used for production
nloodin
parents:
5506
diff
changeset
|
37 |
* this sample code. |
ed7db6a12c2a
7067811: Update demo/sample code to state it should not be used for production
nloodin
parents:
5506
diff
changeset
|
38 |
*/ |
ed7db6a12c2a
7067811: Update demo/sample code to state it should not be used for production
nloodin
parents:
5506
diff
changeset
|
39 |
|
ed7db6a12c2a
7067811: Update demo/sample code to state it should not be used for production
nloodin
parents:
5506
diff
changeset
|
40 |
|
2 | 41 |
/* Monitor contention tracking and monitor wait handling. */ |
42 |
||
43 |
/* |
|
44 |
* Monitor's under contention are unique per trace and signature. |
|
45 |
* Two monitors with the same trace and signature will be treated |
|
46 |
* the same as far as accumulated contention time. |
|
47 |
* |
|
48 |
* The tls table (or thread table) will be used to store the monitor in |
|
49 |
* contention or being waited on. |
|
50 |
* |
|
51 |
* Monitor wait activity is emitted as it happens. |
|
52 |
* |
|
53 |
* Monitor contention is tabulated and summarized at dump time. |
|
54 |
* |
|
55 |
*/ |
|
56 |
||
57 |
#include "hprof.h" |
|
58 |
||
59 |
typedef struct MonitorKey { |
|
60 |
TraceIndex trace_index; |
|
61 |
StringIndex sig_index; |
|
62 |
} MonitorKey; |
|
63 |
||
64 |
typedef struct MonitorInfo { |
|
65 |
jint num_hits; |
|
66 |
jlong contended_time; |
|
67 |
} MonitorInfo; |
|
68 |
||
69 |
typedef struct IterateInfo { |
|
70 |
MonitorIndex *monitors; |
|
71 |
int count; |
|
72 |
jlong total_contended_time; |
|
73 |
} IterateInfo; |
|
74 |
||
75 |
/* Private internal functions. */ |
|
76 |
||
77 |
static MonitorKey* |
|
78 |
get_pkey(MonitorIndex index) |
|
79 |
{ |
|
80 |
void * key_ptr; |
|
81 |
int key_len; |
|
82 |
||
83 |
table_get_key(gdata->monitor_table, index, &key_ptr, &key_len); |
|
84 |
HPROF_ASSERT(key_len==sizeof(MonitorKey)); |
|
85 |
HPROF_ASSERT(key_ptr!=NULL); |
|
86 |
return (MonitorKey*)key_ptr; |
|
87 |
} |
|
88 |
||
89 |
static MonitorInfo * |
|
90 |
get_info(MonitorIndex index) |
|
91 |
{ |
|
92 |
MonitorInfo * info; |
|
93 |
||
94 |
HPROF_ASSERT(index!=0); |
|
95 |
info = (MonitorInfo*)table_get_info(gdata->monitor_table, index); |
|
96 |
HPROF_ASSERT(info!=NULL); |
|
97 |
return info; |
|
98 |
} |
|
99 |
||
100 |
static MonitorIndex |
|
101 |
find_or_create_entry(JNIEnv *env, TraceIndex trace_index, jobject object) |
|
102 |
{ |
|
103 |
static MonitorKey empty_key; |
|
104 |
MonitorKey key; |
|
105 |
MonitorIndex index; |
|
106 |
char *sig; |
|
107 |
||
108 |
HPROF_ASSERT(object!=NULL); |
|
109 |
WITH_LOCAL_REFS(env, 1) { |
|
110 |
jclass clazz; |
|
111 |
||
112 |
clazz = getObjectClass(env, object); |
|
113 |
getClassSignature(clazz, &sig, NULL); |
|
114 |
} END_WITH_LOCAL_REFS; |
|
115 |
||
116 |
key = empty_key; |
|
117 |
key.trace_index = trace_index; |
|
118 |
key.sig_index = string_find_or_create(sig); |
|
119 |
jvmtiDeallocate(sig); |
|
120 |
index = table_find_or_create_entry(gdata->monitor_table, &key, |
|
121 |
(int)sizeof(key), NULL, NULL); |
|
122 |
return index; |
|
123 |
} |
|
124 |
||
125 |
static void |
|
126 |
cleanup_item(MonitorIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg) |
|
127 |
{ |
|
128 |
} |
|
129 |
||
130 |
static void |
|
131 |
list_item(TableIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg) |
|
132 |
{ |
|
133 |
MonitorInfo *info; |
|
134 |
MonitorKey *pkey; |
|
135 |
||
136 |
HPROF_ASSERT(key_len==sizeof(MonitorKey)); |
|
137 |
HPROF_ASSERT(key_ptr!=NULL); |
|
138 |
HPROF_ASSERT(info_ptr!=NULL); |
|
139 |
pkey = (MonitorKey*)key_ptr; |
|
140 |
info = (MonitorInfo *)info_ptr; |
|
141 |
debug_message( |
|
142 |
"Monitor 0x%08x: trace=0x%08x, sig=0x%08x, " |
|
143 |
"num_hits=%d, contended_time=(%d,%d)\n", |
|
144 |
index, |
|
145 |
pkey->trace_index, |
|
146 |
pkey->sig_index, |
|
147 |
info->num_hits, |
|
148 |
jlong_high(info->contended_time), |
|
149 |
jlong_low(info->contended_time)); |
|
150 |
} |
|
151 |
||
152 |
static void |
|
153 |
collect_iterator(MonitorIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg) |
|
154 |
{ |
|
155 |
MonitorInfo *info; |
|
156 |
IterateInfo *iterate; |
|
157 |
||
158 |
HPROF_ASSERT(key_len==sizeof(MonitorKey)); |
|
159 |
HPROF_ASSERT(info_ptr!=NULL); |
|
160 |
HPROF_ASSERT(arg!=NULL); |
|
161 |
iterate = (IterateInfo *)arg; |
|
162 |
info = (MonitorInfo *)info_ptr; |
|
163 |
iterate->monitors[iterate->count++] = index; |
|
164 |
iterate->total_contended_time += info->contended_time; |
|
165 |
} |
|
166 |
||
167 |
static int |
|
168 |
qsort_compare(const void *p_monitor1, const void *p_monitor2) |
|
169 |
{ |
|
170 |
MonitorInfo * info1; |
|
171 |
MonitorInfo * info2; |
|
172 |
MonitorIndex monitor1; |
|
173 |
MonitorIndex monitor2; |
|
174 |
jlong result; |
|
175 |
||
176 |
HPROF_ASSERT(p_monitor1!=NULL); |
|
177 |
HPROF_ASSERT(p_monitor2!=NULL); |
|
178 |
monitor1 = *(MonitorIndex *)p_monitor1; |
|
179 |
monitor2 = *(MonitorIndex *)p_monitor2; |
|
180 |
info1 = get_info(monitor1); |
|
181 |
info2 = get_info(monitor2); |
|
182 |
||
183 |
result = info2->contended_time - info1->contended_time; |
|
184 |
if (result < (jlong)0) { |
|
185 |
return -1; |
|
186 |
} else if ( result > (jlong)0 ) { |
|
187 |
return 1; |
|
188 |
} |
|
189 |
return info2->num_hits - info1->num_hits; |
|
190 |
} |
|
191 |
||
192 |
static void |
|
193 |
clear_item(MonitorIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg) |
|
194 |
{ |
|
195 |
MonitorInfo *info; |
|
196 |
||
197 |
HPROF_ASSERT(key_len==sizeof(MonitorKey)); |
|
198 |
HPROF_ASSERT(info_ptr!=NULL); |
|
199 |
info = (MonitorInfo *)info_ptr; |
|
200 |
info->contended_time = 0; |
|
201 |
} |
|
202 |
||
203 |
static TraceIndex |
|
204 |
get_trace(TlsIndex tls_index, JNIEnv *env) |
|
205 |
{ |
|
206 |
TraceIndex trace_index; |
|
207 |
||
208 |
trace_index = tls_get_trace(tls_index, env, gdata->max_trace_depth, JNI_FALSE); |
|
209 |
return trace_index; |
|
210 |
} |
|
211 |
||
212 |
/* External functions (called from hprof_init.c) */ |
|
213 |
||
214 |
void |
|
215 |
monitor_init(void) |
|
216 |
{ |
|
217 |
gdata->monitor_table = table_initialize("Monitor", |
|
218 |
32, 32, 31, (int)sizeof(MonitorInfo)); |
|
219 |
} |
|
220 |
||
221 |
void |
|
222 |
monitor_list(void) |
|
223 |
{ |
|
224 |
debug_message( |
|
225 |
"------------------- Monitor Table ------------------------\n"); |
|
226 |
table_walk_items(gdata->monitor_table, &list_item, NULL); |
|
227 |
debug_message( |
|
228 |
"----------------------------------------------------------\n"); |
|
229 |
} |
|
230 |
||
231 |
void |
|
232 |
monitor_cleanup(void) |
|
233 |
{ |
|
234 |
table_cleanup(gdata->monitor_table, &cleanup_item, (void*)NULL); |
|
235 |
gdata->monitor_table = NULL; |
|
236 |
} |
|
237 |
||
238 |
void |
|
239 |
monitor_clear(void) |
|
240 |
{ |
|
241 |
table_walk_items(gdata->monitor_table, &clear_item, NULL); |
|
242 |
} |
|
243 |
||
244 |
/* Contended monitor output */ |
|
245 |
void |
|
246 |
monitor_write_contended_time(JNIEnv *env, double cutoff) |
|
247 |
{ |
|
248 |
int n_entries; |
|
249 |
||
250 |
n_entries = table_element_count(gdata->monitor_table); |
|
251 |
if ( n_entries == 0 ) { |
|
252 |
return; |
|
253 |
} |
|
254 |
||
255 |
rawMonitorEnter(gdata->data_access_lock); { |
|
256 |
IterateInfo iterate; |
|
257 |
int i; |
|
258 |
int n_items; |
|
259 |
jlong total_contended_time; |
|
260 |
||
261 |
/* First write all trace we might refer to. */ |
|
262 |
trace_output_unmarked(env); |
|
263 |
||
264 |
/* Looking for an array of monitor index values of interest */ |
|
265 |
iterate.monitors = HPROF_MALLOC(n_entries*(int)sizeof(MonitorIndex)); |
|
266 |
(void)memset(iterate.monitors, 0, n_entries*(int)sizeof(MonitorIndex)); |
|
267 |
||
268 |
/* Get a combined total and an array of monitor index numbers */ |
|
269 |
iterate.total_contended_time = 0; |
|
270 |
iterate.count = 0; |
|
271 |
table_walk_items(gdata->monitor_table, &collect_iterator, &iterate); |
|
272 |
||
273 |
/* Sort that list */ |
|
274 |
n_entries = iterate.count; |
|
275 |
if ( n_entries > 0 ) { |
|
276 |
qsort(iterate.monitors, n_entries, sizeof(MonitorIndex), |
|
277 |
&qsort_compare); |
|
278 |
} |
|
279 |
||
280 |
/* Apply the cutoff */ |
|
281 |
n_items = 0; |
|
282 |
for (i = 0; i < n_entries; i++) { |
|
283 |
MonitorIndex index; |
|
284 |
MonitorInfo *info; |
|
285 |
double percent; |
|
286 |
||
287 |
index = iterate.monitors[i]; |
|
288 |
info = get_info(index); |
|
289 |
percent = (double)info->contended_time / |
|
290 |
(double)iterate.total_contended_time; |
|
291 |
if (percent < cutoff) { |
|
292 |
break; |
|
293 |
} |
|
294 |
iterate.monitors[n_items++] = index; |
|
295 |
} |
|
296 |
||
297 |
/* Output the items that make sense */ |
|
298 |
total_contended_time = iterate.total_contended_time / 1000000; |
|
299 |
||
300 |
if ( n_items > 0 && total_contended_time > 0 ) { |
|
301 |
double accum; |
|
302 |
||
303 |
/* Output the info on this monitor enter site */ |
|
304 |
io_write_monitor_header(total_contended_time); |
|
305 |
||
306 |
accum = 0.0; |
|
307 |
for (i = 0; i < n_items; i++) { |
|
308 |
MonitorIndex index; |
|
309 |
MonitorInfo *info; |
|
310 |
MonitorKey *pkey; |
|
311 |
double percent; |
|
312 |
char *sig; |
|
313 |
||
314 |
index = iterate.monitors[i]; |
|
315 |
pkey = get_pkey(index); |
|
316 |
info = get_info(index); |
|
317 |
||
318 |
sig = string_get(pkey->sig_index); |
|
319 |
||
320 |
percent = (double)info->contended_time / |
|
321 |
(double)iterate.total_contended_time * 100.0; |
|
322 |
accum += percent; |
|
323 |
io_write_monitor_elem(i + 1, percent, accum, |
|
324 |
info->num_hits, |
|
325 |
trace_get_serial_number(pkey->trace_index), |
|
326 |
sig); |
|
327 |
} |
|
328 |
io_write_monitor_footer(); |
|
329 |
} |
|
330 |
HPROF_FREE(iterate.monitors); |
|
331 |
} rawMonitorExit(gdata->data_access_lock); |
|
332 |
} |
|
333 |
||
334 |
void |
|
335 |
monitor_contended_enter_event(JNIEnv *env, jthread thread, jobject object) |
|
336 |
{ |
|
337 |
TlsIndex tls_index; |
|
338 |
MonitorIndex index; |
|
339 |
TraceIndex trace_index; |
|
340 |
||
341 |
HPROF_ASSERT(env!=NULL); |
|
342 |
HPROF_ASSERT(thread!=NULL); |
|
343 |
HPROF_ASSERT(object!=NULL); |
|
344 |
||
345 |
tls_index = tls_find_or_create(env, thread); |
|
346 |
HPROF_ASSERT(tls_get_monitor(tls_index)==0); |
|
347 |
trace_index = get_trace(tls_index, env); |
|
348 |
index = find_or_create_entry(env, trace_index, object); |
|
349 |
tls_monitor_start_timer(tls_index); |
|
350 |
tls_set_monitor(tls_index, index); |
|
351 |
} |
|
352 |
||
353 |
void |
|
354 |
monitor_contended_entered_event(JNIEnv* env, jthread thread, jobject object) |
|
355 |
{ |
|
356 |
TlsIndex tls_index; |
|
357 |
MonitorInfo *info; |
|
358 |
MonitorIndex index; |
|
359 |
||
360 |
HPROF_ASSERT(env!=NULL); |
|
361 |
HPROF_ASSERT(object!=NULL); |
|
362 |
HPROF_ASSERT(thread!=NULL); |
|
363 |
||
364 |
tls_index = tls_find_or_create(env, thread); |
|
365 |
HPROF_ASSERT(tls_index!=0); |
|
366 |
index = tls_get_monitor(tls_index); |
|
367 |
HPROF_ASSERT(index!=0); |
|
368 |
info = get_info(index); |
|
369 |
info->contended_time += tls_monitor_stop_timer(tls_index); |
|
370 |
info->num_hits++; |
|
371 |
tls_set_monitor(tls_index, 0); |
|
372 |
} |
|
373 |
||
374 |
void |
|
375 |
monitor_wait_event(JNIEnv *env, jthread thread, jobject object, jlong timeout) |
|
376 |
{ |
|
377 |
TlsIndex tls_index; |
|
378 |
MonitorKey *pkey; |
|
379 |
MonitorIndex index; |
|
380 |
TraceIndex trace_index; |
|
381 |
||
382 |
HPROF_ASSERT(env!=NULL); |
|
383 |
HPROF_ASSERT(object!=NULL); |
|
384 |
HPROF_ASSERT(thread!=NULL); |
|
385 |
||
386 |
tls_index = tls_find_or_create(env, thread); |
|
387 |
HPROF_ASSERT(tls_index!=0); |
|
388 |
HPROF_ASSERT(tls_get_monitor(tls_index)==0); |
|
389 |
trace_index = get_trace(tls_index, env); |
|
390 |
index = find_or_create_entry(env, trace_index, object); |
|
391 |
pkey = get_pkey(index); |
|
392 |
tls_monitor_start_timer(tls_index); |
|
393 |
tls_set_monitor(tls_index, index); |
|
394 |
||
395 |
rawMonitorEnter(gdata->data_access_lock); { |
|
396 |
io_write_monitor_wait(string_get(pkey->sig_index), timeout, |
|
397 |
tls_get_thread_serial_number(tls_index)); |
|
398 |
} rawMonitorExit(gdata->data_access_lock); |
|
399 |
} |
|
400 |
||
401 |
void |
|
402 |
monitor_waited_event(JNIEnv *env, jthread thread, |
|
403 |
jobject object, jboolean timed_out) |
|
404 |
{ |
|
405 |
TlsIndex tls_index; |
|
406 |
MonitorIndex index; |
|
407 |
jlong time_waited; |
|
408 |
||
409 |
tls_index = tls_find_or_create(env, thread); |
|
410 |
HPROF_ASSERT(tls_index!=0); |
|
411 |
time_waited = tls_monitor_stop_timer(tls_index); |
|
412 |
index = tls_get_monitor(tls_index); |
|
413 |
||
414 |
if ( index ==0 ) { |
|
415 |
/* As best as I can tell, on Solaris X86 (not SPARC) I sometimes |
|
416 |
* get a "waited" event on a thread that I have never seen before |
|
417 |
* at all, so how did I get a WAITED event? Perhaps when I |
|
418 |
* did the VM_INIT handling, a thread I've never seen had already |
|
419 |
* done the WAIT (which I never saw?), and now I see this thread |
|
420 |
* for the first time, and also as it finishes it's WAIT? |
|
421 |
* Only happening on faster processors? |
|
422 |
*/ |
|
423 |
tls_set_monitor(tls_index, 0); |
|
424 |
return; |
|
425 |
} |
|
426 |
HPROF_ASSERT(index!=0); |
|
427 |
tls_set_monitor(tls_index, 0); |
|
428 |
if (object == NULL) { |
|
429 |
rawMonitorEnter(gdata->data_access_lock); { |
|
430 |
io_write_monitor_sleep(time_waited, |
|
431 |
tls_get_thread_serial_number(tls_index)); |
|
432 |
} rawMonitorExit(gdata->data_access_lock); |
|
433 |
} else { |
|
434 |
MonitorKey *pkey; |
|
435 |
||
436 |
pkey = get_pkey(index); |
|
437 |
rawMonitorEnter(gdata->data_access_lock); { |
|
438 |
io_write_monitor_waited(string_get(pkey->sig_index), time_waited, |
|
439 |
tls_get_thread_serial_number(tls_index)); |
|
440 |
} rawMonitorExit(gdata->data_access_lock); |
|
441 |
} |
|
442 |
} |