[2024-09-26T04:15:46.515Z] Running test ClassLoadingTest_5m_2 ... [2024-09-26T04:15:46.515Z] =============================================== [2024-09-26T04:15:46.825Z] ClassLoadingTest_5m_2 Start Time: Thu Sep 26 04:15:46 2024 Epoch Time (ms): 1727324146489 [2024-09-26T04:15:46.825Z] variation: Mode1000 [2024-09-26T04:15:46.825Z] JVM_OPTIONS: [2024-09-26T04:15:46.825Z] { \ [2024-09-26T04:15:46.825Z] echo ""; echo "TEST SETUP:"; \ [2024-09-26T04:15:46.825Z] echo "Nothing to be done for setup."; \ [2024-09-26T04:15:46.825Z] mkdir -p "F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\\TKG\\output_17273201016149\\ClassLoadingTest_5m_2"; \ [2024-09-26T04:15:46.825Z] cd "F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\\TKG\\output_17273201016149\\ClassLoadingTest_5m_2"; \ [2024-09-26T04:15:46.825Z] echo ""; echo "TESTING:"; \ [2024-09-26T04:15:46.826Z] perl F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests///..//jvmtest\\system\\otherLoadTest/../\\STF\\stf.core\\scripts\\stf.pl -test-root="F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests///..//jvmtest\\system\\otherLoadTest/../\\STF;F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests///..//jvmtest\\system\\otherLoadTest/../\\aqa-systemtest""" -systemtest-prereqs="F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/../../testDependency/system_lib\\" -java-args=' ' -results-root="F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\\TKG\\output_17273201016149\\ClassLoadingTest_5m_2" -test=ClassloadingLoadTest -test-args="timeLimit=5m"; \ [2024-09-26T04:15:46.826Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "ClassLoadingTest_5m_2""_PASSED"; echo "-----------------------------------"; cd F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/; rm -f -r "F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\\TKG\\output_17273201016149\\ClassLoadingTest_5m_2"; else echo "-----------------------------------"; echo "ClassLoadingTest_5m_2""_FAILED"; echo "-----------------------------------"; fi; \ [2024-09-26T04:15:46.826Z] echo ""; echo "TEST TEARDOWN:"; \ [2024-09-26T04:15:46.826Z] echo "Nothing to be done for teardown."; \ [2024-09-26T04:15:46.826Z] } 2>&1 | tee -a "F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\\TKG\\output_17273201016149\\TestTargetResult"; [2024-09-26T04:15:46.826Z] [2024-09-26T04:15:46.826Z] TEST SETUP: [2024-09-26T04:15:46.826Z] Nothing to be done for setup. [2024-09-26T04:15:46.826Z] [2024-09-26T04:15:46.826Z] TESTING: [2024-09-26T04:15:47.137Z] STF 04:15:46.914 - ========================= S T F ========================= [2024-09-26T04:15:47.137Z] systemtest-prereqs has been processed, and set to: F:/workspace/testDependency/system_libRetrieving amount of free space on drive containing F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\TKG\output_17273201016149\ClassLoadingTest_5m_2 [2024-09-26T04:15:47.137Z] There is 111342 Mb free [2024-09-26T04:15:47.137Z] STF 04:15:46.942 - ================== G E N E R A T I O N ================== [2024-09-26T04:15:47.137Z] STF 04:15:46.945 - Checking JVM: F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/jdkbinary/j2sdk-image [2024-09-26T04:15:47.137Z] STF 04:15:46.945 - Starting process to generate scripts: F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/jdkbinary/j2sdk-image/bin/java -Dlog4j.skipJansi=true -Djava.system.class.loader=net.adoptopenjdk.stf.runner.StfClassLoader -classpath F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/../../testDependency/system_lib\/log4j/log4j-api.jar;F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/../../testDependency/system_lib\/log4j/log4j-core.jar;F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/jvmtest/system/STF/stf.core/scripts/../bin net.adoptopenjdk.stf.runner.StfRunner -properties "F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\TKG\output_17273201016149\ClassLoadingTest_5m_2/20240926-041546-ClassloadingLoadTest/stf_parameters.properties, , F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/jvmtest/system/STF/stf.core/config/stf.properties" -testDir "F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\TKG\output_17273201016149\ClassLoadingTest_5m_2/20240926-041546-ClassloadingLoadTest" [2024-09-26T04:15:48.228Z] GEN 04:15:47.796 - Found test. Project: 'openjdk.test.load' class: 'ClassloadingLoadTest.class' Dir: 'F:\workspace\workspace\Test_openjdk11_hs_sanity.system_x86-32_windows\jvmtest\system\aqa-systemtest\openjdk.test.load\bin' [2024-09-26T04:15:48.228Z] GEN 04:15:47.815 - Found test. Project: 'openjdk.test.load' class: 'net.adoptopenjdk.stf.ClassloadingLoadTest' [2024-09-26T04:15:48.228Z] GEN Classpath directories used by project 'openjdk.test.load': [2024-09-26T04:15:48.228Z] GEN F:\\workspace\\workspace\\Test_openjdk11_hs_sanity.system_x86-32_windows\\jvmtest\\system\\aqa-systemtest\\openjdk.test.load\\bin [2024-09-26T04:15:48.228Z] GEN F:\\workspace\\workspace\\Test_openjdk11_hs_sanity.system_x86-32_windows\\jvmtest\\system\\STF\\stf.core\\bin [2024-09-26T04:15:48.228Z] GEN F:\\workspace\\workspace\\Test_openjdk11_hs_sanity.system_x86-32_windows\\jvmtest\\system\\STF\\stf.load\\bin [2024-09-26T04:15:48.228Z] GEN F:/workspace/testDependency/system_lib/log4j/log4j-api.jar [2024-09-26T04:15:48.228Z] GEN F:/workspace/testDependency/system_lib/log4j/log4j-core.jar [2024-09-26T04:15:48.228Z] GEN F:/workspace/testDependency/system_lib/junit/junit.jar [2024-09-26T04:15:48.228Z] GEN F:/workspace/testDependency/system_lib/junit/hamcrest-core.jar [2024-09-26T04:15:48.228Z] GEN 04:15:48.025 - Using Mode NoOptions. Values = '' [2024-09-26T04:15:48.228Z] GEN 04:15:48.102 - [2024-09-26T04:15:48.228Z] GEN 04:15:48.102 - Test command summary: [2024-09-26T04:15:48.228Z] GEN 04:15:48.102 - Step Stage Command Description [2024-09-26T04:15:48.228Z] GEN 04:15:48.102 - -----+--------+-----------------+------------ [2024-09-26T04:15:48.228Z] GEN 04:15:48.102 - 1 execute Run java Run classloading tests [2024-09-26T04:15:48.228Z] STF 04:15:48.136 - [2024-09-26T04:15:48.228Z] STF 04:15:48.136 - Script generation completed [2024-09-26T04:15:48.228Z] STF 04:15:48.136 - [2024-09-26T04:15:48.228Z] STF 04:15:48.136 - [2024-09-26T04:15:48.228Z] STF 04:15:48.136 - ======================= S E T U P ======================= [2024-09-26T04:15:48.228Z] STF 04:15:48.136 - Running setup: perl F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\TKG\output_17273201016149\ClassLoadingTest_5m_2/20240926-041546-ClassloadingLoadTest/setUp.pl [2024-09-26T04:15:48.541Z] STF 04:15:48.264 - SETUP stage completed [2024-09-26T04:15:48.541Z] STF 04:15:48.278 - [2024-09-26T04:15:48.541Z] STF 04:15:48.278 - ==================== E X E C U T E - ==================== [2024-09-26T04:15:48.541Z] STF 04:15:48.278 - Running execute: perl F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\TKG\output_17273201016149\ClassLoadingTest_5m_2/20240926-041546-ClassloadingLoadTest/execute.pl [2024-09-26T04:15:48.541Z] STF 04:15:48.404 - [2024-09-26T04:15:48.541Z] STF 04:15:48.404 - Java version [2024-09-26T04:15:48.541Z] STF 04:15:48.404 - Running: F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/jdkbinary/j2sdk-image/bin/java -version [2024-09-26T04:15:48.541Z] openjdk version "11.0.25-beta" 2024-10-15 [2024-09-26T04:15:48.541Z] OpenJDK Runtime Environment Temurin-11.0.25+7-202409252112 (build 11.0.25-beta+7-ea) [2024-09-26T04:15:48.541Z] OpenJDK Client VM Temurin-11.0.25+7-202409252112 (build 11.0.25-beta+7-ea, mixed mode) [2024-09-26T04:15:48.541Z] STF 04:15:48.501 - [2024-09-26T04:15:48.541Z] STF 04:15:48.501 - +------ Step 1 - Run classloading tests [2024-09-26T04:15:48.541Z] STF 04:15:48.501 - | Run foreground process [2024-09-26T04:15:48.541Z] STF 04:15:48.501 - | Program: F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/jdkbinary/j2sdk-image/bin/java [2024-09-26T04:15:48.541Z] STF 04:15:48.501 - | Mnemonic: CLT [2024-09-26T04:15:48.541Z] STF 04:15:48.501 - | Echo: ECHO_ON [2024-09-26T04:15:48.541Z] STF 04:15:48.501 - | Expectation: CLEAN_RUN within 1h5m [2024-09-26T04:15:48.541Z] STF 04:15:48.501 - | [2024-09-26T04:15:48.541Z] STF 04:15:48.502 - Running command: F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/jdkbinary/j2sdk-image/bin/java -Djava.classloading.dir=F:\workspace\workspace\Test_openjdk11_hs_sanity.system_x86-32_windows\jvmtest\system\aqa-systemtest -Djava.version.number=11 --add-modules=java.rmi -classpath F:\workspace\workspace\Test_openjdk11_hs_sanity.system_x86-32_windows\jvmtest\system\STF\stf.load\bin;F:\workspace\workspace\Test_openjdk11_hs_sanity.system_x86-32_windows\jvmtest\system\STF\stf.core\bin;F:/workspace/testDependency/system_lib/log4j/log4j-api.jar;F:/workspace/testDependency/system_lib/log4j/log4j-core.jar;F:/workspace/testDependency/system_lib/junit/junit.jar;F:/workspace/testDependency/system_lib/junit/hamcrest-core.jar;F:\workspace\workspace\Test_openjdk11_hs_sanity.system_x86-32_windows\jvmtest\system\aqa-systemtest\openjdk.test.classloading\bin net.adoptopenjdk.loadTest.LoadTest -resultsDir F:\workspace\workspace\Test_openjdk11_hs_sanity.system_x86-32_windows\aqa-tests\TKG\output_17273201016149\ClassLoadingTest_5m_2\20240926-041546-ClassloadingLoadTest\results -resultsPrefix 1.CLT. -timeLimit 5m -abortIfOutOfMemory false -reportFailureLimit 1 -abortAtFailureLimit 10 -maxTotalLogFileSpace 200M -maxSingleLogSize 1/25 -suite.classloading.threadCount 10 -suite.classloading.inventoryFile F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/TKG/output_17273201016149/ClassLoadingTest_5m_2/20240926-041546-ClassloadingLoadTest/results/1.CLT.inventory/openjdk.test.load/config/inventories/classloading/classloading.xml -suite.classloading.inventoryExcludeFile none -suite.classloading.selection random -suite.classloading.seed -1 -suite.classloading.repeatCount 1 -suite.classloading.thinkingTime 0ms..0ms [2024-09-26T04:15:48.541Z] STF 04:15:48.503 - Redirecting stderr to F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/TKG/output_17273201016149/ClassLoadingTest_5m_2/20240926-041546-ClassloadingLoadTest/results/1.CLT.stderr [2024-09-26T04:15:48.541Z] STF 04:15:48.503 - Redirecting stdout to F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/TKG/output_17273201016149/ClassLoadingTest_5m_2/20240926-041546-ClassloadingLoadTest/results/1.CLT.stdout [2024-09-26T04:15:48.857Z] STF 04:15:48.531 - Monitoring processes: CLT [2024-09-26T04:15:49.534Z] CLT 04:15:49.329 - Load test parameters [2024-09-26T04:15:49.534Z] CLT 04:15:49.332 - Time limited = true [2024-09-26T04:15:49.534Z] CLT 04:15:49.333 - Time limit = 5m [2024-09-26T04:15:49.534Z] CLT 04:15:49.334 - abortIfOutOfMemory = false [2024-09-26T04:15:49.534Z] CLT 04:15:49.334 - reportFailureLimit = 1 [2024-09-26T04:15:49.534Z] CLT 04:15:49.334 - abortAtFailureLimit = 10 [2024-09-26T04:15:49.534Z] CLT 04:15:49.338 - maxTotalLogFileSpace = 209715200 [2024-09-26T04:15:49.534Z] CLT 04:15:49.338 - maxSingleLogSize = 8388608 [2024-09-26T04:15:49.534Z] CLT 04:15:49.338 - Parameters for suite 0 [2024-09-26T04:15:49.534Z] CLT 04:15:49.338 - Suite name = classloading [2024-09-26T04:15:49.534Z] CLT 04:15:49.338 - Number threads = 10 [2024-09-26T04:15:49.534Z] CLT 04:15:49.339 - Supplied seed = -1 [2024-09-26T04:15:49.534Z] CLT 04:15:49.339 - Inventory file = F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/TKG/output_17273201016149/ClassLoadingTest_5m_2/20240926-041546-ClassloadingLoadTest/results/1.CLT.inventory/openjdk.test.load/config/inventories/classloading/classloading.xml [2024-09-26T04:15:49.534Z] CLT 04:15:49.341 - Exclude file = none [2024-09-26T04:15:49.534Z] CLT 04:15:49.341 - Number tests = -1 [2024-09-26T04:15:49.534Z] CLT 04:15:49.341 - Repeat count = 1 [2024-09-26T04:15:49.534Z] CLT 04:15:49.341 - Thinking time = 0ms..0ms [2024-09-26T04:15:49.534Z] CLT 04:15:49.341 - Selection mode = random [2024-09-26T04:15:49.534Z] CLT 04:15:49.342 - Actual seed = 1727360602857 [2024-09-26T04:15:49.534Z] CLT 04:15:49.365 - Parsing inventory file. Root=F:\\workspace\\workspace\\Test_openjdk11_hs_sanity.system_x86-32_windows\\aqa-tests\\TKG\\output_17273201016149\\ClassLoadingTest_5m_2\\20240926-041546-ClassloadingLoadTest\\results\\1.CLT.inventory File=openjdk.test.load/config/inventories/classloading/classloading.xml [2024-09-26T04:15:49.534Z] CLT 04:15:49.371 - Final test list: [2024-09-26T04:15:49.534Z] CLT 04:15:49.383 - 0 ArbitraryJava[net.adoptopenjdk.test.classloading.deadlock.DeadlockTest runTest] Weighting=1 [2024-09-26T04:15:49.534Z] CLT 04:15:49.383 - 1 ArbitraryJava[net.adoptopenjdk.test.classloading.ClassMapHog run] Weighting=1 [2024-09-26T04:15:49.534Z] CLT 04:15:49.383 - 2 ArbitraryJava[net.adoptopenjdk.test.classloading.ClassHog run] Weighting=1 [2024-09-26T04:15:49.534Z] CLT 04:15:49.416 - Starting thread. Suite=0 thread=0 [2024-09-26T04:15:49.534Z] CLT 04:15:49.417 - Starting thread. Suite=0 thread=1 [2024-09-26T04:15:49.534Z] CLT 04:15:49.417 - Starting thread. Suite=0 thread=2 [2024-09-26T04:15:49.534Z] CLT 04:15:49.418 - Starting thread. Suite=0 thread=3 [2024-09-26T04:15:49.534Z] CLT 04:15:49.418 - Starting thread. Suite=0 thread=4 [2024-09-26T04:15:49.534Z] CLT 04:15:49.419 - Starting thread. Suite=0 thread=5 [2024-09-26T04:15:49.534Z] CLT 04:15:49.419 - Starting thread. Suite=0 thread=6 [2024-09-26T04:15:49.534Z] CLT 04:15:49.419 - Starting thread. Suite=0 thread=7 [2024-09-26T04:15:49.534Z] CLT 04:15:49.419 - Starting thread. Suite=0 thread=8 [2024-09-26T04:15:49.534Z] CLT 04:15:49.420 - Starting thread. Suite=0 thread=9 [2024-09-26T04:16:12.382Z] CLT 04:16:09.533 - Completed 6.7%. Number of tests started=1624 [2024-09-26T04:16:31.427Z] CLT 04:16:29.422 - Completed 13.3%. Number of tests started=3333 (+1709) [2024-09-26T04:16:50.450Z] CLT 04:16:49.413 - Completed 20.0%. Number of tests started=5270 (+1937) [2024-09-26T04:17:13.345Z] CLT 04:17:09.487 - Completed 26.7%. Number of tests started=6944 (+1674) [2024-09-26T04:17:32.343Z] CLT 04:17:29.529 - Completed 33.4%. Number of tests started=8557 (+1613) [2024-09-26T04:17:51.411Z] CLT 04:17:49.521 - Completed 40.0%. Number of tests started=10424 (+1867) [2024-09-26T04:18:10.424Z] CLT 04:18:09.466 - Completed 46.7%. Number of tests started=12071 (+1647) [2024-09-26T04:18:33.275Z] CLT 04:18:29.472 - Completed 53.4%. Number of tests started=13901 (+1830) [2024-09-26T04:18:52.282Z] CLT 04:18:49.508 - Completed 60.1%. Number of tests started=15448 (+1547) [2024-09-26T04:19:11.262Z] CLT 04:19:09.459 - Completed 66.7%. Number of tests started=17147 (+1699) [2024-09-26T04:19:30.266Z] CLT 04:19:29.427 - Completed 73.4%. Number of tests started=18987 (+1840) [2024-09-26T04:19:53.155Z] CLT 04:19:49.477 - Completed 80.0%. Number of tests started=20502 (+1515) [2024-09-26T04:20:12.112Z] CLT 04:20:09.466 - Completed 86.7%. Number of tests started=22390 (+1888) [2024-09-26T04:20:31.185Z] CLT 04:20:29.427 - Completed 93.4%. Number of tests started=24211 (+1821) [2024-09-26T04:20:50.159Z] STF 04:20:48.328 - Heartbeat: Process CLT is still running [2024-09-26T04:20:50.159Z] CLT 04:20:49.342 - Thread completed. Suite=0 thread=0 [2024-09-26T04:20:50.159Z] CLT 04:20:49.366 - Thread completed. Suite=0 thread=9 [2024-09-26T04:20:50.159Z] CLT 04:20:49.385 - Thread completed. Suite=0 thread=4 [2024-09-26T04:20:50.159Z] CLT 04:20:49.386 - Thread completed. Suite=0 thread=3 [2024-09-26T04:20:50.159Z] CLT 04:20:49.388 - Thread completed. Suite=0 thread=6 [2024-09-26T04:20:50.159Z] CLT 04:20:49.392 - Thread completed. Suite=0 thread=1 [2024-09-26T04:20:50.159Z] CLT 04:20:49.410 - Thread completed. Suite=0 thread=7 [2024-09-26T04:20:50.159Z] CLT 04:20:49.414 - Thread completed. Suite=0 thread=5 [2024-09-26T04:20:50.159Z] CLT 04:20:49.434 - Thread completed. Suite=0 thread=2 [2024-09-26T04:20:50.159Z] CLT 04:20:49.434 - Thread completed. Suite=0 thread=8 [2024-09-26T04:20:50.159Z] CLT 04:20:49.481 - Test stopped due to reaching runtime limit [2024-09-26T04:20:50.159Z] CLT 04:20:49.481 - Load test completed [2024-09-26T04:20:50.159Z] CLT 04:20:49.483 - Ran : 25887 [2024-09-26T04:20:50.159Z] CLT 04:20:49.483 - Passed : 25887 [2024-09-26T04:20:50.159Z] CLT 04:20:49.484 - Failed : 0 [2024-09-26T04:20:50.159Z] CLT 04:20:49.485 - Result : PASSED [2024-09-26T04:20:50.159Z] STF 04:20:49.850 - Monitoring Report Summary: [2024-09-26T04:20:50.159Z] STF 04:20:49.850 - o Process CLT ended with the expected exit code (0) [2024-09-26T04:20:50.159Z] STF 04:20:49.851 - EXECUTE stage completed [2024-09-26T04:20:50.478Z] STF 04:20:50.354 - [2024-09-26T04:20:50.478Z] STF 04:20:50.354 - ==================== T E A R D O W N ==================== [2024-09-26T04:20:50.478Z] STF 04:20:50.354 - Running teardown: perl F:/workspace/workspace/Test_openjdk11_hs_sanity.system_x86-32_windows/aqa-tests/\TKG\output_17273201016149\ClassLoadingTest_5m_2/20240926-041546-ClassloadingLoadTest/tearDown.pl [2024-09-26T04:20:50.800Z] STF 04:20:50.490 - TEARDOWN stage completed [2024-09-26T04:20:50.800Z] STF 04:20:50.507 - [2024-09-26T04:20:50.800Z] STF 04:20:50.507 - ===================== R E S U L T S ===================== [2024-09-26T04:20:50.800Z] STF 04:20:50.507 - Stage results: [2024-09-26T04:20:50.800Z] STF 04:20:50.507 - setUp: pass [2024-09-26T04:20:50.800Z] STF 04:20:50.507 - execute: pass [2024-09-26T04:20:50.800Z] STF 04:20:50.507 - teardown: pass [2024-09-26T04:20:50.800Z] STF 04:20:50.507 - [2024-09-26T04:20:50.800Z] STF 04:20:50.507 - Overall result: PASSED [2024-09-26T04:20:50.800Z] ----------------------------------- [2024-09-26T04:20:50.800Z] ClassLoadingTest_5m_2_PASSED [2024-09-26T04:20:50.800Z] ----------------------------------- [2024-09-26T04:20:50.800Z] [2024-09-26T04:20:50.800Z] TEST TEARDOWN: [2024-09-26T04:20:50.800Z] Nothing to be done for teardown. [2024-09-26T04:20:50.800Z] ClassLoadingTest_5m_2 Finish Time: Thu Sep 26 04:20:50 2024 Epoch Time (ms): 1727324450627