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

jdk17+ jdk_util_0_FAILED java/util/stream/test/org/openjdk/tests/java/util/stream/CountLargeTest.java - java timed out #15164

Closed JasonFengJ9 closed 2 years ago

JasonFengJ9 commented 2 years ago

Failure link

From an internal build job/Test_openjdknext_j9_sanity.openjdk_aarch64_linux_Personal/2/consoleFull(ub18-aarch64-4):

12:36:01  openjdk version "19-internal" 2022-09-20
12:36:01  OpenJDK Runtime Environment (build 19-internal-adhoc.jenkins.BuildJDKnextaarch64linuxPersonal)
12:36:01  Eclipse OpenJ9 VM (build loom_patch-1e7a31c30d4, JRE 19 Linux aarch64-64-Bit Compressed References 20220531_28 (JIT enabled, AOT enabled)
12:36:01  OpenJ9   - 1e7a31c30d4
12:36:01  OMR      - e542d083538
12:36:01  JCL      - a66f9edf71a based on jdk-19+24)

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

Optional info

Failure output (captured from console output)

14:11:07  TEST: java/util/stream/test/org/openjdk/tests/java/util/stream/CountLargeTest.java

14:11:07  ACTION: testng -- Error. Program `/home/jenkins/workspace/Test_openjdknext_j9_sanity.openjdk_aarch64_linux_Personal/openjdkbinary/j2sdk-image/bin/java' timed out (timeout set to 960000ms, elapsed time including timeout handling was 964561ms).

14:11:07  TEST RESULT: Error. test was interrupted! (timeout?)

14:11:10  jdk_util_1_FAILED

Need triage if it was a hang. Not seen in other platform.

jdk_util_0

14:11:07  "MainThread" prio=5 Id=27 RUNNABLE
14:11:07    at java.base@19-internal/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
14:11:07    at java.base@19-internal/java.util.stream.LongPipeline$1$1.accept(LongPipeline.java:177)
14:11:07    at java.base@19-internal/java.util.stream.Streams$RangeLongSpliterator.forEachRemaining(Streams.java:233)
14:11:07    at java.base@19-internal/java.util.Spliterator$OfLong.forEachRemaining(Spliterator.java:775)
14:11:07    at java.base@19-internal/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:522)
14:11:07    at java.base@19-internal/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:512)
14:11:07    at java.base@19-internal/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921)
14:11:07    at java.base@19-internal/java.util.stream.ReduceOps$5.evaluateSequential(ReduceOps.java:258)
14:11:07    at java.base@19-internal/java.util.stream.ReduceOps$5.evaluateSequential(ReduceOps.java:248)
14:11:07    at java.base@19-internal/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:239)
14:11:07    at java.base@19-internal/java.util.stream.ReferencePipeline.count(ReferencePipeline.java:709)
14:11:07    at app//org.openjdk.tests.java.util.stream.CountLargeTest.testRefLarge(CountLargeTest.java:53)
...
14:11:07  test org.openjdk.tests.java.util.stream.CountLargeTest.testDoubleLarge(): success
14:11:07  test org.openjdk.tests.java.util.stream.CountLargeTest.testIntLarge(): success
14:11:07  test org.openjdk.tests.java.util.stream.CountLargeTest.testLongLarge(): success

jdk_util_1

14:11:07  "MainThread" prio=5 Id=27 RUNNABLE
14:11:07    at java.base@19-internal/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
14:11:07    at java.base@19-internal/java.util.stream.LongPipeline$1$1.accept(LongPipeline.java:177)
14:11:07    at java.base@19-internal/java.util.stream.Streams$RangeLongSpliterator.forEachRemaining(Streams.java:233)
14:11:07    at java.base@19-internal/java.util.Spliterator$OfLong.forEachRemaining(Spliterator.java:775)
14:11:07    at java.base@19-internal/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:522)
14:11:07    at java.base@19-internal/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:512)
14:11:07    at java.base@19-internal/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921)
14:11:07    at java.base@19-internal/java.util.stream.ReduceOps$5.evaluateSequential(ReduceOps.java:258)
14:11:07    at java.base@19-internal/java.util.stream.ReduceOps$5.evaluateSequential(ReduceOps.java:248)
14:11:07    at java.base@19-internal/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:239)
14:11:07    at java.base@19-internal/java.util.stream.ReferencePipeline.count(ReferencePipeline.java:709)
14:11:07    at app//org.openjdk.tests.java.util.stream.CountLargeTest.testRefLarge(CountLargeTest.java:53)
...
14:11:07  test org.openjdk.tests.java.util.stream.CountLargeTest.testDoubleLarge(): success
14:11:07  test org.openjdk.tests.java.util.stream.CountLargeTest.testIntLarge(): success
14:11:07  test org.openjdk.tests.java.util.stream.CountLargeTest.testLongLarge(): success
JasonFengJ9 commented 2 years ago

This might not be Loom related, to be triaged.

JasonFengJ9 commented 2 years ago

Also observed at JDK17 0.33.0 m1 aarch64_linux

job/Test_openjdk17_j9_sanity.openjdk_aarch64_linux_testList_0/126/(cent7-aarch64-4) jdk_util_0

openjdk version "17.0.4" 2022-07-19
IBM Semeru Runtime Open Edition 17.0.4.0-m1 (build 17.0.4+3)
Eclipse OpenJ9 VM 17.0.4.0-m1 (build v0.33.0-release-c9a377390, JRE 17 Linux aarch64-64-Bit Compressed References 20220601_180 (JIT enabled, AOT enabled)
OpenJ9   - c9a377390
OMR      - 942daf672
JCL      - 02c2140051b based on jdk-17.0.4+3)

[2022-06-01T19:29:10.334Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache Mode150
[2022-06-01T19:29:10.334Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:+UseCompressedOops 

[2022-06-01T19:57:36.089Z] TEST: java/util/stream/test/org/openjdk/tests/java/util/stream/CountLargeTest.java

[2022-06-01T19:57:36.091Z] TEST RESULT: Error. Program `/home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_linux_testList_0/openjdkbinary/j2sdk-image/bin/java' timed out (timeout set to 960000ms, elapsed time including timeout handling was 964180ms).
[2022-06-01T19:57:36.091Z] --------------------------------------------------
[2022-06-01T19:57:36.091Z] Test results: passed: 892; error: 1
[2022-06-01T19:57:50.696Z] Report written to /home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_linux_testList_0/jvmtest/openjdk/report/html/report.html
[2022-06-01T19:57:50.696Z] Results written to /home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_linux_testList_0/aqa-tests/TKG/output_16541099337591/jdk_util_0/work
[2022-06-01T19:57:50.696Z] Error: Some tests failed or other problems occurred.
[2022-06-01T19:57:50.696Z] 
[2022-06-01T19:57:50.696Z] jdk_util_0_FAILED
15:57:36  "MainThread" prio=5 Id=26 RUNNABLE
15:57:36    at java.base@17.0.4/java.util.stream.Streams$RangeLongSpliterator.forEachRemaining(Streams.java:233)
15:57:36    at java.base@17.0.4/java.util.Spliterator$OfLong.forEachRemaining(Spliterator.java:775)
15:57:36    at java.base@17.0.4/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:522)
15:57:36    at java.base@17.0.4/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:512)
15:57:36    at java.base@17.0.4/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921)
15:57:36    at java.base@17.0.4/java.util.stream.ReduceOps$5.evaluateSequential(ReduceOps.java:258)
15:57:36    at java.base@17.0.4/java.util.stream.ReduceOps$5.evaluateSequential(ReduceOps.java:248)
15:57:36    at java.base@17.0.4/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:239)
15:57:36    at java.base@17.0.4/java.util.stream.ReferencePipeline.count(ReferencePipeline.java:709)
15:57:36    at app//org.openjdk.tests.java.util.stream.CountLargeTest.testRefLarge(CountLargeTest.java:53)
...
15:57:36  test org.openjdk.tests.java.util.stream.CountLargeTest.testDoubleLarge(): success
15:57:36  test org.openjdk.tests.java.util.stream.CountLargeTest.testIntLarge(): success
15:57:36  test org.openjdk.tests.java.util.stream.CountLargeTest.testLongLarge(): success

50x grinder - job/Grinder/24474/ - passed

pshipton commented 2 years ago

I opened a separate issue for timeouts in this test on alinux in the openj9 nightly builds last night. I was blaming it on a machine change, as last night we are running on OSU machines which are much slower than the alinux machines we usually run on. https://github.com/eclipse-openj9/openj9/issues/15198

Also related is https://github.com/ibmruntimes/openj9-openjdk-jdk/pull/450 to get a javacore in addition to the core we already get on timeout.

pshipton commented 2 years ago

@JasonFengJ9 https://github.com/eclipse-openj9/openj9/issues/15164#issuecomment-1145223447 doesn't have a build link or machine.

JasonFengJ9 commented 2 years ago

https://github.com/eclipse-openj9/openj9/issues/15164#issuecomment-1145223447 doesn't have a build link or machine.

Added.

pshipton commented 2 years ago

Closing this as a dup of https://github.com/eclipse-openj9/openj9/issues/15198, in which there is more discussion of the problem and a reference to a potential fix.