serviceability_jvmti_j9_0 FAILED serviceability/jvmti/GetMethodDeclaringClass/TestUnloadedClass.java 'OutOfMemoryError' missing from stdout/stderr

[JasonFengJ9]

Failure link

From internal Test_openjdk21_j9_extended.openjdk_ppc64le_linux_testList_1 (rtj-rhel8le-rtp-test-8kd6c-1)

java version "21.0.6-beta" 2025-01-21
IBM Semeru Runtime Certified Edition 21.0.6+4-202411231604 (build 21.0.6-beta+4-202411231604)
Eclipse OpenJ9 VM 21.0.6+4-202411231604 (build master-3da9d2f0ba, JRE 21 Linux ppc64le-64-Bit Compressed References 20241123_312 (JIT enabled, AOT enabled)
OpenJ9   - 3da9d2f0ba
OMR      - 32ef86c51
JCL      - 8967a7c62 based on jdk-21.0.6+4)

Rerun in Grinder - Change TARGET to run only the failed test targets

Optional info

Failure output (captured from console output)

[2024-11-23T17:10:20.104Z] variation: Mode150
[2024-11-23T17:10:20.104Z] JVM_OPTIONS:  -XX:+UseCompressedOops -Xverbosegclog 

[2024-11-23T17:11:54.865Z] TEST: serviceability/jvmti/GetMethodDeclaringClass/TestUnloadedClass.java

[2024-11-23T17:11:54.866Z]  exitValue = 134
[2024-11-23T17:11:54.866Z] 
[2024-11-23T17:11:54.866Z] java.lang.RuntimeException: 'OutOfMemoryError' missing from stdout/stderr
[2024-11-23T17:11:54.866Z] 	at jdk.test.lib.process.OutputAnalyzer.shouldContain(OutputAnalyzer.java:231)
[2024-11-23T17:11:54.866Z] 	at TestUnloadedClass.main(TestUnloadedClass.java:53)
[2024-11-23T17:11:54.866Z] 	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
[2024-11-23T17:11:54.866Z] 	at java.base/java.lang.reflect.Method.invoke(Method.java:586)
[2024-11-23T17:11:54.866Z] 	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
[2024-11-23T17:11:54.866Z] 	at java.base/java.lang.Thread.run(Thread.java:1595)
[2024-11-23T17:11:54.866Z] 
[2024-11-23T17:11:54.866Z] JavaTest Message: Test threw exception: java.lang.RuntimeException
[2024-11-23T17:11:54.866Z] JavaTest Message: shutting down test
[2024-11-23T17:11:54.866Z] 
[2024-11-23T17:11:54.866Z] 
[2024-11-23T17:11:54.866Z] TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: 'OutOfMemoryError' missing from stdout/stderr
[2024-11-23T17:11:54.866Z] --------------------------------------------------
[2024-11-23T17:15:50.137Z] Test results: passed: 156; failed: 1
[2024-11-23T17:16:09.439Z] Report written to /home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_ppc64le_linux_testList_1/jvmtest/openjdk/report/html/report.html
[2024-11-23T17:16:09.439Z] Results written to /home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_ppc64le_linux_testList_1/aqa-tests/TKG/output_17323818186962/serviceability_jvmti_j9_0/work
[2024-11-23T17:16:09.439Z] Error: Some tests failed or other problems occurred.
[2024-11-23T17:16:09.439Z] -----------------------------------
[2024-11-23T17:16:09.439Z] serviceability_jvmti_j9_0_FAILED

The existing code 134 means a SIGABRT signal.

50x internal Grinder - fails 100%

[github-actions]

Issue Number: 20676
Status: Open
Recommended Components: comp:jvmti, comp:vm, comp:test

[pshipton]

This is a new test added by 8339725: Concurrent GC crashed due to GetMethodDeclaringClass.
https://bugs.openjdk.org/browse/JDK-8339725

There is an assertion.

12:11:54  Thread 0000000000273D00 structures scan: slot 00007FFF2C397618 has bad value FFFFFFFFFFFFFFFF, iterator state 2
12:11:54  java: /home/jenkins/workspace/build-scripts/jobs/jdk21u/jdk21u-linux-ppc64le-openj9-IBM/workspace/build/src/openj9/runtime/gc_glue_java/ScavengerRootScanner.hpp:123: virtual void MM_ScavengerRootScanner::doVMThreadSlot(J9Object**, GC_VMThreadIterator*): Assertion `0' failed.

[pshipton]

@dmitripivkine pls take a look.

[dmitripivkine]

An assertion occur an attempt to scan JNI Local References !J9Pool 0x00007FFF2C008C60 !J9JNIReferenceFrame 0x00007FFF2C008A18 for !j9vmthread 0x00273d00.
Problematic slot:

> !walkj9pool 0x00007FFF2C008C60 | grep -i 7FFF2C397618
	[17]	=	0x00007FFF2C397618

0x7FFF2C3975F0 :  00000000fd0ed650 00000000fd0e44a0 [ P........D...... ]
0x7FFF2C397600 :  00000000fffffed0 00000000fd1a4938 [ ........8I...... ]
0x7FFF2C397610 :  00000000fd0f3ee0 ffffffffffffffff [ .>.............. ] <-----

There are ~200000 elements in this pool and most of them (if not all) are class objects for MyClass class for various class loaders.
Taking to consideration class object for unloaded class is replaced to 0xffffffffffffffff I have a hypothesis there is a time hole when newly created class was unloaded just before it's class object was added to JNI Local References pool.
@pshipton @TobiAjila

[dmitripivkine]

I do see class unloading but not last but previous Global GC. So next one should discover the problem but it wasn't. It means theory with just created class unloaded might not fit. Any way, somehow we got class object from unloaded class 0xffffffffffffffff in JNI Local References pool.

[dmitripivkine]

I do see class unloading but not last but previous Global GC. So next one should discover the problem but it wasn't. It means theory with just created class unloaded might not fit. Any way, somehow we got class object from unloaded class 0xffffffffffffffff in JNI Local References pool.

There are lot of failures in the grinder. I did check a few of them. The problem is the same, 0xffffffffffffffff in JNI Local References pool. Looks like previous GC doing class unloading and current one (Global or Local) crashed. I can not find another case where there is one extra GC survived between class unloading and crash. I guess it is possible if this middle GC happened before JNI Local Ref is added to the pool.

Also noticed (not sure is it related) there is warning for very last (crashed) GC in verbose log:

<warning details="slow exclusive request due to Exclusive Access" threadname="Thread-0" timems="821" />

[pshipton]

@tajila this needs some attention.

[tajila]

@hangshao0 Please take a look

[hangshao0]

@fengxue-IS will look at this.