[2025-04-16T04:08:21.191Z] Running test renaissance-als_0 ... [2025-04-16T04:08:21.191Z] =============================================== [2025-04-16T04:08:21.191Z] renaissance-als_0 Start Time: Wed Apr 16 04:08:21 2025 Epoch Time (ms): 1744776501090 [2025-04-16T04:08:21.191Z] variation: NoOptions [2025-04-16T04:08:21.191Z] JVM_OPTIONS: [2025-04-16T04:08:21.191Z] { \ [2025-04-16T04:08:21.191Z] echo ""; echo "TEST SETUP:"; \ [2025-04-16T04:08:21.191Z] echo "Nothing to be done for setup."; \ [2025-04-16T04:08:21.191Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17447764578791/renaissance-als_0"; \ [2025-04-16T04:08:21.191Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17447764578791/renaissance-als_0"; \ [2025-04-16T04:08:21.191Z] echo ""; echo "TESTING:"; \ [2025-04-16T04:08:21.191Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/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_ppc64le_linux/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17447764578791/renaissance-als_0"/als.json" als; \ [2025-04-16T04:08:21.191Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17447764578791/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-04-16T04:08:21.191Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-04-16T04:08:21.191Z] echo "Nothing to be done for teardown."; \ [2025-04-16T04:08:21.191Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17447764578791/TestTargetResult"; [2025-04-16T04:08:21.191Z] [2025-04-16T04:08:21.191Z] TEST SETUP: [2025-04-16T04:08:21.191Z] Nothing to be done for setup. [2025-04-16T04:08:22.141Z] [2025-04-16T04:08:22.141Z] TESTING: [2025-04-16T04:08:27.503Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-04-16T04:08:31.647Z] WARNING: An illegal reflective access operation has occurred [2025-04-16T04:08:31.647Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/output_17447764578791/renaissance-als_0/harness-040821-9232334578485388966/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-04-16T04:08:31.647Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-04-16T04:08:31.647Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-04-16T04:08:31.647Z] WARNING: All illegal access operations will be denied in a future release [2025-04-16T04:08:32.595Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-04-16T04:08:32.595Z] GC before operation: completed in 57.012 ms, heap usage 300.000 MB -> 34.454 MB. [2025-04-16T04:08:50.865Z] ====== als (apache-spark) [default], iteration 0 completed (17362.915 ms) ====== [2025-04-16T04:08:50.865Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-04-16T04:08:50.865Z] GC before operation: completed in 122.474 ms, heap usage 523.608 MB -> 60.756 MB. [2025-04-16T04:09:00.605Z] ====== als (apache-spark) [default], iteration 1 completed (8434.437 ms) ====== [2025-04-16T04:09:00.605Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-04-16T04:09:00.605Z] GC before operation: completed in 102.029 ms, heap usage 417.826 MB -> 61.906 MB. [2025-04-16T04:09:08.381Z] ====== als (apache-spark) [default], iteration 2 completed (7937.623 ms) ====== [2025-04-16T04:09:08.381Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-04-16T04:09:08.381Z] GC before operation: completed in 95.356 ms, heap usage 226.096 MB -> 61.895 MB. [2025-04-16T04:09:16.797Z] ====== als (apache-spark) [default], iteration 3 completed (7895.637 ms) ====== [2025-04-16T04:09:16.797Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-04-16T04:09:16.797Z] GC before operation: completed in 115.262 ms, heap usage 423.088 MB -> 62.576 MB. [2025-04-16T04:09:24.938Z] ====== als (apache-spark) [default], iteration 4 completed (7931.390 ms) ====== [2025-04-16T04:09:24.938Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-04-16T04:09:24.938Z] GC before operation: completed in 107.628 ms, heap usage 420.793 MB -> 63.195 MB. [2025-04-16T04:09:33.124Z] ====== als (apache-spark) [default], iteration 5 completed (8131.446 ms) ====== [2025-04-16T04:09:33.124Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-04-16T04:09:33.124Z] GC before operation: completed in 112.869 ms, heap usage 270.491 MB -> 63.601 MB. [2025-04-16T04:09:41.428Z] ====== als (apache-spark) [default], iteration 6 completed (7822.383 ms) ====== [2025-04-16T04:09:41.428Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-04-16T04:09:41.428Z] GC before operation: completed in 118.622 ms, heap usage 240.052 MB -> 64.127 MB. [2025-04-16T04:09:49.551Z] ====== als (apache-spark) [default], iteration 7 completed (7915.942 ms) ====== [2025-04-16T04:09:49.551Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-04-16T04:09:49.551Z] GC before operation: completed in 118.035 ms, heap usage 237.904 MB -> 64.425 MB. [2025-04-16T04:09:57.701Z] ====== als (apache-spark) [default], iteration 8 completed (7862.487 ms) ====== [2025-04-16T04:09:57.701Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-04-16T04:09:57.701Z] GC before operation: completed in 113.624 ms, heap usage 234.412 MB -> 65.102 MB. [2025-04-16T04:10:05.866Z] ====== als (apache-spark) [default], iteration 9 completed (7719.666 ms) ====== [2025-04-16T04:10:05.866Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-04-16T04:10:05.866Z] GC before operation: completed in 130.942 ms, heap usage 269.115 MB -> 65.370 MB. [2025-04-16T04:10:14.004Z] ====== als (apache-spark) [default], iteration 10 completed (7821.157 ms) ====== [2025-04-16T04:10:14.004Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-04-16T04:10:14.004Z] GC before operation: completed in 121.370 ms, heap usage 287.359 MB -> 65.599 MB. [2025-04-16T04:10:24.792Z] ====== als (apache-spark) [default], iteration 11 completed (8127.306 ms) ====== [2025-04-16T04:10:24.792Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-04-16T04:10:24.792Z] GC before operation: completed in 126.096 ms, heap usage 180.279 MB -> 65.755 MB. [2025-04-16T04:10:31.463Z] ====== als (apache-spark) [default], iteration 12 completed (7901.980 ms) ====== [2025-04-16T04:10:31.463Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-04-16T04:10:31.463Z] GC before operation: completed in 127.514 ms, heap usage 107.429 MB -> 66.055 MB. [2025-04-16T04:10:39.575Z] ====== als (apache-spark) [default], iteration 13 completed (7811.310 ms) ====== [2025-04-16T04:10:39.575Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-04-16T04:10:39.575Z] GC before operation: completed in 124.012 ms, heap usage 180.308 MB -> 66.233 MB. [2025-04-16T04:10:47.713Z] ====== als (apache-spark) [default], iteration 14 completed (7792.722 ms) ====== [2025-04-16T04:10:47.713Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-04-16T04:10:47.713Z] GC before operation: completed in 113.379 ms, heap usage 424.105 MB -> 66.708 MB. [2025-04-16T04:10:55.873Z] ====== als (apache-spark) [default], iteration 15 completed (7912.271 ms) ====== [2025-04-16T04:10:55.873Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-04-16T04:10:55.873Z] GC before operation: completed in 127.218 ms, heap usage 241.559 MB -> 66.956 MB. [2025-04-16T04:11:04.006Z] ====== als (apache-spark) [default], iteration 16 completed (7923.873 ms) ====== [2025-04-16T04:11:04.006Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-04-16T04:11:04.006Z] GC before operation: completed in 114.986 ms, heap usage 280.171 MB -> 67.188 MB. [2025-04-16T04:11:12.136Z] ====== als (apache-spark) [default], iteration 17 completed (8286.600 ms) ====== [2025-04-16T04:11:12.136Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-04-16T04:11:13.083Z] GC before operation: completed in 135.725 ms, heap usage 89.876 MB -> 67.222 MB. [2025-04-16T04:11:21.209Z] ====== als (apache-spark) [default], iteration 18 completed (7752.984 ms) ====== [2025-04-16T04:11:21.209Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-04-16T04:11:21.209Z] GC before operation: completed in 119.170 ms, heap usage 236.304 MB -> 67.620 MB. [2025-04-16T04:11:29.346Z] ====== als (apache-spark) [default], iteration 19 completed (8110.480 ms) ====== [2025-04-16T04:11:29.346Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-04-16T04:11:29.346Z] GC before operation: completed in 135.418 ms, heap usage 101.973 MB -> 67.715 MB. [2025-04-16T04:11:38.674Z] ====== als (apache-spark) [default], iteration 20 completed (8288.597 ms) ====== [2025-04-16T04:11:38.675Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-04-16T04:11:38.675Z] GC before operation: completed in 132.385 ms, heap usage 275.867 MB -> 68.076 MB. [2025-04-16T04:11:45.524Z] ====== als (apache-spark) [default], iteration 21 completed (7342.039 ms) ====== [2025-04-16T04:11:45.524Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-04-16T04:11:45.524Z] GC before operation: completed in 119.359 ms, heap usage 249.368 MB -> 68.322 MB. [2025-04-16T04:11:53.669Z] ====== als (apache-spark) [default], iteration 22 completed (7487.393 ms) ====== [2025-04-16T04:11:53.669Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-04-16T04:11:53.669Z] GC before operation: completed in 133.689 ms, heap usage 272.119 MB -> 68.718 MB. [2025-04-16T04:12:01.796Z] ====== als (apache-spark) [default], iteration 23 completed (7998.849 ms) ====== [2025-04-16T04:12:01.797Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-04-16T04:12:01.797Z] GC before operation: completed in 134.183 ms, heap usage 284.679 MB -> 68.933 MB. [2025-04-16T04:12:09.914Z] ====== als (apache-spark) [default], iteration 24 completed (7659.916 ms) ====== [2025-04-16T04:12:09.914Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-04-16T04:12:09.914Z] GC before operation: completed in 136.858 ms, heap usage 551.259 MB -> 69.522 MB. [2025-04-16T04:12:18.061Z] ====== als (apache-spark) [default], iteration 25 completed (7647.079 ms) ====== [2025-04-16T04:12:18.061Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-04-16T04:12:18.061Z] GC before operation: completed in 131.642 ms, heap usage 264.402 MB -> 69.347 MB. [2025-04-16T04:12:26.194Z] ====== als (apache-spark) [default], iteration 26 completed (7697.480 ms) ====== [2025-04-16T04:12:26.194Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-04-16T04:12:26.194Z] GC before operation: completed in 148.570 ms, heap usage 241.796 MB -> 69.644 MB. [2025-04-16T04:12:34.306Z] ====== als (apache-spark) [default], iteration 27 completed (7828.940 ms) ====== [2025-04-16T04:12:34.306Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-04-16T04:12:34.306Z] GC before operation: completed in 135.539 ms, heap usage 306.798 MB -> 69.971 MB. [2025-04-16T04:12:42.697Z] ====== als (apache-spark) [default], iteration 28 completed (8178.361 ms) ====== [2025-04-16T04:12:42.697Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-04-16T04:12:42.697Z] GC before operation: completed in 136.816 ms, heap usage 347.698 MB -> 70.248 MB. [2025-04-16T04:12:51.404Z] ====== als (apache-spark) [default], iteration 29 completed (7607.184 ms) ====== [2025-04-16T04:12:51.404Z] ----------------------------------- [2025-04-16T04:12:51.404Z] renaissance-als_0_PASSED [2025-04-16T04:12:51.404Z] ----------------------------------- [2025-04-16T04:12:51.404Z] [2025-04-16T04:12:51.404Z] TEST TEARDOWN: [2025-04-16T04:12:51.404Z] Nothing to be done for teardown. [2025-04-16T04:12:51.404Z] renaissance-als_0 Finish Time: Wed Apr 16 04:12:50 2025 Epoch Time (ms): 1744776770807