Openjdk-tests: testJps taking a considerable time on some platforms

[andrew-m-leonard]

The extended.functional testJps set of 6 tests is taking a considerable amount of time on some platforms,eg:
jdk11 J9 aarch64 : 49 mins : https://ci.adoptopenjdk.net/view/Test_functional/job/Test_openjdk11_j9_extended.functional_aarch64_linux/36/testReport/org.openj9.test.attachAPI/TestJps/
jdk11 J9 AIX : 51mins : https://ci.adoptopenjdk.net/view/Test_functional/job/Test_openjdk11_j9_extended.functional_ppc64_aix/8/testReport/org.openj9.test.attachAPI/TestJps/
jdk11 J9 s390x : 1hr40mins : https://ci.adoptopenjdk.net/view/Test_functional/job/Test_openjdk11_j9_extended.functional_s390x_linux/6/testReport/org.openj9.test.attachAPI/TestJps/
jdk8 J9 s390x : 1hr40mins : https://ci.adoptopenjdk.net/view/Test_functional/job/Test_openjdk8_j9_extended.functional_s390x_linux/23/testReport/org.openj9.test.attachAPI/TestJps/

[smlambert]

Please compare these to the runs at ci.eclipse.org/openj9. If the execution times are approximately the same then they are working as designed (or you can raise the issue at openj9 if you feel there is a better way to write the test).

[smlambert]

https://ci.eclipse.org/openj9/view/Test_Functional_Nightly/job/Test_openjdk11_j9_extended.functional_s390x_linux_Nightly_testList_0/169/testReport/org.openj9.test.attachAPI/ - 1.5 hrs, with TestJps taking 10sec.

Perhaps start by comparing the machines and why TestJps takes 1hr 40min on test-marist-ubuntu1604-s390x-2X and 10sec on rh7-390-3.

[andrew-m-leonard]

Thanks Shelley, yes, considerable difference in timing! i'll have a look at what the test is doing

[andrew-m-leonard]

Running some debug tests on machine: https://ci.adoptopenjdk.net/computer/test-marist-ubuntu1604-s390x-1/
and could not understand why it was so slow, ran a ps -ef
Note all the old extended.system and sanity.system jobs including DaaLoadTest which is consuming lots of CPU!

jenkins   1665     1  0 Nov03 ?        00:01:58 /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/openjdkbinary/j2sdk-image/bin/java -Xgcpolicy:gencon -Xgc:concurrentScavenge -classpath /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/stf/stf.load/bin:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/stf/stf.core/bin:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-api-2.13.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-core-2.13.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/junit-4.12/junit-4.12.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/junit-4.12/hamcrest-core-1.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/openj9-systemtest/openj9.test.daa/bin net.adoptopenjdk.loadTest.LoadTest -resultsDir /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/openjdk-tests/TKG/test_output_16043950528003/DaaLoadTest_all_ConcurrentScavenge_0/20201103-105828-DaaLoadTest/results -resultsPrefix 1.DLT. -dumpRequested false -reportFailureLimit 1 -abortAtFailureLimit 10 -maxTotalLogFileSpace 200M -maxSingleLogSize 1/25 -suite.daa.threadCount 2 -suite.daa.totalNumberTests 7200 -suite.daa.inventoryFile /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/openjdk-tests/TKG/test_output_16043950528003/DaaLoadTest_all_ConcurrentScavenge_0/20201103-105828-DaaLoadTest/results/1.DLT.inventory/openj9.test.load/config/inventories/daa/daaAll.xml -suite.daa.inventoryExcludeFile none -suite.daa.selection random -suite.daa.seed -1 -suite.daa.repeatCount 1 -suite.daa.thinkingTime 0ms..0ms
root      2212     1  0 Nov06 ?        00:00:00 /sbin/rpcbind -f -w
jenkins   3021     1  0 Oct31 ?        00:00:49 /home/jenkins/workspace/Test_openjdk8_j9_extended.system_s390x_linux/openjdkbinary/j2sdk-image/bin/java -classpath /home/jenkins/workspace/Test_openjdk8_j9_extended.system_s390x_linux/jvmtest/system/stf/stf.load/bin:/home/jenkins/workspace/Test_openjdk8_j9_extended.system_s390x_linux/jvmtest/system/stf/stf.core/bin:/home/jenkins/workspace/Test_openjdk8_j9_extended.system_s390x_linux/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-api-2.13.3.jar:/home/jenkins/workspace/Test_openjdk8_j9_extended.system_s390x_linux/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-core-2.13.3.jar:/home/jenkins/workspace/Test_openjdk8_j9_extended.system_s390x_linux/jvmtest/system/systemtest_prereqs/junit-4.12/junit-4.12.jar:/home/jenkins/workspace/Test_openjdk8_j9_extended.system_s390x_linux/jvmtest/system/systemtest_prereqs/junit-4.12/hamcrest-core-1.3.jar:/home/jenkins/workspace/Test_openjdk8_j9_extended.system_s390x_linux/jvmtest/system/openj9-systemtest/openj9.test.daa/bin net.adoptopenjdk.loadTest.LoadTest -resultsDir /home/jenkins/workspace/Test_openjdk8_j9_extended.system_s390x_linux/openjdk-tests/TKG/test_output_16041764261554/DaaLoadTest_all_0/20201031-215132-DaaLoadTest/results -resultsPrefix 1.DLT. -dumpRequested false -reportFailureLimit 1 -abortAtFailureLimit 10 -maxTotalLogFileSpace 200M -maxSingleLogSize 1/25 -suite.daa.threadCount 2 -suite.daa.totalNumberTests 7200 -suite.daa.inventoryFile /home/jenkins/workspace/Test_openjdk8_j9_extended.system_s390x_linux/openjdk-tests/TKG/test_output_16041764261554/DaaLoadTest_all_0/20201031-215132-DaaLoadTest/results/1.DLT.inventory/openj9.test.load/config/inventories/daa/daaAll.xml -suite.daa.inventoryExcludeFile none -suite.daa.selection random -suite.daa.seed -1 -suite.daa.repeatCount 1 -suite.daa.thinkingTime 0ms..0ms
jenkins   4983     1  0 Nov01 ?        00:02:01 /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/openjdkbinary/j2sdk-image/bin/java -classpath /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/stf/stf.load/bin:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/stf/stf.core/bin:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-api-2.13.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-core-2.13.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/junit-4.12/junit-4.12.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/junit-4.12/hamcrest-core-1.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/openj9-systemtest/openj9.test.daa/bin net.adoptopenjdk.loadTest.LoadTest -resultsDir /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/openjdk-tests/TKG/test_output_16042182746895/DaaLoadTest_all_0/20201101-092448-DaaLoadTest/results -resultsPrefix 1.DLT. -dumpRequested false -reportFailureLimit 1 -abortAtFailureLimit 10 -maxTotalLogFileSpace 200M -maxSingleLogSize 1/25 -suite.daa.threadCount 2 -suite.daa.totalNumberTests 7200 -suite.daa.inventoryFile /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/openjdk-tests/TKG/test_output_16042182746895/DaaLoadTest_all_0/20201101-092448-DaaLoadTest/results/1.DLT.inventory/openj9.test.load/config/inventories/daa/daaAll.xml -suite.daa.inventoryExcludeFile none -suite.daa.selection random -suite.daa.seed -1 -suite.daa.repeatCount 1 -suite.daa.thinkingTime 0ms..0ms
jenkins   5714     1  0 Oct25 ?        00:00:33 /lib/systemd/systemd --user
jenkins   5716  5714  0 Oct25 ?        00:00:00 (sd-pam)
jenkins   8175     1  0 Oct31 ?        00:03:02 /home/jenkins/workspace/Test_openjdk15_j9_extended.system_s390x_linux_xl/openjdkbinary/j2sdk-image/bin/java -classpath /home/jenkins/workspace/Test_openjdk15_j9_extended.system_s390x_linux_xl/jvmtest/system/stf/stf.load/bin:/home/jenkins/workspace/Test_openjdk15_j9_extended.system_s390x_linux_xl/jvmtest/system/stf/stf.core/bin:/home/jenkins/workspace/Test_openjdk15_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-api-2.13.3.jar:/home/jenkins/workspace/Test_openjdk15_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-core-2.13.3.jar:/home/jenkins/workspace/Test_openjdk15_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/junit-4.12/junit-4.12.jar:/home/jenkins/workspace/Test_openjdk15_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/junit-4.12/hamcrest-core-1.3.jar:/home/jenkins/workspace/Test_openjdk15_j9_extended.system_s390x_linux_xl/jvmtest/system/openj9-systemtest/openj9.test.daa/bin net.adoptopenjdk.loadTest.LoadTest -resultsDir /home/jenkins/workspace/Test_openjdk15_j9_extended.system_s390x_linux_xl/openjdk-tests/TKG/test_output_16040991624822/DaaLoadTest_all_0/20201031-000631-DaaLoadTest/results -resultsPrefix 1.DLT. -dumpRequested false -reportFailureLimit 1 -abortAtFailureLimit 10 -maxTotalLogFileSpace 200M -maxSingleLogSize 1/25 -suite.daa.threadCount 2 -suite.daa.totalNumberTests 7200 -suite.daa.inventoryFile /home/jenkins/workspace/Test_openjdk15_j9_extended.system_s390x_linux_xl/openjdk-tests/TKG/test_output_16040991624822/DaaLoadTest_all_0/20201031-000631-DaaLoadTest/results/1.DLT.inventory/openj9.test.load/config/inventories/daa/daaAll.xml -suite.daa.inventoryExcludeFile none -suite.daa.selection random -suite.daa.seed -1 -suite.daa.repeatCount 1 -suite.daa.thinkingTime 0ms..0ms
root     13772     1  0 Nov04 ?        00:00:21 /usr/lib/accountsservice/accounts-daemon
jenkins  14083     1  0 Nov03 ?        00:00:21 /home/jenkins/workspace/Test_openjdk8_j9_sanity.system_s390x_linux/openjdkbinary/j2sdk-image/bin/java -Xgcpolicy:gencon -Xgc:concurrentScavenge -classpath /home/jenkins/workspace/Test_openjdk8_j9_sanity.system_s390x_linux/jvmtest/system/stf/stf.load/bin:/home/jenkins/workspace/Test_openjdk8_j9_sanity.system_s390x_linux/jvmtest/system/stf/stf.core/bin:/home/jenkins/workspace/Test_openjdk8_j9_sanity.system_s390x_linux/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-api-2.13.3.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.system_s390x_linux/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-core-2.13.3.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.system_s390x_linux/jvmtest/system/systemtest_prereqs/junit-4.12/junit-4.12.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.system_s390x_linux/jvmtest/system/systemtest_prereqs/junit-4.12/hamcrest-core-1.3.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.system_s390x_linux/jvmtest/system/openj9-systemtest/openj9.test.daa/bin net.adoptopenjdk.loadTest.LoadTest -resultsDir /home/jenkins/workspace/Test_openjdk8_j9_sanity.system_s390x_linux/openjdk-tests/TKG/test_output_16044270632359/DaaLoadTest_daa2_ConcurrentScavenge_0/20201103-230013-DaaLoadTest/results -resultsPrefix 1.DLT. -dumpRequested false -reportFailureLimit 1 -abortAtFailureLimit 10 -maxTotalLogFileSpace 200M -maxSingleLogSize 1/25 -suite.daa.threadCount 2 -suite.daa.totalNumberTests 4200 -suite.daa.inventoryFile /home/jenkins/workspace/Test_openjdk8_j9_sanity.system_s390x_linux/openjdk-tests/TKG/test_output_16044270632359/DaaLoadTest_daa2_ConcurrentScavenge_0/20201103-230013-DaaLoadTest/results/1.DLT.inventory/openj9.test.load/config/inventories/daa/daa2.xml -suite.daa.inventoryExcludeFile none -suite.daa.selection random -suite.daa.seed -1 -suite.daa.repeatCount 1 -suite.daa.thinkingTime 0ms..0ms
root     15231     2  0 14:31 ?        00:00:00 [kworker/u10:3]
root     17040  1103  0 Nov05 ?        00:00:00 sshd: jenkins [priv]
jenkins  17081 17040  0 Nov05 ?        00:16:42 sshd: jenkins@notty
jenkins  17095 17081  0 Nov05 ?        00:00:00 bash -c cd "/home/jenkins" && java  -jar remoting.jar -workDir /home/jenkins -jar-cache /home/jenkins/remoting/jarCache
jenkins  17096 17095  5 Nov05 ?        14:47:50 java -jar remoting.jar -workDir /home/jenkins -jar-cache /home/jenkins/remoting/jarCache
jenkins  20921 32226  0 Nov05 ?        00:00:00 bash -c cd "/home/jenkins" && java  -jar remoting.jar -workDir /home/jenkins -jar-cache /home/jenkins/remoting/jarCache
jenkins  20922 20921  1 Nov05 ?        04:42:29 java -jar remoting.jar -workDir /home/jenkins -jar-cache /home/jenkins/remoting/jarCache
jenkins  23123 17096  0 15:44 ?        00:00:00 Xvfb -displayfd 2 -screen 0 1024x768x24 -fbdir /home/jenkins/xvfb-4711-..fbdir2536215750000524263
jenkins  23159     1  0 15:45 ?        00:00:00 sh -c ({ while [ -d '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6' -a \! -f '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-result.txt' ]; do touch '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-log.txt'; sleep 3; done } & jsc=durable-855c56e594061604b31afe98d52e505d; JENKINS_SERVER_COOKIE=$jsc 'sh' -xe  '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/script.sh' > '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-log.txt' 2>&1; echo $? > '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-result.txt.tmp'; mv '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-result.txt.tmp' '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-result.txt'; wait) >&- 2>&- &
jenkins  23160 23159  0 15:45 ?        00:00:00 sh -c ({ while [ -d '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6' -a \! -f '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-result.txt' ]; do touch '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-log.txt'; sleep 3; done } & jsc=durable-855c56e594061604b31afe98d52e505d; JENKINS_SERVER_COOKIE=$jsc 'sh' -xe  '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/script.sh' > '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-log.txt' 2>&1; echo $? > '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-result.txt.tmp'; mv '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-result.txt.tmp' '/home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/jenkins-result.txt'; wait) >&- 2>&- &
jenkins  23162 23159  0 15:45 ?        00:00:00 sh -xe /home/jenkins/workspace/Grinder@tmp/durable-b6873fe6/script.sh
jenkins  23163 23162  0 15:45 ?        00:00:00 bash ./openjdk-tests/maketest.sh ./openjdk-tests _TestJps
jenkins  23166 23163  0 15:45 ?        00:00:00 make _TestJps
jenkins  23203 23166  0 15:45 ?        00:00:00 make -f runtest.mk _TestJps
jenkins  23245 23203  0 15:45 ?        00:00:00 /bin/sh -c if [ -f "../autoGen.mk" ]; then \ ?make -C .. -f autoGen.mk TestJps; \ fi
jenkins  23246 23245  0 15:45 ?        00:00:00 make -C .. -f autoGen.mk TestJps
jenkins  23248 23246  0 15:45 ?        00:00:00 /bin/sh -c if [ -f "functional/autoGen.mk" ]; then \ ?make -C functional -f autoGen.mk TestJps; \ fi
jenkins  23249 23248  0 15:45 ?        00:00:00 make -C functional -f autoGen.mk TestJps
jenkins  23251 23249  0 15:45 ?        00:00:00 /bin/sh -c if [ -f "Java8andUp/autoGen.mk" ]; then \ ?make -C Java8andUp -f autoGen.mk TestJps; \ fi
jenkins  23252 23251  0 15:45 ?        00:00:00 make -C Java8andUp -f autoGen.mk TestJps
jenkins  23298 23252  0 15:45 ?        00:00:00 /bin/sh -c { itercnt=1; \ mkdir -p "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/test_output_16056279029970/TestJps_0"; \ cd "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/test_output_16056279029970/TestJps_0"; \ "/home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java"   \ -cp "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/TestConfig/resources:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/lib/testng.jar:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/lib/jcommander.jar:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/functional/Java8andUp/GeneralTest.jar" \ -Dcom.ibm.tools.attach.enable=yes \ -Djdk.attach.allowAttachSelf=true \ -Dcom.ibm.tools.attach.timeout=15000 \ org.testng.TestNG -d "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/test_output_16056279029970/TestJps_0" "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/functional/Java8andUp/testng.xml" -testnames TestJps \ -groups level.extended \ -excludegroups d.*.linux_390-64_cmprssptrs,d.*.arch.390,d.*.os.linux,d.*.bits.64,d.*.generic-all; \ if [ $? -eq 0 ] ; then echo ""; echo "TestJps_0""_PASSED"; echo ""; cd /home/jenkins/workspace/Grinder/openjdk-tests/TKG/..;  else echo ""; echo "TestJps_0""_FAILED"; echo ""; fi; } 2>&1 | tee -a "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/test_output_16056279029970/TestTargetResult";
jenkins  23299 23298  0 15:45 ?        00:00:00 /bin/sh -c { itercnt=1; \ mkdir -p "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/test_output_16056279029970/TestJps_0"; \ cd "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/test_output_16056279029970/TestJps_0"; \ "/home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java"   \ -cp "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/TestConfig/resources:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/lib/testng.jar:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/lib/jcommander.jar:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/functional/Java8andUp/GeneralTest.jar" \ -Dcom.ibm.tools.attach.enable=yes \ -Djdk.attach.allowAttachSelf=true \ -Dcom.ibm.tools.attach.timeout=15000 \ org.testng.TestNG -d "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/test_output_16056279029970/TestJps_0" "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/functional/Java8andUp/testng.xml" -testnames TestJps \ -groups level.extended \ -excludegroups d.*.linux_390-64_cmprssptrs,d.*.arch.390,d.*.os.linux,d.*.bits.64,d.*.generic-all; \ if [ $? -eq 0 ] ; then echo ""; echo "TestJps_0""_PASSED"; echo ""; cd /home/jenkins/workspace/Grinder/openjdk-tests/TKG/..;  else echo ""; echo "TestJps_0""_FAILED"; echo ""; fi; } 2>&1 | tee -a "/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/test_output_16056279029970/TestTargetResult";
jenkins  23300 23298  0 15:45 ?        00:00:00 tee -a /home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/test_output_16056279029970/TestTargetResult
jenkins  23302 23299  0 15:45 ?        00:00:04 /home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java -cp /home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/TestConfig/resources:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/lib/testng.jar:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/lib/jcommander.jar:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/functional/Java8andUp/GeneralTest.jar -Dcom.ibm.tools.attach.enable=yes -Djdk.attach.allowAttachSelf=true -Dcom.ibm.tools.attach.timeout=15000 org.testng.TestNG -d /home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/test_output_16056279029970/TestJps_0 /home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/functional/Java8andUp/testng.xml -testnames TestJps -groups level.extended -excludegroups d.*.linux_390-64_cmprssptrs,d.*.arch.390,d.*.os.linux,d.*.bits.64,d.*.generic-all
root     26128     2  0 16:28 ?        00:00:00 [kworker/0:2]
jenkins  26310     1  0 Nov02 ?        00:01:45 /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/openjdkbinary/j2sdk-image/bin/java -classpath /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/stf/stf.load/bin:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/stf/stf.core/bin:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-api-2.13.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/log4j-2.13.3/log4j-core-2.13.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/junit-4.12/junit-4.12.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/systemtest_prereqs/junit-4.12/hamcrest-core-1.3.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/jvmtest/system/openj9-systemtest/openj9.test.daa/bin net.adoptopenjdk.loadTest.LoadTest -resultsDir /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/openjdk-tests/TKG/test_output_16042957175362/DaaLoadTest_all_0/20201102-065521-DaaLoadTest/results -resultsPrefix 1.DLT. -dumpRequested false -reportFailureLimit 1 -abortAtFailureLimit 10 -maxTotalLogFileSpace 200M -maxSingleLogSize 1/25 -suite.daa.threadCount 2 -suite.daa.totalNumberTests 7200 -suite.daa.inventoryFile /home/jenkins/workspace/Test_openjdk11_j9_extended.system_s390x_linux_xl/openjdk-tests/TKG/test_output_16042957175362/DaaLoadTest_all_0/20201102-065521-DaaLoadTest/results/1.DLT.inventory/openj9.test.load/config/inventories/daa/daaAll.xml -suite.daa.inventoryExcludeFile none -suite.daa.selection random -suite.daa.seed -1 -suite.daa.repeatCount 1 -suite.daa.thinkingTime 0ms..0ms
root     26999     2  0 16:40 ?        00:00:00 [kworker/2:2]
root     27828     2  0 16:52 ?        00:00:00 [kworker/3:1]
root     28181     2  0 16:58 ?        00:00:00 [kworker/1:2]
root     28410     2  0 17:02 ?        00:00:00 [kworker/2:0]
root     28721     2  0 17:07 ?        00:00:00 [kworker/0:0]
root     28858     2  0 17:08 ?        00:00:00 [kworker/u10:1]
root     28859     2  0 17:08 ?        00:00:00 [kworker/3:2]
root     28860     2  0 17:08 ?        00:00:00 [kworker/1:1]
jenkins  29260 23302  0 17:16 ?        00:00:00 /home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java -Dcom.ibm.tools.attach.enable=yes -classpath /home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/TestConfig/resources:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/lib/testng.jar:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../TKG/lib/jcommander.jar:/home/jenkins/workspace/Grinder/openjdk-tests/TKG/../../jvmtest/functional/Java8andUp/GeneralTest.jar org.openj9.test.attachAPI.TargetVM
jenkins  29282 23302  0 17:16 ?        00:00:00 /home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/jps
jenkins  29436 17096  0 17:18 ?        00:00:00 /home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/jps -m
root     29477     2  0 17:18 ?        00:00:00 [kworker/0:1]
root     29530     2  0 17:18 ?        00:00:00 [kworker/0:3]
root     29532     2  0 17:18 ?        00:00:00 [kworker/1:0]
jenkins  29579 23160  0 17:19 ?        00:00:00 sleep 3
jenkins  29580 17096  0 17:20 ?        00:00:00 ps -ef
root     32177  1103  0 Nov05 ?        00:00:00 sshd: jenkins [priv]
jenkins  32226 32177  0 Nov05 ?        00:02:38 sshd: jenkins@notty

[andrew-m-leonard]

I have killed all these rogue processes and rerun my JpsTest Grinder on that machine: https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/4713/
Job now takes 13seconds !!
@sxa @ShelleyLambert rogue Processes again was the problem

[sxa]

I've adjusted the SXA-processCheck job to allow it to hit processes with kill -KILL as an optional parameter and am running with that parameter as job 118 Let's see if the JDK11 and later nightlies are helped by this

[smlambert]

This is very good to hear 👍

[sxa]

Previously (and still now by default) it would run this line and not issue a hard kill if a normal one didn't work:

 echo Cleanup failed - may need manual intervention as I am too scared to run kill -KILL ...

My view is that if a job gets into a state where it won't respond to a normal kill signal then that's a bit of a serious error case and we should be trying to look into where it's locked up like that and see if it's a JVM issue that we can resolve - the processCheck job was only really intended to be a mitigation until we tried to stop those situations occurring. Happy to accept willing volunteers to look into any locked-up processes obvs ;-)

[smlambert]

Yep, agree @sxa, as briefly mentioned in call today, the idea would be to attempt to figure out which tests are culprits.

Talked with @renfeiw and there is a branch with some other environment checks being worked on by a part-time student. I think we can/should proceed with adding Will's fix to maketest.sh in the interim, while we wait for the other environment checks work to land, then we can move it from maketest to TKG (once the landing spot is ready).

[andrew-m-leonard]

Having run the overnight SXA process cleanup, the jpsTest now runs in 14 seconds
The nightly s390x tests all ran through smoothly and were finished by morning