openj9
openj9 copied to clipboard
eclipse-openj9
OpenJDK java/lang/invoke/lambda/LogGeneratedClassesTest timeout or other
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/103 jdk_lang_1 java/lang/invoke/lambda/LogGeneratedClassesTest.java
21:43:31 Timeout refired 960 times
21:43:31 Timeout information:
21:43:31 Running jcmd on process 3231992
21:43:31 Dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/aqa-tests/TKG/output_17014839509011/jdk_lang_1/work/scratch/0/core.20231201.214315.3231992.0001.dmp
21:43:31 Dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/aqa-tests/TKG/output_17014839509011/jdk_lang_1/work/scratch/0/javacore.20231201.214328.3231992.0002.txt
21:43:31 Running jstack on process 3231992
21:43:31 2023-12-01T21:43:28.981766665
21:43:31 Virtual machine: 3231992 JVM information:
21:43:31 JRE 11 Linux s390x-64-Bit 20231201_685 (JIT enabled, AOT enabled)
21:43:31 OpenJ9 - 244201c2b45
21:43:31 OMR - 69bd2849661
21:43:31 JCL - 72e4c5d71e3 based on jdk-11.0.22+5
21:43:31
21:43:31 "main" prio=5 Id=1 WAITING
21:43:31 at [email protected]/java.lang.Object.waitImpl(Native Method)
21:43:31 at [email protected]/java.lang.Object.wait(Object.java:251)
21:43:31 at [email protected]/java.lang.Object.wait(Object.java:219)
21:43:31 at [email protected]/java.lang.Thread.join(Thread.java:766)
21:43:31 at [email protected]/java.lang.Thread.join(Thread.java:721)
21:43:31 at app//com.sun.javatest.regtest.agent.MainActionHelper.runClass(MainActionHelper.java:198)
21:43:31 at app//com.sun.javatest.regtest.agent.AgentServer.doMain(AgentServer.java:306)
21:43:31 at app//com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:233)
21:43:31 at app//com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:70)
21:43:31
21:43:31 "JIT Compilation Thread-000" prio=10 Id=3 RUNNABLE
21:43:31
21:43:31 "JIT Compilation Thread-001 Suspended" prio=10 Id=4 RUNNABLE
21:43:31
21:43:31 "JIT Compilation Thread-002 Suspended" prio=10 Id=5 RUNNABLE
21:43:31
21:43:31 "JIT Compilation Thread-003 Suspended" prio=10 Id=6 RUNNABLE
21:43:31
21:43:31 "JIT Compilation Thread-004 Suspended" prio=10 Id=7 RUNNABLE
21:43:31
21:43:31 "JIT Compilation Thread-005 Suspended" prio=10 Id=8 RUNNABLE
21:43:31
21:43:31 "JIT Compilation Thread-006 Suspended" prio=10 Id=9 RUNNABLE
21:43:31
21:43:31 "JIT Diagnostic Compilation Thread-007 Suspended" prio=10 Id=10 RUNNABLE
21:43:31
21:43:31 "JIT-SamplerThread" prio=10 Id=11 TIMED_WAITING
21:43:31
21:43:31 "IProfiler" prio=5 Id=12 RUNNABLE
21:43:31
21:43:31 "Common-Cleaner" prio=8 Id=2 TIMED_WAITING
21:43:31 at [email protected]/java.lang.Object.waitImpl(Native Method)
21:43:31 at [email protected]/java.lang.Object.wait(Object.java:251)
21:43:31 at [email protected]/java.lang.Object.wait(Object.java:219)
21:43:31 at [email protected]/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
21:43:31 at [email protected]/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:148)
21:43:31 at [email protected]/java.lang.Thread.run(Thread.java:839)
21:43:31 at [email protected]/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:161)
21:43:31
21:43:31 "Concurrent Mark Helper" prio=1 Id=13 RUNNABLE
21:43:31
21:43:31 "GC Worker" prio=5 Id=14 RUNNABLE
21:43:31
21:43:31 "GC Worker" prio=5 Id=15 RUNNABLE
21:43:31
21:43:31 "GC Worker" prio=5 Id=16 RUNNABLE
21:43:31
21:43:31 "Finalizer thread" prio=5 Id=17 RUNNABLE
21:43:31
21:43:31 "Attach API wait loop" prio=10 Id=20 RUNNABLE
21:43:31 at [email protected]/openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
21:43:31 at [email protected]/openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
21:43:31 at [email protected]/openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
21:43:31 at [email protected]/openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
21:43:31
21:43:31 "pool-1-thread-1" prio=5 Id=21 TIMED_WAITING
21:43:31 at [email protected]/jdk.internal.misc.Unsafe.park(Native Method)
21:43:31 at [email protected]/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
21:43:31 at [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
21:43:31 at [email protected]/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
21:43:31 at [email protected]/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
21:43:31 at [email protected]/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
21:43:31 at [email protected]/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
21:43:31 at [email protected]/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
21:43:31 at [email protected]/java.lang.Thread.run(Thread.java:839)
21:43:31
21:43:31 "ClassByNameCache Reaper" prio=5 Id=43 WAITING
21:43:31 at [email protected]/java.lang.Object.waitImpl(Native Method)
21:43:31 at [email protected]/java.lang.Object.wait(Object.java:251)
21:43:31 at [email protected]/java.lang.Object.wait(Object.java:219)
21:43:31 at [email protected]/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
21:43:31 at [email protected]/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:109)
21:43:31 at [email protected]/java.io.ClassByNameCache$Reaper.run(ClassByNameCache.java:232)
21:43:31 at [email protected]/java.lang.Thread.run(Thread.java:839)
21:43:31
21:43:31 "process reaper (pid 3237752)" prio=10 Id=139 RUNNABLE
21:43:31 at [email protected]/java.lang.ProcessHandleImpl.waitForProcessExit0(Native Method)
21:43:31 at [email protected]/java.lang.ProcessHandleImpl$1.run(ProcessHandleImpl.java:141)
21:43:31 at [email protected]/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
21:43:31 at [email protected]/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
21:43:31 at [email protected]/java.lang.Thread.run(Thread.java:839)
21:43:31
21:43:31 "AgentVMThread" prio=5 Id=311 RUNNABLE
21:43:31 at [email protected]/java.io.FileInputStream.readBytes(Native Method)
21:43:31 at [email protected]/java.io.FileInputStream.read(FileInputStream.java:279)
21:43:31 at [email protected]/java.io.BufferedInputStream.read1(BufferedInputStream.java:290)
21:43:31 at [email protected]/java.io.BufferedInputStream.read(BufferedInputStream.java:351)
21:43:31 - locked java.lang.ProcessImpl$ProcessPipeInputStream@18c36758
21:43:31 at [email protected]/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
21:43:31 at [email protected]/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
21:43:31 at [email protected]/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
21:43:31 - locked java.io.InputStreamReader@a716529
21:43:31 at [email protected]/java.io.InputStreamReader.read(InputStreamReader.java:181)
21:43:31 at [email protected]/java.io.BufferedReader.fill(BufferedReader.java:161)
21:43:31 at [email protected]/java.io.BufferedReader.readLine(BufferedReader.java:326)
21:43:31 - locked java.io.InputStreamReader@a716529
21:43:31 at [email protected]/java.io.BufferedReader.readLine(BufferedReader.java:392)
21:43:31 at LUtils.doExec(LUtils.java:111)
21:43:31 at LUtils.doExec(LUtils.java:83)
21:43:31 at LogGeneratedClassesTest.testDumpDirNotExist(LogGeneratedClassesTest.java:142)
21:43:31 at [email protected]/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
21:43:31 at [email protected]/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
21:43:31 at [email protected]/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
21:43:31 at [email protected]/java.lang.reflect.Method.invoke(Method.java:572)
21:43:31 at app//org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
21:43:31 at app//org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599)
21:43:31 at app//org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174)
21:43:31 at app//org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46)
21:43:31 at app//org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822)
21:43:31 at app//org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147)
21:43:31 at app//org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146)
21:43:31 at app//org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128)
21:43:31 at [email protected]/java.util.ArrayList.forEach(ArrayList.java:1541)
21:43:31 at app//org.testng.TestRunner.privateRun(TestRunner.java:764)
21:43:31 at app//org.testng.TestRunner.run(TestRunner.java:585)
21:43:31 at app//org.testng.SuiteRunner.runTest(SuiteRunner.java:384)
21:43:31 at app//org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378)
21:43:31 at app//org.testng.SuiteRunner.privateRun(SuiteRunner.java:337)
21:43:31 at app//org.testng.SuiteRunner.run(SuiteRunner.java:286)
21:43:31 at app//org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53)
21:43:31 at app//org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96)
21:43:31 at app//org.testng.TestNG.runSuitesSequentially(TestNG.java:1218)
21:43:31 at app//org.testng.TestNG.runSuitesLocally(TestNG.java:1140)
21:43:31 at app//org.testng.TestNG.runSuites(TestNG.java:1069)
21:43:31 at app//org.testng.TestNG.run(TestNG.java:1037)
21:43:31 at app//com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:94)
21:43:31 at [email protected]/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
21:43:31 at [email protected]/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
21:43:31 at [email protected]/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
21:43:31 at [email protected]/java.lang.reflect.Method.invoke(Method.java:572)
21:43:31 at app//com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:312)
21:43:31 at [email protected]/java.lang.Thread.run(Thread.java:839)
21:43:31
21:43:31 "file lock watchdog" prio=10 Id=313 TIMED_WAITING
21:43:31 at [email protected]/java.lang.Object.waitImpl(Native Method)
21:43:31 at [email protected]/java.lang.Object.wait(Object.java:251)
21:43:31 at [email protected]/java.lang.Object.wait(Object.java:219)
21:43:31 at [email protected]/java.util.TimerThread.mainLoop(Timer.java:592)
21:43:31 at [email protected]/java.util.TimerThread.run(Timer.java:533)
21:43:31
21:43:31 "Attachment portNumber: 36609" prio=10 Id=315 RUNNABLE
21:43:31 at [email protected]/openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
21:43:31 at [email protected]/openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:249)
21:43:31 at [email protected]/openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:185)
21:43:31 at [email protected]/openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:248)
21:43:31 at [email protected]/openj9.internal.tools.attach.target.Attachment.run(Attachment.java:159)
21:43:31
21:43:31
21:43:31 --- Timeout information end.
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_ppc64le_linux_Nightly_testList_0/108/ jdk_lang_0 java/lang/invoke/lambda/LogGeneratedClassesTest.java
21:56:30 Unable to visit NotExist/DUMP_LAMBDA_PROXY_CLASS_FILES: java.nio.file.NoSuchFileException: NotExist/DUMP_LAMBDA_PROXY_CLASS_FILES
21:56:30 Unable to visit DUMP_LAMBDA_PROXY_CLASS_FILES: java.nio.file.NoSuchFileException: DUMP_LAMBDA_PROXY_CLASS_FILES
21:56:30 java.lang.Exception: failures: 1
21:56:30 at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:104)
21:56:30 at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
21:56:30 at java.base/java.lang.reflect.Method.invoke(Method.java:586)
21:56:30 at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
21:56:30 at java.base/java.lang.Thread.run(Thread.java:1595)
21:56:30
21:56:30 JavaTest Message: Test threw exception: java.lang.Exception
21:56:30 JavaTest Message: shutting down test
21:56:30
21:56:30 STDOUT:
21:56:30 config LogGeneratedClassesTest.setup(): success
21:56:30 test LogGeneratedClassesTest.testDumpDirIsFile(): failure
21:56:30 java.lang.AssertionError: only show error once expected [1] but found [2]
21:56:30 at org.testng.Assert.fail(Assert.java:99)
21:56:30 at org.testng.Assert.failNotEquals(Assert.java:1037)
21:56:30 at org.testng.Assert.assertEqualsImpl(Assert.java:140)
21:56:30 at org.testng.Assert.assertEquals(Assert.java:122)
21:56:30 at org.testng.Assert.assertEquals(Assert.java:797)
21:56:30 at LogGeneratedClassesTest.testDumpDirIsFile(LogGeneratedClassesTest.java:177)
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/108 - timeout
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_OMR_testList_1/52/ jdk_lang_1 java/lang/invoke/lambda/LogGeneratedClassesTest.java
07:34:12 Unable to visit NotExist/DUMP_LAMBDA_PROXY_CLASS_FILES: java.nio.file.NoSuchFileException: NotExist/DUMP_LAMBDA_PROXY_CLASS_FILES
07:34:12 Unable to visit DUMP_LAMBDA_PROXY_CLASS_FILES: java.nio.file.NoSuchFileException: DUMP_LAMBDA_PROXY_CLASS_FILES
07:34:12 java.lang.Exception: failures: 1
07:34:12 at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:104)
07:34:12 at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
07:34:12 at java.base/java.lang.reflect.Method.invoke(Method.java:586)
07:34:12 at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
07:34:12 at java.base/java.lang.Thread.run(Thread.java:1595)
07:34:12
07:34:12 JavaTest Message: Test threw exception: java.lang.Exception
07:34:12 JavaTest Message: shutting down test
07:34:12
07:34:12 STDOUT:
07:34:12 config LogGeneratedClassesTest.setup(): success
07:34:12 test LogGeneratedClassesTest.testDumpDirIsFile(): failure
07:34:12 java.lang.AssertionError: only show error once expected [1] but found [2]
07:34:12 at org.testng.Assert.fail(Assert.java:99)
07:34:12 at org.testng.Assert.failNotEquals(Assert.java:1037)
07:34:12 at org.testng.Assert.assertEqualsImpl(Assert.java:140)
07:34:12 at org.testng.Assert.assertEquals(Assert.java:122)
07:34:12 at org.testng.Assert.assertEquals(Assert.java:797)
07:34:12 at LogGeneratedClassesTest.testDumpDirIsFile(LogGeneratedClassesTest.java:177)
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/111
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/125 - timeout
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_aarch64_linux_Nightly_testList_0/134 - only show error once expected [1] but found [2]
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_s390x_linux_OMR_testList_1/66 - timeout
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_s390x_linux_OMR_testList_1/65 - timeout
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_OMR_testList_0/59 - only show error once expected [1] but found [2]
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_ppc64le_linux_Nightly_testList_0/132/ - only show error once expected [1] but found [2]
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_aarch64_linux_OMR_testList_1/72/ - timeout https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_OMR_testList_1/38/ - timeout
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/136/ - only show error once expected [1] but found [2]
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/129/ - timeout
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_ppc64le_linux_Nightly_testList_0/137/ - expected [1] but found [2]
This type of failure may be due to the following
20:22:06 Unable to visit NotExist/DUMP_LAMBDA_PROXY_CLASS_FILES: java.nio.file.NoSuchFileException: NotExist/DUMP_LAMBDA_PROXY_CLASS_FILES
20:22:06 Unable to visit DUMP_LAMBDA_PROXY_CLASS_FILES: java.nio.file.NoSuchFileException: DUMP_LAMBDA_PROXY_CLASS_FILES
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_s390x_linux_OMR_testList_1/69/ - timeout https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_s390x_linux_OMR_testList_0/70 - timeout https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_x86-64_linux_OMR_testList_1/41 x 2 - timeout
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_s390x_linux_OMR_testList_0/72/ - timeout
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_Nightly_testList_1/137/ - timeout
It continues to occur, I don't think I need to keep logging all the failures.
I have been unable to reproduce the timout error in LogGeneratedClassesTest locally on a x86_64 Linux machine with jdk11, jdk17 and jdk21.
I was able to reproduce the intermittent assert error in LogGeneratedClassesTest.testDumpDirIsFile locally on a x86_64 Linux machine with jdk21: java.lang.AssertionError: only show error once expected [1] but found [2]. The test creates a file named DUMP_LAMBDA_PROXY_CLASS_FILES (instead of a directory) and checks for an error message DUMP_LAMBDA_PROXY_CLASS_FILES is not a directory in the output of the java command in the test. The java command in the test runs TestLambda with -Djdk.invoke.LambdaMetafactory.dumpProxyClassFiles which results in a request to add the lambda proxy class files in a directory named DUMP_LAMBDA_PROXY_CLASS_FILES.
package com.example;
public class TestLambda {
interface I {
int foo();
}
public static void main(String[] args) {
System.setSecurityManager(new SecurityManager()); <-----
I lam = () -> 10;
Runnable r = () -> {
System.out.println("Runnable");
};
r.run();
System.out.println("Finish");
}
}
@Test
public void testDumpDirIsFile() throws IOException {
Path testDir = Path.of("notDir");
Path dumpFile = testDir.resolve(DUMP_LAMBDA_PROXY_CLASS_FILES);
Files.createDirectory(testDir);
Files.createFile(dumpFile); <-----
assertTrue(Files.isRegularFile(dumpFile));
TestResult tr = doExec(JAVA_CMD.getAbsolutePath(),
"-cp", "..",
"-Duser.dir=" + testDir.toAbsolutePath(),
"-Djava.security.manager=allow",
"-Djdk.invoke.LambdaMetafactory.dumpProxyClassFiles", <-----
"com.example.TestLambda"); <------
assertEquals(tr.testOutput.stream()
.filter(s -> s.contains("DUMP_LAMBDA_PROXY_CLASS_FILES is not a directory"))
.count(),
1, "only show error once");
assertTrue(tr.exitValue != 0);
}
An output of the java command in the test (when it passes) indicates that the error message is generated in the main thread by ClassFileDumper.validateDumpDir during the initialization of SecurityManager.
Exception in thread "main" java.lang.BootstrapMethodError: java.lang.ExceptionInInitializerError
at java.base/java.lang.SecurityManager.addNonExportedPackages(SecurityManager.java:1232)
at java.base/java.lang.SecurityManager.<clinit>(SecurityManager.java:1223)
at com.example.TestLambda.main(TestLambda.java:7)
Caused by: java.lang.ExceptionInInitializerError
at java.base/java.lang.J9VMInternals.recordInitializationFailure(J9VMInternals.java:175)
at java.base/java.lang.invoke.LambdaMetafactory.metafactory(LambdaMetafactory.java:331)
at java.base/java.lang.invoke.BootstrapMethodInvoker.invoke(BootstrapMethodInvoker.java:134)
at java.base/java.lang.invoke.CallSite.makeSite(CallSite.java:316)
at java.base/java.lang.invoke.MethodHandleNatives.linkCallSiteImpl(MethodHandleNatives.java:274)
at java.base/java.lang.invoke.MethodHandleNatives.linkCallSite(MethodHandleNatives.java:264)
at java.base/java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:195)
... 3 more
Caused by: java.lang.IllegalArgumentException: Path DUMP_LAMBDA_PROXY_CLASS_FILES is not a directory <-----
at java.base/jdk.internal.util.ClassFileDumper$2.run(ClassFileDumper.java:169)
at java.base/jdk.internal.util.ClassFileDumper$2.run(ClassFileDumper.java:157)
at java.base/java.security.AccessController.doPrivileged(AccessController.java:692)
at java.base/jdk.internal.util.ClassFileDumper.validateDumpDir(ClassFileDumper.java:157)
at java.base/jdk.internal.util.ClassFileDumper.<init>(ClassFileDumper.java:87)
at java.base/jdk.internal.util.ClassFileDumper.getInstance(ClassFileDumper.java:66)
at java.base/java.lang.invoke.InnerClassLambdaMetafactory.<clinit>(InnerClassLambdaMetafactory.java:95)
... 9 more
An output of the java command in the test (when it fails) indicates that the error message appears twice in two separate threads. In addition to the main thread, the error message is generated in the Attach API initializer thread during the initialization of InternalCRIUSupport.
Exception in thread "main" java.lang.BootstrapMethodError: java.lang.ExceptionInInitializerError
at java.base/java.lang.SecurityManager.addNonExportedPackages(SecurityManager.java:1232)
Exception in thread "Attach API initializer" java.lang.BootstrapMethodError: java.lang.NoClassDefFoundError: java.lang.invoke.InnerClassLambdaMetafactory (initialization failure)
at java.base/openj9.internal.criu.InternalCRIUSupport.<clinit>(InternalCRIUSupport.java:215)
at java.base/java.util.Timer.schedule(Timer.java:214)
at java.base/openj9.internal.tools.attach.target.FileLock.lockFile(FileLock.java:100)
at java.base/openj9.internal.tools.attach.target.CommonDirectory.obtainControllerLock(CommonDirectory.java:148)
at java.base/openj9.internal.tools.attach.target.AttachHandler.createFiles(AttachHandler.java:190)
at java.base/openj9.internal.tools.attach.target.AttachHandler.initialize(AttachHandler.java:296)
at java.base/openj9.internal.tools.attach.target.AttachHandler.run(AttachHandler.java:229)
at java.base/java.lang.SecurityManager.<clinit>(SecurityManager.java:1223)
at com.example.TestLambda.main(TestLambda.java:7)
Caused by: java.lang.ExceptionInInitializerError
at java.base/java.lang.J9VMInternals.recordInitializationFailure(J9VMInternals.java:175)
at java.base/java.lang.invoke.LambdaMetafactory.metafactory(LambdaMetafactory.java:331)
at java.base/java.lang.invoke.BootstrapMethodInvoker.invoke(BootstrapMethodInvoker.java:134)
at java.base/java.lang.invoke.CallSite.makeSite(CallSite.java:316)
at java.base/java.lang.invoke.MethodHandleNatives.linkCallSiteImpl(MethodHandleNatives.java:274)
at java.base/java.lang.invoke.MethodHandleNatives.linkCallSite(MethodHandleNatives.java:264)
at java.base/java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:195)
... 3 more
Caused by: java.lang.IllegalArgumentException: Path DUMP_LAMBDA_PROXY_CLASS_FILES is not a directory <-----
at java.base/jdk.internal.util.ClassFileDumper$2.run(ClassFileDumper.java:169)
at java.base/jdk.internal.util.ClassFileDumper$2.run(ClassFileDumper.java:157)
at java.base/java.security.AccessController.doPrivileged(AccessController.java:692)
at java.base/jdk.internal.util.ClassFileDumper.validateDumpDir(ClassFileDumper.java:157)
at java.base/jdk.internal.util.ClassFileDumper.<init>(ClassFileDumper.java:87)
at java.base/jdk.internal.util.ClassFileDumper.getInstance(ClassFileDumper.java:66)
at java.base/java.lang.invoke.InnerClassLambdaMetafactory.<clinit>(InnerClassLambdaMetafactory.java:95)
... 9 more
Caused by: java.lang.NoClassDefFoundError: java.lang.invoke.InnerClassLambdaMetafactory (initialization failure)
at java.base/java.lang.J9VMInternals.initializationAlreadyFailed(J9VMInternals.java:146)
at java.base/java.lang.invoke.LambdaMetafactory.metafactory(LambdaMetafactory.java:331)
at java.base/java.lang.invoke.BootstrapMethodInvoker.invoke(BootstrapMethodInvoker.java:134)
at java.base/java.lang.invoke.CallSite.makeSite(CallSite.java:316)
at java.base/java.lang.invoke.MethodHandleNatives.linkCallSiteImpl(MethodHandleNatives.java:274)
at java.base/java.lang.invoke.MethodHandleNatives.linkCallSite(MethodHandleNatives.java:264)
at java.base/java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:195)
... 7 more
Caused by: java.lang.ExceptionInInitializerError
at java.base/java.lang.J9VMInternals.recordInitializationFailure(J9VMInternals.java:175)
at java.base/java.lang.invoke.LambdaMetafactory.metafactory(LambdaMetafactory.java:331)
at java.base/java.lang.invoke.BootstrapMethodInvoker.invoke(BootstrapMethodInvoker.java:134)
at java.base/java.lang.invoke.CallSite.makeSite(CallSite.java:316)
at java.base/java.lang.invoke.MethodHandleNatives.linkCallSiteImpl(MethodHandleNatives.java:274)
at java.base/java.lang.invoke.MethodHandleNatives.linkCallSite(MethodHandleNatives.java:264)
at java.base/java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:195)
at java.base/java.lang.SecurityManager.addNonExportedPackages(SecurityManager.java:1232)
at java.base/java.lang.SecurityManager.<clinit>(SecurityManager.java:1223)
at com.example.TestLambda.main(TestLambda.java:7)
Caused by: java.lang.IllegalArgumentException: Path DUMP_LAMBDA_PROXY_CLASS_FILES is not a directory <-----
at java.base/jdk.internal.util.ClassFileDumper$2.run(ClassFileDumper.java:169)
at java.base/jdk.internal.util.ClassFileDumper$2.run(ClassFileDumper.java:157)
at java.base/java.security.AccessController.doPrivileged(AccessController.java:692)
at java.base/jdk.internal.util.ClassFileDumper.validateDumpDir(ClassFileDumper.java:157)
at java.base/jdk.internal.util.ClassFileDumper.<init>(ClassFileDumper.java:87)
at java.base/jdk.internal.util.ClassFileDumper.getInstance(ClassFileDumper.java:66)
at java.base/java.lang.invoke.InnerClassLambdaMetafactory.<clinit>(InnerClassLambdaMetafactory.java:95)
... 9 more
@tajila given the intermittent assert error in LogGeneratedClassesTest.testDumpDirIsFile, where the error message appears twice in two separate threads (main thread and Attach API initializer), and considering that the test does not seem to enable criu support with -XX:+EnableCRIUSupport, export criu modules with --add-exports java.base/openj9.internal.criu=ALL-UNNAMED, or use any criu features like InternalCRIUSupport, I would like to understand:
- How could criu features be initialized by the
Attach API initializerthread during the test? - Would the expected behaviour be that no criu features are initialized during the test?
How could criu features be initialized by the Attach API initializer thread during the test?
I think thats the key. Why does the application require InternalCRIUSupport. My guess is that it is using some crypto/security APIs. We have a certain set we allow when CRIu is enabled. So its probably checking if criu is enabled. You'd need to find which API is requesting that check.
Why does the application require InternalCRIUSupport. My guess is that it is using some crypto/security APIs. We have a certain set we allow when CRIu is enabled. So its probably checking if criu is enabled.
@tajila requesting your input on the preferred approach to resolve the intermittent assert error in the test LogGeneratedClassesTest.testDumpDirIsFile.
The intermittent assert error in the test java.lang.AssertionError: only show error once expected [1] but found [2] occurs when the test creates a file named DUMP_LAMBDA_PROXY_CLASS_FILES (instead of a directory), runs TestLambda in a java command with -Djdk.invoke.LambdaMetafactory.dumpProxyClassFiles, and finds two instances of the error message DUMP_LAMBDA_PROXY_CLASS_FILES is not a directory in the output of the java command.
package com.example;
public class TestLambda {
interface I {
int foo();
}
public static void main(String[] args) {
System.setSecurityManager(new SecurityManager()); <-----
I lam = () -> 10;
Runnable r = () -> {
System.out.println("Runnable");
};
r.run();
System.out.println("Finish");
}
}
The first instance of the error message in the main thread is expected and occurs during the initialization of SecurityManager, which includes lambda expressions.
The second instance of the error message in the Attach API initializer thread is intermittent and occurs during the initialization of InternalCRIUSupport, which includes a lambda expression. The reference to InternalCRIUSupport is in System.setSecurityManager.
https://github.com/eclipse-openj9/openj9/blob/01d6c8e06ca385f16a9c2db050a916b8944fc5fd/jcl/src/java.base/share/classes/java/lang/System.java#L1237-L1247
The error message in the Attach API initializer thread can be avoided with the following apporaches:
- Refactor the static block in
InternalCRIUSupportto remove use of lambda expression https://github.com/singh264/openj9/commit/37e4dceb2a36bc28801ad72eaf7a3a1388f60d09. - Disable
CRIU_SUPPORTby default https://github.com/singh264/openj9-openjdk-jdk21/commit/630bd8a624257638bec4699a933153ff39f969da.
After taking a second look:
Exception in thread "Attach API initializer" java.lang.BootstrapMethodError: java.lang.NoClassDefFoundError: java.lang.invoke.InnerClassLambdaMetafactory (initialization failure)
at java.base/openj9.internal.criu.InternalCRIUSupport.<clinit>(InternalCRIUSupport.java:215)
at java.base/java.util.Timer.schedule(Timer.java:214)
The following is interesting because InternalCRIUSupport is in java.base so it should be there all the time regardless of the following
test does not seem to enable criu support with -XX:+EnableCRIUSupport, export criu modules with --add-exports java.base/openj9.internal.criu=ALL-UNNAMED
Do you know what causes the init failure exactly? is it a missing class
Created https://github.com/adoptium/aqa-tests/pull/5047 to exclude the test since it fails too often in the builds.
Do you know what causes the init failure exactly? is it a missing class
The init failure is caused by the absence of ClassFileDumper which is requested during the initialization of InnerClassLambdaMetafactory to add the lambda class files in a directory named DUMP_LAMBDA_PROXY_CLASS_FILES. The error message DUMP_LAMBDA_PROXY_CLASS_FILES is not a directory seems to appear in the main thread before the Attach API initializer thread.
Caused by: java.lang.IllegalArgumentException: Path DUMP_LAMBDA_PROXY_CLASS_FILES is not a directory
at java.base/jdk.internal.util.ClassFileDumper$2.run(ClassFileDumper.java:169)
at java.base/jdk.internal.util.ClassFileDumper$2.run(ClassFileDumper.java:157)
at java.base/java.security.AccessController.doPrivileged(AccessController.java:692)
at java.base/jdk.internal.util.ClassFileDumper.validateDumpDir(ClassFileDumper.java:157)
at java.base/jdk.internal.util.ClassFileDumper.<init>(ClassFileDumper.java:87) <-----
at java.base/jdk.internal.util.ClassFileDumper.getInstance(ClassFileDumper.java:66)
at java.base/java.lang.invoke.InnerClassLambdaMetafactory.<clinit>(InnerClassLambdaMetafactory.java:95) <-----
... 9 more