OOM running pull request testing on plinux #968

pshipton · 2018-01-17T22:15:21Z

We've seen this a couple of times today.

https://ci.eclipse.org/openj9/job/PullRequest-Sanity-linux_ppc-64_cmprssptrs_le/328/console

15:40:02 package org.openj9.resources.annotationPackage
15:40:02 PASSED: test_elementFormDefault
15:40:02 PASSED: test_isAnnotationPresent
15:40:02 
15:40:02 ===============================================
15:40:02     JCL_TEST_Test-Annotation-Package
15:40:02     Tests run: 2, Failures: 0, Skips: 0
15:40:02 ===============================================
15:40:02 
15:40:02 org.openj9.test.java.lang.
15:40:03 JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2018/01/17 20:40:03 - please wait.
15:40:03 JVMDUMP032I JVM requested System dump using '/home/jenkins/jenkins-agent/workspace/PullRequest-Sanity-linux_ppc-64_cmprssptrs_le/openj9/test/TestConfig/core.20180117.204003.20846.0001.dmp' in response to an event

It also occurred in testing for #962.
https://ci.eclipse.org/openj9/job/PullRequest-Sanity-linux_ppc-64_cmprssptrs_le/326/console

Both of these occurred on ub16-ppcle-3

It didn't reoccur on restart, which occurred on ub16-ppcle-2
https://ci.eclipse.org/openj9/job/PullRequest-Sanity-linux_ppc-64_cmprssptrs_le/329/console

The text was updated successfully, but these errors were encountered:

pshipton · 2018-01-17T22:20:44Z

Happened in the last nightly build https://ci.eclipse.org/openj9/view/Test/job/Test-Sanity-JDK9-linux_ppc-64_cmprssptrs_le/49/console
on ub16-ppcle-4

AdamBrousseau · 2018-01-17T22:26:18Z

Also 315 on ub16-ppcle-3
and
nightly 43 on ub16-ppcle-2

pshipton · 2018-01-17T22:52:24Z

Adam retrieved the diagnostic files from the nightly build, downloaded to Adam's team directory in j9build/cores.zip

1TISIGINFO Dump Event "systhrow" (00040000) Detail "java/lang/OutOfMemoryError" "Java heap space" received

3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at org/openj9/test/java/lang/Test_OutOfMemoryError.test_getMessage(Test_OutOfMemoryError.java:39)
4XESTACKTRACE                at jdk/internal/reflect/NativeMethodAccessorImpl.invoke0(Native Method)
4XESTACKTRACE                at jdk/internal/reflect/NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
4XESTACKTRACE                at jdk/internal/reflect/DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43(Compiled Code))
4XESTACKTRACE                at java/lang/reflect/Method.invoke(Method.java:564(Compiled Code))
4XESTACKTRACE                at org/testng/internal/MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104(Compiled Code))
4XESTACKTRACE                at org/testng/internal/Invoker.invokeMethod(Invoker.java:645(Compiled Code))
4XESTACKTRACE                at org/testng/internal/Invoker.invokeTestMethod(Invoker.java:851)
4XESTACKTRACE                at org/testng/internal/Invoker.invokeTestMethods(Invoker.java:1177)
4XESTACKTRACE                at org/testng/internal/TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
4XESTACKTRACE                at org/testng/internal/TestMethodWorker.run(TestMethodWorker.java:112)
4XESTACKTRACE                at org/testng/TestRunner.privateRun(TestRunner.java:756)
4XESTACKTRACE                at org/testng/TestRunner.run(TestRunner.java:610)
4XESTACKTRACE                at org/testng/SuiteRunner.runTest(SuiteRunner.java:387)
4XESTACKTRACE                at org/testng/SuiteRunner.runSequentially(SuiteRunner.java:382)
4XESTACKTRACE                at org/testng/SuiteRunner.privateRun(SuiteRunner.java:340)
4XESTACKTRACE                at org/testng/SuiteRunner.run(SuiteRunner.java:289)
4XESTACKTRACE                at org/testng/SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
4XESTACKTRACE                at org/testng/SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
4XESTACKTRACE                at org/testng/TestNG.runSuitesSequentially(TestNG.java:1293)
4XESTACKTRACE                at org/testng/TestNG.runSuitesLocally(TestNG.java:1218)
4XESTACKTRACE                at org/testng/TestNG.runSuites(TestNG.java:1133)
4XESTACKTRACE                at org/testng/TestNG.run(TestNG.java:1104)
4XESTACKTRACE                at org/testng/TestNG.privateMain(TestNG.java:1434)
4XESTACKTRACE                at org/testng/TestNG.main(TestNG.java:1403)

1STHEAPTOTAL   Total memory:                  2140078080 (0x000000007F8F0000)
1STHEAPINUSE   Total memory in use:              7006712 (0x00000000006AE9F8)
1STHEAPFREE    Total memory free:             2133071368 (0x000000007F241608)

3STHSTTYPE 06:38:20:895429948 GMT j9mm.101 - J9AllocateIndexableObject() returning NULL! 8589934600 bytes requested for object of class 0000000000478400 from memory space 'Generational' id=00003FFF940A0850

dmitripivkine · 2018-01-17T23:10:49Z

I have seen this before. This looks like an attempt of allocation of reference array with 2GB elements (intentional OOM). Test itself seems passed even with OOM thrown

pshipton · 2018-01-17T23:14:34Z

Looking at the console output, in this case the OOM seems to have terminated the VM.

pshipton · 2018-01-17T23:16:34Z

A working test should look like the following, and continue to run

org.openj9.test.java.lang.
JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2018/01/17 15:36:20 - please wait.
JVMDUMP032I JVM requested System dump using '/tmp/bld_376274/openj9/test/TestConfig/core.20180117.153620.1943.0001.dmp' in response to an event
JVMDUMP010I System dump written to /tmp/bld_376274/openj9/test/TestConfig/core.20180117.153620.1943.0001.dmp
JVMDUMP032I JVM requested Heap dump using '/tmp/bld_376274/openj9/test/TestConfig/heapdump.20180117.153620.1943.0002.phd' in response to an event
JVMDUMP010I Heap dump written to /tmp/bld_376274/openj9/test/TestConfig/heapdump.20180117.153620.1943.0002.phd
JVMDUMP032I JVM requested Java dump using '/tmp/bld_376274/openj9/test/TestConfig/javacore.20180117.153620.1943.0003.txt' in response to an event
JVMDUMP010I Java dump written to /tmp/bld_376274/openj9/test/TestConfig/javacore.20180117.153620.1943.0003.txt
JVMDUMP032I JVM requested Snap dump using '/tmp/bld_376274/openj9/test/TestConfig/Snap.20180117.153620.1943.0004.trc' in response to an event
JVMDUMP010I Snap dump written to /tmp/bld_376274/openj9/test/TestConfig/Snap.20180117.153620.1943.0004.trc
JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
[Support_Exec] [INFO] ***9-internal+0-adhoc.openj9.openjdk
JRE 9 IBM J9 2.9 Linux ppc64le-64 Compressed References 20180117_376274 (JIT enabled, AOT enabled)
OpenJ9   - b338003
OMR      - 3cda7d8***
org.openj9.test.java.lang.Test_System$TestSecurityManager
Exception in thread "no-op thread" org.openj9.test.java.lang.Test_ThreadGroup$1UncaughtException
	at org.openj9.test.java.lang.Test_ThreadGroup$14.uncaughtException(Test_ThreadGroup.java:1204) from jdk.internal.loader.ClassLoaders$AppClassLoader@76597532(file:/tmp/bld_376274/openj9/jvmtest/Java8andUp/GeneralTest.jar)
	at java.lang.Thread.uncaughtException(java.base@9-internal/Thread.java:1354) from jrt:/java.base
org.openj9.test.java.lang.Test_Throwable$TestException: test
PASSED: dummyReflectHelper
PASSED: testDefaultMethodInheritance
PASSED: testInterfaceMethodInheritance
...

pshipton · 2018-01-17T23:32:07Z

Seems I looked at the wrong javacore file. The message from the matching console is as follows. Available from the machine there is a core and heapdump for process 20821, but no javacore file. Seems like an unreported crash occurred either before or early in javacore creation.

01:43:37 JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2018/01/17 06:43:36 - please wait.
01:43:37 JVMDUMP032I JVM requested System dump using '/home/jenkins/jenkins-agent/workspace/Test-Sanity-JDK9-linux_ppc-64_cmprssptrs_le/openj9/test/TestConfig/core.20180117.064336.20821.0001.dmp' in response to an event
01:46:06 JVMPORT030W /proc/sys/kernel/core_pattern setting "|/usr/share/apport/apport %p %s %c %d %P" specifies that the core dump is to be piped to an external program.  Attempting to rename either core or core.20889.
01:46:06 
01:46:06 JVMDUMP010I System dump written to /home/jenkins/jenkins-agent/workspace/Test-Sanity-JDK9-linux_ppc-64_cmprssptrs_le/openj9/test/TestConfig/core.20180117.064336.20821.0001.dmp
01:46:06 JVMDUMP032I JVM requested Heap dump using '/home/jenkins/jenkins-agent/workspace/Test-Sanity-JDK9-linux_ppc-64_cmprssptrs_le/openj9/test/TestConfig/heapdump.20180117.064336.20821.0002.phd' in response to an event

pshipton · 2018-01-18T15:13:18Z

Note we don't have the ability to properly analyse the core files from OpenJ9 since there is no DDR support yet - #378

terryzuoty · 2018-02-13T16:18:29Z

This OOM message does not have relationship with JCL_TEST_Test-Annotation-Package because it was actually generated by
18:29:55 ===============================================
18:29:55 JCL_TEST_Java-Lang
18:29:55 Tests run: 357, Failures: 0, Skips: 0
18:29:55 ===============================================
(link https://ci.eclipse.org/openj9/job/PullRequest-Sanity-linux_ppc-64_cmprssptrs_le/397/consoleFull)

The test /test/Java8andUp/src/org/openj9/test/java/lang/Test_OutOfMemoryError.java belongs to the JCL_TEST_Java-Lang test target. In the test, it is generating the OOM on purpose and testing the OOM behaviour. And the same test failure message also exists in jvm.28 builds. I think this is an expected behaviour. If there is cmd options to hide this output, we can add it into the test cmds.

DanHeidinga · 2018-03-12T15:11:02Z

@TianyuZuo Any update on this?

terryzuoty · 2018-03-12T15:33:52Z

This should be fixed by #1169

DanHeidinga · 2018-03-13T01:57:30Z

Closing this. Please reopen if the issue is seen again.

smlambert mentioned this issue Jan 17, 2018

Find and archive any core / dmp files in post test step #969

Closed

keithc-ca mentioned this issue Jan 18, 2018

Remove obsolete remnants of rcm (resource managed) and buildinfo #916

Merged

DanHeidinga mentioned this issue Jan 18, 2018

Fix timing hole releasing safe point VM access #978

Merged

pshipton mentioned this issue Jan 18, 2018

Aborted pull request testing contains confusing message #981

Closed

DanHeidinga mentioned this issue Jan 26, 2018

Change some tracepoints from level 2 to 3, disabled by default #1029

Merged

pshipton mentioned this issue Jan 30, 2018

Create release notes for V0.8 #1052

Closed

mstoodle added the test failure label Jan 31, 2018

This was referenced Feb 6, 2018

Ensure primitive types are assigned to java.base #1103

Merged

Use decompressedArrayCopy in StringBuilder/StringBuffer to remove redundant bound checks #1098

Merged

DanHeidinga closed this as completed Mar 13, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

OOM running pull request testing on plinux #968

OOM running pull request testing on plinux #968

pshipton commented Jan 17, 2018 •

edited

Loading

pshipton commented Jan 17, 2018

AdamBrousseau commented Jan 17, 2018 •

edited

Loading

pshipton commented Jan 17, 2018 •

edited

Loading

dmitripivkine commented Jan 17, 2018

pshipton commented Jan 17, 2018

pshipton commented Jan 17, 2018

pshipton commented Jan 17, 2018 •

edited

Loading

pshipton commented Jan 18, 2018 •

edited

Loading

terryzuoty commented Feb 13, 2018

DanHeidinga commented Mar 12, 2018

terryzuoty commented Mar 12, 2018

DanHeidinga commented Mar 13, 2018

OOM running pull request testing on plinux #968

OOM running pull request testing on plinux #968

Comments

pshipton commented Jan 17, 2018 • edited Loading

pshipton commented Jan 17, 2018

AdamBrousseau commented Jan 17, 2018 • edited Loading

pshipton commented Jan 17, 2018 • edited Loading

dmitripivkine commented Jan 17, 2018

pshipton commented Jan 17, 2018

pshipton commented Jan 17, 2018

pshipton commented Jan 17, 2018 • edited Loading

pshipton commented Jan 18, 2018 • edited Loading

terryzuoty commented Feb 13, 2018

DanHeidinga commented Mar 12, 2018

terryzuoty commented Mar 12, 2018

DanHeidinga commented Mar 13, 2018

pshipton commented Jan 17, 2018 •

edited

Loading

AdamBrousseau commented Jan 17, 2018 •

edited

Loading

pshipton commented Jan 17, 2018 •

edited

Loading

pshipton commented Jan 17, 2018 •

edited

Loading

pshipton commented Jan 18, 2018 •

edited

Loading