[2025-05-07T11:27:29.653Z] Running test renaissance-als_0 ... [2025-05-07T11:27:29.653Z] =============================================== [2025-05-07T11:27:29.653Z] renaissance-als_0 Start Time: Wed May 7 11:27:29 2025 Epoch Time (ms): 1746617249100 [2025-05-07T11:27:29.653Z] variation: NoOptions [2025-05-07T11:27:29.653Z] JVM_OPTIONS: [2025-05-07T11:27:29.653Z] { \ [2025-05-07T11:27:29.653Z] echo ""; echo "TEST SETUP:"; \ [2025-05-07T11:27:29.653Z] echo "Nothing to be done for setup."; \ [2025-05-07T11:27:29.653Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17466172034810/renaissance-als_0"; \ [2025-05-07T11:27:29.653Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17466172034810/renaissance-als_0"; \ [2025-05-07T11:27:29.653Z] echo ""; echo "TESTING:"; \ [2025-05-07T11:27:29.653Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_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_ppc64le_linux/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17466172034810/renaissance-als_0"/als.json" als; \ [2025-05-07T11:27:29.653Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17466172034810/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-05-07T11:27:29.653Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-05-07T11:27:29.653Z] echo "Nothing to be done for teardown."; \ [2025-05-07T11:27:29.653Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_17466172034810/TestTargetResult"; [2025-05-07T11:27:29.653Z] [2025-05-07T11:27:29.653Z] TEST SETUP: [2025-05-07T11:27:29.653Z] Nothing to be done for setup. [2025-05-07T11:27:29.653Z] [2025-05-07T11:27:29.653Z] TESTING: [2025-05-07T11:27:36.438Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-05-07T11:27:39.423Z] WARNING: An illegal reflective access operation has occurred [2025-05-07T11:27:39.423Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/output_17466172034810/renaissance-als_0/harness-112729-4033299014291524820/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-05-07T11:27:39.423Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-05-07T11:27:39.423Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-05-07T11:27:39.423Z] WARNING: All illegal access operations will be denied in a future release [2025-05-07T11:27:41.352Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-05-07T11:27:41.352Z] GC before operation: completed in 61.907 ms, heap usage 265.000 MB -> 34.451 MB. [2025-05-07T11:28:02.503Z] ====== als (apache-spark) [default], iteration 0 completed (19608.070 ms) ====== [2025-05-07T11:28:02.503Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-05-07T11:28:02.503Z] GC before operation: completed in 121.904 ms, heap usage 108.933 MB -> 60.281 MB. [2025-05-07T11:28:10.633Z] ====== als (apache-spark) [default], iteration 1 completed (9037.028 ms) ====== [2025-05-07T11:28:10.633Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-05-07T11:28:10.633Z] GC before operation: completed in 110.760 ms, heap usage 607.558 MB -> 61.755 MB. [2025-05-07T11:28:20.276Z] ====== als (apache-spark) [default], iteration 2 completed (8803.637 ms) ====== [2025-05-07T11:28:20.276Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-05-07T11:28:20.276Z] GC before operation: completed in 114.886 ms, heap usage 407.344 MB -> 62.108 MB. [2025-05-07T11:28:28.366Z] ====== als (apache-spark) [default], iteration 3 completed (8446.474 ms) ====== [2025-05-07T11:28:28.366Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-05-07T11:28:29.305Z] GC before operation: completed in 112.114 ms, heap usage 306.796 MB -> 62.563 MB. [2025-05-07T11:28:37.357Z] ====== als (apache-spark) [default], iteration 4 completed (8135.646 ms) ====== [2025-05-07T11:28:37.357Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-05-07T11:28:37.357Z] GC before operation: completed in 127.614 ms, heap usage 244.159 MB -> 63.076 MB. [2025-05-07T11:28:45.420Z] ====== als (apache-spark) [default], iteration 5 completed (8057.542 ms) ====== [2025-05-07T11:28:45.420Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-05-07T11:28:46.360Z] GC before operation: completed in 119.151 ms, heap usage 93.414 MB -> 63.337 MB. [2025-05-07T11:28:54.418Z] ====== als (apache-spark) [default], iteration 6 completed (8283.603 ms) ====== [2025-05-07T11:28:54.419Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-05-07T11:28:54.419Z] GC before operation: completed in 124.199 ms, heap usage 216.417 MB -> 63.860 MB. [2025-05-07T11:29:04.055Z] ====== als (apache-spark) [default], iteration 7 completed (8271.727 ms) ====== [2025-05-07T11:29:04.055Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-05-07T11:29:04.055Z] GC before operation: completed in 125.902 ms, heap usage 126.723 MB -> 64.396 MB. [2025-05-07T11:29:12.116Z] ====== als (apache-spark) [default], iteration 8 completed (8345.826 ms) ====== [2025-05-07T11:29:12.116Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-05-07T11:29:12.116Z] GC before operation: completed in 123.351 ms, heap usage 244.286 MB -> 64.918 MB. [2025-05-07T11:29:21.762Z] ====== als (apache-spark) [default], iteration 9 completed (8514.577 ms) ====== [2025-05-07T11:29:21.762Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-05-07T11:29:21.762Z] GC before operation: completed in 124.144 ms, heap usage 156.315 MB -> 65.198 MB. [2025-05-07T11:29:29.822Z] ====== als (apache-spark) [default], iteration 10 completed (8127.805 ms) ====== [2025-05-07T11:29:29.822Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-05-07T11:29:29.822Z] GC before operation: completed in 123.700 ms, heap usage 203.299 MB -> 65.442 MB. [2025-05-07T11:29:37.890Z] ====== als (apache-spark) [default], iteration 11 completed (8222.106 ms) ====== [2025-05-07T11:29:37.890Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-05-07T11:29:37.890Z] GC before operation: completed in 111.767 ms, heap usage 220.120 MB -> 65.706 MB. [2025-05-07T11:29:47.518Z] ====== als (apache-spark) [default], iteration 12 completed (8140.059 ms) ====== [2025-05-07T11:29:47.518Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-05-07T11:29:47.518Z] GC before operation: completed in 132.469 ms, heap usage 208.535 MB -> 65.924 MB. [2025-05-07T11:29:55.568Z] ====== als (apache-spark) [default], iteration 13 completed (8228.108 ms) ====== [2025-05-07T11:29:55.568Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-05-07T11:29:55.568Z] GC before operation: completed in 132.674 ms, heap usage 251.987 MB -> 66.287 MB. [2025-05-07T11:30:03.616Z] ====== als (apache-spark) [default], iteration 14 completed (8211.612 ms) ====== [2025-05-07T11:30:03.616Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-05-07T11:30:03.616Z] GC before operation: completed in 133.377 ms, heap usage 149.298 MB -> 65.954 MB. [2025-05-07T11:30:13.307Z] ====== als (apache-spark) [default], iteration 15 completed (8189.555 ms) ====== [2025-05-07T11:30:13.308Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-05-07T11:30:13.308Z] GC before operation: completed in 118.096 ms, heap usage 276.728 MB -> 66.806 MB. [2025-05-07T11:30:20.684Z] ====== als (apache-spark) [default], iteration 16 completed (8049.017 ms) ====== [2025-05-07T11:30:20.684Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-05-07T11:30:20.684Z] GC before operation: completed in 135.300 ms, heap usage 257.892 MB -> 67.116 MB. [2025-05-07T11:30:30.329Z] ====== als (apache-spark) [default], iteration 17 completed (8201.396 ms) ====== [2025-05-07T11:30:30.329Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-05-07T11:30:30.329Z] GC before operation: completed in 136.699 ms, heap usage 175.327 MB -> 67.240 MB. [2025-05-07T11:30:38.383Z] ====== als (apache-spark) [default], iteration 18 completed (7939.527 ms) ====== [2025-05-07T11:30:38.383Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-05-07T11:30:38.383Z] GC before operation: completed in 140.308 ms, heap usage 655.539 MB -> 68.003 MB. [2025-05-07T11:30:46.447Z] ====== als (apache-spark) [default], iteration 19 completed (8634.118 ms) ====== [2025-05-07T11:30:46.447Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-05-07T11:30:46.447Z] GC before operation: completed in 128.368 ms, heap usage 267.530 MB -> 67.797 MB. [2025-05-07T11:30:56.116Z] ====== als (apache-spark) [default], iteration 20 completed (8075.897 ms) ====== [2025-05-07T11:30:56.116Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-05-07T11:30:56.116Z] GC before operation: completed in 131.593 ms, heap usage 224.499 MB -> 68.043 MB. [2025-05-07T11:31:04.163Z] ====== als (apache-spark) [default], iteration 21 completed (8148.538 ms) ====== [2025-05-07T11:31:04.163Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-05-07T11:31:04.163Z] GC before operation: completed in 132.256 ms, heap usage 234.301 MB -> 68.285 MB. [2025-05-07T11:31:12.214Z] ====== als (apache-spark) [default], iteration 22 completed (8055.122 ms) ====== [2025-05-07T11:31:12.214Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-05-07T11:31:12.214Z] GC before operation: completed in 132.010 ms, heap usage 276.602 MB -> 68.568 MB. [2025-05-07T11:31:21.848Z] ====== als (apache-spark) [default], iteration 23 completed (8102.411 ms) ====== [2025-05-07T11:31:21.848Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-05-07T11:31:21.848Z] GC before operation: completed in 138.068 ms, heap usage 328.439 MB -> 69.004 MB. [2025-05-07T11:31:29.909Z] ====== als (apache-spark) [default], iteration 24 completed (8337.176 ms) ====== [2025-05-07T11:31:29.910Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-05-07T11:31:29.910Z] GC before operation: completed in 135.543 ms, heap usage 270.959 MB -> 69.058 MB. [2025-05-07T11:31:37.963Z] ====== als (apache-spark) [default], iteration 25 completed (8163.553 ms) ====== [2025-05-07T11:31:37.963Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-05-07T11:31:37.963Z] GC before operation: completed in 130.828 ms, heap usage 105.696 MB -> 69.192 MB. [2025-05-07T11:31:46.281Z] ====== als (apache-spark) [default], iteration 26 completed (7711.584 ms) ====== [2025-05-07T11:31:46.281Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-05-07T11:31:46.281Z] GC before operation: completed in 123.889 ms, heap usage 305.245 MB -> 69.677 MB. [2025-05-07T11:31:54.338Z] ====== als (apache-spark) [default], iteration 27 completed (7737.080 ms) ====== [2025-05-07T11:31:54.338Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-05-07T11:31:54.338Z] GC before operation: completed in 133.357 ms, heap usage 145.295 MB -> 69.246 MB. [2025-05-07T11:32:02.391Z] ====== als (apache-spark) [default], iteration 28 completed (8079.768 ms) ====== [2025-05-07T11:32:02.391Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-05-07T11:32:03.329Z] GC before operation: completed in 122.887 ms, heap usage 286.517 MB -> 69.599 MB. [2025-05-07T11:32:11.381Z] ====== als (apache-spark) [default], iteration 29 completed (8138.055 ms) ====== [2025-05-07T11:32:11.381Z] ----------------------------------- [2025-05-07T11:32:11.381Z] renaissance-als_0_PASSED [2025-05-07T11:32:11.381Z] ----------------------------------- [2025-05-07T11:32:11.381Z] [2025-05-07T11:32:11.381Z] TEST TEARDOWN: [2025-05-07T11:32:11.381Z] Nothing to be done for teardown. [2025-05-07T11:32:11.381Z] renaissance-als_0 Finish Time: Wed May 7 11:32:11 2025 Epoch Time (ms): 1746617531153