Created attachment 1859772 [details]
pstack of the JDK native hang.

Description of problem:

We observe a JDK hang during our automatic regression tests, in particular Eclipse-based debugger tests. See attached "pstack_50337.txt".

We assume the deadlocked threads are:

Thread 88 (Thread 0x7fffb4378700 (LWP 50344)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007ffff688d3e3 in os::PlatformEvent::park (this=0x7ffff0756100) at src/hotspot/os/posix/os_posix.cpp:2003
#2  0x00007ffff668f57c in SimpleEnter (Self=<optimized out>, this=<optimized out>) at src/hotspot/share/prims/jvmtiRawMonitor.cpp:150
#3  JvmtiRawMonitor::raw_enter (this=this@entry=0x7ffff07c0000, __the_thread__=__the_thread__@entry=0x7ffff0755800) at src/hotspot/share/prims/jvmtiRawMonitor.cpp:304
#4  0x00007ffff6671cb8 in JvmtiEnv::RawMonitorEnter (this=<optimized out>, rmonitor=0x7ffff07c0000) at src/hotspot/share/prims/jvmtiEnv.cpp:3324
#5  0x00007ffff49c4a7b in debugMonitorEnter (monitor=0x7ffff07c0000) at src/jdk.jdwp.agent/share/native/libjdwp/util.c:1043
#6  0x00007ffff49a9758 in cbTrackingObjectFree (jvmti_env=<optimized out>, tag=140729502422448) at src/jdk.jdwp.agent/share/native/libjdwp/classTrack.c:67
#7  0x00007ffff667fe1d in JvmtiExport::post_object_free (env=0x7ffff07c00f0, tag=140729502422448) at src/hotspot/share/prims/jvmtiExport.cpp:1470
#8  0x00007ffff66a098c in JvmtiTagMap::do_weak_oops (this=0x7ffff07c1940, is_alive=is_alive@entry=0x7fffb4377380, f=f@entry=0x7ffff7182150 <do_nothing_cl>) at src/hotspot/share/prims/jvmtiTagMap.cpp:3377
#9  0x00007ffff66a0ac5 in JvmtiTagMap::weak_oops_do (is_alive=is_alive@entry=0x7fffb4377380, f=f@entry=0x7ffff7182150 <do_nothing_cl>) at src/hotspot/share/prims/jvmtiTagMap.cpp:3325
#10 0x00007ffff667eeca in JvmtiExport::weak_oops_do (is_alive=is_alive@entry=0x7fffb4377380, f=f@entry=0x7ffff7182150 <do_nothing_cl>) at src/hotspot/share/prims/jvmtiExport.cpp:2590
#11 0x00007ffff6b44d11 in WeakProcessor::weak_oops_do (is_alive=is_alive@entry=0x7fffb4377380, keep_alive=0x7ffff7182150 <do_nothing_cl>) at src/hotspot/share/gc/shared/weakProcessor.cpp:38
#12 0x00007ffff640e9a3 in G1ConcurrentMark::weak_refs_work (this=this@entry=0x7ffff00708f0, clear_all_soft_refs=clear_all_soft_refs@entry=false) at src/hotspot/share/gc/g1/g1ConcurrentMark.cpp:1674
#13 0x00007ffff640fc59 in G1ConcurrentMark::remark (this=0x7ffff00708f0) at src/hotspot/share/gc/g1/g1ConcurrentMark.cpp:1163
#14 0x00007ffff6b36136 in VM_CGC_Operation::doit (this=0x7fffd4d3bdb0) at src/hotspot/share/gc/g1/vm_operations_g1.cpp:210
#15 0x00007ffff6b2dea0 in VM_Operation::evaluate (this=this@entry=0x7fffd4d3bdb0) at src/hotspot/share/runtime/vmOperations.cpp:67
#16 0x00007ffff6b33d3f in VMThread::evaluate_operation (this=this@entry=0x7ffff0755800, op=0x7fffd4d3bdb0) at src/hotspot/share/runtime/vmThread.cpp:413
#17 0x00007ffff6b341be in VMThread::loop (this=this@entry=0x7ffff0755800) at src/hotspot/share/runtime/vmThread.cpp:548
#18 0x00007ffff6b3472c in VMThread::run (this=0x7ffff0755800) at src/hotspot/share/runtime/vmThread.cpp:310
#19 0x00007ffff6abefea in Thread::call_run (this=0x7ffff0755800) at src/hotspot/share/runtime/thread.cpp:380
#20 0x00007ffff6883a48 in thread_native_entry (thread=0x7ffff0755800) at src/hotspot/os/linux/os_linux.cpp:784
#21 0x00007ffff79b0ea5 in start_thread (arg=0x7fffb4378700) at pthread_create.c:307
#22 0x00007ffff72c496d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 4 (Thread 0x7ffed41e3700 (LWP 72615)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007ffff688d3e3 in os::PlatformEvent::park (this=0x7ffe34013b00) at src/hotspot/os/posix/os_posix.cpp:2003
#2  0x00007ffff6835008 in ParkCommon (timo=0, ev=0x7ffe34013b00) at src/hotspot/share/runtime/mutex.cpp:404
#3  Monitor::ILock (this=this@entry=0x7ffff00159c0, Self=Self@entry=0x7ffef4036000) at src/hotspot/share/runtime/mutex.cpp:466
#4  0x00007ffff6835a48 in lock_without_safepoint_check (Self=0x7ffef4036000, this=0x7ffff00159c0) at src/hotspot/share/runtime/mutex.cpp:938
#5  Monitor::lock_without_safepoint_check (this=0x7ffff00159c0) at src/hotspot/share/runtime/mutex.cpp:944
#6  0x00007ffff6937d4d in SafepointSynchronize::block (thread=0x7ffef4036000) at src/hotspot/share/runtime/safepoint.cpp:910
#7  0x00007ffff6ab9e8e in block_if_requested_local_poll (thread=0x7ffef4036000) at src/hotspot/share/runtime/safepointMechanism.inline.hpp:63
#8  block_if_requested (thread=0x7ffef4036000) at src/hotspot/share/runtime/safepointMechanism.inline.hpp:73
#9  JavaThread::check_safepoint_and_suspend_for_native_trans (thread=thread@entry=0x7ffef4036000) at src/hotspot/share/runtime/thread.cpp:2505
#10 0x00007ffff6612d1d in ThreadStateTransition::transition_from_native (thread=thread@entry=0x7ffef4036000, to=_thread_in_vm) at src/hotspot/share/runtime/interfaceSupport.inline.hpp:168
#11 0x00007ffff66217b0 in trans_from_native (to=_thread_in_vm, this=0x7ffed41e1560) at src/hotspot/share/runtime/interfaceSupport.inline.hpp:179
#12 ThreadInVMfromNative (thread=0x7ffef4036000, this=0x7ffed41e1560) at src/hotspot/share/runtime/interfaceSupport.inline.hpp:267
#13 jvmti_Allocate (env=0x7ffff000bd70, size=24, mem_ptr=0x7ffed41e15c0, this=<optimized out>) at build/hotspot/variant-server/gensrc/jvmtifiles/jvmtiEnter.cpp:336
#14 0x00007ffff49c6786 in jvmtiAllocate (numBytes=numBytes@entry=24) at src/jdk.jdwp.agent/share/native/libjdwp/util.c:1808
#15 0x00007ffff49a92ad in bagCreateBag (itemSize=itemSize@entry=8, initialAllocation=initialAllocation@entry=10) at src/jdk.jdwp.agent/share/native/libjdwp/bag.c:40
#16 0x00007ffff49a97b0 in classTrack_processUnloads (env=env@entry=0x7ffef4036348) at src/jdk.jdwp.agent/share/native/libjdwp/classTrack.c:91
#17 0x00007ffff49b1253 in event_callback (env=env@entry=0x7ffef4036348, evinfo=evinfo@entry=0x7ffed41e1700) at src/jdk.jdwp.agent/share/native/libjdwp/eventHandler.c:583
#18 0x00007ffff49b215e in cbClassPrepare (jvmti_env=<optimized out>, env=0x7ffef4036348, thread=0x7ffee00010d0, klass=0x7ffee00010d8) at src/jdk.jdwp.agent/share/native/libjdwp/eventHandler.c:892
#19 0x00007ffff6681094 in JvmtiExport::post_class_prepare (thread=0x7ffef4036000, klass=0x840362840) at src/hotspot/share/prims/jvmtiExport.cpp:1337
#20 0x00007ffff64cf5c8 in InstanceKlass::link_class_impl (this=0x840362840, throw_verifyerror=<optimized out>, __the_thread__=0x7ffef4036000) at src/hotspot/share/oops/instanceKlass.cpp:838
#21 0x00007ffff64cf14e in InstanceKlass::link_class_impl (this=0x840355040, throw_verifyerror=throw_verifyerror@entry=true, __the_thread__=__the_thread__@entry=0x7ffef4036000) at src/hotspot/share/oops/instanceKlass.cpp:753
#22 0x00007ffff64cf5ee in InstanceKlass::link_class (this=this@entry=0x840355040, __the_thread__=__the_thread__@entry=0x7ffef4036000) at src/hotspot/share/oops/instanceKlass.cpp:697
#23 0x00007ffff65b16a9 in get_class_declared_methods_helper (env=env@entry=0x7ffef4036348, ofClass=ofClass@entry=0x7ffed41e1d10, publicOnly=publicOnly@entry=1 '\001', want_constructor=want_constructor@entry=true, klass=0x8002b7898, __the_thread__=__the_thread__@entry=0x7ffef4036000) at src/hotspot/share/prims/jvm.cpp:1814
#24 0x00007ffff65b1cb9 in JVM_GetClassDeclaredConstructors (env=0x7ffef4036348, ofClass=0x7ffed41e1d10, publicOnly=<optimized out>) at src/hotspot/share/prims/jvm.cpp:1878
#25 0x00007fffdfaff4fb in ?? ()
#26 0x0000000508398330 in ?? ()
#27 0x00007ffff62a3823 in CollectedHeap::array_allocate (this=<optimized out>, klass=<optimized out>, size=<optimized out>, length=<optimized out>, do_zero=<optimized out>, __the_thread__=<optimized out>) at src/hotspot/share/gc/shared/collectedHeap.cpp:457
#28 0x00007fffd81b5edc in ?? ()
#29 0x00007ffed41e1ec0 in ?? ()
#30 0x00007ffff64d80eb in InstanceKlass::allocate_objArray (this=<optimized out>, n=<optimized out>, length=0, __the_thread__=0x7ffef4036000) at src/hotspot/share/oops/instanceKlass.cpp:1221
#31 0x00007fffd769dda8 in ?? ()
#32 0x0000000000000000 in ?? ()

It seems Thread 88 is in GC, at a safepoint (looking at the start of G1ConcurrentMark::remark() body). Its waiting on Thread 4, due to Thread 4 holding a lock while calling classTrack_processUnloads(). Thread 4 seems to wait on a safepoint.

Unfortunately we have limited understanding of safepoints so we are not 100% this is the full set of threads involved in the deadlock. Maybe the deadlock is more complicated.

Version-Release number of selected component (if applicable):

openjdk version "11.0.10" 2021-01-19 LTS
OpenJDK Runtime Environment 18.9 (build 11.0.10+9-LTS)
OpenJDK 64-Bit Server VM 18.9 (build 11.0.10+9-LTS, mixed mode, sharing)

How reproducible:

We have to reproduction steps, the hang was seen during our ARTs. Eclipse itself is hanging and then timing out in various JDI operations:

!ENTRY org.eclipse.jdt.debug 4 125 2022-02-05 05:34:25.103
!MESSAGE Internal error logged from JDI Debug: 
!STACK 0
org.eclipse.jdi.TimeoutException: Timeout occurred while waiting for packet 21676.
	at org.eclipse.jdi.internal.connect.PacketReceiveManager.getReply(PacketReceiveManager.java:196)
	at org.eclipse.jdi.internal.connect.PacketReceiveManager.getReply(PacketReceiveManager.java:207)
	at org.eclipse.jdi.internal.MirrorImpl.requestVM(MirrorImpl.java:195)
	at org.eclipse.jdi.internal.MirrorImpl.requestVM(MirrorImpl.java:230)
	at org.eclipse.jdi.internal.request.EventRequestImpl.enable(EventRequestImpl.java:261)
	at org.eclipse.jdt.internal.debug.core.model.JDIDebugTarget.createClassPrepareRequest(JDIDebugTarget.java:1282)
	at org.eclipse.jdt.internal.debug.core.model.JDIDebugTarget.createClassPrepareRequest(JDIDebugTarget.java:1230)
	at org.eclipse.jdt.internal.debug.core.model.JDIDebugTarget.createClassPrepareRequest(JDIDebugTarget.java:1203)
	at org.eclipse.jdt.internal.debug.core.model.JDIDebugTarget.createClassPrepareRequest(JDIDebugTarget.java:1180)
	at org.eclipse.jdt.internal.debug.core.breakpoints.JavaBreakpoint.createRequests(JavaBreakpoint.java:633)
	at org.eclipse.jdt.internal.debug.core.breakpoints.JavaBreakpoint.addToTarget(JavaBreakpoint.java:615)
	at org.eclipse.jdt.internal.debug.core.model.JDIDebugTarget.breakpointAdded(JDIDebugTarget.java:1616)
	at com.advantest.itee.jtm.debugger.core.JtmDebugTarget.breakpointAdded(JtmDebugTarget.java:554)
	at org.eclipse.jdt.internal.debug.ui.JavaDebugOptionsManager.notifyTarget(JavaDebugOptionsManager.java:320)
	at org.eclipse.jdt.internal.debug.ui.JavaDebugOptionsManager.handleDebugEvents(JavaDebugOptionsManager.java:533)
	at org.eclipse.debug.core.DebugPlugin$EventNotifier.run(DebugPlugin.java:1214)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
	at org.eclipse.debug.core.DebugPlugin$EventNotifier.dispatch(DebugPlugin.java:1248)
	at org.eclipse.debug.core.DebugPlugin$EventDispatchJob.run(DebugPlugin.java:480)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)


"Worker-17: Label Job" #104 prio=5 os_prio=0 cpu=1068.44ms elapsed=2017.66s tid=0x0000555559d88000 nid=0x5522 in Object.wait()  [0x00007fff43c33000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(java.base.10/Native Method)
	- waiting on <no object reference available>
	at org.eclipse.jdi.internal.connect.PacketReceiveManager.waitForPacketAvailable(PacketReceiveManager.java:220)
	at org.eclipse.jdi.internal.connect.PacketReceiveManager.getReply(PacketReceiveManager.java:165)
	- waiting to re-lock in wait() <0x000000101d070590> (a java.util.LinkedList)
	at org.eclipse.jdi.internal.connect.PacketReceiveManager.getReply(PacketReceiveManager.java:207)
	at org.eclipse.jdi.internal.MirrorImpl.requestVM(MirrorImpl.java:195)
	at org.eclipse.jdi.internal.MirrorImpl.requestVM(MirrorImpl.java:230)
	at org.eclipse.jdi.internal.MirrorImpl.requestVM(MirrorImpl.java:246)
	at org.eclipse.jdi.internal.ThreadReferenceImpl.name(ThreadReferenceImpl.java:359)
	at org.eclipse.jdt.internal.debug.core.model.JDIThread.getName(JDIThread.java:1274)
	at org.eclipse.jdt.internal.debug.ui.JDIModelPresentation.getThreadText(JDIModelPresentation.java:344)
	at org.eclipse.jdt.internal.debug.ui.JDIModelPresentation.getText(JDIModelPresentation.java:258)
	at org.eclipse.debug.internal.ui.LazyModelPresentation.getText(LazyModelPresentation.java:188)
	at org.eclipse.debug.internal.ui.DelegatingModelPresentation.getText(DelegatingModelPresentation.java:151)
	at org.eclipse.debug.internal.ui.model.elements.DebugElementLabelProvider.getLabel(DebugElementLabelProvider.java:39)
	at org.eclipse.debug.internal.ui.model.elements.ElementLabelProvider.getLabel(ElementLabelProvider.java:297)
	at org.eclipse.debug.internal.ui.model.elements.ElementLabelProvider.retrieveLabel(ElementLabelProvider.java:200)
	at org.eclipse.debug.internal.ui.model.elements.ElementLabelProvider$LabelUpdater.run(ElementLabelProvider.java:147)
	at org.eclipse.debug.internal.ui.model.elements.ElementLabelProvider$LabelJob.run(ElementLabelProvider.java:74)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)


"Worker-5: Debug Event Dispatch" #91 prio=5 os_prio=0 cpu=1527.02ms elapsed=2017.68s tid=0x0000555558730800 nid=0x550d in Object.wait()  [0x00007fff47d40000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(java.base.10/Native Method)
	- waiting on <no object reference available>
	at org.eclipse.jdi.internal.connect.PacketReceiveManager.waitForPacketAvailable(PacketReceiveManager.java:220)
	at org.eclipse.jdi.internal.connect.PacketReceiveManager.getReply(PacketReceiveManager.java:165)
	- waiting to re-lock in wait() <0x000000101d070590> (a java.util.LinkedList)
	at org.eclipse.jdi.internal.connect.PacketReceiveManager.getReply(PacketReceiveManager.java:207)
	at org.eclipse.jdi.internal.MirrorImpl.requestVM(MirrorImpl.java:195)
	at org.eclipse.jdi.internal.MirrorImpl.requestVM(MirrorImpl.java:230)
	at org.eclipse.jdi.internal.MirrorImpl.requestVM(MirrorImpl.java:246)
	at org.eclipse.jdi.internal.ThreadReferenceImpl.currentContendedMonitor(ThreadReferenceImpl.java:123)
	at org.eclipse.jdt.internal.debug.core.model.JDIThread.getContendedMonitor(JDIThread.java:3366)
	at org.eclipse.jdt.internal.debug.ui.monitors.JavaMonitorThread.update(JavaMonitorThread.java:179)
	- locked <0x00000010feadd038> (a org.eclipse.jdt.internal.debug.ui.monitors.JavaMonitorThread)
	at org.eclipse.jdt.internal.debug.ui.monitors.JavaMonitorThread.getContendedMonitor0(JavaMonitorThread.java:151)
	at org.eclipse.jdt.internal.debug.ui.monitors.ThreadMonitorManager$DetectDeadlock.run(ThreadMonitorManager.java:254)
	at org.eclipse.debug.core.DebugPlugin$AsynchRunner.run(DebugPlugin.java:1175)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
	at org.eclipse.debug.core.DebugPlugin$AsynchRunner.async(DebugPlugin.java:1162)
	at org.eclipse.debug.core.DebugPlugin$EventDispatchJob.run(DebugPlugin.java:478)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)


(there are more JDI operations that were hanging and eventually timed out)




Actual results:

JDK hangs in native code.

Expected results:

We expect no hang in JDK native code.

Additional info:

See stack traces above.