[2025-05-29T02:18:50.844Z] Running test renaissance-als_0 ... [2025-05-29T02:18:50.844Z] =============================================== [2025-05-29T02:18:50.844Z] renaissance-als_0 Start Time: Thu May 29 02:18:50 2025 Epoch Time (ms): 1748485130422 [2025-05-29T02:18:50.844Z] variation: NoOptions [2025-05-29T02:18:50.844Z] JVM_OPTIONS: [2025-05-29T02:18:50.844Z] { \ [2025-05-29T02:18:50.844Z] echo ""; echo "TEST SETUP:"; \ [2025-05-29T02:18:50.844Z] echo "Nothing to be done for setup."; \ [2025-05-29T02:18:50.844Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17484850835836/renaissance-als_0"; \ [2025-05-29T02:18:50.844Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17484850835836/renaissance-als_0"; \ [2025-05-29T02:18:50.844Z] echo ""; echo "TESTING:"; \ [2025-05-29T02:18:50.844Z] "/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_17484850835836/renaissance-als_0"/als.json" als; \ [2025-05-29T02:18:50.844Z] 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_17484850835836/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-05-29T02:18:50.844Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-05-29T02:18:50.844Z] echo "Nothing to be done for teardown."; \ [2025-05-29T02:18:50.844Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17484850835836/TestTargetResult"; [2025-05-29T02:18:50.844Z] [2025-05-29T02:18:50.844Z] TEST SETUP: [2025-05-29T02:18:50.844Z] Nothing to be done for setup. [2025-05-29T02:18:50.844Z] [2025-05-29T02:18:50.844Z] TESTING: [2025-05-29T02:19:00.671Z] NOTE: 'als' benchmark uses Spark local executor with 12 (out of 24) threads. [2025-05-29T02:19:04.077Z] WARNING: An illegal reflective access operation has occurred [2025-05-29T02:19:04.077Z] 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_17484850835836/renaissance-als_0/harness-021851-16418167379355116302/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-05-29T02:19:04.077Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-05-29T02:19:04.077Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-05-29T02:19:04.077Z] WARNING: All illegal access operations will be denied in a future release [2025-05-29T02:19:05.657Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-05-29T02:19:05.657Z] GC before operation: completed in 89.339 ms, heap usage 255.002 MB -> 35.382 MB. [2025-05-29T02:19:21.720Z] ====== als (apache-spark) [default], iteration 0 completed (14710.290 ms) ====== [2025-05-29T02:19:21.720Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-05-29T02:19:21.720Z] GC before operation: completed in 120.196 ms, heap usage 369.013 MB -> 61.547 MB. [2025-05-29T02:19:28.583Z] ====== als (apache-spark) [default], iteration 1 completed (5961.439 ms) ====== [2025-05-29T02:19:28.583Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-05-29T02:19:28.583Z] GC before operation: completed in 124.585 ms, heap usage 833.690 MB -> 63.009 MB. [2025-05-29T02:19:34.150Z] ====== als (apache-spark) [default], iteration 2 completed (5740.164 ms) ====== [2025-05-29T02:19:34.150Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-05-29T02:19:34.150Z] GC before operation: completed in 148.682 ms, heap usage 142.882 MB -> 63.192 MB. [2025-05-29T02:19:40.979Z] ====== als (apache-spark) [default], iteration 3 completed (5664.149 ms) ====== [2025-05-29T02:19:40.979Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-05-29T02:19:40.979Z] GC before operation: completed in 131.954 ms, heap usage 283.192 MB -> 63.429 MB. [2025-05-29T02:19:46.600Z] ====== als (apache-spark) [default], iteration 4 completed (5730.450 ms) ====== [2025-05-29T02:19:46.600Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-05-29T02:19:46.600Z] GC before operation: completed in 145.477 ms, heap usage 600.096 MB -> 64.380 MB. [2025-05-29T02:19:52.181Z] ====== als (apache-spark) [default], iteration 5 completed (5679.345 ms) ====== [2025-05-29T02:19:52.181Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-05-29T02:19:52.945Z] GC before operation: completed in 154.850 ms, heap usage 1.656 GB -> 65.983 MB. [2025-05-29T02:19:58.517Z] ====== als (apache-spark) [default], iteration 6 completed (5541.071 ms) ====== [2025-05-29T02:19:58.517Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-05-29T02:19:58.517Z] GC before operation: completed in 164.338 ms, heap usage 1.450 GB -> 66.363 MB. [2025-05-29T02:20:04.090Z] ====== als (apache-spark) [default], iteration 7 completed (5454.996 ms) ====== [2025-05-29T02:20:04.090Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-05-29T02:20:04.090Z] GC before operation: completed in 137.345 ms, heap usage 816.871 MB -> 66.258 MB. [2025-05-29T02:20:10.914Z] ====== als (apache-spark) [default], iteration 8 completed (5602.179 ms) ====== [2025-05-29T02:20:10.914Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-05-29T02:20:10.914Z] GC before operation: completed in 179.597 ms, heap usage 1.465 GB -> 67.393 MB. [2025-05-29T02:20:16.502Z] ====== als (apache-spark) [default], iteration 9 completed (5436.252 ms) ====== [2025-05-29T02:20:16.502Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-05-29T02:20:16.502Z] GC before operation: completed in 146.498 ms, heap usage 547.214 MB -> 66.670 MB. [2025-05-29T02:20:22.075Z] ====== als (apache-spark) [default], iteration 10 completed (5456.732 ms) ====== [2025-05-29T02:20:22.075Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-05-29T02:20:22.075Z] GC before operation: completed in 141.772 ms, heap usage 1.001 GB -> 67.501 MB. [2025-05-29T02:20:27.638Z] ====== als (apache-spark) [default], iteration 11 completed (5426.008 ms) ====== [2025-05-29T02:20:27.638Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-05-29T02:20:27.638Z] GC before operation: completed in 167.694 ms, heap usage 1.665 GB -> 68.352 MB. [2025-05-29T02:20:34.462Z] ====== als (apache-spark) [default], iteration 12 completed (5546.364 ms) ====== [2025-05-29T02:20:34.462Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-05-29T02:20:34.462Z] GC before operation: completed in 183.161 ms, heap usage 220.285 MB -> 67.072 MB. [2025-05-29T02:20:40.034Z] ====== als (apache-spark) [default], iteration 13 completed (5308.017 ms) ====== [2025-05-29T02:20:40.034Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-05-29T02:20:40.034Z] GC before operation: completed in 149.525 ms, heap usage 613.052 MB -> 67.802 MB. [2025-05-29T02:20:45.592Z] ====== als (apache-spark) [default], iteration 14 completed (5487.633 ms) ====== [2025-05-29T02:20:45.592Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-05-29T02:20:45.592Z] GC before operation: completed in 166.695 ms, heap usage 1.070 GB -> 68.591 MB. [2025-05-29T02:20:51.179Z] ====== als (apache-spark) [default], iteration 15 completed (5473.263 ms) ====== [2025-05-29T02:20:51.179Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-05-29T02:20:51.179Z] GC before operation: completed in 181.221 ms, heap usage 1.729 GB -> 69.590 MB. [2025-05-29T02:20:56.751Z] ====== als (apache-spark) [default], iteration 16 completed (5378.936 ms) ====== [2025-05-29T02:20:56.751Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-05-29T02:20:57.516Z] GC before operation: completed in 176.066 ms, heap usage 1.819 GB -> 69.782 MB. [2025-05-29T02:21:03.105Z] ====== als (apache-spark) [default], iteration 17 completed (5446.247 ms) ====== [2025-05-29T02:21:03.105Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-05-29T02:21:03.105Z] GC before operation: completed in 165.881 ms, heap usage 531.971 MB -> 68.703 MB. [2025-05-29T02:21:08.680Z] ====== als (apache-spark) [default], iteration 18 completed (5345.041 ms) ====== [2025-05-29T02:21:08.680Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-05-29T02:21:08.680Z] GC before operation: completed in 176.849 ms, heap usage 234.601 MB -> 68.555 MB. [2025-05-29T02:21:14.247Z] ====== als (apache-spark) [default], iteration 19 completed (5470.918 ms) ====== [2025-05-29T02:21:14.247Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-05-29T02:21:15.010Z] GC before operation: completed in 166.999 ms, heap usage 1.474 GB -> 70.209 MB. [2025-05-29T02:21:20.579Z] ====== als (apache-spark) [default], iteration 20 completed (5457.169 ms) ====== [2025-05-29T02:21:20.579Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-05-29T02:21:20.579Z] GC before operation: completed in 165.728 ms, heap usage 901.448 MB -> 69.925 MB. [2025-05-29T02:21:26.156Z] ====== als (apache-spark) [default], iteration 21 completed (5229.859 ms) ====== [2025-05-29T02:21:26.156Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-05-29T02:21:26.156Z] GC before operation: completed in 170.665 ms, heap usage 610.333 MB -> 69.904 MB. [2025-05-29T02:21:31.723Z] ====== als (apache-spark) [default], iteration 22 completed (5495.667 ms) ====== [2025-05-29T02:21:31.724Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-05-29T02:21:31.724Z] GC before operation: completed in 142.225 ms, heap usage 554.645 MB -> 70.106 MB. [2025-05-29T02:21:37.298Z] ====== als (apache-spark) [default], iteration 23 completed (5445.905 ms) ====== [2025-05-29T02:21:37.298Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-05-29T02:21:38.063Z] GC before operation: completed in 206.803 ms, heap usage 358.581 MB -> 70.041 MB. [2025-05-29T02:21:43.627Z] ====== als (apache-spark) [default], iteration 24 completed (5261.363 ms) ====== [2025-05-29T02:21:43.627Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-05-29T02:21:43.627Z] GC before operation: completed in 183.043 ms, heap usage 915.576 MB -> 70.904 MB. [2025-05-29T02:21:49.255Z] ====== als (apache-spark) [default], iteration 25 completed (5297.510 ms) ====== [2025-05-29T02:21:49.255Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-05-29T02:21:49.255Z] GC before operation: completed in 161.581 ms, heap usage 868.642 MB -> 71.066 MB. [2025-05-29T02:21:54.825Z] ====== als (apache-spark) [default], iteration 26 completed (5513.392 ms) ====== [2025-05-29T02:21:54.825Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-05-29T02:21:54.825Z] GC before operation: completed in 180.741 ms, heap usage 352.869 MB -> 70.788 MB. [2025-05-29T02:22:00.391Z] ====== als (apache-spark) [default], iteration 27 completed (5376.715 ms) ====== [2025-05-29T02:22:00.392Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-05-29T02:22:01.154Z] GC before operation: completed in 176.626 ms, heap usage 314.267 MB -> 70.613 MB. [2025-05-29T02:22:06.722Z] ====== als (apache-spark) [default], iteration 28 completed (5035.669 ms) ====== [2025-05-29T02:22:06.723Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-05-29T02:22:06.723Z] GC before operation: completed in 176.123 ms, heap usage 1.016 GB -> 71.533 MB. [2025-05-29T02:22:12.299Z] ====== als (apache-spark) [default], iteration 29 completed (5249.447 ms) ====== [2025-05-29T02:22:12.299Z] ----------------------------------- [2025-05-29T02:22:12.299Z] renaissance-als_0_PASSED [2025-05-29T02:22:12.299Z] ----------------------------------- [2025-05-29T02:22:12.299Z] [2025-05-29T02:22:12.299Z] TEST TEARDOWN: [2025-05-29T02:22:12.299Z] Nothing to be done for teardown. [2025-05-29T02:22:12.299Z] renaissance-als_0 Finish Time: Thu May 29 02:22:11 2025 Epoch Time (ms): 1748485331669