JDK-6447640 : methodOopDesc::jmethod_id() can deadlock when used by the VMThread
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jvmti
  • Affected Version: 6
  • Priority: P2
  • Status: Resolved
  • Resolution: Fixed
  • OS: generic
  • CPU: generic
  • Submitted: 2006-07-11
  • Updated: 2024-04-03
  • Resolved: 2006-07-27
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 b93Fixed
Related Reports
Relates :  
Relates :  
Description
During Suspend/Resume stress testing of the fix for 6440070 over the
July 4th Shutdown on Solaris SPARC Client and Server VMs, there were
many failed runs due to a hang:

producer-c1-fast/CPUSampling/save.6440070/doit_loop.log: 1 hang
producer-c1-fast/PepTest/save.6440070/doit_loop.log:     7 hangs
producer-c1-jvmg/Java2Demo/save.6440070/doit_loop.log:   1 hang
producer-c1-jvmg/PepTest/save.6440070/doit_loop.log:     1 hang
producer-c1-prod/Java2Demo/save.6440070/doit_loop.log:   1 hang
producer-c1-prod/PepTest/save.6440070/doit_loop.log:     15 hangs

I have attached a sample hang as threads.log.207 and I have included
the stack traces for the interesting threads below.

This failure looks like a classic deadlock. Thread t@2 called
methodOopDesc::jmethod_id() and blocked on a safepoint trying to
acquire JNIGlobalHandle_lock while holding the JNIIdentifier_lock.
Thread t@8 called JVM/TI GetThreadListStackTraces() which resulted in a
VM operation so thread t@3 (VMThread) called methodOopDesc::jmethod_id()
while trying to get a stack trace at a safepoint. The VMThread blocks
on JNIIdentifier_lock and we have a deadlock.


THREAD t@2

The thread is posting a ClassLoad event and the event handler calls
JVM/TI GetStackTrace(). While trying to fill in the stack trace info,
this thread blocks on a safepoint.

t@2 (l@2) stopped in ___lwp_mutex_lock at 0xff29f990
0xff29f990: ___lwp_mutex_lock+0x0008:	ta       8
current thread: t@2
  [1] ___lwp_mutex_lock(0xa66a0, 0x52800, 0xad318, 0x529bd, 0xd8c284, 0x52800), at 0xff29f990 
=>[2] Mutex::lock_without_safepoint_check(this = ???) (optimized), at 0xfe276c1c (line ~294) in "os_solaris.hpp"
  [3] SafepointSynchronize::block(thread = ???) (optimized), at 0xfe38b980 (line ~582) in "safepoint.cpp"
  [4] Mutex::wait_for_lock_blocking_implementation(this = ???, thread = ???) (optimized), at 0xfe27b93c (line ~299) in "os_solaris.hpp"
  [5] Mutex::lock(this = ???, thread = ???) (optimized), at 0xfe276558 (line ~124) in "mutex.cpp"
  [6] JNIHandles::make_jmethod_id(mh = CLASS) (optimized), at 0xfde649a4 (line ~88) in "jniHandles.cpp"
    make_jmethod_id() tries to grab the JNIGlobalHandle_lock and
    blocks on the safepoint.

  [7] instanceKlass::jmethod_id_for_impl(ik_h = CLASS, method_h = CLASS) (optimized), at 0xfdc77c20 (line ~972) in "instanceKlass.cpp"
    jmethod_id_for_impl() grabs the JNIIdentifier_lock before it calls
    make_jmethod_id().

  [8] methodOopDesc::jmethod_id(this = ???) (optimized), at 0xfdb44fcc (line ~27) in "klassOop.hpp"
  [9] JvmtiEnvBase::get_stack_trace(this = ???, java_thread = ???, start_depth = ???, max_count = ???, frame_buffer = ???, count_ptr = ???) (optimized), at 0xfe0fd68c (line ~682) in "jvmtiEnvBase.cpp"
  [10] JvmtiEnv::GetStackTrace(this = ???, java_thread = ???, start_depth = ???, max_frame_count = ???, frame_buffer = ???, count_ptr = ???) (optimized), at 0xfe0e17dc (line ~789) in "jvmtiEnv.cpp"
  [11] jvmti_GetStackTrace(env = ???, thread = ???, start_depth = ???, max_frame_count = ???, frame_buffer = ???, count_ptr = ???) (optimized), at 0xfdf84820 (line ~1130) in "jvmtiEnter.cpp"
  [12] getStackTrace(0xfdf83430, 0xff08cca0, 0xfd6cc5e0, 0xfd67e67c, 0x800, 0x1540c), at 0xfd6b6d4c 
  [13] trace_get_current(0x148b14, 0x30d41, 0x4, 0x0, 0x1464b8, 0x16cf30), at 0xfd6b16bc 
  [14] get_trace(0x148b14, 0x30d41, 0x4, 0x0, 0x1464b8, 0x16cf30), at 0xfd6aeb84 
  [15] tls_get_trace(0x30000001, 0xa8104, 0x4, 0x0, 0x800, 0x1bb50), at 0xfd6b0630 
  [16] event_class_load(0xa8104, 0x1488c4, 0x1488c8, 0x0, 0x90000001, 0x34bfc), at 0xfd6975d8 
  [17] cbClassLoad(0xfd6cc5e0, 0xa8104, 0x1488c4, 0x1488c8, 0xfd6cc94c, 0xa8aa0), at 0xfd69dca8 
  [18] JvmtiExport::post_class_load(thread = ???, klass = CLASS) (optimized), at 0xfe116070 (line ~780) in "jvmtiExport.cpp"
  [19] SystemDictionary::define_instance_class(k = CLASS, __the_thread__ = ???) (optimized), at 0xfe41feac (line ~1277) in "systemDictionary.cpp"
  [20] SystemDictionary::load_instance_class(class_name = CLASS, class_loader = CLASS, __the_thread__ = ???) (optimized), at 0xfe41df7c (line ~1169) in "systemDictionary.cpp"
  [21] SystemDictionary::resolve_instance_class_or_null(class_name = CLASS, class_loader = CLASS, protection_domain = CLASS, __the_thread__ = ???) (optimized), at 0xfe4172e4 (line ~733) in "systemDictionary.cpp"
  [22] SystemDictionary::resolve_or_null(class_name = CLASS, class_loader = CLASS, protection_domain = CLASS, __the_thread__ = ???) (optimized), at 0xfe411e70 (line ~206) in "systemDictionary.cpp"
  [23] SystemDictionary::resolve_or_fail(class_name = CLASS, class_loader = CLASS, protection_domain = CLASS, throw_error = ???, __the_thread__ = ???) (optimized), at 0xfe410fb4 (line ~155) in "systemDictionary.cpp"
  [24] constantPoolOopDesc::klass_at_impl(this_oop = CLASS, which = ???, __the_thread__ = ???) (optimized), at 0xfdb9ef0c (line ~61) in "constantPoolOop.cpp"
  [25] InterpreterRuntime::_new(thread = ???, pool = ???, index = ???) (optimized), at 0xfdccff58 (line ~206) in "constantPoolOop.hpp"
  [26] 0xfb42eefc(0xf30254d0, 0x8, 0xff0a2174, 0xfb420f20, 0x0, 0xfd67f760), at 0xfb42eefb 
  [27] 0xfb405a10(0xf30254d0, 0x8, 0xff0a2174, 0xfb42db00, 0x0, 0xfd67f7f0), at 0xfb405a0f 
  [28] 0xfb4058a8(0xf30254d0, 0x8, 0xff0a2174, 0xfb42dee0, 0x0, 0xfd67f880), at 0xfb4058a7 
  [29] 0xfb4058a8(0x4a000, 0x8, 0xff0a2174, 0xfb42db00, 0x0, 0xfd67f900), at 0xfb4058a7 
  [30] 0xfb4058a8(0x4a000, 0x8, 0xff0a2174, 0xfb42e3f0, 0x0, 0xfd67f998), at 0xfb4058a7 
  [31] 0xfb4058a8(0xf30254b8, 0x8, 0xff0a2174, 0xfb42e390, 0x0, 0xfd67fa28), at 0xfb4058a7 
  [32] 0xfb405a10(0x17, 0x2c970, 0x16, 0xfb42dee0, 0xfd67fd59, 0xfd67fab0), at 0xfb405a0f 
  [33] 0xfb4002d0(0xfd67fbb8, 0xfd67fee8, 0xa, 0xf7008ff0, 0xfb4121c0, 0xfd67fd00), at 0xfb4002cf 
  [34] JavaCalls::call_helper(result = ???, m = ???, args = ???, __the_thread__ = ???) (optimized), at 0xfdd0e20c (line ~367) in "javaCalls.cpp"
  [35] jni_invoke_nonstatic(env = ???, result = ???, receiver = ???, call_type = ???, method_id = ???, args = ???, __the_thread__ = ???) (optimized), at 0xfdd55a1c (line ~1054) in "jni.cpp"
  [36] jni_NewObject(env = ???, clazz = ???, methodID = ???, ...) (optimized), at 0xfdd598b4 (line ~1131) in "jni.cpp"
  [37] JavaMain(0x0, 0x2b32c, 0x2ac30, 0xa91b8, 0xffbef03e, 0x2ac22), at 0x13218 

THREAD t@3

This is the VMThread and it is handling a VM operation in response to
thread t@8's JVM/TI GetThreadListStackTraces() call. While trying to
fill in the stack trace info, this thread blocks trying to acquire a
lock.

t@3 (l@3) stopped in ___lwp_mutex_lock at 0xff29f990
0xff29f990: ___lwp_mutex_lock+0x0008:	ta       8
current thread: t@3
  [1] ___lwp_mutex_lock(0xa7140, 0x52800, 0xad318, 0x529bd, 0xd8c284, 0x52800), at 0xff29f990 
=>[2] os::Solaris::Event::lock(this = ???) (optimized), at 0xfe277cc0 (line ~294) in "os_solaris.hpp"
  [3] Mutex::lock(this = ???, thread = ???) (optimized), at 0xfe276518 (line ~120) in "mutex.cpp"
  [4] instanceKlass::jmethod_id_for_impl(ik_h = CLASS, method_h = CLASS) (optimized), at 0xfdc770dc (line ~943) in "instanceKlass.cpp"
  [5] methodOopDesc::jmethod_id(this = ???) (optimized), at 0xfdb44fcc (line ~27) in "klassOop.hpp"
    jmethod_id_for_impl() tries to grab the JNIIdentifier_lock, but it
    blocks because thread t@2 is holding it.

  [6] JvmtiEnvBase::get_stack_trace(this = ???, java_thread = ???, start_depth = ???, max_count = ???, frame_buffer = ???, count_ptr = ???) (optimized), at 0xfe0fd68c (line ~682) in "jvmtiEnvBase.cpp"
  [7] VM_GetThreadListStackTraces::doit(this = ???) (optimized), at 0xfe100750 (line ~1038) in "jvmtiEnvBase.cpp"
  [8] VM_Operation::evaluate(this = ???) (optimized), at 0xfe5bb2cc (line ~25) in "vm_operations.cpp"
  [9] VMThread::evaluate_operation(this = ???, op = ???) (optimized), at 0xfe5b94d4 (line ~314) in "vmThread.cpp"
  [10] VMThread::loop(this = ???) (optimized), at 0xfe5b9cc4 (line ~423) in "vmThread.cpp"
  [11] VMThread::run(this = ???) (optimized), at 0xfe5b8fd4 (line ~227) in "vmThread.cpp"
  [12] java_start(thread_addr = ???) (optimized), at 0xfe2cc100 (line ~944) in "os_solaris.cpp"


THREAD t@8

This thread has called JVM/TI GetThreadListStackTraces() which is
implemented by a VM operation. This thread is waiting for thread t@3
(VMThread) to finish the VM operation.

t@8 (l@8) stopped in ___lwp_cond_wait at 0xff29fa08
0xff29fa08: ___lwp_cond_wait+0x0004:	ta       8
current thread: t@8
  [1] ___lwp_cond_wait(0xa68b8, 0xa68a0, 0x0, 0x7d0, 0xff098ab8, 0x7f97f4), at 0xff29fa08 
  [2] _lwp_cond_wait(0xa68b8, 0xa68a0, 0xad318, 0x1, 0x0, 0x64400), at 0xff296f4c 
=>[3] Monitor::wait(this = ???, no_safepoint_check = ???, timeout = ???) (optimized), at 0xfe27c6c4 (line ~337) in "os_solaris.hpp"
  [4] VMThread::execute(op = ???) (optimized), at 0xfe5ba778 (line ~562) in "vmThread.cpp"
  [5] JvmtiEnv::GetThreadListStackTraces(this = ???, thread_count = ???, thread_list = ???, max_frame_count = ???, stack_info_ptr = ???) (optimized), at 0xfe0e19d8 (line ~829) in "jvmtiEnv.cpp"
  [6] jvmti_GetThreadListStackTraces(env = ???, thread_count = ???, thread_list = ???, max_frame_count = ???, stack_info_ptr = ???) (optimized), at 0xfdf86470 (line ~1206) in "jvmtiEnter.cpp"
  [7] getThreadListStackTraces(0xff08cca0, 0xfd6cc5e0, 0xfd6cc94c, 0x834, 0x800, 0x1539c), at 0xfd6b6dbc 
  [8] trace_get_all_current(0x1, 0x2e238, 0x2e250, 0x4, 0x0, 0x2de30), at 0xfd6b1734 
  [9] trace_increment_all_sample_costs(0x1, 0x2e238, 0x2e250, 0x4, 0x0, 0x2de30), at 0xfd6b18e4 
  [10] tls_sample_all_threads(0x197104, 0xfd6cc5e0, 0x834, 0xfd6cc118, 0xfd6cc94c, 0x2e250), at 0xfd6afd50 
  [11] cpu_loop_function(0xfd6cc5e0, 0x197104, 0xfd6b8204, 0xfd6b81ec, 0xfd6cc118, 0x1), at 0xfd6968e0 
  [12] JvmtiAgentThread::call_start_function(this = ???) (optimized), at 0xfe14846c (line ~63) in "jvmtiImpl.cpp"
  [13] JavaThread::thread_main_inner(this = ???) (optimized), at 0xfe468080 (line ~1412) in "thread.cpp"
  [14] java_start(thread_addr = ???) (optimized), at 0xfe2cc100 (line ~944) in "os_solaris.cpp"

Comments
EVALUATION I suspect that the VMThread should never use methodOopDesc::jmethod_id() and should use methodOopDesc::find_jmethod_id_or_null(). However, Robert should know for sure.
11-07-2006