[2025-08-28T12:23:46.547Z] Running test renaissance-als_0 ... [2025-08-28T12:23:46.547Z] =============================================== [2025-08-28T12:23:46.547Z] renaissance-als_0 Start Time: Thu Aug 28 12:23:46 2025 Epoch Time (ms): 1756383826367 [2025-08-28T12:23:46.547Z] variation: NoOptions [2025-08-28T12:23:46.547Z] JVM_OPTIONS: [2025-08-28T12:23:46.547Z] { \ [2025-08-28T12:23:46.547Z] echo ""; echo "TEST SETUP:"; \ [2025-08-28T12:23:46.547Z] echo "Nothing to be done for setup."; \ [2025-08-28T12:23:46.547Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17563834421410/renaissance-als_0"; \ [2025-08-28T12:23:46.547Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17563834421410/renaissance-als_0"; \ [2025-08-28T12:23:46.547Z] echo ""; echo "TESTING:"; \ [2025-08-28T12:23:46.547Z] "/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_17563834421410/renaissance-als_0"/als.json" als; \ [2025-08-28T12:23:46.547Z] 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_17563834421410/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-08-28T12:23:46.547Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-08-28T12:23:46.547Z] echo "Nothing to be done for teardown."; \ [2025-08-28T12:23:46.547Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17563834421410/TestTargetResult"; [2025-08-28T12:23:46.547Z] [2025-08-28T12:23:46.547Z] TEST SETUP: [2025-08-28T12:23:46.547Z] Nothing to be done for setup. [2025-08-28T12:23:46.547Z] [2025-08-28T12:23:46.547Z] TESTING: [2025-08-28T12:23:59.162Z] NOTE: 'als' benchmark uses Spark local executor with 2 (out of 2) threads. [2025-08-28T12:24:04.174Z] WARNING: An illegal reflective access operation has occurred [2025-08-28T12:24:04.174Z] 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_17563834421410/renaissance-als_0/harness-122348-14521570524796312922/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-08-28T12:24:04.174Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-08-28T12:24:04.174Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-08-28T12:24:04.174Z] WARNING: All illegal access operations will be denied in a future release [2025-08-28T12:24:05.484Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-08-28T12:24:06.471Z] GC before operation: completed in 591.455 ms, heap usage 328.001 MB -> 34.493 MB. [2025-08-28T12:25:12.344Z] ====== als (apache-spark) [default], iteration 0 completed (57232.485 ms) ====== [2025-08-28T12:25:12.344Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-08-28T12:25:12.344Z] GC before operation: completed in 419.738 ms, heap usage 610.232 MB -> 60.730 MB. [2025-08-28T12:25:46.334Z] ====== als (apache-spark) [default], iteration 1 completed (35532.158 ms) ====== [2025-08-28T12:25:46.334Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-08-28T12:25:46.334Z] GC before operation: completed in 392.335 ms, heap usage 413.704 MB -> 61.270 MB. [2025-08-28T12:26:11.382Z] ====== als (apache-spark) [default], iteration 2 completed (27986.829 ms) ====== [2025-08-28T12:26:11.382Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-08-28T12:26:11.382Z] GC before operation: completed in 364.361 ms, heap usage 382.277 MB -> 61.825 MB. [2025-08-28T12:26:45.741Z] ====== als (apache-spark) [default], iteration 3 completed (32808.011 ms) ====== [2025-08-28T12:26:45.741Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-08-28T12:26:46.391Z] GC before operation: completed in 1257.289 ms, heap usage 346.277 MB -> 62.388 MB. [2025-08-28T12:27:10.732Z] ====== als (apache-spark) [default], iteration 4 completed (23639.002 ms) ====== [2025-08-28T12:27:10.732Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-08-28T12:27:10.732Z] GC before operation: completed in 276.040 ms, heap usage 192.075 MB -> 62.654 MB. [2025-08-28T12:27:31.945Z] ====== als (apache-spark) [default], iteration 5 completed (20756.728 ms) ====== [2025-08-28T12:27:31.945Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-08-28T12:27:32.572Z] GC before operation: completed in 299.359 ms, heap usage 155.456 MB -> 63.198 MB. [2025-08-28T12:27:52.902Z] ====== als (apache-spark) [default], iteration 6 completed (17710.532 ms) ====== [2025-08-28T12:27:52.902Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-08-28T12:27:52.902Z] GC before operation: completed in 290.579 ms, heap usage 222.122 MB -> 63.826 MB. [2025-08-28T12:28:17.897Z] ====== als (apache-spark) [default], iteration 7 completed (23786.718 ms) ====== [2025-08-28T12:28:17.897Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-08-28T12:28:17.897Z] GC before operation: completed in 289.964 ms, heap usage 258.862 MB -> 64.424 MB. [2025-08-28T12:28:38.709Z] ====== als (apache-spark) [default], iteration 8 completed (20921.399 ms) ====== [2025-08-28T12:28:38.709Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-08-28T12:28:38.709Z] GC before operation: completed in 314.351 ms, heap usage 216.194 MB -> 64.914 MB. [2025-08-28T12:29:08.203Z] ====== als (apache-spark) [default], iteration 9 completed (25941.829 ms) ====== [2025-08-28T12:29:08.203Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-08-28T12:29:08.203Z] GC before operation: completed in 407.085 ms, heap usage 228.850 MB -> 65.226 MB. [2025-08-28T12:29:25.495Z] ====== als (apache-spark) [default], iteration 10 completed (18332.916 ms) ====== [2025-08-28T12:29:25.495Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-08-28T12:29:25.495Z] GC before operation: completed in 385.733 ms, heap usage 207.148 MB -> 65.445 MB. [2025-08-28T12:29:46.119Z] ====== als (apache-spark) [default], iteration 11 completed (20877.794 ms) ====== [2025-08-28T12:29:46.119Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-08-28T12:29:46.119Z] GC before operation: completed in 569.023 ms, heap usage 150.906 MB -> 65.571 MB. [2025-08-28T12:30:10.592Z] ====== als (apache-spark) [default], iteration 12 completed (21901.935 ms) ====== [2025-08-28T12:30:10.593Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-08-28T12:30:10.593Z] GC before operation: completed in 354.996 ms, heap usage 305.949 MB -> 66.037 MB. [2025-08-28T12:30:34.994Z] ====== als (apache-spark) [default], iteration 13 completed (21847.647 ms) ====== [2025-08-28T12:30:34.994Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-08-28T12:30:34.994Z] GC before operation: completed in 357.895 ms, heap usage 260.340 MB -> 66.192 MB. [2025-08-28T12:30:55.820Z] ====== als (apache-spark) [default], iteration 14 completed (22404.215 ms) ====== [2025-08-28T12:30:55.820Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-08-28T12:30:55.820Z] GC before operation: completed in 220.893 ms, heap usage 134.537 MB -> 66.307 MB. [2025-08-28T12:31:20.789Z] ====== als (apache-spark) [default], iteration 15 completed (21715.721 ms) ====== [2025-08-28T12:31:20.789Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-08-28T12:31:20.789Z] GC before operation: completed in 463.247 ms, heap usage 97.722 MB -> 66.558 MB. [2025-08-28T12:31:44.821Z] ====== als (apache-spark) [default], iteration 16 completed (24548.130 ms) ====== [2025-08-28T12:31:44.821Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-08-28T12:31:44.821Z] GC before operation: completed in 501.675 ms, heap usage 196.150 MB -> 66.805 MB. [2025-08-28T12:32:05.159Z] ====== als (apache-spark) [default], iteration 17 completed (19398.235 ms) ====== [2025-08-28T12:32:05.159Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-08-28T12:32:05.159Z] GC before operation: completed in 427.383 ms, heap usage 145.741 MB -> 67.047 MB. [2025-08-28T12:32:25.469Z] ====== als (apache-spark) [default], iteration 18 completed (18506.300 ms) ====== [2025-08-28T12:32:25.469Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-08-28T12:32:25.469Z] GC before operation: completed in 463.355 ms, heap usage 209.579 MB -> 67.442 MB. [2025-08-28T12:32:46.918Z] ====== als (apache-spark) [default], iteration 19 completed (21709.146 ms) ====== [2025-08-28T12:32:46.918Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-08-28T12:32:46.918Z] GC before operation: completed in 619.919 ms, heap usage 294.260 MB -> 67.823 MB. [2025-08-28T12:33:12.141Z] ====== als (apache-spark) [default], iteration 20 completed (25191.775 ms) ====== [2025-08-28T12:33:12.141Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-08-28T12:33:12.141Z] GC before operation: completed in 309.178 ms, heap usage 264.947 MB -> 67.930 MB. [2025-08-28T12:33:32.799Z] ====== als (apache-spark) [default], iteration 21 completed (18522.530 ms) ====== [2025-08-28T12:33:32.799Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-08-28T12:33:32.799Z] GC before operation: completed in 613.562 ms, heap usage 223.417 MB -> 68.171 MB. [2025-08-28T12:33:53.435Z] ====== als (apache-spark) [default], iteration 22 completed (20365.046 ms) ====== [2025-08-28T12:33:53.435Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-08-28T12:33:53.435Z] GC before operation: completed in 486.636 ms, heap usage 226.368 MB -> 68.402 MB. [2025-08-28T12:34:13.713Z] ====== als (apache-spark) [default], iteration 23 completed (19116.216 ms) ====== [2025-08-28T12:34:13.713Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-08-28T12:34:13.713Z] GC before operation: completed in 272.773 ms, heap usage 112.750 MB -> 68.654 MB. [2025-08-28T12:34:34.226Z] ====== als (apache-spark) [default], iteration 24 completed (18703.667 ms) ====== [2025-08-28T12:34:34.226Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-08-28T12:34:34.226Z] GC before operation: completed in 268.735 ms, heap usage 116.622 MB -> 68.348 MB. [2025-08-28T12:34:58.681Z] ====== als (apache-spark) [default], iteration 25 completed (24565.915 ms) ====== [2025-08-28T12:34:58.681Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-08-28T12:34:58.681Z] GC before operation: completed in 464.429 ms, heap usage 310.232 MB -> 69.280 MB. [2025-08-28T12:35:16.296Z] ====== als (apache-spark) [default], iteration 26 completed (16228.044 ms) ====== [2025-08-28T12:35:16.296Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-08-28T12:35:16.296Z] GC before operation: completed in 387.623 ms, heap usage 352.134 MB -> 69.555 MB. [2025-08-28T12:35:36.813Z] ====== als (apache-spark) [default], iteration 27 completed (19000.878 ms) ====== [2025-08-28T12:35:36.813Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-08-28T12:35:36.813Z] GC before operation: completed in 489.516 ms, heap usage 223.246 MB -> 69.660 MB. [2025-08-28T12:35:57.070Z] ====== als (apache-spark) [default], iteration 28 completed (21251.630 ms) ====== [2025-08-28T12:35:57.070Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-08-28T12:35:57.070Z] GC before operation: completed in 582.168 ms, heap usage 230.807 MB -> 69.905 MB. [2025-08-28T12:36:17.802Z] ====== als (apache-spark) [default], iteration 29 completed (18507.188 ms) ====== [2025-08-28T12:36:17.802Z] ----------------------------------- [2025-08-28T12:36:17.802Z] renaissance-als_0_PASSED [2025-08-28T12:36:17.802Z] ----------------------------------- [2025-08-28T12:36:17.802Z] [2025-08-28T12:36:17.802Z] TEST TEARDOWN: [2025-08-28T12:36:17.802Z] Nothing to be done for teardown. [2025-08-28T12:36:17.802Z] renaissance-als_0 Finish Time: Thu Aug 28 12:36:16 2025 Epoch Time (ms): 1756384576915