[2025-08-25T22:22:50.965Z] Running test renaissance-als_0 ... [2025-08-25T22:22:50.965Z] =============================================== [2025-08-25T22:22:50.965Z] renaissance-als_0 Start Time: Mon Aug 25 22:22:50 2025 Epoch Time (ms): 1756160570653 [2025-08-25T22:22:50.965Z] variation: NoOptions [2025-08-25T22:22:50.965Z] JVM_OPTIONS: [2025-08-25T22:22:50.965Z] { \ [2025-08-25T22:22:50.965Z] echo ""; echo "TEST SETUP:"; \ [2025-08-25T22:22:50.965Z] echo "Nothing to be done for setup."; \ [2025-08-25T22:22:50.965Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17561603909544/renaissance-als_0"; \ [2025-08-25T22:22:50.965Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17561603909544/renaissance-als_0"; \ [2025-08-25T22:22:50.965Z] echo ""; echo "TESTING:"; \ [2025-08-25T22:22:50.965Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_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_s390x_linux/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17561603909544/renaissance-als_0"/als.json" als; \ [2025-08-25T22:22:50.965Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17561603909544/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-08-25T22:22:50.965Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-08-25T22:22:50.965Z] echo "Nothing to be done for teardown."; \ [2025-08-25T22:22:50.965Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17561603909544/TestTargetResult"; [2025-08-25T22:22:50.965Z] [2025-08-25T22:22:50.965Z] TEST SETUP: [2025-08-25T22:22:50.965Z] Nothing to be done for setup. [2025-08-25T22:22:50.965Z] [2025-08-25T22:22:50.965Z] TESTING: [2025-08-25T22:22:56.629Z] NOTE: 'als' benchmark uses Spark local executor with 2 (out of 2) threads. [2025-08-25T22:22:59.346Z] WARNING: An illegal reflective access operation has occurred [2025-08-25T22:22:59.346Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/output_17561603909544/renaissance-als_0/harness-222251-8526373166939971456/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-08-25T22:22:59.346Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-08-25T22:22:59.346Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-08-25T22:22:59.346Z] WARNING: All illegal access operations will be denied in a future release [2025-08-25T22:22:59.936Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-08-25T22:22:59.936Z] GC before operation: completed in 124.787 ms, heap usage 341.500 MB -> 34.505 MB. [2025-08-25T22:23:27.436Z] ====== als (apache-spark) [default], iteration 0 completed (25612.042 ms) ====== [2025-08-25T22:23:27.436Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-08-25T22:23:27.436Z] GC before operation: completed in 174.199 ms, heap usage 197.202 MB -> 60.248 MB. [2025-08-25T22:23:44.290Z] ====== als (apache-spark) [default], iteration 1 completed (15531.510 ms) ====== [2025-08-25T22:23:44.290Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-08-25T22:23:44.290Z] GC before operation: completed in 193.178 ms, heap usage 286.596 MB -> 61.221 MB. [2025-08-25T22:23:58.385Z] ====== als (apache-spark) [default], iteration 2 completed (14595.497 ms) ====== [2025-08-25T22:23:58.385Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-08-25T22:23:58.385Z] GC before operation: completed in 188.883 ms, heap usage 178.322 MB -> 61.630 MB. [2025-08-25T22:24:12.906Z] ====== als (apache-spark) [default], iteration 3 completed (13419.501 ms) ====== [2025-08-25T22:24:12.906Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-08-25T22:24:12.906Z] GC before operation: completed in 167.880 ms, heap usage 104.896 MB -> 62.163 MB. [2025-08-25T22:24:27.282Z] ====== als (apache-spark) [default], iteration 4 completed (13556.225 ms) ====== [2025-08-25T22:24:27.282Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-08-25T22:24:27.282Z] GC before operation: completed in 130.377 ms, heap usage 116.595 MB -> 62.684 MB. [2025-08-25T22:24:39.190Z] ====== als (apache-spark) [default], iteration 5 completed (13252.247 ms) ====== [2025-08-25T22:24:39.190Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-08-25T22:24:39.190Z] GC before operation: completed in 265.317 ms, heap usage 159.581 MB -> 63.217 MB. [2025-08-25T22:24:53.749Z] ====== als (apache-spark) [default], iteration 6 completed (13818.407 ms) ====== [2025-08-25T22:24:53.749Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-08-25T22:24:53.749Z] GC before operation: completed in 188.594 ms, heap usage 100.484 MB -> 63.753 MB. [2025-08-25T22:25:08.578Z] ====== als (apache-spark) [default], iteration 7 completed (12812.906 ms) ====== [2025-08-25T22:25:08.578Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-08-25T22:25:08.578Z] GC before operation: completed in 229.083 ms, heap usage 124.248 MB -> 64.277 MB. [2025-08-25T22:25:20.603Z] ====== als (apache-spark) [default], iteration 8 completed (13359.755 ms) ====== [2025-08-25T22:25:20.603Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-08-25T22:25:20.603Z] GC before operation: completed in 187.218 ms, heap usage 178.074 MB -> 64.803 MB. [2025-08-25T22:25:34.771Z] ====== als (apache-spark) [default], iteration 9 completed (13581.683 ms) ====== [2025-08-25T22:25:34.771Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-08-25T22:25:34.771Z] GC before operation: completed in 145.388 ms, heap usage 127.333 MB -> 65.079 MB. [2025-08-25T22:25:48.888Z] ====== als (apache-spark) [default], iteration 10 completed (12599.096 ms) ====== [2025-08-25T22:25:48.889Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-08-25T22:25:48.889Z] GC before operation: completed in 129.842 ms, heap usage 139.087 MB -> 65.337 MB. [2025-08-25T22:26:02.954Z] ====== als (apache-spark) [default], iteration 11 completed (13322.511 ms) ====== [2025-08-25T22:26:02.954Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-08-25T22:26:02.954Z] GC before operation: completed in 153.888 ms, heap usage 209.916 MB -> 65.708 MB. [2025-08-25T22:26:15.549Z] ====== als (apache-spark) [default], iteration 12 completed (13301.191 ms) ====== [2025-08-25T22:26:15.549Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-08-25T22:26:15.549Z] GC before operation: completed in 223.905 ms, heap usage 188.330 MB -> 65.839 MB. [2025-08-25T22:26:29.713Z] ====== als (apache-spark) [default], iteration 13 completed (13361.724 ms) ====== [2025-08-25T22:26:29.713Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-08-25T22:26:29.713Z] GC before operation: completed in 178.182 ms, heap usage 260.785 MB -> 66.203 MB. [2025-08-25T22:26:43.815Z] ====== als (apache-spark) [default], iteration 14 completed (13673.925 ms) ====== [2025-08-25T22:26:43.815Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-08-25T22:26:43.815Z] GC before operation: completed in 172.111 ms, heap usage 130.223 MB -> 66.309 MB. [2025-08-25T22:26:55.703Z] ====== als (apache-spark) [default], iteration 15 completed (11945.297 ms) ====== [2025-08-25T22:26:55.703Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-08-25T22:26:55.703Z] GC before operation: completed in 181.608 ms, heap usage 240.922 MB -> 66.691 MB. [2025-08-25T22:27:09.744Z] ====== als (apache-spark) [default], iteration 16 completed (12868.786 ms) ====== [2025-08-25T22:27:09.744Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-08-25T22:27:09.744Z] GC before operation: completed in 144.833 ms, heap usage 169.618 MB -> 66.814 MB. [2025-08-25T22:27:21.653Z] ====== als (apache-spark) [default], iteration 17 completed (11637.128 ms) ====== [2025-08-25T22:27:21.653Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-08-25T22:27:21.653Z] GC before operation: completed in 150.813 ms, heap usage 150.663 MB -> 67.059 MB. [2025-08-25T22:27:35.712Z] ====== als (apache-spark) [default], iteration 18 completed (13062.632 ms) ====== [2025-08-25T22:27:35.712Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-08-25T22:27:35.712Z] GC before operation: completed in 137.154 ms, heap usage 144.267 MB -> 67.308 MB. [2025-08-25T22:27:47.624Z] ====== als (apache-spark) [default], iteration 19 completed (12255.763 ms) ====== [2025-08-25T22:27:47.624Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-08-25T22:27:47.624Z] GC before operation: completed in 185.119 ms, heap usage 247.278 MB -> 67.668 MB. [2025-08-25T22:28:01.693Z] ====== als (apache-spark) [default], iteration 20 completed (13341.146 ms) ====== [2025-08-25T22:28:01.693Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-08-25T22:28:01.693Z] GC before operation: completed in 151.098 ms, heap usage 241.152 MB -> 67.909 MB. [2025-08-25T22:28:16.139Z] ====== als (apache-spark) [default], iteration 21 completed (13032.991 ms) ====== [2025-08-25T22:28:16.139Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-08-25T22:28:16.139Z] GC before operation: completed in 179.794 ms, heap usage 267.112 MB -> 68.147 MB. [2025-08-25T22:28:30.635Z] ====== als (apache-spark) [default], iteration 22 completed (13790.327 ms) ====== [2025-08-25T22:28:30.635Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-08-25T22:28:30.635Z] GC before operation: completed in 217.237 ms, heap usage 214.542 MB -> 68.422 MB. [2025-08-25T22:28:42.758Z] ====== als (apache-spark) [default], iteration 23 completed (13369.967 ms) ====== [2025-08-25T22:28:42.758Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-08-25T22:28:42.758Z] GC before operation: completed in 212.470 ms, heap usage 134.408 MB -> 68.578 MB. [2025-08-25T22:28:59.568Z] ====== als (apache-spark) [default], iteration 24 completed (14552.994 ms) ====== [2025-08-25T22:28:59.568Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-08-25T22:28:59.568Z] GC before operation: completed in 215.316 ms, heap usage 229.308 MB -> 68.946 MB. [2025-08-25T22:29:11.534Z] ====== als (apache-spark) [default], iteration 25 completed (13536.135 ms) ====== [2025-08-25T22:29:11.534Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-08-25T22:29:12.139Z] GC before operation: completed in 242.144 ms, heap usage 253.663 MB -> 69.190 MB. [2025-08-25T22:29:26.712Z] ====== als (apache-spark) [default], iteration 26 completed (13672.702 ms) ====== [2025-08-25T22:29:26.712Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-08-25T22:29:26.712Z] GC before operation: completed in 174.849 ms, heap usage 278.147 MB -> 69.444 MB. [2025-08-25T22:29:41.386Z] ====== als (apache-spark) [default], iteration 27 completed (13296.374 ms) ====== [2025-08-25T22:29:41.386Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-08-25T22:29:41.386Z] GC before operation: completed in 186.482 ms, heap usage 232.417 MB -> 69.689 MB. [2025-08-25T22:29:53.335Z] ====== als (apache-spark) [default], iteration 28 completed (13021.532 ms) ====== [2025-08-25T22:29:53.335Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-08-25T22:29:53.335Z] GC before operation: completed in 148.390 ms, heap usage 210.449 MB -> 69.351 MB. [2025-08-25T22:30:07.535Z] ====== als (apache-spark) [default], iteration 29 completed (13371.736 ms) ====== [2025-08-25T22:30:07.536Z] ----------------------------------- [2025-08-25T22:30:07.536Z] renaissance-als_0_PASSED [2025-08-25T22:30:07.536Z] ----------------------------------- [2025-08-25T22:30:07.536Z] [2025-08-25T22:30:07.536Z] TEST TEARDOWN: [2025-08-25T22:30:07.536Z] Nothing to be done for teardown. [2025-08-25T22:30:07.536Z] renaissance-als_0 Finish Time: Mon Aug 25 22:30:06 2025 Epoch Time (ms): 1756161006807