[2025-04-16T06:45:53.568Z] Running test renaissance-als_0 ... [2025-04-16T06:45:53.568Z] =============================================== [2025-04-16T06:45:53.568Z] renaissance-als_0 Start Time: Wed Apr 16 06:45:52 2025 Epoch Time (ms): 1744785952996 [2025-04-16T06:45:53.568Z] variation: NoOptions [2025-04-16T06:45:53.568Z] JVM_OPTIONS: [2025-04-16T06:45:53.568Z] { \ [2025-04-16T06:45:53.568Z] echo ""; echo "TEST SETUP:"; \ [2025-04-16T06:45:53.568Z] echo "Nothing to be done for setup."; \ [2025-04-16T06:45:53.568Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17447859112037/renaissance-als_0"; \ [2025-04-16T06:45:53.568Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17447859112037/renaissance-als_0"; \ [2025-04-16T06:45:53.568Z] echo ""; echo "TESTING:"; \ [2025-04-16T06:45:53.568Z] "/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_17447859112037/renaissance-als_0"/als.json" als; \ [2025-04-16T06:45:53.568Z] 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_17447859112037/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-04-16T06:45:53.568Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-04-16T06:45:53.568Z] echo "Nothing to be done for teardown."; \ [2025-04-16T06:45:53.568Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17447859112037/TestTargetResult"; [2025-04-16T06:45:53.568Z] [2025-04-16T06:45:53.568Z] TEST SETUP: [2025-04-16T06:45:53.568Z] Nothing to be done for setup. [2025-04-16T06:45:53.568Z] [2025-04-16T06:45:53.568Z] TESTING: [2025-04-16T06:45:59.539Z] NOTE: 'als' benchmark uses Spark local executor with 2 (out of 2) threads. [2025-04-16T06:46:02.525Z] WARNING: An illegal reflective access operation has occurred [2025-04-16T06:46:02.526Z] 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_17447859112037/renaissance-als_0/harness-064553-14996531710877950166/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-04-16T06:46:02.526Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-04-16T06:46:02.526Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-04-16T06:46:02.526Z] WARNING: All illegal access operations will be denied in a future release [2025-04-16T06:46:03.848Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-04-16T06:46:04.504Z] GC before operation: completed in 149.629 ms, heap usage 345.000 MB -> 34.498 MB. [2025-04-16T06:46:38.339Z] ====== als (apache-spark) [default], iteration 0 completed (30076.680 ms) ====== [2025-04-16T06:46:38.339Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-04-16T06:46:38.339Z] GC before operation: completed in 246.085 ms, heap usage 138.170 MB -> 60.254 MB. [2025-04-16T06:46:53.145Z] ====== als (apache-spark) [default], iteration 1 completed (17781.188 ms) ====== [2025-04-16T06:46:53.145Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-04-16T06:46:53.797Z] GC before operation: completed in 220.501 ms, heap usage 321.682 MB -> 61.332 MB. [2025-04-16T06:47:10.952Z] ====== als (apache-spark) [default], iteration 2 completed (16760.502 ms) ====== [2025-04-16T06:47:10.952Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-04-16T06:47:10.952Z] GC before operation: completed in 160.814 ms, heap usage 240.188 MB -> 61.748 MB. [2025-04-16T06:47:28.136Z] ====== als (apache-spark) [default], iteration 3 completed (15019.182 ms) ====== [2025-04-16T06:47:28.136Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-04-16T06:47:28.136Z] GC before operation: completed in 203.715 ms, heap usage 117.016 MB -> 61.709 MB. [2025-04-16T06:47:42.732Z] ====== als (apache-spark) [default], iteration 4 completed (15711.602 ms) ====== [2025-04-16T06:47:42.732Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-04-16T06:47:42.732Z] GC before operation: completed in 208.418 ms, heap usage 258.896 MB -> 62.800 MB. [2025-04-16T06:48:00.063Z] ====== als (apache-spark) [default], iteration 5 completed (15966.788 ms) ====== [2025-04-16T06:48:00.063Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-04-16T06:48:00.063Z] GC before operation: completed in 185.656 ms, heap usage 135.142 MB -> 63.206 MB. [2025-04-16T06:48:14.910Z] ====== als (apache-spark) [default], iteration 6 completed (15239.269 ms) ====== [2025-04-16T06:48:14.910Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-04-16T06:48:14.910Z] GC before operation: completed in 249.056 ms, heap usage 382.450 MB -> 64.036 MB. [2025-04-16T06:48:32.157Z] ====== als (apache-spark) [default], iteration 7 completed (16959.604 ms) ====== [2025-04-16T06:48:32.157Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-04-16T06:48:32.813Z] GC before operation: completed in 253.044 ms, heap usage 253.117 MB -> 64.380 MB. [2025-04-16T06:48:53.218Z] ====== als (apache-spark) [default], iteration 8 completed (18589.868 ms) ====== [2025-04-16T06:48:53.218Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-04-16T06:48:53.218Z] GC before operation: completed in 221.228 ms, heap usage 227.158 MB -> 64.901 MB. [2025-04-16T06:49:14.579Z] ====== als (apache-spark) [default], iteration 9 completed (20357.143 ms) ====== [2025-04-16T06:49:14.579Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-04-16T06:49:14.579Z] GC before operation: completed in 610.965 ms, heap usage 97.917 MB -> 65.085 MB. [2025-04-16T06:49:38.777Z] ====== als (apache-spark) [default], iteration 10 completed (22006.410 ms) ====== [2025-04-16T06:49:38.777Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-04-16T06:49:38.777Z] GC before operation: completed in 364.378 ms, heap usage 144.002 MB -> 65.302 MB. [2025-04-16T06:49:56.190Z] ====== als (apache-spark) [default], iteration 11 completed (18035.390 ms) ====== [2025-04-16T06:49:56.190Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-04-16T06:49:56.190Z] GC before operation: completed in 214.736 ms, heap usage 606.594 MB -> 66.097 MB. [2025-04-16T06:50:16.741Z] ====== als (apache-spark) [default], iteration 12 completed (18826.457 ms) ====== [2025-04-16T06:50:16.741Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-04-16T06:50:16.741Z] GC before operation: completed in 286.474 ms, heap usage 219.215 MB -> 65.900 MB. [2025-04-16T06:50:34.209Z] ====== als (apache-spark) [default], iteration 13 completed (17651.050 ms) ====== [2025-04-16T06:50:34.209Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-04-16T06:50:34.209Z] GC before operation: completed in 207.892 ms, heap usage 249.900 MB -> 66.152 MB. [2025-04-16T06:50:51.478Z] ====== als (apache-spark) [default], iteration 14 completed (16844.393 ms) ====== [2025-04-16T06:50:51.478Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-04-16T06:50:51.478Z] GC before operation: completed in 208.498 ms, heap usage 255.297 MB -> 66.399 MB. [2025-04-16T06:51:08.835Z] ====== als (apache-spark) [default], iteration 15 completed (17775.979 ms) ====== [2025-04-16T06:51:08.835Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-04-16T06:51:08.835Z] GC before operation: completed in 254.921 ms, heap usage 161.715 MB -> 66.569 MB. [2025-04-16T06:51:29.357Z] ====== als (apache-spark) [default], iteration 16 completed (18000.613 ms) ====== [2025-04-16T06:51:29.357Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-04-16T06:51:29.357Z] GC before operation: completed in 168.032 ms, heap usage 152.035 MB -> 66.822 MB. [2025-04-16T06:51:43.986Z] ====== als (apache-spark) [default], iteration 17 completed (16330.146 ms) ====== [2025-04-16T06:51:43.986Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-04-16T06:51:43.986Z] GC before operation: completed in 278.572 ms, heap usage 104.230 MB -> 67.071 MB. [2025-04-16T06:52:01.286Z] ====== als (apache-spark) [default], iteration 18 completed (16375.676 ms) ====== [2025-04-16T06:52:01.286Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-04-16T06:52:01.286Z] GC before operation: completed in 181.759 ms, heap usage 260.242 MB -> 67.434 MB. [2025-04-16T06:52:22.109Z] ====== als (apache-spark) [default], iteration 19 completed (19601.897 ms) ====== [2025-04-16T06:52:22.109Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-04-16T06:52:22.109Z] GC before operation: completed in 236.196 ms, heap usage 174.289 MB -> 67.688 MB. [2025-04-16T06:52:42.640Z] ====== als (apache-spark) [default], iteration 20 completed (20831.904 ms) ====== [2025-04-16T06:52:42.640Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-04-16T06:52:42.640Z] GC before operation: completed in 172.646 ms, heap usage 148.784 MB -> 67.804 MB. [2025-04-16T06:53:07.009Z] ====== als (apache-spark) [default], iteration 21 completed (22048.140 ms) ====== [2025-04-16T06:53:07.009Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-04-16T06:53:07.009Z] GC before operation: completed in 259.684 ms, heap usage 266.309 MB -> 68.163 MB. [2025-04-16T06:53:28.270Z] ====== als (apache-spark) [default], iteration 22 completed (21252.891 ms) ====== [2025-04-16T06:53:28.270Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-04-16T06:53:28.270Z] GC before operation: completed in 604.695 ms, heap usage 202.708 MB -> 68.382 MB. [2025-04-16T06:53:52.558Z] ====== als (apache-spark) [default], iteration 23 completed (22228.285 ms) ====== [2025-04-16T06:53:52.558Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-04-16T06:53:52.558Z] GC before operation: completed in 268.096 ms, heap usage 259.400 MB -> 68.674 MB. [2025-04-16T06:54:09.970Z] ====== als (apache-spark) [default], iteration 24 completed (18576.047 ms) ====== [2025-04-16T06:54:09.970Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-04-16T06:54:09.970Z] GC before operation: completed in 400.070 ms, heap usage 247.537 MB -> 68.918 MB. [2025-04-16T06:54:30.698Z] ====== als (apache-spark) [default], iteration 25 completed (19736.721 ms) ====== [2025-04-16T06:54:30.698Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-04-16T06:54:30.698Z] GC before operation: completed in 292.024 ms, heap usage 149.803 MB -> 69.051 MB. [2025-04-16T06:54:51.257Z] ====== als (apache-spark) [default], iteration 26 completed (19414.897 ms) ====== [2025-04-16T06:54:51.257Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-04-16T06:54:51.257Z] GC before operation: completed in 212.465 ms, heap usage 114.361 MB -> 69.404 MB. [2025-04-16T06:55:08.808Z] ====== als (apache-spark) [default], iteration 27 completed (18037.411 ms) ====== [2025-04-16T06:55:08.808Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-04-16T06:55:09.481Z] GC before operation: completed in 277.483 ms, heap usage 305.896 MB -> 69.764 MB. [2025-04-16T06:55:30.753Z] ====== als (apache-spark) [default], iteration 28 completed (19300.742 ms) ====== [2025-04-16T06:55:30.753Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-04-16T06:55:30.753Z] GC before operation: completed in 291.139 ms, heap usage 181.084 MB -> 69.892 MB. [2025-04-16T06:55:48.220Z] ====== als (apache-spark) [default], iteration 29 completed (18318.927 ms) ====== [2025-04-16T06:55:48.893Z] ----------------------------------- [2025-04-16T06:55:48.893Z] renaissance-als_0_PASSED [2025-04-16T06:55:48.893Z] ----------------------------------- [2025-04-16T06:55:48.893Z] [2025-04-16T06:55:48.893Z] TEST TEARDOWN: [2025-04-16T06:55:48.893Z] Nothing to be done for teardown. [2025-04-16T06:55:48.893Z] renaissance-als_0 Finish Time: Wed Apr 16 06:55:48 2025 Epoch Time (ms): 1744786548622