[2025-10-16T21:08:59.906Z] Running test renaissance-als_0 ... [2025-10-16T21:08:59.906Z] =============================================== [2025-10-16T21:08:59.906Z] renaissance-als_0 Start Time: Thu Oct 16 21:08:59 2025 Epoch Time (ms): 1760648939241 [2025-10-16T21:08:59.906Z] variation: NoOptions [2025-10-16T21:08:59.906Z] JVM_OPTIONS: [2025-10-16T21:08:59.906Z] { \ [2025-10-16T21:08:59.906Z] echo ""; echo "TEST SETUP:"; \ [2025-10-16T21:08:59.906Z] echo "Nothing to be done for setup."; \ [2025-10-16T21:08:59.906Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17606488279144/renaissance-als_0"; \ [2025-10-16T21:08:59.906Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17606488279144/renaissance-als_0"; \ [2025-10-16T21:08:59.906Z] echo ""; echo "TESTING:"; \ [2025-10-16T21:08:59.906Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/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_ppc64_aix/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17606488279144/renaissance-als_0"/als.json" als; \ [2025-10-16T21:08:59.906Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17606488279144/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-10-16T21:08:59.906Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-10-16T21:08:59.906Z] echo "Nothing to be done for teardown."; \ [2025-10-16T21:08:59.906Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17606488279144/TestTargetResult"; [2025-10-16T21:08:59.906Z] [2025-10-16T21:08:59.906Z] TEST SETUP: [2025-10-16T21:08:59.906Z] Nothing to be done for setup. [2025-10-16T21:08:59.906Z] [2025-10-16T21:08:59.906Z] TESTING: [2025-10-16T21:09:08.145Z] NOTE: 'als' benchmark uses Spark local executor with 12 (out of 24) threads. [2025-10-16T21:09:12.583Z] WARNING: An illegal reflective access operation has occurred [2025-10-16T21:09:12.583Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/output_17606488279144/renaissance-als_0/harness-210900-16462044209088392843/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-10-16T21:09:12.583Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-10-16T21:09:12.583Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-10-16T21:09:12.583Z] WARNING: All illegal access operations will be denied in a future release [2025-10-16T21:09:14.168Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-10-16T21:09:14.168Z] GC before operation: completed in 82.577 ms, heap usage 251.455 MB -> 35.397 MB. [2025-10-16T21:09:30.231Z] ====== als (apache-spark) [default], iteration 0 completed (14453.051 ms) ====== [2025-10-16T21:09:30.231Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-10-16T21:09:30.231Z] GC before operation: completed in 121.978 ms, heap usage 366.782 MB -> 61.667 MB. [2025-10-16T21:09:35.825Z] ====== als (apache-spark) [default], iteration 1 completed (5765.776 ms) ====== [2025-10-16T21:09:35.825Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-10-16T21:09:35.825Z] GC before operation: completed in 121.504 ms, heap usage 685.323 MB -> 62.815 MB. [2025-10-16T21:09:41.404Z] ====== als (apache-spark) [default], iteration 2 completed (5661.929 ms) ====== [2025-10-16T21:09:41.404Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-10-16T21:09:41.404Z] GC before operation: completed in 132.138 ms, heap usage 297.828 MB -> 62.786 MB. [2025-10-16T21:09:48.240Z] ====== als (apache-spark) [default], iteration 3 completed (5473.518 ms) ====== [2025-10-16T21:09:48.240Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-10-16T21:09:48.240Z] GC before operation: completed in 133.370 ms, heap usage 1.157 GB -> 64.301 MB. [2025-10-16T21:09:53.811Z] ====== als (apache-spark) [default], iteration 4 completed (5374.387 ms) ====== [2025-10-16T21:09:53.811Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-10-16T21:09:53.811Z] GC before operation: completed in 133.793 ms, heap usage 826.424 MB -> 64.646 MB. [2025-10-16T21:09:59.383Z] ====== als (apache-spark) [default], iteration 5 completed (5418.381 ms) ====== [2025-10-16T21:09:59.383Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-10-16T21:09:59.383Z] GC before operation: completed in 132.360 ms, heap usage 578.312 MB -> 64.795 MB. [2025-10-16T21:10:04.960Z] ====== als (apache-spark) [default], iteration 6 completed (5485.623 ms) ====== [2025-10-16T21:10:04.960Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-10-16T21:10:04.960Z] GC before operation: completed in 185.726 ms, heap usage 1.337 GB -> 66.165 MB. [2025-10-16T21:10:10.539Z] ====== als (apache-spark) [default], iteration 7 completed (5477.057 ms) ====== [2025-10-16T21:10:10.539Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-10-16T21:10:10.539Z] GC before operation: completed in 148.512 ms, heap usage 1.153 GB -> 66.581 MB. [2025-10-16T21:10:17.367Z] ====== als (apache-spark) [default], iteration 8 completed (5544.229 ms) ====== [2025-10-16T21:10:17.367Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-10-16T21:10:17.367Z] GC before operation: completed in 148.497 ms, heap usage 487.815 MB -> 66.395 MB. [2025-10-16T21:10:22.943Z] ====== als (apache-spark) [default], iteration 9 completed (5469.050 ms) ====== [2025-10-16T21:10:22.943Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-10-16T21:10:22.943Z] GC before operation: completed in 119.806 ms, heap usage 351.089 MB -> 66.431 MB. [2025-10-16T21:10:28.514Z] ====== als (apache-spark) [default], iteration 10 completed (5315.560 ms) ====== [2025-10-16T21:10:28.514Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-10-16T21:10:28.514Z] GC before operation: completed in 122.152 ms, heap usage 562.061 MB -> 66.917 MB. [2025-10-16T21:10:34.089Z] ====== als (apache-spark) [default], iteration 11 completed (5431.499 ms) ====== [2025-10-16T21:10:34.089Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-10-16T21:10:34.089Z] GC before operation: completed in 157.658 ms, heap usage 496.287 MB -> 67.292 MB. [2025-10-16T21:10:39.671Z] ====== als (apache-spark) [default], iteration 12 completed (5475.314 ms) ====== [2025-10-16T21:10:39.671Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-10-16T21:10:39.671Z] GC before operation: completed in 148.483 ms, heap usage 1.272 GB -> 68.089 MB. [2025-10-16T21:10:45.307Z] ====== als (apache-spark) [default], iteration 13 completed (5461.783 ms) ====== [2025-10-16T21:10:45.307Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-10-16T21:10:46.073Z] GC before operation: completed in 141.046 ms, heap usage 749.583 MB -> 67.868 MB. [2025-10-16T21:10:51.647Z] ====== als (apache-spark) [default], iteration 14 completed (5284.199 ms) ====== [2025-10-16T21:10:51.648Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-10-16T21:10:51.648Z] GC before operation: completed in 153.089 ms, heap usage 744.884 MB -> 68.161 MB. [2025-10-16T21:11:01.798Z] ====== als (apache-spark) [default], iteration 15 completed (5325.259 ms) ====== [2025-10-16T21:11:01.798Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-10-16T21:11:01.798Z] GC before operation: completed in 160.895 ms, heap usage 1.451 GB -> 69.021 MB. [2025-10-16T21:11:14.637Z] ====== als (apache-spark) [default], iteration 16 completed (5260.547 ms) ====== [2025-10-16T21:11:14.637Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-10-16T21:11:14.637Z] GC before operation: completed in 150.886 ms, heap usage 470.564 MB -> 68.224 MB. [2025-10-16T21:11:14.637Z] ====== als (apache-spark) [default], iteration 17 completed (5064.691 ms) ====== [2025-10-16T21:11:14.637Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-10-16T21:11:14.637Z] GC before operation: completed in 143.759 ms, heap usage 734.948 MB -> 68.789 MB. [2025-10-16T21:11:15.426Z] ====== als (apache-spark) [default], iteration 18 completed (5210.094 ms) ====== [2025-10-16T21:11:15.426Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-10-16T21:11:15.426Z] GC before operation: completed in 159.906 ms, heap usage 701.215 MB -> 69.187 MB. [2025-10-16T21:11:19.343Z] ====== als (apache-spark) [default], iteration 19 completed (5288.390 ms) ====== [2025-10-16T21:11:19.343Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-10-16T21:11:19.343Z] GC before operation: completed in 160.690 ms, heap usage 1.065 GB -> 69.809 MB. [2025-10-16T21:11:24.915Z] ====== als (apache-spark) [default], iteration 20 completed (5348.295 ms) ====== [2025-10-16T21:11:24.915Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-10-16T21:11:24.915Z] GC before operation: completed in 157.236 ms, heap usage 1.486 GB -> 70.445 MB. [2025-10-16T21:11:30.488Z] ====== als (apache-spark) [default], iteration 21 completed (5282.346 ms) ====== [2025-10-16T21:11:30.488Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-10-16T21:11:30.488Z] GC before operation: completed in 163.768 ms, heap usage 912.270 MB -> 70.010 MB. [2025-10-16T21:11:36.092Z] ====== als (apache-spark) [default], iteration 22 completed (5085.958 ms) ====== [2025-10-16T21:11:36.092Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-10-16T21:11:36.092Z] GC before operation: completed in 167.081 ms, heap usage 1.323 GB -> 70.704 MB. [2025-10-16T21:11:41.671Z] ====== als (apache-spark) [default], iteration 23 completed (5124.619 ms) ====== [2025-10-16T21:11:41.671Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-10-16T21:11:41.671Z] GC before operation: completed in 159.984 ms, heap usage 700.664 MB -> 70.350 MB. [2025-10-16T21:11:47.253Z] ====== als (apache-spark) [default], iteration 24 completed (5042.420 ms) ====== [2025-10-16T21:11:47.253Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-10-16T21:11:47.253Z] GC before operation: completed in 149.740 ms, heap usage 138.797 MB -> 70.288 MB. [2025-10-16T21:11:52.837Z] ====== als (apache-spark) [default], iteration 25 completed (5248.968 ms) ====== [2025-10-16T21:11:52.837Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-10-16T21:11:52.837Z] GC before operation: completed in 160.109 ms, heap usage 1.145 GB -> 71.293 MB. [2025-10-16T21:11:58.420Z] ====== als (apache-spark) [default], iteration 26 completed (5052.643 ms) ====== [2025-10-16T21:11:58.420Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-10-16T21:11:58.420Z] GC before operation: completed in 148.788 ms, heap usage 446.351 MB -> 70.743 MB. [2025-10-16T21:12:04.001Z] ====== als (apache-spark) [default], iteration 27 completed (4991.149 ms) ====== [2025-10-16T21:12:04.001Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-10-16T21:12:04.001Z] GC before operation: completed in 168.005 ms, heap usage 596.046 MB -> 71.299 MB. [2025-10-16T21:12:08.612Z] ====== als (apache-spark) [default], iteration 28 completed (5149.448 ms) ====== [2025-10-16T21:12:08.612Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-10-16T21:12:09.375Z] GC before operation: completed in 205.614 ms, heap usage 985.498 MB -> 71.459 MB. [2025-10-16T21:12:14.947Z] ====== als (apache-spark) [default], iteration 29 completed (5156.974 ms) ====== [2025-10-16T21:12:14.947Z] ----------------------------------- [2025-10-16T21:12:14.947Z] renaissance-als_0_PASSED [2025-10-16T21:12:14.947Z] ----------------------------------- [2025-10-16T21:12:14.947Z] [2025-10-16T21:12:14.947Z] TEST TEARDOWN: [2025-10-16T21:12:14.947Z] Nothing to be done for teardown. [2025-10-16T21:12:14.947Z] renaissance-als_0 Finish Time: Thu Oct 16 21:12:14 2025 Epoch Time (ms): 1760649134629