[2025-08-01T21:12:02.993Z] Running test renaissance-als_0 ... [2025-08-01T21:12:02.994Z] =============================================== [2025-08-01T21:12:02.994Z] renaissance-als_0 Start Time: Fri Aug 1 16:12:00 2025 Epoch Time (ms): 1754082720256 [2025-08-01T21:12:02.994Z] variation: NoOptions [2025-08-01T21:12:02.994Z] JVM_OPTIONS: [2025-08-01T21:12:02.994Z] { \ [2025-08-01T21:12:02.994Z] echo ""; echo "TEST SETUP:"; \ [2025-08-01T21:12:02.994Z] echo "Nothing to be done for setup."; \ [2025-08-01T21:12:02.994Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_linux/aqa-tests/TKG/../TKG/output_17540827195805/renaissance-als_0"; \ [2025-08-01T21:12:02.994Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_linux/aqa-tests/TKG/../TKG/output_17540827195805/renaissance-als_0"; \ [2025-08-01T21:12:02.994Z] echo ""; echo "TESTING:"; \ [2025-08-01T21:12:02.994Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_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_x86-64_linux/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_linux/aqa-tests/TKG/../TKG/output_17540827195805/renaissance-als_0"/als.json" als; \ [2025-08-01T21:12:02.994Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_linux/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_linux/aqa-tests/TKG/../TKG/output_17540827195805/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-08-01T21:12:02.994Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-08-01T21:12:02.994Z] echo "Nothing to be done for teardown."; \ [2025-08-01T21:12:02.994Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_linux/aqa-tests/TKG/../TKG/output_17540827195805/TestTargetResult"; [2025-08-01T21:12:02.994Z] [2025-08-01T21:12:02.994Z] TEST SETUP: [2025-08-01T21:12:02.994Z] Nothing to be done for setup. [2025-08-01T21:12:02.994Z] [2025-08-01T21:12:02.994Z] TESTING: [2025-08-01T21:12:09.126Z] NOTE: 'als' benchmark uses Spark local executor with 8 (out of 8) threads. [2025-08-01T21:12:12.132Z] WARNING: An illegal reflective access operation has occurred [2025-08-01T21:12:12.132Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_linux/aqa-tests/TKG/output_17540827195805/renaissance-als_0/harness-161200-16582889568913337523/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-08-01T21:12:12.132Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-08-01T21:12:12.132Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-08-01T21:12:12.132Z] WARNING: All illegal access operations will be denied in a future release [2025-08-01T21:12:13.508Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-08-01T21:12:13.508Z] GC before operation: completed in 105.855 ms, heap usage 384.011 MB -> 35.119 MB. [2025-08-01T21:12:31.228Z] ====== als (apache-spark) [default], iteration 0 completed (16419.093 ms) ====== [2025-08-01T21:12:31.228Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-08-01T21:12:31.228Z] GC before operation: completed in 119.964 ms, heap usage 408.146 MB -> 61.323 MB. [2025-08-01T21:12:37.468Z] ====== als (apache-spark) [default], iteration 1 completed (7072.846 ms) ====== [2025-08-01T21:12:37.468Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-08-01T21:12:38.147Z] GC before operation: completed in 206.022 ms, heap usage 660.405 MB -> 62.605 MB. [2025-08-01T21:12:45.689Z] ====== als (apache-spark) [default], iteration 2 completed (6872.083 ms) ====== [2025-08-01T21:12:45.689Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-08-01T21:12:45.689Z] GC before operation: completed in 158.125 ms, heap usage 282.671 MB -> 62.622 MB. [2025-08-01T21:12:51.881Z] ====== als (apache-spark) [default], iteration 3 completed (6251.515 ms) ====== [2025-08-01T21:12:51.882Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-08-01T21:12:51.882Z] GC before operation: completed in 166.105 ms, heap usage 797.894 MB -> 63.782 MB. [2025-08-01T21:12:59.420Z] ====== als (apache-spark) [default], iteration 4 completed (6668.253 ms) ====== [2025-08-01T21:12:59.420Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-08-01T21:12:59.420Z] GC before operation: completed in 151.709 ms, heap usage 242.444 MB -> 63.692 MB. [2025-08-01T21:13:05.647Z] ====== als (apache-spark) [default], iteration 5 completed (6386.502 ms) ====== [2025-08-01T21:13:05.647Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-08-01T21:13:05.647Z] GC before operation: completed in 171.703 ms, heap usage 237.616 MB -> 64.216 MB. [2025-08-01T21:13:12.263Z] ====== als (apache-spark) [default], iteration 6 completed (6286.132 ms) ====== [2025-08-01T21:13:12.263Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-08-01T21:13:12.263Z] GC before operation: completed in 139.450 ms, heap usage 284.854 MB -> 64.755 MB. [2025-08-01T21:13:18.511Z] ====== als (apache-spark) [default], iteration 7 completed (6278.815 ms) ====== [2025-08-01T21:13:18.511Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-08-01T21:13:18.511Z] GC before operation: completed in 167.635 ms, heap usage 574.582 MB -> 65.687 MB. [2025-08-01T21:13:26.048Z] ====== als (apache-spark) [default], iteration 8 completed (6320.083 ms) ====== [2025-08-01T21:13:26.048Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-08-01T21:13:26.048Z] GC before operation: completed in 211.397 ms, heap usage 261.971 MB -> 65.843 MB. [2025-08-01T21:13:32.340Z] ====== als (apache-spark) [default], iteration 9 completed (6466.843 ms) ====== [2025-08-01T21:13:32.340Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-08-01T21:13:32.340Z] GC before operation: completed in 159.779 ms, heap usage 252.647 MB -> 66.130 MB. [2025-08-01T21:13:39.869Z] ====== als (apache-spark) [default], iteration 10 completed (6495.406 ms) ====== [2025-08-01T21:13:39.869Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-08-01T21:13:39.869Z] GC before operation: completed in 197.581 ms, heap usage 328.465 MB -> 66.326 MB. [2025-08-01T21:13:46.169Z] ====== als (apache-spark) [default], iteration 11 completed (6471.660 ms) ====== [2025-08-01T21:13:46.169Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-08-01T21:13:46.169Z] GC before operation: completed in 217.844 ms, heap usage 478.158 MB -> 66.947 MB. [2025-08-01T21:13:52.420Z] ====== als (apache-spark) [default], iteration 12 completed (6174.919 ms) ====== [2025-08-01T21:13:52.420Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-08-01T21:13:52.420Z] GC before operation: completed in 160.515 ms, heap usage 207.461 MB -> 66.807 MB. [2025-08-01T21:13:59.960Z] ====== als (apache-spark) [default], iteration 13 completed (6357.581 ms) ====== [2025-08-01T21:13:59.960Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-08-01T21:13:59.960Z] GC before operation: completed in 156.269 ms, heap usage 295.349 MB -> 67.117 MB. [2025-08-01T21:14:06.196Z] ====== als (apache-spark) [default], iteration 14 completed (6245.053 ms) ====== [2025-08-01T21:14:06.196Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-08-01T21:14:06.196Z] GC before operation: completed in 168.984 ms, heap usage 220.567 MB -> 67.463 MB. [2025-08-01T21:14:12.387Z] ====== als (apache-spark) [default], iteration 15 completed (6170.953 ms) ====== [2025-08-01T21:14:12.387Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-08-01T21:14:12.387Z] GC before operation: completed in 163.158 ms, heap usage 237.450 MB -> 67.628 MB. [2025-08-01T21:14:18.668Z] ====== als (apache-spark) [default], iteration 16 completed (6451.702 ms) ====== [2025-08-01T21:14:18.668Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-08-01T21:14:19.331Z] GC before operation: completed in 190.757 ms, heap usage 612.209 MB -> 68.293 MB. [2025-08-01T21:14:25.537Z] ====== als (apache-spark) [default], iteration 17 completed (6160.561 ms) ====== [2025-08-01T21:14:25.537Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-08-01T21:14:25.537Z] GC before operation: completed in 153.643 ms, heap usage 628.056 MB -> 68.563 MB. [2025-08-01T21:14:31.748Z] ====== als (apache-spark) [default], iteration 18 completed (6208.671 ms) ====== [2025-08-01T21:14:31.748Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-08-01T21:14:32.413Z] GC before operation: completed in 140.233 ms, heap usage 265.789 MB -> 68.345 MB. [2025-08-01T21:14:38.647Z] ====== als (apache-spark) [default], iteration 19 completed (6516.523 ms) ====== [2025-08-01T21:14:38.647Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-08-01T21:14:38.647Z] GC before operation: completed in 146.175 ms, heap usage 175.438 MB -> 68.546 MB. [2025-08-01T21:14:46.183Z] ====== als (apache-spark) [default], iteration 20 completed (6621.082 ms) ====== [2025-08-01T21:14:46.183Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-08-01T21:14:46.183Z] GC before operation: completed in 142.597 ms, heap usage 221.832 MB -> 68.877 MB. [2025-08-01T21:14:52.434Z] ====== als (apache-spark) [default], iteration 21 completed (6424.824 ms) ====== [2025-08-01T21:14:52.434Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-08-01T21:14:52.434Z] GC before operation: completed in 158.492 ms, heap usage 239.826 MB -> 69.151 MB. [2025-08-01T21:14:58.620Z] ====== als (apache-spark) [default], iteration 22 completed (6008.587 ms) ====== [2025-08-01T21:14:58.620Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-08-01T21:14:59.286Z] GC before operation: completed in 172.374 ms, heap usage 242.419 MB -> 69.406 MB. [2025-08-01T21:15:05.477Z] ====== als (apache-spark) [default], iteration 23 completed (6441.521 ms) ====== [2025-08-01T21:15:05.477Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-08-01T21:15:06.141Z] GC before operation: completed in 174.349 ms, heap usage 284.902 MB -> 69.757 MB. [2025-08-01T21:15:12.407Z] ====== als (apache-spark) [default], iteration 24 completed (6412.911 ms) ====== [2025-08-01T21:15:12.407Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-08-01T21:15:12.407Z] GC before operation: completed in 151.509 ms, heap usage 179.787 MB -> 69.784 MB. [2025-08-01T21:15:18.637Z] ====== als (apache-spark) [default], iteration 25 completed (6118.875 ms) ====== [2025-08-01T21:15:18.637Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-08-01T21:15:19.302Z] GC before operation: completed in 161.592 ms, heap usage 278.020 MB -> 70.162 MB. [2025-08-01T21:15:25.473Z] ====== als (apache-spark) [default], iteration 26 completed (6357.897 ms) ====== [2025-08-01T21:15:25.473Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-08-01T21:15:25.473Z] GC before operation: completed in 158.406 ms, heap usage 264.334 MB -> 70.408 MB. [2025-08-01T21:15:32.994Z] ====== als (apache-spark) [default], iteration 27 completed (6474.329 ms) ====== [2025-08-01T21:15:32.994Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-08-01T21:15:32.994Z] GC before operation: completed in 168.010 ms, heap usage 156.179 MB -> 70.852 MB. [2025-08-01T21:15:39.164Z] ====== als (apache-spark) [default], iteration 28 completed (6366.219 ms) ====== [2025-08-01T21:15:39.164Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-08-01T21:15:39.164Z] GC before operation: completed in 167.110 ms, heap usage 564.734 MB -> 70.848 MB. [2025-08-01T21:15:45.367Z] ====== als (apache-spark) [default], iteration 29 completed (6247.894 ms) ====== [2025-08-01T21:15:46.030Z] ----------------------------------- [2025-08-01T21:15:46.030Z] renaissance-als_0_PASSED [2025-08-01T21:15:46.030Z] ----------------------------------- [2025-08-01T21:15:46.030Z] [2025-08-01T21:15:46.030Z] TEST TEARDOWN: [2025-08-01T21:15:46.030Z] Nothing to be done for teardown. [2025-08-01T21:15:46.030Z] renaissance-als_0 Finish Time: Fri Aug 1 16:15:43 2025 Epoch Time (ms): 1754082943739