[2026-01-11T01:36:41.726Z] Running test renaissance-als_0 ... [2026-01-11T01:36:41.726Z] =============================================== [2026-01-11T01:36:42.042Z] renaissance-als_0 Start Time: Sun Jan 11 01:36:41 2026 Epoch Time (ms): 1768095401794 [2026-01-11T01:36:42.042Z] variation: NoOptions [2026-01-11T01:36:42.042Z] JVM_OPTIONS: [2026-01-11T01:36:42.042Z] { \ [2026-01-11T01:36:42.042Z] echo ""; echo "TEST SETUP:"; \ [2026-01-11T01:36:42.042Z] echo "Nothing to be done for setup."; \ [2026-01-11T01:36:42.042Z] mkdir -p "C:/jenkins/workspace/Test_openjdk25_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17680950777787\\renaissance-als_0"; \ [2026-01-11T01:36:42.042Z] cd "C:/jenkins/workspace/Test_openjdk25_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17680950777787\\renaissance-als_0"; \ [2026-01-11T01:36:42.042Z] echo ""; echo "TESTING:"; \ [2026-01-11T01:36:42.042Z] "c:/jenkins/workspace/Test_openjdk25_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_openjdk25_hs_extended.perf_x86-64_windows/aqa-tests///..//jvmtest\\perf\\renaissance\\renaissance.jar" --json ""C:/jenkins/workspace/Test_openjdk25_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17680950777787\\renaissance-als_0"\\als.json" als; \ [2026-01-11T01:36:42.042Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd C:/jenkins/workspace/Test_openjdk25_hs_extended.perf_x86-64_windows/aqa-tests/; rm -f -r "C:/jenkins/workspace/Test_openjdk25_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17680950777787\\renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2026-01-11T01:36:42.042Z] echo ""; echo "TEST TEARDOWN:"; \ [2026-01-11T01:36:42.042Z] echo "Nothing to be done for teardown."; \ [2026-01-11T01:36:42.042Z] } 2>&1 | tee -a "C:/jenkins/workspace/Test_openjdk25_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17680950777787\\TestTargetResult"; [2026-01-11T01:36:42.398Z] [2026-01-11T01:36:42.398Z] TEST SETUP: [2026-01-11T01:36:42.398Z] Nothing to be done for setup. [2026-01-11T01:36:42.398Z] [2026-01-11T01:36:42.398Z] TESTING: [2026-01-11T01:36:43.150Z] WARNING: A terminally deprecated method in sun.misc.Unsafe has been called [2026-01-11T01:36:43.150Z] WARNING: sun.misc.Unsafe::objectFieldOffset has been called by scala.runtime.LazyVals$ (file:/C:/jenkins/workspace/Test_openjdk25_hs_extended.perf_x86-64_windows/aqa-tests/TKG/output_17680950777787/renaissance-als_0/launcher-013642-14635404852641369068/renaissance-harness_3/lib/scala3-library_3-3.3.4.jar) [2026-01-11T01:36:43.150Z] WARNING: Please consider reporting this to the maintainers of class scala.runtime.LazyVals$ [2026-01-11T01:36:43.150Z] WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release [2026-01-11T01:36:59.009Z] NOTE: 'als' benchmark uses Spark local executor with 2 (out of 2) threads. [2026-01-11T01:37:04.280Z] ====== als (apache-spark) [default], iteration 0 started ====== [2026-01-11T01:37:04.280Z] GC before operation: completed in 231.514 ms, heap usage 52.500 MB -> 35.481 MB. [2026-01-11T01:38:03.061Z] ====== als (apache-spark) [default], iteration 0 completed (51500.548 ms) ====== [2026-01-11T01:38:03.061Z] ====== als (apache-spark) [default], iteration 1 started ====== [2026-01-11T01:38:03.061Z] GC before operation: completed in 235.596 ms, heap usage 131.679 MB -> 61.528 MB. [2026-01-11T01:38:27.518Z] ====== als (apache-spark) [default], iteration 1 completed (29026.438 ms) ====== [2026-01-11T01:38:27.518Z] ====== als (apache-spark) [default], iteration 2 started ====== [2026-01-11T01:38:27.518Z] GC before operation: completed in 215.008 ms, heap usage 441.594 MB -> 63.128 MB. [2026-01-11T01:38:57.388Z] ====== als (apache-spark) [default], iteration 2 completed (29096.683 ms) ====== [2026-01-11T01:38:57.388Z] ====== als (apache-spark) [default], iteration 3 started ====== [2026-01-11T01:38:57.388Z] GC before operation: completed in 178.997 ms, heap usage 118.052 MB -> 62.827 MB. [2026-01-11T01:39:26.467Z] ====== als (apache-spark) [default], iteration 3 completed (27983.466 ms) ====== [2026-01-11T01:39:26.467Z] ====== als (apache-spark) [default], iteration 4 started ====== [2026-01-11T01:39:26.467Z] GC before operation: completed in 142.430 ms, heap usage 172.604 MB -> 63.801 MB. [2026-01-11T01:39:55.897Z] ====== als (apache-spark) [default], iteration 4 completed (27809.976 ms) ====== [2026-01-11T01:39:55.897Z] ====== als (apache-spark) [default], iteration 5 started ====== [2026-01-11T01:39:55.897Z] GC before operation: completed in 140.777 ms, heap usage 167.354 MB -> 63.936 MB. [2026-01-11T01:40:24.542Z] ====== als (apache-spark) [default], iteration 5 completed (27983.449 ms) ====== [2026-01-11T01:40:24.542Z] ====== als (apache-spark) [default], iteration 6 started ====== [2026-01-11T01:40:24.542Z] GC before operation: completed in 158.711 ms, heap usage 193.366 MB -> 64.645 MB. [2026-01-11T01:40:52.528Z] ====== als (apache-spark) [default], iteration 6 completed (27332.766 ms) ====== [2026-01-11T01:40:52.528Z] ====== als (apache-spark) [default], iteration 7 started ====== [2026-01-11T01:40:52.528Z] GC before operation: completed in 379.444 ms, heap usage 423.153 MB -> 65.983 MB. [2026-01-11T01:41:21.051Z] ====== als (apache-spark) [default], iteration 7 completed (27677.621 ms) ====== [2026-01-11T01:41:21.051Z] ====== als (apache-spark) [default], iteration 8 started ====== [2026-01-11T01:41:21.051Z] GC before operation: completed in 160.332 ms, heap usage 110.121 MB -> 66.513 MB. [2026-01-11T01:41:49.852Z] ====== als (apache-spark) [default], iteration 8 completed (27548.591 ms) ====== [2026-01-11T01:41:49.852Z] ====== als (apache-spark) [default], iteration 9 started ====== [2026-01-11T01:41:49.852Z] GC before operation: completed in 149.733 ms, heap usage 166.738 MB -> 66.118 MB. [2026-01-11T01:42:17.616Z] ====== als (apache-spark) [default], iteration 9 completed (27560.536 ms) ====== [2026-01-11T01:42:17.616Z] ====== als (apache-spark) [default], iteration 10 started ====== [2026-01-11T01:42:17.616Z] GC before operation: completed in 421.964 ms, heap usage 483.711 MB -> 67.398 MB. [2026-01-11T01:42:45.696Z] ====== als (apache-spark) [default], iteration 10 completed (27575.898 ms) ====== [2026-01-11T01:42:45.696Z] ====== als (apache-spark) [default], iteration 11 started ====== [2026-01-11T01:42:45.696Z] GC before operation: completed in 135.869 ms, heap usage 238.964 MB -> 67.303 MB. [2026-01-11T01:43:13.984Z] ====== als (apache-spark) [default], iteration 11 completed (27218.006 ms) ====== [2026-01-11T01:43:13.984Z] ====== als (apache-spark) [default], iteration 12 started ====== [2026-01-11T01:43:13.984Z] GC before operation: completed in 160.889 ms, heap usage 436.491 MB -> 67.852 MB. [2026-01-11T01:43:38.227Z] ====== als (apache-spark) [default], iteration 12 completed (27423.805 ms) ====== [2026-01-11T01:43:38.227Z] ====== als (apache-spark) [default], iteration 13 started ====== [2026-01-11T01:43:38.791Z] GC before operation: completed in 146.870 ms, heap usage 103.771 MB -> 67.256 MB. [2026-01-11T01:44:07.348Z] ====== als (apache-spark) [default], iteration 13 completed (27511.830 ms) ====== [2026-01-11T01:44:07.348Z] ====== als (apache-spark) [default], iteration 14 started ====== [2026-01-11T01:44:07.348Z] GC before operation: completed in 149.701 ms, heap usage 86.822 MB -> 67.406 MB. [2026-01-11T01:44:35.180Z] ====== als (apache-spark) [default], iteration 14 completed (26884.971 ms) ====== [2026-01-11T01:44:35.180Z] ====== als (apache-spark) [default], iteration 15 started ====== [2026-01-11T01:44:35.180Z] GC before operation: completed in 131.043 ms, heap usage 153.880 MB -> 68.211 MB. [2026-01-11T01:45:03.625Z] ====== als (apache-spark) [default], iteration 15 completed (27088.792 ms) ====== [2026-01-11T01:45:03.625Z] ====== als (apache-spark) [default], iteration 16 started ====== [2026-01-11T01:45:03.625Z] GC before operation: completed in 137.326 ms, heap usage 205.996 MB -> 68.344 MB. [2026-01-11T01:45:32.691Z] ====== als (apache-spark) [default], iteration 16 completed (26810.129 ms) ====== [2026-01-11T01:45:32.691Z] ====== als (apache-spark) [default], iteration 17 started ====== [2026-01-11T01:45:32.691Z] GC before operation: completed in 125.048 ms, heap usage 213.155 MB -> 68.614 MB. [2026-01-11T01:45:57.275Z] ====== als (apache-spark) [default], iteration 17 completed (27161.949 ms) ====== [2026-01-11T01:45:57.275Z] ====== als (apache-spark) [default], iteration 18 started ====== [2026-01-11T01:45:57.275Z] GC before operation: completed in 147.468 ms, heap usage 183.367 MB -> 68.864 MB. [2026-01-11T01:46:26.575Z] ====== als (apache-spark) [default], iteration 18 completed (27213.068 ms) ====== [2026-01-11T01:46:26.575Z] ====== als (apache-spark) [default], iteration 19 started ====== [2026-01-11T01:46:26.575Z] GC before operation: completed in 147.065 ms, heap usage 356.867 MB -> 69.321 MB. [2026-01-11T01:46:55.222Z] ====== als (apache-spark) [default], iteration 19 completed (27252.019 ms) ====== [2026-01-11T01:46:55.222Z] ====== als (apache-spark) [default], iteration 20 started ====== [2026-01-11T01:46:55.222Z] GC before operation: completed in 139.192 ms, heap usage 440.841 MB -> 69.788 MB. [2026-01-11T01:47:24.659Z] ====== als (apache-spark) [default], iteration 20 completed (29301.764 ms) ====== [2026-01-11T01:47:24.660Z] ====== als (apache-spark) [default], iteration 21 started ====== [2026-01-11T01:47:24.660Z] GC before operation: completed in 140.756 ms, heap usage 339.012 MB -> 69.838 MB. [2026-01-11T01:47:52.699Z] ====== als (apache-spark) [default], iteration 21 completed (27603.502 ms) ====== [2026-01-11T01:47:52.699Z] ====== als (apache-spark) [default], iteration 22 started ====== [2026-01-11T01:47:52.699Z] GC before operation: completed in 134.089 ms, heap usage 449.423 MB -> 70.368 MB. [2026-01-11T01:48:20.848Z] ====== als (apache-spark) [default], iteration 22 completed (27305.939 ms) ====== [2026-01-11T01:48:20.848Z] ====== als (apache-spark) [default], iteration 23 started ====== [2026-01-11T01:48:20.848Z] GC before operation: completed in 138.821 ms, heap usage 88.018 MB -> 69.702 MB. [2026-01-11T01:48:44.871Z] ====== als (apache-spark) [default], iteration 23 completed (27426.715 ms) ====== [2026-01-11T01:48:44.872Z] ====== als (apache-spark) [default], iteration 24 started ====== [2026-01-11T01:48:44.872Z] GC before operation: completed in 369.281 ms, heap usage 330.615 MB -> 70.660 MB. [2026-01-11T01:49:13.677Z] ====== als (apache-spark) [default], iteration 24 completed (26930.349 ms) ====== [2026-01-11T01:49:13.677Z] ====== als (apache-spark) [default], iteration 25 started ====== [2026-01-11T01:49:13.677Z] GC before operation: completed in 137.764 ms, heap usage 443.136 MB -> 71.175 MB. [2026-01-11T01:49:42.238Z] ====== als (apache-spark) [default], iteration 25 completed (26940.526 ms) ====== [2026-01-11T01:49:42.238Z] ====== als (apache-spark) [default], iteration 26 started ====== [2026-01-11T01:49:42.238Z] GC before operation: completed in 147.589 ms, heap usage 375.500 MB -> 71.176 MB. [2026-01-11T01:50:10.822Z] ====== als (apache-spark) [default], iteration 26 completed (27199.496 ms) ====== [2026-01-11T01:50:10.822Z] ====== als (apache-spark) [default], iteration 27 started ====== [2026-01-11T01:50:10.822Z] GC before operation: completed in 137.443 ms, heap usage 253.503 MB -> 71.281 MB. [2026-01-11T01:50:38.664Z] ====== als (apache-spark) [default], iteration 27 completed (27138.831 ms) ====== [2026-01-11T01:50:38.664Z] ====== als (apache-spark) [default], iteration 28 started ====== [2026-01-11T01:50:38.664Z] GC before operation: completed in 141.239 ms, heap usage 485.046 MB -> 71.412 MB. [2026-01-11T01:51:06.440Z] ====== als (apache-spark) [default], iteration 28 completed (27431.396 ms) ====== [2026-01-11T01:51:06.440Z] ====== als (apache-spark) [default], iteration 29 started ====== [2026-01-11T01:51:06.440Z] GC before operation: completed in 140.724 ms, heap usage 256.055 MB -> 71.280 MB. [2026-01-11T01:51:29.629Z] ====== als (apache-spark) [default], iteration 29 completed (26944.000 ms) ====== [2026-01-11T01:51:30.380Z] 01:51:30.132 WARN [Thread-1] org.renaissance.core - Error deleting scratch directory C:\jenkins\workspace\Test_openjdk25_hs_extended.perf_x86-64_windows\aqa-tests\TKG\output_17680950777787\renaissance-als_0\harness-013643-11474269453093077630: harness-013643-11474269453093077630\apache-spark\als\hadoop\bin\hadoop.dll [2026-01-11T01:51:30.380Z] [2026-01-11T01:51:30.012+0000] org.renaissance.core (org.renaissance.core.DirUtils lambda$createScratchDirectory$1) [2026-01-11T01:51:30.380Z] WARNING: Error deleting scratch directory C:\jenkins\workspace\Test_openjdk25_hs_extended.perf_x86-64_windows\aqa-tests\TKG\output_17680950777787\renaissance-als_0\harness-013643-11474269453093077630: harness-013643-11474269453093077630\apache-spark\als\hadoop\bin\hadoop.dll [2026-01-11T01:51:30.380Z] [2026-01-11T01:51:30.139+0000] org.renaissance.core (org.renaissance.core.DirUtils lambda$createScratchDirectory$1) [2026-01-11T01:51:30.380Z] W01:51:30.141 WARN [Thread-0] org.renaissance.core - Error deleting scratch directory C:\jenkins\workspace\Test_openjdk25_hs_extended.perf_x86-64_windows\aqa-tests\TKG\output_17680950777787\renaissance-als_0\launcher-013642-14635404852641369068: launcher-013642-14635404852641369068\renaissance-harness_3\lib\renaissance-harness_3-0.16.0.jar: The process cannot access the file because it is being used by another process [2026-01-11T01:51:30.380Z] ARNING: Error deleting scratch directory C:\jenkins\workspace\Test_openjdk25_hs_extended.perf_x86-64_windows\aqa-tests\TKG\output_17680950777787\renaissance-als_0\launcher-013642-14635404852641369068: launcher-013642-14635404852641369068\renaissance-harness_3\lib\renaissance-harness_3-0.16.0.jar: The process cannot access the file because it is being used by another process [2026-01-11T01:51:30.380Z] ----------------------------------- [2026-01-11T01:51:30.380Z] renaissance-als_0_PASSED [2026-01-11T01:51:30.380Z] ----------------------------------- [2026-01-11T01:51:30.713Z] [2026-01-11T01:51:30.713Z] TEST TEARDOWN: [2026-01-11T01:51:30.713Z] Nothing to be done for teardown. [2026-01-11T01:51:30.713Z] renaissance-als_0 Finish Time: Sun Jan 11 01:51:30 2026 Epoch Time (ms): 1768096290578