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.27k stars 720 forks source link

jdk_util_1_FAILED java/util/ResourceBundle/Bug4168625Test.java testLowMemoryLoadstderr OOM #19462

Open JasonFengJ9 opened 3 months ago

JasonFengJ9 commented 3 months ago

Failure link

From an internal build:

java version "11.0.24-beta" 2024-07-16
IBM Semeru Runtime Certified Edition 11.0.24+1-202405040113 (build 11.0.24-beta+1)
Eclipse OpenJ9 VM 11.0.24+1-202405040113 (build master-2c34fcf0fb, JRE 11 Linux aarch64-64-Bit Compressed References 20240504_583 (JIT enabled, AOT enabled)
OpenJ9   - 2c34fcf0fb
OMR      - acd6f7e0b
JCL      - b17cf9f10c based on jdk-11.0.24+1)

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

Optional info

Failure output (captured from console output)

[2024-05-04T02:38:29.991Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache Mode650
[2024-05-04T02:38:29.991Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-UseCompressedOops -Xverbosegclog 

[2024-05-04T03:06:18.444Z] TEST: java/util/ResourceBundle/Bug4168625Test.java

[2024-05-04T03:06:18.445Z] STDOUT:
[2024-05-04T03:06:18.445Z] Bug4168625Test {
[2024-05-04T03:06:18.445Z]   testLowMemoryLoadstderr:
[2024-05-04T03:06:18.445Z] JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2024/05/03 22:49:06 - please wait.
[2024-05-04T03:06:18.445Z] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/javacore.20240503.224906.63733.0001.txt' in response to an event
[2024-05-04T03:06:18.445Z] JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/javacore.20240503.224906.63733.0001.txt
[2024-05-04T03:06:18.445Z] JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/Snap.20240503.224906.63733.0002.trc' in response to an event
[2024-05-04T03:06:18.445Z] JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/Snap.20240503.224906.63733.0002.trc
[2024-05-04T03:06:18.445Z] JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
[2024-05-04T03:06:18.445Z] JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2024/05/03 22:49:07 - please wait.
[2024-05-04T03:06:18.445Z] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/javacore.20240503.224907.63733.0003.txt' in response to an event
[2024-05-04T03:06:18.445Z] JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/javacore.20240503.224907.63733.0003.txt
[2024-05-04T03:06:18.445Z] JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/Snap.20240503.224907.63733.0004.trc' in response to an event
[2024-05-04T03:06:18.445Z] JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/Snap.20240503.224907.63733.0004.trc
[2024-05-04T03:06:18.445Z] JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
[2024-05-04T03:06:18.445Z] JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2024/05/03 22:49:08 - please wait.
[2024-05-04T03:06:18.445Z] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/javacore.20240503.224908.63733.0005.txt' in response to an event
[2024-05-04T03:06:18.445Z] JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/javacore.20240503.224908.63733.0005.txt
[2024-05-04T03:06:18.445Z] JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/Snap.20240503.224908.63733.0006.trc' in response to an event
[2024-05-04T03:06:18.445Z] JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/Snap.20240503.224908.63733.0006.trc
[2024-05-04T03:06:18.445Z] JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
[2024-05-04T03:06:18.445Z] JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2024/05/03 22:49:09 - please wait.
[2024-05-04T03:06:18.445Z] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work/scratch/2/javacore.20240503.224909.63733.0007.txt' in response to an event
[2024-05-04T03:06:18.445Z] 
[2024-05-04T03:06:18.445Z] TEST RESULT: Error. Agent communication error: java.net.SocketTimeoutException: Read timed out; check console log for any additional details
[2024-05-04T03:06:18.445Z] --------------------------------------------------
[2024-05-04T03:07:34.565Z] Test results: passed: 856; error: 1
[2024-05-04T03:07:58.195Z] Report written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/report/html/report.html
[2024-05-04T03:07:58.195Z] Results written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_testList_1/aqa-tests/TKG/output_17147882767729/jdk_util_1/work
[2024-05-04T03:07:58.195Z] Error: Some tests failed or other problems occurred.
[2024-05-04T03:07:58.195Z] -----------------------------------
[2024-05-04T03:07:58.195Z] jdk_util_1_FAILED
4XESTACKTRACE                at Bug4168625Test.causeResourceBundleCacheFlush(Bug4168625Test.java:538)
4XESTACKTRACE                at Bug4168625Test.testLowMemoryLoad(Bug4168625Test.java:307)

50x internal grinder - passed

dmitripivkine commented 3 months ago

There is OOM an attempt to allocate ~1G bytes object:

1STGCHTYPE     GC History
3STHSTTYPE     02:49:06:305487362 GMT j9mm.101 -   J9AllocateIndexableObject() returning NULL! 1073741840 bytes requested for object of class 0000FFFF9C215A00 from memory space 'Generational' id=0000FFFF9C0C53B0
3STHSTTYPE     02:49:06:305338239 GMT j9mm.134 -   Allocation failure end: newspace=11665408/13238272 oldspace=520267304/1601568768 loa=16016384/16016384
3STHSTTYPE     02:49:06:305299871 GMT j9mm.470 -   Allocation failure cycle end: newspace=11665408/13238272 oldspace=520267304/1601568768 loa=16016384/16016384

If it is intentional, so test should expect heap (Tenure really) is almost empty.

pshipton commented 3 months ago

The test is allocating memory until an OOM occurs. https://github.com/ibmruntimes/openj9-openjdk-jdk11/blob/openj9/test/jdk/java/util/ResourceBundle/Bug4168625Test.java#L532

pshipton commented 3 months ago

The test failed because it timed out, not because of the intentional OOMs. There is no indication or diagnostics to show what it was doing when it timed out. Given we couldn't reproduce it, we couldn't be overly concerned.