[2025-06-12T04:46:15.177Z] Running test renaissance-als_0 ... [2025-06-12T04:46:15.177Z] =============================================== [2025-06-12T04:46:15.177Z] renaissance-als_0 Start Time: Thu Jun 12 00:46:14 2025 Epoch Time (ms): 1749703574353 [2025-06-12T04:46:15.177Z] variation: NoOptions [2025-06-12T04:46:15.177Z] JVM_OPTIONS: [2025-06-12T04:46:15.177Z] { \ [2025-06-12T04:46:15.177Z] echo ""; echo "TEST SETUP:"; \ [2025-06-12T04:46:15.177Z] echo "Nothing to be done for setup."; \ [2025-06-12T04:46:15.177Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17497035125400/renaissance-als_0"; \ [2025-06-12T04:46:15.177Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17497035125400/renaissance-als_0"; \ [2025-06-12T04:46:15.177Z] echo ""; echo "TESTING:"; \ [2025-06-12T04:46:15.177Z] "/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_17497035125400/renaissance-als_0"/als.json" als; \ [2025-06-12T04:46:15.178Z] 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_17497035125400/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-06-12T04:46:15.178Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-06-12T04:46:15.178Z] echo "Nothing to be done for teardown."; \ [2025-06-12T04:46:15.178Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17497035125400/TestTargetResult"; [2025-06-12T04:46:15.178Z] [2025-06-12T04:46:15.178Z] TEST SETUP: [2025-06-12T04:46:15.178Z] Nothing to be done for setup. [2025-06-12T04:46:15.178Z] [2025-06-12T04:46:15.178Z] TESTING: [2025-06-12T04:46:33.198Z] NOTE: 'als' benchmark uses Spark local executor with 2 (out of 2) threads. [2025-06-12T04:46:40.180Z] WARNING: An illegal reflective access operation has occurred [2025-06-12T04:46:40.180Z] 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_17497035125400/renaissance-als_0/harness-004616-13419191745127227812/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-06-12T04:46:40.180Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-06-12T04:46:40.180Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-06-12T04:46:40.180Z] WARNING: All illegal access operations will be denied in a future release [2025-06-12T04:46:41.635Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-06-12T04:46:41.635Z] GC before operation: completed in 183.911 ms, heap usage 245.885 MB -> 34.453 MB. [2025-06-12T04:47:47.479Z] ====== als (apache-spark) [default], iteration 0 completed (55897.668 ms) ====== [2025-06-12T04:47:47.479Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-06-12T04:47:47.479Z] GC before operation: completed in 310.176 ms, heap usage 157.358 MB -> 60.269 MB. [2025-06-12T04:48:06.051Z] ====== als (apache-spark) [default], iteration 1 completed (26346.854 ms) ====== [2025-06-12T04:48:06.051Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-06-12T04:48:06.762Z] GC before operation: completed in 700.432 ms, heap usage 418.775 MB -> 61.319 MB. [2025-06-12T04:48:41.772Z] ====== als (apache-spark) [default], iteration 2 completed (29791.895 ms) ====== [2025-06-12T04:48:41.772Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-06-12T04:48:41.772Z] GC before operation: completed in 567.029 ms, heap usage 123.538 MB -> 61.161 MB. [2025-06-12T04:49:17.055Z] ====== als (apache-spark) [default], iteration 3 completed (33912.463 ms) ====== [2025-06-12T04:49:17.055Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-06-12T04:49:17.055Z] GC before operation: completed in 291.851 ms, heap usage 112.682 MB -> 61.716 MB. [2025-06-12T04:49:42.201Z] ====== als (apache-spark) [default], iteration 4 completed (25766.603 ms) ====== [2025-06-12T04:49:42.201Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-06-12T04:49:42.201Z] GC before operation: completed in 476.141 ms, heap usage 229.977 MB -> 62.779 MB. [2025-06-12T04:50:12.294Z] ====== als (apache-spark) [default], iteration 5 completed (29390.312 ms) ====== [2025-06-12T04:50:12.294Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-06-12T04:50:12.294Z] GC before operation: completed in 814.179 ms, heap usage 132.279 MB -> 63.472 MB. [2025-06-12T04:50:43.105Z] ====== als (apache-spark) [default], iteration 6 completed (28109.719 ms) ====== [2025-06-12T04:50:43.105Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-06-12T04:50:43.105Z] GC before operation: completed in 357.345 ms, heap usage 235.077 MB -> 63.882 MB. [2025-06-12T04:51:05.531Z] ====== als (apache-spark) [default], iteration 7 completed (23990.108 ms) ====== [2025-06-12T04:51:05.531Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-06-12T04:51:05.531Z] GC before operation: completed in 243.242 ms, heap usage 223.240 MB -> 64.297 MB. [2025-06-12T04:51:30.610Z] ====== als (apache-spark) [default], iteration 8 completed (25195.333 ms) ====== [2025-06-12T04:51:30.610Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-06-12T04:51:31.683Z] GC before operation: completed in 493.811 ms, heap usage 402.544 MB -> 65.052 MB. [2025-06-12T04:52:01.491Z] ====== als (apache-spark) [default], iteration 9 completed (28909.731 ms) ====== [2025-06-12T04:52:01.491Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-06-12T04:52:01.491Z] GC before operation: completed in 319.567 ms, heap usage 223.691 MB -> 65.175 MB. [2025-06-12T04:52:27.266Z] ====== als (apache-spark) [default], iteration 10 completed (23046.557 ms) ====== [2025-06-12T04:52:27.266Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-06-12T04:52:27.266Z] GC before operation: completed in 423.824 ms, heap usage 370.903 MB -> 65.529 MB. [2025-06-12T04:52:53.047Z] ====== als (apache-spark) [default], iteration 11 completed (26532.121 ms) ====== [2025-06-12T04:52:53.047Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-06-12T04:52:54.045Z] GC before operation: completed in 590.426 ms, heap usage 228.308 MB -> 65.678 MB. [2025-06-12T04:53:25.822Z] ====== als (apache-spark) [default], iteration 12 completed (31662.760 ms) ====== [2025-06-12T04:53:25.822Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-06-12T04:53:25.822Z] GC before operation: completed in 396.003 ms, heap usage 222.775 MB -> 65.926 MB. [2025-06-12T04:53:50.985Z] ====== als (apache-spark) [default], iteration 13 completed (22113.874 ms) ====== [2025-06-12T04:53:50.985Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-06-12T04:53:50.985Z] GC before operation: completed in 466.311 ms, heap usage 102.429 MB -> 66.185 MB. [2025-06-12T04:54:12.602Z] ====== als (apache-spark) [default], iteration 14 completed (22753.826 ms) ====== [2025-06-12T04:54:12.602Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-06-12T04:54:12.602Z] GC before operation: completed in 282.416 ms, heap usage 320.373 MB -> 66.519 MB. [2025-06-12T04:54:42.300Z] ====== als (apache-spark) [default], iteration 15 completed (25165.332 ms) ====== [2025-06-12T04:54:42.300Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-06-12T04:54:42.300Z] GC before operation: completed in 679.152 ms, heap usage 248.519 MB -> 66.675 MB. [2025-06-12T04:55:11.790Z] ====== als (apache-spark) [default], iteration 16 completed (28720.271 ms) ====== [2025-06-12T04:55:11.790Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-06-12T04:55:11.790Z] GC before operation: completed in 325.224 ms, heap usage 139.195 MB -> 66.803 MB. [2025-06-12T04:55:30.675Z] ====== als (apache-spark) [default], iteration 17 completed (20753.225 ms) ====== [2025-06-12T04:55:30.675Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-06-12T04:55:30.675Z] GC before operation: completed in 627.144 ms, heap usage 210.781 MB -> 67.163 MB. [2025-06-12T04:56:01.025Z] ====== als (apache-spark) [default], iteration 18 completed (26399.172 ms) ====== [2025-06-12T04:56:01.025Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-06-12T04:56:01.025Z] GC before operation: completed in 491.544 ms, heap usage 107.104 MB -> 66.856 MB. [2025-06-12T04:56:30.835Z] ====== als (apache-spark) [default], iteration 19 completed (31873.004 ms) ====== [2025-06-12T04:56:30.835Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-06-12T04:56:30.835Z] GC before operation: completed in 396.523 ms, heap usage 245.269 MB -> 67.706 MB. [2025-06-12T04:57:00.273Z] ====== als (apache-spark) [default], iteration 20 completed (28180.198 ms) ====== [2025-06-12T04:57:00.273Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-06-12T04:57:00.921Z] GC before operation: completed in 761.880 ms, heap usage 243.302 MB -> 67.915 MB. [2025-06-12T04:57:24.341Z] ====== als (apache-spark) [default], iteration 21 completed (22118.719 ms) ====== [2025-06-12T04:57:24.341Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-06-12T04:57:24.341Z] GC before operation: completed in 308.287 ms, heap usage 86.677 MB -> 68.391 MB. [2025-06-12T04:57:46.483Z] ====== als (apache-spark) [default], iteration 22 completed (19582.581 ms) ====== [2025-06-12T04:57:46.483Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-06-12T04:57:46.483Z] GC before operation: completed in 485.808 ms, heap usage 244.617 MB -> 68.404 MB. [2025-06-12T04:58:07.770Z] ====== als (apache-spark) [default], iteration 23 completed (22006.671 ms) ====== [2025-06-12T04:58:07.770Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-06-12T04:58:07.770Z] GC before operation: completed in 371.495 ms, heap usage 207.656 MB -> 68.682 MB. [2025-06-12T04:58:29.458Z] ====== als (apache-spark) [default], iteration 24 completed (21050.798 ms) ====== [2025-06-12T04:58:29.458Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-06-12T04:58:29.458Z] GC before operation: completed in 462.295 ms, heap usage 361.854 MB -> 69.027 MB. [2025-06-12T04:59:04.994Z] ====== als (apache-spark) [default], iteration 25 completed (30492.907 ms) ====== [2025-06-12T04:59:04.994Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-06-12T04:59:04.994Z] GC before operation: completed in 479.487 ms, heap usage 249.126 MB -> 66.040 MB. [2025-06-12T04:59:23.387Z] ====== als (apache-spark) [default], iteration 26 completed (22060.383 ms) ====== [2025-06-12T04:59:23.387Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-06-12T04:59:24.088Z] GC before operation: completed in 635.163 ms, heap usage 140.441 MB -> 66.106 MB. [2025-06-12T04:59:49.135Z] ====== als (apache-spark) [default], iteration 27 completed (23585.226 ms) ====== [2025-06-12T04:59:49.135Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-06-12T04:59:49.769Z] GC before operation: completed in 959.850 ms, heap usage 135.843 MB -> 66.462 MB. [2025-06-12T05:00:11.534Z] ====== als (apache-spark) [default], iteration 28 completed (20606.347 ms) ====== [2025-06-12T05:00:11.534Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-06-12T05:00:11.534Z] GC before operation: completed in 350.322 ms, heap usage 116.001 MB -> 66.590 MB. [2025-06-12T05:00:32.764Z] ====== als (apache-spark) [default], iteration 29 completed (20552.839 ms) ====== [2025-06-12T05:00:32.764Z] ----------------------------------- [2025-06-12T05:00:32.764Z] renaissance-als_0_PASSED [2025-06-12T05:00:32.764Z] ----------------------------------- [2025-06-12T05:00:32.764Z] [2025-06-12T05:00:32.764Z] TEST TEARDOWN: [2025-06-12T05:00:32.764Z] Nothing to be done for teardown. [2025-06-12T05:00:32.764Z] renaissance-als_0 Finish Time: Thu Jun 12 01:00:32 2025 Epoch Time (ms): 1749704432704