search

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.29k stars 723 forks source link

JDK11 AIX jdk_nio_0_FAILED - BasicMulticastTests threw exception: java.util.NoSuchElementException #12795

Open JasonFengJ9 opened 3 years ago

JasonFengJ9 commented 3 years ago

Failure link

From an internal build Test_openjdk11_j9_extended.openjdk_ppc64_aix/13/ (pll011):

java version "11.0.12" 2021-07-20
Java(TM) SE Runtime Environment 11.0.12.0-IBM (build 11.0.12+4)
Eclipse OpenJ9 VM 11.0.12.0-IBM (build master-262b10ca7, JRE 11 AIX ppc64-64-Bit Compressed References 20210528_76 (JIT enabled, AOT enabled)
OpenJ9   - 262b10ca7
OMR      - e358cd0e5
JCL      - 34925c161a based on jdk-11.0.12+4)

Rerun in Grinder

Optional info

Failure output (captured from console output)

[2021-05-29T03:04:29.456Z] Running test jdk_net_0 ...
[2021-05-29T03:04:29.456Z] ===============================================
[2021-05-29T03:04:29.456Z] jdk_net_0 Start Time: Fri May 28 23:04:26 2021 Epoch Time (ms): 1622257466786
[2021-05-29T03:04:29.456Z] "/home/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_ppc64_aix/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:destroyAll; "/home/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_ppc64_aix/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
[2021-05-29T03:04:29.456Z] JVMSHRC005I No shared class caches available
[2021-05-29T03:04:29.456Z] JVMSHRC005I No shared class caches available
[2021-05-29T03:04:29.456Z] cache cleanup done
[2021-05-29T03:04:29.456Z] variation: Mode150
[2021-05-29T03:04:29.456Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2021-05-29T06:43:01.140Z] Running test jdk_nio_0 ...
[2021-05-29T06:43:01.140Z] ===============================================
[2021-05-29T06:43:01.140Z] jdk_nio_0 Start Time: Sat May 29 02:43:00 2021 Epoch Time (ms): 1622270580433
[2021-05-29T06:43:01.140Z] "/home/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_ppc64_aix/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:destroyAll; "/home/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_ppc64_aix/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
[2021-05-29T06:43:01.140Z] JVMSHRC005I No shared class caches available
[2021-05-29T06:43:01.140Z] JVMSHRC005I No shared class caches available
[2021-05-29T06:43:01.140Z] cache cleanup done
[2021-05-29T06:43:01.140Z] variation: Mode150
[2021-05-29T06:43:01.140Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2021-05-29T06:49:02.228Z] STDERR:
[2021-05-29T06:49:02.228Z] java.util.NoSuchElementException
[2021-05-29T06:49:02.228Z]  at java.base/java.util.Spliterators$1Adapter.next(Spliterators.java:688)
[2021-05-29T06:49:02.228Z]  at BasicMulticastTests.main(BasicMulticastTests.java:212)
[2021-05-29T06:49:02.228Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2021-05-29T06:49:02.228Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2021-05-29T06:49:02.228Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2021-05-29T06:49:02.228Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2021-05-29T06:49:02.228Z]  at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:312)
[2021-05-29T06:49:02.228Z]  at java.base/java.lang.Thread.run(Thread.java:861)
[2021-05-29T06:49:02.228Z] 
[2021-05-29T06:49:02.228Z] JavaTest Message: Test threw exception: java.util.NoSuchElementException
[2021-05-29T06:49:02.228Z] JavaTest Message: shutting down test
[2021-05-29T06:49:02.228Z] 
[2021-05-29T06:49:02.228Z] 
[2021-05-29T06:49:02.228Z] TEST RESULT: Failed. Execution failed: `main' threw exception: java.util.NoSuchElementException
[2021-05-29T06:49:02.228Z] --------------------------------------------------
[2021-05-29T07:13:51.046Z] Test results: passed: 384; failed: 1
[2021-05-29T07:13:52.495Z] Report written to /home/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_ppc64_aix/jvmtest/openjdk/report/html/report.html
[2021-05-29T07:13:52.495Z] Results written to /home/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_ppc64_aix/openjdk-tests/TKG/output_16222554973820/jdk_nio_0/work
[2021-05-29T07:13:52.495Z] Error: Some tests failed or other problems occurred.
[2021-05-29T07:13:52.495Z] 
[2021-05-29T07:13:52.495Z] jdk_nio_0_FAILED

Might be related failures:

Test_openjdk11_j9_extended.openjdk_ppc64_aix/13/ (pll011):

[2021-05-29T04:42:20.980Z] java.util.NoSuchElementException: No value present
[2021-05-29T04:42:20.980Z]  at java.base/java.util.Optional.get(Optional.java:148)
[2021-05-29T04:42:20.980Z]  at SocketPermissionTest.joinGroupMulticastTest(SocketPermissionTest.java:224)
[2021-05-29T04:42:20.980Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2021-05-29T04:42:20.980Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2021-05-29T04:42:20.980Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2021-05-29T04:42:20.980Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2021-05-29T04:42:20.980Z]  at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:85)
[2021-05-29T04:42:20.980Z]  at org.testng.internal.Invoker.invokeMethod(Invoker.java:639)
[2021-05-29T04:42:20.980Z]  at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:821)
[2021-05-29T04:42:20.980Z]  at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1131)
[2021-05-29T04:42:20.980Z]  at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125)
[2021-05-29T04:42:20.980Z]  at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:108)
[2021-05-29T04:42:20.980Z]  at org.testng.TestRunner.privateRun(TestRunner.java:773)
[2021-05-29T04:42:20.980Z]  at org.testng.TestRunner.run(TestRunner.java:623)
[2021-05-29T04:42:20.980Z]  at org.testng.SuiteRunner.runTest(SuiteRunner.java:357)
[2021-05-29T04:42:20.980Z]  at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:352)
[2021-05-29T04:42:20.980Z]  at org.testng.SuiteRunner.privateRun(SuiteRunner.java:310)
[2021-05-29T04:42:20.980Z]  at org.testng.SuiteRunner.run(SuiteRunner.java:259)
[2021-05-29T04:42:20.980Z]  at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
[2021-05-29T04:42:20.980Z]  at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
[2021-05-29T04:42:20.980Z]  at org.testng.TestNG.runSuitesSequentially(TestNG.java:1185)
[2021-05-29T04:42:20.980Z]  at org.testng.TestNG.runSuitesLocally(TestNG.java:1110)
[2021-05-29T04:42:20.980Z]  at org.testng.TestNG.run(TestNG.java:1018)
[2021-05-29T04:42:20.980Z]  at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:94)
[2021-05-29T04:42:20.980Z]  at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:54)
[2021-05-29T04:42:20.980Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2021-05-29T04:42:20.980Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2021-05-29T04:42:20.980Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2021-05-29T04:42:20.980Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2021-05-29T04:42:20.980Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2021-05-29T04:42:20.980Z]  at java.base/java.lang.Thread.run(Thread.java:861)
[2021-05-29T04:42:20.980Z] config SocketPermissionTest.setupSecurityManager(): success
[2021-05-29T04:42:20.980Z] test SocketPermissionTest.listenDatagramSocketTest(): success
[2021-05-29T04:42:20.980Z] config SocketPermissionTest.setupSecurityManager(): success
[2021-05-29T04:42:20.980Z] test SocketPermissionTest.listenMulticastSocketTest(): success
[2021-05-29T04:42:20.981Z] config SocketPermissionTest.setupSecurityManager(): success
[2021-05-29T04:42:20.981Z] test SocketPermissionTest.listenServerSocketTest(): success
[2021-05-29T04:42:20.981Z] config SocketPermissionTest.setupSecurityManager(): success
[2021-05-29T04:42:20.981Z] test SocketPermissionTest.sendDatagramPacketTest(): success
[2021-05-29T04:42:20.981Z] 
[2021-05-29T04:42:20.981Z] ===============================================
[2021-05-29T04:42:20.981Z] java/net/SocketPermission/SocketPermissionTest.java
[2021-05-29T04:42:20.981Z] Total tests run: 8, Failures: 1, Skips: 0
[2021-05-29T04:42:20.981Z] ===============================================

[2021-05-29T04:53:44.627Z] jdk_net_0_FAILED

Rerun in Grinder

pshipton commented 3 years ago

Does this normally pass, or is it a new test? If it's not new, can the failure be repeated?

JasonFengJ9 commented 3 years ago

Does this normally pass, or is it a new test? If it's not new, can the failure be repeated?

This is a weekly run, not new, it did pass, also failed with other errors such as timeout. JDK8/16/17 same tests appear intermittent timeout error, JDK11 as per this issue recently hit NoSuchElementException (last pass was April 23, first failure was May 7th) Created this issue to track the exception, and need triage to determine if it is network related.

pshipton commented 3 years ago

May also be machine related, getting different behavior on different machines.

JasonFengJ9 commented 3 years ago

Another occurrence at Test_openjdk11_j9_extended.openjdk_ppc64_aix/17/ (paix818)

[2021-06-19T02:56:10.266Z] Running test jdk_net_0 ...
[2021-06-19T02:56:10.266Z] ===============================================
[2021-06-19T02:56:10.266Z] jdk_net_0 Start Time: Fri Jun 18 22:56:08 2021 Epoch Time (ms): 1624071368774
[2021-06-19T02:56:10.267Z] "/home/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_ppc64_aix/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:destroyAll; "/home/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_ppc64_aix/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
[2021-06-19T02:56:10.267Z] JVMSHRC005I No shared class caches available
[2021-06-19T02:56:10.267Z] JVMSHRC005I No shared class caches available
[2021-06-19T02:56:10.267Z] cache cleanup done
[2021-06-19T02:56:10.267Z] variation: Mode150
[2021-06-19T02:56:10.267Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2021-06-19T04:33:57.270Z] test SocketPermissionTest.joinGroupMulticastTest(): failure
[2021-06-19T04:33:57.270Z] java.util.NoSuchElementException: No value present
[2021-06-19T04:33:57.270Z]  at java.base/java.util.Optional.get(Optional.java:148)
[2021-06-19T04:33:57.270Z]  at SocketPermissionTest.joinGroupMulticastTest(SocketPermissionTest.java:224)
[2021-06-19T04:33:57.270Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2021-06-19T04:33:57.270Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2021-06-19T04:33:57.270Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2021-06-19T04:33:57.270Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2021-06-19T04:33:57.270Z]  at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:85)
[2021-06-19T04:33:57.270Z]  at org.testng.internal.Invoker.invokeMethod(Invoker.java:639)
[2021-06-19T04:33:57.270Z]  at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:821)
[2021-06-19T04:33:57.270Z]  at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1131)
[2021-06-19T04:33:57.270Z]  at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125)
[2021-06-19T04:33:57.270Z]  at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:108)
[2021-06-19T04:33:57.270Z]  at org.testng.TestRunner.privateRun(TestRunner.java:773)
[2021-06-19T04:33:57.270Z]  at org.testng.TestRunner.run(TestRunner.java:623)
[2021-06-19T04:33:57.270Z]  at org.testng.SuiteRunner.runTest(SuiteRunner.java:357)
[2021-06-19T04:33:57.270Z]  at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:352)
[2021-06-19T04:33:57.270Z]  at org.testng.SuiteRunner.privateRun(SuiteRunner.java:310)
[2021-06-19T04:33:57.270Z]  at org.testng.SuiteRunner.run(SuiteRunner.java:259)
[2021-06-19T04:33:57.270Z]  at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
[2021-06-19T04:33:57.270Z]  at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
[2021-06-19T04:33:57.270Z]  at org.testng.TestNG.runSuitesSequentially(TestNG.java:1185)
[2021-06-19T04:33:57.270Z]  at org.testng.TestNG.runSuitesLocally(TestNG.java:1110)
[2021-06-19T04:33:57.270Z]  at org.testng.TestNG.run(TestNG.java:1018)
[2021-06-19T04:33:57.270Z]  at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:94)
[2021-06-19T04:33:57.270Z]  at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:54)
[2021-06-19T04:33:57.270Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2021-06-19T04:33:57.270Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2021-06-19T04:33:57.270Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2021-06-19T04:33:57.270Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2021-06-19T04:33:57.270Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2021-06-19T04:33:57.270Z]  at java.base/java.lang.Thread.run(Thread.java:866)

Rerun in Grinder

JasonFengJ9 commented 3 years ago

Just note this is seen in JDK11 0.27 release build Test_openjdk11_j9_extended.openjdk_ppc64_aix/22/ (paix817).