JDK-8031717 : Kitchensink crashes in ObjectSynchronizer when inflating lock
  • Type: Bug
  • Component: hotspot
  • Sub-Component: compiler
  • Affected Version: 9
  • Priority: P2
  • Status: Closed
  • Resolution: Duplicate
  • Submitted: 2014-01-14
  • Updated: 2014-03-03
  • Resolved: 2014-03-03
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
Duplicate :  
JDK-8031703 - Missing post-barrier in ReferenceProcessor
Description
50c2ec08 77c2fa29 ntdll!NtGetContextThread+0x12
50c2ec28 77c3c571 ntdll!LdrpFindLoadedDllByName+0x68
50c2ed10 77c3e2d0 ntdll!LdrpFindOrMapDll+0x171
50c2ef70 7289cec3 ntdll!LdrpLoadImportModule+0x287
50c2ef84 50c2f388 dbghelp!Win32LiveAllocationProvider::Free+0x19
WARNING: Frame IP not in any known module. Following frames may be wrong.
50c2f4ec 728971ca 0x50c2f388
50c2f554 6fb05716 dbghelp!MiniDumpWriteDump+0xf2
50c2f5a0 6fae4b0b jvm!os::check_or_create_dump(void * exceptionRecord = 0x00000000, void * contextRecord = 0x00000000, char * buffer = 0x7021ec18 "C:\local\aurora\sandbox\results\kitchensink\hs_err_pid14616.mdmp", unsigned int bufferSize = 0x7d0)+0x146 [c:\jprt\t\p1\090500.brutisso\s\src\os\windows\vm\os_windows.cpp @ 1020]
50c2f7b0 6fad9b35 jvm!VMError::report_and_die(void)+0x10b [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\utilities\vmerror.cpp @ 908]
50c2f7f8 6fa97c08 jvm!report_vm_error(char * file = 0x70005670 "C:\jprt\T\P1\090500.brutisso\s\src\share\vm\runtime\synchronizer.cpp", int line = 0n1212, char * error_msg = 0x70005c38 "assert(inf->header()->is_neutral()) failed", char * detail_msg = 0x6ff5854c "invariant")+0x45 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\utilities\debug.cpp @ 223]
50c2f864 6fa988e4 jvm!ObjectSynchronizer::inflate(class Thread * Self = 0x505e1000, class oopDesc * object = 0x3e6abd30)+0x228 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\synchronizer.cpp @ 1212]
50c2f884 6fa993f3 jvm!ObjectSynchronizer::slow_enter(class Handle obj = class Handle, class BasicLock * lock = 0x50c2f910, class Thread * __the_thread__ = 0x505e1000)+0x124 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\synchronizer.cpp @ 258]
50c2f89c 6fa843b0 jvm!ObjectSynchronizer::fast_enter(class Handle obj = class Handle, class BasicLock * lock = 0x50c2f910, bool attempt_rebias = true, class Thread * __the_thread__ = 0x505e1000)+0xc3 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\synchronizer.cpp @ 180]
50c2f8c8 027d51ef jvm!SharedRuntime::complete_monitor_locking_C(class oopDesc * _obj = 0x3e6abd30, class BasicLock * lock = 0x50c2f910, class JavaThread * thread = 0x505e1000)+0xf0 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\sharedruntime.cpp @ 1845]

50c2f97c 6fa69be4 0x27d51ef
// From hs_err file:
// v  ~RuntimeStub::_complete_monitor_locking_Java
// J 657 C2 java.lang.ref.Finalizer.access$100(Ljava/lang/ref/Finalizer;Lsun/misc/JavaLangAccess;)V (6 bytes) @ 0x029abba0 [0x029ab5c0+0x5e0]
// J 3978% C2 java.lang.ref.Finalizer$FinalizerThread.run()V (55 bytes) @ 0x02ef6978 [0x02ef6880+0xf8]
// v  ~StubRoutines::call_stub

50c2fa10 6fb95c02 jvm!JavaCalls::call_helper(class JavaValue * result = 0x50c2fbb0, class methodHandle * m = 0x50c2fa84, class JavaCallArguments * args = 0x50c2fb18, class Thread * __the_thread__ = 0x005e1000)+0x3c4 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\javacalls.cpp @ 402]
50c2fa58 6fa69ca8 jvm!os::os_exception_wrapper(<function> * f = 0x6fa69820, class JavaValue * value = 0x50c2fbb0, class methodHandle * method = 0x50c2fa84, class JavaCallArguments * args = 0x50c2fb18, class Thread * thread = 0x505e1000)+0xa2 [c:\jprt\t\p1\090500.brutisso\s\src\os_cpu\windows_x86\vm\os_windows_x86.cpp @ 114]
50c2fa78 6fa69fbe jvm!JavaCalls::call(class JavaValue * result = 0x50c2fbb0, class methodHandle method = class methodHandle, class JavaCallArguments * args = 0x50c2fb18, class Thread * __the_thread__ = 0x505e1000)+0x48 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\javacalls.cpp @ 307]
50c2faec 6fa6a077 jvm!JavaCalls::call_virtual(class JavaValue * result = 0x50c2fbb0, class KlassHandle spec_klass = class KlassHandle, class Symbol * name = 0x504d0778, class Symbol * signature = 0x504d1c10, class JavaCallArguments * args = 0x50c2fb18, class Thread * __the_thread__ = 0x505e1000)+0x11e [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\javacalls.cpp @ 204]
50c2fb64 6f9d5361 jvm!JavaCalls::call_virtual(class JavaValue * result = 0x50c2fbb0, class Handle receiver = class Handle, class KlassHandle spec_klass = class KlassHandle, class Symbol * name = 0x504d0778, class Symbol * signature = 0x504d1c10, class Thread * __the_thread__ = 0x505e1000)+0x77 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\javacalls.cpp @ 211]
50c2fbc0 6faa2d99 jvm!thread_entry(class JavaThread * thread = 0x5066a618, class Thread * __the_thread__ = 0x505e1518)+0x91 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\prims\jvm.cpp @ 2812]
50c2fc14 6faa2f33 jvm!JavaThread::thread_main_inner(void)+0xd9 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\thread.cpp @ 1699]
50c2fc48 6fb05571 jvm!JavaThread::run(void)+0x173 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\thread.cpp @ 1679]
50c2fd08 7321c556 jvm!java_start(class Thread * thread = 0x505e1000)+0xb1 [c:\jprt\t\p1\090500.brutisso\s\src\os\windows\vm\os_windows.cpp @ 431]
50c2fd40 7321c600 msvcr100!_endthreadex+0x3f
50c2fd4c 774c3677 msvcr100!_endthreadex+0xce
50c2fd58 77c39f42 kernel32!BaseThreadInitThunk+0xe
50c2fd98 77c39f15 ntdll!__RtlUserThreadStart+0x70
50c2fdb0 00000000 ntdll!_RtlUserThreadStart+0x1b
Comments
I see you've done it already. Thanks.
03-03-2014
I looked through the test result history, this crash happened three times. First time was Jan 13th and last time was Feb 5th. Again this seems to correlate well in time with the fix for JDK-8031703. I think we should close it as a duplicate. I can do it if you want?
03-03-2014
[~pliden], can I assign this bug to you?
28-02-2014
The symptoms of this bug looks very similar to the bug that was fixed in JDK-8031703 and I can think up a scenario where that bug could cause a failure like this. Basically, JDK-8031703 fixed an issue where the reference processor forgot to do a post-barrier and a later GC could then trash the Reference pending list. So the pending list could end up pointing to dead/moved Finalizer objects. As long as those objects aren't overwritten the ReferenceHandler thread could have moved the dead objects from the pending list into the FinalizerQueue. The FinalizerThread would then remove them from the queue and call runFinalizer(). The first thing we do there is to lock the Finalizer object and I guess that is the first time we actually notice that we're dealing with a stable oop. These bugs also correlate well in time. The bug fixed by JDK-8031703 was introduced into the hs-gc tree on Friday Jan 10th and this bug was filed after a failure in nightly-tests the following Monday (Jan 13th). The fix for JDK-8031703 got into the tree on Feb 6th, so if it hasn't been seen after that I'd say it's most likely the same bug.
28-02-2014
This smells more like a GC issue. Can someone with a Windows machine get the compiled code for the two Java methods on the stack? Maybe [~ehelin]?
28-02-2014
The bytecode of java.lang.ref.Finalizer.access$100 is: static void access$100(java.lang.ref.Finalizer, sun.misc.JavaLangAccess); Code: 0: aload_0 1: aload_1 2: invokespecial #4 // Method runFinalizer:(Lsun/misc/JavaLangAccess;)V 5: return So the monitorexit that fails is either in runFinalizer() or in one of its callees, e.g. remove().
28-02-2014
Given the compiled Java methods on the stack: Java frames: (J=compiled Java code, j=interpreted, Vv=VM code) v ~RuntimeStub::_complete_monitor_locking_Java J 657 C2 java.lang.ref.Finalizer.access$100(Ljava/lang/ref/Finalizer;Lsun/misc/JavaLangAccess;)V (6 bytes) @ 0x029abba0 [0x029ab5c0+0x5e0] J 3978% C2 java.lang.ref.Finalizer$FinalizerThread.run()V (55 bytes) @ 0x02ef6978 [0x02ef6880+0xf8] v ~StubRoutines::call_stub and the last compile event: Event: 1679.630 Thread 0x517e8800 nmethod 18170 0x030f1e88 code [0x030f1fc0, 0x030f224c] the Finalizer methods are around for quite some time already (compile ids 657 and 3978 compared to 18170) and surely have finalized other objects since.
28-02-2014
Let's look at the arguments: 50c2f8c8 027d51ef jvm!SharedRuntime::complete_monitor_locking_C(class oopDesc * _obj = 0x3e6abd30, class BasicLock * lock = 0x50c2f910, class JavaThread * thread = 0x505e1000)+0xf0 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\sharedruntime.cpp @ 1845] --- oopDesc * _obj = 0x3e6abd30 The address is in the heap: garbage-first heap total 983040K, used 892263K [0x12000000, 0x4e000000, 0x4e000000) More precisely in this region: CS SU TS 11 PTAMS 0x3e600000 NTAMS 0x3e600000 space 1024K, 50% used [0x3e600000, 0x3e680000, 0x3e700000) The region is only 50% used and _obj pointer seems to point into the unused part. --- BasicLock * lock = 0x50c2f910 The lock address points into the stack of the thread so that should be okay: =>0x505e1000 JavaThread "Finalizer" daemon [_thread_in_vm, id=4360, stack(0x50be0000,0x50c30000)] --- JavaThread * thread = 0x505e1000 The thread pointer is correct: =>0x505e1000 JavaThread "Finalizer" daemon [_thread_in_vm, id=4360, stack(0x50be0000,0x50c30000)]
28-02-2014
Moving from hotspot/runtime -> hotspot/compiler for further triage.
27-02-2014
Here's the crashing thread's stack from stack_traces.txt: 50c2f7f8 6fa97c08 jvm!report_vm_error(char * file = 0x70005670 "C:\jprt\T\P1\090500.brutisso\s\src\share\vm\runtime\synchronizer.cpp", int line = 0n1212, char * error_msg = 0x70005c38 "assert(inf->header()->is_neutral()) failed", char * detail_msg = 0x6ff5854c "invariant")+0x45 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\utilities\debug.cpp @ 223] 50c2f864 6fa988e4 jvm!ObjectSynchronizer::inflate(class Thread * Self = 0x505e1000, class oopDesc * object = 0x3e6abd30)+0x228 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\synchronizer.cpp @ 1212] 50c2f884 6fa993f3 jvm!ObjectSynchronizer::slow_enter(class Handle obj = class Handle, class BasicLock * lock = 0x50c2f910, class Thread * __the_thread__ = 0x505e1000)+0x124 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\synchronizer.cpp @ 258] 50c2f89c 6fa843b0 jvm!ObjectSynchronizer::fast_enter(class Handle obj = class Handle, class BasicLock * lock = 0x50c2f910, bool attempt_rebias = true, class Thread * __the_thread__ = 0x505e1000)+0xc3 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\synchronizer.cpp @ 180] 50c2f8c8 027d51ef jvm!SharedRuntime::complete_monitor_locking_C(class oopDesc * _obj = 0x3e6abd30, class BasicLock * lock = 0x50c2f910, class JavaThread * thread = 0x505e1000)+0xf0 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\sharedruntime.cpp @ 1845] 50c2f97c 6fa69be4 0x27d51ef 50c2fa10 6fb95c02 jvm!JavaCalls::call_helper(class JavaValue * result = 0x50c2fbb0, class methodHandle * m = 0x50c2fa84, class JavaCallArguments * args = 0x50c2fb18, class Thread * __the_thread__ = 0x005e1000)+0x3c4 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\javacalls.cpp @ 402] 50c2fa58 6fa69ca8 jvm!os::os_exception_wrapper(<function> * f = 0x6fa69820, class JavaValue * value = 0x50c2fbb0, class methodHandle * method = 0x50c2fa84, class JavaCallArguments * args = 0x50c2fb18, class Thread * thread = 0x505e1000)+0xa2 [c:\jprt\t\p1\090500.brutisso\s\src\os_cpu\windows_x86\vm\os_windows_x86.cpp @ 114] 50c2fa78 6fa69fbe jvm!JavaCalls::call(class JavaValue * result = 0x50c2fbb0, class methodHandle method = class methodHandle, class JavaCallArguments * args = 0x50c2fb18, class Thread * __the_thread__ = 0x505e1000)+0x48 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\javacalls.cpp @ 307] 50c2faec 6fa6a077 jvm!JavaCalls::call_virtual(class JavaValue * result = 0x50c2fbb0, class KlassHandle spec_klass = class KlassHandle, class Symbol * name = 0x504d0778, class Symbol * signature = 0x504d1c10, class JavaCallArguments * args = 0x50c2fb18, class Thread * __the_thread__ = 0x505e1000)+0x11e [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\javacalls.cpp @ 204] 50c2fb64 6f9d5361 jvm!JavaCalls::call_virtual(class JavaValue * result = 0x50c2fbb0, class Handle receiver = class Handle, class KlassHandle spec_klass = class KlassHandle, class Symbol * name = 0x504d0778, class Symbol * signature = 0x504d1c10, class Thread * __the_thread__ = 0x505e1000)+0x77 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\javacalls.cpp @ 211] 50c2fbc0 6faa2d99 jvm!thread_entry(class JavaThread * thread = 0x5066a618, class Thread * __the_thread__ = 0x505e1518)+0x91 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\prims\jvm.cpp @ 2812] 50c2fc14 6faa2f33 jvm!JavaThread::thread_main_inner(void)+0xd9 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\thread.cpp @ 1699] 50c2fc48 6fb05571 jvm!JavaThread::run(void)+0x173 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\thread.cpp @ 1679] 50c2fd08 7321c556 jvm!java_start(class Thread * thread = 0x505e1000)+0xb1 [c:\jprt\t\p1\090500.brutisso\s\src\os\windows\vm\os_windows.cpp @ 431] The Java frames from the hs_err_pid file are: Java frames: (J=compiled Java code, j=interpreted, Vv=VM code) v ~RuntimeStub::_complete_monitor_locking_Java J 657 C2 java.lang.ref.Finalizer.access$100(Ljava/lang/ref/Finalizer;Lsun/misc/JavaLangAccess;)V (6 bytes) @ 0x029abba0 [0x029ab5c0+0x5e0] J 3978% C2 java.lang.ref.Finalizer$FinalizerThread.run()V (55 bytes) @ 0x02ef6978 [0x02ef6880+0xf8] v ~StubRoutines::call_stub Here are just four frames from the crash: 50c2f89c 6fa843b0 jvm!ObjectSynchronizer::fast_enter(class Handle obj = class Handle, class BasicLock * lock = 0x50c2f910, bool attempt_rebias = true, class Thread * __the_thread__ = 0x505e1000)+0xc3 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\synchronizer.cpp @ 180] 50c2f8c8 027d51ef jvm!SharedRuntime::complete_monitor_locking_C(class oopDesc * _obj = 0x3e6abd30, class BasicLock * lock = 0x50c2f910, class JavaThread * thread = 0x505e1000)+0xf0 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\sharedruntime.cpp @ 1845] 50c2f97c 6fa69be4 0x27d51ef 50c2fa10 6fb95c02 jvm!JavaCalls::call_helper(class JavaValue * result = 0x50c2fbb0, class methodHandle * m = 0x50c2fa84, class JavaCallArguments * args = 0x50c2fb18, class Thread * __the_thread__ = 0x005e1000)+0x3c4 [c:\jprt\t\p1\090500.brutisso\s\src\share\vm\runtime\javacalls.cpp @ 402] JavaCalls::call_helper() => unknown frame => SharedRuntime::complete_monitor_locking_C() => ObjectSynchronizer::fast_enter() This address from the unknown frame: 0x27d51ef appears to be from the code cache: CodeCache: size=245760Kb used=44787Kb max_used=44800Kb free=200972Kb bounds [0x026d0000, 0x05320000, 0x116d0000] total_blobs=11639 nmethods=11281 adapters=276 compilation: enabled lower: 0x026d0000 ours: 0x027d51ef upper: 0x05320000 It looks like this call into SharedRuntime::complete_monitor_locking_C() is coming from compiled code. This reminds me of a more recent crash with product bits on Solaris SPARC: JDK-8035430 runThese crashed with SEGV in ObjectMonitor::enter(Thread*) after 13.5 hours of execution, no hs_err created The crash in this bug is with Win64 fastdebug bits and the crash in JDK-8035430 is with Solaris SPARCV9 product bits, but the way we call into SharedRuntime::complete_monitor_locking_C() is from compiled ode in both cases.
27-02-2014
Interesting. I've been investigating a KitchenSink monitor deflation bug: JDK-8019160 ObjectSynchronizer::deflate_monitor traps on guarantee (7u40)
14-01-2014
We've seen multiple crashes in our nightly testing with reference handling due to what looks like a compiler bug: https://bugs.openjdk.java.net/browse/JDK-8031703. That bug might be related to this one, but they could also be totally unrelated (Weak/Soft/Phantom references are treated slightly different compared to final references).
14-01-2014
ILW: Impact = High, since crash Likelihood = Low, since its only been seen once in nightly testing Workaround = High, since no workaround is known at this point HLH => P2
14-01-2014
Attached stack traces of all threads.
14-01-2014
Attached hs_err file.
14-01-2014