jtreg java/lang/invoke/VarHandles/VarHandleTestAccess Unexpected exit from test [exit code: 137] #13368

pshipton · 2021-08-24T11:37:42Z

Blocking promotion of jdk17.

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_OpenJDK17/9
jdk_lang_1
JVM_OPTIONS: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:-UseCompressedOops
java/lang/invoke/VarHandles/VarHandleTestAccessChar.java.VarHandleTestAccessChar
java/lang/invoke/VarHandles/VarHandleTestAccessInt.java.VarHandleTestAccessInt
java/lang/invoke/VarHandles/VarHandleTestAccessLong.java.VarHandleTestAccessLong
java/lang/invoke/VarHandles/VarHandleTestAccessShort.java.VarHandleTestAccessShort

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_OpenJDK17/9/openjdk_test_output.tar.gz

Failed. Unexpected exit from test [exit code: 137]

The text was updated successfully, but these errors were encountered:

pshipton · 2021-08-24T12:41:56Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Nightly/2/
jdk_lang_0
java/lang/invoke/VarHandles/VarHandleTestAccessChar.java.VarHandleTestAccessChar
java/lang/invoke/VarHandles/VarHandleTestAccessFloat.java.VarHandleTestAccessFloat
jdk_lang_1
java/lang/invoke/VarHandles/VarHandleTestAccessChar.java.VarHandleTestAccessChar
java/lang/invoke/VarHandles/VarHandleTestAccessDouble.java.VarHandleTestAccessDouble
java/lang/invoke/VarHandles/VarHandleTestAccessInt.java.VarHandleTestAccessInt
java/lang/invoke/VarHandles/VarHandleTestAccessShort.java.VarHandleTestAccessShort

JasonFengJ9 · 2021-08-24T13:37:56Z

This Unexpected exit from test [exit code: 137] wasn't observed at internal tests such as Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Personal/10/.
Could be machine/setup related.

pshipton · 2021-08-24T14:08:16Z

I believe internal testing is running obsolete jdk17 code without OJDK MH enabled.

pshipton · 2021-08-24T14:11:43Z

Internal builds are using JCL - 363eb1d6e4 based on jdk-17+18), while the (non-promoted) latest is jdk-17+35 with OJDK MH enabled.

pshipton · 2021-08-24T14:14:52Z

Are internal builds for jdk17 even running? The last one I see is from July 13.

JasonFengJ9 · 2021-08-24T14:15:04Z

Please check Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Personal/10/console which is built/test against JDK17 (openj9-staging).
Note: this is one of personal builds which have been used to test JDK16/17 recently due to internal nightly/weekly builds not launched since 0.27 release cycle.

13:27:57  openjdk version "17-internal" 2021-09-14
13:27:57  OpenJDK Runtime Environment (build 17-internal+0-adhoc.jenkins.BuildJDK17ppc64lelinuxPersonal)
13:27:57  Eclipse OpenJ9 VM (build master-5d2495e99a7, JRE 17 Linux ppc64le-64-Bit Compressed References 20210823_12 (JIT enabled, AOT enabled)
13:27:57  OpenJ9   - 5d2495e99a7
13:27:57  OMR      - 6eec759cd2d
13:27:57  JCL      - b40e984c3a1 based on jdk-17+35)

pshipton · 2021-08-24T16:11:26Z

We've promoted the jdk17 content regardless of the failures, so this isn't blocking anything any more, except for the tests being green.

pshipton · 2021-08-24T16:13:55Z

and any future jdk17 acceptance build but we may already have the final level considering it's after the OpenJDK Final Release Candidate date.

pshipton · 2021-08-25T11:45:26Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Nightly/3/

midronij · 2021-09-01T06:24:59Z

I've tried to reproduce this in the runtimes grinder with jdk_lang_0 (https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/17831/consoleFull) and jdk_lang_1 (https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/17818/console), but I haven't seen this error so far. The test either passes, or I get something similar to what happened here (#13367 (comment)):

TEST RESULT: Error. Agent communication error: java.io.EOFException; check console log for any additional details

pshipton · 2021-09-08T21:17:48Z

Not sure if this is vm or jit so I've set both.

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Nightly/17/

pshipton · 2021-09-09T13:50:23Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Nightly/18

JasonFengJ9 · 2021-09-10T11:32:04Z

Observed at JDK17 0.28 release zLinux build at job/Test_openjdk17_j9_sanity.openjdk_s390x_linux/49/

openjdk version "17-beta" 2021-09-14
IBM Semeru Runtime Open Edition 17.0.0.0-m1 (build 17-beta+35-202109100251)
Eclipse OpenJ9 VM 17.0.0.0-m1 (build openj9-0.28.0-m1, JRE 17 Linux s390x-64-Bit Compressed References 20210909_25 (JIT enabled, AOT enabled)
OpenJ9   - 5eef84fb1
OMR      - 0bf455f83
JCL      - b6c1a570c77 based on jdk-17+35)

[2021-09-10T04:51:48.484Z] Running test jdk_lang_1 ...
[2021-09-10T04:51:48.484Z] ===============================================
[2021-09-10T04:51:48.484Z] jdk_lang_1 Start Time: Thu Sep  9 21:51:46 2021 Epoch Time (ms): 1631249506072
[2021-09-10T04:51:48.484Z] "/home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_s390x_linux/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:destroyAll; "/home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_s390x_linux/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
[2021-09-10T04:51:48.484Z] JVMSHRC005I No shared class caches available
[2021-09-10T04:51:48.484Z] JVMSHRC005I No shared class caches available
[2021-09-10T04:51:48.484Z] cache cleanup done
[2021-09-10T04:51:48.484Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode650
[2021-09-10T04:51:48.484Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:-UseCompressedOops 

[2021-09-10T05:11:28.027Z] --------------------------------------------------
[2021-09-10T05:11:28.027Z] TEST: java/lang/invoke/VarHandles/VarHandleTestByteArrayAsLong.java

[2021-09-10T05:11:28.036Z] ACTION: testng -- Failed. Unexpected exit from test [exit code: 137]
[2021-09-10T05:11:28.036Z] REASON: User specified action: run testng/othervm/timeout=360 -Diters=20000 -XX:-TieredCompilation VarHandleTestByteArrayAsLong 
[2021-09-10T05:11:28.036Z] TIME:   38.59 seconds
[2021-09-10T05:11:28.036Z] messages:
[2021-09-10T05:11:28.037Z] command: testng -Diters=20000 -XX:-TieredCompilation VarHandleTestByteArrayAsLong
[2021-09-10T05:11:28.037Z] reason: User specified action: run testng/othervm/timeout=360 -Diters=20000 -XX:-TieredCompilation VarHandleTestByteArrayAsLong 
[2021-09-10T05:11:28.037Z] Mode: othervm [/othervm specified]
[2021-09-10T05:11:28.037Z] elapsed time (seconds): 38.59
[2021-09-10T05:11:28.037Z] configuration:

[2021-09-10T05:11:28.039Z] TEST RESULT: Failed. Unexpected exit from test [exit code: 137]
[2021-09-10T05:11:28.039Z] --------------------------------------------------
[2021-09-10T05:47:39.245Z] Test results: passed: 801; failed: 1
[2021-09-10T05:47:46.291Z] Report written to /home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_s390x_linux/jvmtest/openjdk/report/html/report.html
[2021-09-10T05:47:46.291Z] Results written to /home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_s390x_linux/aqa-tests/TKG/output_16312461891078/jdk_lang_1/work
[2021-09-10T05:47:46.292Z] Error: Some tests failed or other problems occurred.
[2021-09-10T05:47:46.292Z] 
[2021-09-10T05:47:46.292Z] jdk_lang_1_FAILED

Rerun in Grinder

Also at JDK17 0.28 release aarch64 build job/Test_openjdk17_j9_sanity.openjdk_aarch64_linux/43/

openjdk version "17-beta" 2021-09-14
IBM Semeru Runtime Open Edition 17.0.0.0-m1 (build 17-beta+35-202109100229)
Eclipse OpenJ9 VM 17.0.0.0-m1 (build openj9-0.28.0-m1, JRE 17 Linux aarch64-64-Bit Compressed References 20210910_26 (JIT enabled, AOT enabled)
OpenJ9   - 5eef84fb1
OMR      - 0bf455f83
JCL      - b6c1a570c77 based on jdk-17+35)

[2021-09-10T04:22:34.384Z] Running test jdk_lang_0 ...
[2021-09-10T04:22:34.384Z] ===============================================
[2021-09-10T04:22:34.384Z] jdk_lang_0 Start Time: Fri Sep 10 00:22:30 2021 Epoch Time (ms): 1631247750870
[2021-09-10T04:22:34.384Z] "/home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_linux/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:destroyAll; "/home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_linux/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
[2021-09-10T04:22:34.384Z] 
[2021-09-10T04:22:34.384Z] Attempting to destroy all caches in cacheDir /home/jenkins/javasharedresources/
[2021-09-10T04:22:34.384Z] 
[2021-09-10T04:22:34.384Z] JVMSHRC806I Compressed references persistent shared cache "sharedcc_jenkins" has been destroyed. Use option -Xnocompressedrefs if you want to destroy a non-compressed references cache.
[2021-09-10T04:22:34.384Z] JVMSHRC005I No shared class caches available
[2021-09-10T04:22:34.384Z] cache cleanup done
[2021-09-10T04:22:34.384Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode150
[2021-09-10T04:22:34.384Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:+UseCompressedOops 

[2021-09-10T04:30:14.480Z] --------------------------------------------------
[2021-09-10T04:30:14.480Z] TEST: java/lang/invoke/VarHandles/VarHandleTestByteArrayAsFloat.java

[2021-09-10T04:30:14.484Z] REASON: User specified action: run testng/othervm/timeout=360 -Diters=20000 VarHandleTestByteArrayAsFloat 
[2021-09-10T04:30:14.484Z] TIME:   23.593 seconds
[2021-09-10T04:30:14.484Z] messages:
[2021-09-10T04:30:14.484Z] command: testng -Diters=20000 VarHandleTestByteArrayAsFloat
[2021-09-10T04:30:14.484Z] reason: User specified action: run testng/othervm/timeout=360 -Diters=20000 VarHandleTestByteArrayAsFloat 
[2021-09-10T04:30:14.485Z] Mode: othervm [/othervm specified]
[2021-09-10T04:30:14.485Z] elapsed time (seconds): 23.593
[2021-09-10T04:30:14.485Z] configuration:

[2021-09-10T04:30:14.487Z] TEST RESULT: Failed. Unexpected exit from test [exit code: 137]
[2021-09-10T04:30:14.487Z] --------------------------------------------------
[2021-09-10T04:40:12.867Z] Test results: passed: 803; failed: 1
[2021-09-10T04:40:21.330Z] Report written to /home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_linux/jvmtest/openjdk/report/html/report.html
[2021-09-10T04:40:21.330Z] Results written to /home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_linux/aqa-tests/TKG/output_163124775083/jdk_lang_0/work
[2021-09-10T04:40:21.330Z] Error: Some tests failed or other problems occurred.
[2021-09-10T04:40:21.330Z] 
[2021-09-10T04:40:21.330Z] jdk_lang_0_FAILED

Rerun in Grinder

0xdaryl · 2021-09-13T14:53:35Z

@midronij : Although there seem to be failures occurring on other platforms, I'd appreciate it if you could continue to triage this problem to narrow down the issue please.

pshipton · 2021-09-13T15:06:53Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Nightly/21
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Nightly/22
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Nightly/23

tajila · 2021-09-14T13:38:08Z

@babsingh Please take a look at this one as well

babsingh · 2021-09-14T17:36:07Z

Google search for `exit code: 137` in a Java app

The search indicates that

[Ref 1] the application container memory has been exceeded (NOT the JVM hitting OOM).

[Ref 2] The exit code 137 then resolves to 128 + 9, whereas Signal 9 is SIGKILL, i.e. the process was forcefully killed. This can among others be a "kill -9 " command. However in your case this could be an out of memory condition on the operating system, which causes a functionality called "OOM Killer" to stop the process which is using up most of the memory in order to keep the OS itself stable even in such a condition.

Ref 1: Java Application gets Out of Memory exit code 137
Ref 2: resolving-java-result-137

The above comments suggests that these failures are due to a machine issue.

Observations

The failure only occurs on ub16-ppcle-1. The 9 Sept 21 build #19 passed, and it was run on cent7-ppcle-3.
The failure is only seen on ppc64le.
Different test targets failed in different builds:
- #21: VarHandleTestAccessLong, VarHandleTestAccessInt, VarHandleTestAccessShort.
- #22: VarHandleTestAccessInt, VarHandleTestAccessLong.
- #23: VarHandleTestAccessByte, VarHandleTestAccessShort.
No Java error is seen in the test output. All tests successfully pass as per the test log.
The tests involve many iterations: -Diters=20000, which suggests a lot of memory is used.

Fix

To test the above hypothesis, we should disable ub16-ppcle-1 and let the jdk17_j9_sanity.openjdk builds run on a different pLinux machine. @AdamBrousseau Can you please help with disabling ub16-ppcle-1?

pshipton · 2021-09-14T21:23:30Z

I think ub16-ppcle-1 is the only external more modern / faster machine we have (POWER8 (architected) - 8359424 kB), the only machine from osu in the builds. The others are all older hardware? at unb. I can disable it temporarily but that is not a fix. Plus it also occurs internally on other machines, other platforms, see #13368 (comment). It didn't occur before jdk17 with OJDK MH. If there is a JVM problem using too much memory, customers may also hit the problem.

pshipton · 2021-09-14T21:25:13Z

Machine has been disabled for the builds tonight anyway.

pshipton · 2021-09-14T21:27:09Z

Note the very first failure is on cent7-ppcle-3 (POWER8E (raw) - 7834176 kB)

babsingh · 2021-09-16T17:00:54Z

If there is a JVM problem using too much memory, customers may also hit the problem.

In this case, the JVM should throw an OOM. But, no error/exception is thrown. Instead, the OS kills the Java process with a SIGKILL. Even, no diagnostic core files are generated for this failure.

babsingh · 2021-09-16T17:25:48Z

I can disable it temporarily but that is not a fix.

I ran the test locally and in grinders (on internal pLinux machines) to reproduce the issue. But, I was unable to reproduce the failure.

I do see differences in the failing and passing test output. Based on the difference, the failure occurs while executing the "VarHandle -> Array" testcase in all variants of the failure. Code for the VarHandle -> Array test case. It executes a lot of VarHandle operations on an array. These VH operations translate to calling the Unsafe methods. The OS may be sending a SIGKILL while calling one of these Unsafe methods.

Next steps: Get access to one of the machines where the failure is reproducible. Study the failure locally on the machine with attempts to generate diagnostic data.

Failing test output:

22:45:20  STDOUT:
22:45:20  config VarHandleTestAccessInt.setup(): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Instance final field", VarHandleBaseTest$VarHandleAccessTestCase@780aa1ad): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Instance final field unsupported", VarHandleBaseTest$VarHandleAccessTestCase@de36362d): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Static final field", VarHandleBaseTest$VarHandleAccessTestCase@1139905c): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Static final field unsupported", VarHandleBaseTest$VarHandleAccessTestCase@eabfa1f0): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Instance field", VarHandle -> Instance field): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Instance field unsupported", VarHandleBaseTest$VarHandleAccessTestCase@d2079fae): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Static field", VarHandle -> Static field): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Static field unsupported", VarHandleBaseTest$VarHandleAccessTestCase@ec40226b): success
>>> Java process unexpectedly exits with code: 137 <<<

Passing test output:

22:45:20  config VarHandleTestAccessInt.setup(): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Instance final field", VarHandleBaseTest$VarHandleAccessTestCase@d651b50a): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Instance final field unsupported", VarHandleBaseTest$VarHandleAccessTestCase@536692e9): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Static final field", VarHandleBaseTest$VarHandleAccessTestCase@63cb9c16): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Static final field unsupported", VarHandleBaseTest$VarHandleAccessTestCase@24c2a6c0): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Instance field", VarHandle -> Instance field): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Instance field unsupported", VarHandleBaseTest$VarHandleAccessTestCase@199c0fda): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Static field", VarHandle -> Static field): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Static field unsupported", VarHandleBaseTest$VarHandleAccessTestCase@72269002): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Array", VarHandle -> Array): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Array unsupported", VarHandle -> Array unsupported): success
22:45:20  test VarHandleTestAccessInt.testAccess("VarHandle -> Array index out of bounds", VarHandleBaseTest$VarHandleAccessTestCase@a383b4a0): success
22:45:20  test VarHandleTestAccessInt.testEquals(): success
22:45:20  test VarHandleTestAccessInt.testIsAccessModeSupported(java.lang.invoke.VarHandleInts$FieldInstanceReadWrite@f53bc7f1): success
22:45:20  test VarHandleTestAccessInt.testIsAccessModeSupported(java.lang.invoke.VarHandleInts$FieldStaticReadWrite@59738b60): success
22:45:20  test VarHandleTestAccessInt.testIsAccessModeSupported(java.lang.invoke.VarHandleInts$Array@264eda3c): success
22:45:20  test VarHandleTestAccessInt.testLookupInstanceToStatic(): success
22:45:20  test VarHandleTestAccessInt.testLookupStaticToInstance(): success
22:45:20  test VarHandleTestAccessInt.testTypes(java.lang.invoke.VarHandleInts$FieldInstanceReadWrite@f53bc7f1, [class VarHandleTestAccessInt]): success
22:45:20  test VarHandleTestAccessInt.testTypes(java.lang.invoke.VarHandleInts$FieldStaticReadWrite@59738b60, []): success
22:45:20  test VarHandleTestAccessInt.testTypes(java.lang.invoke.VarHandleInts$Array@264eda3c, [class [I, int]): success

pshipton · 2021-09-16T20:03:54Z

Instead, the OS kills the Java process with a SIGKILL. Even, no diagnostic core files are generated for this failure.

This could indicate a native memory leak. You could try running the test with memory tracking enabled, or using OS memory tools to look at the memory used by the process while it's still running.

Get access to one of the machines where the failure is reproducible.

Since ub16-ppcle-1 is disabled in jenkins, it's sitting idle.

pshipton · 2021-09-16T20:06:52Z

Something like -Xcheck:memory:noscan,quick,callsite=1000 will dump a summary of allocated memory every 1000 allocations. This will only find leaks that use "malloc". If it's virtual memory, perhaps as allocated as workspace for the jit, using an OS tool is better.

llxia · 2021-10-26T15:56:00Z

@LongyuZhang could you create a separate test target for VarHandleTestAccess and run with the jit opt? Thanks.

llxia · 2021-10-27T19:13:01Z

Just for the record, VarHandleTestAccess test is separated out of jdk_lang for jdk17 via PR adoptium/aqa-tests#3100 and adoptium/aqa-tests#3101

pshipton · 2021-11-01T13:26:41Z

@llxia there is another one here https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Nightly/65/
With jdk_lang_1 running java/lang/invoke/VarHandles/VarHandleTestAccessBoolean.java

pshipton · 2021-11-01T13:33:04Z

I'll create a PR to exclude this test as well.

See adoptium#3101 eclipse-openj9/openj9#13368 Signed-off-by: Peter Shipton <Peter_Shipton@ca.ibm.com>

pshipton · 2021-11-01T13:39:17Z

adoptium/aqa-tests#3111

…3111) See #3101 eclipse-openj9/openj9#13368 Signed-off-by: Peter Shipton <Peter_Shipton@ca.ibm.com>

JasonFengJ9 · 2021-11-23T22:07:13Z

Observed at an internal build job/Test_openjdk17_j9_special.system_s390x_linux_testList_4/93/tapResults/(ub18s390xrt-1-1)

===============================================
Running test DaaLoadTest_daa1_special_5m_16 ...
===============================================
DaaLoadTest_daa1_special_5m_16 Start Time: Sat Nov 20 15:14:13 2021 Epoch Time (ms): 1637450053992
variation: Mode555
JVM_OPTIONS:  -XX:+UseCompressedOops -Xgcpolicy:balanced -Xjit:counts=- - - - - - 1 1 1 1000 250 250 - - - 10000 100000 10000,gcOnResolve,rtResolve,sampleInterval=2,scorchingSampleThreshold=10000,quickProfile -Xcheck:gc:vmthreads:all:quiet 
STF 15:14:14.147 - =========================   S T F   =========================

openjdk version "17.0.1" 2021-10-19
IBM Semeru Runtime Certified Edition 17.0.1+12 (build 17.0.1+12)
Eclipse OpenJ9 VM 17.0.1+12 (build master-0f828acf4, JRE 17 Linux s390x-64-Bit Compressed References 20211120_43 (JIT enabled, AOT enabled)
OpenJ9   - 0f828acf4
OMR      - 83214375c
JCL      - df273956de9 based on jdk-17.0.1+12)

DLT 15:16:23.999 - Completed 40.1%. Number of tests started=307 (+30)
DLT stderr Killed
STF 15:17:00.343 - **FAILED** Process DLT ended with exit code (137) and not the expected exit code/s (0)
STF 15:17:00.349 - Monitoring Report Summary:
STF 15:17:00.360 -   o Process DLT ended with exit code (137) and not the expected exit code/s (0)
STF 15:17:00.516 - Killing processes: DLT
STF 15:17:00.517 -   o Process DLT pid 7171 is not running
**FAILED** at step 1 (Run daa load test). Expected return value=0 Actual=1 at /home/jenkins/workspace/Test_openjdk17_j9_special.system_s390x_linux_testList_4/aqa-tests/TKG/../TKG/output_16374393504751/DaaLoadTest_daa1_special_5m_16/20211120-151414-DaaLoadTest/execute.pl line 115.
STF 15:17:02.544 - **FAILED** execute script failed. Expected return value=0 Actual=1
STF 15:17:02.561 - 
STF 15:17:02.575 - ====================   T E A R D O W N   ====================
STF 15:17:02.576 - Running teardown: perl /home/jenkins/workspace/Test_openjdk17_j9_special.system_s390x_linux_testList_4/aqa-tests/TKG/../TKG/output_16374393504751/DaaLoadTest_daa1_special_5m_16/20211120-151414-DaaLoadTest/tearDown.pl
STF 15:17:03.263 - TEARDOWN stage completed
STF 15:17:03.282 - 
STF 15:17:03.282 - =====================   R E S U L T S   =====================
STF 15:17:03.291 - Stage results:
STF 15:17:03.294 -   setUp:     pass
STF 15:17:03.302 -   execute:  *fail*
STF 15:17:03.302 -   teardown:  pass
STF 15:17:03.302 - 
STF 15:17:03.302 - Overall result: **FAILED**

DaaLoadTest_daa1_special_5m_16_FAILED

JasonFengJ9 · 2021-12-03T13:10:41Z

Observed at JDK17 Head internal build job/Test_openjdk17_j9_special.system_s390x_linux_testList_3/100/ (ub18s390xrt-1-10)

openjdk version "17.0.1-beta" 2021-10-19
IBM Semeru Runtime Certified Edition 17.0.1+12-202112020517 (build 17.0.1-beta+12-202112020517)
Eclipse OpenJ9 VM 17.0.1+12-202112020517 (build master-8b18a989f, JRE 17 Linux s390x-64-Bit Compressed References 20211201_51 (JIT enabled, AOT enabled)
OpenJ9   - 8b18a989f
OMR      - 8d10f065c
JCL      - a60fb4eda99 based on jdk-17.0.1+12)

[2021-12-02T10:53:58.109Z] variation: Mode614
[2021-12-02T10:53:58.109Z] JVM_OPTIONS:  -Xcompressedrefs -Xgcpolicy:gencon -Xjit:counts=- - - - - - 1 1 1 1000 250 250 - - - 10000 100000 10000,gcOnResolve,rtResolve,sampleInterval=2,scorchingSampleThreshold=10000,quickProfile -Xmn512k -Xcheck:gc:vmthreads:all:quiet 

[2021-12-02T10:54:23.518Z] DLT 02:54:22.136 - Completed 6.7%. Number of tests started=43
[2021-12-02T10:54:43.601Z] DLT 02:54:42.055 - Completed 13.4%. Number of tests started=103 (+60)
[2021-12-02T10:55:04.505Z] DLT 02:55:02.080 - Completed 20.0%. Number of tests started=139 (+36)
[2021-12-02T10:58:08.266Z] DLT stderr Killed
[2021-12-02T10:58:08.266Z] STF 02:58:01.531 - **FAILED** Process DLT ended with exit code (137) and not the expected exit code/s (0)
[2021-12-02T10:58:08.266Z] STF 02:58:01.536 - Monitoring Report Summary:
[2021-12-02T10:58:08.266Z] STF 02:58:01.560 -   o Process DLT ended with exit code (137) and not the expected exit code/s (0)
[2021-12-02T10:58:08.266Z] STF 02:58:01.727 - Killing processes: DLT
[2021-12-02T10:58:08.266Z] STF 02:58:01.729 -   o Process DLT pid 2831 is not running
[2021-12-02T10:58:08.266Z] **FAILED** at step 1 (Run daa load test). Expected return value=0 Actual=1 at /home/jenkins/workspace/Test_openjdk17_j9_special.system_s390x_linux_testList_3/aqa-tests/TKG/../TKG/output_16384315794236/DaaLoadTest_daa1_special_5m_20/20211202-025356-DaaLoadTest/execute.pl line 116.
[2021-12-02T10:58:08.266Z] STF 02:58:02.869 - **FAILED** execute script failed. Expected return value=0 Actual=1
[2021-12-02T10:58:08.266Z] STF 02:58:02.884 - 
[2021-12-02T10:58:08.266Z] STF 02:58:02.900 - ====================   T E A R D O W N   ====================
[2021-12-02T10:58:08.266Z] STF 02:58:02.904 - Running teardown: perl /home/jenkins/workspace/Test_openjdk17_j9_special.system_s390x_linux_testList_3/aqa-tests/TKG/../TKG/output_16384315794236/DaaLoadTest_daa1_special_5m_20/20211202-025356-DaaLoadTest/tearDown.pl
[2021-12-02T10:58:08.266Z] STF 02:58:03.358 - TEARDOWN stage completed
[2021-12-02T10:58:08.266Z] STF 02:58:03.364 - 
[2021-12-02T10:58:08.266Z] STF 02:58:03.364 - =====================   R E S U L T S   =====================
[2021-12-02T10:58:08.266Z] STF 02:58:03.365 - Stage results:
[2021-12-02T10:58:08.266Z] STF 02:58:03.367 -   setUp:     pass
[2021-12-02T10:58:08.266Z] STF 02:58:03.368 -   execute:  *fail*
[2021-12-02T10:58:08.266Z] STF 02:58:03.368 -   teardown:  pass
[2021-12-02T10:58:08.266Z] STF 02:58:03.369 - 
[2021-12-02T10:58:08.266Z] STF 02:58:03.369 - Overall result: **FAILED**
[2021-12-02T10:58:08.266Z] 
[2021-12-02T10:58:08.266Z] DaaLoadTest_daa1_special_5m_20_FAILED

And another sub-test.

[2021-12-02T12:18:24.221Z] variation: Mode614
[2021-12-02T12:18:24.221Z] JVM_OPTIONS:  -Xcompressedrefs -Xgcpolicy:gencon -Xjit:counts=- - - - - - 1 1 1 1000 250 250 - - - 10000 100000 10000,gcOnResolve,rtResolve,sampleInterval=2,scorchingSampleThreshold=10000,quickProfile -Xmn512k -Xcheck:gc:vmthreads:all:quiet 

[2021-12-02T12:20:16.270Z] DLT 04:20:08.705 - Completed 33.4%. Number of tests started=201 (+12)
[2021-12-02T12:22:49.200Z] DLT stderr Killed
[2021-12-02T12:22:49.200Z] STF 04:22:33.010 - **FAILED** Process DLT ended with exit code (137) and not the expected exit code/s (0)
[2021-12-02T12:22:49.200Z] STF 04:22:33.021 - Monitoring Report Summary:
[2021-12-02T12:22:49.200Z] STF 04:22:33.030 -   o Process DLT ended with exit code (137) and not the expected exit code/s (0)
[2021-12-02T12:22:49.200Z] STF 04:22:33.169 - Killing processes: DLT
[2021-12-02T12:22:49.200Z] STF 04:22:33.171 -   o Process DLT pid 9377 is not running
[2021-12-02T12:22:49.200Z] **FAILED** at step 1 (Run daa load test). Expected return value=0 Actual=1 at /home/jenkins/workspace/Test_openjdk17_j9_special.system_s390x_linux_testList_3/aqa-tests/TKG/../TKG/output_16384315794236/DaaLoadTest_all_special_5m_20/20211202-041823-DaaLoadTest/execute.pl line 116.
[2021-12-02T12:22:49.200Z] STF 04:22:34.078 - **FAILED** execute script failed. Expected return value=0 Actual=1
[2021-12-02T12:22:49.200Z] STF 04:22:34.093 - 
[2021-12-02T12:22:49.200Z] STF 04:22:34.102 - ====================   T E A R D O W N   ====================
[2021-12-02T12:22:49.200Z] STF 04:22:34.103 - Running teardown: perl /home/jenkins/workspace/Test_openjdk17_j9_special.system_s390x_linux_testList_3/aqa-tests/TKG/../TKG/output_16384315794236/DaaLoadTest_all_special_5m_20/20211202-041823-DaaLoadTest/tearDown.pl
[2021-12-02T12:22:49.200Z] STF 04:22:34.485 - TEARDOWN stage completed
[2021-12-02T12:22:49.200Z] STF 04:22:34.494 - 
[2021-12-02T12:22:49.200Z] STF 04:22:34.494 - =====================   R E S U L T S   =====================
[2021-12-02T12:22:49.200Z] STF 04:22:34.496 - Stage results:
[2021-12-02T12:22:49.200Z] STF 04:22:34.497 -   setUp:     pass
[2021-12-02T12:22:49.200Z] STF 04:22:34.498 -   execute:  *fail*
[2021-12-02T12:22:49.200Z] STF 04:22:34.499 -   teardown:  pass
[2021-12-02T12:22:49.200Z] STF 04:22:34.499 - 
[2021-12-02T12:22:49.200Z] STF 04:22:34.499 - Overall result: **FAILED**
[2021-12-02T12:22:49.200Z] 
[2021-12-02T12:22:49.200Z] DaaLoadTest_all_special_5m_20_FAILED

pshipton · 2021-12-03T13:37:30Z

Added the test excluded label as there are a number of tests excluded under this Issue.
adoptium/aqa-tests#3111

0xdaryl · 2021-12-03T13:41:51Z

Tagging @jdmpapin as he is investigating the excessive memory usage in the JIT relating to OpenJDK MethodHandles.

JasonFengJ9 · 2022-01-27T20:17:09Z

Appeared in a 0.30.0 release build job/Test_openjdk17_j9_special.system_s390x_linux_testList_2/139/tapResults/(ub18s390xrt-1-7)

===============================================
Running test DaaLoadTest_all_special_5m_20 ...
===============================================
DaaLoadTest_all_special_5m_20 Start Time: Wed Jan 26 05:26:21 2022 Epoch Time (ms): 1643203581956
variation: Mode614
JVM_OPTIONS:  -Xcompressedrefs -Xgcpolicy:gencon -Xjit:counts=- - - - - - 1 1 1 1000 250 250 - - - 10000 100000 10000,gcOnResolve,rtResolve,sampleInterval=2,scorchingSampleThreshold=10000,quickProfile -Xmn512k -Xcheck:gc:vmthreads:all:quiet 

openjdk version "17.0.2" 2022-01-18
IBM Semeru Runtime Open Edition 17.0.2.0-rc1 (build 17.0.2+8)
Eclipse OpenJ9 VM 17.0.2.0-rc1 (build openj9-0.30.0-rc1, JRE 17 Linux s390x-64-Bit Compressed References 20220125_94 (JIT enabled, AOT enabled)
OpenJ9   - f441547b8
OMR      - dac962a28
JCL      - 7a0f6b5186d based on jdk-17.0.2+8)

DLT 05:26:46.130 - Completed 6.7%. Number of tests started=122
DLT stderr Killed
STF 05:29:19.745 - **FAILED** Process DLT ended with exit code (137) and not the expected exit code/s (0)
STF 05:29:19.752 - Monitoring Report Summary:
STF 05:29:19.760 -   o Process DLT ended with exit code (137) and not the expected exit code/s (0)
STF 05:29:19.834 - Killing processes: DLT
STF 05:29:19.835 -   o Process DLT pid 25517 is not running
**FAILED** at step 1 (Run daa load test). Expected return value=0 Actual=1 at /home/jenkins/workspace/Test_openjdk17_j9_special.system_s390x_linux_testList_2/aqa-tests/TKG/../TKG/output_1643186639500/DaaLoadTest_all_special_5m_20/20220126-052622-DaaLoadTest/execute.pl line 116.
STF 05:29:20.801 - **FAILED** execute script failed. Expected return value=0 Actual=1
STF 05:29:20.809 - 
STF 05:29:20.815 - ====================   T E A R D O W N   ====================
STF 05:29:20.816 - Running teardown: perl /home/jenkins/workspace/Test_openjdk17_j9_special.system_s390x_linux_testList_2/aqa-tests/TKG/../TKG/output_1643186639500/DaaLoadTest_all_special_5m_20/20220126-052622-DaaLoadTest/tearDown.pl
STF 05:29:21.118 - TEARDOWN stage completed
STF 05:29:21.123 - 
STF 05:29:21.123 - =====================   R E S U L T S   =====================
STF 05:29:21.125 - Stage results:
STF 05:29:21.126 -   setUp:     pass
STF 05:29:21.126 -   execute:  *fail*
STF 05:29:21.127 -   teardown:  pass
STF 05:29:21.127 - 
STF 05:29:21.127 - Overall result: **FAILED**

DaaLoadTest_all_special_5m_20_FAILED

JasonFengJ9 · 2022-04-07T23:17:24Z

Observed at JDK18 0.32 milestone 2 build - job/Test_openjdk18_j9_special.system_s390x_linux_testList_1/33/(ub18s390xrt-1-8)

openjdk version "18" 2022-03-22
IBM Semeru Runtime Open Edition 18.0.1.0-m2 (build 18+37)
Eclipse OpenJ9 VM 18.0.1.0-m2 (build openj9-0.32.0-m2, JRE 18 Linux s390x-64-Bit Compressed References 20220406_58 (JIT enabled, AOT enabled)
OpenJ9   - 959fc5030
OMR      - ab24b6666
JCL      - ea5f594899a based on jdk-18+37)

[2022-04-07T08:36:49.988Z] variation: Mode614
[2022-04-07T08:36:49.989Z] JVM_OPTIONS:  -Xcompressedrefs -Xgcpolicy:gencon -Xjit:counts=- - - - - - 1 1 1 1000 250 250 - - - 10000 100000 10000,gcOnResolve,rtResolve,sampleInterval=2,scorchingSampleThreshold=10000,quickProfile -Xmn512k -Xcheck:gc:vmthreads:all:quiet 

[2022-04-07T08:41:20.228Z] STF 01:41:13.947 -   o Process DLT ended with exit code (137) and not the expected exit code/s (0)
[2022-04-07T08:41:20.228Z] STF 01:41:14.128 - Killing processes: DLT
[2022-04-07T08:41:20.228Z] STF 01:41:14.129 -   o Process DLT pid 4483 is not running
[2022-04-07T08:41:20.228Z] **FAILED** at step 1 (Run daa load test). Expected return value=0 Actual=1 at /home/jenkins/workspace/Test_openjdk18_j9_special.system_s390x_linux_testList_1/aqa-tests/TKG/../TKG/output_16493021029830/DaaLoadTest_all_special_5m_20/20220407-013649-DaaLoadTest/execute.pl line 116.
[2022-04-07T08:41:20.228Z] STF 01:41:14.998 - **FAILED** execute script failed. Expected return value=0 Actual=1
[2022-04-07T08:41:20.228Z] STF 01:41:15.009 - 
[2022-04-07T08:41:20.228Z] STF 01:41:15.018 - ====================   T E A R D O W N   ====================
[2022-04-07T08:41:20.228Z] STF 01:41:15.019 - Running teardown: perl /home/jenkins/workspace/Test_openjdk18_j9_special.system_s390x_linux_testList_1/aqa-tests/TKG/../TKG/output_16493021029830/DaaLoadTest_all_special_5m_20/20220407-013649-DaaLoadTest/tearDown.pl
[2022-04-07T08:41:20.228Z] STF 01:41:15.460 - TEARDOWN stage completed
[2022-04-07T08:41:20.228Z] STF 01:41:15.468 - 
[2022-04-07T08:41:20.228Z] STF 01:41:15.468 - =====================   R E S U L T S   =====================
[2022-04-07T08:41:20.228Z] STF 01:41:15.469 - Stage results:
[2022-04-07T08:41:20.228Z] STF 01:41:15.472 -   setUp:     pass
[2022-04-07T08:41:20.228Z] STF 01:41:15.472 -   execute:  *fail*
[2022-04-07T08:41:20.228Z] STF 01:41:15.472 -   teardown:  pass
[2022-04-07T08:41:20.228Z] STF 01:41:15.473 - 
[2022-04-07T08:41:20.228Z] STF 01:41:15.473 - Overall result: **FAILED**
[2022-04-07T08:41:20.228Z] 
[2022-04-07T08:41:20.228Z] DaaLoadTest_all_special_5m_20_FAILED

JasonFengJ9 · 2022-08-05T14:50:03Z

An internal build(osxrt3)

openjdk version "11.0.16" 2022-07-19
IBM Semeru Runtime Open Edition 11.0.16.0 (build 11.0.16+8)
Eclipse OpenJ9 VM 11.0.16.0 (build openj9-0.33.0, JRE 11 Mac OS X amd64-64-Bit Compressed References 20220804_445 (JIT enabled, AOT enabled)
OpenJ9   - 04a55b45b
OMR      - b58aa2708
JCL      - ab74d97849 based on jdk-11.0.16+8)

[2022-08-04T20:36:05.238Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode650
[2022-08-04T20:36:05.238Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:-UseCompressedOops 

[2022-08-04T20:41:09.040Z] TEST: java/lang/invoke/VarHandles/VarHandleTestMethodHandleAccessBoolean.java

[2022-08-04T20:41:09.041Z] TEST RESULT: Failed. Unexpected exit from test [exit code: 137]

[2022-08-04T20:50:33.263Z] jdk_lang_1_FAILED

pshipton added test failure blocker labels Aug 24, 2021

pshipton added this to the Release 0.28 (Java 17) milestone Aug 24, 2021

pshipton added comp:jit comp:vm labels Sep 8, 2021

tajila assigned babsingh Sep 14, 2021

This was referenced Oct 26, 2021

Add jdk_lang_VarHandleTest_j9 test adoptium/aqa-tests#3100

Merged

Exclude VarHandleTestAccess tests in jdk_lang for jdk17 openj9 temporarily adoptium/aqa-tests#3101

Merged

pshipton added a commit to pshipton/openjdk-tests that referenced this issue Nov 1, 2021

Temp exclude VarHandleTestAccessBoolean in jdk_lang for jdk17 openj9

7ff4753

See adoptium#3101 eclipse-openj9/openj9#13368 Signed-off-by: Peter Shipton <Peter_Shipton@ca.ibm.com>

pshipton mentioned this issue Nov 1, 2021

Temp exclude VarHandleTestAccessBoolean in jdk_lang for jdk17 openj9 adoptium/aqa-tests#3111

Merged

llxia pushed a commit to adoptium/aqa-tests that referenced this issue Nov 1, 2021

Temp exclude VarHandleTestAccessBoolean in jdk_lang for jdk17 openj9 (#…

7efb777

…3111) See #3101 eclipse-openj9/openj9#13368 Signed-off-by: Peter Shipton <Peter_Shipton@ca.ibm.com>

pshipton modified the milestones: Release 0.29.1 (Java 17), Release 0.30 (Java 8, 11, 17) Jan refresh Nov 3, 2021

pshipton added the test excluded label Dec 3, 2021

0xdaryl modified the milestones: Release 0.30 (Java 8, 11, 17) Jan refresh, Release 0.31 (Java 18) Dec 14, 2021

0xdaryl assigned jdmpapin Dec 14, 2021

pshipton modified the milestones: Release 0.31 (Java 18), Release 0.32 (Java 8, 11, 17, 18) Apr refresh Jan 11, 2022

pshipton modified the milestones: Release 0.32 (Java 8, 11, 17, 18) Apr refresh, Tracking Feb 10, 2022

pshipton mentioned this issue Mar 3, 2022

AArch64 macOS: Failure in JDK 11 ASSERTION FAILED ParallelScavengeTask.cpp:120 ((false && ((endTime - startTime) >= _syncCriticalSectionDuration))) #14636

Closed

pshipton mentioned this issue Jul 11, 2022

Unexpected exit from test [exit code: 137] #15508

Open

ThanHenderson mentioned this issue Jan 25, 2024

Do not add LambdaForm classes to SCC with OJDK MHs #18814

Merged

jtreg java/lang/invoke/VarHandles/VarHandleTestAccess Unexpected exit from test [exit code: 137] #13368

jtreg java/lang/invoke/VarHandles/VarHandleTestAccess Unexpected exit from test [exit code: 137] #13368

Comments

pshipton commented Aug 24, 2021

pshipton commented Aug 24, 2021

JasonFengJ9 commented Aug 24, 2021

pshipton commented Aug 24, 2021

pshipton commented Aug 24, 2021

pshipton commented Aug 24, 2021 • edited Loading

JasonFengJ9 commented Aug 24, 2021 • edited Loading

pshipton commented Aug 24, 2021

pshipton commented Aug 24, 2021

pshipton commented Aug 25, 2021

midronij commented Sep 1, 2021 • edited Loading

pshipton commented Sep 8, 2021

pshipton commented Sep 9, 2021

JasonFengJ9 commented Sep 10, 2021 • edited Loading

0xdaryl commented Sep 13, 2021

pshipton commented Sep 13, 2021 • edited Loading

tajila commented Sep 14, 2021 • edited Loading

babsingh commented Sep 14, 2021 • edited Loading

Google search for exit code: 137 in a Java app

Observations

Fix

pshipton commented Sep 14, 2021 • edited Loading

pshipton commented Sep 14, 2021

pshipton commented Sep 14, 2021 • edited Loading

babsingh commented Sep 16, 2021

babsingh commented Sep 16, 2021 • edited Loading

pshipton commented Sep 16, 2021

pshipton commented Sep 16, 2021 • edited Loading

llxia commented Oct 26, 2021

llxia commented Oct 27, 2021

pshipton commented Nov 1, 2021

pshipton commented Nov 1, 2021

pshipton commented Nov 1, 2021

JasonFengJ9 commented Nov 23, 2021

JasonFengJ9 commented Dec 3, 2021

pshipton commented Dec 3, 2021

0xdaryl commented Dec 3, 2021

JasonFengJ9 commented Jan 27, 2022

JasonFengJ9 commented Apr 7, 2022

JasonFengJ9 commented Aug 5, 2022

pshipton commented Aug 24, 2021 •

edited

Loading

JasonFengJ9 commented Aug 24, 2021 •

edited

Loading

midronij commented Sep 1, 2021 •

edited

Loading

JasonFengJ9 commented Sep 10, 2021 •

edited

Loading

pshipton commented Sep 13, 2021 •

edited

Loading

tajila commented Sep 14, 2021 •

edited

Loading

babsingh commented Sep 14, 2021 •

edited

Loading

Google search for `exit code: 137` in a Java app

pshipton commented Sep 14, 2021 •

edited

Loading

pshipton commented Sep 14, 2021 •

edited

Loading

babsingh commented Sep 16, 2021 •

edited

Loading

pshipton commented Sep 16, 2021 •

edited

Loading