eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.28k stars 721 forks source link

OpenJDK java/lang/invoke/lambda/LambdaAsm timeout #18655

Open pshipton opened 10 months ago

pshipton commented 10 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_x86-64_linux_OMR_testList_0/33 jdk_lang_0 java/lang/invoke/lambda/LambdaAsm.java

06:49:57  ACTION: main -- Error. Program `/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_x86-64_linux_OMR_testList_0/jdkbinary/j2sdk-image/bin/java' timed out (timeout set to 960000ms, elapsed time including timeout handling was 972196ms).
06:49:57  REASON: User specified action: run main/othervm LambdaAsm 
06:49:57  TIME:   972.206 seconds
06:49:57  messages:
06:49:57  command: main LambdaAsm
06:49:57  reason: User specified action: run main/othervm LambdaAsm 
06:49:57  Mode: othervm [/othervm specified]
06:49:57  Additional options from @modules: --add-modules java.base,jdk.jdeps,jdk.zipfs --add-exports java.base/jdk.internal.org.objectweb.asm=ALL-UNNAMED --add-exports jdk.jdeps/com.sun.tools.classfile=ALL-UNNAMED
06:49:57  Timeout information:
06:49:57  Running jcmd on process 29131
06:49:57  Dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_x86-64_linux_OMR_testList_0/aqa-tests/TKG/output_170298539851/jdk_lang_0/work/scratch/0/core.20231219.074937.29131.0001.dmp
06:49:57  Dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_x86-64_linux_OMR_testList_0/aqa-tests/TKG/output_170298539851/jdk_lang_0/work/scratch/0/javacore.20231219.074942.29131.0002.txt
06:49:57  Running jstack on process 29131
06:49:57  2023-12-19T07:49:47.217545094
06:49:57  Virtual machine: 29131 JVM information:
06:49:57  JRE 11 Linux amd64-64-Bit Compressed References 20231219_535 (JIT enabled, AOT enabled)
06:49:57  OpenJ9   - 316f2a9
06:49:57  OMR      - 7a7426b
06:49:57  JCL      - 6fd19af based on jdk-11.0.22+6
06:49:57  
06:49:57  "main" prio=5 Id=1 WAITING
06:49:57    at java.base@11.0.22-internal/java.lang.Object.waitImpl(Native Method)
06:49:57    at java.base@11.0.22-internal/java.lang.Object.wait(Object.java:251)
06:49:57    at java.base@11.0.22-internal/java.lang.Object.wait(Object.java:219)
06:49:57    at java.base@11.0.22-internal/java.lang.Thread.join(Thread.java:766)
06:49:57    at java.base@11.0.22-internal/java.lang.Thread.join(Thread.java:721)
06:49:57    at app//com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:74)
06:49:57  
06:49:57  "JIT Compilation Thread-000" prio=10 Id=3 RUNNABLE
06:49:57  
06:49:57  "JIT Compilation Thread-001 Suspended" prio=10 Id=4 RUNNABLE
06:49:57  
06:49:57  "JIT Compilation Thread-002 Suspended" prio=10 Id=5 RUNNABLE
06:49:57  
06:49:57  "JIT Compilation Thread-003 Suspended" prio=10 Id=6 RUNNABLE
06:49:57  
06:49:57  "JIT Compilation Thread-004 Suspended" prio=10 Id=7 RUNNABLE
06:49:57  
06:49:57  "JIT Compilation Thread-005 Suspended" prio=10 Id=8 RUNNABLE
06:49:57  
06:49:57  "JIT Compilation Thread-006 Suspended" prio=10 Id=9 RUNNABLE
06:49:57  
06:49:57  "JIT Diagnostic Compilation Thread-007 Suspended" prio=10 Id=10 RUNNABLE
06:49:57  
06:49:57  "JIT-SamplerThread" prio=10 Id=11 TIMED_WAITING
06:49:57  
06:49:57  "IProfiler" prio=5 Id=12 RUNNABLE
06:49:57  
06:49:57  "Common-Cleaner" prio=8 Id=2 TIMED_WAITING
06:49:57    at java.base@11.0.22-internal/java.lang.Object.waitImpl(Native Method)
06:49:57    at java.base@11.0.22-internal/java.lang.Object.wait(Object.java:251)
06:49:57    at java.base@11.0.22-internal/java.lang.Object.wait(Object.java:219)
06:49:57    at java.base@11.0.22-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
06:49:57    at java.base@11.0.22-internal/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:148)
06:49:57    at java.base@11.0.22-internal/java.lang.Thread.run(Thread.java:839)
06:49:57    at java.base@11.0.22-internal/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:161)
06:49:57  
06:49:57  "Finalizer thread" prio=5 Id=13 RUNNABLE
06:49:57  
06:49:57  "Concurrent Mark Helper" prio=1 Id=14 RUNNABLE
06:49:57  
06:49:57  "GC Worker" prio=5 Id=15 RUNNABLE
06:49:57  
06:49:57  "GC Worker" prio=5 Id=16 RUNNABLE
06:49:57  
06:49:57  "GC Worker" prio=5 Id=17 RUNNABLE
06:49:57  
06:49:57  "Attach API wait loop" prio=10 Id=20 RUNNABLE
06:49:57    at java.base@11.0.22-internal/openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
06:49:57    at java.base@11.0.22-internal/openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
06:49:57    at java.base@11.0.22-internal/openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
06:49:57    at java.base@11.0.22-internal/openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
06:49:57  
06:49:57  "MainThread" prio=5 Id=22 RUNNABLE
06:49:57    at java.base@11.0.22-internal/java.io.FileInputStream.readBytes(Native Method)
06:49:57    at java.base@11.0.22-internal/java.io.FileInputStream.read(FileInputStream.java:279)
06:49:57    at java.base@11.0.22-internal/java.io.BufferedInputStream.read1(BufferedInputStream.java:290)
06:49:57    at java.base@11.0.22-internal/java.io.BufferedInputStream.read(BufferedInputStream.java:351)
06:49:57    - locked java.lang.ProcessImpl$ProcessPipeInputStream@218dc473
06:49:57    at java.base@11.0.22-internal/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
06:49:57    at java.base@11.0.22-internal/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
06:49:57    at java.base@11.0.22-internal/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
06:49:57    - locked java.io.InputStreamReader@cf57613d
06:49:57    at java.base@11.0.22-internal/java.io.InputStreamReader.read(InputStreamReader.java:181)
06:49:57    at java.base@11.0.22-internal/java.io.BufferedReader.fill(BufferedReader.java:161)
06:49:57    at java.base@11.0.22-internal/java.io.BufferedReader.readLine(BufferedReader.java:326)
06:49:57    - locked java.io.InputStreamReader@cf57613d
06:49:57    at java.base@11.0.22-internal/java.io.BufferedReader.readLine(BufferedReader.java:392)
06:49:57    at app//LUtils.doExec(LUtils.java:111)
06:49:57    at app//LUtils.doExec(LUtils.java:83)
06:49:57    at app//LambdaAsm.init(LambdaAsm.java:60)
06:49:57    at app//LambdaAsm.main(LambdaAsm.java:183)
06:49:57    at java.base@11.0.22-internal/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
06:49:57    at java.base@11.0.22-internal/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
06:49:57    at java.base@11.0.22-internal/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
06:49:57    at java.base@11.0.22-internal/java.lang.reflect.Method.invoke(Method.java:572)
06:49:57    at app//com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
06:49:57    at java.base@11.0.22-internal/java.lang.Thread.run(Thread.java:839)
06:49:57  
06:49:57  "process reaper (pid 29185)" prio=10 Id=23 RUNNABLE
06:49:57    at java.base@11.0.22-internal/java.lang.ProcessHandleImpl.waitForProcessExit0(Native Method)
06:49:57    at java.base@11.0.22-internal/java.lang.ProcessHandleImpl$1.run(ProcessHandleImpl.java:141)
06:49:57    at java.base@11.0.22-internal/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
06:49:57    at java.base@11.0.22-internal/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
06:49:57    at java.base@11.0.22-internal/java.lang.Thread.run(Thread.java:839)
06:49:57  
06:49:57  "file lock watchdog" prio=10 Id=25 TIMED_WAITING
06:49:57    at java.base@11.0.22-internal/java.lang.Object.waitImpl(Native Method)
06:49:57    at java.base@11.0.22-internal/java.lang.Object.wait(Object.java:251)
06:49:57    at java.base@11.0.22-internal/java.lang.Object.wait(Object.java:219)
06:49:57    at java.base@11.0.22-internal/java.util.TimerThread.mainLoop(Timer.java:592)
06:49:57    at java.base@11.0.22-internal/java.util.TimerThread.run(Timer.java:533)
06:49:57  
06:49:57  "Attachment portNumber: 38487" prio=10 Id=27 RUNNABLE
06:49:57    at java.base@11.0.22-internal/openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
06:49:57    at java.base@11.0.22-internal/openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:249)
06:49:57    at java.base@11.0.22-internal/openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:185)
06:49:57    at java.base@11.0.22-internal/openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:248)
06:49:57    at java.base@11.0.22-internal/openj9.internal.tools.attach.target.Attachment.run(Attachment.java:159)
06:49:57  
06:49:57  
06:49:57  --- Timeout information end.
pshipton commented 8 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_OMR_testList_0/31 - ub20-ppcle-1 jdk_lang_0 java/lang/invoke/lambda/LambdaAsm.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_OMR_testList_0/31/openjdk_test_output.tar.gz

02:59:17  Timeout information:
02:59:17  Running jcmd on process 265588
02:59:17  Dump written to /home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_OMR_testList_0/aqa-tests/TKG/output_17069459977576/jdk_lang_0/work/scratch/0/core.20240203.075818.265588.0001.dmp
02:59:17  Dump written to /home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_OMR_testList_0/aqa-tests/TKG/output_17069459977576/jdk_lang_0/work/scratch/0/javacore.20240203.075915.265588.0002.txt
02:59:17  Running jstack on process 265588
02:59:17  2024-02-03T07:59:16.371384394
02:59:17  Virtual machine: 265588 JVM information:
02:59:17  JRE 11 Linux ppc64le-64-Bit Compressed References 20240203_525 (JIT enabled, AOT enabled)
02:59:17  OpenJ9   - 8dc58cc3745
02:59:17  OMR      - 410ef0d2314
02:59:17  JCL      - 15ef206397e based on jdk-11.0.23+1
02:59:17  
02:59:17  "main" prio=5 Id=1 WAITING
02:59:17    at java.base@11.0.23-internal/java.lang.Object.waitImpl(Native Method)
02:59:17    at java.base@11.0.23-internal/java.lang.Object.wait(Object.java:251)
02:59:17    at java.base@11.0.23-internal/java.lang.Object.wait(Object.java:219)
02:59:17    at java.base@11.0.23-internal/java.lang.Thread.join(Thread.java:766)
02:59:17    at java.base@11.0.23-internal/java.lang.Thread.join(Thread.java:721)
02:59:17    at app//com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:74)
02:59:17  
02:59:17  "JIT Compilation Thread-000" prio=10 Id=3 RUNNABLE
02:59:17  
02:59:17  "JIT Compilation Thread-001 Suspended" prio=10 Id=4 RUNNABLE
02:59:17  
02:59:17  "JIT Compilation Thread-002 Suspended" prio=10 Id=5 RUNNABLE
02:59:17  
02:59:17  "JIT Compilation Thread-003 Suspended" prio=10 Id=6 RUNNABLE
02:59:17  
02:59:17  "JIT Compilation Thread-004 Suspended" prio=10 Id=7 RUNNABLE
02:59:17  
02:59:17  "JIT Compilation Thread-005 Suspended" prio=10 Id=8 RUNNABLE
02:59:17  
02:59:17  "JIT Compilation Thread-006 Suspended" prio=10 Id=9 RUNNABLE
02:59:17  
02:59:17  "JIT Diagnostic Compilation Thread-007 Suspended" prio=10 Id=10 RUNNABLE
02:59:17  
02:59:17  "JIT-SamplerThread" prio=10 Id=11 TIMED_WAITING
02:59:17  
02:59:17  "IProfiler" prio=5 Id=12 RUNNABLE
02:59:17  
02:59:17  "Common-Cleaner" prio=8 Id=2 TIMED_WAITING
02:59:17    at java.base@11.0.23-internal/java.lang.Object.waitImpl(Native Method)
02:59:17    at java.base@11.0.23-internal/java.lang.Object.wait(Object.java:251)
02:59:17    at java.base@11.0.23-internal/java.lang.Object.wait(Object.java:219)
02:59:17    at java.base@11.0.23-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
02:59:17    at java.base@11.0.23-internal/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:148)
02:59:17    at java.base@11.0.23-internal/java.lang.Thread.run(Thread.java:839)
02:59:17    at java.base@11.0.23-internal/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:161)
02:59:17  
02:59:17  "Finalizer thread" prio=5 Id=13 RUNNABLE
02:59:17  
02:59:17  "Concurrent Mark Helper" prio=1 Id=14 RUNNABLE
02:59:17  
02:59:17  "GC Worker" prio=5 Id=15 RUNNABLE
02:59:17  
02:59:17  "GC Worker" prio=5 Id=16 RUNNABLE
02:59:17  
02:59:17  "GC Worker" prio=5 Id=17 RUNNABLE
02:59:17  
02:59:17  "Attach API wait loop" prio=10 Id=20 RUNNABLE
02:59:17    at java.base@11.0.23-internal/openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
02:59:17    at java.base@11.0.23-internal/openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
02:59:17    at java.base@11.0.23-internal/openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
02:59:17    at java.base@11.0.23-internal/openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
02:59:17  
02:59:17  "MainThread" prio=5 Id=22 RUNNABLE
02:59:17    at java.base@11.0.23-internal/java.io.FileInputStream.readBytes(Native Method)
02:59:17    at java.base@11.0.23-internal/java.io.FileInputStream.read(FileInputStream.java:279)
02:59:17    at java.base@11.0.23-internal/java.io.BufferedInputStream.read1(BufferedInputStream.java:290)
02:59:17    at java.base@11.0.23-internal/java.io.BufferedInputStream.read(BufferedInputStream.java:351)
02:59:17    - locked java.lang.ProcessImpl$ProcessPipeInputStream@316333a8
02:59:17    at java.base@11.0.23-internal/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:295)
02:59:17    at java.base@11.0.23-internal/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:337)
02:59:17    at java.base@11.0.23-internal/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:179)
02:59:17    - locked java.io.InputStreamReader@f606d950
02:59:17    at java.base@11.0.23-internal/java.io.InputStreamReader.read(InputStreamReader.java:181)
02:59:17    at java.base@11.0.23-internal/java.io.BufferedReader.fill(BufferedReader.java:161)
02:59:17    at java.base@11.0.23-internal/java.io.BufferedReader.readLine(BufferedReader.java:326)
02:59:17    - locked java.io.InputStreamReader@f606d950
02:59:17    at java.base@11.0.23-internal/java.io.BufferedReader.readLine(BufferedReader.java:392)
02:59:17    at app//LUtils.doExec(LUtils.java:111)
02:59:17    at app//LUtils.doExec(LUtils.java:83)
02:59:17    at app//LambdaAsm.init(LambdaAsm.java:60)
02:59:17    at app//LambdaAsm.main(LambdaAsm.java:183)
02:59:17    at java.base@11.0.23-internal/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
02:59:17    at java.base@11.0.23-internal/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
02:59:17    at java.base@11.0.23-internal/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
02:59:17    at java.base@11.0.23-internal/java.lang.reflect.Method.invoke(Method.java:572)
02:59:17    at app//com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
02:59:17    at java.base@11.0.23-internal/java.lang.Thread.run(Thread.java:839)
02:59:17  
02:59:17  "process reaper (pid 265662)" prio=10 Id=23 RUNNABLE
02:59:17    at java.base@11.0.23-internal/java.lang.ProcessHandleImpl.waitForProcessExit0(Native Method)
02:59:17    at java.base@11.0.23-internal/java.lang.ProcessHandleImpl$1.run(ProcessHandleImpl.java:145)
02:59:17    at java.base@11.0.23-internal/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
02:59:17    at java.base@11.0.23-internal/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
02:59:17    at java.base@11.0.23-internal/java.lang.Thread.run(Thread.java:839)
02:59:17  
02:59:17  "file lock watchdog" prio=10 Id=25 TIMED_WAITING
02:59:17    at java.base@11.0.23-internal/java.lang.Object.waitImpl(Native Method)
02:59:17    at java.base@11.0.23-internal/java.lang.Object.wait(Object.java:251)
02:59:17    at java.base@11.0.23-internal/java.lang.Object.wait(Object.java:219)
02:59:17    at java.base@11.0.23-internal/java.util.TimerThread.mainLoop(Timer.java:592)
02:59:17    at java.base@11.0.23-internal/java.util.TimerThread.run(Timer.java:533)
02:59:17  
02:59:17  "Attachment portNumber: 38385" prio=10 Id=27 RUNNABLE
02:59:17    at java.base@11.0.23-internal/openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
02:59:17    at java.base@11.0.23-internal/openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:249)
02:59:17    at java.base@11.0.23-internal/openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:185)
02:59:17    at java.base@11.0.23-internal/openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:251)
02:59:17    at java.base@11.0.23-internal/openj9.internal.tools.attach.target.Attachment.run(Attachment.java:161)
02:59:17  
02:59:17  
02:59:17  --- Timeout information end.
pshipton commented 8 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/145 - ub20-390-6 jdk_lang_1 java/lang/invoke/lambda/LambdaAsm.java

21:20:06  "MainThread" prio=5 Id=20 RUNNABLE
21:20:06    at java.base@17.0.11-internal/java.io.FileInputStream.readBytes(Native Method)
21:20:06    at java.base@17.0.11-internal/java.io.FileInputStream.read(FileInputStream.java:276)
21:20:06    at java.base@17.0.11-internal/java.io.BufferedInputStream.read1(BufferedInputStream.java:282)
21:20:06    at java.base@17.0.11-internal/java.io.BufferedInputStream.read(BufferedInputStream.java:343)
21:20:06    - locked java.lang.ProcessImpl$ProcessPipeInputStream@5a762449
21:20:06    at java.base@17.0.11-internal/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:281)
21:20:06    at java.base@17.0.11-internal/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:324)
21:20:06    at java.base@17.0.11-internal/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:189)
21:20:06    - locked java.io.InputStreamReader@1e425f08
21:20:06    at java.base@17.0.11-internal/java.io.InputStreamReader.read(InputStreamReader.java:177)
21:20:06    at java.base@17.0.11-internal/java.io.BufferedReader.fill(BufferedReader.java:162)
21:20:06    at java.base@17.0.11-internal/java.io.BufferedReader.readLine(BufferedReader.java:329)
21:20:06    - locked java.io.InputStreamReader@1e425f08
21:20:06    at java.base@17.0.11-internal/java.io.BufferedReader.readLine(BufferedReader.java:396)
21:20:06    at app//LUtils.doExec(LUtils.java:111)
21:20:06    at app//LUtils.doExec(LUtils.java:83)
21:20:06    at app//LambdaAsm.init(LambdaAsm.java:60)
21:20:06    at app//LambdaAsm.main(LambdaAsm.java:183)