[2025-07-16T04:22:50.266Z] Running test renaissance-als_0 ... [2025-07-16T04:22:50.266Z] =============================================== [2025-07-16T04:22:50.266Z] renaissance-als_0 Start Time: Wed Jul 16 04:22:49 2025 Epoch Time (ms): 1752639769194 [2025-07-16T04:22:50.266Z] variation: NoOptions [2025-07-16T04:22:50.266Z] JVM_OPTIONS: [2025-07-16T04:22:50.266Z] { \ [2025-07-16T04:22:50.266Z] echo ""; echo "TEST SETUP:"; \ [2025-07-16T04:22:50.266Z] echo "Nothing to be done for setup."; \ [2025-07-16T04:22:50.266Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17526397241551/renaissance-als_0"; \ [2025-07-16T04:22:50.266Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17526397241551/renaissance-als_0"; \ [2025-07-16T04:22:50.266Z] echo ""; echo "TESTING:"; \ [2025-07-16T04:22:50.266Z] "/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_17526397241551/renaissance-als_0"/als.json" als; \ [2025-07-16T04:22:50.266Z] 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_17526397241551/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-07-16T04:22:50.266Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-07-16T04:22:50.266Z] echo "Nothing to be done for teardown."; \ [2025-07-16T04:22:50.266Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17526397241551/TestTargetResult"; [2025-07-16T04:22:50.266Z] [2025-07-16T04:22:50.266Z] TEST SETUP: [2025-07-16T04:22:50.266Z] Nothing to be done for setup. [2025-07-16T04:22:50.266Z] [2025-07-16T04:22:50.266Z] TESTING: [2025-07-16T04:22:55.645Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-07-16T04:22:59.805Z] WARNING: An illegal reflective access operation has occurred [2025-07-16T04:22:59.805Z] 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_17526397241551/renaissance-als_0/harness-042250-10217714019897548044/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-07-16T04:22:59.805Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-07-16T04:22:59.805Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-07-16T04:22:59.805Z] WARNING: All illegal access operations will be denied in a future release [2025-07-16T04:23:00.758Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-07-16T04:23:00.758Z] GC before operation: completed in 76.715 ms, heap usage 180.000 MB -> 34.522 MB. [2025-07-16T04:23:22.922Z] ====== als (apache-spark) [default], iteration 0 completed (20423.711 ms) ====== [2025-07-16T04:23:22.922Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-07-16T04:23:22.922Z] GC before operation: completed in 122.670 ms, heap usage 226.228 MB -> 60.399 MB. [2025-07-16T04:23:32.683Z] ====== als (apache-spark) [default], iteration 1 completed (9060.646 ms) ====== [2025-07-16T04:23:32.683Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-07-16T04:23:32.683Z] GC before operation: completed in 115.764 ms, heap usage 504.994 MB -> 61.673 MB. [2025-07-16T04:23:40.838Z] ====== als (apache-spark) [default], iteration 2 completed (8261.887 ms) ====== [2025-07-16T04:23:40.838Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-07-16T04:23:40.838Z] GC before operation: completed in 114.452 ms, heap usage 209.156 MB -> 61.698 MB. [2025-07-16T04:23:48.989Z] ====== als (apache-spark) [default], iteration 3 completed (8597.568 ms) ====== [2025-07-16T04:23:48.989Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-07-16T04:23:48.989Z] GC before operation: completed in 117.986 ms, heap usage 110.253 MB -> 62.245 MB. [2025-07-16T04:23:58.763Z] ====== als (apache-spark) [default], iteration 4 completed (8468.408 ms) ====== [2025-07-16T04:23:58.763Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-07-16T04:23:58.763Z] GC before operation: completed in 120.511 ms, heap usage 104.868 MB -> 62.780 MB. [2025-07-16T04:24:06.930Z] ====== als (apache-spark) [default], iteration 5 completed (8232.873 ms) ====== [2025-07-16T04:24:06.930Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-07-16T04:24:06.930Z] GC before operation: completed in 124.911 ms, heap usage 215.461 MB -> 63.394 MB. [2025-07-16T04:24:15.097Z] ====== als (apache-spark) [default], iteration 6 completed (8272.417 ms) ====== [2025-07-16T04:24:15.097Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-07-16T04:24:16.052Z] GC before operation: completed in 121.010 ms, heap usage 92.952 MB -> 63.808 MB. [2025-07-16T04:24:24.301Z] ====== als (apache-spark) [default], iteration 7 completed (7953.135 ms) ====== [2025-07-16T04:24:24.301Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-07-16T04:24:24.301Z] GC before operation: completed in 132.288 ms, heap usage 237.122 MB -> 64.482 MB. [2025-07-16T04:24:32.482Z] ====== als (apache-spark) [default], iteration 8 completed (7902.097 ms) ====== [2025-07-16T04:24:32.482Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-07-16T04:24:32.482Z] GC before operation: completed in 126.989 ms, heap usage 217.268 MB -> 65.178 MB. [2025-07-16T04:24:40.645Z] ====== als (apache-spark) [default], iteration 9 completed (8081.166 ms) ====== [2025-07-16T04:24:40.645Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-07-16T04:24:40.645Z] GC before operation: completed in 129.034 ms, heap usage 261.977 MB -> 65.258 MB. [2025-07-16T04:24:48.807Z] ====== als (apache-spark) [default], iteration 10 completed (8042.560 ms) ====== [2025-07-16T04:24:48.807Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-07-16T04:24:48.807Z] GC before operation: completed in 124.875 ms, heap usage 201.278 MB -> 65.397 MB. [2025-07-16T04:24:57.571Z] ====== als (apache-spark) [default], iteration 11 completed (8197.554 ms) ====== [2025-07-16T04:24:57.571Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-07-16T04:24:57.571Z] GC before operation: completed in 129.215 ms, heap usage 353.447 MB -> 65.888 MB. [2025-07-16T04:25:05.761Z] ====== als (apache-spark) [default], iteration 12 completed (7916.071 ms) ====== [2025-07-16T04:25:05.761Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-07-16T04:25:05.761Z] GC before operation: completed in 121.832 ms, heap usage 246.645 MB -> 65.983 MB. [2025-07-16T04:25:15.544Z] ====== als (apache-spark) [default], iteration 13 completed (8070.468 ms) ====== [2025-07-16T04:25:15.544Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-07-16T04:25:15.544Z] GC before operation: completed in 120.991 ms, heap usage 277.913 MB -> 66.226 MB. [2025-07-16T04:25:23.724Z] ====== als (apache-spark) [default], iteration 14 completed (8199.900 ms) ====== [2025-07-16T04:25:23.724Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-07-16T04:25:23.724Z] GC before operation: completed in 120.661 ms, heap usage 336.961 MB -> 66.591 MB. [2025-07-16T04:25:31.940Z] ====== als (apache-spark) [default], iteration 15 completed (7893.497 ms) ====== [2025-07-16T04:25:31.940Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-07-16T04:25:31.940Z] GC before operation: completed in 117.510 ms, heap usage 266.399 MB -> 66.759 MB. [2025-07-16T04:25:40.124Z] ====== als (apache-spark) [default], iteration 16 completed (8626.151 ms) ====== [2025-07-16T04:25:40.124Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-07-16T04:25:40.124Z] GC before operation: completed in 127.212 ms, heap usage 259.221 MB -> 67.009 MB. [2025-07-16T04:25:48.327Z] ====== als (apache-spark) [default], iteration 17 completed (8046.587 ms) ====== [2025-07-16T04:25:48.327Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-07-16T04:25:49.285Z] GC before operation: completed in 125.905 ms, heap usage 234.109 MB -> 67.283 MB. [2025-07-16T04:25:57.464Z] ====== als (apache-spark) [default], iteration 18 completed (7985.127 ms) ====== [2025-07-16T04:25:57.464Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-07-16T04:25:57.464Z] GC before operation: completed in 149.981 ms, heap usage 325.288 MB -> 67.639 MB. [2025-07-16T04:26:05.627Z] ====== als (apache-spark) [default], iteration 19 completed (8206.520 ms) ====== [2025-07-16T04:26:05.627Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-07-16T04:26:05.627Z] GC before operation: completed in 127.674 ms, heap usage 224.388 MB -> 67.776 MB. [2025-07-16T04:26:15.393Z] ====== als (apache-spark) [default], iteration 20 completed (8310.681 ms) ====== [2025-07-16T04:26:15.393Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-07-16T04:26:15.393Z] GC before operation: completed in 134.346 ms, heap usage 231.967 MB -> 68.018 MB. [2025-07-16T04:26:23.546Z] ====== als (apache-spark) [default], iteration 21 completed (8157.504 ms) ====== [2025-07-16T04:26:23.546Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-07-16T04:26:23.546Z] GC before operation: completed in 139.205 ms, heap usage 173.152 MB -> 68.152 MB. [2025-07-16T04:26:31.302Z] ====== als (apache-spark) [default], iteration 22 completed (8144.872 ms) ====== [2025-07-16T04:26:31.302Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-07-16T04:26:32.255Z] GC before operation: completed in 119.446 ms, heap usage 245.338 MB -> 68.546 MB. [2025-07-16T04:26:40.413Z] ====== als (apache-spark) [default], iteration 23 completed (7937.625 ms) ====== [2025-07-16T04:26:40.413Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-07-16T04:26:40.413Z] GC before operation: completed in 131.850 ms, heap usage 284.463 MB -> 68.796 MB. [2025-07-16T04:26:48.579Z] ====== als (apache-spark) [default], iteration 24 completed (8296.257 ms) ====== [2025-07-16T04:26:48.579Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-07-16T04:26:48.579Z] GC before operation: completed in 130.680 ms, heap usage 96.852 MB -> 68.923 MB. [2025-07-16T04:26:56.741Z] ====== als (apache-spark) [default], iteration 25 completed (7834.043 ms) ====== [2025-07-16T04:26:56.741Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-07-16T04:26:56.741Z] GC before operation: completed in 136.343 ms, heap usage 238.700 MB -> 69.294 MB. [2025-07-16T04:27:06.681Z] ====== als (apache-spark) [default], iteration 26 completed (8081.873 ms) ====== [2025-07-16T04:27:06.681Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-07-16T04:27:06.681Z] GC before operation: completed in 152.084 ms, heap usage 347.707 MB -> 69.671 MB. [2025-07-16T04:27:14.845Z] ====== als (apache-spark) [default], iteration 27 completed (8153.982 ms) ====== [2025-07-16T04:27:14.846Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-07-16T04:27:14.846Z] GC before operation: completed in 138.551 ms, heap usage 254.852 MB -> 69.771 MB. [2025-07-16T04:27:23.091Z] ====== als (apache-spark) [default], iteration 28 completed (8014.691 ms) ====== [2025-07-16T04:27:23.091Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-07-16T04:27:23.091Z] GC before operation: completed in 134.231 ms, heap usage 89.410 MB -> 69.446 MB. [2025-07-16T04:27:31.270Z] ====== als (apache-spark) [default], iteration 29 completed (7777.098 ms) ====== [2025-07-16T04:27:31.270Z] ----------------------------------- [2025-07-16T04:27:31.270Z] renaissance-als_0_PASSED [2025-07-16T04:27:31.270Z] ----------------------------------- [2025-07-16T04:27:31.270Z] [2025-07-16T04:27:31.270Z] TEST TEARDOWN: [2025-07-16T04:27:31.270Z] Nothing to be done for teardown. [2025-07-16T04:27:31.270Z] renaissance-als_0 Finish Time: Wed Jul 16 04:27:30 2025 Epoch Time (ms): 1752640050684