/*
* Copyright (c) 2003, 2005, Oracle and/or its affiliates. All rights reserved.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions
* are met:
*
* - Redistributions of source code must retain the above copyright
* notice, this list of conditions and the following disclaimer.
*
* - Redistributions in binary form must reproduce the above copyright
* notice, this list of conditions and the following disclaimer in the
* documentation and/or other materials provided with the distribution.
*
* - Neither the name of Oracle nor the names of its
* contributors may be used to endorse or promote products derived
* from this software without specific prior written permission.
*
* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS
* IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
* THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
* PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR
* CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL,
* EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
* PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
* PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF
* LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING
* NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
* SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/
/*
* This source code is provided to illustrate the usage of a given feature
* or technique and has been deliberately simplified. Additional steps
* required for a production-quality application, such as security checks,
* input validation and proper error handling, might not be present in
* this sample code.
*/
/* Monitor contention tracking and monitor wait handling. */
/*
* Monitor's under contention are unique per trace and signature.
* Two monitors with the same trace and signature will be treated
* the same as far as accumulated contention time.
*
* The tls table (or thread table) will be used to store the monitor in
* contention or being waited on.
*
* Monitor wait activity is emitted as it happens.
*
* Monitor contention is tabulated and summarized at dump time.
*
*/
#include "hprof.h"
typedef struct MonitorKey {
TraceIndex trace_index;
StringIndex sig_index;
} MonitorKey;
typedef struct MonitorInfo {
jint num_hits;
jlong contended_time;
} MonitorInfo;
typedef struct IterateInfo {
MonitorIndex *monitors;
int count;
jlong total_contended_time;
} IterateInfo;
/* Private internal functions. */
static MonitorKey*
get_pkey(MonitorIndex index)
{
void * key_ptr;
int key_len;
table_get_key(gdata->monitor_table, index, &key_ptr, &key_len);
HPROF_ASSERT(key_len==sizeof(MonitorKey));
HPROF_ASSERT(key_ptr!=NULL);
return (MonitorKey*)key_ptr;
}
static MonitorInfo *
get_info(MonitorIndex index)
{
MonitorInfo * info;
HPROF_ASSERT(index!=0);
info = (MonitorInfo*)table_get_info(gdata->monitor_table, index);
HPROF_ASSERT(info!=NULL);
return info;
}
static MonitorIndex
find_or_create_entry(JNIEnv *env, TraceIndex trace_index, jobject object)
{
static MonitorKey empty_key;
MonitorKey key;
MonitorIndex index;
char *sig;
HPROF_ASSERT(object!=NULL);
WITH_LOCAL_REFS(env, 1) {
jclass clazz;
clazz = getObjectClass(env, object);
getClassSignature(clazz, &sig, NULL);
} END_WITH_LOCAL_REFS;
key = empty_key;
key.trace_index = trace_index;
key.sig_index = string_find_or_create(sig);
jvmtiDeallocate(sig);
index = table_find_or_create_entry(gdata->monitor_table, &key,
(int)sizeof(key), NULL, NULL);
return index;
}
static void
cleanup_item(MonitorIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg)
{
}
static void
list_item(TableIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg)
{
MonitorInfo *info;
MonitorKey *pkey;
HPROF_ASSERT(key_len==sizeof(MonitorKey));
HPROF_ASSERT(key_ptr!=NULL);
HPROF_ASSERT(info_ptr!=NULL);
pkey = (MonitorKey*)key_ptr;
info = (MonitorInfo *)info_ptr;
debug_message(
"Monitor 0x%08x: trace=0x%08x, sig=0x%08x, "
"num_hits=%d, contended_time=(%d,%d)\n",
index,
pkey->trace_index,
pkey->sig_index,
info->num_hits,
jlong_high(info->contended_time),
jlong_low(info->contended_time));
}
static void
collect_iterator(MonitorIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg)
{
MonitorInfo *info;
IterateInfo *iterate;
HPROF_ASSERT(key_len==sizeof(MonitorKey));
HPROF_ASSERT(info_ptr!=NULL);
HPROF_ASSERT(arg!=NULL);
iterate = (IterateInfo *)arg;
info = (MonitorInfo *)info_ptr;
iterate->monitors[iterate->count++] = index;
iterate->total_contended_time += info->contended_time;
}
static int
qsort_compare(const void *p_monitor1, const void *p_monitor2)
{
MonitorInfo * info1;
MonitorInfo * info2;
MonitorIndex monitor1;
MonitorIndex monitor2;
jlong result;
HPROF_ASSERT(p_monitor1!=NULL);
HPROF_ASSERT(p_monitor2!=NULL);
monitor1 = *(MonitorIndex *)p_monitor1;
monitor2 = *(MonitorIndex *)p_monitor2;
info1 = get_info(monitor1);
info2 = get_info(monitor2);
result = info2->contended_time - info1->contended_time;
if (result < (jlong)0) {
return -1;
} else if ( result > (jlong)0 ) {
return 1;
}
return info2->num_hits - info1->num_hits;
}
static void
clear_item(MonitorIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg)
{
MonitorInfo *info;
HPROF_ASSERT(key_len==sizeof(MonitorKey));
HPROF_ASSERT(info_ptr!=NULL);
info = (MonitorInfo *)info_ptr;
info->contended_time = 0;
}
static TraceIndex
get_trace(TlsIndex tls_index, JNIEnv *env)
{
TraceIndex trace_index;
trace_index = tls_get_trace(tls_index, env, gdata->max_trace_depth, JNI_FALSE);
return trace_index;
}
/* External functions (called from hprof_init.c) */
void
monitor_init(void)
{
gdata->monitor_table = table_initialize("Monitor",
32, 32, 31, (int)sizeof(MonitorInfo));
}
void
monitor_list(void)
{
debug_message(
"------------------- Monitor Table ------------------------\n");
table_walk_items(gdata->monitor_table, &list_item, NULL);
debug_message(
"----------------------------------------------------------\n");
}
void
monitor_cleanup(void)
{
table_cleanup(gdata->monitor_table, &cleanup_item, (void*)NULL);
gdata->monitor_table = NULL;
}
void
monitor_clear(void)
{
table_walk_items(gdata->monitor_table, &clear_item, NULL);
}
/* Contended monitor output */
void
monitor_write_contended_time(JNIEnv *env, double cutoff)
{
int n_entries;
n_entries = table_element_count(gdata->monitor_table);
if ( n_entries == 0 ) {
return;
}
rawMonitorEnter(gdata->data_access_lock); {
IterateInfo iterate;
int i;
int n_items;
jlong total_contended_time;
/* First write all trace we might refer to. */
trace_output_unmarked(env);
/* Looking for an array of monitor index values of interest */
iterate.monitors = HPROF_MALLOC(n_entries*(int)sizeof(MonitorIndex));
(void)memset(iterate.monitors, 0, n_entries*(int)sizeof(MonitorIndex));
/* Get a combined total and an array of monitor index numbers */
iterate.total_contended_time = 0;
iterate.count = 0;
table_walk_items(gdata->monitor_table, &collect_iterator, &iterate);
/* Sort that list */
n_entries = iterate.count;
if ( n_entries > 0 ) {
qsort(iterate.monitors, n_entries, sizeof(MonitorIndex),
&qsort_compare);
}
/* Apply the cutoff */
n_items = 0;
for (i = 0; i < n_entries; i++) {
MonitorIndex index;
MonitorInfo *info;
double percent;
index = iterate.monitors[i];
info = get_info(index);
percent = (double)info->contended_time /
(double)iterate.total_contended_time;
if (percent < cutoff) {
break;
}
iterate.monitors[n_items++] = index;
}
/* Output the items that make sense */
total_contended_time = iterate.total_contended_time / 1000000;
if ( n_items > 0 && total_contended_time > 0 ) {
double accum;
/* Output the info on this monitor enter site */
io_write_monitor_header(total_contended_time);
accum = 0.0;
for (i = 0; i < n_items; i++) {
MonitorIndex index;
MonitorInfo *info;
MonitorKey *pkey;
double percent;
char *sig;
index = iterate.monitors[i];
pkey = get_pkey(index);
info = get_info(index);
sig = string_get(pkey->sig_index);
percent = (double)info->contended_time /
(double)iterate.total_contended_time * 100.0;
accum += percent;
io_write_monitor_elem(i + 1, percent, accum,
info->num_hits,
trace_get_serial_number(pkey->trace_index),
sig);
}
io_write_monitor_footer();
}
HPROF_FREE(iterate.monitors);
} rawMonitorExit(gdata->data_access_lock);
}
void
monitor_contended_enter_event(JNIEnv *env, jthread thread, jobject object)
{
TlsIndex tls_index;
MonitorIndex index;
TraceIndex trace_index;
HPROF_ASSERT(env!=NULL);
HPROF_ASSERT(thread!=NULL);
HPROF_ASSERT(object!=NULL);
tls_index = tls_find_or_create(env, thread);
HPROF_ASSERT(tls_get_monitor(tls_index)==0);
trace_index = get_trace(tls_index, env);
index = find_or_create_entry(env, trace_index, object);
tls_monitor_start_timer(tls_index);
tls_set_monitor(tls_index, index);
}
void
monitor_contended_entered_event(JNIEnv* env, jthread thread, jobject object)
{
TlsIndex tls_index;
MonitorInfo *info;
MonitorIndex index;
HPROF_ASSERT(env!=NULL);
HPROF_ASSERT(object!=NULL);
HPROF_ASSERT(thread!=NULL);
tls_index = tls_find_or_create(env, thread);
HPROF_ASSERT(tls_index!=0);
index = tls_get_monitor(tls_index);
HPROF_ASSERT(index!=0);
info = get_info(index);
info->contended_time += tls_monitor_stop_timer(tls_index);
info->num_hits++;
tls_set_monitor(tls_index, 0);
}
void
monitor_wait_event(JNIEnv *env, jthread thread, jobject object, jlong timeout)
{
TlsIndex tls_index;
MonitorKey *pkey;
MonitorIndex index;
TraceIndex trace_index;
HPROF_ASSERT(env!=NULL);
HPROF_ASSERT(object!=NULL);
HPROF_ASSERT(thread!=NULL);
tls_index = tls_find_or_create(env, thread);
HPROF_ASSERT(tls_index!=0);
HPROF_ASSERT(tls_get_monitor(tls_index)==0);
trace_index = get_trace(tls_index, env);
index = find_or_create_entry(env, trace_index, object);
pkey = get_pkey(index);
tls_monitor_start_timer(tls_index);
tls_set_monitor(tls_index, index);
rawMonitorEnter(gdata->data_access_lock); {
io_write_monitor_wait(string_get(pkey->sig_index), timeout,
tls_get_thread_serial_number(tls_index));
} rawMonitorExit(gdata->data_access_lock);
}
void
monitor_waited_event(JNIEnv *env, jthread thread,
jobject object, jboolean timed_out)
{
TlsIndex tls_index;
MonitorIndex index;
jlong time_waited;
tls_index = tls_find_or_create(env, thread);
HPROF_ASSERT(tls_index!=0);
time_waited = tls_monitor_stop_timer(tls_index);
index = tls_get_monitor(tls_index);
if ( index ==0 ) {
/* As best as I can tell, on Solaris X86 (not SPARC) I sometimes
* get a "waited" event on a thread that I have never seen before
* at all, so how did I get a WAITED event? Perhaps when I
* did the VM_INIT handling, a thread I've never seen had already
* done the WAIT (which I never saw?), and now I see this thread
* for the first time, and also as it finishes it's WAIT?
* Only happening on faster processors?
*/
tls_set_monitor(tls_index, 0);
return;
}
HPROF_ASSERT(index!=0);
tls_set_monitor(tls_index, 0);
if (object == NULL) {
rawMonitorEnter(gdata->data_access_lock); {
io_write_monitor_sleep(time_waited,
tls_get_thread_serial_number(tls_index));
} rawMonitorExit(gdata->data_access_lock);
} else {
MonitorKey *pkey;
pkey = get_pkey(index);
rawMonitorEnter(gdata->data_access_lock); {
io_write_monitor_waited(string_get(pkey->sig_index), time_waited,
tls_get_thread_serial_number(tls_index));
} rawMonitorExit(gdata->data_access_lock);
}
}