Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

openJcePlusTests_0_FAILED ibm.jceplus.junit.openjceplus.multithread.TestAES_128 detail "java/lang/OutOfMemoryError", exception "native memory exhausted" #19887

Closed
JasonFengJ9 opened this issue Jul 19, 2024 · 10 comments

Comments

@JasonFengJ9
Copy link
Member

JasonFengJ9 commented Jul 19, 2024

Failure link

From an internal build(paix825):

java version "21.0.4-beta" 2024-07-16
IBM Semeru Runtime Certified Edition 21.0.4+6-202407180209 (build 21.0.4-beta+6-202407180209)
Eclipse OpenJ9 VM 21.0.4+6-202407180209 (build master-0e944e75c8, JRE 21 AIX ppc64-64-Bit Compressed References 20240718_216 (JIT enabled, AOT enabled)
OpenJ9   - 0e944e75c8
OMR      - de311dd2b
JCL      - 4f7da7b3b based on jdk-21.0.4+6)

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

Optional info

Failure output (captured from console output)

[2024-07-18T19:24:08.242Z] variation: NoOptions
[2024-07-18T19:24:08.242Z] JVM_OPTIONS:  

[2024-07-18T19:25:07.405Z]      [test]     [junit] Test calling: ibm.jceplus.junit.openjceplus.multithread.TestAES_128
[2024-07-18T19:25:07.405Z]      [test]     [junit] executing testAES_128
[2024-07-18T19:25:07.405Z]      [test]     [junit] executing testAES_128
[2024-07-18T19:25:07.405Z]      [test]     [junit] executing testAES_128
[2024-07-18T19:25:07.405Z]      [test]     [junit] executing testAES_128
[2024-07-18T19:25:07.405Z]      [test]     [junit] executing testAES_128
[2024-07-18T19:25:07.405Z]      [test]     [junit] executing testAES_128
[2024-07-18T19:25:07.405Z]      [test]     [junit] executing testAES_128
[2024-07-18T19:25:07.405Z]      [test]     [junit] executing testAES_128
[2024-07-18T19:25:20.734Z]      [test]     [junit] JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "native memory exhausted" at 2024/07/18 15:25:18 - please wait.

[2024-07-18T19:25:44.697Z]      [test]     [junit] Test finished: ibm.jceplus.junit.openjceplus.multithread.TestAES_128

[2024-07-18T19:25:47.016Z] openJcePlusTests_0_FAILED

50x internal grinder - 5 failures reproduced along with a few others.

@JasonFengJ9
Copy link
Member Author

Also seen at JDK22 ppc64_aix 0.46 rc1

openjdk version "22.0.2" 2024-07-16
IBM Semeru Runtime Open Edition 22.0.2.0-rc1 (build 22.0.2+9)
Eclipse OpenJ9 VM 22.0.2.0-rc1 (build v0.46.0-release-6c99fa94be, JRE 22 AIX ppc64-64-Bit Compressed References 20240716_17 (JIT enabled, AOT enabled)
OpenJ9   - 6c99fa94be
OMR      - 840a9adba
JCL      - cfe2b5689d1 based on jdk-22.0.2+9)
[2024-07-22T15:14:18.640Z]      [test]     [junit] executing testAES_128
[2024-07-22T15:15:14.231Z]      [test]     [junit] JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "native memory exhausted" at 2024/07/22 11:15:07 - please wait.

[2024-07-22T15:15:53.579Z] openJcePlusTests_0_FAILED

@pshipton
Copy link
Member

@KostasTsiounis pls help find someone to take a look at this failure, we need to determine if a fix is required in 0.46.

@pshipton
Copy link
Member

Related to #19642?

@KostasTsiounis
Copy link
Contributor

This is the same test, but a different error. #19642 was a segmentation fault, while this is an out of memory, more specifically java.lang.OutOfMemoryError: Failed to create a thread: retVal -1073741830, errno 11.

We have observed similar failures in a memory issue that was originally reported in Java 8 (that involves the test that was running MessageDigest.getInstance() by multiple threads in a tight loop to which we added a explicit call to the GC). It looks like the fact that we are running so many threads leads to the GC being overwhelmed and eventually running out of memory. AIX seems to be affected more.

I don't think this is a blocker for 0.46. I am already working on a solution to replace finalizers with Cleaners, but it will most likely be ready for the next release and I am not exactly sure how much it will help eventually.

I will look further look into it, but I don't think this a common use case where that many threads run so many iterations of algorithms. Plus, we haven't encountered in other platforms, unless we crank up the threads to 20 or more per test.

@jasonkatonica
Copy link
Contributor

Most likely this should be fixed due to a overlay that was found in #19642. I believe that this issue could be closed until we see this occur again.

@JasonFengJ9
Copy link
Member Author

Closing as per #19887 (comment)

@JasonFengJ9
Copy link
Member Author

JasonFengJ9 commented Aug 7, 2024

JDK11 ppc64_aix(pll011)

java version "11.0.25-beta" 2024-10-15
IBM Semeru Runtime Certified Edition 11.0.25+1-202408052207 (build 11.0.25-beta+1-202408052207)
Eclipse OpenJ9 VM 11.0.25+1-202408052207 (build master-27dac39d2c, JRE 11 AIX ppc64-64-Bit Compressed References 20240805_902 (JIT enabled, AOT enabled)
OpenJ9   - 27dac39d2c
OMR      - 9ccff3cf2
JCL      - f10542c9cc based on jdk-11.0.25+1)

[2024-08-06T00:19:44.073Z] variation: NoOptions
[2024-08-06T00:19:44.073Z] JVM_OPTIONS:  

[2024-08-06T00:20:08.817Z]      [test]     [junit] executing testAES_128
[2024-08-06T00:20:20.276Z]      [test]     [junit] JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "native memory exhausted" at 2024/08/05 20:20:19 - please wait.
[2024-08-06T00:20:20.276Z]      [test]     [junit] JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_ppc64_aix_testList_0/aqa-tests/TKG/output_17229026382186/openJcePlusTests_0/core.20240805.202019.20971788.0001.dmp' in response to an event
[2024-08-06T00:21:12.571Z]      [test]     [junit] JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.functional_ppc64_aix_testList_0/aqa-tests/TKG/output_17229026382186/openJcePlusTests_0/core.20240805.202019.20971788.0001.dmp
[2024-08-06T00:21:12.571Z]      [test]     [junit] JVMDUMP032I JVM requested Heap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_ppc64_aix_testList_0/aqa-tests/TKG/output_17229026382186/openJcePlusTests_0/heapdump.20240805.202019.20971788.0002.phd' in response to an event
[2024-08-06T00:21:12.571Z]      [test]     [junit] JVMDUMP016I Aborting: Cannot create file (/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_ppc64_aix_testList_0/aqa-tests/TKG/output_17229026382186/openJcePlusTests_0/heapdump.20240805.202019.20971788.0002.phd)
[2024-08-06T00:21:12.571Z]      [test]     [junit] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_ppc64_aix_testList_0/aqa-tests/TKG/output_17229026382186/openJcePlusTests_0/javacore.20240805.202019.20971788.0003.txt' in response to an event
[2024-08-06T00:21:12.571Z]      [test]     [junit] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 74.347 sec
[2024-08-06T00:21:12.571Z]      [test]     [junit] JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.functional_ppc64_aix_testList_0/aqa-tests/TKG/output_17229026382186/openJcePlusTests_0/javacore.20240805.202019.20971788.0003.txt
[2024-08-06T00:21:12.571Z]      [test]     [junit] JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_ppc64_aix_testList_0/aqa-tests/TKG/output_17229026382186/openJcePlusTests_0/Snap.20240805.202019.20971788.0004.trc' in response to an event
[2024-08-06T00:21:12.571Z]      [test]     [junit] JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.functional_ppc64_aix_testList_0/aqa-tests/TKG/output_17229026382186/openJcePlusTests_0/Snap.20240805.202019.20971788.0004.trc
[2024-08-06T00:21:12.571Z]      [test]     [junit] JVMTRCE010W Native memory allocation failure, falling back to nodynamic trace settings.
[2024-08-06T00:21:12.571Z]      [test]     [junit] JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
[2024-08-06T00:21:12.571Z]      [test] 
[2024-08-06T00:21:12.571Z]      [test] BUILD FAILED
[2024-08-06T00:21:12.571Z]      [test] /home/jenkins/workspace/Test_openjdk11_j9_extended.functional_ppc64_aix_testList_0/aqa-tests/TKG/output_17229026382186/openJcePlusTests_0/test.xml:69: Test ibm.jceplus.junit.TestMultithread failed
[2024-08-06T00:21:12.571Z]      [test] 
[2024-08-06T00:21:12.571Z]      [test] Total time: 1 minute 25 seconds
[2024-08-06T00:21:12.571Z] 
[2024-08-06T00:21:12.571Z] BUILD FAILED
[2024-08-06T00:21:12.571Z] /home/jenkins/workspace/Test_openjdk11_j9_extended.functional_ppc64_aix_testList_0/aqa-tests/TKG/output_17229026382186/openJcePlusTests_0/test.xml:35: Java returned: 1
[2024-08-06T00:21:12.571Z] 
[2024-08-06T00:21:12.571Z] Total time: 1 minute 27 seconds
[2024-08-06T00:21:12.571Z] -----------------------------------
[2024-08-06T00:21:12.571Z] openJcePlusTests_0_FAILED

50x grinder - reproduced once, other failures are #19981.

This failure appeared again in yesterday's build, and re-open.

@JasonFengJ9 JasonFengJ9 reopened this Aug 7, 2024
@jasonkatonica
Copy link
Contributor

There are known issues in the multi-threading testcases to make them unsafe. We are working on a series of fixes in this area which we are hoping helps this case. For now moving this to the next release.

@jasonkatonica
Copy link
Contributor

Numerous fixes associated with multi-threading testing have been delivered in OpenJCEPlus via this PR:

IBM/OpenJCEPlus#207

This fix is expected to be present in .49 code base. This issue can be closed.

Copy link

Issue Number: 19887
Status: Closed
Actual Components: test failure, comp:crypto
Actual Assignees: No one :(
PR Assignees: No one :(

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants