[2025-03-31T01:21:27.703Z] Running test renaissance-als_0 ... [2025-03-31T01:21:27.703Z] =============================================== [2025-03-31T01:21:28.030Z] renaissance-als_0 Start Time: Mon Mar 31 01:21:27 2025 Epoch Time (ms): 1743384087737 [2025-03-31T01:21:28.030Z] variation: NoOptions [2025-03-31T01:21:28.030Z] JVM_OPTIONS: [2025-03-31T01:21:28.030Z] { \ [2025-03-31T01:21:28.030Z] echo ""; echo "TEST SETUP:"; \ [2025-03-31T01:21:28.030Z] echo "Nothing to be done for setup."; \ [2025-03-31T01:21:28.030Z] mkdir -p "C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17433840294711\\renaissance-als_0"; \ [2025-03-31T01:21:28.030Z] cd "C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17433840294711\\renaissance-als_0"; \ [2025-03-31T01:21:28.030Z] echo ""; echo "TESTING:"; \ [2025-03-31T01:21:28.030Z] "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_17433840294711\\renaissance-als_0"\\als.json" als; \ [2025-03-31T01:21:28.030Z] 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_17433840294711\\renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-03-31T01:21:28.030Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-03-31T01:21:28.030Z] echo "Nothing to be done for teardown."; \ [2025-03-31T01:21:28.030Z] } 2>&1 | tee -a "C:/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_windows/aqa-tests/\\TKG\\output_17433840294711\\TestTargetResult"; [2025-03-31T01:21:28.030Z] [2025-03-31T01:21:28.030Z] TEST SETUP: [2025-03-31T01:21:28.030Z] Nothing to be done for setup. [2025-03-31T01:21:28.030Z] [2025-03-31T01:21:28.030Z] TESTING: [2025-03-31T01:21:43.647Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-03-31T01:21:43.977Z] WARNING: An illegal reflective access operation has occurred [2025-03-31T01:21:43.977Z] 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_17433840294711/renaissance-als_0/harness-012128-15405009010294462050/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-03-31T01:21:43.977Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-03-31T01:21:43.977Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-03-31T01:21:43.977Z] WARNING: All illegal access operations will be denied in a future release [2025-03-31T01:21:45.576Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-03-31T01:21:45.576Z] GC before operation: completed in 104.359 ms, heap usage 289.500 MB -> 34.960 MB. [2025-03-31T01:22:19.131Z] ====== als (apache-spark) [default], iteration 0 completed (29474.941 ms) ====== [2025-03-31T01:22:19.131Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-03-31T01:22:19.131Z] GC before operation: completed in 119.756 ms, heap usage 213.467 MB -> 61.005 MB. [2025-03-31T01:22:32.143Z] ====== als (apache-spark) [default], iteration 1 completed (15855.099 ms) ====== [2025-03-31T01:22:32.143Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-03-31T01:22:32.143Z] GC before operation: completed in 138.539 ms, heap usage 223.042 MB -> 61.809 MB. [2025-03-31T01:22:47.940Z] ====== als (apache-spark) [default], iteration 2 completed (15444.440 ms) ====== [2025-03-31T01:22:47.940Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-03-31T01:22:47.940Z] GC before operation: completed in 137.033 ms, heap usage 128.776 MB -> 62.243 MB. [2025-03-31T01:23:03.636Z] ====== als (apache-spark) [default], iteration 3 completed (14944.855 ms) ====== [2025-03-31T01:23:03.636Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-03-31T01:23:03.636Z] GC before operation: completed in 143.534 ms, heap usage 255.326 MB -> 62.858 MB. [2025-03-31T01:23:19.595Z] ====== als (apache-spark) [default], iteration 4 completed (15553.038 ms) ====== [2025-03-31T01:23:19.595Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-03-31T01:23:19.595Z] GC before operation: completed in 144.500 ms, heap usage 239.830 MB -> 63.376 MB. [2025-03-31T01:23:35.521Z] ====== als (apache-spark) [default], iteration 5 completed (15245.560 ms) ====== [2025-03-31T01:23:35.521Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-03-31T01:23:35.521Z] GC before operation: completed in 145.044 ms, heap usage 239.296 MB -> 63.925 MB. [2025-03-31T01:23:51.334Z] ====== als (apache-spark) [default], iteration 6 completed (15157.290 ms) ====== [2025-03-31T01:23:51.334Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-03-31T01:23:51.334Z] GC before operation: completed in 133.872 ms, heap usage 232.907 MB -> 64.413 MB. [2025-03-31T01:24:07.138Z] ====== als (apache-spark) [default], iteration 7 completed (14994.668 ms) ====== [2025-03-31T01:24:07.138Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-03-31T01:24:07.138Z] GC before operation: completed in 139.480 ms, heap usage 309.949 MB -> 65.050 MB. [2025-03-31T01:24:22.962Z] ====== als (apache-spark) [default], iteration 8 completed (15550.939 ms) ====== [2025-03-31T01:24:22.962Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-03-31T01:24:22.962Z] GC before operation: completed in 138.358 ms, heap usage 264.082 MB -> 65.464 MB. [2025-03-31T01:24:38.693Z] ====== als (apache-spark) [default], iteration 9 completed (14577.691 ms) ====== [2025-03-31T01:24:38.693Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-03-31T01:24:38.693Z] GC before operation: completed in 161.148 ms, heap usage 269.039 MB -> 65.792 MB. [2025-03-31T01:24:51.757Z] ====== als (apache-spark) [default], iteration 10 completed (14967.563 ms) ====== [2025-03-31T01:24:51.757Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-03-31T01:24:52.127Z] GC before operation: completed in 154.103 ms, heap usage 408.200 MB -> 66.220 MB. [2025-03-31T01:25:07.974Z] ====== als (apache-spark) [default], iteration 11 completed (15212.355 ms) ====== [2025-03-31T01:25:07.974Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-03-31T01:25:07.974Z] GC before operation: completed in 133.013 ms, heap usage 247.534 MB -> 66.257 MB. [2025-03-31T01:25:23.722Z] ====== als (apache-spark) [default], iteration 12 completed (15241.176 ms) ====== [2025-03-31T01:25:23.722Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-03-31T01:25:23.722Z] GC before operation: completed in 142.875 ms, heap usage 263.750 MB -> 66.491 MB. [2025-03-31T01:25:40.002Z] ====== als (apache-spark) [default], iteration 13 completed (15366.624 ms) ====== [2025-03-31T01:25:40.002Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-03-31T01:25:40.002Z] GC before operation: completed in 143.142 ms, heap usage 248.540 MB -> 66.739 MB. [2025-03-31T01:25:55.842Z] ====== als (apache-spark) [default], iteration 14 completed (14955.018 ms) ====== [2025-03-31T01:25:55.842Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-03-31T01:25:55.842Z] GC before operation: completed in 144.932 ms, heap usage 333.553 MB -> 67.103 MB. [2025-03-31T01:26:09.008Z] ====== als (apache-spark) [default], iteration 15 completed (14805.146 ms) ====== [2025-03-31T01:26:09.008Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-03-31T01:26:09.413Z] GC before operation: completed in 142.675 ms, heap usage 264.095 MB -> 67.261 MB. [2025-03-31T01:26:25.186Z] ====== als (apache-spark) [default], iteration 16 completed (15130.957 ms) ====== [2025-03-31T01:26:25.186Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-03-31T01:26:25.186Z] GC before operation: completed in 134.226 ms, heap usage 232.678 MB -> 67.512 MB. [2025-03-31T01:26:40.975Z] ====== als (apache-spark) [default], iteration 17 completed (14790.706 ms) ====== [2025-03-31T01:26:40.975Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-03-31T01:26:40.975Z] GC before operation: completed in 140.259 ms, heap usage 147.081 MB -> 67.663 MB. [2025-03-31T01:26:56.696Z] ====== als (apache-spark) [default], iteration 18 completed (15012.892 ms) ====== [2025-03-31T01:26:56.696Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-03-31T01:26:56.696Z] GC before operation: completed in 148.935 ms, heap usage 324.475 MB -> 68.142 MB. [2025-03-31T01:27:12.441Z] ====== als (apache-spark) [default], iteration 19 completed (15615.284 ms) ====== [2025-03-31T01:27:12.441Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-03-31T01:27:12.441Z] GC before operation: completed in 132.798 ms, heap usage 97.273 MB -> 68.158 MB. [2025-03-31T01:27:28.265Z] ====== als (apache-spark) [default], iteration 20 completed (15537.896 ms) ====== [2025-03-31T01:27:28.265Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-03-31T01:27:28.265Z] GC before operation: completed in 140.936 ms, heap usage 134.819 MB -> 68.404 MB. [2025-03-31T01:27:44.001Z] ====== als (apache-spark) [default], iteration 21 completed (14867.294 ms) ====== [2025-03-31T01:27:44.001Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-03-31T01:27:44.001Z] GC before operation: completed in 166.094 ms, heap usage 253.109 MB -> 68.770 MB. [2025-03-31T01:27:59.757Z] ====== als (apache-spark) [default], iteration 22 completed (14879.444 ms) ====== [2025-03-31T01:27:59.757Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-03-31T01:27:59.757Z] GC before operation: completed in 146.249 ms, heap usage 264.973 MB -> 69.046 MB. [2025-03-31T01:28:12.800Z] ====== als (apache-spark) [default], iteration 23 completed (15154.780 ms) ====== [2025-03-31T01:28:12.800Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-03-31T01:28:12.800Z] GC before operation: completed in 150.669 ms, heap usage 285.017 MB -> 69.294 MB. [2025-03-31T01:28:28.647Z] ====== als (apache-spark) [default], iteration 24 completed (15252.793 ms) ====== [2025-03-31T01:28:28.647Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-03-31T01:28:28.647Z] GC before operation: completed in 139.729 ms, heap usage 296.897 MB -> 69.545 MB. [2025-03-31T01:28:44.433Z] ====== als (apache-spark) [default], iteration 25 completed (15034.819 ms) ====== [2025-03-31T01:28:44.433Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-03-31T01:28:44.433Z] GC before operation: completed in 150.834 ms, heap usage 268.311 MB -> 69.796 MB. [2025-03-31T01:29:00.239Z] ====== als (apache-spark) [default], iteration 26 completed (14945.612 ms) ====== [2025-03-31T01:29:00.239Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-03-31T01:29:00.239Z] GC before operation: completed in 148.295 ms, heap usage 233.385 MB -> 69.922 MB. [2025-03-31T01:29:16.051Z] ====== als (apache-spark) [default], iteration 27 completed (15053.497 ms) ====== [2025-03-31T01:29:16.051Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-03-31T01:29:16.051Z] GC before operation: completed in 152.781 ms, heap usage 265.181 MB -> 69.822 MB. [2025-03-31T01:29:31.761Z] ====== als (apache-spark) [default], iteration 28 completed (14969.833 ms) ====== [2025-03-31T01:29:31.761Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-03-31T01:29:31.761Z] GC before operation: completed in 150.101 ms, heap usage 265.575 MB -> 70.061 MB. [2025-03-31T01:29:47.526Z] ====== als (apache-spark) [default], iteration 29 completed (17374.965 ms) ====== [2025-03-31T01:29:47.852Z] ----------------------------------- [2025-03-31T01:29:47.852Z] renaissance-als_0_PASSED [2025-03-31T01:29:47.852Z] ----------------------------------- [2025-03-31T01:29:48.164Z] [2025-03-31T01:29:48.164Z] TEST TEARDOWN: [2025-03-31T01:29:48.164Z] Nothing to be done for teardown. [2025-03-31T01:29:48.485Z] renaissance-als_0 Finish Time: Mon Mar 31 01:29:48 2025 Epoch Time (ms): 1743384588153