Openjdk-tests: thorntail-mp-tck test fails on openjdk8-openj9 due to OOM building tests

[lumpfish]

The thorntail-mp-tck test suite is failing on openj9 jdk8 builds it appears because the openj9 vm goes out of memory creating the bom-2.5.1.Final-SNAPSHOT-m2repo.zip file (one of the build steps).

An example failure: https://ci.adoptopenjdk.net/job/Test_openjdk8_hs_sanity.external_thorntail-mp-tck_x86-64_linux/211/

This is the error text around the point of failure.

20:37:49  [INFO] Reading assembly descriptor: /thorntail/boms/src/main/assembly/m2repo-zip.xml
20:37:53  [INFO] Building zip: /thorntail/boms/bom/target/bom-2.5.1.Final-SNAPSHOT-m2repo.zip
20:38:10  JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2019/11/25 20:38:08 - please wait.
20:38:10  JVMDUMP032I JVM requested System dump using '/thorntail/core.20191125.203808.28.0001.dmp' in response to an event
20:38:13  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.2803.
20:38:13  
20:38:13  JVMPORT048E Failed to create system dump because a non-regular file "/thorntail/core" exists with the same name as the expected system dump file
20:38:13  JVMDUMP012E Error in System dump: /thorntail/core.20191125.203808.28.0001.dmp
20:38:13  JVMDUMP032I JVM requested Heap dump using '/thorntail/heapdump.20191125.203808.28.0002.phd' in response to an event
20:38:20  JVMDUMP010I Heap dump written to /thorntail/heapdump.20191125.203808.28.0002.phd
20:38:20  JVMDUMP032I JVM requested Java dump using '/thorntail/javacore.20191125.203808.28.0003.txt' in response to an event
20:38:20  JVMDUMP010I Java dump written to /thorntail/javacore.20191125.203808.28.0003.txt
20:38:20  JVMDUMP032I JVM requested Snap dump using '/thorntail/Snap.20191125.203808.28.0004.trc' in response to an event
20:38:21  JVMDUMP010I Snap dump written to /thorntail/Snap.20191125.203808.28.0004.trc
20:38:21  JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
20:38:21  [INFO] ------------------------------------------------------------------------
20:38:21  [INFO] Reactor Summary for Root 2.5.1.Final-SNAPSHOT:
20:38:21  [INFO] 
20:38:21  [INFO] Thorntail Build Resources .......................... SUCCESS [01:30 min]
20:38:21  [INFO] Root ............................................... SUCCESS [ 45.715 s]
20:38:21  [INFO] Thorntail Build Parent ............................. SUCCESS [ 19.588 s]
20:38:21  [INFO] Bootstrap .......................................... SUCCESS [ 26.478 s]
20:38:21  [INFO] Thorntail: Meta SPI ................................ SUCCESS [  1.019 s]
20:38:21  [INFO] Thorntail: SPI ..................................... SUCCESS [ 16.558 s]
20:38:21  [INFO] Container .......................................... SUCCESS [ 44.618 s]
20:38:21  [INFO] Logging ............................................ SUCCESS [  4.737 s]
20:38:21  [INFO] IO ................................................. SUCCESS [  2.190 s]
20:38:21  [INFO] Naming ............................................. SUCCESS [  2.072 s]
20:38:21  [INFO] EE ................................................. SUCCESS [  3.545 s]
20:38:21  [INFO] Request Controller ................................. SUCCESS [  2.044 s]
20:38:21  [INFO] Undertow ........................................... SUCCESS [ 31.241 s]
20:38:21  [INFO] Elytron ............................................ SUCCESS [  2.971 s]
20:38:21  [INFO] Security ........................................... SUCCESS [  2.643 s]
20:38:21  [INFO] JAX-RS with CDI .................................... SUCCESS [  1.025 s]
20:38:21  [INFO] JAX-RS ............................................. SUCCESS [ 21.468 s]
20:38:21  [INFO] Thorntail: Fraction Metadata ....................... SUCCESS [  3.542 s]
20:38:21  [INFO] Build Tools ........................................ SUCCESS [  2.038 s]
20:38:21  [INFO] Utilities for utilizing Maven to build the uber jar  SUCCESS [  2.232 s]
20:38:21  [INFO] Plugin for Maven ................................... SUCCESS [ 20.117 s]
20:38:21  [INFO] Health API ......................................... SUCCESS [  0.413 s]
20:38:21  [INFO] Bean Validation .................................... SUCCESS [  2.318 s]
20:38:21  [INFO] CDI Configuration .................................. SUCCESS [  8.184 s]
20:38:21  [INFO] Transactions ....................................... SUCCESS [  4.260 s]
20:38:21  [INFO] CDI ................................................ SUCCESS [  9.395 s]
20:38:21  [INFO] Connector .......................................... SUCCESS [  4.996 s]
20:38:21  [INFO] JCA ................................................ SUCCESS [  2.433 s]
20:38:21  [INFO] Datasources ........................................ SUCCESS [  4.915 s]
20:38:21  [INFO] EE Security ........................................ SUCCESS [  2.709 s]
20:38:21  [INFO] EJB ................................................ SUCCESS [  2.848 s]
20:38:21  [INFO] Resource Adapters .................................. SUCCESS [  2.397 s]
20:38:21  [INFO] EJB MDB ............................................ SUCCESS [  2.940 s]
20:38:21  [INFO] JAX-RS with JAXB ................................... SUCCESS [  0.805 s]
20:38:21  [INFO] JAX-RS with JSON-P ................................. SUCCESS [  1.129 s]
20:38:21  [INFO] JAX-RS with JSON-B ................................. SUCCESS [  1.338 s]
20:38:21  [INFO] JAX-RS with Multipart .............................. SUCCESS [  5.652 s]
20:38:21  [INFO] Hibernate Validator ................................ SUCCESS [  3.103 s]
20:38:21  [INFO] JAX-RS with Validation ............................. SUCCESS [  1.290 s]
20:38:21  [INFO] Remoting ........................................... SUCCESS [  1.704 s]
20:38:21  [INFO] JMX ................................................ SUCCESS [  1.767 s]
20:38:21  [INFO] MSC ................................................ SUCCESS [  2.385 s]
20:38:21  [INFO] Infinispan ......................................... SUCCESS [  4.147 s]
20:38:21  [INFO] JPA ................................................ SUCCESS [  4.398 s]
20:38:21  [INFO] JSF ................................................ SUCCESS [  5.715 s]
20:38:21  [INFO] JSON-P ............................................. SUCCESS [  0.518 s]
20:38:21  [INFO] JSON-B ............................................. SUCCESS [  1.306 s]
20:38:21  [INFO] Web ................................................ SUCCESS [  0.867 s]
20:38:21  [INFO] Netflix ............................................ SUCCESS [  0.117 s]
20:38:21  [INFO] Archaius ........................................... SUCCESS [  3.725 s]
20:38:21  [INFO] RX-Java ............................................ SUCCESS [  0.941 s]
20:38:21  [INFO] Hystrix ............................................ SUCCESS [  5.616 s]
20:38:21  [INFO] Topology ........................................... SUCCESS [  4.586 s]
20:38:21  [INFO] Servo .............................................. SUCCESS [  1.671 s]
20:38:21  [INFO] RX-Netty ........................................... SUCCESS [  5.413 s]
20:38:21  [INFO] Ribbon ............................................. SUCCESS [  5.801 s]
20:38:21  [INFO] Keycloak ........................................... SUCCESS [  9.361 s]
20:38:21  [INFO] Ribbon Secured Client .............................. SUCCESS [  3.975 s]
20:38:21  [INFO] Ribbon Secured ..................................... SUCCESS [  4.904 s]
20:38:21  [INFO] Hibernate .......................................... SUCCESS [  2.433 s]
20:38:21  [INFO] Management ......................................... SUCCESS [  4.609 s]
20:38:21  [INFO] MicroProfile Config ................................ SUCCESS [  6.728 s]
20:38:21  [INFO] MicroProfile Health ................................ SUCCESS [  6.841 s]
20:38:21  [INFO] MicroProfile JWT RBAC Auth ......................... SUCCESS [  7.178 s]
20:38:21  [INFO] MicroProfile Metrics ............................... SUCCESS [  8.065 s]
20:38:21  [INFO] MicroProfile OpenAPI ............................... SUCCESS [ 29.421 s]
20:38:21  [INFO] MicroProfile Fault Tolerance ....................... SUCCESS [  5.775 s]
20:38:21  [INFO] OpenTracing TracerResolver ......................... SUCCESS [  4.405 s]
20:38:21  [INFO] MicroProfile Rest Client ........................... SUCCESS [  6.890 s]
20:38:21  [INFO] MicroProfile OpenTracing ........................... SUCCESS [  9.824 s]
20:38:21  [INFO] MicroProfile ....................................... SUCCESS [  1.131 s]
20:38:21  [INFO] Monitor ............................................ SUCCESS [  4.491 s]
20:38:21  [INFO] OpenShift .......................................... SUCCESS [  6.001 s]
20:38:21  [INFO] Topology UI ........................................ SUCCESS [  5.956 s]
20:38:21  [INFO] OpenTracing ........................................ SUCCESS [  2.645 s]
20:38:21  [INFO] Jaeger ............................................. SUCCESS [  5.570 s]
20:38:21  [INFO] Standalone Servers ................................. SUCCESS [  0.127 s]
20:38:21  [INFO] Standalone Server: MicroProfile .................... SUCCESS [ 51.487 s]
20:38:21  [INFO] Standalone Server: Web ............................. SUCCESS [01:03 min]
20:38:21  [INFO] Enhancements to JAX-RS Client API .................. SUCCESS [  0.238 s]
20:38:21  [INFO] Arquillian Resolver ................................ SUCCESS [  0.407 s]
20:38:21  [INFO] SwarmTool .......................................... SUCCESS [  7.436 s]
20:38:21  [INFO] JBoss CLI .......................................... SUCCESS [  0.518 s]
20:38:21  [INFO] JBoss CLI .......................................... SUCCESS [  4.367 s]
20:38:21  [INFO] Gradle Tooling API ................................. SUCCESS [  1.110 s]
20:38:21  [INFO] Gradle Plugin ...................................... SUCCESS [  4.114 s]
20:38:21  [INFO] Arquillian Daemon .................................. SUCCESS [  2.326 s]
20:38:21  [INFO] Arquillian Adapter ................................. SUCCESS [  2.474 s]
20:38:21  [INFO] Arquillian ......................................... SUCCESS [  5.818 s]
20:38:21  [INFO] JGroups ............................................ SUCCESS [  2.769 s]
20:38:21  [INFO] Arquillian Test .................................... SUCCESS [  0.219 s]
20:38:21  [INFO] Arquillian Adapter for Gradle ...................... SUCCESS [  0.569 s]
20:38:21  [INFO] JPA Spatial Extensions ............................. SUCCESS [  3.254 s]
20:38:21  [INFO] JPA EclipseLink .................................... SUCCESS [  6.851 s]
20:38:21  [INFO] MVC ................................................ SUCCESS [  4.964 s]
20:38:21  [INFO] Batch .............................................. SUCCESS [  3.126 s]
20:38:21  [INFO] Messaging .......................................... SUCCESS [  2.883 s]
20:38:21  [INFO] EJB Remote ......................................... SUCCESS [  2.733 s]
20:38:21  [INFO] Mail ............................................... SUCCESS [  1.597 s]
20:38:21  [INFO] Web Services ....................................... SUCCESS [  4.471 s]
20:38:21  [INFO] Full ............................................... SUCCESS [  0.819 s]
20:38:21  [INFO] AsciidoctorJ ....................................... SUCCESS [  4.079 s]
20:38:21  [INFO] Drools Server ...................................... SUCCESS [ 52.275 s]
20:38:21  [INFO] Fluentd ............................................ SUCCESS [  3.032 s]
20:38:21  [INFO] Flyway ............................................. SUCCESS [  3.582 s]
20:38:21  [INFO] JavaFX ............................................. SUCCESS [  1.386 s]
20:38:21  [INFO] Jolokia ............................................ SUCCESS [  4.718 s]
20:38:21  [INFO] Logstash ........................................... SUCCESS [  1.635 s]
20:38:21  [INFO] Keycloak MicroProfile JWT .......................... SUCCESS [  3.964 s]
20:38:21  [INFO] Keycloak Server .................................... SUCCESS [ 17.296 s]
20:38:21  [INFO] Spring WebMVC ...................................... SUCCESS [  2.130 s]
20:38:21  [INFO] Swagger ............................................ SUCCESS [  6.228 s]
20:38:21  [INFO] Swagger Webapp ..................................... SUCCESS [  4.482 s]
20:38:21  [INFO] Hashicorp Consul ................................... SUCCESS [  6.946 s]
20:38:21  [INFO] JGroups Topology ................................... SUCCESS [  2.317 s]
20:38:21  [INFO] Vert.x ............................................. SUCCESS [ 12.056 s]
20:38:21  [INFO] Zipkin - JAXRS Support ............................. SUCCESS [  8.282 s]
20:38:21  [INFO] JOSE Signing and Encryption Support ................ SUCCESS [ 10.188 s]
20:38:21  [INFO] Hibernate Search ................................... SUCCESS [  7.049 s]
20:38:21  [INFO] JBoss Diagnostic Reporting ......................... SUCCESS [  9.815 s]
20:38:21  [INFO] Management Console ................................. SUCCESS [  2.505 s]
20:38:21  [INFO] Modcluster ......................................... SUCCESS [  2.009 s]
20:38:21  [INFO] Deployment Scanner ................................. SUCCESS [  3.940 s]
20:38:21  [INFO] Cassandra .......................................... SUCCESS [  8.246 s]
20:38:21  [INFO] MongoDB ............................................ SUCCESS [  3.747 s]
20:38:21  [INFO] Neo4j .............................................. SUCCESS [  3.911 s]
20:38:21  [INFO] OrientDB ........................................... SUCCESS [  7.785 s]
20:38:21  [INFO] CDI JAX-RS API Enhancements ........................ SUCCESS [  8.429 s]
20:38:21  [INFO] Standalone Server: Keycloak ........................ SUCCESS [01:38 min]
20:38:21  [INFO] Standalone Server: Management Console .............. SUCCESS [ 31.009 s]
20:38:21  [INFO] Standalone Server: Swagger UI ...................... SUCCESS [ 25.861 s]
20:38:21  [INFO] Standalone Server: Full ............................ SUCCESS [ 58.539 s]
20:38:21  [INFO] Standalone Server: MicroProfile + JPA .............. SUCCESS [ 53.258 s]
20:38:21  [INFO] Helper for a direct run from IDE ................... SUCCESS [  4.189 s]
20:38:21  [INFO] BOMs ............................................... SUCCESS [  0.210 s]
20:38:21  [INFO] BOM: 3+ : Recommended .............................. FAILURE [07:01 min]
20:38:21  [INFO] BOM:  0 : Deprecated ............................... SKIPPED
20:38:21  [INFO] BOM:  1 : Experimental ............................. SKIPPED
20:38:21  [INFO] BOM:  2 : Unstable ................................. SKIPPED
20:38:21  [INFO] BOM:  3 : Stable ................................... SKIPPED
20:38:21  [INFO] BOM:  4 : Frozen ................................... SKIPPED
20:38:21  [INFO] BOM:  5 : Locked ................................... SKIPPED
20:38:21  [INFO] BOM:  * : All ...................................... SKIPPED
20:38:21  [INFO] Test Suite ......................................... SKIPPED
20:38:21  [INFO] Test Suite: AJP .................................... SKIPPED
20:38:21  [INFO] Test Suite: Arquillian Without CDI ................. SKIPPED
20:38:21  [INFO] Test Suite: Buildtool .............................. SKIPPED

(....... lines removed.......)

20:38:21  [INFO] ------------------------------------------------------------------------
20:38:21  [INFO] BUILD FAILURE
20:38:21  [INFO] ------------------------------------------------------------------------
20:38:21  [INFO] Total time:  28:23 min
20:38:21  [INFO] Finished at: 2019-11-25T20:38:21Z
20:38:21  [INFO] ------------------------------------------------------------------------
20:38:21  [ERROR] Failed to execute goal org.apache.maven.plugins:maven-assembly-plugin:3.1.0:single (create-m2repo-zip) on project bom: Failed to create assembly: Error creating assembly archive m2repo: Problem creating zip: Execution exception: Java heap space -> [Help 1]
20:38:21  [ERROR] 
20:38:21  [ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
20:38:21  [ERROR] Re-run Maven using the -X switch to enable full debug logging.
20:38:21  [ERROR] 
20:38:21  [ERROR] For more information about the errors and possible solutions, please read the following articles:
20:38:21  [ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException
20:38:21  [ERROR] 
20:38:21  [ERROR] After correcting the problems, you can resume the build with the command
20:38:21  [ERROR]   mvn <goals> -rf :bom
20:38:35  JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2019/11/25 20:38:34 - please wait.
20:38:35  JVMDUMP032I JVM requested Heap dump using '/thorntail/heapdump.20191125.203834.28.0005.phd' in response to an event
20:38:43  JVMDUMP010I Heap dump written to /thorntail/heapdump.20191125.203834.28.0005.phd
20:38:54  JVMDUMP032I JVM requested Java dump using '/thorntail/javacore.20191125.203834.28.0006.txt' in response to an event
20:38:54  JVMDUMP010I Java dump written to /thorntail/javacore.20191125.203834.28.0006.txt
20:38:54  JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2019/11/25 20:38:53 - please wait.
20:38:54  JVMDUMP032I JVM requested Snap dump using '/thorntail/Snap.20191125.203834.28.0008.trc' in response to an event
20:38:54  JVMDUMP010I Snap dump written to /thorntail/Snap.20191125.203834.28.0008.trc
20:38:54  JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
20:38:54  build finished

[smlambert]

https://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException indicates to go and read more about the plugin that is failing.

It appears to be org.apache.maven.plugins:maven-assembly-plugin:3.1.0:single (create-m2repo-zip) on project bom: Failed to create assembly: Error creating assembly archive m2repo: Problem creating zip: Execution exception: Java heap space

openj9 jdk8 has a small default heap space. Try rerunning with an increased -Xmx to see if this addresses the problem.

Also see the other 2 open thorntail issues to see if this is a duplicate of the others reported, https://github.com/AdoptOpenJDK/openjdk-tests/issues/1161 and https://github.com/AdoptOpenJDK/openjdk-tests/issues/1386 (or if they are no longer valid).

[lumpfish]

Looks the same as https://github.com/AdoptOpenJDK/openjdk-tests/issues/1161.
"Try rerunning with an increased -Xmx to see if this addresses the problem." I'll see if I can work out how to change that.

[smlambert]

Near bottom of console output of the failing test, see this:
00:47:16 For example, to rebuild the failed tests in <Jenkins URL>=https://ci.adoptopenjdk.net/job/Grinder, use the following links:
00:47:16 https://ci.adoptopenjdk.net/job/Grinder/parambuild/?JDK_VERSION=8&JDK_IMPL=hotspot&BUILD_LIST=external/thorntail-mp-tck&JenkinsFile=openjdk_x86-64_linux&DOCKER_REQUIRED=true&TARGET=thorntail_microprofile_tck_0

If you click on that link, it sets up the test to be rerun in a Grinder. To add an extra JVM arg to the test, use the EXTRA_OPTIONS field:

I have launched one here: https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/1138/

[smlambert]

I just noticed the link above is for hotspot build 211, which appears to also be failing intermittently.

The grinder I launched was for hs, so relaunching for j9 here:
https://ci.adoptopenjdk.net/job/Grinder/1139/

[lumpfish]

@smlambert - thank you for pointing out the extra Grinder options.
Your rerun still failed - but I don't think there would be any mechanism for passing EXTRA_OPTIONS to the jvm's started by the test suite within the docker container.
I resubmitted your build with

EXTRA_DOCKER_OPTIONS=--env OPENJ9_JAVA_OPTIONS=-Xmx1g

rather than EXTRA_OPTIONS and that run got past that failure: https://ci.adoptopenjdk.net/job/Grinder/1151 (the job is still running as I write).

For a permanent solution I suggest we update the playlist for the test to inject that environment variable into the docker environment when starting the test. What do you think?

[smlambert]

Absolutely agree, I just didn't want to create a fork to make a Grinder run yesterday. We should be modifying the command line permanently for this.

[lumpfish]

https://ci.adoptopenjdk.net/job/Grinder/1151 completed successfully. I'll test a fix via the playlist file and submit a PR.

[smlambert]

thanks @lumpfish !

[lumpfish]

Raised https://github.com/AdoptOpenJDK/openjdk-tests/pull/1477
Test rerun is here: https://ci.adoptopenjdk.net/job/Grinder/1190. A test failed towards the end of the run, but that is after the build issue fixed by this PR.