[2025-07-16T04:00:26.992Z] Running test renaissance-als_0 ... [2025-07-16T04:00:26.992Z] =============================================== [2025-07-16T04:00:26.992Z] renaissance-als_0 Start Time: Wed Jul 16 04:00:26 2025 Epoch Time (ms): 1752638426426 [2025-07-16T04:00:26.992Z] variation: NoOptions [2025-07-16T04:00:26.992Z] JVM_OPTIONS: [2025-07-16T04:00:26.992Z] { \ [2025-07-16T04:00:26.992Z] echo ""; echo "TEST SETUP:"; \ [2025-07-16T04:00:26.992Z] echo "Nothing to be done for setup."; \ [2025-07-16T04:00:26.992Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_1752638361825/renaissance-als_0"; \ [2025-07-16T04:00:26.992Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_1752638361825/renaissance-als_0"; \ [2025-07-16T04:00:26.992Z] echo ""; echo "TESTING:"; \ [2025-07-16T04:00:26.992Z] "/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_1752638361825/renaissance-als_0"/als.json" als; \ [2025-07-16T04:00:26.992Z] 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_1752638361825/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-07-16T04:00:26.992Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-07-16T04:00:26.992Z] echo "Nothing to be done for teardown."; \ [2025-07-16T04:00:26.992Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_1752638361825/TestTargetResult"; [2025-07-16T04:00:26.992Z] [2025-07-16T04:00:26.992Z] TEST SETUP: [2025-07-16T04:00:26.992Z] Nothing to be done for setup. [2025-07-16T04:00:26.992Z] [2025-07-16T04:00:26.992Z] TESTING: [2025-07-16T04:01:34.098Z] NOTE: 'als' benchmark uses Spark local executor with 12 (out of 16) threads. [2025-07-16T04:01:35.366Z] WARNING: An illegal reflective access operation has occurred [2025-07-16T04:01:35.366Z] 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_1752638361825/renaissance-als_0/harness-040029-12211686266631026661/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-07-16T04:01:35.366Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-07-16T04:01:35.366Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-07-16T04:01:35.366Z] WARNING: All illegal access operations will be denied in a future release [2025-07-16T04:01:38.795Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-07-16T04:01:39.566Z] GC before operation: completed in 201.173 ms, heap usage 78.982 MB -> 35.111 MB. [2025-07-16T04:02:20.957Z] ====== als (apache-spark) [default], iteration 0 completed (36281.765 ms) ====== [2025-07-16T04:02:20.957Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-07-16T04:02:20.957Z] GC before operation: completed in 130.026 ms, heap usage 350.098 MB -> 61.366 MB. [2025-07-16T04:02:39.837Z] ====== als (apache-spark) [default], iteration 1 completed (21768.358 ms) ====== [2025-07-16T04:02:39.837Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-07-16T04:02:39.837Z] GC before operation: completed in 148.907 ms, heap usage 1.935 GB -> 63.716 MB. [2025-07-16T04:03:15.115Z] ====== als (apache-spark) [default], iteration 2 completed (31301.544 ms) ====== [2025-07-16T04:03:15.116Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-07-16T04:03:15.116Z] GC before operation: completed in 177.832 ms, heap usage 423.939 MB -> 62.701 MB. [2025-07-16T04:03:50.400Z] ====== als (apache-spark) [default], iteration 3 completed (36161.573 ms) ====== [2025-07-16T04:03:50.400Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-07-16T04:03:50.400Z] GC before operation: completed in 142.773 ms, heap usage 608.050 MB -> 63.531 MB. [2025-07-16T04:04:20.740Z] ====== als (apache-spark) [default], iteration 4 completed (32141.787 ms) ====== [2025-07-16T04:04:20.740Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-07-16T04:04:20.740Z] GC before operation: completed in 154.908 ms, heap usage 262.343 MB -> 63.621 MB. [2025-07-16T04:04:46.800Z] ====== als (apache-spark) [default], iteration 5 completed (23371.498 ms) ====== [2025-07-16T04:04:46.800Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-07-16T04:04:46.800Z] GC before operation: completed in 197.173 ms, heap usage 639.325 MB -> 64.591 MB. [2025-07-16T04:05:05.701Z] ====== als (apache-spark) [default], iteration 6 completed (20766.345 ms) ====== [2025-07-16T04:05:05.701Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-07-16T04:05:05.701Z] GC before operation: completed in 173.370 ms, heap usage 228.397 MB -> 64.541 MB. [2025-07-16T04:05:27.788Z] ====== als (apache-spark) [default], iteration 7 completed (20540.795 ms) ====== [2025-07-16T04:05:27.788Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-07-16T04:05:27.788Z] GC before operation: completed in 198.028 ms, heap usage 174.244 MB -> 65.081 MB. [2025-07-16T04:05:58.041Z] ====== als (apache-spark) [default], iteration 8 completed (30484.614 ms) ====== [2025-07-16T04:05:58.041Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-07-16T04:05:58.041Z] GC before operation: completed in 186.362 ms, heap usage 128.373 MB -> 65.603 MB. [2025-07-16T04:06:20.117Z] ====== als (apache-spark) [default], iteration 9 completed (21193.649 ms) ====== [2025-07-16T04:06:20.117Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-07-16T04:06:20.117Z] GC before operation: completed in 145.438 ms, heap usage 702.089 MB -> 66.592 MB. [2025-07-16T04:06:50.319Z] ====== als (apache-spark) [default], iteration 10 completed (29808.152 ms) ====== [2025-07-16T04:06:50.319Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-07-16T04:06:50.319Z] GC before operation: completed in 154.895 ms, heap usage 164.129 MB -> 65.712 MB. [2025-07-16T04:07:26.532Z] ====== als (apache-spark) [default], iteration 11 completed (33436.246 ms) ====== [2025-07-16T04:07:26.532Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-07-16T04:07:26.532Z] GC before operation: completed in 164.469 ms, heap usage 163.572 MB -> 66.419 MB. [2025-07-16T04:07:45.478Z] ====== als (apache-spark) [default], iteration 12 completed (22850.203 ms) ====== [2025-07-16T04:07:45.478Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-07-16T04:07:46.249Z] GC before operation: completed in 185.495 ms, heap usage 969.698 MB -> 67.518 MB. [2025-07-16T04:08:21.551Z] ====== als (apache-spark) [default], iteration 13 completed (35416.097 ms) ====== [2025-07-16T04:08:21.551Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-07-16T04:08:21.551Z] GC before operation: completed in 152.929 ms, heap usage 274.587 MB -> 67.039 MB. [2025-07-16T04:08:40.548Z] ====== als (apache-spark) [default], iteration 14 completed (18807.284 ms) ====== [2025-07-16T04:08:40.548Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-07-16T04:08:41.390Z] GC before operation: completed in 219.197 ms, heap usage 1.344 GB -> 68.371 MB. [2025-07-16T04:09:00.335Z] ====== als (apache-spark) [default], iteration 15 completed (19501.053 ms) ====== [2025-07-16T04:09:00.335Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-07-16T04:09:01.112Z] GC before operation: completed in 171.638 ms, heap usage 211.107 MB -> 66.989 MB. [2025-07-16T04:09:23.350Z] ====== als (apache-spark) [default], iteration 16 completed (20185.070 ms) ====== [2025-07-16T04:09:23.350Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-07-16T04:09:23.350Z] GC before operation: completed in 209.707 ms, heap usage 815.733 MB -> 68.502 MB. [2025-07-16T04:09:49.332Z] ====== als (apache-spark) [default], iteration 17 completed (24553.642 ms) ====== [2025-07-16T04:09:49.332Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-07-16T04:09:49.332Z] GC before operation: completed in 189.313 ms, heap usage 331.769 MB -> 68.190 MB. [2025-07-16T04:10:08.285Z] ====== als (apache-spark) [default], iteration 18 completed (21162.107 ms) ====== [2025-07-16T04:10:08.285Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-07-16T04:10:08.285Z] GC before operation: completed in 191.410 ms, heap usage 600.164 MB -> 68.765 MB. [2025-07-16T04:10:38.951Z] ====== als (apache-spark) [default], iteration 19 completed (28301.812 ms) ====== [2025-07-16T04:10:38.951Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-07-16T04:10:38.951Z] GC before operation: completed in 245.604 ms, heap usage 730.410 MB -> 69.121 MB. [2025-07-16T04:10:57.893Z] ====== als (apache-spark) [default], iteration 20 completed (20991.149 ms) ====== [2025-07-16T04:10:57.893Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-07-16T04:10:57.893Z] GC before operation: completed in 152.961 ms, heap usage 307.877 MB -> 68.831 MB. [2025-07-16T04:11:20.064Z] ====== als (apache-spark) [default], iteration 21 completed (19451.827 ms) ====== [2025-07-16T04:11:20.064Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-07-16T04:11:20.064Z] GC before operation: completed in 164.075 ms, heap usage 260.563 MB -> 69.115 MB. [2025-07-16T04:11:42.146Z] ====== als (apache-spark) [default], iteration 22 completed (23312.075 ms) ====== [2025-07-16T04:11:42.146Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-07-16T04:11:42.146Z] GC before operation: completed in 220.747 ms, heap usage 291.456 MB -> 69.365 MB. [2025-07-16T04:12:04.208Z] ====== als (apache-spark) [default], iteration 23 completed (20622.700 ms) ====== [2025-07-16T04:12:04.208Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-07-16T04:12:04.208Z] GC before operation: completed in 246.233 ms, heap usage 167.800 MB -> 70.684 MB. [2025-07-16T04:12:30.407Z] ====== als (apache-spark) [default], iteration 24 completed (25054.694 ms) ====== [2025-07-16T04:12:30.407Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-07-16T04:12:30.407Z] GC before operation: completed in 192.498 ms, heap usage 491.159 MB -> 70.195 MB. [2025-07-16T04:13:02.916Z] ====== als (apache-spark) [default], iteration 25 completed (31562.852 ms) ====== [2025-07-16T04:13:02.916Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-07-16T04:13:02.916Z] GC before operation: completed in 253.510 ms, heap usage 781.672 MB -> 70.640 MB. [2025-07-16T04:13:28.791Z] ====== als (apache-spark) [default], iteration 26 completed (24634.761 ms) ====== [2025-07-16T04:13:28.791Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-07-16T04:13:28.791Z] GC before operation: completed in 190.960 ms, heap usage 349.522 MB -> 70.467 MB. [2025-07-16T04:13:50.878Z] ====== als (apache-spark) [default], iteration 27 completed (24413.165 ms) ====== [2025-07-16T04:13:50.878Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-07-16T04:13:50.878Z] GC before operation: completed in 200.769 ms, heap usage 355.033 MB -> 70.718 MB. [2025-07-16T04:14:21.236Z] ====== als (apache-spark) [default], iteration 28 completed (28500.517 ms) ====== [2025-07-16T04:14:21.236Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-07-16T04:14:21.236Z] GC before operation: completed in 194.011 ms, heap usage 688.969 MB -> 71.280 MB. [2025-07-16T04:14:43.493Z] ====== als (apache-spark) [default], iteration 29 completed (23232.227 ms) ====== [2025-07-16T04:14:43.493Z] ----------------------------------- [2025-07-16T04:14:43.493Z] renaissance-als_0_PASSED [2025-07-16T04:14:43.493Z] ----------------------------------- [2025-07-16T04:14:43.493Z] [2025-07-16T04:14:43.493Z] TEST TEARDOWN: [2025-07-16T04:14:43.493Z] Nothing to be done for teardown. [2025-07-16T04:14:43.493Z] renaissance-als_0 Finish Time: Wed Jul 16 04:14:43 2025 Epoch Time (ms): 1752639283258