Openj9: DirectByteBufferLoadTest OOM on AIX

Created on 5 Nov 2020 · 22Comments · Source: eclipse/openj9

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/533
DirectByteBufferLoadTest_0
aix71-p8-3

STF 03:50:37.494 - +------ Step 1 - Run DirectByteBuffer load test
STF 03:50:37.494 - | Run foreground process
STF 03:50:37.494 - |   Program:     /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdkbinary/j2sdk-image/bin/java
STF 03:50:37.494 - |   Mnemonic:    DBLT
STF 03:50:37.494 - |   Echo:        ECHO_ON
STF 03:50:37.494 - |   Expectation: CLEAN_RUN within 5m
STF 03:50:37.494 - |
STF 03:50:37.495 - Running command: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdkbinary/j2sdk-image/bin/java -classpath /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/jvmtest/system/stf/stf.load/bin:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/jvmtest/system/stf/stf.core/bin:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-api-2.13.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-core-2.13.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/jvmtest/system/systemtest_prereqs/junit-4.12/junit-4.12.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/jvmtest/system/systemtest_prereqs/junit-4.12/hamcrest-core-1.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/jvmtest/system/openjdk-systemtest/openjdk.test.nio/bin/lib/filesystem.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/jvmtest/system/openjdk-systemtest/openjdk.test.gc/bin:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/jvmtest/system/openjdk-systemtest/openjdk.test.nio/bin net.adoptopenjdk.loadTest.LoadTest -resultsDir /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results -resultsPrefix 1.DBLT. -reportFailureLimit 1 -abortAtFailureLimit 10 -maxTotalLogFileSpace 200M -maxSingleLogSize 1/25 -suite.DirectByteBuffer.thinkingTime 1ms..1ms -suite.DirectByteBuffer.threadCount 15 -suite.DirectByteBuffer.totalNumberTests 16 -suite.DirectByteBuffer.inventoryFile /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/1.DBLT.inventory/openjdk.test.load/config/inventories/gc/directByteBuffer.xml -suite.DirectByteBuffer.inventoryExcludeFile none -suite.DirectByteBuffer.selection random -suite.DirectByteBuffer.seed -1 -suite.DirectByteBuffer.repeatCount 1
STF 03:50:37.495 - Redirecting stderr to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/1.DBLT.stderr
STF 03:50:37.495 - Redirecting stdout to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/1.DBLT.stdout
STF 03:50:37.511 - Monitoring processes: DBLT
DBLT 03:50:38.681 - Load test parameters
DBLT 03:50:38.685 -   Time limited         = false
DBLT 03:50:38.688 -   abortIfOutOfMemory   = true
DBLT 03:50:38.688 -   reportFailureLimit   = 1
DBLT 03:50:38.689 -   abortAtFailureLimit  = 10
DBLT 03:50:38.690 -   maxTotalLogFileSpace = 209715200
DBLT 03:50:38.691 -   maxSingleLogSize     = 8388608
DBLT 03:50:38.691 - Parameters for suite 0
DBLT 03:50:38.693 -   Suite name     = DirectByteBuffer
DBLT 03:50:38.693 -   Number threads = 15
DBLT 03:50:38.694 -   Supplied seed  = -1
DBLT 03:50:38.695 -   Inventory file = /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/1.DBLT.inventory/openjdk.test.load/config/inventories/gc/directByteBuffer.xml
DBLT 03:50:38.696 -   Exclude file   = none
DBLT 03:50:38.697 -   Number tests   = 16
DBLT 03:50:38.698 -   Repeat count   = 1
DBLT 03:50:38.698 -   Thinking time  = 1ms..1ms
DBLT 03:50:38.699 -   Selection mode = random
DBLT 03:50:38.701 -   Actual seed    = 1606012649832
DBLT 03:50:38.712 - Parsing inventory file. Root=/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/1.DBLT.inventory File=openjdk.test.load/config/inventories/gc/directByteBuffer.xml
DBLT 03:50:38.718 - Found included inventory. File=/openjdk.test.load/config/inventories/nio/nio.xml
DBLT 03:50:38.719 - Parsing inventory file. Root=/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/1.DBLT.inventory File=/openjdk.test.load/config/inventories/nio/nio.xml
DBLT 03:50:38.737 - Final test list:
DBLT 03:50:38.739 -   0 ArbitraryJava[net.adoptopenjdk.test.nio.WordCount run]  Weighting=1 
DBLT 03:50:38.739 -   1 ArbitraryJava[net.adoptopenjdk.test.nio.NioApp run]  Weighting=1 
DBLT 03:50:38.739 -   2 ArbitraryJava[net.adoptopenjdk.test.nio.NioBuffers run]  Weighting=1 
DBLT 03:50:38.740 -   3 ArbitraryJava[net.adoptopenjdk.test.nio.NioBuffersTest run]  Weighting=1 
DBLT 03:50:38.740 -   4 JUnit[net.adoptopenjdk.test.nio2.asyncio.client.MultipleConnectFutureTest]  Weighting=1 
DBLT 03:50:38.741 -   5 JUnit[net.adoptopenjdk.test.nio2.asyncio.client.MultipleConnectAsyncTest]  Weighting=1 
DBLT 03:50:38.741 -   6 JUnit[net.adoptopenjdk.test.nio2.asyncio.client.MultipleReadWriteAsyncTest]  Weighting=1 
DBLT 03:50:38.741 -   7 JUnit[net.adoptopenjdk.test.nio2.asyncio.client.MultipleReadWriteFutureTest]  Weighting=1 
DBLT 03:50:38.741 -   8 JUnit[net.adoptopenjdk.test.nio2.asyncio.file.AsynchronousFileChannelTest]  Weighting=1 
DBLT 03:50:38.742 -   9 JUnit[net.adoptopenjdk.test.nio2.mxbean.ByteBufferMXBeanTest]  Weighting=1 
DBLT 03:50:38.742 -   10 JUnit[net.adoptopenjdk.test.nio2.filesystem.FileSystemsTest]  Weighting=1 
DBLT 03:50:38.742 -   11 JUnit[net.adoptopenjdk.test.nio2.path.PathDeleteDirectoryTest]  Weighting=1 
DBLT 03:50:38.743 -   12 JUnit[net.adoptopenjdk.test.nio2.path.PathDirectoryStreamTest]  Weighting=1 
DBLT 03:50:38.743 -   13 JUnit[net.adoptopenjdk.test.nio2.path.ScannerTest]  Weighting=1 
DBLT 03:50:38.743 -   14 JUnit[net.adoptopenjdk.test.nio2.path.WalkFileTreeTest]  Weighting=1 
DBLT 03:50:38.743 -   15 JUnit[net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest]  Weighting=1 
DBLT 03:50:38.818 - Starting thread. Suite=0 thread=0
DBLT 03:50:38.820 - Starting thread. Suite=0 thread=1
DBLT 03:50:38.820 - Starting thread. Suite=0 thread=2
DBLT 03:50:38.821 - Starting thread. Suite=0 thread=3
DBLT 03:50:38.821 - Starting thread. Suite=0 thread=4
DBLT 03:50:38.821 - Starting thread. Suite=0 thread=5
DBLT 03:50:38.822 - Starting thread. Suite=0 thread=6
DBLT 03:50:38.822 - Starting thread. Suite=0 thread=7
DBLT 03:50:38.822 - Starting thread. Suite=0 thread=8
DBLT 03:50:38.823 - Starting thread. Suite=0 thread=9
DBLT 03:50:38.823 - Starting thread. Suite=0 thread=10
DBLT 03:50:38.823 - Starting thread. Suite=0 thread=11
DBLT 03:50:38.824 - Starting thread. Suite=0 thread=12
DBLT 03:50:38.824 - Starting thread. Suite=0 thread=13
DBLT 03:50:38.832 - Starting thread. Suite=0 thread=14
DBLT 03:50:38.920 - Thread completed. Suite=0 thread=14
DBLT 03:50:39.001 - Thread completed. Suite=0 thread=8
DBLT 03:50:39.076 - Thread completed. Suite=0 thread=3
DBLT 03:50:39.110 - Thread completed. Suite=0 thread=12
DBLT 03:50:39.126 - Thread completed. Suite=0 thread=11
DBLT 03:50:39.126 - Thread completed. Suite=0 thread=4
DBLT 03:50:39.159 - Thread completed. Suite=0 thread=13
DBLT 03:50:39.167 - Thread completed. Suite=0 thread=9
DBLT 03:50:39.177 - Thread completed. Suite=0 thread=0
DBLT stderr JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2020/11/05 03:50:39 - please wait.
DBLT stderr JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/core.20201105.035039.13566082.0001.dmp' in response to an event
STF 03:50:39.388 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/core.20201105.035039.13566082.0001.dmp
DBLT stderr core file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/core.20201105.035039.13566082.0001.dmp
DBLT stderr JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/core.20201105.035039.13566082.0001.dmp
DBLT stderr JVMDUMP032I JVM requested Heap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035039.13566082.0002.phd' in response to an event
STF 03:50:55.927 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035039.13566082.0002.phd
DBLT stderr heapdump file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035039.13566082.0002.phd
DBLT stderr JVMDUMP010I Heap dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035039.13566082.0002.phd
DBLT stderr JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035039.13566082.0003.txt' in response to an event
STF 03:50:56.300 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035039.13566082.0003.txt
DBLT stderr javacore file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035039.13566082.0003.txt
DBLT stderr JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035039.13566082.0003.txt
DBLT stderr JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035039.13566082.0004.trc' in response to an event
DBLT stderr JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035039.13566082.0004.trc
DBLT stderr JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
DBLT stderr JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2020/11/05 03:50:56 - please wait.
DBLT stderr JVMDUMP032I JVM requested Heap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0005.phd' in response to an event
STF 03:50:56.492 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0005.phd
STF 03:50:56.493 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035039.13566082.0004.trc
DBLT 03:50:56.633 - First failure detected by thread: load-10. Not creating dumps as no dump generation is requested for this load test
DBLT stderr heapdump file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0005.phd
DBLT stderr Snap file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035039.13566082.0004.trc
DBLT stderr JVMDUMP010I Heap dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0005.phd
DBLT stderr JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0006.txt' in response to an event
DBLT stderr JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0006.txt
DBLT stderr JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035056.13566082.0007.trc' in response to an event
DBLT stderr JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2020/11/05 03:50:56 - please wait.
DBLT stderr JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2020/11/05 03:50:56 - please wait.
DBLT stderr JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035056.13566082.0007.trc
DBLT stderr JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
STF 03:50:56.684 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0006.txt
STF 03:50:56.685 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035056.13566082.0007.trc
DBLT 03:50:56.722 - Test failed. Details recorded in execution log.
DBLT 03:50:56.706 - Test failed
DBLT   Failure num.  = 1
DBLT   Test number   = 15
DBLT   Test details  = 'JUnit[net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest]'
DBLT   Suite number  = 0
DBLT   Thread number = 10
DBLT >>> Captured test output >>>
DBLT testStarted : testDirectMemory(net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest)
DBLT Total memory is: 32243712
DBLT Initial free memory: 9742136
DBLT Iteration: 0 Total memory is: 32243712Initial free memory: 9741672
DBLT Iteration: 1 Total memory is: 32243712Initial free memory: 9418128
DBLT Iteration: 2 Total memory is: 32243712Initial free memory: 9234464
DBLT Iteration: 3 Total memory is: 32243712Initial free memory: 9013160
DBLT Iteration: 4 Total memory is: 32243712Initial free memory: 8921000
DBLT Iteration: 5 Total memory is: 32243712Initial free memory: 8644288
DBLT Iteration: 6 Total memory is: 32243712Initial free memory: 8528448
DBLT Iteration: 7 Total memory is: 32243712Initial free memory: 8318168
DBLT Iteration: 8 Total memory is: 32243712Initial free memory: 8198832
DBLT Iteration: 9 Total memory is: 32243712Initial free memory: 7986984
DBLT Iteration: 10 Total memory is: 32243712Initial free memory: 7804808
DBLT Iteration: 11 Total memory is: 32243712Initial free memory: 7787840
DBLT Iteration: 12 Total memory is: 32243712Initial free memory: 7573840
DBLT Iteration: 13 Total memory is: 32243712Initial free memory: 7341560
DBLT Iteration: 14 Total memory is: 32243712Initial free memory: 7164568
DBLT Iteration: 15 Total memory is: 32243712Initial free memory: 9820688
DBLT Iteration: 16 Total memory is: 32243712Initial free memory: 9808136
DBLT Iteration: 17 Total memory is: 32243712Initial free memory: 9807840
DBLT Iteration: 18 Total memory is: 32243712Initial free memory: 9725688
DBLT Iteration: 19 Total memory is: 32243712Initial free memory: 9725488
DBLT Iteration: 20 Total memory is: 32243712Initial free memory: 9696344
DBLT Iteration: 21 Total memory is: 32243712Initial free memory: 9605832
DBLT Iteration: 22 Total memory is: 32243712Initial free memory: 9523600
DBLT Iteration: 23 Total memory is: 32243712Initial free memory: 9523256
DBLT Iteration: 24 Total memory is: 32243712Initial free memory: 9523256
DBLT Iteration: 25 Total memory is: 32243712Initial free memory: 9478088
DBLT Iteration: 26 Total memory is: 32243712Initial free memory: 9477544
DBLT Iteration: 27 Total memory is: 32243712Initial free memory: 9477544
DBLT Iteration: 28 Total memory is: 32243712Initial free memory: 9477544
DBLT Iteration: 29 Total memory is: 32243712Initial free memory: 9267088
DBLT Iteration: 30 Total memory is: 32243712Initial free memory: 9258896
DBLT Iteration: 31 Total memory is: 32243712Initial free memory: 9258896
DBLT Iteration: 32 Total memory is: 32243712Initial free memory: 9209744
DBLT Iteration: 33 Total memory is: 32243712Initial free memory: 9209744
DBLT Iteration: 34 Total memory is: 32243712Initial free memory: 9209744
DBLT Iteration: 35 Total memory is: 32243712Initial free memory: 9209744
DBLT Iteration: 36 Total memory is: 32243712Initial free memory: 9209744
DBLT Iteration: 37 Total memory is: 32243712Initial free memory: 9209744
DBLT Iteration: 38 Total memory is: 32243712Initial free memory: 9209744
DBLT Iteration: 39 Total memory is: 32243712Initial free memory: 9209744
DBLT Iteration: 40 Total memory is: 32243712Initial free memory: 8889824
DBLT Iteration: 41 Total memory is: 32243712Initial free memory: 8757400
DBLT Iteration: 42 Total memory is: 32243712Initial free memory: 8630336
DBLT Iteration: 43 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 44 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 45 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 46 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 47 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 48 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 49 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 50 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 51 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 52 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 53 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 54 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 55 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 56 Total memory is: 32243712Initial free memory: 8357992
DBLT Iteration: 57 Total memory is: 32243712Initial free memory: 8357992
DBLT testFailure: testDirectMemory(net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest): native memory exhausted
DBLT java.lang.OutOfMemoryError: native memory exhausted
DBLT    at java.base/java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:127)
DBLT    at java.base/java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:317)
DBLT    at net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest.testDirectMemory(DirectMemoryTest.java:40)
DBLT    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
DBLT    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
DBLT    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
DBLT    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
DBLT    at junit.framework.TestCase.runTest(TestCase.java:176)
DBLT    at junit.framework.TestCase.runBare(TestCase.java:141)
DBLT    at junit.framework.TestResult$1.protect(TestResult.java:122)
DBLT    at junit.framework.TestResult.runProtected(TestResult.java:142)
DBLT    at junit.framework.TestResult.run(TestResult.java:125)
DBLT    at junit.framework.TestCase.run(TestCase.java:129)
DBLT    at junit.framework.TestSuite.runTest(TestSuite.java:252)
DBLT    at junit.framework.TestSuite.run(TestSuite.java:247)
DBLT    at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:86)
DBLT    at org.junit.runners.Suite.runChild(Suite.java:128)
DBLT    at org.junit.runners.Suite.runChild(Suite.java:27)
DBLT    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
DBLT    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
DBLT    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
DBLT    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
DBLT    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
DBLT    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
DBLT    at net.adoptopenjdk.loadTest.adaptors.JUnitAdaptor.executeTest(JUnitAdaptor.java:130)
DBLT    at net.adoptopenjdk.loadTest.LoadTestRunner$2.run(LoadTestRunner.java:182)
DBLT    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
DBLT    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
DBLT    at java.base/java.lang.Thread.run(Thread.java:835)
DBLT testFinished: testDirectMemory(net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest)
DBLT 
DBLT JUnit Test Results for: net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest
DBLT   Ran    : 1
DBLT   Passed : 0
DBLT   Failed : 1
DBLT   Ignored: 0
DBLT   Result : FAILED
DBLT Test failed:
DBLT java.lang.OutOfMemoryError: native memory exhausted
DBLT    at java.base/java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:127)
DBLT    at java.base/java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:317)
DBLT    at net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest.testDirectMemory(DirectMemoryTest.java:40)
DBLT    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
DBLT    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
DBLT    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
DBLT    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
DBLT    at junit.framework.TestCase.runTest(TestCase.java:176)
DBLT    at junit.framework.TestCase.runBare(TestCase.java:141)
DBLT    at junit.framework.TestResult$1.protect(TestResult.java:122)
DBLT    at junit.framework.TestResult.runProtected(TestResult.java:142)
DBLT    at junit.framework.TestResult.run(TestResult.java:125)
DBLT    at junit.framework.TestCase.run(TestCase.java:129)
DBLT    at junit.framework.TestSuite.runTest(TestSuite.java:252)
DBLT    at junit.framework.TestSuite.run(TestSuite.java:247)
DBLT    at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:86)
DBLT    at org.junit.runners.Suite.runChild(Suite.java:128)
DBLT    at org.junit.runners.Suite.runChild(Suite.java:27)
DBLT    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
DBLT    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
DBLT    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
DBLT    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
DBLT    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
DBLT    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
DBLT    at net.adoptopenjdk.loadTest.adaptors.JUnitAdaptor.executeTest(JUnitAdaptor.java:130)
DBLT    at net.adoptopenjdk.loadTest.LoadTestRunner$2.run(LoadTestRunner.java:182)
DBLT    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
DBLT    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
DBLT    at java.base/java.lang.Thread.run(Thread.java:835)
DBLT <<<
DBLT 
DBLT 03:50:56.723 - Out of memory exception. Aborting test run
DBLT java.lang.OutOfMemoryError: native memory exhausted
DBLT    at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:127) ~[?:?]
DBLT    at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:317) ~[?:?]
DBLT    at net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest.testDirectMemory(DirectMemoryTest.java:40) ~[bin/:?]
DBLT    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
DBLT    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
DBLT    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
DBLT    at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
DBLT    at junit.framework.TestCase.runTest(TestCase.java:176) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestCase.runBare(TestCase.java:141) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult$1.protect(TestResult.java:122) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult.runProtected(TestResult.java:142) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult.run(TestResult.java:125) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestCase.run(TestCase.java:129) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestSuite.runTest(TestSuite.java:252) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestSuite.run(TestSuite.java:247) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:86) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.Suite.runChild(Suite.java:128) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.Suite.runChild(Suite.java:27) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.run(ParentRunner.java:363) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:137) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:115) ~[junit-4.12.jar:4.12]
DBLT    at net.adoptopenjdk.loadTest.adaptors.JUnitAdaptor.executeTest(JUnitAdaptor.java:130) ~[bin/:?]
DBLT    at net.adoptopenjdk.loadTest.LoadTestRunner$2.run(LoadTestRunner.java:182) [bin/:?]
DBLT    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
DBLT    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
DBLT    at java.lang.Thread.run(Thread.java:835) [?:?]
DBLT 03:50:56.762 - Thread completed. Suite=0 thread=6
DBLT 03:50:56.736 - Out of memory exception. Aborting test run
DBLT java.lang.OutOfMemoryError: native memory exhausted
DBLT    at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:127) ~[?:?]
DBLT    at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:317) ~[?:?]
DBLT    at net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest.testDirectMemory(DirectMemoryTest.java:40) ~[bin/:?]
DBLT    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
DBLT    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
DBLT    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
DBLT    at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
DBLT    at junit.framework.TestCase.runTest(TestCase.java:176) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestCase.runBare(TestCase.java:141) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult$1.protect(TestResult.java:122) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult.runProtected(TestResult.java:142) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult.run(TestResult.java:125) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestCase.run(TestCase.java:129) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestSuite.runTest(TestSuite.java:252) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestSuite.run(TestSuite.java:247) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:86) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.Suite.runChild(Suite.java:128) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.Suite.runChild(Suite.java:27) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.run(ParentRunner.java:363) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:137) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:115) ~[junit-4.12.jar:4.12]
DBLT    at net.adoptopenjdk.loadTest.adaptors.JUnitAdaptor.executeTest(JUnitAdaptor.java:130) ~[bin/:?]
DBLT    at net.adoptopenjdk.loadTest.LoadTestRunner$2.run(LoadTestRunner.java:182) [bin/:?]
DBLT    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
DBLT    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
DBLT    at java.lang.Thread.run(Thread.java:835) [?:?]
DBLT 03:50:56.764 - Thread completed. Suite=0 thread=10
DBLT stderr javacore file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0006.txt
DBLT stderr Snap file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035056.13566082.0007.trc
DBLT stderr JVMDUMP032I JVM requested Heap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0008.phd' in response to an event
STF 03:50:56.878 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0008.phd
DBLT stderr heapdump file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0008.phd
DBLT stderr JVMDUMP010I Heap dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0008.phd
DBLT stderr JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0010.txt' in response to an event
DBLT stderr JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0010.txt
DBLT stderr JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035056.13566082.0011.trc' in response to an event
DBLT stderr JVMDUMP010I Snap dump written to {nothing to snap}
DBLT stderr JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
DBLT stderr JVMDUMP032I JVM requested Heap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0009.phd' in response to an event
STF 03:50:57.069 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0010.txt
STF 03:50:57.069 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0009.phd
DBLT 03:50:57.121 - Test failed. Details recorded in execution log.
DBLT 03:50:57.121 - Out of memory exception. Aborting test run
DBLT java.lang.OutOfMemoryError: native memory exhausted
DBLT    at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:127) ~[?:?]
DBLT    at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:317) ~[?:?]
DBLT    at net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest.testDirectMemory(DirectMemoryTest.java:40) ~[bin/:?]
DBLT    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
DBLT    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
DBLT    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
DBLT    at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
DBLT    at junit.framework.TestCase.runTest(TestCase.java:176) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestCase.runBare(TestCase.java:141) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult$1.protect(TestResult.java:122) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult.runProtected(TestResult.java:142) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult.run(TestResult.java:125) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestCase.run(TestCase.java:129) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestSuite.runTest(TestSuite.java:252) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestSuite.run(TestSuite.java:247) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:86) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.Suite.runChild(Suite.java:128) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.Suite.runChild(Suite.java:27) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.run(ParentRunner.java:363) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:137) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:115) ~[junit-4.12.jar:4.12]
DBLT    at net.adoptopenjdk.loadTest.adaptors.JUnitAdaptor.executeTest(JUnitAdaptor.java:130) ~[bin/:?]
DBLT    at net.adoptopenjdk.loadTest.LoadTestRunner$2.run(LoadTestRunner.java:182) [bin/:?]
DBLT    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
DBLT    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
DBLT    at java.lang.Thread.run(Thread.java:835) [?:?]
DBLT 03:50:57.123 - Thread completed. Suite=0 thread=2
DBLT 03:50:57.138 - Test failed. Details recorded in execution log.
DBLT 03:50:57.138 - Out of memory exception. Aborting test run
DBLT java.lang.OutOfMemoryError: native memory exhausted
DBLT    at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:127) ~[?:?]
DBLT    at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:317) ~[?:?]
DBLT    at net.adoptopenjdk.test.gc.directbytebuffer.DirectMemoryTest.testDirectMemory(DirectMemoryTest.java:40) ~[bin/:?]
DBLT    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
DBLT    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
DBLT    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
DBLT    at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
DBLT    at junit.framework.TestCase.runTest(TestCase.java:176) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestCase.runBare(TestCase.java:141) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult$1.protect(TestResult.java:122) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult.runProtected(TestResult.java:142) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestResult.run(TestResult.java:125) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestCase.run(TestCase.java:129) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestSuite.runTest(TestSuite.java:252) ~[junit-4.12.jar:4.12]
DBLT    at junit.framework.TestSuite.run(TestSuite.java:247) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:86) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.Suite.runChild(Suite.java:128) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.Suite.runChild(Suite.java:27) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runners.ParentRunner.run(ParentRunner.java:363) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:137) ~[junit-4.12.jar:4.12]
DBLT    at org.junit.runner.JUnitCore.run(JUnitCore.java:115) ~[junit-4.12.jar:4.12]
DBLT    at net.adoptopenjdk.loadTest.adaptors.JUnitAdaptor.executeTest(JUnitAdaptor.java:130) ~[bin/:?]
DBLT    at net.adoptopenjdk.loadTest.LoadTestRunner$2.run(LoadTestRunner.java:182) [bin/:?]
DBLT    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
DBLT    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
DBLT    at java.lang.Thread.run(Thread.java:835) [?:?]
DBLT 03:50:57.141 - Thread completed. Suite=0 thread=1
DBLT stderr javacore file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0010.txt
DBLT stderr heapdump file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0009.phd
DBLT stderr JVMDUMP010I Heap dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/heapdump.20201105.035056.13566082.0009.phd
DBLT stderr JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0012.txt' in response to an event
DBLT stderr JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0012.txt
DBLT stderr JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035056.13566082.0013.trc' in response to an event
DBLT stderr JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035056.13566082.0013.trc
DBLT stderr JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
STF 03:50:57.271 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0012.txt
STF 03:50:57.272 - Found dump at: /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035056.13566082.0013.trc
DBLT stderr javacore file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/javacore.20201105.035056.13566082.0012.txt
DBLT stderr Snap file generated - /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/results/Snap.20201105.035056.13566082.0013.trc
DBLT 03:50:57.634 - Thread completed. Suite=0 thread=7
DBLT 03:50:57.648 - Thread completed. Suite=0 thread=5
DBLT 03:50:57.717 - Load test completed
DBLT 03:50:57.717 -   Ran     : 16
DBLT 03:50:57.718 -   Passed  : 12
DBLT 03:50:57.718 -   Failed  : 4
DBLT 03:50:57.718 -   Result  : FAILED
DBLT 03:50:57.719 - Note that only the first 1 failures have been reported
STF 03:50:58.081 - **FAILED** Process DBLT ended with exit code (1) and not the expected exit code/s (0)
STF 03:50:58.081 - Monitoring Report Summary:
STF 03:50:58.081 -   o Process DBLT has crashed unexpectedly
STF 03:50:58.081 - Killing processes: DBLT
STF 03:50:58.081 -   o Process DBLT is not running
**FAILED** at step 1 (Run DirectByteBuffer load test). Expected return value=0 Actual=1 at /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/../TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/execute.pl line 91.
STF 03:50:58.187 - **FAILED** execute script failed. Expected return value=0 Actual=1
STF 03:50:58.187 - 
STF 03:50:58.187 - ====================   T E A R D O W N   ====================
STF 03:50:58.187 - Running teardown: perl /home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/openjdk-tests/TKG/../TKG/test_output_16045657327373/DirectByteBufferLoadTest_0/20201105-035034-DirectByteBufferLoadTest/tearDown.pl
STF 03:50:58.308 - TEARDOWN stage completed
STF 03:50:58.312 - 
STF 03:50:58.312 - =====================   R E S U L T S   =====================
STF 03:50:58.312 - Stage results:
STF 03:50:58.312 -   setUp:     pass
STF 03:50:58.312 -   execute:  *fail*
STF 03:50:58.312 -   teardown:  pass
STF 03:50:58.312 - 
STF 03:50:58.312 - Overall result: **FAILED**

test aix test failure

Source

pshipton

All 22 comments

Trying grinders on the same machine
5x https://ci.eclipse.org/openj9/job/Grinder/1155/ - passed
25x https://ci.eclipse.org/openj9/job/Grinder/1157/ - failed 2/25

pshipton on 5 Nov 2020

@dmitripivkine fyi. Perhaps an iceberg problem as it's out of native memory. Not sure if it's specific to AIX, or a new failure that just happened to occur on AIX first, or some problem that has been lurking for a while.

pshipton on 5 Nov 2020

👍1

This test had been excluded from AIX for some time and was reenabled recently because I thought this PR had fixed it: https://github.com/AdoptOpenJDK/openjdk-systemtest/pull/368. I haven't seen any errors on the adoptopenjdk machines since it was merged)
Unless you think there's a 'real' issue on AIX, could you provide any insight into when unused native memory is reclaimed to help me understand how the test can be tuned more effectively to avoid false failures?

lumpfish on 10 Nov 2020

The test workload is run with nbrCpus - 1 (minimum 2) threads. The machine in the output sample above must have had 16 CPUs. So 15 threads are running the nio load test in parallel with this code which explicitly allocates a directByteBuffer:

    public static void testDirectMemory() {
        try {
            int ITERATIONS = 90;
            int ALLOC_SIZE = 10000000; // 10Mbytes

            ByteBuffer[] bbStore = new ByteBuffer[ITERATIONS];
            Runtime r = Runtime.getRuntime();

            System.out.println("Total memory is: " + r.totalMemory());
            System.out.println("Initial free memory: " + r.freeMemory());
            int i;
            for (i = 0; i < ITERATIONS; i++) {

                System.out.println("Iteration: " + i + " Total memory is: "
                        + r.totalMemory() + "Initial free memory: "
                        + r.freeMemory());
                bbStore[i] = ByteBuffer.allocateDirect(ALLOC_SIZE);
                // *** dereference to allow GC
                bbStore[i] = null;
            }

            assertTrue(i==ITERATIONS);

        } catch (Exception e) {
            System.out.println("Caught Exception: \n" + e);
            fail("Exception::"+e);
        }
    }

My concern is - should this be expected to work? Should we be able to expect that the native memory is reclaimed because the pointer to it is dereferenced?

lumpfish on 10 Nov 2020

The change in AdoptOpenJDK/openjdk-systemtest#368 introduced a short delay between repeated invocations of the test code on each thread, which appeared to 'fix' the issue in the AdoptOpenJDK testing.

lumpfish on 10 Nov 2020

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly/539

pshipton on 11 Nov 2020

I share concern with @lumpfish I think this test "as is" should not work. The pressure to object heap is minimal, so there is no reason to expect that GC happen often enough and objects are going to be collected after de-referencing. So test should force SystemGC at least. Even with forcing SystemGC I can see more potential issues:

as we learn recently de-referencing itself does not guarantee object to be collected due possible extended liveness of the object in JIT
cleaning DBBs involves Finalization. It means asynchronous Finalizer threads should work effective enough to establish dynamic balance of native memory usage below limit. In practice this might be a reason for intermittent errors (considering wide variety of machine configurations)

Regarding possible extended liveness I can not verify this because system core is generated in non-safe point so java thread stacks are not walkable. Heap expansion is small (less than 32M of 2G).

dmitripivkine on 11 Nov 2020

If the success of the tests depends on the execution of a GC cycle which should reclaim the native memory, then perhaps increasing the delay between successive runs of the testDirectMemory method to around the interval between GC cycles would make the test safe, while still catching situations where the memory is not being reclaimed correctly. Is it possible to provide an estimate of a 'typical' interval between GC cycles we could try?

lumpfish on 12 Nov 2020

The interval between GC cycles depends on allocation rate, heap size, heap geometry, GC policy etc. In general case it is not possible to predict (for example if App sleeps and does not allocate objects GC might never occur). So I believe the best way to be sure that GC is executed is to force System GC twice to be sure Aggressive GC is executed. Also GC cycle itself does not release native memory but allowed to do it for followed Finalization (executed asynchronously).

dmitripivkine on 12 Nov 2020

Since we have an environment at ci.eclipse.org where this is showing itself relatively consistently we could try the 'double SystemGC' and see if it makes a difference. @Mesbah-Alam - would you be able to try @dmitripivkine 's suggestion on a branch an run some grinders on aix?

lumpfish on 12 Nov 2020

👍1

Also I noticed there is no explicit -Xmx option so in Java 11 it is set as 25% of RAM by default (2G in this core). So large heap is not necessary for test obviously (it the core heap is expanded less than 32m). It means large chunk of memory is reserved for heap but never used. This prevents using this memory for native allocations. I would recommend to add maximum heap size cap (for example -Xmx512m to match Java 8 behaviour or less)

dmitripivkine on 12 Nov 2020

FYI OpenJ9 Java 8 doesn't have the -Xmx512 limitation any more, it also uses 25%.

pshipton on 12 Nov 2020

👍1

Added -Xmx512
Added double System.gc() calls in the test

https://github.com/AdoptOpenJDK/openjdk-systemtest/pull/377/files

Ran a 5x Grinder, it didn't reproduce the issue: https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/4701/console

I guess we should deliver this change and see if it resolves the issue in the build.

Mesbah-Alam on 13 Nov 2020

Re https://github.com/eclipse/openj9/issues/11112#issuecomment-722457186 the existing test failed 2/25. Pls try a 25x grinder and if it doesn't fail then deliver the change.

pshipton on 13 Nov 2020

👍1

25x Grinder didn't cause the failure : https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/4702/tapResults/

Mesbah-Alam on 13 Nov 2020

Test has been updated to call System.gc(). A cap of -Xmx512 has also been added.

Mesbah-Alam on 14 Nov 2020

@Mesbah-Alam - since we're doing this investigation, I think it would be worth testing the changes separately (adding -Xmx and the System.gc() calls) to discover whether either change will work (in which case we can choose one of them) or whether both are needed.

lumpfish on 16 Nov 2020

It's been a while since this problem was seen in the builds. I'll keep it open since Simon is asking for additional investigation, but move it to the next milestone.

pshipton on 11 Dec 2020

I'll keep it open since Simon is asking for additional investigation, but move it to the next milestone.

I was just asking @mesbah whether both changes (System.gc() and -Xmx512) were needed or whether one would suffice, but I believe the PR included both changes. If you're not seeing the failures any more and do not need to know the answer, then by all means close this issue.

lumpfish on 14 Dec 2020

@dmitripivkine do you need any further information (I suspect not)?

pshipton on 15 Dec 2020