[2025-11-19T22:17:56.198Z] Running test renaissance-als_0 ... [2025-11-19T22:17:56.198Z] =============================================== [2025-11-19T22:17:56.198Z] renaissance-als_0 Start Time: Wed Nov 19 22:17:56 2025 Epoch Time (ms): 1763590676087 [2025-11-19T22:17:56.198Z] variation: NoOptions [2025-11-19T22:17:56.198Z] JVM_OPTIONS: [2025-11-19T22:17:56.198Z] { \ [2025-11-19T22:17:56.198Z] echo ""; echo "TEST SETUP:"; \ [2025-11-19T22:17:56.198Z] echo "Nothing to be done for setup."; \ [2025-11-19T22:17:56.198Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17635905594377/renaissance-als_0"; \ [2025-11-19T22:17:56.198Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17635905594377/renaissance-als_0"; \ [2025-11-19T22:17:56.198Z] echo ""; echo "TESTING:"; \ [2025-11-19T22:17:56.198Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/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_ppc64_aix/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17635905594377/renaissance-als_0"/als.json" als; \ [2025-11-19T22:17:56.198Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17635905594377/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-11-19T22:17:56.198Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-11-19T22:17:56.198Z] echo "Nothing to be done for teardown."; \ [2025-11-19T22:17:56.198Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17635905594377/TestTargetResult"; [2025-11-19T22:17:56.965Z] [2025-11-19T22:17:56.965Z] TEST SETUP: [2025-11-19T22:17:56.965Z] Nothing to be done for setup. [2025-11-19T22:17:56.965Z] [2025-11-19T22:17:56.965Z] TESTING: [2025-11-19T22:18:05.269Z] NOTE: 'als' benchmark uses Spark local executor with 12 (out of 24) threads. [2025-11-19T22:18:10.938Z] WARNING: An illegal reflective access operation has occurred [2025-11-19T22:18:10.938Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/output_17635905594377/renaissance-als_0/harness-221757-9935629500880968730/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-11-19T22:18:10.938Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-11-19T22:18:10.938Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-11-19T22:18:10.938Z] WARNING: All illegal access operations will be denied in a future release [2025-11-19T22:18:11.741Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-11-19T22:18:12.515Z] GC before operation: completed in 77.496 ms, heap usage 216.108 MB -> 35.358 MB. [2025-11-19T22:18:29.962Z] ====== als (apache-spark) [default], iteration 0 completed (15087.872 ms) ====== [2025-11-19T22:18:29.962Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-11-19T22:18:29.962Z] GC before operation: completed in 118.265 ms, heap usage 345.824 MB -> 61.643 MB. [2025-11-19T22:18:34.617Z] ====== als (apache-spark) [default], iteration 1 completed (5800.639 ms) ====== [2025-11-19T22:18:34.617Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-11-19T22:18:34.617Z] GC before operation: completed in 139.637 ms, heap usage 790.058 MB -> 62.985 MB. [2025-11-19T22:18:40.886Z] ====== als (apache-spark) [default], iteration 2 completed (5721.468 ms) ====== [2025-11-19T22:18:40.886Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-11-19T22:18:40.886Z] GC before operation: completed in 129.751 ms, heap usage 411.822 MB -> 63.012 MB. [2025-11-19T22:18:46.487Z] ====== als (apache-spark) [default], iteration 3 completed (5593.625 ms) ====== [2025-11-19T22:18:46.488Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-11-19T22:18:46.488Z] GC before operation: completed in 134.835 ms, heap usage 508.143 MB -> 63.780 MB. [2025-11-19T22:18:52.086Z] ====== als (apache-spark) [default], iteration 4 completed (5289.889 ms) ====== [2025-11-19T22:18:52.086Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-11-19T22:18:52.086Z] GC before operation: completed in 133.889 ms, heap usage 405.555 MB -> 64.129 MB. [2025-11-19T22:18:57.699Z] ====== als (apache-spark) [default], iteration 5 completed (5496.851 ms) ====== [2025-11-19T22:18:57.699Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-11-19T22:18:58.476Z] GC before operation: completed in 137.672 ms, heap usage 373.532 MB -> 64.530 MB. [2025-11-19T22:19:07.769Z] ====== als (apache-spark) [default], iteration 6 completed (5444.914 ms) ====== [2025-11-19T22:19:07.769Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-11-19T22:19:07.769Z] GC before operation: completed in 150.388 ms, heap usage 761.517 MB -> 65.602 MB. [2025-11-19T22:19:09.358Z] ====== als (apache-spark) [default], iteration 7 completed (5367.431 ms) ====== [2025-11-19T22:19:09.358Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-11-19T22:19:10.129Z] GC before operation: completed in 132.317 ms, heap usage 362.072 MB -> 65.528 MB. [2025-11-19T22:19:17.468Z] ====== als (apache-spark) [default], iteration 8 completed (5530.582 ms) ====== [2025-11-19T22:19:17.468Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-11-19T22:19:17.468Z] GC before operation: completed in 131.856 ms, heap usage 301.203 MB -> 66.045 MB. [2025-11-19T22:19:21.155Z] ====== als (apache-spark) [default], iteration 9 completed (5328.084 ms) ====== [2025-11-19T22:19:21.155Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-11-19T22:19:21.155Z] GC before operation: completed in 141.790 ms, heap usage 645.786 MB -> 66.794 MB. [2025-11-19T22:19:26.931Z] ====== als (apache-spark) [default], iteration 10 completed (5296.952 ms) ====== [2025-11-19T22:19:26.931Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-11-19T22:19:26.931Z] GC before operation: completed in 149.545 ms, heap usage 1.167 GB -> 67.642 MB. [2025-11-19T22:19:32.530Z] ====== als (apache-spark) [default], iteration 11 completed (5203.480 ms) ====== [2025-11-19T22:19:32.530Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-11-19T22:19:32.530Z] GC before operation: completed in 169.352 ms, heap usage 564.397 MB -> 67.294 MB. [2025-11-19T22:19:58.080Z] ====== als (apache-spark) [default], iteration 12 completed (5410.444 ms) ====== [2025-11-19T22:19:58.080Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-11-19T22:19:58.080Z] GC before operation: completed in 140.816 ms, heap usage 515.897 MB -> 67.419 MB. [2025-11-19T22:19:58.080Z] ====== als (apache-spark) [default], iteration 13 completed (5327.306 ms) ====== [2025-11-19T22:19:58.080Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-11-19T22:19:58.080Z] GC before operation: completed in 171.958 ms, heap usage 1.429 GB -> 68.643 MB. [2025-11-19T22:19:58.080Z] ====== als (apache-spark) [default], iteration 14 completed (5404.377 ms) ====== [2025-11-19T22:19:58.080Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-11-19T22:19:58.080Z] GC before operation: completed in 181.538 ms, heap usage 1.681 GB -> 69.071 MB. [2025-11-19T22:19:58.080Z] ====== als (apache-spark) [default], iteration 15 completed (5194.391 ms) ====== [2025-11-19T22:19:58.080Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-11-19T22:19:58.080Z] GC before operation: completed in 152.176 ms, heap usage 667.555 MB -> 68.433 MB. [2025-11-19T22:20:01.520Z] ====== als (apache-spark) [default], iteration 16 completed (5275.797 ms) ====== [2025-11-19T22:20:01.520Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-11-19T22:20:01.520Z] GC before operation: completed in 156.416 ms, heap usage 201.309 MB -> 67.995 MB. [2025-11-19T22:20:07.118Z] ====== als (apache-spark) [default], iteration 17 completed (5334.180 ms) ====== [2025-11-19T22:20:07.118Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-11-19T22:20:07.118Z] GC before operation: completed in 175.373 ms, heap usage 1.196 GB -> 69.496 MB. [2025-11-19T22:20:12.750Z] ====== als (apache-spark) [default], iteration 18 completed (5350.965 ms) ====== [2025-11-19T22:20:12.750Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-11-19T22:20:12.751Z] GC before operation: completed in 161.087 ms, heap usage 928.027 MB -> 69.399 MB. [2025-11-19T22:20:18.366Z] ====== als (apache-spark) [default], iteration 19 completed (5375.074 ms) ====== [2025-11-19T22:20:18.366Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-11-19T22:20:18.366Z] GC before operation: completed in 172.660 ms, heap usage 1016.916 MB -> 69.776 MB. [2025-11-19T22:20:23.986Z] ====== als (apache-spark) [default], iteration 20 completed (5338.158 ms) ====== [2025-11-19T22:20:23.986Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-11-19T22:20:23.986Z] GC before operation: completed in 161.351 ms, heap usage 473.753 MB -> 69.205 MB. [2025-11-19T22:20:29.886Z] ====== als (apache-spark) [default], iteration 21 completed (5163.668 ms) ====== [2025-11-19T22:20:29.886Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-11-19T22:20:29.886Z] GC before operation: completed in 175.503 ms, heap usage 1.725 GB -> 70.949 MB. [2025-11-19T22:20:35.533Z] ====== als (apache-spark) [default], iteration 22 completed (5164.707 ms) ====== [2025-11-19T22:20:35.533Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-11-19T22:20:35.533Z] GC before operation: completed in 164.381 ms, heap usage 771.510 MB -> 70.222 MB. [2025-11-19T22:20:41.203Z] ====== als (apache-spark) [default], iteration 23 completed (5370.989 ms) ====== [2025-11-19T22:20:41.203Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-11-19T22:20:41.203Z] GC before operation: completed in 158.568 ms, heap usage 777.382 MB -> 70.505 MB. [2025-11-19T22:20:46.880Z] ====== als (apache-spark) [default], iteration 24 completed (5407.090 ms) ====== [2025-11-19T22:20:46.880Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-11-19T22:20:46.880Z] GC before operation: completed in 165.458 ms, heap usage 149.815 MB -> 70.081 MB. [2025-11-19T22:20:52.576Z] ====== als (apache-spark) [default], iteration 25 completed (5208.027 ms) ====== [2025-11-19T22:20:52.576Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-11-19T22:20:52.576Z] GC before operation: completed in 210.571 ms, heap usage 1.062 GB -> 71.355 MB. [2025-11-19T22:21:01.589Z] ====== als (apache-spark) [default], iteration 26 completed (5323.261 ms) ====== [2025-11-19T22:21:01.589Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-11-19T22:21:01.589Z] GC before operation: completed in 164.673 ms, heap usage 1.006 GB -> 71.586 MB. [2025-11-19T22:21:04.097Z] ====== als (apache-spark) [default], iteration 27 completed (5255.480 ms) ====== [2025-11-19T22:21:04.097Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-11-19T22:21:04.097Z] GC before operation: completed in 169.406 ms, heap usage 592.850 MB -> 70.842 MB. [2025-11-19T22:21:09.721Z] ====== als (apache-spark) [default], iteration 28 completed (5199.519 ms) ====== [2025-11-19T22:21:09.721Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-11-19T22:21:09.721Z] GC before operation: completed in 187.624 ms, heap usage 307.382 MB -> 70.829 MB. [2025-11-19T22:21:15.384Z] ====== als (apache-spark) [default], iteration 29 completed (5263.123 ms) ====== [2025-11-19T22:21:15.384Z] ----------------------------------- [2025-11-19T22:21:15.384Z] renaissance-als_0_PASSED [2025-11-19T22:21:15.384Z] ----------------------------------- [2025-11-19T22:21:15.384Z] [2025-11-19T22:21:15.384Z] TEST TEARDOWN: [2025-11-19T22:21:15.384Z] Nothing to be done for teardown. [2025-11-19T22:21:15.384Z] renaissance-als_0 Finish Time: Wed Nov 19 22:21:15 2025 Epoch Time (ms): 1763590875115