renaissance-als_0
[2025-07-15T10:28:37.674Z] Running test renaissance-als_0 ...
[2025-07-15T10:28:37.674Z] ===============================================
[2025-07-15T10:28:37.674Z] renaissance-als_0 Start Time: Tue Jul 15 11:28:37 2025 Epoch Time (ms): 1752575317380
[2025-07-15T10:28:37.674Z] variation: NoOptions
[2025-07-15T10:28:37.674Z] JVM_OPTIONS:
[2025-07-15T10:28:37.674Z] { \
[2025-07-15T10:28:37.674Z] echo ""; echo "TEST SETUP:"; \
[2025-07-15T10:28:37.674Z] echo "Nothing to be done for setup."; \
[2025-07-15T10:28:37.674Z] mkdir -p "/Users/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_mac/aqa-tests/TKG/../TKG/output_17525753166596/renaissance-als_0"; \
[2025-07-15T10:28:37.674Z] cd "/Users/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_mac/aqa-tests/TKG/../TKG/output_17525753166596/renaissance-als_0"; \
[2025-07-15T10:28:37.674Z] echo ""; echo "TESTING:"; \
[2025-07-15T10:28:37.674Z] "/Users/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_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/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_mac/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/Users/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_mac/aqa-tests/TKG/../TKG/output_17525753166596/renaissance-als_0"/als.json" als; \
[2025-07-15T10:28:37.674Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /Users/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_mac/aqa-tests/TKG/..; rm -f -r "/Users/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_mac/aqa-tests/TKG/../TKG/output_17525753166596/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \
[2025-07-15T10:28:37.674Z] echo ""; echo "TEST TEARDOWN:"; \
[2025-07-15T10:28:37.674Z] echo "Nothing to be done for teardown."; \
[2025-07-15T10:28:37.674Z] } 2>&1 | tee -a "/Users/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_mac/aqa-tests/TKG/../TKG/output_17525753166596/TestTargetResult";
[2025-07-15T10:28:37.674Z]
[2025-07-15T10:28:37.674Z] TEST SETUP:
[2025-07-15T10:28:37.674Z] Nothing to be done for setup.
[2025-07-15T10:28:37.674Z]
[2025-07-15T10:28:37.674Z] TESTING:
[2025-07-15T10:28:45.306Z] NOTE: 'als' benchmark uses Spark local executor with 8 (out of 8) threads.
[2025-07-15T10:28:47.824Z] WARNING: An illegal reflective access operation has occurred
[2025-07-15T10:28:47.824Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/Users/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_mac/aqa-tests/TKG/output_17525753166596/renaissance-als_0/harness-112838-13820541332450784721/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme
[2025-07-15T10:28:47.824Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$
[2025-07-15T10:28:47.824Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
[2025-07-15T10:28:47.824Z] WARNING: All illegal access operations will be denied in a future release
[2025-07-15T10:28:49.058Z] ====== als (apache-spark) [default], iteration 0 started ======
[2025-07-15T10:28:49.058Z] GC before operation: completed in 52.493 ms, heap usage 80.506 MB -> 35.056 MB.
[2025-07-15T10:34:44.956Z] ====== als (apache-spark) [default], iteration 0 completed (344510.973 ms) ======
[2025-07-15T10:34:44.956Z] ====== als (apache-spark) [default], iteration 1 started ======
[2025-07-15T10:34:44.956Z] GC before operation: completed in 179.564 ms, heap usage 417.729 MB -> 63.012 MB.
[2025-07-15T10:40:25.719Z] ====== als (apache-spark) [default], iteration 1 completed (344154.035 ms) ======
[2025-07-15T10:40:25.719Z] ====== als (apache-spark) [default], iteration 2 started ======
[2025-07-15T10:40:25.719Z] GC before operation: completed in 180.996 ms, heap usage 700.471 MB -> 63.782 MB.
[2025-07-15T10:46:06.766Z] ====== als (apache-spark) [default], iteration 2 completed (343699.419 ms) ======
[2025-07-15T10:46:06.766Z] ====== als (apache-spark) [default], iteration 3 started ======
[2025-07-15T10:46:06.766Z] GC before operation: completed in 171.668 ms, heap usage 408.428 MB -> 64.209 MB.
[2025-07-15T10:52:02.626Z] ====== als (apache-spark) [default], iteration 3 completed (356932.389 ms) ======
[2025-07-15T10:52:02.626Z] ====== als (apache-spark) [default], iteration 4 started ======
[2025-07-15T10:52:02.626Z] GC before operation: completed in 158.948 ms, heap usage 418.814 MB -> 64.763 MB.
[2025-07-15T10:57:58.589Z] ====== als (apache-spark) [default], iteration 4 completed (357453.585 ms) ======
[2025-07-15T10:57:58.589Z] ====== als (apache-spark) [default], iteration 5 started ======
[2025-07-15T10:57:58.589Z] GC before operation: completed in 193.066 ms, heap usage 1.192 GB -> 65.554 MB.
[2025-07-15T11:04:09.618Z] ====== als (apache-spark) [default], iteration 5 completed (360854.057 ms) ======
[2025-07-15T11:04:09.618Z] ====== als (apache-spark) [default], iteration 6 started ======
[2025-07-15T11:04:09.618Z] GC before operation: completed in 168.887 ms, heap usage 674.088 MB -> 65.800 MB.
[2025-07-15T11:10:05.537Z] ====== als (apache-spark) [default], iteration 6 completed (362973.290 ms) ======
[2025-07-15T11:10:05.537Z] ====== als (apache-spark) [default], iteration 7 started ======
[2025-07-15T11:10:05.537Z] GC before operation: completed in 169.558 ms, heap usage 414.037 MB -> 66.375 MB.
[2025-07-15T11:16:16.359Z] ====== als (apache-spark) [default], iteration 7 completed (362019.525 ms) ======
[2025-07-15T11:16:16.359Z] ====== als (apache-spark) [default], iteration 8 started ======
[2025-07-15T11:16:16.359Z] GC before operation: completed in 192.389 ms, heap usage 553.704 MB -> 67.232 MB.
[2025-07-15T11:22:12.058Z] ====== als (apache-spark) [default], iteration 8 completed (362629.087 ms) ======
[2025-07-15T11:22:12.058Z] ====== als (apache-spark) [default], iteration 9 started ======
[2025-07-15T11:22:12.058Z] GC before operation: completed in 199.497 ms, heap usage 644.239 MB -> 67.527 MB.
[2025-07-15T11:28:25.180Z] ====== als (apache-spark) [default], iteration 9 completed (363602.943 ms) ======
[2025-07-15T11:28:25.180Z] ====== als (apache-spark) [default], iteration 10 started ======
[2025-07-15T11:28:25.180Z] GC before operation: completed in 178.397 ms, heap usage 412.372 MB -> 67.746 MB.
[2025-07-15T11:34:20.897Z] ====== als (apache-spark) [default], iteration 10 completed (362169.651 ms) ======
[2025-07-15T11:34:20.897Z] ====== als (apache-spark) [default], iteration 11 started ======
[2025-07-15T11:34:20.897Z] GC before operation: completed in 198.014 ms, heap usage 312.441 MB -> 64.657 MB.
[2025-07-15T11:40:16.685Z] ====== als (apache-spark) [default], iteration 11 completed (360418.228 ms) ======
[2025-07-15T11:40:16.685Z] ====== als (apache-spark) [default], iteration 12 started ======
[2025-07-15T11:40:16.685Z] GC before operation: completed in 209.519 ms, heap usage 997.527 MB -> 64.693 MB.
[2025-07-15T11:46:27.545Z] ====== als (apache-spark) [default], iteration 12 completed (362234.957 ms) ======
[2025-07-15T11:46:27.545Z] ====== als (apache-spark) [default], iteration 13 started ======
[2025-07-15T11:46:27.545Z] GC before operation: completed in 184.027 ms, heap usage 388.442 MB -> 64.579 MB.
[2025-07-15T11:52:23.299Z] ====== als (apache-spark) [default], iteration 13 completed (363090.677 ms) ======
[2025-07-15T11:52:23.299Z] ====== als (apache-spark) [default], iteration 14 started ======
[2025-07-15T11:52:23.299Z] GC before operation: completed in 215.205 ms, heap usage 1.077 GB -> 65.023 MB.
[2025-07-15T11:58:34.140Z] ====== als (apache-spark) [default], iteration 14 completed (366084.238 ms) ======
[2025-07-15T11:58:34.140Z] ====== als (apache-spark) [default], iteration 15 started ======
[2025-07-15T11:58:34.140Z] GC before operation: completed in 195.731 ms, heap usage 843.758 MB -> 65.203 MB.
[2025-07-15T12:04:45.103Z] ====== als (apache-spark) [default], iteration 15 completed (369433.773 ms) ======
[2025-07-15T12:04:45.103Z] ====== als (apache-spark) [default], iteration 16 started ======
[2025-07-15T12:04:45.103Z] GC before operation: completed in 175.091 ms, heap usage 319.773 MB -> 65.349 MB.
[2025-07-15T12:10:56.068Z] ====== als (apache-spark) [default], iteration 16 completed (369079.898 ms) ======
[2025-07-15T12:10:56.068Z] ====== als (apache-spark) [default], iteration 17 started ======
[2025-07-15T12:10:56.068Z] GC before operation: completed in 168.161 ms, heap usage 410.466 MB -> 65.592 MB.
[2025-07-15T12:17:06.951Z] ====== als (apache-spark) [default], iteration 17 completed (375431.930 ms) ======
[2025-07-15T12:17:06.951Z] ====== als (apache-spark) [default], iteration 18 started ======
[2025-07-15T12:17:06.951Z] GC before operation: completed in 189.585 ms, heap usage 394.537 MB -> 65.840 MB.
[2025-07-15T12:23:32.912Z] ====== als (apache-spark) [default], iteration 18 completed (378766.394 ms) ======
[2025-07-15T12:23:32.912Z] ====== als (apache-spark) [default], iteration 19 started ======
[2025-07-15T12:23:32.912Z] GC before operation: completed in 191.331 ms, heap usage 597.491 MB -> 66.210 MB.
[2025-07-15T12:29:43.792Z] ====== als (apache-spark) [default], iteration 19 completed (380561.642 ms) ======
[2025-07-15T12:29:43.792Z] ====== als (apache-spark) [default], iteration 20 started ======
[2025-07-15T12:29:43.792Z] GC before operation: completed in 174.324 ms, heap usage 282.826 MB -> 65.029 MB.
[2025-07-15T12:36:09.764Z] ====== als (apache-spark) [default], iteration 20 completed (381638.094 ms) ======
[2025-07-15T12:36:09.764Z] ====== als (apache-spark) [default], iteration 21 started ======
[2025-07-15T12:36:09.764Z] GC before operation: completed in 178.967 ms, heap usage 411.834 MB -> 66.608 MB.
[2025-07-15T12:42:35.848Z] ====== als (apache-spark) [default], iteration 21 completed (382360.751 ms) ======
[2025-07-15T12:42:35.848Z] ====== als (apache-spark) [default], iteration 22 started ======
[2025-07-15T12:42:35.848Z] GC before operation: completed in 192.740 ms, heap usage 552.977 MB -> 67.153 MB.
[2025-07-15T12:49:01.931Z] ====== als (apache-spark) [default], iteration 22 completed (383483.887 ms) ======
[2025-07-15T12:49:01.931Z] ====== als (apache-spark) [default], iteration 23 started ======
[2025-07-15T12:49:01.931Z] GC before operation: completed in 200.315 ms, heap usage 569.537 MB -> 66.700 MB.
[2025-07-15T12:55:27.926Z] ====== als (apache-spark) [default], iteration 23 completed (387159.925 ms) ======
[2025-07-15T12:55:27.926Z] ====== als (apache-spark) [default], iteration 24 started ======
[2025-07-15T12:55:27.926Z] GC before operation: completed in 190.507 ms, heap usage 397.375 MB -> 66.840 MB.
[2025-07-15T13:01:53.970Z] ====== als (apache-spark) [default], iteration 24 completed (385407.195 ms) ======
[2025-07-15T13:01:53.970Z] ====== als (apache-spark) [default], iteration 25 started ======
[2025-07-15T13:01:53.970Z] GC before operation: completed in 179.183 ms, heap usage 776.789 MB -> 65.900 MB.
[2025-07-15T13:08:19.974Z] ====== als (apache-spark) [default], iteration 25 completed (385014.748 ms) ======
[2025-07-15T13:08:19.974Z] ====== als (apache-spark) [default], iteration 26 started ======
[2025-07-15T13:08:19.974Z] GC before operation: completed in 197.082 ms, heap usage 363.866 MB -> 66.965 MB.
[2025-07-15T13:14:45.973Z] ====== als (apache-spark) [default], iteration 26 completed (387124.315 ms) ======
[2025-07-15T13:14:45.974Z] ====== als (apache-spark) [default], iteration 27 started ======
[2025-07-15T13:14:45.974Z] GC before operation: completed in 207.145 ms, heap usage 662.344 MB -> 67.341 MB.
[2025-07-15T13:21:11.966Z] ====== als (apache-spark) [default], iteration 27 completed (385734.951 ms) ======
[2025-07-15T13:21:11.966Z] ====== als (apache-spark) [default], iteration 28 started ======
[2025-07-15T13:21:11.966Z] GC before operation: completed in 182.147 ms, heap usage 413.015 MB -> 67.381 MB.
[2025-07-15T13:27:37.970Z] ====== als (apache-spark) [default], iteration 28 completed (382606.908 ms) ======
[2025-07-15T13:27:37.970Z] ====== als (apache-spark) [default], iteration 29 started ======
[2025-07-15T13:27:37.970Z] GC before operation: completed in 185.862 ms, heap usage 402.694 MB -> 67.627 MB.
[2025-07-15T13:34:04.025Z] ====== als (apache-spark) [default], iteration 29 completed (383666.940 ms) ======
[2025-07-15T13:34:04.025Z] -----------------------------------
[2025-07-15T13:34:04.025Z] renaissance-als_0_PASSED
[2025-07-15T13:34:04.025Z] -----------------------------------
[2025-07-15T13:34:04.025Z]
[2025-07-15T13:34:04.025Z] TEST TEARDOWN:
[2025-07-15T13:34:04.025Z] Nothing to be done for teardown.
[2025-07-15T13:34:04.025Z] renaissance-als_0 Finish Time: Tue Jul 15 14:33:50 2025 Epoch Time (ms): 1752586430342