While running com/sun/jdi tests in the loom project, I recently started to see the following assert triggered:
classTrack_addPreparedClass(JNIEnv *env_unused, jclass klass)
{
jvmtiError error;
jvmtiEnv* env = trackingEnv;
if (gdata && gdata->assertOn) {
// Check this is not already tagged.
jlong tag;
error = JVMTI_FUNC_PTR(trackingEnv, GetTag)(env, klass, &tag);
if (error != JVMTI_ERROR_NONE) {
EXIT_ERROR(error, "Unable to GetTag with class trackingEnv");
}
JDI_ASSERT(tag == NOT_TAGGED); <----------- HERE
}
Usually when it is triggered I see the following in the test output:
FATAL ERROR in native method: JDWP Assertion Failed, jvmtiError=AGENT_ERROR_INTERNAL(181)
at jdk.internal.misc.Unsafe.ensureClassInitialized0(java.base@19-loom/Native Method)
at jdk.internal.misc.Unsafe.ensureClassInitialized(java.base@19-loom/Unsafe.java:1160)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@19-loom/Reference.java:203)
With some extra debugging output I found that the class in question is java/lang/Cleaner. The assert is very rare, and pretty much only on linux-aarch64, and seems it can impact any of the com/sun/jdi tests. I think I know what's going on, but first some background.
The debug agent calls SetTag on every loaded class, setting the tag to be a pointer to the class signature. This way when the class is unloaded, an ObjectFree event is generated, which the debug agent uses to trigger the sending of a CLASS_UNLOAD to the debugger. classTrack_addPreparedClass() does this tagging, but as you can see above it first asserts that it has not been tagged already. When the debug agent is initialized, it calls JVMTI GetLoadedClasses, and for each class returned it calls classTrack_addPreparedClass(). It then sets up a ClassPrepare event callback so it can tag any additional classes that get loaded later. (There is another bug here. There could be a class loaded after the call to GetLoadedClasses and before setting up the ClassPrepare event callback. These classes will not get tagged, but that is not the cause of these com/sun/jdi failures. JDK-8282851 has been filed.).
What I think is happening is that the Cleaner class has been loaded and is available to GetLoadedClasses, but the ClassPrepare event has not yet been generated. The thread that did the loading gets unscheduled for a short while. In the meantime the debug agent is starting up, calls GetLoadedClasses, and tags all the classes, including Cleaner. It then sets up up the ClassPrepare event callback. At this point the thread that just loaded Cleaner gets some more cycles and generates the ClassPrepare event, but by this time the debug agent has already tagged it since it was included with GetLoadedClasses, so classTrack_addPreparedClass() unexpectedly find the class already tagged.
I think this assert is assuming something which we now know won't always be true. The assert can either be removed, or maybe it should assert that the old tag matches the new tag.
BTW, although this is a long standing bug, but it hadn't been exposed until recently when it was triggered by a recent change in Loom:
"Delay starting finalizer and reference handler threads to phase 2"
https://orahub.oci.oraclecorp.com/jpg-mirrors/loom-open/-/commit/c474b8e233adac6a3aa0672e2bf312906ce262ff
classTrack_addPreparedClass(JNIEnv *env_unused, jclass klass)
{
jvmtiError error;
jvmtiEnv* env = trackingEnv;
if (gdata && gdata->assertOn) {
// Check this is not already tagged.
jlong tag;
error = JVMTI_FUNC_PTR(trackingEnv, GetTag)(env, klass, &tag);
if (error != JVMTI_ERROR_NONE) {
EXIT_ERROR(error, "Unable to GetTag with class trackingEnv");
}
JDI_ASSERT(tag == NOT_TAGGED); <----------- HERE
}
Usually when it is triggered I see the following in the test output:
FATAL ERROR in native method: JDWP Assertion Failed, jvmtiError=AGENT_ERROR_INTERNAL(181)
at jdk.internal.misc.Unsafe.ensureClassInitialized0(java.base@19-loom/Native Method)
at jdk.internal.misc.Unsafe.ensureClassInitialized(java.base@19-loom/Unsafe.java:1160)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@19-loom/Reference.java:203)
With some extra debugging output I found that the class in question is java/lang/Cleaner. The assert is very rare, and pretty much only on linux-aarch64, and seems it can impact any of the com/sun/jdi tests. I think I know what's going on, but first some background.
The debug agent calls SetTag on every loaded class, setting the tag to be a pointer to the class signature. This way when the class is unloaded, an ObjectFree event is generated, which the debug agent uses to trigger the sending of a CLASS_UNLOAD to the debugger. classTrack_addPreparedClass() does this tagging, but as you can see above it first asserts that it has not been tagged already. When the debug agent is initialized, it calls JVMTI GetLoadedClasses, and for each class returned it calls classTrack_addPreparedClass(). It then sets up a ClassPrepare event callback so it can tag any additional classes that get loaded later. (There is another bug here. There could be a class loaded after the call to GetLoadedClasses and before setting up the ClassPrepare event callback. These classes will not get tagged, but that is not the cause of these com/sun/jdi failures. JDK-8282851 has been filed.).
What I think is happening is that the Cleaner class has been loaded and is available to GetLoadedClasses, but the ClassPrepare event has not yet been generated. The thread that did the loading gets unscheduled for a short while. In the meantime the debug agent is starting up, calls GetLoadedClasses, and tags all the classes, including Cleaner. It then sets up up the ClassPrepare event callback. At this point the thread that just loaded Cleaner gets some more cycles and generates the ClassPrepare event, but by this time the debug agent has already tagged it since it was included with GetLoadedClasses, so classTrack_addPreparedClass() unexpectedly find the class already tagged.
I think this assert is assuming something which we now know won't always be true. The assert can either be removed, or maybe it should assert that the old tag matches the new tag.
BTW, although this is a long standing bug, but it hadn't been exposed until recently when it was triggered by a recent change in Loom:
"Delay starting finalizer and reference handler threads to phase 2"
https://orahub.oci.oraclecorp.com/jpg-mirrors/loom-open/-/commit/c474b8e233adac6a3aa0672e2bf312906ce262ff
- relates to
-
JDK-8282851 Debug Agent might miss some loaded classes during startup
-
- Open
-