[2025-10-01T22:15:24.930Z] Running test renaissance-als_0 ... [2025-10-01T22:15:24.930Z] =============================================== [2025-10-01T22:15:24.930Z] renaissance-als_0 Start Time: Wed Oct 1 22:15:24 2025 Epoch Time (ms): 1759356924338 [2025-10-01T22:15:24.930Z] variation: NoOptions [2025-10-01T22:15:24.930Z] JVM_OPTIONS: [2025-10-01T22:15:24.930Z] { \ [2025-10-01T22:15:24.930Z] echo ""; echo "TEST SETUP:"; \ [2025-10-01T22:15:24.930Z] echo "Nothing to be done for setup."; \ [2025-10-01T22:15:24.930Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17593567378701/renaissance-als_0"; \ [2025-10-01T22:15:24.930Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17593567378701/renaissance-als_0"; \ [2025-10-01T22:15:24.930Z] echo ""; echo "TESTING:"; \ [2025-10-01T22:15:24.930Z] "/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_17593567378701/renaissance-als_0"/als.json" als; \ [2025-10-01T22:15:24.930Z] 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_17593567378701/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-10-01T22:15:24.930Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-10-01T22:15:24.930Z] echo "Nothing to be done for teardown."; \ [2025-10-01T22:15:24.930Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17593567378701/TestTargetResult"; [2025-10-01T22:15:24.930Z] [2025-10-01T22:15:24.930Z] TEST SETUP: [2025-10-01T22:15:24.930Z] Nothing to be done for setup. [2025-10-01T22:15:24.930Z] [2025-10-01T22:15:24.930Z] TESTING: [2025-10-01T22:15:31.603Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-10-01T22:15:35.742Z] WARNING: An illegal reflective access operation has occurred [2025-10-01T22:15:35.742Z] 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_17593567378701/renaissance-als_0/harness-221525-2139219855542839178/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-10-01T22:15:35.742Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-10-01T22:15:35.742Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-10-01T22:15:35.742Z] WARNING: All illegal access operations will be denied in a future release [2025-10-01T22:15:36.689Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-10-01T22:15:36.689Z] GC before operation: completed in 60.747 ms, heap usage 207.002 MB -> 34.438 MB. [2025-10-01T22:15:57.888Z] ====== als (apache-spark) [default], iteration 0 completed (19962.153 ms) ====== [2025-10-01T22:15:57.888Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-10-01T22:15:57.888Z] GC before operation: completed in 124.968 ms, heap usage 392.803 MB -> 60.467 MB. [2025-10-01T22:16:06.556Z] ====== als (apache-spark) [default], iteration 1 completed (8754.319 ms) ====== [2025-10-01T22:16:06.556Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-10-01T22:16:06.556Z] GC before operation: completed in 125.287 ms, heap usage 284.925 MB -> 61.340 MB. [2025-10-01T22:16:16.319Z] ====== als (apache-spark) [default], iteration 2 completed (8605.918 ms) ====== [2025-10-01T22:16:16.319Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-10-01T22:16:16.319Z] GC before operation: completed in 98.324 ms, heap usage 275.713 MB -> 61.806 MB. [2025-10-01T22:16:24.431Z] ====== als (apache-spark) [default], iteration 3 completed (7903.059 ms) ====== [2025-10-01T22:16:24.431Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-10-01T22:16:24.431Z] GC before operation: completed in 101.577 ms, heap usage 335.279 MB -> 62.453 MB. [2025-10-01T22:16:32.544Z] ====== als (apache-spark) [default], iteration 4 completed (8135.110 ms) ====== [2025-10-01T22:16:32.544Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-10-01T22:16:32.544Z] GC before operation: completed in 101.507 ms, heap usage 243.699 MB -> 62.867 MB. [2025-10-01T22:16:40.655Z] ====== als (apache-spark) [default], iteration 5 completed (8050.732 ms) ====== [2025-10-01T22:16:40.655Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-10-01T22:16:40.655Z] GC before operation: completed in 97.809 ms, heap usage 151.558 MB -> 63.265 MB. [2025-10-01T22:16:48.768Z] ====== als (apache-spark) [default], iteration 6 completed (7951.560 ms) ====== [2025-10-01T22:16:48.768Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-10-01T22:16:48.768Z] GC before operation: completed in 99.725 ms, heap usage 235.438 MB -> 63.910 MB. [2025-10-01T22:16:56.898Z] ====== als (apache-spark) [default], iteration 7 completed (7835.411 ms) ====== [2025-10-01T22:16:56.898Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-10-01T22:16:56.898Z] GC before operation: completed in 125.263 ms, heap usage 271.267 MB -> 64.513 MB. [2025-10-01T22:17:06.608Z] ====== als (apache-spark) [default], iteration 8 completed (8137.432 ms) ====== [2025-10-01T22:17:06.608Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-10-01T22:17:06.608Z] GC before operation: completed in 116.021 ms, heap usage 338.853 MB -> 65.112 MB. [2025-10-01T22:17:14.224Z] ====== als (apache-spark) [default], iteration 9 completed (7851.995 ms) ====== [2025-10-01T22:17:14.224Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-10-01T22:17:14.224Z] GC before operation: completed in 108.032 ms, heap usage 149.071 MB -> 65.131 MB. [2025-10-01T22:17:22.520Z] ====== als (apache-spark) [default], iteration 10 completed (8048.298 ms) ====== [2025-10-01T22:17:22.520Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-10-01T22:17:22.520Z] GC before operation: completed in 101.188 ms, heap usage 277.138 MB -> 65.504 MB. [2025-10-01T22:17:30.624Z] ====== als (apache-spark) [default], iteration 11 completed (7956.926 ms) ====== [2025-10-01T22:17:30.624Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-10-01T22:17:30.624Z] GC before operation: completed in 111.681 ms, heap usage 139.925 MB -> 65.655 MB. [2025-10-01T22:17:38.744Z] ====== als (apache-spark) [default], iteration 12 completed (7644.729 ms) ====== [2025-10-01T22:17:38.744Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-10-01T22:17:38.744Z] GC before operation: completed in 108.089 ms, heap usage 255.566 MB -> 65.896 MB. [2025-10-01T22:17:46.838Z] ====== als (apache-spark) [default], iteration 13 completed (8098.288 ms) ====== [2025-10-01T22:17:46.838Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-10-01T22:17:46.838Z] GC before operation: completed in 107.262 ms, heap usage 213.808 MB -> 66.235 MB. [2025-10-01T22:17:54.943Z] ====== als (apache-spark) [default], iteration 14 completed (7591.674 ms) ====== [2025-10-01T22:17:54.943Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-10-01T22:17:54.943Z] GC before operation: completed in 106.577 ms, heap usage 406.299 MB -> 66.591 MB. [2025-10-01T22:18:03.102Z] ====== als (apache-spark) [default], iteration 15 completed (7638.226 ms) ====== [2025-10-01T22:18:03.102Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-10-01T22:18:03.102Z] GC before operation: completed in 114.618 ms, heap usage 213.031 MB -> 66.629 MB. [2025-10-01T22:18:11.207Z] ====== als (apache-spark) [default], iteration 16 completed (7889.642 ms) ====== [2025-10-01T22:18:11.207Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-10-01T22:18:11.207Z] GC before operation: completed in 107.536 ms, heap usage 161.022 MB -> 66.880 MB. [2025-10-01T22:18:19.351Z] ====== als (apache-spark) [default], iteration 17 completed (7580.203 ms) ====== [2025-10-01T22:18:19.351Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-10-01T22:18:19.351Z] GC before operation: completed in 107.659 ms, heap usage 444.845 MB -> 67.599 MB. [2025-10-01T22:18:27.459Z] ====== als (apache-spark) [default], iteration 18 completed (7581.347 ms) ====== [2025-10-01T22:18:27.459Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-10-01T22:18:27.459Z] GC before operation: completed in 124.004 ms, heap usage 329.041 MB -> 67.721 MB. [2025-10-01T22:18:35.560Z] ====== als (apache-spark) [default], iteration 19 completed (8091.550 ms) ====== [2025-10-01T22:18:35.560Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-10-01T22:18:35.560Z] GC before operation: completed in 115.242 ms, heap usage 338.549 MB -> 67.868 MB. [2025-10-01T22:18:43.754Z] ====== als (apache-spark) [default], iteration 20 completed (7977.320 ms) ====== [2025-10-01T22:18:43.754Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-10-01T22:18:43.754Z] GC before operation: completed in 117.453 ms, heap usage 282.135 MB -> 68.004 MB. [2025-10-01T22:18:52.529Z] ====== als (apache-spark) [default], iteration 21 completed (7524.739 ms) ====== [2025-10-01T22:18:52.529Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-10-01T22:18:52.529Z] GC before operation: completed in 114.270 ms, heap usage 581.338 MB -> 68.685 MB. [2025-10-01T22:18:59.217Z] ====== als (apache-spark) [default], iteration 22 completed (7508.355 ms) ====== [2025-10-01T22:18:59.217Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-10-01T22:18:59.217Z] GC before operation: completed in 121.413 ms, heap usage 542.808 MB -> 68.960 MB. [2025-10-01T22:19:07.346Z] ====== als (apache-spark) [default], iteration 23 completed (7571.096 ms) ====== [2025-10-01T22:19:07.346Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-10-01T22:19:07.346Z] GC before operation: completed in 115.411 ms, heap usage 252.750 MB -> 68.772 MB. [2025-10-01T22:19:17.065Z] ====== als (apache-spark) [default], iteration 24 completed (8263.159 ms) ====== [2025-10-01T22:19:17.065Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-10-01T22:19:17.065Z] GC before operation: completed in 130.051 ms, heap usage 268.345 MB -> 69.030 MB. [2025-10-01T22:19:25.170Z] ====== als (apache-spark) [default], iteration 25 completed (8200.997 ms) ====== [2025-10-01T22:19:25.170Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-10-01T22:19:25.170Z] GC before operation: completed in 117.419 ms, heap usage 182.027 MB -> 69.158 MB. [2025-10-01T22:19:33.278Z] ====== als (apache-spark) [default], iteration 26 completed (7637.695 ms) ====== [2025-10-01T22:19:33.278Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-10-01T22:19:33.278Z] GC before operation: completed in 117.431 ms, heap usage 493.011 MB -> 69.856 MB. [2025-10-01T22:19:41.398Z] ====== als (apache-spark) [default], iteration 27 completed (7749.109 ms) ====== [2025-10-01T22:19:41.398Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-10-01T22:19:41.398Z] GC before operation: completed in 118.241 ms, heap usage 295.138 MB -> 69.765 MB. [2025-10-01T22:19:49.517Z] ====== als (apache-spark) [default], iteration 28 completed (8262.266 ms) ====== [2025-10-01T22:19:49.517Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-10-01T22:19:49.517Z] GC before operation: completed in 119.915 ms, heap usage 272.453 MB -> 69.736 MB. [2025-10-01T22:19:57.686Z] ====== als (apache-spark) [default], iteration 29 completed (7996.662 ms) ====== [2025-10-01T22:19:57.686Z] ----------------------------------- [2025-10-01T22:19:57.687Z] renaissance-als_0_PASSED [2025-10-01T22:19:57.687Z] ----------------------------------- [2025-10-01T22:19:57.687Z] [2025-10-01T22:19:57.687Z] TEST TEARDOWN: [2025-10-01T22:19:57.687Z] Nothing to be done for teardown. [2025-10-01T22:19:57.687Z] renaissance-als_0 Finish Time: Wed Oct 1 22:19:57 2025 Epoch Time (ms): 1759357197512