[2025-08-13T23:21:49.085Z] Running test renaissance-als_0 ... [2025-08-13T23:21:49.085Z] =============================================== [2025-08-13T23:21:49.085Z] renaissance-als_0 Start Time: Wed Aug 13 23:21:48 2025 Epoch Time (ms): 1755127308456 [2025-08-13T23:21:49.085Z] variation: NoOptions [2025-08-13T23:21:49.085Z] JVM_OPTIONS: [2025-08-13T23:21:49.085Z] { \ [2025-08-13T23:21:49.085Z] echo ""; echo "TEST SETUP:"; \ [2025-08-13T23:21:49.085Z] echo "Nothing to be done for setup."; \ [2025-08-13T23:21:49.085Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17551271249815/renaissance-als_0"; \ [2025-08-13T23:21:49.085Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17551271249815/renaissance-als_0"; \ [2025-08-13T23:21:49.085Z] echo ""; echo "TESTING:"; \ [2025-08-13T23:21:49.085Z] "/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_17551271249815/renaissance-als_0"/als.json" als; \ [2025-08-13T23:21:49.085Z] 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_17551271249815/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-08-13T23:21:49.085Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-08-13T23:21:49.085Z] echo "Nothing to be done for teardown."; \ [2025-08-13T23:21:49.085Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17551271249815/TestTargetResult"; [2025-08-13T23:21:49.085Z] [2025-08-13T23:21:49.085Z] TEST SETUP: [2025-08-13T23:21:49.085Z] Nothing to be done for setup. [2025-08-13T23:21:49.085Z] [2025-08-13T23:21:49.085Z] TESTING: [2025-08-13T23:21:55.810Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-08-13T23:21:58.812Z] WARNING: An illegal reflective access operation has occurred [2025-08-13T23:21:58.812Z] 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_17551271249815/renaissance-als_0/harness-232149-17612930118771028953/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-08-13T23:21:58.812Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-08-13T23:21:58.812Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-08-13T23:21:58.812Z] WARNING: All illegal access operations will be denied in a future release [2025-08-13T23:21:59.760Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-08-13T23:21:59.760Z] GC before operation: completed in 57.546 ms, heap usage 336.511 MB -> 34.493 MB. [2025-08-13T23:22:20.933Z] ====== als (apache-spark) [default], iteration 0 completed (19515.587 ms) ====== [2025-08-13T23:22:20.933Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-08-13T23:22:20.933Z] GC before operation: completed in 118.655 ms, heap usage 121.227 MB -> 60.359 MB. [2025-08-13T23:22:29.056Z] ====== als (apache-spark) [default], iteration 1 completed (9010.959 ms) ====== [2025-08-13T23:22:29.056Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-08-13T23:22:29.056Z] GC before operation: completed in 106.369 ms, heap usage 376.031 MB -> 61.405 MB. [2025-08-13T23:22:37.960Z] ====== als (apache-spark) [default], iteration 2 completed (8326.063 ms) ====== [2025-08-13T23:22:37.960Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-08-13T23:22:37.961Z] GC before operation: completed in 111.650 ms, heap usage 219.290 MB -> 61.964 MB. [2025-08-13T23:22:47.654Z] ====== als (apache-spark) [default], iteration 3 completed (8060.004 ms) ====== [2025-08-13T23:22:47.654Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-08-13T23:22:47.654Z] GC before operation: completed in 97.145 ms, heap usage 305.306 MB -> 62.506 MB. [2025-08-13T23:22:55.779Z] ====== als (apache-spark) [default], iteration 4 completed (7956.027 ms) ====== [2025-08-13T23:22:55.779Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-08-13T23:22:55.779Z] GC before operation: completed in 113.272 ms, heap usage 338.796 MB -> 63.146 MB. [2025-08-13T23:23:03.902Z] ====== als (apache-spark) [default], iteration 5 completed (7877.185 ms) ====== [2025-08-13T23:23:03.902Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-08-13T23:23:03.902Z] GC before operation: completed in 110.626 ms, heap usage 483.619 MB -> 63.802 MB. [2025-08-13T23:23:12.012Z] ====== als (apache-spark) [default], iteration 6 completed (7867.822 ms) ====== [2025-08-13T23:23:12.012Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-08-13T23:23:12.012Z] GC before operation: completed in 126.244 ms, heap usage 244.778 MB -> 63.978 MB. [2025-08-13T23:23:20.161Z] ====== als (apache-spark) [default], iteration 7 completed (7831.338 ms) ====== [2025-08-13T23:23:20.161Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-08-13T23:23:20.161Z] GC before operation: completed in 117.197 ms, heap usage 314.402 MB -> 64.609 MB. [2025-08-13T23:23:28.270Z] ====== als (apache-spark) [default], iteration 8 completed (7946.033 ms) ====== [2025-08-13T23:23:28.270Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-08-13T23:23:28.270Z] GC before operation: completed in 118.024 ms, heap usage 221.461 MB -> 65.022 MB. [2025-08-13T23:23:37.275Z] ====== als (apache-spark) [default], iteration 9 completed (7707.804 ms) ====== [2025-08-13T23:23:37.275Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-08-13T23:23:37.275Z] GC before operation: completed in 123.710 ms, heap usage 190.176 MB -> 65.308 MB. [2025-08-13T23:23:43.940Z] ====== als (apache-spark) [default], iteration 10 completed (7792.445 ms) ====== [2025-08-13T23:23:43.940Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-08-13T23:23:43.940Z] GC before operation: completed in 103.846 ms, heap usage 230.973 MB -> 65.558 MB. [2025-08-13T23:23:52.209Z] ====== als (apache-spark) [default], iteration 11 completed (7580.929 ms) ====== [2025-08-13T23:23:52.209Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-08-13T23:23:52.209Z] GC before operation: completed in 112.148 ms, heap usage 245.694 MB -> 65.899 MB. [2025-08-13T23:24:00.311Z] ====== als (apache-spark) [default], iteration 12 completed (7826.076 ms) ====== [2025-08-13T23:24:00.311Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-08-13T23:24:00.311Z] GC before operation: completed in 119.227 ms, heap usage 201.458 MB -> 65.940 MB. [2025-08-13T23:24:08.414Z] ====== als (apache-spark) [default], iteration 13 completed (7652.618 ms) ====== [2025-08-13T23:24:08.414Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-08-13T23:24:08.414Z] GC before operation: completed in 122.386 ms, heap usage 223.289 MB -> 66.275 MB. [2025-08-13T23:24:16.516Z] ====== als (apache-spark) [default], iteration 14 completed (7868.976 ms) ====== [2025-08-13T23:24:16.516Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-08-13T23:24:16.516Z] GC before operation: completed in 113.232 ms, heap usage 217.504 MB -> 66.523 MB. [2025-08-13T23:24:26.206Z] ====== als (apache-spark) [default], iteration 15 completed (8088.568 ms) ====== [2025-08-13T23:24:26.206Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-08-13T23:24:26.206Z] GC before operation: completed in 107.031 ms, heap usage 218.305 MB -> 66.797 MB. [2025-08-13T23:24:32.923Z] ====== als (apache-spark) [default], iteration 16 completed (7889.147 ms) ====== [2025-08-13T23:24:32.923Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-08-13T23:24:33.878Z] GC before operation: completed in 114.007 ms, heap usage 200.614 MB -> 66.923 MB. [2025-08-13T23:24:41.420Z] ====== als (apache-spark) [default], iteration 17 completed (7876.535 ms) ====== [2025-08-13T23:24:41.420Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-08-13T23:24:41.420Z] GC before operation: completed in 110.318 ms, heap usage 235.237 MB -> 67.318 MB. [2025-08-13T23:24:49.541Z] ====== als (apache-spark) [default], iteration 18 completed (7778.353 ms) ====== [2025-08-13T23:24:49.541Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-08-13T23:24:49.541Z] GC before operation: completed in 118.878 ms, heap usage 432.392 MB -> 67.670 MB. [2025-08-13T23:24:57.690Z] ====== als (apache-spark) [default], iteration 19 completed (7731.541 ms) ====== [2025-08-13T23:24:57.690Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-08-13T23:24:57.690Z] GC before operation: completed in 121.104 ms, heap usage 216.780 MB -> 67.814 MB. [2025-08-13T23:25:05.824Z] ====== als (apache-spark) [default], iteration 20 completed (7950.602 ms) ====== [2025-08-13T23:25:05.824Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-08-13T23:25:05.824Z] GC before operation: completed in 115.086 ms, heap usage 335.432 MB -> 68.158 MB. [2025-08-13T23:25:13.953Z] ====== als (apache-spark) [default], iteration 21 completed (7772.748 ms) ====== [2025-08-13T23:25:13.953Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-08-13T23:25:13.953Z] GC before operation: completed in 128.016 ms, heap usage 257.325 MB -> 68.303 MB. [2025-08-13T23:25:23.639Z] ====== als (apache-spark) [default], iteration 22 completed (7881.268 ms) ====== [2025-08-13T23:25:23.639Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-08-13T23:25:23.639Z] GC before operation: completed in 117.970 ms, heap usage 318.326 MB -> 68.683 MB. [2025-08-13T23:25:31.744Z] ====== als (apache-spark) [default], iteration 23 completed (8114.648 ms) ====== [2025-08-13T23:25:31.744Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-08-13T23:25:31.744Z] GC before operation: completed in 134.045 ms, heap usage 320.015 MB -> 68.930 MB. [2025-08-13T23:25:39.847Z] ====== als (apache-spark) [default], iteration 24 completed (7925.011 ms) ====== [2025-08-13T23:25:39.847Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-08-13T23:25:39.847Z] GC before operation: completed in 118.116 ms, heap usage 230.301 MB -> 69.088 MB. [2025-08-13T23:25:47.371Z] ====== als (apache-spark) [default], iteration 25 completed (7966.312 ms) ====== [2025-08-13T23:25:47.371Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-08-13T23:25:47.371Z] GC before operation: completed in 118.077 ms, heap usage 251.305 MB -> 69.307 MB. [2025-08-13T23:25:55.637Z] ====== als (apache-spark) [default], iteration 26 completed (7945.781 ms) ====== [2025-08-13T23:25:55.637Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-08-13T23:25:56.584Z] GC before operation: completed in 131.575 ms, heap usage 311.215 MB -> 69.547 MB. [2025-08-13T23:26:04.699Z] ====== als (apache-spark) [default], iteration 27 completed (7923.196 ms) ====== [2025-08-13T23:26:04.699Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-08-13T23:26:04.699Z] GC before operation: completed in 116.488 ms, heap usage 294.371 MB -> 69.371 MB. [2025-08-13T23:26:12.790Z] ====== als (apache-spark) [default], iteration 28 completed (7460.470 ms) ====== [2025-08-13T23:26:12.790Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-08-13T23:26:12.790Z] GC before operation: completed in 113.693 ms, heap usage 327.694 MB -> 70.297 MB. [2025-08-13T23:26:20.915Z] ====== als (apache-spark) [default], iteration 29 completed (7586.184 ms) ====== [2025-08-13T23:26:20.915Z] ----------------------------------- [2025-08-13T23:26:20.915Z] renaissance-als_0_PASSED [2025-08-13T23:26:20.915Z] ----------------------------------- [2025-08-13T23:26:20.915Z] [2025-08-13T23:26:20.915Z] TEST TEARDOWN: [2025-08-13T23:26:20.915Z] Nothing to be done for teardown. [2025-08-13T23:26:20.915Z] renaissance-als_0 Finish Time: Wed Aug 13 23:26:19 2025 Epoch Time (ms): 1755127579848