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.28k stars 721 forks source link

OpenJDK java/util/StringJoiner/StringJoinerTest OutOfMemoryError: Java heap space #18708

Open pshipton opened 10 months ago

pshipton commented 10 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_windows_OMR_testList_0/60/ - win2012-x86-1 jdk_util_0 java/util/StringJoiner/StringJoinerTest.java

javacore and verbosegc at \aqa-tests\TKG\output_17046684601791\jdk_util_0\work\java\util\StringJoiner\StringJoinerTest\ https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_sanity.openjdk_x86-64_windows_OMR_testList_0/60/openjdk_test_output.tar.gz

21:07:10  command: testng -Xmx4g -XX:+CompactStrings StringJoinerTest
21:07:10  reason: User specified action: run testng/othervm -Xmx4g -XX:+CompactStrings StringJoinerTest 
21:07:10  started: Sun Jan 07 20:06:56 CST 2024
21:07:10  Mode: othervm [/othervm specified]
21:07:10  Additional options from @modules: --add-modules java.base --add-exports java.base/jdk.internal.util=ALL-UNNAMED
21:07:10  finished: Sun Jan 07 20:06:58 CST 2024
21:07:10  elapsed time (seconds): 1.547
21:07:10  configuration:
21:07:10  Boot Layer
21:07:10    add modules: java.base                   
21:07:10    add exports: java.base/jdk.internal.util ALL-UNNAMED
21:07:10  
21:07:10  STDOUT:
21:07:10  STDERR:
21:07:10  JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2024/01/07 20:06:58 - please wait.
21:07:10  JVMDUMP032I JVM requested Java dump using 'F:\Users\jenkins\workspace\Test_openjdk17_j9_sanity.openjdk_x86-64_windows_OMR_testList_0\aqa-tests\TKG\output_17046684601791\jdk_util_0\work\scratch\4_136\javacore.20240107.200658.5292.0001.txt' in response to an event
21:07:10  JVMDUMP010I Java dump written to F:\Users\jenkins\workspace\Test_openjdk17_j9_sanity.openjdk_x86-64_windows_OMR_testList_0\aqa-tests\TKG\output_17046684601791\jdk_util_0\work\scratch\4_136\javacore.20240107.200658.5292.0001.txt
21:07:10  JVMDUMP032I JVM requested Snap dump using 'F:\Users\jenkins\workspace\Test_openjdk17_j9_sanity.openjdk_x86-64_windows_OMR_testList_0\aqa-tests\TKG\output_17046684601791\jdk_util_0\work\scratch\4_136\Snap.20240107.200658.5292.0002.trc' in response to an event
21:07:10  JVMDUMP010I Snap dump written to F:\Users\jenkins\workspace\Test_openjdk17_j9_sanity.openjdk_x86-64_windows_OMR_testList_0\aqa-tests\TKG\output_17046684601791\jdk_util_0\work\scratch\4_136\Snap.20240107.200658.5292.0002.trc
21:07:10  JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
21:07:10  org.testng.TestNGException: 
21:07:10  An error occurred while instantiating class StringJoinerTest: Java heap space
21:07:10    at org.testng.internal.InstanceCreator.createInstanceUsingObjectFactory(InstanceCreator.java:123)
21:07:10    at org.testng.internal.InstanceCreator.createInstance(InstanceCreator.java:79)
21:07:10    at org.testng.internal.ClassImpl.getDefaultInstance(ClassImpl.java:109)
21:07:10    at org.testng.internal.ClassImpl.getInstances(ClassImpl.java:167)
21:07:10    at org.testng.TestClass.getInstances(TestClass.java:102)
21:07:10    at org.testng.TestClass.initTestClassesAndInstances(TestClass.java:82)
21:07:10    at org.testng.TestClass.init(TestClass.java:74)
21:07:10    at org.testng.TestClass.<init>(TestClass.java:39)
21:07:10    at org.testng.TestRunner.initMethods(TestRunner.java:457)
21:07:10    at org.testng.TestRunner.init(TestRunner.java:336)
21:07:10    at org.testng.TestRunner.init(TestRunner.java:289)
21:07:10    at org.testng.TestRunner.<init>(TestRunner.java:180)
21:07:10    at org.testng.SuiteRunner$DefaultTestRunnerFactory.newTestRunner(SuiteRunner.java:613)
21:07:10    at org.testng.SuiteRunner.init(SuiteRunner.java:178)
21:07:10    at org.testng.SuiteRunner.<init>(SuiteRunner.java:112)
21:07:10    at org.testng.TestNG.createSuiteRunner(TestNG.java:1306)
21:07:10    at org.testng.TestNG.createSuiteRunners(TestNG.java:1282)
21:07:10    at org.testng.TestNG.runSuitesLocally(TestNG.java:1131)
21:07:10    at org.testng.TestNG.runSuites(TestNG.java:1069)
21:07:10    at org.testng.TestNG.run(TestNG.java:1037)
21:07:10    at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:102)
21:07:10    at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:58)
21:07:10    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
21:07:10    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
21:07:10    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
21:07:10    at java.base/java.lang.reflect.Method.invoke(Method.java:574)
21:07:10    at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
21:07:10    at java.base/java.lang.Thread.run(Thread.java:857)
21:07:10  Caused by: java.lang.OutOfMemoryError: Java heap space
21:07:10    at java.base/java.lang.String.repeat(String.java:5198)
21:07:10    at StringJoinerTest.<clinit>(StringJoinerTest.java:52)
21:07:10    at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
21:07:10    at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
21:07:10    at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
21:07:10    at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
21:07:10    at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
21:07:10    at org.testng.internal.ObjectFactoryImpl.newInstance(ObjectFactoryImpl.java:23)
21:07:10    at org.testng.internal.InstanceCreator.instantiateUsingDefaultConstructor(InstanceCreator.java:193)
21:07:10    at org.testng.internal.InstanceCreator.createInstanceUsingObjectFactory(InstanceCreator.java:113)
21:07:10    ... 27 more
3STHSTTYPE     02:06:58:190465642 GMT j9mm.101 -   J9AllocateIndexableObject() returning NULL! 2147483648 bytes requested for object of class 000000000004B300 from memory space 'Generational' id=0000002859AD6340
3STHSTTYPE     02:06:58:190355742 GMT j9mm.134 -   Allocation failure end: newspace=1889960/3014656 oldspace=5026808/6291456 loa=0/0
3STHSTTYPE     02:06:58:190284872 GMT j9mm.470 -   Allocation failure cycle end: newspace=1889960/3014656 oldspace=5026808/6291456 loa=0/0
3STHSTTYPE     02:06:58:190168097 GMT j9mm.475 -   GlobalGC end: workstackoverflow=171798691840 overflowcount=0 memory=6916768/9306112
3STHSTTYPE     02:06:58:189919499 GMT j9mm.506 - * Failed to commit memory: address=00000007005F0000, size=3063414784
3STHSTTYPE     02:06:58:189767749 GMT j9mm.90 -   GlobalGC collect complete
pshipton commented 10 months ago

@dmitripivkine fyi

pshipton commented 10 months ago

There was https://github.com/eclipse-openj9/openj9/issues/10631. Maybe another machine problem?

dmitripivkine commented 10 months ago

OOM caused by request to allocate very large object (2G bytes), I am not sure it was intended:

02:06:58.196820867                 0x0       j9mm.101  Event       J9AllocateIndexableObject() returning NULL! 2147483648 bytes requested for object of class 0x4b300 from memory space 'Generational' id=0x2859ad6340
02:06:58.196986766           *0x1f0b00       j9mm.126  Event       at 0x2f7160 org/testng/SuiteRunner.<init>(Lorg/testng/internal/IConfiguration;Lorg/testng/xml/XmlSuite;Ljava/lang/String;Lorg/testng/ITestRunnerFactory;ZLjava/util/List;Ljava/util/Collection;Ljava/util/Collection;Ljava/util/Collection;Lorg/testng/DataProviderHolder;Ljava/util/Comparator;)V, jit 0x0, pc 0x286a651b26
02:06:58.196993343            0x1f0b00       j9mm.126  Event       at 0x2317a8 org/testng/TestNG.createSuiteRunner(Lorg/testng/xml/XmlSuite;)Lorg/testng/SuiteRunner;, jit 0x0, pc 0x286a5a49d6
02:06:58.196999410            0x1f0b00       j9mm.126  Event       at 0x231788 org/testng/TestNG.createSuiteRunners(Lorg/testng/internal/SuiteRunnerMap;Lorg/testng/xml/XmlSuite;)V, jit 0x0, pc 0x286a5a4879
02:06:58.197005796            0x1f0b00       j9mm.126  Event       at 0x2316e8 org/testng/TestNG.runSuitesLocally()Ljava/util/List;, jit 0x0, pc 0x286a5a4303
02:06:58.197011831            0x1f0b00       j9mm.126  Event       at 0x231648 org/testng/TestNG.runSuites()Ljava/util/List;, jit 0x0, pc 0x286a5a3fb5
02:06:58.197018153            0x1f0b00       j9mm.126  Event       at 0x231628 org/testng/TestNG.run()V, jit 0x0, pc 0x286a5a3f09
02:06:58.197026020            0x1f0b00       j9mm.126  Event       at 0x22c2a8 com/sun/javatest/regtest/agent/TestNGRunner.main(Ljava/lang/ClassLoader;[Ljava/lang/String;)V, jit 0x0, pc 0x286a59c1cf
02:06:58.197032246            0x1f0b00       j9mm.126  Event       at 0x22c288 com/sun/javatest/regtest/agent/TestNGRunner.main([Ljava/lang/String;)V, jit 0x0, pc 0x286a59c05a
02:06:58.197038903            0x1f0b00       j9mm.126  Event       at 0x156448 jdk/internal/reflect/NativeMethodAccessorImpl.invoke0(Ljava/lang/reflect/Method;Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;, jit 0x286a0a9ca8, pc 0x7ffe19e05952
02:06:58.197045177            0x1f0b00       j9mm.126  Event       at 0x156408 jdk/internal/reflect/NativeMethodAccessorImpl.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;, jit 0x0, pc 0x28660c84b5
02:06:58.197051690            0x1f0b00       j9mm.126  Event       at 0x156768 jdk/internal/reflect/DelegatingMethodAccessorImpl.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;, jit 0x0, pc 0x28660c8752
02:06:58.197057916            0x1f0b00       j9mm.126  Event       at 0x70068 java/lang/reflect/Method.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;, jit 0x0, pc 0x2865f4b921
02:06:58.197064493            0x1f0b00       j9mm.126  Event       at 0x22b9f8 com/sun/javatest/regtest/agent/MainWrapper$MainTask.run()V, jit 0x0, pc 0x286a59b762
02:06:58.197070847            0x1f0b00       j9mm.126  Event       at 0x78700 java/lang/Thread.run()V, jit 0x0, pc 0x2865f596a5
dmitripivkine commented 10 months ago

... or may be it is a machine failure over all, there is the failure an attempt to expand object heap:

02:06:58.196271828                 0x0       j9mm.506  Exception * Failed to commit memory: address=0x7005f0000, size=3063414784
pshipton commented 3 weeks ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_windows_Nightly_testList_1/252

dmitripivkine commented 3 weeks ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_windows_Nightly_testList_1/252

This failure is different, this is machine issue - memory can not be allocated:

3STHSTTYPE     05:47:44:382562984 GMT j9mm.101 -   J9AllocateIndexableObject() returning NULL! 2147483656 bytes requested for object of class 0000009B5926D700 from memory space 'Generational' id=0000009B4D178BB0
3STHSTTYPE     05:47:44:382412434 GMT j9mm.134 -   Allocation failure end: newspace=2668456/3538944 oldspace=4178304/6291456 loa=0/0
3STHSTTYPE     05:47:44:382331771 GMT j9mm.470 -   Allocation failure cycle end: newspace=2668456/3538944 oldspace=4178304/6291456 loa=0/0
3STHSTTYPE     05:47:44:382205659 GMT j9mm.475 -   GlobalGC end: workstackoverflow=665719930880 overflowcount=0 memory=6846760/9830400
3STHSTTYPE     05:47:44:381926797 GMT j9mm.506 - * Failed to commit memory: address=00007FF5516E0000, size=3064594432 <------------------------
3STHSTTYPE     05:47:44:381747234 GMT j9mm.90 -   GlobalGC collect complete
3STHSTTYPE     05:47:44:381613868 GMT j9mm.137 -   Compact end: bytesmoved=1398504

@pshipton I think this machine win2012-x86-1 should be rebooted.

pshipton commented 3 weeks ago

They should be automatically rebooted once or twice a day. I think we are getting rid of all the win2012 machines soon, they are out of support. @AdamBrousseau ?

AdamBrousseau commented 3 weeks ago

Yes, the windows nodes are restarted 2x daily https://openj9-jenkins.osuosl.org/job/Sanitize-Nodes_windows/ Windows rebuilds are on the list. At the moment we are focusing on xlinux.