On Tue, 12 Jul 2022 01:44:28 GMT, Zhengyu Gu <z...@openjdk.org> wrote:
>> Currently, jdi only check and process class unloading event when it detects >> a new GC cycle. >> >> After [JDK-8212879](https://bugs.openjdk.org/browse/JDK-8212879), posting >> class events can overlap with GC finish event, that results, sometimes, it >> only captures partial or even empty unloaded class list. The pending list >> usually can be flushed out at next GC cycle. But for the classes unloaded >> during the last GC cycle, the class unloading events may lost forever. >> >> This patch checks and processes class unloading events unconditionally, >> suggested by @kbarrett, the last pending unloaded class list can be flushed >> by other events, such as `VM_DEATH`. >> >> It also performs `commonRef_compact()` only when there are classes unloaded. >> >> New test failed about 20% without patch, none with patch. >> >> **Update** >> There are significant changes from early patch. >> >> The new approach: >> No longer removing dead objects and post events on VM thread. I believe it >> was implemented this way to workaround the following issues: >> - JDI event handler uses JVMTI raw monitor, it requires thread in >> `_in_native` state >> - The thread can not hold lock, which is needed to protect `JvmtiTagMap` >> while walking, when transition to `_in_native` state >> >> The new solution breaks up into two steps: >> - Collect all dead object tags with lock >> - Transition to `_in_native` state and post object free events in one batch >> >> This way, JDI event handler can process object free events upon arrivals >> without delay. >> >> **Update 2** >> There is a comment for ` JvmtiTagMap::check_hashmap()` that states >> `ObjectFree` events are posted before heap walks. >> >> // This checks for posting and rehashing before operations that >> // this tagmap table. The calls from a JavaThread only rehash, posting is >> // only done before heap walks. >> void JvmtiTagMap::check_hashmap(bool post_events) { >> >> Now, the events are actually posted after heap walks, but I don't think it >> makes any material material difference. >> Even the events are posted earlier in old code, but they are only processed >> after next GC cycle. > > Zhengyu Gu has updated the pull request incrementally with one additional > commit since the last revision: > > Rename test It seems during test shutdown, ObjectFree events are being delivered after JVMTI events have been disabled: nsk_jvmti_enableEvents(JVMTI_DISABLE, eventsCount, events, NULL); NSK_TRACE(jni->DeleteGlobalRef(debugeeClass)); NSK_TRACE(jvmti->DestroyRawMonitor(counterMonitor_ptr)); NSK_DISPLAY0("Let debugee to finish\n"); The first line is disabling events. A couple statements later the monitor is freed. After that a printf that we are seeing in the output. After the printf the ObjectFree events arrives and we try to use the freed monitor. Here's the stack trace when the event arrives (I got this by inserting an assert(0)): #4 0x00007f451f6752af in increaseCounter (counterPtr=0x7f451f699ad8 <eventCount>) at /opt/mach5/mesos/work_dir/slaves/0c72054a-24ab-4dbb-944f-97f9341a1b96-S8484/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/fa6bd5a2-99f3-402f-b5bb-613077cc393c/runs/f384ea29-cdca-4da9-887c-7f0c9eff2c41/workspace/open/test/hotspot/jtreg/vmTestbase/nsk/share/native/JVMTITools.cpp:71 #5 0x00007f451dc10f13 in JvmtiExport::post_object_free(JvmtiEnv*, GrowableArray<long>*) () from /opt/mach5/mesos/work_dir/jib-master/install/2022-07-12-0516516.chris.plummer.zhengyu/linux-x64-debug.jdk/jdk-20/fastdebug/lib/server/libjvm.so #6 0x00007f451dc4772d in JvmtiTagMap::post_dead_objects(GrowableArray<long>*) () from /opt/mach5/mesos/work_dir/jib-master/install/2022-07-12-0516516.chris.plummer.zhengyu/linux-x64-debug.jdk/jdk-20/fastdebug/lib/server/libjvm.so #7 0x00007f451dc4804a in JvmtiTagMap::remove_and_post_dead_objects() () from /opt/mach5/mesos/work_dir/jib-master/install/2022-07-12-0516516.chris.plummer.zhengyu/linux-x64-debug.jdk/jdk-20/fastdebug/lib/server/libjvm.so #8 0x00007f451dc48615 in JvmtiTagMap::flush_all_object_free_events() () from /opt/mach5/mesos/work_dir/jib-master/install/2022-07-12-0516516.chris.plummer.zhengyu/linux-x64-debug.jdk/jdk-20/fastdebug/lib/server/libjvm.so #9 0x00007f451e15ed93 in ServiceThread::service_thread_entry(JavaThread*, JavaThread*) () from /opt/mach5/mesos/work_dir/jib-master/install/2022-07-12-0516516.chris.plummer.zhengyu/linux-x64-debug.jdk/jdk-20/fastdebug/lib/server/libjvm.so #10 0x00007f451d8ff948 in JavaThread::thread_main_inner() () from /opt/mach5/mesos/work_dir/jib-master/install/2022-07-12-0516516.chris.plummer.zhengyu/linux-x64-debug.jdk/jdk-20/fastdebug/lib/server/libjvm.so #11 0x00007f451e31ec20 in Thread::call_run() () from /opt/mach5/mesos/work_dir/jib-master/install/2022-07-12-0516516.chris.plummer.zhengyu/linux-x64-debug.jdk/jdk-20/fastdebug/lib/server/libjvm.so #12 0x00007f451dfe1ef4 in thread_native_entry(Thread*) () from /opt/mach5/mesos/work_dir/jib-master/install/2022-07-12-0516516.chris.plummer.zhengyu/linux-x64-debug.jdk/jdk-20/fastdebug/lib/server/libjvm.so #13 0x00007f451f17d1df in start_thread () from /lib64/libpthread.so.0 #14 0x00007f451ebe5dd3 in clone () from /lib64/libc.so.6 It's a little misleading because of some inlining. Here's the actual ObjectFree callback: void JNICALL ObjectFree(jvmtiEnv *jvmti_env, jlong tag) { increaseCounter(&eventCount); // NSK_DISPLAY0(" event: ObjectFree\n"); } I'm a bit less sure now that this is a test bug. I wonder if some JVMTI synchronization is now being bypassed that would normally have blocked the test when it tried to disable events, and not allow the disabling until the ObjectFree events had all finished being posted. ------------- PR: https://git.openjdk.org/jdk/pull/9168
