MacOS java/lang/reflect/exeCallerAccessTest/CallerAccessTest.java - RuntimeException: Expected to get exit value of [0]

[JasonFengJ9]

Failure link

From an internal build job/Test_openjdk18_j9_sanity.openjdk_x86-64_mac_testList_1/1/(osxrt8):

openjdk version "18-beta" 2022-03-22
IBM Semeru Runtime Open Edition 18.0.0.0 (build 18-beta+32-202201270253)
Eclipse OpenJ9 VM 18.0.0.0 (build master-5e9bd4ea0, JRE 18 Mac OS X amd64-64-Bit Compressed References 20220126_21 (JIT enabled, AOT enabled)
OpenJ9   - 5e9bd4ea0
OMR      - 4a009d2fe
JCL      - 0764ffcb69 based on jdk-18+32)

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

Optional info

Failure output (captured from console output)

[2022-01-27T03:37:52.444Z] Running test jdk_lang_1 ...
[2022-01-27T03:37:52.855Z] ===============================================


[2022-01-27T03:37:52.855Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode650
[2022-01-27T03:37:52.855Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:-UseCompressedOops 

[2022-01-27T03:44:26.638Z] TEST: java/lang/reflect/exeCallerAccessTest/CallerAccessTest.java

[2022-01-27T03:44:26.640Z] STDERR:
[2022-01-27T03:44:26.640Z]  stdout: [];
[2022-01-27T03:44:26.640Z]  stderr: []
[2022-01-27T03:44:26.640Z]  exitValue = 139
[2022-01-27T03:44:26.640Z] 
[2022-01-27T03:44:26.640Z] java.lang.RuntimeException: Expected to get exit value of [0]
[2022-01-27T03:44:26.640Z] 
[2022-01-27T03:44:26.640Z] 	at jdk.test.lib.process.OutputAnalyzer.shouldHaveExitValue(OutputAnalyzer.java:489)
[2022-01-27T03:44:26.640Z] 	at CallerAccessTest.main(CallerAccessTest.java:64)
[2022-01-27T03:44:26.640Z] 	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
[2022-01-27T03:44:26.640Z] 	at java.base/java.lang.reflect.Method.invoke(Method.java:577)
[2022-01-27T03:44:26.640Z] 	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:312)
[2022-01-27T03:44:26.640Z] 	at java.base/java.lang.Thread.run(Thread.java:884)
[2022-01-27T03:44:26.640Z] 
[2022-01-27T03:44:26.640Z] JavaTest Message: Test threw exception: java.lang.RuntimeException
[2022-01-27T03:44:26.640Z] JavaTest Message: shutting down test
[2022-01-27T03:44:26.640Z] 
[2022-01-27T03:44:26.640Z] 
[2022-01-27T03:44:26.640Z] TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: Expected to get exit value of [0]
[2022-01-27T03:44:26.640Z] --------------------------------------------------
[2022-01-27T03:45:51.859Z] Test results: passed: 797; failed: 1; error: 1
[2022-01-27T03:46:01.622Z] Report written to /Users/jenkins/workspace/Test_openjdk18_j9_sanity.openjdk_x86-64_mac_testList_1/jvmtest/openjdk/report/html/report.html
[2022-01-27T03:46:01.623Z] Results written to /Users/jenkins/workspace/Test_openjdk18_j9_sanity.openjdk_x86-64_mac_testList_1/aqa-tests/TKG/output_16432546715178/jdk_lang_1/work
[2022-01-27T03:46:01.623Z] Error: Some tests failed or other problems occurred.
[2022-01-27T03:46:01.623Z] 
[2022-01-27T03:46:01.623Z] jdk_lang_1_FAILED

50x grinder - job/Grinder/20614/ - all failed

[pshipton]

This is showing up in jdk17 builds now. Possibly since the test was un-excluded.
Setting as a blocker since it's failing in every nightly MacOS build.
@tajila

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_Nightly/148/
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_Nightly/149/

[tajila]

@JasonFengJ9 Is this only failing on macosx?

[JasonFengJ9]

Is this only failing on macosx?

It appears so, not seen in other platforms.

[tajila]

exit code 139 on the process launched with ProcessBuilder indicates a crash.

@babsingh Please investigate

[tajila]

There were changes in OpenJDK made 7 days ago, 60a165f358a076320357303cf72dbc0e74d9c06c regarding this

ibmruntimes/openj9-openjdk-jdk@60a165f358a07

[tajila]

Pasting more output form the grinder

11:03:01  STDOUT:
11:03:01  Launching: /Users/jenkins/workspace/Grinder_iteration_1/openjdkbinary/openjdk-test-image/jdk/jtreg/native/CallerAccessTest shared library path: /Users/jenkins/workspace/Grinder_iteration_1/openjdkbinary/j2sdk-image/Contents/Home/bin/../lib:/Users/jenkins/workspace/Grinder_iteration_1/openjdkbinary/j2sdk-image/Contents/Home/bin/../lib/server
11:03:01  [2022-02-02T16:02:24.122994Z] Gathering output for process 82782
11:03:01  [2022-02-02T16:02:24.152516Z] Waiting for completion for process 82782
11:03:01  [2022-02-02T16:02:55.636353Z] Waiting for completion finished for process 82782
11:03:01  [2022-02-02T16:02:55.637813Z] Waiting for completion for process 82782
11:03:01  [2022-02-02T16:02:55.637890Z] Waiting for completion finished for process 82782
11:03:01  STDERR:
11:03:01   stdout: [];
11:03:01   stderr: []
11:03:01   exitValue = 139
11:03:01  
11:03:01  java.lang.RuntimeException: Expected to get exit value of [0]
11:03:01  
11:03:01  	at jdk.test.lib.process.OutputAnalyzer.shouldHaveExitValue(OutputAnalyzer.java:489)
11:03:01  	at CallerAccessTest.main(CallerAccessTest.java:64)
11:03:01  	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
11:03:01  	at java.base/java.lang.reflect.Method.invoke(Method.java:577)
11:03:01  	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:312)
11:03:01  	at java.base/java.lang.Thread.run(Thread.java:889)
11:03:01  
11:03:01  JavaTest Message: Test threw exception: java.lang.RuntimeException
11:03:01  JavaTest Message: shutting down test

[babsingh]

Most recent grinder: https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/20769/

ProcessBuilder is doing the following:

export DYLD_LIBRARY_PATH=/Users/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/Contents/Home/bin/../lib:/Users/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/Contents/Home/bin/../lib/server

# Native executable
/Users/jenkins/workspace/Grinder/openjdkbinary/openjdk-test-image/jdk/jtreg/native/CallerAccessTest

While executing CallerAccessTest, there is a segfault. Core files are not generated for the segfault. Also, lldb does not work:

lldb -- /Users/jenkins/workspace/Grinder/openjdkbinary/openjdk-test-image/jdk/jtreg/native/CallerAccessTest
(lldb) target create "/Users/jenkins/workspace/Grinder/openjdkbinary/openjdk-test-image/jdk/jtreg/native/CallerAccessTest"
Current executable set to '/Users/jenkins/workspace/Grinder/openjdkbinary/openjdk-test-image/jdk/jtreg/native/CallerAccessTest' (x86_64).
(lldb) r
error: process exited with status -1 (developer mode is not enabled on this machine and this is a non-interactive debug session.)

Without lldb, we won't be able to find the cause of the segfault. We will need to enable developer mode for lldb to work on the Mac machines as per https://www.mail-archive.com/cfarm-users@lists.tetaneutral.net/msg00691.html. fyi @AdamBrousseau