[2025-05-16T22:33:31.617Z] Running test renaissance-als_0 ... [2025-05-16T22:33:31.617Z] =============================================== [2025-05-16T22:33:31.617Z] renaissance-als_0 Start Time: Fri May 16 18:33:31 2025 Epoch Time (ms): 1747434811401 [2025-05-16T22:33:31.617Z] variation: NoOptions [2025-05-16T22:33:31.617Z] JVM_OPTIONS: [2025-05-16T22:33:31.617Z] { \ [2025-05-16T22:33:31.617Z] echo ""; echo "TEST SETUP:"; \ [2025-05-16T22:33:31.617Z] echo "Nothing to be done for setup."; \ [2025-05-16T22:33:31.617Z] mkdir -p "/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/../TKG/output_17474348112088/renaissance-als_0"; \ [2025-05-16T22:33:31.617Z] cd "/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/../TKG/output_17474348112088/renaissance-als_0"; \ [2025-05-16T22:33:31.617Z] echo ""; echo "TESTING:"; \ [2025-05-16T22:33:31.617Z] "/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_17474348112088/renaissance-als_0"/als.json" als; \ [2025-05-16T22:33:31.617Z] 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_17474348112088/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-05-16T22:33:31.617Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-05-16T22:33:31.617Z] echo "Nothing to be done for teardown."; \ [2025-05-16T22:33:31.617Z] } 2>&1 | tee -a "/Users/admin/workspace/workspace/Test_openjdk11_hs_extended.perf_aarch64_mac/aqa-tests/TKG/../TKG/output_17474348112088/TestTargetResult"; [2025-05-16T22:33:31.617Z] [2025-05-16T22:33:31.617Z] TEST SETUP: [2025-05-16T22:33:31.617Z] Nothing to be done for setup. [2025-05-16T22:33:31.617Z] [2025-05-16T22:33:31.617Z] TESTING: [2025-05-16T22:33:36.905Z] NOTE: 'als' benchmark uses Spark local executor with 3 (out of 3) threads. [2025-05-16T22:33:37.746Z] WARNING: An illegal reflective access operation has occurred [2025-05-16T22:33:37.746Z] 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_17474348112088/renaissance-als_0/harness-183331-9909617899787471649/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-05-16T22:33:37.746Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-05-16T22:33:37.746Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-05-16T22:33:37.746Z] WARNING: All illegal access operations will be denied in a future release [2025-05-16T22:33:38.569Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-05-16T22:33:38.569Z] GC before operation: completed in 29.221 ms, heap usage 360.002 MB -> 34.634 MB. [2025-05-16T22:33:50.172Z] ====== als (apache-spark) [default], iteration 0 completed (10268.543 ms) ====== [2025-05-16T22:33:50.172Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-05-16T22:33:50.172Z] GC before operation: completed in 52.016 ms, heap usage 369.760 MB -> 60.496 MB. [2025-05-16T22:33:54.456Z] ====== als (apache-spark) [default], iteration 1 completed (4628.461 ms) ====== [2025-05-16T22:33:54.456Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-05-16T22:33:54.456Z] GC before operation: completed in 45.621 ms, heap usage 177.825 MB -> 61.178 MB. [2025-05-16T22:33:57.932Z] ====== als (apache-spark) [default], iteration 2 completed (3906.609 ms) ====== [2025-05-16T22:33:57.932Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-05-16T22:33:57.932Z] GC before operation: completed in 46.627 ms, heap usage 399.200 MB -> 61.972 MB. [2025-05-16T22:34:02.288Z] ====== als (apache-spark) [default], iteration 3 completed (3614.191 ms) ====== [2025-05-16T22:34:02.288Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-05-16T22:34:02.288Z] GC before operation: completed in 47.245 ms, heap usage 227.584 MB -> 62.395 MB. [2025-05-16T22:34:05.742Z] ====== als (apache-spark) [default], iteration 4 completed (3514.098 ms) ====== [2025-05-16T22:34:05.742Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-05-16T22:34:05.742Z] GC before operation: completed in 47.431 ms, heap usage 247.757 MB -> 63.037 MB. [2025-05-16T22:34:09.171Z] ====== als (apache-spark) [default], iteration 5 completed (3813.625 ms) ====== [2025-05-16T22:34:09.171Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-05-16T22:34:09.171Z] GC before operation: completed in 49.323 ms, heap usage 208.532 MB -> 63.467 MB. [2025-05-16T22:34:13.456Z] ====== als (apache-spark) [default], iteration 6 completed (3517.202 ms) ====== [2025-05-16T22:34:13.456Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-05-16T22:34:13.456Z] GC before operation: completed in 50.779 ms, heap usage 132.052 MB -> 63.876 MB. [2025-05-16T22:34:16.917Z] ====== als (apache-spark) [default], iteration 7 completed (3855.785 ms) ====== [2025-05-16T22:34:16.917Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-05-16T22:34:16.917Z] GC before operation: completed in 50.609 ms, heap usage 270.804 MB -> 64.544 MB. [2025-05-16T22:34:21.250Z] ====== als (apache-spark) [default], iteration 8 completed (3661.249 ms) ====== [2025-05-16T22:34:21.250Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-05-16T22:34:21.250Z] GC before operation: completed in 51.332 ms, heap usage 188.548 MB -> 64.935 MB. [2025-05-16T22:34:24.623Z] ====== als (apache-spark) [default], iteration 9 completed (3764.353 ms) ====== [2025-05-16T22:34:24.623Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-05-16T22:34:24.623Z] GC before operation: completed in 51.540 ms, heap usage 102.443 MB -> 65.216 MB. [2025-05-16T22:34:28.933Z] ====== als (apache-spark) [default], iteration 10 completed (3645.085 ms) ====== [2025-05-16T22:34:28.933Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-05-16T22:34:28.933Z] GC before operation: completed in 51.484 ms, heap usage 169.494 MB -> 65.472 MB. [2025-05-16T22:34:32.361Z] ====== als (apache-spark) [default], iteration 11 completed (3487.336 ms) ====== [2025-05-16T22:34:32.361Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-05-16T22:34:32.361Z] GC before operation: completed in 57.567 ms, heap usage 281.428 MB -> 65.946 MB. [2025-05-16T22:34:35.805Z] ====== als (apache-spark) [default], iteration 12 completed (3705.165 ms) ====== [2025-05-16T22:34:35.805Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-05-16T22:34:35.805Z] GC before operation: completed in 55.597 ms, heap usage 177.195 MB -> 65.652 MB. [2025-05-16T22:34:40.050Z] ====== als (apache-spark) [default], iteration 13 completed (3657.887 ms) ====== [2025-05-16T22:34:40.050Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-05-16T22:34:40.050Z] GC before operation: completed in 60.401 ms, heap usage 120.180 MB -> 66.234 MB. [2025-05-16T22:34:43.409Z] ====== als (apache-spark) [default], iteration 14 completed (3499.388 ms) ====== [2025-05-16T22:34:43.409Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-05-16T22:34:43.409Z] GC before operation: completed in 54.077 ms, heap usage 275.424 MB -> 66.568 MB. [2025-05-16T22:34:47.683Z] ====== als (apache-spark) [default], iteration 15 completed (3583.572 ms) ====== [2025-05-16T22:34:47.683Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-05-16T22:34:47.683Z] GC before operation: completed in 62.971 ms, heap usage 479.702 MB -> 67.172 MB. [2025-05-16T22:34:51.072Z] ====== als (apache-spark) [default], iteration 16 completed (3762.604 ms) ====== [2025-05-16T22:34:51.072Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-05-16T22:34:51.072Z] GC before operation: completed in 56.021 ms, heap usage 256.482 MB -> 67.072 MB. [2025-05-16T22:34:55.394Z] ====== als (apache-spark) [default], iteration 17 completed (3870.076 ms) ====== [2025-05-16T22:34:55.394Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-05-16T22:34:55.394Z] GC before operation: completed in 58.914 ms, heap usage 92.440 MB -> 67.199 MB. [2025-05-16T22:34:58.799Z] ====== als (apache-spark) [default], iteration 18 completed (3699.350 ms) ====== [2025-05-16T22:34:58.799Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-05-16T22:34:58.799Z] GC before operation: completed in 58.537 ms, heap usage 139.859 MB -> 66.997 MB. [2025-05-16T22:35:03.265Z] ====== als (apache-spark) [default], iteration 19 completed (3779.330 ms) ====== [2025-05-16T22:35:03.265Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-05-16T22:35:03.265Z] GC before operation: completed in 57.951 ms, heap usage 103.078 MB -> 67.686 MB. [2025-05-16T22:35:06.713Z] ====== als (apache-spark) [default], iteration 20 completed (3625.421 ms) ====== [2025-05-16T22:35:06.713Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-05-16T22:35:06.713Z] GC before operation: completed in 64.350 ms, heap usage 376.885 MB -> 68.275 MB. [2025-05-16T22:35:10.093Z] ====== als (apache-spark) [default], iteration 21 completed (3469.245 ms) ====== [2025-05-16T22:35:10.093Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-05-16T22:35:10.093Z] GC before operation: completed in 57.335 ms, heap usage 236.096 MB -> 68.313 MB. [2025-05-16T22:35:14.373Z] ====== als (apache-spark) [default], iteration 22 completed (4027.233 ms) ====== [2025-05-16T22:35:14.373Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-05-16T22:35:14.373Z] GC before operation: completed in 57.617 ms, heap usage 140.166 MB -> 68.493 MB. [2025-05-16T22:35:18.710Z] ====== als (apache-spark) [default], iteration 23 completed (4002.653 ms) ====== [2025-05-16T22:35:18.710Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-05-16T22:35:18.710Z] GC before operation: completed in 63.614 ms, heap usage 259.809 MB -> 68.943 MB. [2025-05-16T22:35:22.960Z] ====== als (apache-spark) [default], iteration 24 completed (3643.117 ms) ====== [2025-05-16T22:35:22.960Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-05-16T22:35:22.960Z] GC before operation: completed in 55.927 ms, heap usage 166.450 MB -> 68.994 MB. [2025-05-16T22:35:26.358Z] ====== als (apache-spark) [default], iteration 25 completed (3595.649 ms) ====== [2025-05-16T22:35:26.358Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-05-16T22:35:26.358Z] GC before operation: completed in 58.127 ms, heap usage 234.989 MB -> 69.337 MB. [2025-05-16T22:35:29.796Z] ====== als (apache-spark) [default], iteration 26 completed (3565.596 ms) ====== [2025-05-16T22:35:29.796Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-05-16T22:35:29.797Z] GC before operation: completed in 58.542 ms, heap usage 422.771 MB -> 69.698 MB. [2025-05-16T22:35:34.056Z] ====== als (apache-spark) [default], iteration 27 completed (3720.355 ms) ====== [2025-05-16T22:35:34.056Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-05-16T22:35:34.056Z] GC before operation: completed in 64.684 ms, heap usage 320.818 MB -> 69.929 MB. [2025-05-16T22:35:37.489Z] ====== als (apache-spark) [default], iteration 28 completed (3862.005 ms) ====== [2025-05-16T22:35:37.489Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-05-16T22:35:37.489Z] GC before operation: completed in 61.434 ms, heap usage 203.188 MB -> 69.498 MB. [2025-05-16T22:35:41.765Z] ====== als (apache-spark) [default], iteration 29 completed (3649.425 ms) ====== [2025-05-16T22:35:41.765Z] ----------------------------------- [2025-05-16T22:35:41.765Z] renaissance-als_0_PASSED [2025-05-16T22:35:41.765Z] ----------------------------------- [2025-05-16T22:35:41.765Z] [2025-05-16T22:35:41.765Z] TEST TEARDOWN: [2025-05-16T22:35:41.765Z] Nothing to be done for teardown. [2025-05-16T22:35:41.765Z] renaissance-als_0 Finish Time: Fri May 16 18:35:41 2025 Epoch Time (ms): 1747434941355