JDK-8371103 : vmTestbase/nsk/jvmti/scenarios/events/EM02/em02t006/TestDescription.java failing
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jvmti
  • Affected Version: 26
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2025-11-02
  • Updated: 2025-11-08
  • Resolved: 2025-11-08
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 26
26 masterFixed
Related Reports
Causes :  
JDK-8212879 - Make JVMTI TagMap table concurrent
Relates :  
JDK-8370732 - Use WhiteBox.getWhiteBox().fullGC() to provoking gc for nsk/jvmti tests
Sub Tasks
JDK-8371114 :  
Problemlist vmTestbase/nsk/jvmti/scenarios/events/EM02/em02t006/TestDescription.java - Resolved
Description
This test appears to be failing since JDK-8370732.

#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (/System/Volumes/Data/mesos/work_dir/slaves/526fbd26-20de-495c-9a19-a04adc16f7d1-S23856/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/b2f6dc6f-febe-439d-8ace-c5e52cb44044/runs/a0fc9155-3bef-4f7f-bcd6-8075dbe18a0d/workspace/open/src/hotspot/share/runtime/interfaceSupport.inline.hpp:187), pid=6409, tid=33539
#  assert(!thread->owns_locks()) failed: must release all locks when leaving VM
#
# JRE version: Java(TM) SE Runtime Environment (26.0+23) (fastdebug build 26-ea+23-2299)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 26-ea+23-2299, mixed mode, tiered, compressed oops, compressed class ptrs, g1 gc, bsd-aarch64)
# Core dump will be written. Default location: core.6409
#
# If you would like to submit a bug report, please visit:
#   https://bugreport.java.com/bugreport/crash.jsp
#

Current thread (0x0000000141015e10):  JavaThread "JVMTI agent thread" daemon [_thread_in_vm, id=33539, stack(0x000000016e1c0000,0x000000016e3c3000) (2060K)]

Stack: [0x000000016e1c0000,0x000000016e3c3000],  sp=0x000000016e3c26d0,  free space=2057k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.dylib+0x123dea8]  VMError::report(outputStream*, bool)+0x1b68  (interfaceSupport.inline.hpp:187)
V  [libjvm.dylib+0x12417a4]  VMError::report_and_die(int, char const*, char const*, char*, Thread*, unsigned char*, void const*, void const*, char const*, int, unsigned long)+0x55c
V  [libjvm.dylib+0x5bad40]  print_error_for_unit_test(char const*, char const*, char*)+0x0
V  [libjvm.dylib+0x4ac340]  GrowableArray<ModuleClassPathList*>::GrowableArray(int, MemTag)+0x0
V  [libjvm.dylib+0xc30218]  JvmtiExport::post_object_free(JvmtiEnv*, GrowableArray<long>*)+0x2a0
V  [libjvm.dylib+0xc57c64]  JvmtiTagMap::remove_and_post_dead_objects()+0x140
V  [libjvm.dylib+0xc57e90]  JvmtiTagMap::flush_object_free_events()+0x100
V  [libjvm.dylib+0xc256a0]  JvmtiEventControllerPrivate::set_event_callbacks(JvmtiEnvBase*, jvmtiEventCallbacks const*, int)+0x158
V  [libjvm.dylib+0xc2749c]  JvmtiEventController::set_event_callbacks(JvmtiEnvBase*, jvmtiEventCallbacks const*, int)+0x54
V  [libjvm.dylib+0xc01d48]  JvmtiEnv::SetEventCallbacks(jvmtiEventCallbacks const*, int)+0x4c
V  [libjvm.dylib+0xbb4d70]  jvmti_SetEventCallbacks(_jvmtiEnv*, jvmtiEventCallbacks const*, int)+0x150
C  [libem02t006.dylib+0xb434]  setCallBacks(int)+0x204
C  [libem02t006.dylib+0xb520]  agentProc(_jvmtiEnv*, JNIEnv_*, void*)+0xb0
C  [libem02t006.dylib+0xb754]  agentThreadWrapper(_jvmtiEnv*, JNIEnv_*, void*)+0x1c0
V  [libjvm.dylib+0xc3f8c8]  JvmtiAgentThread::start_function_wrapper(JavaThread*, JavaThread*)+0x88
V  [libjvm.dylib+0x922828]  JavaThread::thread_main_inner()+0x1d0
V  [libjvm.dylib+0x117de1c]  Thread::call_run()+0xf0
V  [libjvm.dylib+0xedae7c]  thread_native_entry(Thread*)+0x138
C  [libsystem_pthread.dylib+0x6bc8]  _pthread_start+0x88
Lock stack of current Java thread (top to bottom):
Comments
Changeset: 88c4678e Branch: master Author: Leonid Mesnik <lmesnik@openjdk.org> Date: 2025-11-08 21:30:58 +0000 URL: https://git.openjdk.org/jdk/commit/88c4678eed818cbe9380f35352e90883fed27d33
08-11-2025
A pull request was submitted for review. Branch: master URL: https://git.openjdk.org/jdk/pull/28184 Date: 2025-11-06 21:26:24 +0000
06-11-2025
> Yes, the daemon thread might be never exiting callback, so we could wait it forever. This is why there is timeout here Let's discuss this outside of this Bug.
04-11-2025
Yes it is intermittent. > We observed the same on AIX and Windows. In the meantime 2 errors on linux aarch64 occurred too.
04-11-2025
Seems like it's intermittent fails on linux-x64 and linux-aarch64.
04-11-2025
[~stefank] Thank you for your feedback about VM Death, we could discuss it separately. Just on reply right now: >>>The thread can now send events even when _execution_finished == true >> 2) It is highly dubious to have a *time limited* sleep instead of proper synchronization. Unless I'm mistaken this means that there's a scenario where A JVMTI event can be sent after this function exits. Yes, the daemon thread might be never exiting callback, so we could wait it forever. This is why there is timeout here
03-11-2025
I think that test update in 8370732: Use WhiteBox.getWhiteBox().fullGC() to provoking gc for nsk/jvmti tests start triggering GC much earlier. So we have some events to flush now. The failure log shows that test is still in progress. So it is not related with VM Death event "MainThread" #23 prio=5 tid=0x0000000140868c10 nid=27139 runnable [0x0000000170352000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked - nsk.share.jvmti.DebugeeClass.checkStatus(int) @bci=0 (Interpreted frame) - locked <0x00000007c0058d38> (a java.lang.Class for nsk.share.jvmti.DebugeeClass) - nsk.jvmti.scenarios.events.EM02.em02t006.runIt(java.lang.String[], java.io.PrintStream) @bci=92, line=68 (Interpreted frame) - nsk.jvmti.scenarios.events.EM02.em02t006.run(java.lang.String[], java.io.PrintStream) @bci=9, line=44 (Interpreted frame) - nsk.jvmti.scenarios.events.EM02.em02t006.main(java.lang.String[]) @bci=9, line=39 (Interpreted frame) - java.lang.invoke.LambdaForm$DMH+0x00007c0000081800.invokeStatic(java.lang.Object, java.lang.Object) @bci=10 (Interpreted frame) - java.lang.invoke.LambdaForm$MH+0x00007c0000082c00.invoke(java.lang.Object, java.lang.Object, java.lang.Object) @bci=33 (Interpreted frame) - java.lang.invoke.Invokers$Holder.invokeExact_MT(java.lang.Object, java.lang.Object, java.lang.Object, java.lang.Object) @bci=20 (Interpreted frame) - jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(java.lang.Object, java.lang.Object[]) @bci=55, line=155 (Interpreted frame) - jdk.internal.reflect.DirectMethodHandleAccessor.invoke(java.lang.Object, java.lang.Object[]) @bci=23, line=104 (Interpreted frame) - java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object[]) @bci=102, line=565 (Interpreted frame) - com.sun.javatest.regtest.agent.MainWrapper$MainTask.run() @bci=134, line=138 (Interpreted frame) - java.lang.Thread.runWith(java.lang.Object, java.lang.Runnable) @bci=5, line=1487 (Interpreted frame) - java.lang.Thread.run() @bci=19, line=1474 (Interpreted frame) "JVMTI agent thread" #27 daemon prio=10 tid=0x000000012701ec10 nid=33283 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_in_vm
03-11-2025
Do you have any ideas why this has started to fail now? I'm wondering if this has to do with the recent change with: 8355631: The events might be generated after VM_DEATH event That change added this macro: ``` +#define JVMTI_JAVA_THREAD_EVENT_CALLBACK_BLOCK(thread) \ + JvmtiJavaThreadEventTransition jet(thread); \ + if (JvmtiEventController::is_execution_finished()) {\ + return; \ + } ``` and replaced almost all usages of JvmtiJavaThreadEventTransition. Except, it didn't replace the usage in post_object_free. I don't know if this triggers this problem. With that said, me and Axel looked at the newly added code to prevent events from being sent after VMDeath. It seems to have a couple synchronization issues that needs to be dealt with: 1) The usage of JvmtiJavaThreadEventTransition in post_object_free will cause callers to not properly synchronized with vm_death() see: void JvmtiEventController::vm_death() { // No new event callbacks except vm_death can be called after this point. AtomicAccess::store(&_execution_finished, true); if (JvmtiEnvBase::environments_might_exist()) { MutexLocker mu(JvmtiThreadState_lock); JvmtiEventControllerPrivate::vm_death(); } // Some events might be still in callback for daemons and VM internal threads. const double start = os::elapsedTime(); const double max_wait_time = 60; // The first time we see the callback count reach zero we know all actual // callbacks are complete. The count could rise again, but those "callbacks" // will immediately see `execution_finished()` and return (dropping the count). while (in_callback_count() > 0) { os::naked_short_sleep(100); if (os::elapsedTime() - start > max_wait_time) { break; } } } The thread can now send events even when _execution_finished == true 2) It is highly dubious to have a *time limited* sleep instead of proper synchronization. Unless I'm mistaken this means that there's a scenario where A JVMTI event can be sent after this function exits. FWIW, I'm currently working away two other such dubious cases in our shutdown code and this is the third one I see. 3) It could be worth noting that we first thought that the relaxed accesses to _execution_finished and in_callback_count() could be reordered. But, if IIUC we will take a lock if environments_might_exist returns true, and that will add the required memory barriers. That's a bit subtle and should be documented.
03-11-2025
We observed the same on AIX and Windows. AIX : # Internal Error (/priv/jenkins/ci2/client-home/workspace/openjdk-jdk-dev-aix_ppc64-dbg/jdk/src/hotspot/share/runtime/interfaceSupport.inline.hpp:187), pid=7405900, tid=6426 # assert(!thread->owns_locks()) failed: must release all locks when leaving VM Stack: [0x0000000117ac0000,0x0000000117ccd888], sp=0x0000000117ccc760, free space=2097k No context given, using current context. Native frame: iar: 0x090000001f08aeac libjvm.so::AixNativeCallstack::print_callstack_for_context(outputStream*, ucontext_t const*, bool, char*, unsigned long)+0x4ec (C++ uses_alloca saves_cr saves_lr stores_bc gpr_saved:18 fixedparms:5 parmsonstk:1) lr: 0x090000001ee274dc libjvm.so::CompressedOops::decode_not_null(narrowOop)+0xbc (C++ uses_alloca saves_lr stores_bc gpr_saved:2 fixedparms:1 parmsonstk:1) sp: 0x0000000117ccb700 (base - 0x2188) rtoc: 0x08001000a0472838 |---stackaddr----| |----lrsave------|: <function name> 0x0000000117ccbaf0 - 0x090000001f08a944 libjvm.so::os::Aix::platform_print_native_stack(outputStream*, void const*, char*, int, unsigned char*&)+0x24 (C++ uses_alloca saves_lr stores_bc gpr_saved:1 fixedparms:5 parmsonstk:1) 0x0000000117ccbb70 - 0x090000001f08a7f8 libjvm.so::NativeStackPrinter::print_stack(outputStream*, char*, int, unsigned char*&, bool, int)+0x58 (C++ fp_present uses_alloca saves_cr saves_lr stores_bc gpr_saved:6 fixedparms:7 parmsonstk:1) 0x0000000117ccbc80 - 0x090000001f82a1f8 libjvm.so::VMError::report(outputStream*, bool)+0x23b8 (C++ fp_present uses_alloca saves_cr saves_lr stores_bc gpr_saved:18 fixedparms:2 parmsonstk:1) 0x0000000117ccc770 - 0x090000001ee09e1c libjvm.so::VMError::report_and_die(int, char const*, char const*, char*, Thread*, unsigned char*, void const*, void const*, char const*, int, unsigned long)+0x85c (C++ uses_alloca saves_lr stores_bc gpr_saved:18 fixedparms:8 parmsonstk:1) 0x0000000117ccc940 - 0x090000001ee092e0 libjvm.so::report_vm_error(char const*, int, char const*, char const*, ...)+0xa0 (C++ uses_alloca saves_lr stores_bc gpr_saved:5 fixedparms:4 parmsonstk:1) 0x0000000117ccca00 - 0x090000001eec9334 libjvm.so::ThreadToNativeFromVM::ThreadToNativeFromVM(JavaThread*)+0x114 (C++ uses_alloca saves_lr stores_bc gpr_saved:1 fixedparms:2 parmsonstk:1) 0x0000000117ccca80 - 0x090000001f05a62c libjvm.so::JvmtiExport::post_object_free(JvmtiEnv*, GrowableArray<long>*)+0x38c (C++ uses_alloca saves_lr stores_bc gpr_saved:10 fixedparms:2 parmsonstk:1) 0x0000000117cccbd0 - 0x090000001f05a0dc libjvm.so::JvmtiTagMap::remove_and_post_dead_objects()+0x17c (C++ fp_present uses_alloca saves_lr stores_bc gpr_saved:7 fixedparms:1 parmsonstk:1) 0x0000000117ccccf0 - 0x090000001f059730 libjvm.so::JvmtiTagMap::flush_object_free_events()+0x150 (C++ uses_alloca saves_lr stores_bc gpr_saved:5 fixedparms:1 parmsonstk:1) 0x0000000117cccd90 - 0x090000001f23c098 libjvm.so::JvmtiEventControllerPrivate::set_event_callbacks(JvmtiEnvBase*, jvmtiEventCallbacks const*, int)+0x198 (C++ uses_alloca saves_lr stores_bc gpr_saved:6 fixedparms:3 parmsonstk:1) 0x0000000117ccce70 - 0x090000001f23bdf4 libjvm.so::JvmtiEventController::set_event_callbacks(JvmtiEnvBase*, jvmtiEventCallbacks const*, int)+0x74 (C++ uses_alloca saves_lr stores_bc gpr_saved:5 fixedparms:3 parmsonstk:1) 0x0000000117cccf10 - 0x090000001f23bcf4 libjvm.so::JvmtiEnv::SetEventCallbacks(jvmtiEventCallbacks const*, int)+0x54 (C++ uses_alloca saves_lr stores_bc gpr_saved:5 fixedparms:3 parmsonstk:1) 0x0000000117cccfd0 - 0x090000001f27b960 libjvm.so::jvmti_SetEventCallbacks(_jvmtiEnv*, jvmtiEventCallbacks const*, int)+0x180 (C++ uses_alloca saves_cr saves_lr stores_bc gpr_saved:7 fixedparms:3 parmsonstk:1) 0x0000000117ccd0b0 - 0x090000002bf8fafc libem02t006.so::setCallBacks(int)+0x19c (C++ saves_lr stores_bc gpr_saved:3 fixedparms:1 parmsonstk:1) 0x0000000117ccd270 - 0x090000002bf8f550 libem02t006.so::agentProc(_jvmtiEnv*, JNIEnv_*, void*)+0xf0 (C++ saves_lr stores_bc gpr_saved:4 fixedparms:3 parmsonstk:1) 0x0000000117ccd300 - 0x090000002bf8d400 libem02t006.so::agentThreadWrapper(_jvmtiEnv*, JNIEnv_*, void*)+0x200 (C++ saves_lr stores_bc gpr_saved:9 fixedparms:3 parmsonstk:1) 0x0000000117ccd3c0 - 0x090000001f14e544 libjvm.so::JvmtiAgentThread::call_start_function()+0xa4 (C++ uses_alloca saves_lr stores_bc gpr_saved:3 fixedparms:1 parmsonstk:1) 0x0000000117ccd450 - 0x090000001f14e3b4 libjvm.so::JvmtiAgentThread::start_function_wrapper(JavaThread*, JavaThread*)+0x94 (C++ uses_alloca saves_lr stores_bc gpr_saved:3 fixedparms:2 parmsonstk:1) 0x0000000117ccd4e0 - 0x090000001f079c7c libjvm.so::JavaThread::thread_main_inner()+0x21c (C++ uses_alloca saves_lr stores_bc gpr_saved:4 fixedparms:1 parmsonstk:1) 0x0000000117ccd5b0 - 0x090000001f077c20 libjvm.so::JavaThread::run()+0x220 (C++ uses_alloca saves_lr stores_bc gpr_saved:5 fixedparms:1 parmsonstk:1) 0x0000000117ccd650 - 0x090000001eee9ca8 libjvm.so::Thread::call_run()+0x128 (C++ uses_alloca saves_lr stores_bc gpr_saved:3 fixedparms:1 parmsonstk:1) 0x0000000117ccd6e0 - 0x090000001eee8f6c libjvm.so::thread_native_entry(Thread*)+0x20c (C++ uses_alloca saves_lr stores_bc gpr_saved:8 fixedparms:1 parmsonstk:1) 0x0000000117ccd7a0 - 0x090000000056204c libpthreads.a::_pthread_body+0xec (C saves_lr stores_bc gpr_saved:1 fixedparms:1 ) 0x0000000117ccd820 - 0x0000000000000000 *** end of backchain *** ----------------------- Windows : # Internal Error (d:\priv\jenkins\ci2\client-home\workspace\openjdk-jdk-windows_x86_64-dbg\jdk\src\hotspot\share\runtime/interfaceSupport.inline.hpp:187), pid=33356, tid=18040 # assert(!thread->owns_locks()) failed: must release all locks when leaving VM Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) V [jvm.dll+0xbcf25d] JvmtiJavaThreadEventTransition::JvmtiJavaThreadEventTransition+0xed (jvmtiExport.cpp:99) V [jvm.dll+0xbda524] JvmtiExport::post_object_free+0x1c4 (jvmtiExport.cpp:1780) V [jvm.dll+0xc003da] JvmtiTagMap::remove_and_post_dead_objects+0x14a (jvmtiTagMap.cpp:1199) V [jvm.dll+0xbf8b03] JvmtiTagMap::flush_object_free_events+0xb3 (jvmtiTagMap.cpp:1222) V [jvm.dll+0xbcd921] JvmtiEventControllerPrivate::set_event_callbacks+0x151 (jvmtiEventController.cpp:798) V [jvm.dll+0xbcd76f] JvmtiEventController::set_event_callbacks+0x6f (jvmtiEventController.cpp:1112) V [jvm.dll+0xbba2c7] JvmtiEnv::SetEventCallbacks+0x47 (jvmtiEnv.cpp:566) V [jvm.dll+0xb81067] jvmti_SetEventCallbacks+0x147 (jvmtiEnter.cpp:5437) C [em02t006.dll+0x3a84] setCallBacks+0x1d4 (em02t006.cpp:429) C [em02t006.dll+0x2262] agentProc+0x5e (em02t006.cpp:455) C [em02t006.dll+0x233a] agentThreadWrapper+0xba (agent_tools.cpp:151) V [jvm.dll+0xbe201d] JvmtiAgentThread::call_start_function+0xcd (jvmtiImpl.cpp:90) V [jvm.dll+0x952744] JavaThread::thread_main_inner+0x264 (javaThread.cpp:772) V [jvm.dll+0x11d2221] Thread::call_run+0x1c1 (thread.cpp:248) V [jvm.dll+0xe4aeb4] thread_native_entry+0xc4 (os_windows.cpp:555) C [ucrtbase.dll+0x1fb80] (no source info available) C [KERNEL32.DLL+0x84d4] (no source info available) C [ntdll.dll+0x51d41] (no source info available)
03-11-2025
The root cause if the issue: https://bugs.openjdk.org/browse/JDK-8212879 The JvmtiEventControllerPrivate::flush_object_free_events(JvmtiEnvBase* env) is called from JvmtiEventControllerPrivate::set_event_callbacks() while ` MutexLocker mu(JvmtiThreadState_lock);` is held in the `JvmtiEventController::set_event_callbacks(JvmtiEnvBase *env, const jvmtiEventCallbacks* callbacks, jint size_of_callbacks)`
02-11-2025