[2025-08-27T22:36:42.575Z] Running test renaissance-als_0 ... [2025-08-27T22:36:42.575Z] =============================================== [2025-08-27T22:36:42.575Z] renaissance-als_0 Start Time: Wed Aug 27 18:36:42 2025 Epoch Time (ms): 1756334202310 [2025-08-27T22:36:42.575Z] variation: NoOptions [2025-08-27T22:36:42.575Z] JVM_OPTIONS: [2025-08-27T22:36:42.575Z] { \ [2025-08-27T22:36:42.575Z] echo ""; echo "TEST SETUP:"; \ [2025-08-27T22:36:42.575Z] echo "Nothing to be done for setup."; \ [2025-08-27T22:36:42.575Z] mkdir -p "/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/../TKG/output_1756334202885/renaissance-als_0"; \ [2025-08-27T22:36:42.575Z] cd "/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/../TKG/output_1756334202885/renaissance-als_0"; \ [2025-08-27T22:36:42.575Z] echo ""; echo "TESTING:"; \ [2025-08-27T22:36:42.575Z] "/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/jdkbinary/j2sdk-image/Contents/Home/bin/..//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 "/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/../TKG/output_1756334202885/renaissance-als_0"/als.json" als; \ [2025-08-27T22:36:42.575Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/..; rm -f -r "/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/../TKG/output_1756334202885/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-08-27T22:36:42.575Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-08-27T22:36:42.575Z] echo "Nothing to be done for teardown."; \ [2025-08-27T22:36:42.575Z] } 2>&1 | tee -a "/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/../TKG/output_1756334202885/TestTargetResult"; [2025-08-27T22:36:42.575Z] [2025-08-27T22:36:42.575Z] TEST SETUP: [2025-08-27T22:36:42.575Z] Nothing to be done for setup. [2025-08-27T22:36:42.575Z] [2025-08-27T22:36:42.575Z] TESTING: [2025-08-27T22:36:46.515Z] NOTE: 'als' benchmark uses Spark local executor with 3 (out of 3) threads. [2025-08-27T22:36:47.742Z] WARNING: An illegal reflective access operation has occurred [2025-08-27T22:36:47.742Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/output_1756334202885/renaissance-als_0/harness-183642-8601303856435438849/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-08-27T22:36:47.742Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-08-27T22:36:47.742Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-08-27T22:36:47.742Z] WARNING: All illegal access operations will be denied in a future release [2025-08-27T22:36:48.090Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-08-27T22:36:48.090Z] GC before operation: completed in 24.045 ms, heap usage 267.000 MB -> 34.564 MB. [2025-08-27T22:36:57.337Z] ====== als (apache-spark) [default], iteration 0 completed (9017.171 ms) ====== [2025-08-27T22:36:57.337Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-08-27T22:36:57.337Z] GC before operation: completed in 54.978 ms, heap usage 515.798 MB -> 60.656 MB. [2025-08-27T22:37:02.358Z] ====== als (apache-spark) [default], iteration 1 completed (4309.763 ms) ====== [2025-08-27T22:37:02.358Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-08-27T22:37:02.359Z] GC before operation: completed in 49.259 ms, heap usage 405.095 MB -> 61.415 MB. [2025-08-27T22:37:06.539Z] ====== als (apache-spark) [default], iteration 2 completed (3870.133 ms) ====== [2025-08-27T22:37:06.539Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-08-27T22:37:06.539Z] GC before operation: completed in 48.529 ms, heap usage 263.124 MB -> 61.862 MB. [2025-08-27T22:37:10.577Z] ====== als (apache-spark) [default], iteration 3 completed (3800.555 ms) ====== [2025-08-27T22:37:10.577Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-08-27T22:37:10.577Z] GC before operation: completed in 48.974 ms, heap usage 146.154 MB -> 62.277 MB. [2025-08-27T22:37:14.617Z] ====== als (apache-spark) [default], iteration 4 completed (3888.354 ms) ====== [2025-08-27T22:37:14.617Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-08-27T22:37:14.617Z] GC before operation: completed in 50.762 ms, heap usage 213.399 MB -> 62.928 MB. [2025-08-27T22:37:17.864Z] ====== als (apache-spark) [default], iteration 5 completed (3463.297 ms) ====== [2025-08-27T22:37:17.864Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-08-27T22:37:17.864Z] GC before operation: completed in 53.821 ms, heap usage 361.738 MB -> 63.709 MB. [2025-08-27T22:37:21.862Z] ====== als (apache-spark) [default], iteration 6 completed (3704.263 ms) ====== [2025-08-27T22:37:21.862Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-08-27T22:37:21.862Z] GC before operation: completed in 51.166 ms, heap usage 393.033 MB -> 64.095 MB. [2025-08-27T22:37:24.964Z] ====== als (apache-spark) [default], iteration 7 completed (3386.320 ms) ====== [2025-08-27T22:37:24.964Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-08-27T22:37:24.964Z] GC before operation: completed in 52.268 ms, heap usage 262.647 MB -> 64.533 MB. [2025-08-27T22:37:28.945Z] ====== als (apache-spark) [default], iteration 8 completed (3496.384 ms) ====== [2025-08-27T22:37:28.945Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-08-27T22:37:28.945Z] GC before operation: completed in 57.354 ms, heap usage 208.167 MB -> 65.141 MB. [2025-08-27T22:37:33.034Z] ====== als (apache-spark) [default], iteration 9 completed (3924.115 ms) ====== [2025-08-27T22:37:33.034Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-08-27T22:37:33.034Z] GC before operation: completed in 55.533 ms, heap usage 177.003 MB -> 65.259 MB. [2025-08-27T22:37:36.197Z] ====== als (apache-spark) [default], iteration 10 completed (3533.372 ms) ====== [2025-08-27T22:37:36.197Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-08-27T22:37:36.567Z] GC before operation: completed in 53.869 ms, heap usage 102.740 MB -> 65.513 MB. [2025-08-27T22:37:40.613Z] ====== als (apache-spark) [default], iteration 11 completed (3527.788 ms) ====== [2025-08-27T22:37:40.613Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-08-27T22:37:40.613Z] GC before operation: completed in 58.698 ms, heap usage 165.099 MB -> 65.760 MB. [2025-08-27T22:37:43.817Z] ====== als (apache-spark) [default], iteration 12 completed (3689.036 ms) ====== [2025-08-27T22:37:43.817Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-08-27T22:37:43.817Z] GC before operation: completed in 60.949 ms, heap usage 352.441 MB -> 66.244 MB. [2025-08-27T22:37:47.871Z] ====== als (apache-spark) [default], iteration 13 completed (3297.896 ms) ====== [2025-08-27T22:37:47.871Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-08-27T22:37:47.871Z] GC before operation: completed in 59.110 ms, heap usage 254.348 MB -> 66.331 MB. [2025-08-27T22:37:51.039Z] ====== als (apache-spark) [default], iteration 14 completed (3512.591 ms) ====== [2025-08-27T22:37:51.039Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-08-27T22:37:51.039Z] GC before operation: completed in 79.762 ms, heap usage 227.824 MB -> 66.596 MB. [2025-08-27T22:37:55.069Z] ====== als (apache-spark) [default], iteration 15 completed (3806.852 ms) ====== [2025-08-27T22:37:55.069Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-08-27T22:37:55.069Z] GC before operation: completed in 64.073 ms, heap usage 256.984 MB -> 66.874 MB. [2025-08-27T22:37:59.166Z] ====== als (apache-spark) [default], iteration 16 completed (3768.051 ms) ====== [2025-08-27T22:37:59.166Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-08-27T22:37:59.166Z] GC before operation: completed in 68.783 ms, heap usage 203.646 MB -> 67.102 MB. [2025-08-27T22:38:03.163Z] ====== als (apache-spark) [default], iteration 17 completed (4008.381 ms) ====== [2025-08-27T22:38:03.163Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-08-27T22:38:03.163Z] GC before operation: completed in 65.545 ms, heap usage 178.176 MB -> 67.248 MB. [2025-08-27T22:38:07.170Z] ====== als (apache-spark) [default], iteration 18 completed (3991.000 ms) ====== [2025-08-27T22:38:07.170Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-08-27T22:38:07.170Z] GC before operation: completed in 86.055 ms, heap usage 504.770 MB -> 67.933 MB. [2025-08-27T22:38:12.231Z] ====== als (apache-spark) [default], iteration 19 completed (4093.625 ms) ====== [2025-08-27T22:38:12.231Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-08-27T22:38:12.231Z] GC before operation: completed in 77.575 ms, heap usage 403.416 MB -> 67.993 MB. [2025-08-27T22:38:16.376Z] ====== als (apache-spark) [default], iteration 20 completed (4275.176 ms) ====== [2025-08-27T22:38:16.376Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-08-27T22:38:16.376Z] GC before operation: completed in 83.815 ms, heap usage 229.113 MB -> 68.131 MB. [2025-08-27T22:38:20.614Z] ====== als (apache-spark) [default], iteration 21 completed (4355.207 ms) ====== [2025-08-27T22:38:20.614Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-08-27T22:38:20.614Z] GC before operation: completed in 90.603 ms, heap usage 238.593 MB -> 68.342 MB. [2025-08-27T22:38:25.787Z] ====== als (apache-spark) [default], iteration 22 completed (4521.418 ms) ====== [2025-08-27T22:38:25.787Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-08-27T22:38:25.787Z] GC before operation: completed in 102.880 ms, heap usage 300.905 MB -> 68.761 MB. [2025-08-27T22:38:30.875Z] ====== als (apache-spark) [default], iteration 23 completed (4760.324 ms) ====== [2025-08-27T22:38:30.875Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-08-27T22:38:30.875Z] GC before operation: completed in 84.175 ms, heap usage 228.573 MB -> 68.749 MB. [2025-08-27T22:38:35.901Z] ====== als (apache-spark) [default], iteration 24 completed (4579.347 ms) ====== [2025-08-27T22:38:35.901Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-08-27T22:38:35.902Z] GC before operation: completed in 76.290 ms, heap usage 155.142 MB -> 69.015 MB. [2025-08-27T22:38:39.932Z] ====== als (apache-spark) [default], iteration 25 completed (4553.677 ms) ====== [2025-08-27T22:38:39.932Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-08-27T22:38:39.932Z] GC before operation: completed in 81.545 ms, heap usage 254.572 MB -> 69.354 MB. [2025-08-27T22:38:44.961Z] ====== als (apache-spark) [default], iteration 26 completed (4555.235 ms) ====== [2025-08-27T22:38:44.961Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-08-27T22:38:44.961Z] GC before operation: completed in 76.045 ms, heap usage 219.176 MB -> 69.606 MB. [2025-08-27T22:38:49.017Z] ====== als (apache-spark) [default], iteration 27 completed (4339.798 ms) ====== [2025-08-27T22:38:49.017Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-08-27T22:38:49.408Z] GC before operation: completed in 80.571 ms, heap usage 211.698 MB -> 69.844 MB. [2025-08-27T22:38:54.535Z] ====== als (apache-spark) [default], iteration 28 completed (4461.531 ms) ====== [2025-08-27T22:38:54.535Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-08-27T22:38:54.535Z] GC before operation: completed in 70.471 ms, heap usage 247.364 MB -> 69.978 MB. [2025-08-27T22:38:58.600Z] ====== als (apache-spark) [default], iteration 29 completed (4258.919 ms) ====== [2025-08-27T22:38:58.600Z] ----------------------------------- [2025-08-27T22:38:58.600Z] renaissance-als_0_PASSED [2025-08-27T22:38:58.600Z] ----------------------------------- [2025-08-27T22:38:58.600Z] [2025-08-27T22:38:58.600Z] TEST TEARDOWN: [2025-08-27T22:38:58.600Z] Nothing to be done for teardown. [2025-08-27T22:38:58.600Z] renaissance-als_0 Finish Time: Wed Aug 27 18:38:58 2025 Epoch Time (ms): 1756334338355