[2025-08-28T21:36:41.609Z] Running test renaissance-als_0 ... [2025-08-28T21:36:41.609Z] =============================================== [2025-08-28T21:36:41.609Z] renaissance-als_0 Start Time: Thu Aug 28 21:36:40 2025 Epoch Time (ms): 1756417000831 [2025-08-28T21:36:41.609Z] variation: NoOptions [2025-08-28T21:36:41.609Z] JVM_OPTIONS: [2025-08-28T21:36:41.609Z] { \ [2025-08-28T21:36:41.609Z] echo ""; echo "TEST SETUP:"; \ [2025-08-28T21:36:41.609Z] echo "Nothing to be done for setup."; \ [2025-08-28T21:36:41.609Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux_testList_1/aqa-tests/TKG/../TKG/output_17564170007691/renaissance-als_0"; \ [2025-08-28T21:36:41.609Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux_testList_1/aqa-tests/TKG/../TKG/output_17564170007691/renaissance-als_0"; \ [2025-08-28T21:36:41.609Z] echo ""; echo "TESTING:"; \ [2025-08-28T21:36:41.609Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux_testList_1/jdkbinary/j2sdk-image/bin/java" --add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.base/java.util.concurrent=ALL-UNNAMED --add-opens java.base/java.nio=ALL-UNNAMED --add-opens java.base/sun.nio.ch=ALL-UNNAMED --add-opens java.base/java.lang.invoke=ALL-UNNAMED -jar "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux_testList_1/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux_testList_1/aqa-tests/TKG/../TKG/output_17564170007691/renaissance-als_0"/als.json" als; \ [2025-08-28T21:36:41.609Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux_testList_1/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux_testList_1/aqa-tests/TKG/../TKG/output_17564170007691/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-08-28T21:36:41.609Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-08-28T21:36:41.609Z] echo "Nothing to be done for teardown."; \ [2025-08-28T21:36:41.609Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux_testList_1/aqa-tests/TKG/../TKG/output_17564170007691/TestTargetResult"; [2025-08-28T21:36:41.609Z] [2025-08-28T21:36:41.609Z] TEST SETUP: [2025-08-28T21:36:41.609Z] Nothing to be done for setup. [2025-08-28T21:36:41.609Z] [2025-08-28T21:36:41.609Z] TESTING: [2025-08-28T21:36:53.192Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-08-28T21:36:58.709Z] WARNING: An illegal reflective access operation has occurred [2025-08-28T21:36:58.709Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux_testList_1/aqa-tests/TKG/output_17564170007691/renaissance-als_0/harness-213642-12728146838893657323/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-08-28T21:36:58.709Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-08-28T21:36:58.709Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-08-28T21:36:58.709Z] WARNING: All illegal access operations will be denied in a future release [2025-08-28T21:37:01.132Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-08-28T21:37:01.132Z] GC before operation: completed in 193.894 ms, heap usage 354.000 MB -> 35.025 MB. [2025-08-28T21:38:08.215Z] ====== als (apache-spark) [default], iteration 0 completed (60447.836 ms) ====== [2025-08-28T21:38:08.215Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-08-28T21:38:08.215Z] GC before operation: completed in 319.681 ms, heap usage 209.909 MB -> 60.332 MB. [2025-08-28T21:38:24.216Z] ====== als (apache-spark) [default], iteration 1 completed (20806.182 ms) ====== [2025-08-28T21:38:24.216Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-08-28T21:38:24.977Z] GC before operation: completed in 301.697 ms, heap usage 419.293 MB -> 61.417 MB. [2025-08-28T21:38:43.772Z] ====== als (apache-spark) [default], iteration 2 completed (17722.786 ms) ====== [2025-08-28T21:38:43.772Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-08-28T21:38:43.772Z] GC before operation: completed in 416.560 ms, heap usage 153.819 MB -> 61.683 MB. [2025-08-28T21:39:02.503Z] ====== als (apache-spark) [default], iteration 3 completed (16657.905 ms) ====== [2025-08-28T21:39:02.503Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-08-28T21:39:02.503Z] GC before operation: completed in 280.582 ms, heap usage 148.302 MB -> 62.190 MB. [2025-08-28T21:39:21.284Z] ====== als (apache-spark) [default], iteration 4 completed (19260.688 ms) ====== [2025-08-28T21:39:21.284Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-08-28T21:39:21.284Z] GC before operation: completed in 460.780 ms, heap usage 193.286 MB -> 62.691 MB. [2025-08-28T21:39:43.271Z] ====== als (apache-spark) [default], iteration 5 completed (18790.020 ms) ====== [2025-08-28T21:39:43.271Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-08-28T21:39:43.271Z] GC before operation: completed in 293.092 ms, heap usage 270.657 MB -> 63.350 MB. [2025-08-28T21:40:01.987Z] ====== als (apache-spark) [default], iteration 6 completed (19365.785 ms) ====== [2025-08-28T21:40:01.987Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-08-28T21:40:01.987Z] GC before operation: completed in 367.592 ms, heap usage 253.034 MB -> 63.870 MB. [2025-08-28T21:40:20.795Z] ====== als (apache-spark) [default], iteration 7 completed (18962.425 ms) ====== [2025-08-28T21:40:20.795Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-08-28T21:40:20.795Z] GC before operation: completed in 273.113 ms, heap usage 202.507 MB -> 64.274 MB. [2025-08-28T21:40:39.535Z] ====== als (apache-spark) [default], iteration 8 completed (17803.709 ms) ====== [2025-08-28T21:40:39.535Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-08-28T21:40:40.303Z] GC before operation: completed in 422.758 ms, heap usage 222.459 MB -> 64.934 MB. [2025-08-28T21:40:59.062Z] ====== als (apache-spark) [default], iteration 9 completed (16588.127 ms) ====== [2025-08-28T21:40:59.062Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-08-28T21:40:59.062Z] GC before operation: completed in 367.861 ms, heap usage 261.607 MB -> 65.224 MB. [2025-08-28T21:41:15.673Z] ====== als (apache-spark) [default], iteration 10 completed (15645.210 ms) ====== [2025-08-28T21:41:15.673Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-08-28T21:41:15.673Z] GC before operation: completed in 312.335 ms, heap usage 226.164 MB -> 65.471 MB. [2025-08-28T21:41:31.737Z] ====== als (apache-spark) [default], iteration 11 completed (17052.297 ms) ====== [2025-08-28T21:41:31.737Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-08-28T21:41:32.510Z] GC before operation: completed in 288.640 ms, heap usage 253.767 MB -> 65.741 MB. [2025-08-28T21:41:51.372Z] ====== als (apache-spark) [default], iteration 12 completed (17674.825 ms) ====== [2025-08-28T21:41:51.372Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-08-28T21:41:51.372Z] GC before operation: completed in 321.875 ms, heap usage 268.951 MB -> 66.018 MB. [2025-08-28T21:42:07.387Z] ====== als (apache-spark) [default], iteration 13 completed (16061.481 ms) ====== [2025-08-28T21:42:07.387Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-08-28T21:42:07.387Z] GC before operation: completed in 350.212 ms, heap usage 615.493 MB -> 66.699 MB. [2025-08-28T21:42:26.139Z] ====== als (apache-spark) [default], iteration 14 completed (16144.053 ms) ====== [2025-08-28T21:42:26.139Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-08-28T21:42:26.139Z] GC before operation: completed in 299.219 ms, heap usage 238.291 MB -> 66.519 MB. [2025-08-28T21:42:42.756Z] ====== als (apache-spark) [default], iteration 15 completed (15940.014 ms) ====== [2025-08-28T21:42:42.756Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-08-28T21:42:42.756Z] GC before operation: completed in 356.986 ms, heap usage 230.571 MB -> 66.654 MB. [2025-08-28T21:42:58.802Z] ====== als (apache-spark) [default], iteration 16 completed (16924.385 ms) ====== [2025-08-28T21:42:58.802Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-08-28T21:42:59.566Z] GC before operation: completed in 322.684 ms, heap usage 263.566 MB -> 67.014 MB. [2025-08-28T21:43:18.364Z] ====== als (apache-spark) [default], iteration 17 completed (16951.640 ms) ====== [2025-08-28T21:43:18.364Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-08-28T21:43:18.364Z] GC before operation: completed in 345.738 ms, heap usage 279.779 MB -> 66.798 MB. [2025-08-28T21:43:34.391Z] ====== als (apache-spark) [default], iteration 18 completed (15271.554 ms) ====== [2025-08-28T21:43:34.391Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-08-28T21:43:34.391Z] GC before operation: completed in 303.187 ms, heap usage 288.738 MB -> 67.534 MB. [2025-08-28T21:43:48.017Z] ====== als (apache-spark) [default], iteration 19 completed (14454.548 ms) ====== [2025-08-28T21:43:48.017Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-08-28T21:43:48.017Z] GC before operation: completed in 363.860 ms, heap usage 214.168 MB -> 67.720 MB. [2025-08-28T21:44:07.292Z] ====== als (apache-spark) [default], iteration 20 completed (18857.240 ms) ====== [2025-08-28T21:44:07.292Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-08-28T21:44:08.055Z] GC before operation: completed in 326.357 ms, heap usage 187.280 MB -> 68.129 MB. [2025-08-28T21:44:26.783Z] ====== als (apache-spark) [default], iteration 21 completed (16977.225 ms) ====== [2025-08-28T21:44:26.783Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-08-28T21:44:26.783Z] GC before operation: completed in 418.646 ms, heap usage 261.939 MB -> 68.247 MB. [2025-08-28T21:44:45.486Z] ====== als (apache-spark) [default], iteration 22 completed (17131.290 ms) ====== [2025-08-28T21:44:45.486Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-08-28T21:44:45.486Z] GC before operation: completed in 328.806 ms, heap usage 421.063 MB -> 68.629 MB. [2025-08-28T21:45:01.548Z] ====== als (apache-spark) [default], iteration 23 completed (16680.907 ms) ====== [2025-08-28T21:45:01.548Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-08-28T21:45:01.548Z] GC before operation: completed in 287.503 ms, heap usage 235.555 MB -> 68.785 MB. [2025-08-28T21:45:17.537Z] ====== als (apache-spark) [default], iteration 24 completed (15961.518 ms) ====== [2025-08-28T21:45:17.537Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-08-28T21:45:18.294Z] GC before operation: completed in 343.704 ms, heap usage 314.010 MB -> 69.128 MB. [2025-08-28T21:45:34.710Z] ====== als (apache-spark) [default], iteration 25 completed (15264.617 ms) ====== [2025-08-28T21:45:34.710Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-08-28T21:45:34.710Z] GC before operation: completed in 321.703 ms, heap usage 302.968 MB -> 69.269 MB. [2025-08-28T21:45:50.831Z] ====== als (apache-spark) [default], iteration 26 completed (15922.243 ms) ====== [2025-08-28T21:45:50.831Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-08-28T21:45:50.831Z] GC before operation: completed in 387.466 ms, heap usage 202.290 MB -> 69.396 MB. [2025-08-28T21:46:06.831Z] ====== als (apache-spark) [default], iteration 27 completed (15333.723 ms) ====== [2025-08-28T21:46:06.831Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-08-28T21:46:06.831Z] GC before operation: completed in 340.362 ms, heap usage 238.346 MB -> 69.763 MB. [2025-08-28T21:46:25.566Z] ====== als (apache-spark) [default], iteration 28 completed (16159.904 ms) ====== [2025-08-28T21:46:25.566Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-08-28T21:46:25.566Z] GC before operation: completed in 376.618 ms, heap usage 230.682 MB -> 69.543 MB. [2025-08-28T21:46:41.665Z] ====== als (apache-spark) [default], iteration 29 completed (17332.256 ms) ====== [2025-08-28T21:46:42.552Z] ----------------------------------- [2025-08-28T21:46:42.552Z] renaissance-als_0_PASSED [2025-08-28T21:46:42.552Z] ----------------------------------- [2025-08-28T21:46:42.552Z] [2025-08-28T21:46:42.552Z] TEST TEARDOWN: [2025-08-28T21:46:42.552Z] Nothing to be done for teardown. [2025-08-28T21:46:42.552Z] renaissance-als_0 Finish Time: Thu Aug 28 21:46:42 2025 Epoch Time (ms): 1756417602221