[2025-07-31T04:24:40.756Z] Running test renaissance-als_0 ... [2025-07-31T04:24:40.756Z] =============================================== [2025-07-31T04:24:40.756Z] renaissance-als_0 Start Time: Thu Jul 31 04:24:40 2025 Epoch Time (ms): 1753935880717 [2025-07-31T04:24:41.082Z] variation: NoOptions [2025-07-31T04:24:41.082Z] JVM_OPTIONS: [2025-07-31T04:24:41.082Z] { \ [2025-07-31T04:24:41.082Z] echo ""; echo "TEST SETUP:"; \ [2025-07-31T04:24:41.082Z] echo "Nothing to be done for setup."; \ [2025-07-31T04:24:41.082Z] mkdir -p "C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows_rerun/aqa-tests/\\TKG\\output_17539358784423\\renaissance-als_0"; \ [2025-07-31T04:24:41.082Z] cd "C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows_rerun/aqa-tests/\\TKG\\output_17539358784423\\renaissance-als_0"; \ [2025-07-31T04:24:41.082Z] echo ""; echo "TESTING:"; \ [2025-07-31T04:24:41.082Z] "c:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows_rerun/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 "C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows_rerun/aqa-tests///..//jvmtest\\perf\\renaissance\\renaissance.jar" --json ""C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows_rerun/aqa-tests/\\TKG\\output_17539358784423\\renaissance-als_0"\\als.json" als; \ [2025-07-31T04:24:41.082Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows_rerun/aqa-tests/; rm -f -r "C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows_rerun/aqa-tests/\\TKG\\output_17539358784423\\renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-07-31T04:24:41.082Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-07-31T04:24:41.082Z] echo "Nothing to be done for teardown."; \ [2025-07-31T04:24:41.082Z] } 2>&1 | tee -a "C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows_rerun/aqa-tests/\\TKG\\output_17539358784423\\TestTargetResult"; [2025-07-31T04:24:41.082Z] [2025-07-31T04:24:41.082Z] TEST SETUP: [2025-07-31T04:24:41.082Z] Nothing to be done for setup. [2025-07-31T04:24:41.082Z] [2025-07-31T04:24:41.082Z] TESTING: [2025-07-31T04:24:59.899Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-07-31T04:25:02.137Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-07-31T04:25:02.502Z] GC before operation: completed in 34.264 ms, heap usage 53.826 MB -> 35.568 MB. [2025-07-31T04:25:36.047Z] ====== als (apache-spark) [default], iteration 0 completed (31393.357 ms) ====== [2025-07-31T04:25:36.047Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-07-31T04:25:36.047Z] GC before operation: completed in 153.969 ms, heap usage 180.835 MB -> 62.823 MB. [2025-07-31T04:25:55.695Z] ====== als (apache-spark) [default], iteration 1 completed (18880.683 ms) ====== [2025-07-31T04:25:55.695Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-07-31T04:25:55.695Z] GC before operation: completed in 77.344 ms, heap usage 192.227 MB -> 63.387 MB. [2025-07-31T04:26:14.968Z] ====== als (apache-spark) [default], iteration 2 completed (18432.589 ms) ====== [2025-07-31T04:26:14.968Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-07-31T04:26:14.968Z] GC before operation: completed in 81.891 ms, heap usage 398.215 MB -> 64.172 MB. [2025-07-31T04:26:31.152Z] ====== als (apache-spark) [default], iteration 3 completed (17989.477 ms) ====== [2025-07-31T04:26:31.152Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-07-31T04:26:31.152Z] GC before operation: completed in 79.929 ms, heap usage 350.371 MB -> 64.750 MB. [2025-07-31T04:26:50.044Z] ====== als (apache-spark) [default], iteration 4 completed (18590.200 ms) ====== [2025-07-31T04:26:50.044Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-07-31T04:26:50.044Z] GC before operation: completed in 96.124 ms, heap usage 325.087 MB -> 65.392 MB. [2025-07-31T04:27:08.944Z] ====== als (apache-spark) [default], iteration 5 completed (18196.484 ms) ====== [2025-07-31T04:27:08.944Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-07-31T04:27:08.944Z] GC before operation: completed in 95.755 ms, heap usage 192.204 MB -> 65.751 MB. [2025-07-31T04:27:27.880Z] ====== als (apache-spark) [default], iteration 6 completed (18160.505 ms) ====== [2025-07-31T04:27:27.880Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-07-31T04:27:27.880Z] GC before operation: completed in 97.309 ms, heap usage 236.408 MB -> 66.526 MB. [2025-07-31T04:27:48.832Z] ====== als (apache-spark) [default], iteration 7 completed (19062.968 ms) ====== [2025-07-31T04:27:48.832Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-07-31T04:27:48.832Z] GC before operation: completed in 75.608 ms, heap usage 162.563 MB -> 66.786 MB. [2025-07-31T04:28:04.827Z] ====== als (apache-spark) [default], iteration 8 completed (17638.561 ms) ====== [2025-07-31T04:28:04.827Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-07-31T04:28:04.827Z] GC before operation: completed in 94.693 ms, heap usage 448.043 MB -> 67.833 MB. [2025-07-31T04:28:24.207Z] ====== als (apache-spark) [default], iteration 9 completed (18361.500 ms) ====== [2025-07-31T04:28:24.207Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-07-31T04:28:24.207Z] GC before operation: completed in 83.336 ms, heap usage 391.662 MB -> 67.849 MB. [2025-07-31T04:28:43.577Z] ====== als (apache-spark) [default], iteration 10 completed (17756.010 ms) ====== [2025-07-31T04:28:43.577Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-07-31T04:28:43.577Z] GC before operation: completed in 91.254 ms, heap usage 303.455 MB -> 68.078 MB. [2025-07-31T04:28:59.499Z] ====== als (apache-spark) [default], iteration 11 completed (17548.998 ms) ====== [2025-07-31T04:28:59.499Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-07-31T04:28:59.499Z] GC before operation: completed in 83.233 ms, heap usage 563.938 MB -> 68.698 MB. [2025-07-31T04:29:18.408Z] ====== als (apache-spark) [default], iteration 12 completed (17673.646 ms) ====== [2025-07-31T04:29:18.408Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-07-31T04:29:18.408Z] GC before operation: completed in 89.062 ms, heap usage 118.077 MB -> 68.427 MB. [2025-07-31T04:29:37.260Z] ====== als (apache-spark) [default], iteration 13 completed (18321.581 ms) ====== [2025-07-31T04:29:37.260Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-07-31T04:29:37.260Z] GC before operation: completed in 89.612 ms, heap usage 353.917 MB -> 68.942 MB. [2025-07-31T04:29:56.135Z] ====== als (apache-spark) [default], iteration 14 completed (17956.041 ms) ====== [2025-07-31T04:29:56.135Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-07-31T04:29:56.135Z] GC before operation: completed in 95.199 ms, heap usage 161.729 MB -> 68.937 MB. [2025-07-31T04:30:14.983Z] ====== als (apache-spark) [default], iteration 15 completed (20602.665 ms) ====== [2025-07-31T04:30:14.983Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-07-31T04:30:14.983Z] GC before operation: completed in 81.804 ms, heap usage 353.642 MB -> 69.420 MB. [2025-07-31T04:30:37.811Z] ====== als (apache-spark) [default], iteration 16 completed (21205.695 ms) ====== [2025-07-31T04:30:37.811Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-07-31T04:30:37.811Z] GC before operation: completed in 106.838 ms, heap usage 313.809 MB -> 69.586 MB. [2025-07-31T04:30:56.732Z] ====== als (apache-spark) [default], iteration 17 completed (19404.596 ms) ====== [2025-07-31T04:30:56.733Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-07-31T04:30:56.733Z] GC before operation: completed in 86.897 ms, heap usage 501.588 MB -> 70.091 MB. [2025-07-31T04:31:15.614Z] ====== als (apache-spark) [default], iteration 18 completed (18984.831 ms) ====== [2025-07-31T04:31:15.614Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-07-31T04:31:15.614Z] GC before operation: completed in 84.934 ms, heap usage 343.797 MB -> 70.101 MB. [2025-07-31T04:31:34.579Z] ====== als (apache-spark) [default], iteration 19 completed (18848.844 ms) ====== [2025-07-31T04:31:34.579Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-07-31T04:31:34.579Z] GC before operation: completed in 82.628 ms, heap usage 447.882 MB -> 70.583 MB. [2025-07-31T04:31:53.564Z] ====== als (apache-spark) [default], iteration 20 completed (19590.490 ms) ====== [2025-07-31T04:31:53.564Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-07-31T04:31:53.564Z] GC before operation: completed in 80.170 ms, heap usage 211.222 MB -> 70.418 MB. [2025-07-31T04:32:16.355Z] ====== als (apache-spark) [default], iteration 21 completed (19660.272 ms) ====== [2025-07-31T04:32:16.355Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-07-31T04:32:16.355Z] GC before operation: completed in 85.443 ms, heap usage 107.704 MB -> 70.734 MB. [2025-07-31T04:32:35.192Z] ====== als (apache-spark) [default], iteration 22 completed (19136.315 ms) ====== [2025-07-31T04:32:35.192Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-07-31T04:32:35.192Z] GC before operation: completed in 81.658 ms, heap usage 521.943 MB -> 71.427 MB. [2025-07-31T04:32:54.073Z] ====== als (apache-spark) [default], iteration 23 completed (19077.112 ms) ====== [2025-07-31T04:32:54.073Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-07-31T04:32:54.073Z] GC before operation: completed in 92.561 ms, heap usage 473.302 MB -> 71.712 MB. [2025-07-31T04:33:12.947Z] ====== als (apache-spark) [default], iteration 24 completed (19721.251 ms) ====== [2025-07-31T04:33:12.947Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-07-31T04:33:12.947Z] GC before operation: completed in 85.308 ms, heap usage 323.285 MB -> 71.806 MB. [2025-07-31T04:33:31.811Z] ====== als (apache-spark) [default], iteration 25 completed (19118.671 ms) ====== [2025-07-31T04:33:31.811Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-07-31T04:33:31.811Z] GC before operation: completed in 81.469 ms, heap usage 198.508 MB -> 71.739 MB. [2025-07-31T04:33:50.714Z] ====== als (apache-spark) [default], iteration 26 completed (18854.927 ms) ====== [2025-07-31T04:33:50.715Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-07-31T04:33:50.715Z] GC before operation: completed in 94.793 ms, heap usage 161.084 MB -> 72.061 MB. [2025-07-31T04:34:13.440Z] ====== als (apache-spark) [default], iteration 27 completed (19180.011 ms) ====== [2025-07-31T04:34:13.440Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-07-31T04:34:13.440Z] GC before operation: completed in 82.939 ms, heap usage 368.909 MB -> 72.058 MB. [2025-07-31T04:34:32.261Z] ====== als (apache-spark) [default], iteration 28 completed (19265.416 ms) ====== [2025-07-31T04:34:32.261Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-07-31T04:34:32.261Z] GC before operation: completed in 81.383 ms, heap usage 367.509 MB -> 72.382 MB. [2025-07-31T04:34:51.127Z] ====== als (apache-spark) [default], iteration 29 completed (19012.453 ms) ====== [2025-07-31T04:34:51.127Z] [2025-07-31T04:34:49.066+0000] org.renaissance.core (org.renaissance.core.DirUtils lambda$createScratchDirectory$1) [2025-07-31T04:34:51.127Z] WARNING: Error deleting scratch directory C:\jenkins\workspace\Test_openjdk21_hs_extended.perf_x86-64_windows_rerun\aqa-tests\TKG\output_17539358784423\renaissance-als_0\harness-042441-10182750569511830749: harness-042441-10182750569511830749\apache-spark\als\hadoop\bin\hadoop.dll [2025-07-31T04:34:51.127Z] ----------------------------------- [2025-07-31T04:34:51.127Z] renaissance-als_0_PASSED [2025-07-31T04:34:51.127Z] ----------------------------------- [2025-07-31T04:34:51.127Z] [2025-07-31T04:34:51.127Z] TEST TEARDOWN: [2025-07-31T04:34:51.127Z] Nothing to be done for teardown. [2025-07-31T04:34:51.127Z] renaissance-als_0 Finish Time: Thu Jul 31 04:34:49 2025 Epoch Time (ms): 1753936489843