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.26k stars 717 forks source link

java/lang/ref/SoftReference/Pin.java "systhrow", detail "java/lang/OutOfMemoryError" #18429

Open JasonFengJ9 opened 9 months ago

JasonFengJ9 commented 9 months ago

Failure link

From an internal build(mac11x64rt04):

java version "21.0.1-beta" 2023-10-17
IBM Semeru Runtime Certified Edition 21.0.1+12-202311072235 (build 21.0.1-beta+12-202311072235)
Eclipse OpenJ9 VM 21.0.1+12-202311072235 (build master-70f56555a, JRE 21 Mac OS X amd64-64-Bit Compressed References 20231107_30 (JIT enabled, AOT enabled)
OpenJ9   - 70f56555a
OMR      - 2a9a7f4e4
JCL      - aec9b74fc based on jdk-21.0.1+12)

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

Optional info

Failure output (captured from console output)

[2023-11-08T00:10:30.980Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode501
[2023-11-08T00:10:30.980Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -Xjit -Xgcpolicy:balanced -Xnocompressedrefs 

[2023-11-08T00:15:43.414Z] TEST: java/lang/ref/SoftReference/Pin.java

[2023-11-08T00:15:43.414Z] STDOUT:
[2023-11-08T00:15:43.414Z] STDERR:
[2023-11-08T00:15:43.414Z] Filling array with 128 SoftReferences to blocks of 32768 bytes.
[2023-11-08T00:15:43.414Z] Allowing SoftReferences to be enqueued.
[2023-11-08T00:15:43.414Z] Invoking get() on SoftReferences.
[2023-11-08T00:15:43.414Z] Forcing desperate garbage collection...
[2023-11-08T00:15:43.414Z] JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/11/07 19:15:41 - please wait.

[2023-11-08T00:15:43.414Z] JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
[2023-11-08T00:15:43.414Z] Exception in thread "Attach API wait loop" java/lang/OutOfMemoryError: Java heap space
[2023-11-08T00:15:43.414Z]  at java/lang/Throwable.printStackTrace (java.base@21.0.1-beta/Throwable.java:554)
[2023-11-08T00:15:43.414Z]  at java/lang/Throwable.printStackTraceHelper (java.base@21.0.1-beta/Throwable.java:338)
[2023-11-08T00:15:43.414Z]  at java/lang/Throwable.printStackTrace (java.base@21.0.1-beta/Throwable.java:307)
[2023-11-08T00:15:43.414Z]  at java/lang/Throwable.printStackTrace (java.base@21.0.1-beta/Throwable.java:250)
[2023-11-08T00:15:43.414Z] JVMDUMP032I JVM requested Snap dump using '/Users/jenkins/workspace/Test_openjdk21_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16994022294149/jdk_lang_j9_0/work/scratch/1/Snap.20231107.191541.63241.0004.trc' in response to an event
[2023-11-08T00:15:43.414Z] JVMDUMP010I Snap dump written to {nothing to snap}
[2023-11-08T00:15:43.414Z] JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
[2023-11-08T00:15:43.414Z] java.lang.OutOfMemoryError: Java heap space
[2023-11-08T00:15:43.414Z]  at Pin.main(Pin.java:80)
[2023-11-08T00:15:43.414Z]  at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
[2023-11-08T00:15:43.414Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:580)
[2023-11-08T00:15:43.414Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
[2023-11-08T00:15:43.414Z]  at java.base/java.lang.Thread.run(Thread.java:1595)
[2023-11-08T00:15:43.414Z] 
[2023-11-08T00:15:43.414Z] JavaTest Message: Test threw exception: java.lang.OutOfMemoryError: Java heap space

[2023-11-08T00:15:43.414Z] TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.OutOfMemoryError: Java heap space
[2023-11-08T00:15:43.415Z] --------------------------------------------------
[2023-11-08T00:21:50.211Z] Test results: passed: 922; failed: 1
[2023-11-08T00:22:00.906Z] Report written to /Users/jenkins/workspace/Test_openjdk21_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16994022294149/jdk_lang_j9_0/report/html/report.html
[2023-11-08T00:22:00.906Z] Results written to /Users/jenkins/workspace/Test_openjdk21_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16994022294149/jdk_lang_j9_0/work
[2023-11-08T00:22:00.906Z] Error: Some tests failed or other problems occurred.
[2023-11-08T00:22:00.906Z] -----------------------------------
[2023-11-08T00:22:00.906Z] jdk_lang_j9_0_FAILED

50x internal grinder - passed

pshipton commented 9 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_s390x_linux_OMR_testList_0/49

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_sanity.openjdk_s390x_linux_OMR_testList_0/49/openjdk_test_output.tar.gz

@dmitripivkine pls take a look

dmitripivkine commented 9 months ago

There is no system core stored in results (javacore and snap traces only), so not much I can do. One observation this test runs with 16m heap. Is it intentional? There are seven (sic!) -Xmx options in command line, all of them 512m except most right one 16m.

llxia commented 9 months ago

Openjdk has the option set: https://github.com/ibmruntimes/openj9-openjdk-jdk17/blob/3dfae786468898b7e68263de89961729443b6aef/test/jdk/java/lang/ref/SoftReference/Pin.java#L27

dmitripivkine commented 9 months ago

Looking to the source... I believe OOM has been triggered by line https://github.com/ibmruntimes/openj9-openjdk-jdk17/blob/3dfae786468898b7e68263de89961729443b6aef/test/jdk/java/lang/ref/SoftReference/Pin.java#L70 There is output for Forcing desperate garbage collection..., so we got so far. Starting line 71 there is try and while loop forcing and catching OOM. Or, alternatively, intentional OOM has not been caught.

dmitripivkine commented 9 months ago

@tajila Looking to Snap traces I can see many system GC in a raw. Is it possible we are missing to catch OOM?

tajila commented 9 months ago

The systhrow OOM event is thrown by the attach API thread. It is a legitimate possibility with this test. The only way to mitigate this is to disable attach API when running this test.

dmitripivkine commented 9 months ago

The systhrow OOM event is thrown by the attach API thread. It is a legitimate possibility with this test. The only way to mitigate this is to disable attach API when running this test.

@pshipton @llxia @JasonFengJ9 There are many tests rely on artificially generated OOM handling. I am not sure about scale of the problem, how often we have it. Is it reasonable to review test base and try to improve builds stability by selectively disable attach API?

pshipton commented 6 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_s390x_linux_OpenJDK8_testList_1/12 jdk_lang_j9_0 java/lang/ref/SoftReference/Pin.java

04:11:52  Filling array with 128 SoftReferences to blocks of 32768 bytes.
04:11:52  Allowing SoftReferences to be enqueued.
04:11:52  Invoking get() on SoftReferences.
04:11:52  Forcing desperate garbage collection...
04:11:52  JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2024/02/09 09:11:49 - please wait.