[2025-11-20T16:46:43.526Z] Running test renaissance-als_0 ... [2025-11-20T16:46:43.526Z] =============================================== [2025-11-20T16:46:43.526Z] renaissance-als_0 Start Time: Thu Nov 20 16:46:43 2025 Epoch Time (ms): 1763657203476 [2025-11-20T16:46:43.871Z] variation: NoOptions [2025-11-20T16:46:43.871Z] JVM_OPTIONS: [2025-11-20T16:46:43.871Z] { \ [2025-11-20T16:46:43.871Z] echo ""; echo "TEST SETUP:"; \ [2025-11-20T16:46:43.871Z] echo "Nothing to be done for setup."; \ [2025-11-20T16:46:43.871Z] mkdir -p "C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17636570004825\\renaissance-als_0"; \ [2025-11-20T16:46:43.871Z] cd "C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17636570004825\\renaissance-als_0"; \ [2025-11-20T16:46:43.871Z] echo ""; echo "TESTING:"; \ [2025-11-20T16:46:43.871Z] "c:/jenkins/workspace/Test_openjdk11_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_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests///..//jvmtest\\perf\\renaissance\\renaissance.jar" --json ""C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17636570004825\\renaissance-als_0"\\als.json" als; \ [2025-11-20T16:46:43.871Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/; rm -f -r "C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17636570004825\\renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-11-20T16:46:43.871Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-11-20T16:46:43.871Z] echo "Nothing to be done for teardown."; \ [2025-11-20T16:46:43.871Z] } 2>&1 | tee -a "C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17636570004825\\TestTargetResult"; [2025-11-20T16:46:43.871Z] [2025-11-20T16:46:43.871Z] TEST SETUP: [2025-11-20T16:46:43.871Z] Nothing to be done for setup. [2025-11-20T16:46:43.871Z] [2025-11-20T16:46:43.871Z] TESTING: [2025-11-20T16:47:02.978Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-11-20T16:47:03.702Z] WARNING: An illegal reflective access operation has occurred [2025-11-20T16:47:03.702Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/TKG/output_17636570004825/renaissance-als_0/harness-164644-7058915923254509896/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-11-20T16:47:03.702Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-11-20T16:47:03.702Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-11-20T16:47:03.702Z] WARNING: All illegal access operations will be denied in a future release [2025-11-20T16:47:04.863Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-11-20T16:47:04.863Z] GC before operation: completed in 82.778 ms, heap usage 414.011 MB -> 35.014 MB. [2025-11-20T16:47:38.642Z] ====== als (apache-spark) [default], iteration 0 completed (30942.460 ms) ====== [2025-11-20T16:47:38.642Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-11-20T16:47:38.642Z] GC before operation: completed in 130.520 ms, heap usage 223.666 MB -> 60.931 MB. [2025-11-20T16:47:57.971Z] ====== als (apache-spark) [default], iteration 1 completed (18346.894 ms) ====== [2025-11-20T16:47:57.971Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-11-20T16:47:57.971Z] GC before operation: completed in 141.049 ms, heap usage 229.577 MB -> 61.888 MB. [2025-11-20T16:48:13.920Z] ====== als (apache-spark) [default], iteration 2 completed (17412.267 ms) ====== [2025-11-20T16:48:13.920Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-11-20T16:48:13.920Z] GC before operation: completed in 135.313 ms, heap usage 467.696 MB -> 62.630 MB. [2025-11-20T16:48:33.293Z] ====== als (apache-spark) [default], iteration 3 completed (17374.606 ms) ====== [2025-11-20T16:48:33.293Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-11-20T16:48:33.293Z] GC before operation: completed in 125.752 ms, heap usage 218.221 MB -> 62.814 MB. [2025-11-20T16:48:52.585Z] ====== als (apache-spark) [default], iteration 4 completed (18502.984 ms) ====== [2025-11-20T16:48:52.585Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-11-20T16:48:52.585Z] GC before operation: completed in 155.266 ms, heap usage 136.254 MB -> 62.772 MB. [2025-11-20T16:49:08.612Z] ====== als (apache-spark) [default], iteration 5 completed (16821.690 ms) ====== [2025-11-20T16:49:08.612Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-11-20T16:49:08.612Z] GC before operation: completed in 133.377 ms, heap usage 245.782 MB -> 63.915 MB. [2025-11-20T16:49:24.757Z] ====== als (apache-spark) [default], iteration 6 completed (17467.047 ms) ====== [2025-11-20T16:49:24.757Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-11-20T16:49:25.137Z] GC before operation: completed in 138.147 ms, heap usage 330.762 MB -> 64.500 MB. [2025-11-20T16:49:44.544Z] ====== als (apache-spark) [default], iteration 7 completed (17024.936 ms) ====== [2025-11-20T16:49:44.544Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-11-20T16:49:44.544Z] GC before operation: completed in 155.654 ms, heap usage 105.727 MB -> 64.345 MB. [2025-11-20T16:50:00.656Z] ====== als (apache-spark) [default], iteration 8 completed (17420.936 ms) ====== [2025-11-20T16:50:00.656Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-11-20T16:50:00.656Z] GC before operation: completed in 153.865 ms, heap usage 375.739 MB -> 65.635 MB. [2025-11-20T16:50:19.824Z] ====== als (apache-spark) [default], iteration 9 completed (16862.419 ms) ====== [2025-11-20T16:50:19.824Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-11-20T16:50:19.824Z] GC before operation: completed in 168.896 ms, heap usage 333.320 MB -> 65.830 MB. [2025-11-20T16:50:35.852Z] ====== als (apache-spark) [default], iteration 10 completed (16975.556 ms) ====== [2025-11-20T16:50:35.852Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-11-20T16:50:35.852Z] GC before operation: completed in 155.275 ms, heap usage 223.079 MB -> 66.090 MB. [2025-11-20T16:50:51.865Z] ====== als (apache-spark) [default], iteration 11 completed (16937.330 ms) ====== [2025-11-20T16:50:51.865Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-11-20T16:50:52.303Z] GC before operation: completed in 139.867 ms, heap usage 92.628 MB -> 66.121 MB. [2025-11-20T16:51:11.712Z] ====== als (apache-spark) [default], iteration 12 completed (16649.959 ms) ====== [2025-11-20T16:51:11.712Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-11-20T16:51:11.712Z] GC before operation: completed in 159.064 ms, heap usage 249.940 MB -> 66.482 MB. [2025-11-20T16:51:27.902Z] ====== als (apache-spark) [default], iteration 13 completed (16855.838 ms) ====== [2025-11-20T16:51:27.902Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-11-20T16:51:27.902Z] GC before operation: completed in 143.166 ms, heap usage 248.509 MB -> 66.723 MB. [2025-11-20T16:51:43.986Z] ====== als (apache-spark) [default], iteration 14 completed (16472.204 ms) ====== [2025-11-20T16:51:43.986Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-11-20T16:51:43.986Z] GC before operation: completed in 141.671 ms, heap usage 292.736 MB -> 66.972 MB. [2025-11-20T16:52:00.082Z] ====== als (apache-spark) [default], iteration 15 completed (16623.860 ms) ====== [2025-11-20T16:52:00.083Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-11-20T16:52:00.083Z] GC before operation: completed in 140.213 ms, heap usage 190.984 MB -> 67.122 MB. [2025-11-20T16:52:19.456Z] ====== als (apache-spark) [default], iteration 16 completed (16814.470 ms) ====== [2025-11-20T16:52:19.456Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-11-20T16:52:19.456Z] GC before operation: completed in 176.673 ms, heap usage 194.147 MB -> 66.903 MB. [2025-11-20T16:52:35.577Z] ====== als (apache-spark) [default], iteration 17 completed (17725.618 ms) ====== [2025-11-20T16:52:35.577Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-11-20T16:52:35.577Z] GC before operation: completed in 148.904 ms, heap usage 215.732 MB -> 67.733 MB. [2025-11-20T16:52:54.982Z] ====== als (apache-spark) [default], iteration 18 completed (17536.441 ms) ====== [2025-11-20T16:52:54.982Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-11-20T16:52:54.982Z] GC before operation: completed in 147.717 ms, heap usage 237.526 MB -> 67.982 MB. [2025-11-20T16:53:11.237Z] ====== als (apache-spark) [default], iteration 19 completed (17300.507 ms) ====== [2025-11-20T16:53:11.237Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-11-20T16:53:11.237Z] GC before operation: completed in 150.382 ms, heap usage 406.052 MB -> 68.335 MB. [2025-11-20T16:53:30.461Z] ====== als (apache-spark) [default], iteration 20 completed (17402.213 ms) ====== [2025-11-20T16:53:30.461Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-11-20T16:53:30.461Z] GC before operation: completed in 141.425 ms, heap usage 93.756 MB -> 68.348 MB. [2025-11-20T16:53:46.599Z] ====== als (apache-spark) [default], iteration 21 completed (16753.418 ms) ====== [2025-11-20T16:53:46.599Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-11-20T16:53:46.599Z] GC before operation: completed in 146.840 ms, heap usage 116.426 MB -> 68.594 MB. [2025-11-20T16:54:02.707Z] ====== als (apache-spark) [default], iteration 22 completed (16964.516 ms) ====== [2025-11-20T16:54:02.707Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-11-20T16:54:03.088Z] GC before operation: completed in 156.618 ms, heap usage 296.638 MB -> 68.994 MB. [2025-11-20T16:54:22.385Z] ====== als (apache-spark) [default], iteration 23 completed (16793.661 ms) ====== [2025-11-20T16:54:22.385Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-11-20T16:54:22.385Z] GC before operation: completed in 150.160 ms, heap usage 194.585 MB -> 69.123 MB. [2025-11-20T16:54:38.324Z] ====== als (apache-spark) [default], iteration 24 completed (16580.638 ms) ====== [2025-11-20T16:54:38.324Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-11-20T16:54:38.324Z] GC before operation: completed in 186.715 ms, heap usage 628.644 MB -> 69.921 MB. [2025-11-20T16:54:57.723Z] ====== als (apache-spark) [default], iteration 25 completed (18788.215 ms) ====== [2025-11-20T16:54:57.723Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-11-20T16:54:57.723Z] GC before operation: completed in 153.523 ms, heap usage 156.316 MB -> 69.625 MB. [2025-11-20T16:55:14.033Z] ====== als (apache-spark) [default], iteration 26 completed (16858.962 ms) ====== [2025-11-20T16:55:14.033Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-11-20T16:55:14.033Z] GC before operation: completed in 157.487 ms, heap usage 267.882 MB -> 69.987 MB. [2025-11-20T16:55:33.507Z] ====== als (apache-spark) [default], iteration 27 completed (18466.827 ms) ====== [2025-11-20T16:55:33.507Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-11-20T16:55:33.507Z] GC before operation: completed in 152.134 ms, heap usage 305.248 MB -> 70.357 MB. [2025-11-20T16:55:52.765Z] ====== als (apache-spark) [default], iteration 28 completed (18258.801 ms) ====== [2025-11-20T16:55:52.765Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-11-20T16:55:52.765Z] GC before operation: completed in 156.607 ms, heap usage 287.607 MB -> 70.014 MB. [2025-11-20T16:56:08.722Z] ====== als (apache-spark) [default], iteration 29 completed (16784.550 ms) ====== [2025-11-20T16:56:08.722Z] ----------------------------------- [2025-11-20T16:56:08.722Z] renaissance-als_0_PASSED [2025-11-20T16:56:08.722Z] ----------------------------------- [2025-11-20T16:56:08.722Z] [2025-11-20T16:56:08.722Z] TEST TEARDOWN: [2025-11-20T16:56:08.722Z] Nothing to be done for teardown. [2025-11-20T16:56:08.722Z] renaissance-als_0 Finish Time: Thu Nov 20 16:56:08 2025 Epoch Time (ms): 1763657768259