Wednesday Oct 28, 2015

JVM hang with CMS collector

This blog post was long due but better late than never. Sometime back I worked on an interesting GC problem which initially looked like an issue with the JVM runtime system. I am talking about 'JDK-8085965: VM hangs in C2Compiler'. This bug has been fixed in JDK 9 and 8u45+. In this post, I want to share interesting symptoms of this bug, and the troubleshooting steps taken that helped in getting to the root of the problem.

This report came in as a JVM hang when running with the CMS collector. Looking at the core file revealed that the JVM was in the '_synchronizing' state at that point.

(gdb) print SafepointSynchronize::_state
$1 = SafepointSynchronize::_synchronizing
(gdb) print SafepointSynchronize::_waiting_to_block
$2 = 1

It was waiting for one thread to come to safe-point state and block.

And the only thread running at that time was the Compiler thread. Stack trace of the Compiler thread:
(gdb) where
#0  Dependencies::find_finalizable_subclass (k=0x101047428)
#1  0x00007fd6804a38ee in ciInstanceKlass::has_finalizable_subclass (this=0x7fd67913e950)
#2  0x00007fd6809c28fb in Parse::call_register_finalizer (this=0x7fd6395405a0)
#3  0x00007fd6809c2fb9 in Parse::return_current (this=0x101047428, value=0x0)
#4  0x00007fd6809cf526 in Parse::do_one_bytecode (this=0x101047428)    
#5  0x00007fd6809c17d8 in Parse::do_one_block (this=0x7fd6395405a0)
#6  0x00007fd6809c1a57 in Parse::do_all_blocks (this=0x7fd6395405a0)
#7  0x00007fd6809c5fe9 in Parse::Parse (this=0x7fd6395405a0, caller=<optimized out>, parse_method=<optimized out>, expected_uses=5377)
#8  0x00007fd6804784e8 in ParseGenerator::generate (this=0x7fd63004dd60, jvms=0x7fd61c402f40)
#9  0x00007fd6805eea36 in Parse::do_call (this=0x7fd6395409c0)
#10 0x00007fd6809cf5aa in Parse::do_one_bytecode (this=0x101047428)
#11 0x00007fd6809c17d8 in Parse::do_one_block (this=0x7fd6395409c0)
#12 0x00007fd6809c1a57 in Parse::do_all_blocks (this=0x7fd6395409c0)
#13 0x00007fd6809c5fe9 in Parse::Parse (this=0x7fd6395409c0, caller=<optimized out>, parse_method=<optimized out>, expected_uses=5377)

The klass* passed to find_finalizable_subclass() was: 0x101047428

(gdb) info frame
Stack level 0, frame at 0x7fd639540240:
 rip = 0x7fd6805955a0 in Dependencies::find_finalizable_subclass

(gdb) print k
$1 = (Klass *) 0x101047428

(gdb) print *$1
$2 = {<Metadata> = {<MetaspaceObj> = {<No data fields>}, _vptr.Metadata =
0x7fd680fc9670 <vtable for InstanceKlass+16>}, _layout_helper = 16,
  _super_check_offset = 64, _name = 0x7fd618009850, _secondary_super_cache =
 0x100009608, _secondary_supers = 0x7fd668848a88, _primary_supers = {
    0x100000f28, 0x100009418, 0x1000097f0, 0x101047428, 0x0, 0x0, 0x0, 0x0},
 _java_mirror = 0xa77b4b40, _super = 0x1000097f0, _subklass = 0x0,
   _next_sibling = 0x101047428, _next_link = 0x0, _class_loader_data =
 0x7fd618003ab0, _modifier_flags = 1, _access_flags = {_flags = 536870913},
   _last_biased_lock_bulk_revocation_time = 0, _prototype_header = 0x5,
 _biased_lock_revocation_count = 0, _trace_id = 1685520384,
   _modified_oops = 0 '\000', _accumulated_modified_oops = 0 '\000',
 _shared_class_path_index = -1}
(gdb) x/s 0x7fd618009850+8
 0x7fd618009858: "sun/reflect/GeneratedMethodAccessor1389"

 _next_sibling = 0x101047428

The next_sibling in this case was the same as the klass itself. So, the compiler thread was stuck in the following loop:

 1187 Klass* Dependencies::find_finalizable_subclass(Klass* k) {
 1188   if (k->is_interface())  return NULL;
 1189   if (k->has_finalizer()) return k;
 1190   k = k->subklass();
 1191   while (k != NULL) {
 1192     Klass* result = find_finalizable_subclass(k);
 1193     if (result != NULL) return result;
 1194     k = k->next_sibling(); 
 1195   }
 1196   return NULL;
 1197 }

Then we did another run with the failing program using TraceClassLoading and TraceClassUnloading JVM options. From the core file of this run, found that VM was stuck while going over a circular siblings list. Note that the subklasses of a Klass are maintained using the _next_sibling field of its first _subklass.

Here's the klass and subklasses chain built from the core file:

super class sun/reflect/SerializationConstructorAccessorImpl - 0x1001acec0
   |--subklasses chain
0x1010eec30-sun/reflect/GeneratedSerializationConstructorAccessor232->
0x1010ef030-sun/reflect/GeneratedSerializationConstructorAccessor231->
0x1010ef430-sun/reflect/GeneratedSerializationConstructorAccessor230->
0x1010ef830-sun/reflect/GeneratedSerializationConstructorAccessor229->
0x1010efc30-sun/reflect/GeneratedSerializationConstructorAccessor228->
0x1010f0030-sun/reflect/GeneratedSerializationConstructorAccessor227->
0x1010f0430-sun/reflect/GeneratedSerializationConstructorAccessor226->
0x1010f0830-sun/reflect/GeneratedSerializationConstructorAccessor225->
0x1010f0c30- sun/reflect/GeneratedSerializationConstructorAccessor224->
0x1010f1030-sun/reflect/GeneratedSerializationConstructorAccessor223->
0x1010f1430-sun/reflect/GeneratedSerializationConstructorAccessor222->
0x1010f1830-sun/reflect/GeneratedSerializationConstructorAccessor221->
0x1010f1c30-sun/reflect/GeneratedSerializationConstructorAccessor220->
0x1010f2030-sun/reflect/GeneratedSerializationConstructorAccessor219->
0x1010f2430- sun/reflect/GeneratedSerializationConstructorAccessor218->
0x1010f2830-sun/reflect/GeneratedSerializationConstructorAccessor217->
0x10110b830-sun/reflect/GeneratedMethodAccessor94->
0x1010e8430-sun/reflect/GeneratedSerializationConstructorAccessor256->
0x1010e8830-sun/reflect/GeneratedSerializationConstructorAccessor255->
0x1010e8c30-sun/reflect/GeneratedSerializationConstructorAccessor254->
0x1010e9830-sun/reflect/GeneratedSerializationConstructorAccessor253->
0x1010e9c30-sun/reflect/GeneratedSerializationConstructorAccessor252->
0x1010ea030-sun/reflect/GeneratedSerializationConstructorAccessor251->
0x1010ea430-sun/reflect/GeneratedSerializationConstructorAccessor250->
0x1010ea830-sun/reflect/GeneratedSerializationConstructorAccessor249->
0x1010eac30-sun/reflect/GeneratedSerializationConstructorAccessor248->
0x1010eb030-sun/reflect/GeneratedSerializationConstructorAccessor247->
0x1010eb430-sun/reflect/GeneratedSerializationConstructorAccessor246->
0x1010eb830-sun/reflect/GeneratedSerializationConstructorAccessor245->
0x1010ebc30-sun/reflect/GeneratedSerializationConstructorAccessor244->
0x1010ec030-sun/reflect/GeneratedSerializationConstructorAccessor243->
0x1010ec430-sun/reflect/GeneratedSerializationConstructorAccessor242->
0x1010ec830-sun/reflect/GeneratedSerializationConstructorAccessor241->
0x1010ecc30-sun/reflect/GeneratedSerializationConstructorAccessor240->
0x1010ed030-sun/reflect/GeneratedSerializationConstructorAccessor239->
0x1010ed430-sun/reflect/GeneratedSerializationConstructorAccessor238->
0x1010ed830-sun/reflect/GeneratedSerializationConstructorAccessor237->
0x1010edc30-sun/reflect/GeneratedSerializationConstructorAccessor236->
0x1010ee030-sun/reflect/GeneratedSerializationConstructorAccessor235->
0x1010ee430-sun/reflect/GeneratedSerializationConstructorAccessor234->
0x1010ee830-sun/reflect/GeneratedSerializationConstructorAccessor233->
0x1010eec30-sun/reflect/GeneratedSerializationConstructorAccessor232

The GC logs generated with TraceClassLoading and TraceClassUnloading options had:

[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor216 0x000000010110b830]


So, GeneratedSerializationConstructorAccessor216 was unloaded from address 0x10110b830, and sun/reflect/GeneratedMethodAccessor94 got loaded at the same address. But the link to GeneratedSerializationConstructorAccessor216 in the siblings list was not updated after this class was unloaded, and that corrupted the subKlasses chain.

That made me look at the other JVM options used for this failing program. hs_err file showed that -Xnoclassgc was being used to turn off the class unloading but the logs indicated that classes were still getting unloaded. From that point, this mystery was not very hard to solve.

In JDK8, CMSClassUnloadingEnabled option which is used to control the class-unloading in CMS collector, was enabled by default. And this problem was occurring due to the conflicting values getting set for CMSClassUnloadingEnabled and ClassUnloading options. One phase of the class-unloading which is common to the other collectors too that updates subkalsses/siblings links is performed only when ClassUnloading option is enabled. So when -Xnoclassgc or -XX:-ClassUnloading are specified on the command line, due to this bug CMSClassUnloadingEnabled stays enabled and classes get unloaded but that common step gets skipped which corrupts the class hierarchy links leading to hangs or crashes.

The fix was simple - disable CMS class unloading options when -Xnoclassgc or -XX:-ClassUnloading are specified.

There is a similar bug open for G1 collector which is being worked and is targeted for JDK9:
    JDK-8114823: G1 doesn't honor request to disable class unloading


Thursday Apr 02, 2015

Updates to the Java Troubleshooting Guide

Mattis Castegren who is my manager at Oracle, and is the guest writer for this blog post would like to share some details on the Java Troubleshooting Guide. Here's what he has to say:--

With the release of JDK 8, the official Java Troubleshooting Guide got a big overhaul. All pages were looked over and updated for JDK 8, and the two previous guides for the JVM and for Desktop Technologies were merged into one.

In the last month, with the release of 8u40, we have launched the next phase in this project. In this phase, we have added a lot of chapters about the new supportability tools that have been introduced in Java over the last few years.

The biggest new additions are a set of pages on how to use the Java Flight Recorder (JFR). If you haven't used JFR before, you should definitely check out the following chapters:

2.3 What are Java Flight Recordings

2.4 How to Produce a Flight Recording

2.5 Inspect a Flight Recording

These chapters contain step by step instructions on how to record a JFR and also goes through what to look for in a recording to find common issues. The chapters contain lots of screen shots and details on how to interpret the data.

Once you have learned the basics, you can also look at the following two chapters on how to use JFR to debug specific issues:

3.1 Debug a Memory Leak Using Java Flight Recorder

4 Troubleshoot Performance Issues Using JFR

When you have read through these chapters, you will be ready to use this great tool to find bottle necks in your own application.

Other new additions to the troubleshooting guide is a new chapter on how to set up Java for better troubleshooting: Prepare Java for Troubleshooting, as well as a lot of minor updates and clarifications.

Sunday Feb 24, 2008

Debugging JVM hang with 'dbx'

Recently worked on a JVM hang problem, so posting here the steps followed in debugging this issue with dbx.

Customer was facing hard hang on a Solaris-x86 machine with jdk 1.5.0_08 and the process was not even responding to kill -3. They sent us a core file of the hung process.

For dbx to have the debug information, I re-built the product version of 1.5.0_08 libjvm.so with -g flag and loaded and used this new libjvm.so with dbx. With that, dbx was able to get all the debug information for the core file that was generated with a libjvm.so without any debug info.

The pstack on the core file showed that VMThread is trying to acquire Threads_lock, main thread is waiting on a condition on Threads_lock and another thread 3992 was also trying to grab Threads_lock, so this lock seemed to be causing the deadlock.

----------------- lwp# 1 / thread# 1 --------------------
fef4009b lwp_park (0, 0, 0)
fef3a909 cond_wait_queue (807c540, 807c528, 0, 0) + 3b
fef3ae02 _cond_wait (807c540, 807c528) + 66
fef3ae44 cond_wait (807c540, 807c528) + 21
fe92fc64 __1cHMonitorEwait6Mil_i_ (807c4d0, 0, 0) + 2a4
fecf526b __1cHThreadsKdestroy_vm6F_i_ (8073fb9, 0, 806dc14, fee4d33c, fee4a2a0, 10004) + 7b
feb66ea3 jni_DestroyJavaVM (fee43560) + 123
08051f8e main (2, 807017c, 80432b4) + bfb
080512fa ???????? (86, 8043468, 804346d, 8043494, 80434a8, 80434c6)
----------------- lwp# 11 / thread# 11 --------------------
fef4009b lwp_park (0, 0, 0)
fef399bb slow_lock (fbc92000, 807c528, 0) + 3d
fef39ab1 mutex_lock_impl (807c528, 0) + ec
fef39bbd mutex_lock (807c528) + 1a
fe8c9a00 __1cFMutexElock6MpnGThread__v_ (807c4d0, 8261480) + c0
fe8cc1fe __1cFMutexElock6M_v_ (807c4d0) + 4e
fe996295 __1cUSafepointSynchronizeFbegin6F_v_ (fee493fc, 8261480, fedee000, f8199b74, 3, f8199bbc) + 85
fea659c4 __1cIVMThreadEloop6M_v_ (8261480) + 134
fea66478 __1cIVMThreadDrun6M_v_ (8261480) + 88
fecbe0f2 __1cG_start6Fpv_0_ (8261480) + d2
fef3fd52 _thr_setup (fbc92000) + 4e
fef40040 _lwp_start (fbc92000, 0, 0, f8199ff8, fef40040, fbc92000)
----------------- lwp# 3992 / thread# 3992 --------------------
fef4009b lwp_park (0, 0, 0)
fef399bb slow_lock (6c173c00, 807c528, 0) + 3d
fef39ab1 mutex_lock_impl (807c528, 0) + ec
fef39bbd mutex_lock (807c528) + 1a
fe8ea95e __1cFMutexbClock_without_safepoint_check6M_v_ (807c4d0) + 7e
fe95c56e __1cUSafepointSynchronizeFblock6FpnKJavaThread__v_ (a27f780) + ee
fecb6825 __1cGParkerEpark6Mix_v_ (a27f908, 0, d964b198, 45) + 1e5
fed0963d Unsafe_Park (a27f840, 6807aba4, 0, d964b198, 45, 9480bcb8) + 1dd
f876f2f9 ???????? (0, 0, a27c330, 0, 9ae69a8, 0)
00000000 ???????? (fecf6330, fea09d40, fea03c80, fe964f40, fe91cc40, fe939c50)
00000000 ???????? (fffffd2c, 3badd9be, f468fe16, e78b7254, fe1dbbcc, 0)
00000000 ???????? ()

Now let's look at the Threads_lock in dbx.

(dbx) print -fx Threads_lock
Threads_lock = 0x807c4d0

(dbx) print -r \*((Monitor\*)0x807c4d0)
\*((class Monitor \*) 0x807c4d0) = {
Monitor::Mutex::_lock_count = 0
Monitor::Mutex::_lock_event = 0x807c500
Monitor::Mutex::_suppress_signal = 0
Monitor::Mutex::_owner = 0x97b0978 <----------------
Monitor::Mutex::_name = 0xfed97a0f "Threads_lock"
Monitor::Mutex::INVALID_THREAD = 0
Monitor::_event = (nil)
Monitor::_counter = 0
Monitor::_waiters = 1
Monitor::_tickets = 0
}

(dbx) print -r \*((Thread\*)0x97b0978)
\*((class Thread \*) 0x97b0978) = {
Thread::ThreadShadow::_pending_exception = (nil)
Thread::_exception_file = (nil)
Thread::_exception_line = 0
Thread::_real_malloc_address = 0x97b0d28
Thread::_rawmonitor_list = (nil)
Thread::_SR_lock = 0x9b7b890
Thread::_vm_suspend_depth = 0
Thread::_suspend_flags = 0
Thread::_active_handles = 0x97b0b48
Thread::_free_handle_block = (nil)
Thread::_last_handle_mark = 0x65c92618
Thread::_oops_do_parity = 0
Thread::_highest_lock = 0x65c92cb8 "x\^I{\^I\\xe8\^K{\^I\\xb0\\xd6\\x82\\xf4\\xa0H\\xbeu"
Thread::_unboosted_priority = NoPriority
Thread::_tlab = {
Thread::ThreadLocalAllocBuffer::_start = 0x762476d8
Thread::ThreadLocalAllocBuffer::_top = 0x7624c750
Thread::ThreadLocalAllocBuffer::_end = 0x76257308
Thread::ThreadLocalAllocBuffer::_size = 14078U
Thread::ThreadLocalAllocBuffer::_refill_waste_limit = 219U
Thread::ThreadLocalAllocBuffer::_number_of_refills = 6U
Thread::ThreadLocalAllocBuffer::_fast_refill_waste = 0
Thread::ThreadLocalAllocBuffer::_slow_refill_waste = 202U
Thread::ThreadLocalAllocBuffer::_gc_waste = 0
Thread::ThreadLocalAllocBuffer::_slow_allocations = 0
Thread::ThreadLocalAllocBuffer::_allocation_fraction = {
Thread::ThreadLocalAllocBuffer::AdaptiveWeightedAverage::_average = 0.006992618
Thread::ThreadLocalAllocBuffer::AdaptiveWeightedAverage::_sample_count = 1U
Thread::ThreadLocalAllocBuffer::AdaptiveWeightedAverage::_weight = 35U
Thread::ThreadLocalAllocBuffer::AdaptiveWeightedAverage::_last_sample = 0.006992618
}
Thread::ThreadLocalAllocBuffer::_target_refills = 50
Thread::ThreadLocalAllocBuffer::_global_stats = 136222936
}
Thread::_vm_operation_started_count = 1
Thread::_vm_operation_completed_count = 1
Thread::_current_pending_monitor = (nil)
Thread::_current_pending_monitor_is_from_java = 1
Thread::_current_waiting_monitor = (nil)
Thread::_osthread = 0x97b0b00 <-------------
Thread::_resource_area = 0x8c55f50
Thread::_handle_area = 0x98dafc0
Thread::_stack_base = 0x65c93000 ""
Thread::_stack_size = 262144U
Thread::_self_raw_id = 1731617792U
}

(dbx) print -r \*((OSThread\*)0x97b0b00)
\*((class OSThread \*) 0x97b0b00) = {
OSThread::_start_proc = (nil)
OSThread::_start_parm = (nil)
OSThread::_state = RUNNABLE
OSThread::_interrupted = 0
OSThread::_thread_id = 11982U
OSThread::_lwp_id = 11982U
OSThread::_caller_sigmask = {
OSThread::__sigbits = (4U, 0, 0, 0)
}
OSThread::_vm_created_thread = 1
OSThread::_current_callback = (nil)
OSThread::_current_callback_lock = (nil)
OSThread::_interrupt_event = 0x97b07d8
OSThread::_saved_interrupt_thread_state = _thread_new
}

This shows that owner of Threads_lock is thread with id 11982. Stack trace of this thread.

(dbx) thread t@11982
t@11982 (l@11982) stopped in __lwp_park at 0xfef4009b
0xfef4009b: __lwp_park+0x000b: jae __lwp_park+0x19 [ 0xfef400a9, .+0xe ]
(dbx) where
current thread: t@11982
=>[1] __lwp_park(0x0, 0x0), at 0xfef4009b
[2] mutex_lock_queue(0x67366400, 0x0, 0x88a0598, 0x0), at 0xfef3911f
[3] slow_lock(0x67366400, 0x88a0598, 0x0), at 0xfef399bb
[4] mutex_lock_impl(0x88a0598, 0x0), at 0xfef39ab1
[5] __mutex_lock(0x88a0598), at 0xfef39bbd
[6] Mutex::wait_for_lock_blocking_implementation(0xa27f908, 0x97b0978), at 0xfe9d93ba
[7] Mutex::lock(0xa27f908, 0x97b0978), at 0xfe8c99ea
[8] Mutex::lock(0xa27f908), at 0xfe8cc1fe
[9] Parker::unpark(0xa27f908), at 0xfecb69bb
[10] os::interrupt(0xa27f780), at 0xfecbf6bb
[11] Thread::interrupt(0xa27f780), at 0xfecf2ed9
[12] JVM_Interrupt(0x97b0a38, 0x65c923fc, 0x65c923d0, 0x0, 0x65c923fc, 0xf4873020, 0x0, 0xf482f600, 0x65c923fc, 0x65c92424,
0xf8202b6b, 0x0, 0xf8206399, 0x9593fdc0, 0x1, 0x0, 0x65c92400, 0xf482db6b, 0x65c92438, 0xf4873020), at 0xfeb92255
[13] 0xf820843a(0x0, 0xf8206399, 0x9593fdc0, 0x1, 0x0, 0x65c92400), at 0xf820843a
[14] 0xf8202b6b(0x0, 0x0, 0x97f59c18, 0x9593fdc0, 0x65c9243c, 0xf5746e95), at 0xf8202b6b
[15] 0xf8202b6b(0x967a0c40, 0x9, 0x968f6eb8, 0x65c92464, 0xf57472be, 0x65c92498), at 0xf8202b6b
[16] 0xf8202b6b(0x0, 0x968f6eb8, 0x967a0c40, 0x65c9249c, 0xf5845a0c, 0x65c924c4), at 0xf8202b6b
[17] 0xf8202b6b(0x1b58, 0x967a0c40, 0x65c924c8, 0xf5845674, 0x65c92524, 0xf58a1f78), at 0xf8202b6b
[18] 0xf8202b6b(0x7624c168, 0x7624c138, 0x7624c108, 0x7624c0d8, 0x7624bee8, 0x7624bd00), at 0xf8202b6b

It is trying to acquire Monitor 0xa27f908

Now, look at this Monitor:
(dbx) print -r \*((Monitor\*)0xa27f908)
\*((class Monitor \*) 0xa27f908) = {
Monitor::Mutex::_lock_count = 0
Monitor::Mutex::_lock_event = 0x88a0570 <-----------
Monitor::Mutex::_suppress_signal = 0
Monitor::Mutex::_owner = (nil)
Monitor::Mutex::_name = 0xfed97c99 "Park Semaphore"
Monitor::Mutex::INVALID_THREAD = 0
Monitor::_event = (nil)
Monitor::_counter = 0
Monitor::_waiters = 0
Monitor::_tickets = 0
}
(dbx) print -r \*((Event\*)0x88a0570)
More than one identifier 'Event'.
Select one of the following:
0) Cancel
1) class os::Solaris::Event
2) class Solaris::Event
> 1
\*((class os::Solaris::Event \*) 0x88a0570) = {
Event::_count = 0
Event::_nParked = 0
Event::CachePad = (-6.7529205832009e-205, -6.6220952168053e-205, -1.2786650622506e-204, -1.9668306807887e-204)
Event::_mutex = (
{
Event::_lwp_mutex::flags = {
Event::_lwp_mutex::flag1 = 4U
Event::_lwp_mutex::flag2 = '\\0'
Event::_lwp_mutex::ceiling = '\\0'
Event::_lwp_mutex::mbcp_type_un = {
Event::_lwp_mutex::bcptype = 0
Event::_lwp_mutex::mtype_rcount = {
Event::_lwp_mutex::count_type1 = '\\0'
Event::_lwp_mutex::count_type2 = '\\0'
}
}
Event::_lwp_mutex::magic = 19800U
}
Event::_lwp_mutex::lock = {
Event::_lwp_mutex::lock64 = {
Event::_lwp_mutex::pad = ""
}
Event::_lwp_mutex::lock32 = {
Event::_lwp_mutex::ownerpid = 0
Event::_lwp_mutex::lockword = 16842752U
}
Event::_lwp_mutex::owner64 = 72339069014638592ULL
}
Event::_lwp_mutex::data = 1813462016ULL
}

)
Event::_cond = (
{
Event::_lwp_cond::flags = {
Event::_lwp_cond::flag = ""
Event::_lwp_cond::type = 0
Event::_lwp_cond::magic = 17238U
}
Event::_lwp_cond::data = 0
}

)
Event::FreeNext = (nil)
Event::Immortal = 0
}

Here _lwp_mutex->data which is 0x6C173C00 is the owner thread (ulwp_t)

looking at it:
(dbx) x 0x6C173C00/30X
0x6c173c00: 0x6c173c00 0x00000000 0x00000000 0x00000000
0x6c173c10: 0x00000000 0x00000000 0x00000000 0x00000000
0x6c173c20: 0x00000000 0x00000000 0x00000000 0xfef6b740
0x6c173c30: 0x00000000 0x00000000 0x6c174000 0x6c173800
0x6c173c40: 0x00000000 0x00000000 0x00000000 0x6803b000
0x6c173c50: 0x00040000 0x00000000 0x6807b000 0x00040000
0x6c173c60: 0x6803b000 0x00040000 0x00000000 0x00000398
0x6c173c70: 0x00000f98 0x0000007f

0x00000f98 (which is 3992) is the thread id holding this Event::mutex

Now looking at thread 3992:
(dbx) thread t@3992
t@3992 (l@3992) stopped in __lwp_park at 0xfef4009b
0xfef4009b: __lwp_park+0x000b: jae __lwp_park+0x19 [ 0xfef400a9, .+0xe ]
(dbx) where
current thread: t@3992
=>[1] __lwp_park(0x0, 0x0), at 0xfef4009b
[2] mutex_lock_queue(0x6c173c00, 0x0, 0x807c528, 0x0), at 0xfef3911f
[3] slow_lock(0x6c173c00, 0x807c528, 0x0), at 0xfef399bb
[4] mutex_lock_impl(0x807c528, 0x0), at 0xfef39ab1
[5] __mutex_lock(0x807c528), at 0xfef39bbd
[6] Mutex::lock_without_safepoint_check(0x807c4d0), at 0xfe8ea95e
[7] SafepointSynchronize::block(0xa27f780), at 0xfe95c56e
[8] Parker::park(0xa27f908, 0x0, 0xd964b198, 0x45), at 0xfecb6825
[9] Unsafe_Park(0xa27f840, 0x6807aba4, 0x0, 0xd964b198, 0x45, 0x9480bcb8), at 0xfed0963d

It is waiting to lock Threads_lock.

So threads 11982 and 3992 have a deadlock.

Thread 11982 – holds Thread_lock and waiting to acquire Monitor 0xa27f908
Thread 3992 – holds lock on 0xa27f908 and waiting to acquire Threads_lock

This problem has been fixed with 6601725 in 5.0u15 and mustang.

About

Poonam-Oracle

Search

Categories
Archives
« July 2016
SunMonTueWedThuFriSat
     
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
      
Today