JDK-6296437 : HPROF: hat is throwing exception on hprof output in mustang
  • Type: Bug
  • Component: tools
  • Sub-Component: hprof
  • Affected Version: 6
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • OS: solaris_10
  • CPU: sparc
  • Submitted: 2005-07-13
  • Updated: 2010-04-02
  • Resolved: 2005-09-30
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 6
6 b55Fixed
Related Reports
Relates :  
JDK-6231936 - hprof format=b problem with HAT: Thread 200000 not found for JNI local ref
Relates :  
JDK-6204559 - HPROF: HAT thinks the timestamp in the format=b file is bad
Relates :  
JDK-6324132 - JHAT: Make the reading of the dump more forgiving
Relates :  
JDK-6325354 - HPROF: format=b problem with HAT: Thread 200000 not found for JNI local ref
Description
I'm trying to use hat tool from http://hat.dev.java.net, with the
  latest mustang build, and it's not going too well.

  hat throws this exception when trying to parse the binary output
  file created by hprof:
#>/import/java/jdk1.6.0/solaris-sparc/bin/java -client -version
java version "1.6.0-ea"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.6.0-ea-b42)
Java HotSpot(TM) Client VM (build 1.6.0-ea-b42, mixed mode)

/import/java/jdk1.6.0/solaris-sparc/bin/java -client -agentlib:hprof=depth=6,format=b LeakWindow

[tdv@nukite:] -< ~/public_html/bugs/disposer_leak >
#>/import/java/jdk1.6.0/solaris-sparc/bin/java -jar ~/perf/hat/bin/hat.jar ./java.hprof
Started HTTP server on port 7000
Reading from ./java.hprof...
Dump file created Thu Feb 27 04:56:57 PST 1992
java.io.IOException: Thread 200001 not found for JNI local ref
        at hat.parser.HprofReader.getThreadObjectFromSequence(HprofReader.java:577)
        at hat.parser.HprofReader.readHeapDump(HprofReader.java:379)
        at hat.parser.HprofReader.read(HprofReader.java:221)
        at hat.parser.Reader.readFile(Reader.java:90)
        at hat.Main.main(Main.java:149)

I've attached the hprof file.

###@###.### 2005-07-13 18:02:42 GMT
Comments
SUGGESTED FIX +++ hprof_tls.c Fri Sep 16 21:39:20 2005 @@ -1,7 +1,7 @@ /* - * @(#)hprof_tls.c 1.52 05/04/28 + * @(#)hprof_tls.c 1.53 05/09/15 * * Copyright (c) 2004 Sun Microsystems, Inc. All Rights Reserved. * * Redistribution and use in source and binary forms, with or without * modification, are permitted provided that the following conditions are met: @@ -37,16 +37,19 @@ #include "hprof.h" /* Thread Local Storage Table and method entry/exit handling. */ /* - * The tls table items have no key, and are searched via a walk of - * the table looking for a jthread match. This isn't a performance + * The tls table items have a key of it's serial number, but may be + * searched via a walk of the table looking for a jthread match. + * This isn't a performance * issue because the table index should normally be stored in the * Thread Local Storage for the thread. The table is only searched * when the jthread is seen before the Thread Local Storage is set * (e.g. before VM_INIT or the ThreadStart). + * The key is only used when we need to lookup a tls table entry by + * way of it's serial number, which should be unique per thread. * * Each active thread that we have seen should have a unique TlsIndex * which is an index into this table. * * For cpu=times, each table entry will have a stack to hold the method @@ -80,11 +83,10 @@ } StackElement; typedef struct TlsInfo { jint sample_status; /* Thread status for cpu sampling */ jboolean agent_thread; /* Is thread our own agent thread? */ - SerialNumber thread_serial_num; /* unique thread serial number */ jthread globalref; /* Global reference for thread */ Stack *stack; /* Stack of StackElements entry/exit */ MonitorIndex monitor_index; /* last contended mon */ jint tracker_status; /* If we are inside Tracker class */ FrameIndex *frames_buffer; /* Buffer used to create TraceIndex */ @@ -91,10 +93,11 @@ jvmtiFrameInfo *jframes_buffer; /* Buffer used to create TraceIndex */ int buffer_depth; /* Frames allowed in buffer */ TraceIndex last_trace; /* Last trace for this thread */ ObjectIndex thread_object_index;/* If heap=dump */ jlong monitor_start_time; /* Start time for monitor */ + jint in_heap_dump; /* If we are an object in the dump */ } TlsInfo; typedef struct SearchData { JNIEnv *env; jthread thread; @@ -120,10 +123,27 @@ jint sample_status; } SampleData; /* Private internal functions. */ +static SerialNumber +get_key(TlsIndex index) +{ + SerialNumber *pkey; + int key_len; + + if ( index == 0 ) { + return 0; + } + pkey = NULL; + key_len = 0; + table_get_key(gdata->tls_table, index, (void**)&pkey, &key_len); + HPROF_ASSERT(pkey!=NULL); + HPROF_ASSERT(key_len==(int)sizeof(SerialNumber)); + return *pkey; +} + static TlsInfo * get_info(TlsIndex index) { return (TlsInfo*)table_get_info(gdata->tls_table, index); } @@ -188,11 +208,11 @@ info = (TlsInfo*)info_ptr; debug_message( "Tls 0x%08x: SN=%u, sample_status=%d, agent=%d, " "thread=%p, monitor=0x%08x, " "tracker_status=%d\n", index, - info->thread_serial_num, + *(SerialNumber*)key_ptr, info->sample_status, info->agent_thread, (void*)info->globalref, info->monitor_index, info->tracker_status); @@ -338,25 +358,28 @@ /* Get various lists on known threads */ static void get_thread_list(TableIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg) { + SerialNumber thread_serial_num; TlsInfo *info; ThreadList *list; jthread thread; + HPROF_ASSERT(key_ptr!=NULL); HPROF_ASSERT(info_ptr!=NULL); + thread_serial_num = *(SerialNumber*)key_ptr; info = (TlsInfo*)info_ptr; list = (ThreadList*)arg; thread = newLocalReference(list->env, info->globalref); if ( thread != NULL && info->sample_status != 0 && !info->agent_thread ) { if ( list->infos != NULL ) { list->infos[list->count] = info; } if ( list->serial_nums != NULL ) { - list->serial_nums[list->count] = info->thread_serial_num; + list->serial_nums[list->count] = thread_serial_num; } list->threads[list->count] = thread; list->count++; /* Local reference gets freed by caller */ } else { @@ -455,10 +478,11 @@ } static void pop_method(TlsIndex index, jlong current_time, jmethodID method, FrameIndex frame_index) { + SerialNumber thread_serial_num; TlsInfo * info; StackElement element; void *p; int depth; int trace_depth; @@ -468,10 +492,11 @@ TraceIndex trace_index; HPROF_ASSERT(method!=NULL); HPROF_ASSERT(frame_index!=0); + thread_serial_num = get_key(index); info = get_info(index); HPROF_ASSERT(info!=NULL); HPROF_ASSERT(info->stack!=NULL); depth = stack_depth(info->stack); p = stack_pop(info->stack); @@ -499,11 +524,11 @@ e = *(StackElement*)stack_element(info->stack, (depth - i) - 1); info->frames_buffer[i] = e.frame_index; HPROF_ASSERT(e.frame_index!=0); } - trace_index = trace_find_or_create(info->thread_serial_num, + trace_index = trace_find_or_create(thread_serial_num, trace_depth, info->frames_buffer, info->jframes_buffer); /* Calculate time spent */ total_time = current_time - element.method_start_time; if ( total_time < 0 ) { @@ -523,16 +548,19 @@ } static void dump_thread_state(TlsIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg) { + SerialNumber thread_serial_num; TlsInfo *info; jthread thread; JNIEnv *env; + HPROF_ASSERT(key_ptr!=NULL); HPROF_ASSERT(info_ptr!=NULL); env = (JNIEnv*)arg; + thread_serial_num = *(SerialNumber*)key_ptr; info = (TlsInfo*)info_ptr; thread = newLocalReference(env, info->globalref); if ( thread != NULL ) { jint threadState; SerialNumber trace_serial_num; @@ -545,28 +573,27 @@ if ( info->last_trace == 0 ) { trace_serial_num = trace_get_serial_number(gdata->system_trace_index); } else { trace_serial_num = trace_get_serial_number(info->last_trace); } - io_write_monitor_dump_thread_state(info->thread_serial_num, + io_write_monitor_dump_thread_state(thread_serial_num, trace_serial_num, threadState); deleteLocalReference(env, thread); } } static SerialNumber get_serial_number(JNIEnv *env, jthread thread) { TlsIndex index; - TlsInfo *info; + if ( thread == NULL ) { + return gdata->unknown_thread_serial_num; + } HPROF_ASSERT(env!=NULL); - index = tls_find_or_create(env, thread); - - info = get_info(index); - return info->thread_serial_num; + return get_key(index); } static void dump_monitor_state(TlsIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg) { @@ -650,10 +677,11 @@ /* External interfaces */ TlsIndex tls_find_or_create(JNIEnv *env, jthread thread) { + SerialNumber thread_serial_num; static TlsInfo empty_info; TlsInfo info; TlsIndex index; HPROF_ASSERT(env!=NULL); @@ -668,21 +696,21 @@ index = search(env, thread); if ( index != 0 ) { setThreadLocalStorage(thread, (void*)(ptrdiff_t)index); return index; } + thread_serial_num = gdata->thread_serial_number_counter++; info = empty_info; - info.thread_serial_num = gdata->thread_serial_number_counter++; info.monitor_index = 0; info.sample_status = 1; info.agent_thread = JNI_FALSE; info.stack = stack_init(INITIAL_THREAD_STACK_LIMIT, INITIAL_THREAD_STACK_LIMIT, (int)sizeof(StackElement)); setup_trace_buffers(&info, gdata->max_trace_depth); info.globalref = newWeakGlobalReference(env, thread); - index = table_create_entry(gdata->tls_table, NULL, 0, (void*)&info); + index = table_create_entry(gdata->tls_table, &thread_serial_num, (int)sizeof(SerialNumber), (void*)&info); setThreadLocalStorage(thread, (void*)(ptrdiff_t)index); HPROF_ASSERT(search(env,thread)==index); return index; } @@ -700,11 +728,11 @@ void tls_init(void) { gdata->tls_table = table_initialize("TLS", - 16, 16, 0, (int)sizeof(TlsInfo)); + 16, 16, 16, (int)sizeof(TlsInfo)); } void tls_list(void) { @@ -747,11 +775,11 @@ index = tls_find_or_create(env, thread); info = get_info(index); *ppstatus = &(info->tracker_status); status = **ppstatus; - thread_serial_num = info->thread_serial_num; + thread_serial_num = get_key(index); if ( pindex != NULL ) { *pindex = index; } if ( status != 0 ) { @@ -788,17 +816,11 @@ } SerialNumber tls_get_thread_serial_number(TlsIndex index) { - TlsInfo *info; - - if ( index == 0 ) { - return 0; - } - info = get_info(index); - return info->thread_serial_num; + return get_key(index); } void tls_set_monitor(TlsIndex index, MonitorIndex monitor_index) { @@ -826,18 +848,20 @@ { HPROF_ASSERT(env!=NULL); /* Sample thread stack for last time, do NOT free the entry yet. */ table_lock_enter(gdata->tls_table); { + SerialNumber thread_serial_num; TlsInfo *info; jthread thread; + thread_serial_num = get_key(index); info = get_info(index); thread = newLocalReference(env, info->globalref); if (gdata->heap_dump && thread!=NULL) { setup_trace_buffers(info, gdata->max_trace_depth); - info->last_trace = get_trace(thread, info->thread_serial_num, + info->last_trace = get_trace(thread, thread_serial_num, gdata->max_trace_depth, JNI_FALSE, info->frames_buffer, info->jframes_buffer); } if ( thread != NULL ) { deleteLocalReference(env, thread); @@ -1092,24 +1116,71 @@ } TraceIndex tls_get_trace(TlsIndex index, JNIEnv *env, int depth, jboolean skip_init) { + SerialNumber thread_serial_num; TraceIndex trace_index; TlsInfo *info; jthread thread; + thread_serial_num = get_key(index); info = get_info(index); HPROF_ASSERT(info!=NULL); setup_trace_buffers(info, depth); thread = newLocalReference(env, info->globalref); if ( thread != NULL ) { - trace_index = get_trace(thread, info->thread_serial_num, - depth, skip_init, + trace_index = get_trace(thread, thread_serial_num, depth, skip_init, info->frames_buffer, info->jframes_buffer); deleteLocalReference(env, thread); } else { trace_index = gdata->system_trace_index; } return trace_index; } +void +tls_set_in_heap_dump(TlsIndex index, jint in_heap_dump) +{ + TlsInfo *info; + + info = get_info(index); + info->in_heap_dump = in_heap_dump; +} + +jint +tls_get_in_heap_dump(TlsIndex index) +{ + TlsInfo *info; + + info = get_info(index); + return info->in_heap_dump; +} + +static void +clean_in_heap_dump(TableIndex index, void *key_ptr, int key_len, void *info_ptr, void *arg) +{ + TlsInfo *info; + + HPROF_ASSERT(info_ptr!=NULL); + info = (TlsInfo*)info_ptr; + info->in_heap_dump = 0; +} + +void +tls_clear_in_heap_dump(void) +{ + table_walk_items(gdata->tls_table, &clean_in_heap_dump, NULL); +} + +TlsIndex +tls_find(SerialNumber thread_serial_num) +{ + TlsIndex index; + + if ( thread_serial_num == 0 ) { + return 0; + } + index = table_find_entry(gdata->tls_table, + (void*)&thread_serial_num, (int)sizeof(SerialNumber)); + return index; +}
20-09-2005
EVALUATION Added a field in the TLS (thread local storage) table of hprof to track which threads have been dumped, and when a reference to that thread (via it's serial number) we will make sure we use the 'unknown thread' serial number if the thread does not exist anymore. Added a search key of the thread serial number on the TLS table for quick lookups.
20-09-2005
SUGGESTED FIX Track threads placed in dumps, don't let any locals refer to threads that have not been dumped.
14-09-2005
EVALUATION Need to track threads dumped closely. But a separate bug may need to be filed to make jhat more forgiving.
13-09-2005