[2025-05-08T09:41:25.013Z] Running test renaissance-als_0 ... [2025-05-08T09:41:25.340Z] =============================================== [2025-05-08T09:41:25.341Z] renaissance-als_0 Start Time: Thu May 8 09:41:25 2025 Epoch Time (ms): 1746697285236 [2025-05-08T09:41:25.341Z] variation: NoOptions [2025-05-08T09:41:25.668Z] JVM_OPTIONS: [2025-05-08T09:41:25.668Z] { \ [2025-05-08T09:41:25.668Z] echo ""; echo "TEST SETUP:"; \ [2025-05-08T09:41:25.668Z] echo "Nothing to be done for setup."; \ [2025-05-08T09:41:25.668Z] mkdir -p "C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17466972283983\\renaissance-als_0"; \ [2025-05-08T09:41:25.668Z] cd "C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17466972283983\\renaissance-als_0"; \ [2025-05-08T09:41:25.668Z] echo ""; echo "TESTING:"; \ [2025-05-08T09:41:25.668Z] "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_17466972283983\\renaissance-als_0"\\als.json" als; \ [2025-05-08T09:41:25.668Z] 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_17466972283983\\renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-05-08T09:41:25.668Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-05-08T09:41:25.668Z] echo "Nothing to be done for teardown."; \ [2025-05-08T09:41:25.668Z] } 2>&1 | tee -a "C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17466972283983\\TestTargetResult"; [2025-05-08T09:41:25.668Z] [2025-05-08T09:41:25.668Z] TEST SETUP: [2025-05-08T09:41:25.668Z] Nothing to be done for setup. [2025-05-08T09:41:25.668Z] [2025-05-08T09:41:25.668Z] TESTING: [2025-05-08T09:41:38.591Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-05-08T09:41:41.485Z] WARNING: An illegal reflective access operation has occurred [2025-05-08T09:41:41.485Z] 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_17466972283983/renaissance-als_0/harness-094126-15187146318623906122/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-05-08T09:41:41.485Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-05-08T09:41:41.485Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-05-08T09:41:41.485Z] WARNING: All illegal access operations will be denied in a future release [2025-05-08T09:41:42.651Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-05-08T09:41:42.985Z] GC before operation: completed in 108.476 ms, heap usage 312.002 MB -> 34.949 MB. [2025-05-08T09:42:16.438Z] ====== als (apache-spark) [default], iteration 0 completed (28636.104 ms) ====== [2025-05-08T09:42:16.438Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-05-08T09:42:16.438Z] GC before operation: completed in 119.004 ms, heap usage 164.985 MB -> 60.848 MB. [2025-05-08T09:42:29.454Z] ====== als (apache-spark) [default], iteration 1 completed (15717.114 ms) ====== [2025-05-08T09:42:29.454Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-05-08T09:42:29.454Z] GC before operation: completed in 145.833 ms, heap usage 506.922 MB -> 62.105 MB. [2025-05-08T09:42:45.298Z] ====== als (apache-spark) [default], iteration 2 completed (15260.061 ms) ====== [2025-05-08T09:42:45.298Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-05-08T09:42:45.298Z] GC before operation: completed in 127.755 ms, heap usage 238.686 MB -> 62.381 MB. [2025-05-08T09:43:01.160Z] ====== als (apache-spark) [default], iteration 3 completed (15455.094 ms) ====== [2025-05-08T09:43:01.160Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-05-08T09:43:01.160Z] GC before operation: completed in 150.076 ms, heap usage 224.710 MB -> 62.820 MB. [2025-05-08T09:43:16.899Z] ====== als (apache-spark) [default], iteration 4 completed (15031.317 ms) ====== [2025-05-08T09:43:16.899Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-05-08T09:43:16.899Z] GC before operation: completed in 135.405 ms, heap usage 157.529 MB -> 63.196 MB. [2025-05-08T09:43:32.593Z] ====== als (apache-spark) [default], iteration 5 completed (15127.550 ms) ====== [2025-05-08T09:43:32.593Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-05-08T09:43:32.593Z] GC before operation: completed in 144.731 ms, heap usage 228.725 MB -> 63.893 MB. [2025-05-08T09:43:48.281Z] ====== als (apache-spark) [default], iteration 6 completed (15629.264 ms) ====== [2025-05-08T09:43:48.281Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-05-08T09:43:48.281Z] GC before operation: completed in 143.041 ms, heap usage 122.139 MB -> 64.304 MB. [2025-05-08T09:44:04.083Z] ====== als (apache-spark) [default], iteration 7 completed (14848.851 ms) ====== [2025-05-08T09:44:04.083Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-05-08T09:44:04.083Z] GC before operation: completed in 134.094 ms, heap usage 220.525 MB -> 64.920 MB. [2025-05-08T09:44:19.878Z] ====== als (apache-spark) [default], iteration 8 completed (15122.293 ms) ====== [2025-05-08T09:44:19.878Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-05-08T09:44:19.878Z] GC before operation: completed in 158.081 ms, heap usage 301.329 MB -> 65.618 MB. [2025-05-08T09:44:35.744Z] ====== als (apache-spark) [default], iteration 9 completed (15430.442 ms) ====== [2025-05-08T09:44:35.744Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-05-08T09:44:35.744Z] GC before operation: completed in 138.092 ms, heap usage 262.403 MB -> 65.753 MB. [2025-05-08T09:44:51.437Z] ====== als (apache-spark) [default], iteration 10 completed (16119.784 ms) ====== [2025-05-08T09:44:51.437Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-05-08T09:44:51.437Z] GC before operation: completed in 136.598 ms, heap usage 324.909 MB -> 66.192 MB. [2025-05-08T09:45:07.365Z] ====== als (apache-spark) [default], iteration 11 completed (15125.110 ms) ====== [2025-05-08T09:45:07.365Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-05-08T09:45:07.365Z] GC before operation: completed in 136.718 ms, heap usage 287.050 MB -> 66.218 MB. [2025-05-08T09:45:23.089Z] ====== als (apache-spark) [default], iteration 12 completed (15046.751 ms) ====== [2025-05-08T09:45:23.089Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-05-08T09:45:23.089Z] GC before operation: completed in 140.054 ms, heap usage 94.127 MB -> 66.349 MB. [2025-05-08T09:45:36.188Z] ====== als (apache-spark) [default], iteration 13 completed (14803.156 ms) ====== [2025-05-08T09:45:36.188Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-05-08T09:45:36.188Z] GC before operation: completed in 140.711 ms, heap usage 166.292 MB -> 66.592 MB. [2025-05-08T09:45:52.160Z] ====== als (apache-spark) [default], iteration 14 completed (15243.727 ms) ====== [2025-05-08T09:45:52.160Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-05-08T09:45:52.160Z] GC before operation: completed in 132.034 ms, heap usage 107.695 MB -> 66.844 MB. [2025-05-08T09:46:07.985Z] ====== als (apache-spark) [default], iteration 15 completed (14405.169 ms) ====== [2025-05-08T09:46:07.985Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-05-08T09:46:07.985Z] GC before operation: completed in 150.497 ms, heap usage 238.100 MB -> 67.250 MB. [2025-05-08T09:46:21.162Z] ====== als (apache-spark) [default], iteration 16 completed (14974.689 ms) ====== [2025-05-08T09:46:21.162Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-05-08T09:46:21.536Z] GC before operation: completed in 144.509 ms, heap usage 98.720 MB -> 67.357 MB. [2025-05-08T09:46:37.445Z] ====== als (apache-spark) [default], iteration 17 completed (15483.676 ms) ====== [2025-05-08T09:46:37.445Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-05-08T09:46:37.445Z] GC before operation: completed in 141.713 ms, heap usage 144.321 MB -> 67.603 MB. [2025-05-08T09:46:53.216Z] ====== als (apache-spark) [default], iteration 18 completed (15000.992 ms) ====== [2025-05-08T09:46:53.216Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-05-08T09:46:53.216Z] GC before operation: completed in 146.835 ms, heap usage 95.918 MB -> 67.852 MB. [2025-05-08T09:47:09.122Z] ====== als (apache-spark) [default], iteration 19 completed (15492.631 ms) ====== [2025-05-08T09:47:09.122Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-05-08T09:47:09.122Z] GC before operation: completed in 168.919 ms, heap usage 286.470 MB -> 68.243 MB. [2025-05-08T09:47:25.046Z] ====== als (apache-spark) [default], iteration 20 completed (14985.973 ms) ====== [2025-05-08T09:47:25.046Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-05-08T09:47:25.046Z] GC before operation: completed in 140.108 ms, heap usage 237.413 MB -> 68.495 MB. [2025-05-08T09:47:40.815Z] ====== als (apache-spark) [default], iteration 21 completed (14931.257 ms) ====== [2025-05-08T09:47:40.815Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-05-08T09:47:40.815Z] GC before operation: completed in 156.303 ms, heap usage 278.085 MB -> 68.736 MB. [2025-05-08T09:47:56.617Z] ====== als (apache-spark) [default], iteration 22 completed (16524.206 ms) ====== [2025-05-08T09:47:56.618Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-05-08T09:47:56.618Z] GC before operation: completed in 136.437 ms, heap usage 148.584 MB -> 68.890 MB. [2025-05-08T09:48:12.374Z] ====== als (apache-spark) [default], iteration 23 completed (14632.688 ms) ====== [2025-05-08T09:48:12.374Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-05-08T09:48:12.374Z] GC before operation: completed in 146.602 ms, heap usage 249.114 MB -> 69.267 MB. [2025-05-08T09:48:31.226Z] ====== als (apache-spark) [default], iteration 24 completed (14920.022 ms) ====== [2025-05-08T09:48:31.226Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-05-08T09:48:31.226Z] GC before operation: completed in 139.105 ms, heap usage 280.889 MB -> 69.508 MB. [2025-05-08T09:48:42.124Z] ====== als (apache-spark) [default], iteration 25 completed (14783.041 ms) ====== [2025-05-08T09:48:42.124Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-05-08T09:48:42.124Z] GC before operation: completed in 141.094 ms, heap usage 161.519 MB -> 69.643 MB. [2025-05-08T09:48:56.361Z] ====== als (apache-spark) [default], iteration 26 completed (14601.854 ms) ====== [2025-05-08T09:48:56.361Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-05-08T09:48:56.361Z] GC before operation: completed in 148.927 ms, heap usage 351.111 MB -> 70.110 MB. [2025-05-08T09:49:12.231Z] ====== als (apache-spark) [default], iteration 27 completed (15016.714 ms) ====== [2025-05-08T09:49:12.231Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-05-08T09:49:12.231Z] GC before operation: completed in 148.435 ms, heap usage 233.951 MB -> 69.791 MB. [2025-05-08T09:49:28.204Z] ====== als (apache-spark) [default], iteration 28 completed (14829.703 ms) ====== [2025-05-08T09:49:28.204Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-05-08T09:49:28.204Z] GC before operation: completed in 141.220 ms, heap usage 289.771 MB -> 70.156 MB. [2025-05-08T09:49:41.154Z] ====== als (apache-spark) [default], iteration 29 completed (14426.623 ms) ====== [2025-05-08T09:49:41.826Z] ----------------------------------- [2025-05-08T09:49:41.826Z] renaissance-als_0_PASSED [2025-05-08T09:49:41.826Z] ----------------------------------- [2025-05-08T09:49:41.826Z] [2025-05-08T09:49:41.826Z] TEST TEARDOWN: [2025-05-08T09:49:41.826Z] Nothing to be done for teardown. [2025-05-08T09:49:42.137Z] renaissance-als_0 Finish Time: Thu May 8 09:49:41 2025 Epoch Time (ms): 1746697781832