[2025-05-17T01:34:24.916Z] Running test renaissance-als_0 ... [2025-05-17T01:34:24.916Z] =============================================== [2025-05-17T01:34:24.916Z] renaissance-als_0 Start Time: Sat May 17 01:34:24 2025 Epoch Time (ms): 1747445664418 [2025-05-17T01:34:24.916Z] variation: NoOptions [2025-05-17T01:34:24.916Z] JVM_OPTIONS: [2025-05-17T01:34:24.916Z] { \ [2025-05-17T01:34:24.916Z] echo ""; echo "TEST SETUP:"; \ [2025-05-17T01:34:24.916Z] echo "Nothing to be done for setup."; \ [2025-05-17T01:34:24.916Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17474456177388/renaissance-als_0"; \ [2025-05-17T01:34:24.916Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17474456177388/renaissance-als_0"; \ [2025-05-17T01:34:24.916Z] echo ""; echo "TESTING:"; \ [2025-05-17T01:34:24.916Z] "/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_17474456177388/renaissance-als_0"/als.json" als; \ [2025-05-17T01:34:24.916Z] 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_17474456177388/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-05-17T01:34:24.916Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-05-17T01:34:24.916Z] echo "Nothing to be done for teardown."; \ [2025-05-17T01:34:24.916Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17474456177388/TestTargetResult"; [2025-05-17T01:34:24.916Z] [2025-05-17T01:34:24.916Z] TEST SETUP: [2025-05-17T01:34:24.916Z] Nothing to be done for setup. [2025-05-17T01:34:24.916Z] [2025-05-17T01:34:24.916Z] TESTING: [2025-05-17T01:34:34.732Z] NOTE: 'als' benchmark uses Spark local executor with 12 (out of 24) threads. [2025-05-17T01:34:38.129Z] WARNING: An illegal reflective access operation has occurred [2025-05-17T01:34:38.129Z] 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_17474456177388/renaissance-als_0/harness-013425-17286871420920023266/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-05-17T01:34:38.129Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-05-17T01:34:38.129Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-05-17T01:34:38.129Z] WARNING: All illegal access operations will be denied in a future release [2025-05-17T01:34:40.579Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-05-17T01:34:40.579Z] GC before operation: completed in 84.310 ms, heap usage 90.368 MB -> 35.302 MB. [2025-05-17T01:34:56.632Z] ====== als (apache-spark) [default], iteration 0 completed (15898.334 ms) ====== [2025-05-17T01:34:56.632Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-05-17T01:34:57.396Z] GC before operation: completed in 118.811 ms, heap usage 382.311 MB -> 61.685 MB. [2025-05-17T01:35:04.240Z] ====== als (apache-spark) [default], iteration 1 completed (6171.869 ms) ====== [2025-05-17T01:35:04.240Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-05-17T01:35:04.240Z] GC before operation: completed in 139.341 ms, heap usage 901.911 MB -> 63.115 MB. [2025-05-17T01:35:09.827Z] ====== als (apache-spark) [default], iteration 2 completed (5632.153 ms) ====== [2025-05-17T01:35:09.827Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-05-17T01:35:09.827Z] GC before operation: completed in 137.138 ms, heap usage 746.367 MB -> 63.406 MB. [2025-05-17T01:35:15.517Z] ====== als (apache-spark) [default], iteration 3 completed (5589.951 ms) ====== [2025-05-17T01:35:15.517Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-05-17T01:35:15.517Z] GC before operation: completed in 148.118 ms, heap usage 649.997 MB -> 63.913 MB. [2025-05-17T01:35:22.350Z] ====== als (apache-spark) [default], iteration 4 completed (5539.459 ms) ====== [2025-05-17T01:35:22.350Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-05-17T01:35:22.350Z] GC before operation: completed in 141.949 ms, heap usage 1.241 GB -> 65.017 MB. [2025-05-17T01:35:27.924Z] ====== als (apache-spark) [default], iteration 5 completed (5504.344 ms) ====== [2025-05-17T01:35:27.924Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-05-17T01:35:27.924Z] GC before operation: completed in 142.118 ms, heap usage 1.117 GB -> 65.543 MB. [2025-05-17T01:35:33.516Z] ====== als (apache-spark) [default], iteration 6 completed (5521.500 ms) ====== [2025-05-17T01:35:33.517Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-05-17T01:35:33.517Z] GC before operation: completed in 147.148 ms, heap usage 875.674 MB -> 65.716 MB. [2025-05-17T01:35:40.348Z] ====== als (apache-spark) [default], iteration 7 completed (5569.371 ms) ====== [2025-05-17T01:35:40.348Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-05-17T01:35:40.348Z] GC before operation: completed in 142.478 ms, heap usage 510.145 MB -> 65.729 MB. [2025-05-17T01:35:45.922Z] ====== als (apache-spark) [default], iteration 8 completed (5435.230 ms) ====== [2025-05-17T01:35:45.923Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-05-17T01:35:45.923Z] GC before operation: completed in 144.622 ms, heap usage 375.275 MB -> 66.182 MB. [2025-05-17T01:35:51.496Z] ====== als (apache-spark) [default], iteration 9 completed (5349.360 ms) ====== [2025-05-17T01:35:51.496Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-05-17T01:35:51.496Z] GC before operation: completed in 156.796 ms, heap usage 1.211 GB -> 67.757 MB. [2025-05-17T01:35:57.087Z] ====== als (apache-spark) [default], iteration 10 completed (5425.404 ms) ====== [2025-05-17T01:35:57.087Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-05-17T01:35:57.087Z] GC before operation: completed in 150.004 ms, heap usage 870.312 MB -> 67.222 MB. [2025-05-17T01:36:02.671Z] ====== als (apache-spark) [default], iteration 11 completed (5280.056 ms) ====== [2025-05-17T01:36:02.671Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-05-17T01:36:02.671Z] GC before operation: completed in 154.015 ms, heap usage 491.736 MB -> 67.105 MB. [2025-05-17T01:36:27.621Z] ====== als (apache-spark) [default], iteration 12 completed (5573.589 ms) ====== [2025-05-17T01:36:27.621Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-05-17T01:36:27.621Z] GC before operation: completed in 153.948 ms, heap usage 917.432 MB -> 67.832 MB. [2025-05-17T01:36:27.621Z] ====== als (apache-spark) [default], iteration 13 completed (5300.200 ms) ====== [2025-05-17T01:36:27.621Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-05-17T01:36:27.621Z] GC before operation: completed in 147.788 ms, heap usage 487.552 MB -> 67.775 MB. [2025-05-17T01:36:27.621Z] ====== als (apache-spark) [default], iteration 14 completed (5526.759 ms) ====== [2025-05-17T01:36:27.621Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-05-17T01:36:27.621Z] GC before operation: completed in 162.089 ms, heap usage 935.538 MB -> 68.426 MB. [2025-05-17T01:36:27.622Z] ====== als (apache-spark) [default], iteration 15 completed (5449.783 ms) ====== [2025-05-17T01:36:27.622Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-05-17T01:36:27.622Z] GC before operation: completed in 197.870 ms, heap usage 804.093 MB -> 68.591 MB. [2025-05-17T01:36:32.061Z] ====== als (apache-spark) [default], iteration 16 completed (5558.757 ms) ====== [2025-05-17T01:36:32.061Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-05-17T01:36:32.061Z] GC before operation: completed in 154.454 ms, heap usage 867.965 MB -> 68.858 MB. [2025-05-17T01:36:37.640Z] ====== als (apache-spark) [default], iteration 17 completed (5458.220 ms) ====== [2025-05-17T01:36:37.640Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-05-17T01:36:37.640Z] GC before operation: completed in 158.433 ms, heap usage 711.809 MB -> 68.978 MB. [2025-05-17T01:36:43.199Z] ====== als (apache-spark) [default], iteration 18 completed (5454.072 ms) ====== [2025-05-17T01:36:43.199Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-05-17T01:36:43.968Z] GC before operation: completed in 174.778 ms, heap usage 399.214 MB -> 69.001 MB. [2025-05-17T01:36:49.544Z] ====== als (apache-spark) [default], iteration 19 completed (5403.579 ms) ====== [2025-05-17T01:36:49.544Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-05-17T01:36:49.544Z] GC before operation: completed in 164.925 ms, heap usage 281.167 MB -> 68.760 MB. [2025-05-17T01:36:55.130Z] ====== als (apache-spark) [default], iteration 20 completed (5308.279 ms) ====== [2025-05-17T01:36:55.130Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-05-17T01:36:55.130Z] GC before operation: completed in 148.830 ms, heap usage 145.879 MB -> 69.038 MB. [2025-05-17T01:37:00.711Z] ====== als (apache-spark) [default], iteration 21 completed (5360.494 ms) ====== [2025-05-17T01:37:00.711Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-05-17T01:37:00.711Z] GC before operation: completed in 150.126 ms, heap usage 334.282 MB -> 69.498 MB. [2025-05-17T01:37:06.281Z] ====== als (apache-spark) [default], iteration 22 completed (5387.585 ms) ====== [2025-05-17T01:37:06.281Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-05-17T01:37:07.045Z] GC before operation: completed in 187.130 ms, heap usage 289.496 MB -> 69.676 MB. [2025-05-17T01:37:12.730Z] ====== als (apache-spark) [default], iteration 23 completed (5489.107 ms) ====== [2025-05-17T01:37:12.730Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-05-17T01:37:12.730Z] GC before operation: completed in 175.179 ms, heap usage 484.546 MB -> 70.313 MB. [2025-05-17T01:37:18.313Z] ====== als (apache-spark) [default], iteration 24 completed (5368.927 ms) ====== [2025-05-17T01:37:18.313Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-05-17T01:37:18.313Z] GC before operation: completed in 155.859 ms, heap usage 856.126 MB -> 70.891 MB. [2025-05-17T01:37:23.897Z] ====== als (apache-spark) [default], iteration 25 completed (5401.832 ms) ====== [2025-05-17T01:37:23.897Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-05-17T01:37:23.897Z] GC before operation: completed in 186.121 ms, heap usage 2.127 GB -> 72.359 MB. [2025-05-17T01:37:29.472Z] ====== als (apache-spark) [default], iteration 26 completed (5292.427 ms) ====== [2025-05-17T01:37:29.472Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-05-17T01:37:30.237Z] GC before operation: completed in 189.877 ms, heap usage 2.066 GB -> 72.608 MB. [2025-05-17T01:37:35.803Z] ====== als (apache-spark) [default], iteration 27 completed (5178.976 ms) ====== [2025-05-17T01:37:35.803Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-05-17T01:37:35.803Z] GC before operation: completed in 158.837 ms, heap usage 273.493 MB -> 70.352 MB. [2025-05-17T01:37:41.367Z] ====== als (apache-spark) [default], iteration 28 completed (5308.456 ms) ====== [2025-05-17T01:37:41.368Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-05-17T01:37:41.368Z] GC before operation: completed in 179.416 ms, heap usage 415.745 MB -> 70.888 MB. [2025-05-17T01:37:46.938Z] ====== als (apache-spark) [default], iteration 29 completed (5350.075 ms) ====== [2025-05-17T01:37:46.938Z] ----------------------------------- [2025-05-17T01:37:46.938Z] renaissance-als_0_PASSED [2025-05-17T01:37:46.938Z] ----------------------------------- [2025-05-17T01:37:47.714Z] [2025-05-17T01:37:47.714Z] TEST TEARDOWN: [2025-05-17T01:37:47.714Z] Nothing to be done for teardown. [2025-05-17T01:37:47.714Z] renaissance-als_0 Finish Time: Sat May 17 01:37:46 2025 Epoch Time (ms): 1747445866907