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 722 forks source link

java/rmi/server/Unreferenced/leaseCheckInterval/LeaseCheckInterval.java - TEST FAILED: unreferenced() not invoked after 20.0 seconds #12948

Open JasonFengJ9 opened 3 years ago

JasonFengJ9 commented 3 years ago

Failure link

From an internal build Test_openjdk11_j9_extended.openjdk_x86-64_windows/16/ (win16x64cudart1):

openjdk version "11.0.12" 2021-07-20
OpenJDK Runtime Environment Semeru-11.0.12.0-m1 (build 11.0.12+5)
Eclipse OpenJ9 VM Semeru-11.0.12.0-m1 (build v0.27.0-release-3309d95fa, JRE 11 Windows Server 2016 amd64-64-Bit Compressed References 20210613_132 (JIT enabled, AOT enabled)
OpenJ9   - 3309d95fa
OMR      - 4ed9b9de5
JCL      - a4db72eb0f based on jdk-11.0.12+5)

Rerun in Grinder

Optional info

Failure output (captured from console output)

[2021-06-13T10:16:03.226Z] Running test jdk_rmi_0 ...
[2021-06-13T10:16:03.226Z] ===============================================
[2021-06-13T10:16:03.226Z] jdk_rmi_0 Start Time: Sun Jun 13 06:15:45 2021 Epoch Time (ms): 1623579345530
[2021-06-13T10:16:03.226Z] "C:/Users/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_x86-64_windows/openjdkbinary/j2sdk-image\\bin\\java" -Xshareclasses:destroyAll; "C:/Users/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_x86-64_windows/openjdkbinary/j2sdk-image\\bin\\java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
[2021-06-13T10:16:04.026Z] 
[2021-06-13T10:16:04.026Z] Attempting to destroy all caches in cacheDir C:\Users\jenkins\AppData\Local\javasharedresources\
[2021-06-13T10:16:04.026Z] 
[2021-06-13T10:16:04.026Z] JVMSHRC241E Error: unable to delete shared class cache file
[2021-06-13T10:16:04.026Z] JVMSHRC336E Port layer error code = -100
[2021-06-13T10:16:04.026Z] JVMSHRC337E Platform error message: (32) The process cannot access the file because it is being used by another process.
[2021-06-13T10:16:04.026Z] JVMSHRC430I Failed to remove current generation of shared class cache "sharedcc_jenkins"
[2021-06-13T10:16:04.026Z] JVMSHRC241E Error: unable to delete shared class cache file
[2021-06-13T10:16:04.026Z] JVMSHRC336E Port layer error code = -100
[2021-06-13T10:16:04.026Z] JVMSHRC337E Platform error message: (32) The process cannot access the file because it is being used by another process.
[2021-06-13T10:16:04.026Z] JVMSHRC430I Failed to remove current generation of shared class cache "sharedcc_jenkins"
[2021-06-13T10:16:04.026Z] 
[2021-06-13T10:16:04.026Z] Attempting to destroy all caches in cacheDir C:\Users\jenkins\AppData\Local\javasharedresources\
[2021-06-13T10:16:04.026Z] 
[2021-06-13T10:16:04.026Z] JVMSHRC241E Error: unable to delete shared class cache file
[2021-06-13T10:16:04.026Z] JVMSHRC336E Port layer error code = -100
[2021-06-13T10:16:04.026Z] JVMSHRC337E Platform error message: (32) The process cannot access the file because it is being used by another process.
[2021-06-13T10:16:04.026Z] JVMSHRC430I Failed to remove current generation of shared class cache "sharedcc_jenkins"
[2021-06-13T10:16:04.026Z] JVMSHRC241E Error: unable to delete shared class cache file
[2021-06-13T10:16:04.026Z] JVMSHRC336E Port layer error code = -100
[2021-06-13T10:16:04.026Z] JVMSHRC337E Platform error message: (32) The process cannot access the file because it is being used by another process.
[2021-06-13T10:16:04.027Z] JVMSHRC430I Failed to remove current generation of shared class cache "sharedcc_jenkins"
[2021-06-13T10:16:04.027Z] cache cleanup done
[2021-06-13T10:16:04.027Z] variation: Mode150
[2021-06-13T10:16:04.027Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2021-06-13T10:37:52.205Z] JAVAVM: command = [C:\Users\jenkins\workspace\Test_openjdk11_j9_extended.openjdk_x86-64_windows\openjdkbinary\j2sdk-image\bin\java, -ea, -esa, -Xmx512m, -XX:+UseCompressedOops, -Drmi.registry.port=64389, SelfTerminator]
[2021-06-13T10:37:52.205Z] waiting for unreferenced() callback...
[2021-06-13T10:37:52.205Z] java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds
[2021-06-13T10:37:52.205Z]  at LeaseCheckInterval.main(LeaseCheckInterval.java:111)
[2021-06-13T10:37:52.205Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2021-06-13T10:37:52.205Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2021-06-13T10:37:52.205Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2021-06-13T10:37:52.205Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2021-06-13T10:37:52.205Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2021-06-13T10:37:52.205Z]  at java.base/java.lang.Thread.run(Thread.java:866)
[2021-06-13T10:37:52.205Z] 
[2021-06-13T10:37:52.205Z] JavaTest Message: Test threw exception: java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds
[2021-06-13T10:37:52.205Z] JavaTest Message: shutting down test
[2021-06-13T10:37:52.205Z] 
[2021-06-13T10:37:52.205Z] STATUS:Failed.`main' threw exception: java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds

[2021-06-13T10:41:23.156Z] jdk_rmi_0_FAILED

This might be network related though there was an error Port layer error code = -100 at setup stage.

JasonFengJ9 commented 1 year ago

JDK11 0.36 build(win10x86-rt1-1)

openjdk version "11.0.18" 2023-01-17
IBM Semeru Runtime Open Edition 11.0.18.0 (build 11.0.18+10)
Eclipse OpenJ9 VM 11.0.18.0 (build openj9-0.36.0, JRE 11 Windows 10 amd64-64-Bit Compressed References 20230207_562 (JIT enabled, AOT enabled)
OpenJ9   - e68fb241f
OMR      - f491bbf6f
JCL      - b732de1eee based on jdk-11.0.18+10)

[2023-02-10T16:45:18.396Z] variation: Mode150
[2023-02-10T16:45:18.801Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2023-02-10T17:30:12.840Z] TEST: java/rmi/server/Unreferenced/leaseCheckInterval/LeaseCheckInterval.java

[2023-02-10T17:30:12.842Z] STDERR:
[2023-02-10T17:30:12.842Z] 
[2023-02-10T17:30:12.842Z] Regression test for bug 4285878
[2023-02-10T17:30:12.842Z] 
[2023-02-10T17:30:12.842Z] exported remote object
[2023-02-10T17:30:12.842Z] created local registry
[2023-02-10T17:30:12.842Z] bound remote object in local registry
[2023-02-10T17:30:12.842Z] starting remote client VM...
[2023-02-10T17:30:12.842Z] JAVAVM: command = [C:\Users\jenkins\workspace\Test_openjdk11_j9_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image\bin\java, -ea, -esa, -Xmx512m, -XX:+UseCompressedOops, -Drmi.registry.port=52994, SelfTerminator]
[2023-02-10T17:30:12.842Z] waiting for unreferenced() callback...
[2023-02-10T17:30:12.842Z] java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds
[2023-02-10T17:30:12.842Z]  at LeaseCheckInterval.main(LeaseCheckInterval.java:111)
[2023-02-10T17:30:12.842Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-02-10T17:30:12.842Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2023-02-10T17:30:12.842Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-02-10T17:30:12.842Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2023-02-10T17:30:12.842Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2023-02-10T17:30:12.842Z]  at java.base/java.lang.Thread.run(Thread.java:839)
[2023-02-10T17:30:12.842Z] 
[2023-02-10T17:30:12.842Z] JavaTest Message: Test threw exception: java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds

[2023-02-10T17:38:28.726Z] jdk_rmi_0_FAILED

50x grinder - 19/49 failed

pshipton commented 1 year ago

The failures are all on the following, where every test failed on these machines. Similarly to https://github.ibm.com/runtimes/backlog/issues/1024 win10x86-rt3-1.fyre.ibm.com win10x86-rt4-1.fyre.ibm.com

JasonFengJ9 commented 1 year ago

Adoptium JDK11 jdk_rmi_0 50x grinder

pshipton commented 1 year ago

The grinder failed to run since the JDK_IMPL was set to openj9. I've restarted it

JasonFengJ9 commented 1 year ago

JDK11 Adoptium failed as well.

15:36:30  openjdk version "11.0.18" 2023-01-17
15:36:30  OpenJDK Runtime Environment Temurin-11.0.18+10 (build 11.0.18+10)
15:36:30  OpenJDK 64-Bit Server VM Temurin-11.0.18+10 (build 11.0.18+10, mixed mode)

16:29:46  STDERR:
16:29:46  
16:29:46  Regression test for bug 4285878
16:29:46  
16:29:46  exported remote object
16:29:46  created local registry
16:29:46  bound remote object in local registry
16:29:46  starting remote client VM...
16:29:46  JAVAVM: command = [C:\Users\jenkins\workspace\Grinder_iteration_0\openjdkbinary\j2sdk-image\bin\java, -ea, -esa, -Xmx512m, -XX:+UseCompressedOops, -Drmi.registry.port=55597, SelfTerminator]
16:29:46  waiting for unreferenced() callback...
16:29:46  java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds
16:29:46    at LeaseCheckInterval.main(LeaseCheckInterval.java:111)
16:29:46    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
16:29:46    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
16:29:46    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
16:29:46    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
16:29:46    at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
16:29:46    at java.base/java.lang.Thread.run(Thread.java:829)
16:29:46  
16:29:46  JavaTest Message: Test threw exception: java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds

This seems a machine/network issue.

JasonFengJ9 commented 1 year ago

JDK11 x86-64_windows rc1(win19x64-fips1-1)

[2023-07-20T07:00:24.391Z] variation: Mode150
[2023-07-20T07:00:24.788Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2023-07-20T07:38:33.222Z] TEST: java/rmi/server/Unreferenced/leaseCheckInterval/LeaseCheckInterval.java

[2023-07-20T07:38:33.223Z] STDERR:
[2023-07-20T07:38:33.223Z] 
[2023-07-20T07:38:33.223Z] Regression test for bug 4285878
[2023-07-20T07:38:33.223Z] 
[2023-07-20T07:38:33.223Z] exported remote object
[2023-07-20T07:38:33.223Z] created local registry
[2023-07-20T07:38:33.223Z] bound remote object in local registry
[2023-07-20T07:38:33.223Z] starting remote client VM...
[2023-07-20T07:38:33.223Z] JAVAVM: command = [C:\Users\jenkins\workspace\Test_openjdk11_j9_extended.openjdk_x86-64_windows\openjdkbinary\j2sdk-image\bin\java, -ea, -esa, -Xmx512m, -XX:+UseCompressedOops, -Drmi.registry.port=58913, SelfTerminator]
[2023-07-20T07:38:33.223Z] waiting for unreferenced() callback...
[2023-07-20T07:38:33.223Z] java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds
[2023-07-20T07:38:33.223Z]  at LeaseCheckInterval.main(LeaseCheckInterval.java:111)
[2023-07-20T07:38:33.223Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-07-20T07:38:33.223Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2023-07-20T07:38:33.223Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-07-20T07:38:33.223Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2023-07-20T07:38:33.223Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2023-07-20T07:38:33.223Z]  at java.base/java.lang.Thread.run(Thread.java:839)
[2023-07-20T07:38:33.223Z] 
[2023-07-20T07:38:33.223Z] JavaTest Message: Test threw exception: java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds

[2023-07-20T07:45:36.711Z] jdk_rmi_0_FAILED
JasonFengJ9 commented 1 year ago

JDK17 x86-64_windows 0.40.0 rc1(win10x86-rt1-1)

[2023-08-03T11:21:52.688Z] variation: Mode150
[2023-08-03T11:21:53.070Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2023-08-03T11:41:33.610Z] TEST: java/rmi/server/Unreferenced/leaseCheckInterval/LeaseCheckInterval.java

[2023-08-03T11:41:33.612Z] STDERR:
[2023-08-03T11:41:33.612Z] 
[2023-08-03T11:41:33.612Z] Regression test for bug 4285878
[2023-08-03T11:41:33.612Z] 
[2023-08-03T11:41:33.612Z] exported remote object
[2023-08-03T11:41:33.612Z] created local registry
[2023-08-03T11:41:33.612Z] bound remote object in local registry
[2023-08-03T11:41:33.612Z] starting remote client VM...
[2023-08-03T11:41:33.612Z] JAVAVM: command = [C:\Users\jenkins\workspace\Test_openjdk17_j9_extended.openjdk_x86-64_windows_testList_4\openjdkbinary\j2sdk-image\bin\java, -ea, -esa, -Xmx512m, -XX:+UseCompressedOops, -Drmi.registry.port=51405, SelfTerminator]
[2023-08-03T11:41:33.612Z] waiting for unreferenced() callback...
[2023-08-03T11:41:33.612Z] java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds
[2023-08-03T11:41:33.612Z]  at LeaseCheckInterval.main(LeaseCheckInterval.java:111)
[2023-08-03T11:41:33.612Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-08-03T11:41:33.612Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[2023-08-03T11:41:33.612Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-08-03T11:41:33.612Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:568)
[2023-08-03T11:41:33.612Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2023-08-03T11:41:33.612Z]  at java.base/java.lang.Thread.run(Thread.java:857)
[2023-08-03T11:41:33.612Z] 
[2023-08-03T11:41:33.612Z] JavaTest Message: Test threw exception: java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds

[2023-08-03T11:41:33.614Z] TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds
[2023-08-03T11:41:33.614Z] --------------------------------------------------
[2023-08-03T11:48:01.386Z] Test results: passed: 85; failed: 2
[2023-08-03T11:48:36.346Z] Report written to C:\Users\jenkins\workspace\Test_openjdk17_j9_extended.openjdk_x86-64_windows_testList_4\aqa-tests\TKG\output_16910382292215\jdk_rmi_0\report\html\report.html
[2023-08-03T11:48:36.346Z] Results written to C:\Users\jenkins\workspace\Test_openjdk17_j9_extended.openjdk_x86-64_windows_testList_4\aqa-tests\TKG\output_16910382292215\jdk_rmi_0\work
[2023-08-03T11:48:36.346Z] Error: Some tests failed or other problems occurred.
[2023-08-03T11:48:36.346Z] -----------------------------------
[2023-08-03T11:48:36.346Z] jdk_rmi_0_FAILED
JasonFengJ9 commented 7 months ago

JDK11 x86-64_windows(win22x86-svl-rt3-1)

openjdk version "11.0.23" 2024-04-16
IBM Semeru Runtime Open Edition 11.0.23.0-m1 (build 11.0.23+6)
Eclipse OpenJ9 VM 11.0.23.0-m1 (build v0.44.0-release-747f86c91, JRE 11 Windows Server 2022 amd64-64-Bit Compressed References 20240319_865 (JIT enabled, AOT enabled)
OpenJ9   - 747f86c91
OMR      - 254af5a04
JCL      - b59f8e52b5 based on jdk-11.0.23+6)

[2024-03-20T21:48:47.790Z] variation: Mode150
[2024-03-20T21:48:47.790Z] JVM_OPTIONS:  -XX:+UseCompressedOops -Xverbosegclog 

[2024-03-20T22:21:55.344Z] TEST: java/rmi/server/Unreferenced/leaseCheckInterval/LeaseCheckInterval.java
[2024-03-20T22:21:55.345Z] STDERR:
[2024-03-20T22:21:55.345Z] 
[2024-03-20T22:21:55.345Z] Regression test for bug 4285878
[2024-03-20T22:21:55.345Z] 
[2024-03-20T22:21:55.345Z] exported remote object
[2024-03-20T22:21:55.345Z] created local registry
[2024-03-20T22:21:55.345Z] bound remote object in local registry
[2024-03-20T22:21:55.345Z] starting remote client VM...
[2024-03-20T22:21:55.345Z] JAVAVM: command = [C:\Users\jenkins\workspace\Test_openjdk11_j9_extended.openjdk_x86-64_windows_testList_0\jdkbinary\j2sdk-image\bin\java, -ea, -esa, -Xmx512m, -XX:+UseCompressedOops, -Xverbosegclog, -Drmi.registry.port=57891, SelfTerminator]
[2024-03-20T22:21:55.345Z] waiting for unreferenced() callback...
[2024-03-20T22:21:55.345Z] java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds
[2024-03-20T22:21:55.345Z]  at LeaseCheckInterval.main(LeaseCheckInterval.java:111)

[2024-03-20T22:29:16.601Z] jdk_rmi_0_FAILED

@llxia @annaibm could you help exclude this test for all Java versions on x86-64_windows?

annaibm commented 7 months ago

PR for excluding java/rmi/server/Unreferenced/leaseCheckInterval/LeaseCheckInterval.java test for all java versions on x86-64_windows. https://github.com/adoptium/aqa-tests/pull/5171

JasonFengJ9 commented 3 months ago

JDK22 x86-64_linux_fips140_3(ubu22x86-rtp-rt9-1)

openjdk version "22.0.2" 2024-07-16
IBM Semeru Runtime Open Edition 22.0.2.0-rc2 (build 22.0.2+9)
Eclipse OpenJ9 VM 22.0.2.0-rc2 (build v0.46.0-release-1a6f6128aa, JRE 22 Linux amd64-64-Bit Compressed References 20240716_19 (JIT enabled, AOT enabled)
OpenJ9   - 1a6f6128aa
OMR      - 840a9adba
JCL      - cfe2b5689d1 based on jdk-22.0.2+9)

[2024-07-27T01:48:42.068Z] variation: Mode650
[2024-07-27T01:48:42.068Z] JVM_OPTIONS:  -XX:-UseCompressedOops -Xverbosegclog  -Dsemeru.fips=true -Dsemeru.customprofile=OpenJCEPlusFIPS

[2024-07-27T02:02:03.717Z] TEST: java/rmi/server/Unreferenced/leaseCheckInterval/LeaseCheckInterval.java

[2024-07-27T02:02:03.719Z] starting remote client VM...
[2024-07-27T02:02:03.719Z] JAVAVM: command = [/home/jenkins/workspace/Test_openjdk22_j9_extended.openjdk_x86-64_linux_fips140_3_openjceplusfips_testList_1/jdkbinary/j2sdk-image/bin/java, -ea, -esa, -Xmx512m, -XX:-UseCompressedOops, -Xverbosegclog, -Dsemeru.fips=true, -Dsemeru.customprofile=OpenJCEPlusFIPS, -Drmi.registry.port=37503, SelfTerminator]
[2024-07-27T02:02:03.719Z] waiting for unreferenced() callback...
[2024-07-27T02:02:03.719Z] java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds
[2024-07-27T02:02:03.719Z]  at LeaseCheckInterval.main(LeaseCheckInterval.java:111)
[2024-07-27T02:02:03.719Z]  at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
[2024-07-27T02:02:03.719Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:586)
[2024-07-27T02:02:03.719Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
[2024-07-27T02:02:03.719Z]  at java.base/java.lang.Thread.run(Thread.java:1582)
[2024-07-27T02:02:03.719Z] 
[2024-07-27T02:02:03.719Z] JavaTest Message: Test threw exception: java.lang.RuntimeException: TEST FAILED: unreferenced() not invoked after 20.0 seconds

[2024-07-27T02:06:27.601Z] jdk_rmi_1_FAILED