[2025-09-25T01:30:02.056Z] Running test renaissance-als_0 ... [2025-09-25T01:30:02.056Z] =============================================== [2025-09-25T01:30:02.394Z] renaissance-als_0 Start Time: Thu Sep 25 01:30:02 2025 Epoch Time (ms): 1758763802108 [2025-09-25T01:30:02.394Z] variation: NoOptions [2025-09-25T01:30:02.394Z] JVM_OPTIONS: [2025-09-25T01:30:02.394Z] { \ [2025-09-25T01:30:02.394Z] echo ""; echo "TEST SETUP:"; \ [2025-09-25T01:30:02.394Z] echo "Nothing to be done for setup."; \ [2025-09-25T01:30:02.394Z] mkdir -p "C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17587634461462\\renaissance-als_0"; \ [2025-09-25T01:30:02.394Z] cd "C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17587634461462\\renaissance-als_0"; \ [2025-09-25T01:30:02.394Z] echo ""; echo "TESTING:"; \ [2025-09-25T01:30:02.394Z] "c:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows/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/aqa-tests///..//jvmtest\\perf\\renaissance\\renaissance.jar" --json ""C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17587634461462\\renaissance-als_0"\\als.json" als; \ [2025-09-25T01:30:02.394Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows/aqa-tests/; rm -f -r "C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17587634461462\\renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-09-25T01:30:02.394Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-09-25T01:30:02.394Z] echo "Nothing to be done for teardown."; \ [2025-09-25T01:30:02.394Z] } 2>&1 | tee -a "C:/jenkins/workspace/Test_openjdk21_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17587634461462\\TestTargetResult"; [2025-09-25T01:30:02.742Z] [2025-09-25T01:30:02.742Z] TEST SETUP: [2025-09-25T01:30:02.742Z] Nothing to be done for setup. [2025-09-25T01:30:02.742Z] [2025-09-25T01:30:02.742Z] TESTING: [2025-09-25T01:30:30.418Z] NOTE: 'als' benchmark uses Spark local executor with 2 (out of 2) threads. [2025-09-25T01:30:34.520Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-09-25T01:30:34.520Z] GC before operation: completed in 91.135 ms, heap usage 48.830 MB -> 35.446 MB. [2025-09-25T01:31:46.940Z] ====== als (apache-spark) [default], iteration 0 completed (59527.829 ms) ====== [2025-09-25T01:31:46.940Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-09-25T01:31:46.940Z] GC before operation: completed in 329.251 ms, heap usage 93.523 MB -> 61.977 MB. [2025-09-25T01:32:07.958Z] ====== als (apache-spark) [default], iteration 1 completed (31525.275 ms) ====== [2025-09-25T01:32:07.958Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-09-25T01:32:08.525Z] GC before operation: completed in 136.777 ms, heap usage 145.823 MB -> 62.975 MB. [2025-09-25T01:32:44.232Z] ====== als (apache-spark) [default], iteration 2 completed (31083.017 ms) ====== [2025-09-25T01:32:44.232Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-09-25T01:32:44.232Z] GC before operation: completed in 155.799 ms, heap usage 326.639 MB -> 64.151 MB. [2025-09-25T01:33:12.906Z] ====== als (apache-spark) [default], iteration 3 completed (30737.840 ms) ====== [2025-09-25T01:33:12.906Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-09-25T01:33:12.906Z] GC before operation: completed in 140.835 ms, heap usage 408.744 MB -> 64.352 MB. [2025-09-25T01:33:41.558Z] ====== als (apache-spark) [default], iteration 4 completed (29088.189 ms) ====== [2025-09-25T01:33:41.558Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-09-25T01:33:41.558Z] GC before operation: completed in 225.067 ms, heap usage 118.955 MB -> 64.170 MB. [2025-09-25T01:34:15.828Z] ====== als (apache-spark) [default], iteration 5 completed (29973.694 ms) ====== [2025-09-25T01:34:15.828Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-09-25T01:34:15.828Z] GC before operation: completed in 143.712 ms, heap usage 219.839 MB -> 65.301 MB. [2025-09-25T01:34:44.909Z] ====== als (apache-spark) [default], iteration 6 completed (30130.219 ms) ====== [2025-09-25T01:34:44.909Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-09-25T01:34:44.909Z] GC before operation: completed in 162.272 ms, heap usage 242.298 MB -> 65.901 MB. [2025-09-25T01:35:13.947Z] ====== als (apache-spark) [default], iteration 7 completed (30857.849 ms) ====== [2025-09-25T01:35:13.947Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-09-25T01:35:14.726Z] GC before operation: completed in 225.051 ms, heap usage 149.870 MB -> 65.859 MB. [2025-09-25T01:35:49.072Z] ====== als (apache-spark) [default], iteration 8 completed (29748.736 ms) ====== [2025-09-25T01:35:49.073Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-09-25T01:35:49.073Z] GC before operation: completed in 136.676 ms, heap usage 298.336 MB -> 67.101 MB. [2025-09-25T01:36:18.045Z] ====== als (apache-spark) [default], iteration 9 completed (29435.626 ms) ====== [2025-09-25T01:36:18.045Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-09-25T01:36:18.045Z] GC before operation: completed in 168.113 ms, heap usage 237.727 MB -> 67.235 MB. [2025-09-25T01:36:46.728Z] ====== als (apache-spark) [default], iteration 10 completed (29428.190 ms) ====== [2025-09-25T01:36:46.728Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-09-25T01:36:46.728Z] GC before operation: completed in 161.111 ms, heap usage 498.198 MB -> 67.817 MB. [2025-09-25T01:37:15.593Z] ====== als (apache-spark) [default], iteration 11 completed (28894.411 ms) ====== [2025-09-25T01:37:15.593Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-09-25T01:37:15.593Z] GC before operation: completed in 142.297 ms, heap usage 316.760 MB -> 67.741 MB. [2025-09-25T01:37:44.497Z] ====== als (apache-spark) [default], iteration 12 completed (28509.908 ms) ====== [2025-09-25T01:37:44.497Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-09-25T01:37:44.497Z] GC before operation: completed in 148.010 ms, heap usage 103.132 MB -> 67.598 MB. [2025-09-25T01:38:13.613Z] ====== als (apache-spark) [default], iteration 13 completed (29234.312 ms) ====== [2025-09-25T01:38:13.613Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-09-25T01:38:13.613Z] GC before operation: completed in 151.916 ms, heap usage 335.762 MB -> 68.336 MB. [2025-09-25T01:38:42.095Z] ====== als (apache-spark) [default], iteration 14 completed (28608.738 ms) ====== [2025-09-25T01:38:42.095Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-09-25T01:38:42.095Z] GC before operation: completed in 142.731 ms, heap usage 295.151 MB -> 68.454 MB. [2025-09-25T01:39:11.404Z] ====== als (apache-spark) [default], iteration 15 completed (28824.024 ms) ====== [2025-09-25T01:39:11.404Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-09-25T01:39:11.404Z] GC before operation: completed in 126.302 ms, heap usage 400.944 MB -> 68.787 MB. [2025-09-25T01:39:40.256Z] ====== als (apache-spark) [default], iteration 16 completed (28924.871 ms) ====== [2025-09-25T01:39:40.256Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-09-25T01:39:40.738Z] GC before operation: completed in 166.570 ms, heap usage 149.973 MB -> 68.881 MB. [2025-09-25T01:40:09.312Z] ====== als (apache-spark) [default], iteration 17 completed (28665.598 ms) ====== [2025-09-25T01:40:09.312Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-09-25T01:40:09.312Z] GC before operation: completed in 132.807 ms, heap usage 479.460 MB -> 69.553 MB. [2025-09-25T01:40:43.301Z] ====== als (apache-spark) [default], iteration 18 completed (28261.489 ms) ====== [2025-09-25T01:40:43.301Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-09-25T01:40:43.301Z] GC before operation: completed in 148.826 ms, heap usage 353.704 MB -> 69.580 MB. [2025-09-25T01:41:11.445Z] ====== als (apache-spark) [default], iteration 19 completed (28661.899 ms) ====== [2025-09-25T01:41:11.445Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-09-25T01:41:11.445Z] GC before operation: completed in 142.271 ms, heap usage 302.131 MB -> 69.856 MB. [2025-09-25T01:41:40.586Z] ====== als (apache-spark) [default], iteration 20 completed (29249.732 ms) ====== [2025-09-25T01:41:40.586Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-09-25T01:41:40.586Z] GC before operation: completed in 136.841 ms, heap usage 240.096 MB -> 70.053 MB. [2025-09-25T01:42:08.958Z] ====== als (apache-spark) [default], iteration 21 completed (28881.821 ms) ====== [2025-09-25T01:42:08.958Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-09-25T01:42:08.958Z] GC before operation: completed in 126.299 ms, heap usage 225.465 MB -> 70.379 MB. [2025-09-25T01:42:37.664Z] ====== als (apache-spark) [default], iteration 22 completed (30421.392 ms) ====== [2025-09-25T01:42:37.665Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-09-25T01:42:37.665Z] GC before operation: completed in 173.019 ms, heap usage 143.981 MB -> 70.451 MB. [2025-09-25T01:43:06.722Z] ====== als (apache-spark) [default], iteration 23 completed (28494.014 ms) ====== [2025-09-25T01:43:06.722Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-09-25T01:43:06.722Z] GC before operation: completed in 283.782 ms, heap usage 285.937 MB -> 70.835 MB. [2025-09-25T01:43:41.124Z] ====== als (apache-spark) [default], iteration 24 completed (28807.614 ms) ====== [2025-09-25T01:43:41.124Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-09-25T01:43:41.124Z] GC before operation: completed in 134.076 ms, heap usage 231.575 MB -> 71.071 MB. [2025-09-25T01:44:04.975Z] ====== als (apache-spark) [default], iteration 25 completed (28083.740 ms) ====== [2025-09-25T01:44:04.975Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-09-25T01:44:04.975Z] GC before operation: completed in 141.296 ms, heap usage 246.738 MB -> 71.391 MB. [2025-09-25T01:44:39.256Z] ====== als (apache-spark) [default], iteration 26 completed (29014.182 ms) ====== [2025-09-25T01:44:39.256Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-09-25T01:44:39.256Z] GC before operation: completed in 673.135 ms, heap usage 339.891 MB -> 71.737 MB. [2025-09-25T01:45:07.095Z] ====== als (apache-spark) [default], iteration 27 completed (28533.491 ms) ====== [2025-09-25T01:45:07.095Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-09-25T01:45:07.095Z] GC before operation: completed in 136.559 ms, heap usage 119.517 MB -> 71.739 MB. [2025-09-25T01:45:34.762Z] ====== als (apache-spark) [default], iteration 28 completed (28181.293 ms) ====== [2025-09-25T01:45:34.763Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-09-25T01:45:34.763Z] GC before operation: completed in 146.194 ms, heap usage 373.503 MB -> 72.273 MB. [2025-09-25T01:46:02.702Z] ====== als (apache-spark) [default], iteration 29 completed (28611.385 ms) ====== [2025-09-25T01:46:02.702Z] 01:46:01.000 WARN [block-manager-storage-async-thread-pool-438] org.apache.spark.shuffle.IndexShuffleBlockResolver - Error deleting data C:\jenkins\workspace\Test_openjdk21_hs_extended.perf_x86-64_windows\aqa-tests\TKG\output_17587634461462\renaissance-als_0\harness-013003-6677278194016638739\apache-spark\als\blockmgr-0a80b60c-976c-4620-ae35-02688ab4fac1\15\shuffle_675_7921_0.data [2025-09-25T01:46:02.702Z] 01:46:01.039 WARN [block-manager-storage-async-thread-pool-474] org.apache.spark.shuffle.IndexShuffleBlockResolver - Error deleting checksum C:\jenkins\workspace\Test_openjdk21_hs_extended.perf_x86-64_windows\aqa-tests\TKG\output_17587634461462\renaissance-als_0\harness-013003-6677278194016638739\apache-spark\als\blockmgr-0a80b60c-976c-4620-ae35-02688ab4fac1\2b\shuffle_687_7801_0.checksum.ADLER32 [2025-09-25T01:46:02.702Z] 01:46:01.048 WARN [block-manager-storage-async-thread-pool-417] org.apache.spark.shuffle.IndexShuffleBlockResolver - Error deleting checksum C:\jenkins\workspace\Test_openjdk21_hs_extended.perf_x86-64_windows\aqa-tests\TKG\output_17587634461462\renaissance-als_0\harness-013003-6677278194016638739\apache-spark\als\blockmgr-0a80b60c-976c-4620-ae35-02688ab4fac1\31\shuffle_684_7824_0.checksum.ADLER32 [2025-09-25T01:46:02.702Z] 01:46:01.052 WARN [block-manager-storage-async-thread-pool-195] org.apache.spark.shuffle.IndexShuffleBlockResolver - Error deleting checksum C:\jenkins\workspace\Test_openjdk21_hs_extended.perf_x86-64_windows\aqa-tests\TKG\output_17587634461462\renaissance-als_0\harness-013003-6677278194016638739\apache-spark\als\blockmgr-0a80b60c-976c-4620-ae35-02688ab4fac1\07\shuffle_679_7877_0.checksum.ADLER32 [2025-09-25T01:46:02.702Z] [2025-09-25T01:46:01.335+0000] org.renaissance.core (org.renaissance.core.DirUtils lambda$createScratchDirectory$1) [2025-09-25T01:46:02.702Z] WARNING: Error deleting scratch directory C:\jenkins\workspace\Test_openjdk21_hs_extended.perf_x86-64_windows\aqa-tests\TKG\output_17587634461462\renaissance-als_0\harness-013003-6677278194016638739: harness-013003-6677278194016638739\apache-spark\als\hadoop\bin\hadoop.dll [2025-09-25T01:46:02.702Z] ----------------------------------- [2025-09-25T01:46:02.702Z] renaissance-als_0_PASSED [2025-09-25T01:46:02.702Z] ----------------------------------- [2025-09-25T01:46:02.702Z] [2025-09-25T01:46:02.702Z] TEST TEARDOWN: [2025-09-25T01:46:02.702Z] Nothing to be done for teardown. [2025-09-25T01:46:02.702Z] renaissance-als_0 Finish Time: Thu Sep 25 01:46:01 2025 Epoch Time (ms): 1758764761964