Bug ID: JDK-8316131 runtime/cds/appcds/TestParallelGCWithCDS.java fails with JNI error

JDK-8316131 : runtime/cds/appcds/TestParallelGCWithCDS.java fails with JNI error

Type: Bug
Component: hotspot
Sub-Component: runtime
Affected Version: 22

Priority: P4
Status: Resolved
Resolution: Fixed

Submitted: 2023-09-12
Updated: 2024-07-24
Resolved: 2024-06-04

Versions (Unresolved/Resolved/Fixed)

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 21	JDK 23
21.0.5-oracleFixed	23 b26Fixed

Related Reports

Relates :	JDK-8335577 - runtime/cds/appcds/TestParallelGCWithCDS.java still fails with JNI error
Relates :	JDK-8316132 - CDSProtectionDomain::get_shared_protection_domain should check for exception

Description

3. Exec with -XX:+UseParallelGC -Xmx2m
Command line: [/jdk-22-galahadstaging+1-20/linux-x64-debug.jdk/jdk-22/fastdebug/bin/java -cp /testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_runtime/classes/0/runtime/cds/appcds/TestParallelGCWithCDS.d:/jdk-22-galahadstaging+1-20/src.full/open/test/hotspot/jtreg/runtime/cds/appcds:/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_runtime/classes/0/test/lib:/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_runtime/classes/0/test/hotspot/jtreg/runtime/cds/appcds:/jtreg/lib/jtreg.jar:/jtreg/lib/junit-platform-console-standalone-1.9.2.jar:/jtreg/lib/testng-7.3.0.jar:/jtreg/lib/jcommander-1.82.jar:/jtreg/lib/guice-5.1.0.jar -XX:MaxRAMPercentage=4.16667 -Djava.io.tmpdir=/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_runtime/tmp -Xcomp -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:-TieredCompilation -XX:-UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseJVMCICompiler -Xshare:on -showversion -XX:SharedArchiveFile=/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_runtime/scratch/5/appcds-00h22m27s118.jsa -Dtest.timeout.factor=25.0 -cp /testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_runtime/scratch/5/hello.jar -XX:+UnlockDiagnosticVMOptions -XX:VerifyArchivedFields=1 -XX:+UseParallelGC -Xmx256m -XX:ObjectAlignmentInBytes=64 -Xmx2m -Xlog:cds Hello ]
[2023-09-12T00:24:14.141810867Z] Gathering output for process 26475
[ELAPSED: 55310 ms]
[logging stdout to /testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_runtime/scratch/5/runtime.cds.appcds.TestParallelGCWithCDS.java-0012-exec.stdout]
[logging stderr to /testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_runtime/scratch/5/runtime.cds.appcds.TestParallelGCWithCDS.java-0012-exec.stderr]
[STDERR]
java version "22-galahadstaging" 2024-03-19
Java(TM) SE Runtime Environment (fastdebug build 22-galahadstaging+1-20)
Java HotSpot(TM) 64-Bit Server VM (fastdebug build 22-galahadstaging+1-20, compiled mode, sharing)
Error: A JNI error has occurred, please check your installation and try again
Exception in thread "main" 
[2023-09-12T00:25:09.451972585Z] Waiting for completion for process 26475
[2023-09-12T00:25:09.452011335Z] Waiting for completion finished for process 26475
[2023-09-12T00:25:09.452026909Z] Waiting for completion for process 26475
[2023-09-12T00:25:09.452182337Z] Waiting for completion finished for process 26475
[2023-09-12T00:25:09.452569181Z] Waiting for completion for process 26475
[2023-09-12T00:25:09.452602542Z] Waiting for completion finished for process 26475
----------System.err:(51/4584)----------
 stdout: [[0.001s][info][cds] optimized module handling: disabled due to incompatible property: jdk.module.addmods.0=jdk.internal.vm.ci
[0.004s][info][cds] trying to map /testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_runtime/scratch/5/appcds-00h22m27s118.jsa
[0.004s][info][cds] Opened archive /testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_runtime/scratch/5/appcds-00h22m27s118.jsa.
[0.004s][info][cds] Archive was created with UseCompressedOops = 0, UseCompressedClassPointers = 1
[0.004s][info][cds] optimized module handling: disabled because archive was created without optimized module handling
[0.004s][info][cds] full module graph: disabled because archive was created without full module graph
[0.004s][info][cds] Core region alignment: 4096
[0.004s][info][cds] Reserved archive_space_rs [0x0000000800000000 - 0x0000000801000000] (16777216) bytes
[0.004s][info][cds] Reserved class_space_rs   [0x0000000801000000 - 0x0000000841000000] (1073741824) bytes
[0.004s][info][cds] Mapped static  region #0 at base 0x0000000800000000 top 0x0000000800506000 (ReadWrite)
[0.004s][info][cds] Mapped static  region #1 at base 0x0000000800506000 top 0x0000000800d27000 (ReadOnly)
[0.004s][info][cds] ArchiveRelocationMode == 1: always map archive(s) at an alternative address
[0.004s][info][cds] Unmapping region #0 at base 0x0000000800000000 (ReadWrite)
[0.004s][info][cds] Unmapping region #1 at base 0x0000000800506000 (ReadOnly)
[0.004s][info][cds] Try to map archive(s) at an alternative address
[0.004s][info][cds] Reserved archive_space_rs [0x00007f369a000000 - 0x00007f369b000000] (16777216) bytes
[0.004s][info][cds] Reserved class_space_rs   [0x00007f369b000000 - 0x00007f36db000000] (1073741824) bytes
[0.004s][info][cds] Mapped static  region #0 at base 0x00007f369a000000 top 0x00007f369a506000 (ReadWrite)
[0.004s][info][cds] Mapped static  region #1 at base 0x00007f369a506000 top 0x00007f369ad27000 (ReadOnly)
[0.004s][info][cds] Mapped static  region #2 at base 0x00007f36f0a87000 top 0x00007f36f0ac9000 (Bitmap)
[0.011s][info][cds] CDS archive was created with max heap size = 256M, and the following configuration:
[0.012s][info][cds]     narrow_klass_base at mapping start address, narrow_klass_shift = 0
[0.012s][info][cds]     narrow_oop_mode = 0, narrow_oop_base = 0x0000000000000000, narrow_oop_shift = 0
[0.012s][info][cds] The current max heap size = 2M, HeapRegion::GrainBytes = 0
[0.012s][info][cds]     narrow_klass_base = 0x00007f369a000000, narrow_klass_shift = 0
[0.012s][info][cds]     narrow_oop_mode = 0, narrow_oop_base = 0x0000000000000000, narrow_oop_shift = 0
[0.012s][info][cds]     heap range = [0x0000000000000000 - 0x0000000000000000]
[0.012s][info][cds] Cannot use CDS heap data. UseG1GC is required for -XX:-UseCompressedOops
[0.012s][info][cds] optimized module handling: disabled
[0.012s][info][cds] full module graph: disabled
[0.012s][info][cds] Unmapping region #2 at base 0x00007f36f0a87000 (Bitmap)
];
 stderr: [java version "22-galahadstaging" 2024-03-19
Java(TM) SE Runtime Environment (fastdebug build 22-galahadstaging+1-20)
Java HotSpot(TM) 64-Bit Server VM (fastdebug build 22-galahadstaging+1-20, compiled mode, sharing)
Error: A JNI error has occurred, please check your installation and try again
Exception in thread "main" ]
 exitValue = 1

java.lang.RuntimeException: '((Too small maximum heap)|(GC triggered before VM initialization completed)|(java.lang.OutOfMemoryError: Java heap space))' missing from stdout/stderr
	at jdk.test.lib.process.OutputAnalyzer.shouldMatch(OutputAnalyzer.java:340)
	at TestParallelGCWithCDS.test(TestParallelGCWithCDS.java:120)
	at TestParallelGCWithCDS.main(TestParallelGCWithCDS.java:57)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
	at java.base/java.lang.Thread.run(Thread.java:1570)

Comments

seems we need as well for jdk21u-dev the OutputAnalyzer part from JDK-8321400. https://github.com/openjdk/jdk/commit/7ece9e90c0198f92cdf8d620e346c4a9832724cd
24-07-2024
jdk21u-dev backport request I would like to have the patch in jdk21u-dev as well, for parity with Oracle JDK. The backport is clean and low risk.
22-07-2024
A pull request was submitted for review. Branch: master URL: https://git.openjdk.org/jdk21u-dev/pull/859 Date: 2024-07-22 07:08:25 +0000
22-07-2024
Changeset: 31f70391 Author: Calvin Cheung <ccheung@openjdk.org> Date: 2024-06-04 16:43:08 +0000 URL: https://git.openjdk.org/jdk/commit/31f70391e5f22ff5803d16b52c1e1248b6253d8c
04-06-2024
A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/19506 Date: 2024-05-31 22:37:56 +0000
31-05-2024
I couldn't reproduce the JNI error. With very small heap, I could reproduce the following: stdout: [[0.002s][info][cds] optimized module handling: disabled due to incompatible property: jdk.module.addmods=jdk.internal.vm.ci Error occurred during initialization of VM Initial heap size set to a larger value than the maximum heap size ]; stderr: [] exitValue = 1 java.lang.RuntimeException: '((Too small maximum heap)\|(GC triggered before VM initialization completed)\|(java.lang.OutOfMemoryError: Java heap space))' missing from stdout/stderr at jdk.test.lib.process.OutputAnalyzer.shouldMatch(OutputAnalyzer.java:371) at TestParallelGCWithCDS.test(TestParallelGCWithCDS.java:120) at TestParallelGCWithCDS.test(TestParallelGCWithCDS.java:64) at TestParallelGCWithCDS.main(TestParallelGCWithCDS.java:51) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138) at java.base/java.lang.Thread.run(Thread.java:1575) Below are the options used in the jtreg command line: -javaoptions:"-Xcomp -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:-TieredCompilation -XX:-UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseJVMCICompiler -Xmx8m -Xms2m" -timeout:25
31-05-2024
I now see JDK-8316132 was also filed.
12-09-2023
If the VM doesn't crash (ie vm_exit_during_initialization) due to the small heap then it should be throwing an exception and the CHECK_EXCEPTION_NULL_LEAVE macro should be reporting that exception. But it isn't. We reach the null check: #define CHECK_EXCEPTION_NULL_LEAVE(CENL_exception) \ do { \ if ((*env)->ExceptionOccurred(env)) { \ JLI_ReportExceptionDescription(env); \ LEAVE(); \ } \ if ((CENL_exception) == NULL) { \ JLI_ReportErrorMessage(JNI_ERROR); \ LEAVE(); \ } \ } while (JNI_FALSE) which leads to the generic "JNI error occurred" message. We should investigate how we are failing without generating an exception.
12-09-2023
The error is from here in src/java.base/share/native/libjli/java.c, where the macro expands to print the "Error: A JNI error has occurred, please check your installation and try again" message mainClass = LoadMainClass(env, mode, what); CHECK_EXCEPTION_NULL_LEAVE(mainClass); << HERE This test cases runs with a very small heap, so it possible for the JVM to fail in many locations with different messages. Instead of checking only for ((Too small maximum heap)\|(GC triggered before VM initialization completed)\|(java.lang.OutOfMemoryError: Java heap space)), its better to change the test to: - assert that exit code is not zero - assert that the JVM has not crashed (no hs_err message in stdout)
12-09-2023