JDK-8159864 : gc/stress/TestStressRSetCoarsening.java hits assert assert(ILocked()) failed: invariant
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 9
  • Priority: P2
  • Status: Closed
  • Resolution: Cannot Reproduce
  • Submitted: 2016-06-18
  • Updated: 2016-09-16
  • Resolved: 2016-07-18
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 9
9Resolved
Related Reports
Relates :  
JDK-8160369 - Memory fences needed around setting and reading object lengths
Description
#  Internal Error (hotspot/src/share/vm/runtime/mutex.cpp:459), pid=30320, tid=30333
#  assert(ILocked()) failed: invariantCurrent thread (0x0000007f8404d000):  ConcurrentGCThread "G1 Refine#6" [stack: 0x0000007f4fbfe000,0x0000007f4fcfe000] [id=30333]

Stack: [0x0000007f4fbfe000,0x0000007f4fcfe000],  sp=0x0000007f4fcfbf70,  free space=1015k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x108c878]  VMError::report(outputStream*, bool)+0x1780
V  [libjvm.so+0x108ce60]  VMError::report_and_die(int, char const*, char const*, std::__va_list, Thread*, unsigned char*, void*, void*, char const*, int, unsigned long)+0x140
V  [libjvm.so+0x108da70]  VMError::report_and_die(Thread*, char const*, int, char const*, char const*, std::__va_list)+0x54
V  [libjvm.so+0x6b51ac]  report_vm_error(char const*, int, char const*, char const*, ...)+0xe0
V  [libjvm.so+0xd54944]  Monitor::ILock(Thread*)+0x114
V  [libjvm.so+0xd570c4]  Monitor::lock_without_safepoint_check()+0x54
V  [libjvm.so+0x8ee060]  OtherRegionsTable::add_reference(void*, unsigned int)+0x170
V  [libjvm.so+0x81bda4]  void G1UpdateRSOrPushRefOopClosure::do_oop_work<unsigned int>(unsigned int*)+0x1a0
V  [libjvm.so+0x7fa07c]  ObjArrayKlass::oop_oop_iterate_bounded_nv(oop, FilterOutOfRegionClosure*, MemRegion)+0x198
V  [libjvm.so+0x8e0954]  HeapRegion::oops_on_card_seq_iterate_careful(MemRegion, FilterOutOfRegionClosure*, bool, signed char*)+0x79c
V  [libjvm.so+0x8195d4]  G1RemSet::refine_card(signed char*, unsigned int, G1ParPushHeapRSClosure*)+0x200
V  [libjvm.so+0x7b7064]  RefineCardTableEntryClosure::do_card_ptr(signed char*, unsigned int)+0x38
V  [libjvm.so+0x736910]  DirtyCardQueueSet::apply_closure_to_buffer(CardTableEntryClosure*, BufferNode*, bool, unsigned int)+0xa4
V  [libjvm.so+0x736e30]  DirtyCardQueueSet::apply_closure_to_completed_buffer(CardTableEntryClosure*, unsigned int, unsigned long, bool)+0x9c
V  [libjvm.so+0x661808]  ConcurrentG1RefineThread::run_service()+0x14c
V  [libjvm.so+0x662100]  ConcurrentGCThread::run()+0x98
V  [libjvm.so+0xdc45d8]  thread_native_entry(Thread*)+0x118
C  [libpthread.so.0+0x7e2c]  start_thread+0xb0
Comments
Thomas: Thanks for the patches, I will share the result after testing them. BTW, the issue that has wrong oop size and reproducible is JDK-8158168, so I will copy your comments to it.
28-06-2016
Patch adds storestore/loadload barriers (in a somewhat conservative way) to see if the test uses garbage values when scanning objects. Potential partial fix for JDK-8160369. Note that I think there is still a missing storestore barriers that is needed after setting the layout helper in a Klass - I could not find a good place, and maybe it's already done somewhere (before returning the klass pointer to store it somewhere). (There is no need for a loadload barrier in our supported platforms as the layout_helper is an address dependent load from the klass pointer). This does not seem to be a problem either in this particular test case as the amount of class loading done here is minimal and should be finished by the time we experience the crashes.
28-06-2016
This is the change that modifies one assert to a guarantee as discussed recently. I think particular for this test, you could add an upper bound for the object size of maybe 32 * M too. (From the logs the max object size is 1M)
28-06-2016
More information from the core dump. Same mutex is used among 9 threads (#1, #2, #4, #5, #7, #8, #10, #14 and #23). And current Monitor::_LockWord.FullWord is came from thread #4. It is also strange that thread #1 has lock word of thread #4 and it is just before returning the Monitor::ILock(). (The assertion failure is firstly strange as the core dump shows ILocked() returns true) (gdb) p/x _LockWord.FullWord $21 = 0x7f84054901 (gdb) p ESelf (from thread #4) $34 = (ParkEvent * const) 0x7f84054900 (gdb) p ESelf->ListNext (thread #14) $35 = 0x7f843f4300 (gdb) p ESelf (from thread #14) $29 = (ParkEvent * const) 0x7f843f4300
24-06-2016
Lots of crashes with this test on ARM64 - see also JDK-8154459 and linked therefrom.
23-06-2016
Looking at the core dump file, the assert is fired from Monitor::ILock(), mutex.cpp:line459 but it is strange as Monitor::ILocked() seems returning 'true'. Need to investigate other threads' current activity. int Monitor::ILocked() { const intptr_t w = _LockWord.FullWord & 0xFF; assert(w == 0 || w == _LBIT, "invariant"); return w == _LBIT; } (gdb) frame 6 #6 0x0000007f899c4944 in Monitor::ILock (this=0x7f8413d350, Self=0x7f8404d000) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/runtime/mutex.cpp:459 459 assert(ILocked(), "invariant"); (gdb) p (_LockWord.FullWord & 0xff ) == 1 $26 = true (gdb) bt #0 0x0000007f8a0f1a88 in raise () from /export/local/home/gtee/8159864/libc.so.6 #1 0x0000007f8a0f4efc in abort () from /export/local/home/gtee/8159864/libc.so.6 #2 0x0000007f89a29b08 in os::abort (dump_core=<optimized out>, siginfo=<optimized out>, context=<optimized out>) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/os/linux/vm/os_linux.cpp:1391 #3 0x0000007f89cfd120 in VMError::report_and_die (id=id@entry=-536870912, message=message@entry=0x7f89eb9ea8 "assert(ILocked()) failed", detail_fmt=detail_fmt@entry=0x7f89e9df10 "invariant", detail_args=..., thread=<optimized out>, pc=pc@entry=0x0, siginfo=siginfo@entry=0x0, context=context@entry=0x0, filename=filename@entry=0x7f89eb9e00 "/scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/runtime/mutex.cpp", lineno=lineno@entry=459, size=size@entry=0) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/utilities/vmError.cpp:1335 #4 0x0000007f89cfda70 in VMError::report_and_die (thread=<optimized out>, filename=filename@entry=0x7f89eb9e00 "/scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/runtime/mutex.cpp", lineno=lineno@entry=459, message=message@entry=0x7f89eb9ea8 "assert(ILocked()) failed", detail_fmt=detail_fmt@entry=0x7f89e9df10 "invariant", detail_args=<error reading variable: Cannot access memory at address 0x7>) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/utilities/vmError.cpp:1104 #5 0x0000007f893251ac in report_vm_error ( file=file@entry=0x7f89eb9e00 "/scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/runtime/mutex.cpp", line=line@entry=459, error_msg=error_msg@entry=0x7f89eb9ea8 "assert(ILocked()) failed", detail_fmt=detail_fmt@entry=0x7f89e9df10 "invariant") at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/utilities/debug.cpp:220 #6 0x0000007f899c4944 in Monitor::ILock (this=0x7f8413d350, Self=0x7f8404d000) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/runtime/mutex.cpp:459 #7 0x0000007f899c70c4 in lock_without_safepoint_check (Self=0x7f8404d000, this=0x7f8413d350) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/runtime/mutex.cpp:963 #8 Monitor::lock_without_safepoint_check (this=0x7f8413d350) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/runtime/mutex.cpp:969 #9 0x0000007f8955e060 in MutexLockerEx (no_safepoint_check=true, mutex=0x7f8413d350, this=<synthetic pointer>) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/runtime/mutexLocker.hpp:209 #10 contains_reference (from=0xe5a0fe48, this=0x7f8413d3f0) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/heapRegionRemSet.cpp:659 #11 OtherRegionsTable::add_reference (this=0x7f8413d3f0, from=from@entry=0xe5a0fe48, tid=<optimized out>) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/heapRegionRemSet.cpp:372 #12 0x0000007f8948bda4 in add_reference (tid=<optimized out>, from=0xe5a0fe48, this=<optimized out>) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/heapRegionRemSet.hpp:227 #13 G1UpdateRSOrPushRefOopClosure::do_oop_work<unsigned int> (this=0x7f4fcfc720, p=0xe5a0fe48) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/g1OopClosures.inline.hpp:232 #14 0x0000007f8946a07c in do_oop_nv<unsigned int> (p=0xe5a0fe48, this=0x7f4fcfc750) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/g1OopClosures.inline.hpp:59 #15 do_oop<FilterOutOfRegionClosure, unsigned int> (p=0xe5a0fe48, closure=0x7f4fcfc750) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/memory/iterator.inline.hpp:72 #16 oop_oop_iterate_elements_specialized_bounded<true, unsigned int, FilterOutOfRegionClosure> (this=<optimized out>, high=<optimized out>, low=<optimized out>, closure=0x7f4fcfc750, a=...) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/oops/objArrayKlass.inline.hpp:65 #17 oop_oop_iterate_elements_bounded<true, FilterOutOfRegionClosure> (mr=..., closure=0x7f4fcfc750, a=..., this=<optimized out>) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/oops/objArrayKlass.inline.hpp:81 #18 oop_oop_iterate_bounded<true, FilterOutOfRegionClosure> (mr=..., closure=0x7f4fcfc750, obj=..., this=<optimized out>) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/oops/objArrayKlass.inline.hpp:108 #19 ObjArrayKlass::oop_oop_iterate_bounded_nv (this=<optimized out>, obj=..., closure=0x7f4fcfc750, mr=...) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/g1OopClosures.cpp:64 #20 0x0000007f89550954 in oop_iterate (mr=..., blk=0x7f4fcfc750, this=0xe5a00000) ---Type <return> to continue, or q <return> to quit--- at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/oops/oop.inline.hpp:726 #21 HeapRegion::oops_on_card_seq_iterate_careful (this=this@entry=0x7f840c0610, mr=..., cl=cl@entry=0x7f4fcfc750, filter_young=filter_young@entry=true, card_ptr=card_ptr@entry=0x7f4f23707f '\377' <repeats 200 times>...) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/heapRegion.cpp:481 #22 0x0000007f894895d4 in G1RemSet::refine_card (this=0x7f8405d5e0, card_ptr=0x7f4f23707f '\377' <repeats 200 times>..., worker_i=14, oops_in_heap_closure=<optimized out>) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/g1RemSet.cpp:679 #23 0x0000007f89427064 in RefineCardTableEntryClosure::do_card_ptr (this=0x7f8404aba0, card_ptr=<optimized out>, worker_i=<optimized out>) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp:103 #24 0x0000007f893a6910 in DirtyCardQueueSet::apply_closure_to_buffer ( this=this@entry=0x7f8a0a2a00 <JavaThread::_dirty_card_queue_set>, cl=cl@entry=0x7f8404aba0, node=node@entry=0x7ed80537a0, consume=consume@entry=true, worker_i=worker_i@entry=14) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/dirtyCardQueue.cpp:165 #25 0x0000007f893a6e30 in DirtyCardQueueSet::apply_closure_to_completed_buffer ( this=0x7f8a0a2a00 <JavaThread::_dirty_card_queue_set>, cl=0x7f8404aba0, worker_i=14, stop_at=<optimized out>, during_pause=during_pause@entry=false) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/dirtyCardQueue.cpp:239 #26 0x0000007f892d1808 in ConcurrentG1RefineThread::run_service (this=0x7f8404d000) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/g1/concurrentG1RefineThread.cpp:151 #27 0x0000007f892d2100 in ConcurrentGCThread::run (this=0x7f8404d000) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/share/vm/gc/shared/concurrentGCThread.cpp:82 #28 0x0000007f89a345d8 in thread_native_entry (thread=0x7f8404d000) at /scratch/opt/jprt/T/P1/185941.dfazunen/s/hotspot/src/os/linux/vm/os_linux.cpp:688 #29 0x0000007f8a246e2c in start_thread () from /export/local/home/gtee/8159864/libpthread.so.0 #30 0x0000007f8a186430 in clone () from /export/local/home/gtee/8159864/libc.so.6
20-06-2016