[2025-08-29T12:02:56.633Z] Running test renaissance-als_0 ... [2025-08-29T12:02:56.633Z] =============================================== [2025-08-29T12:02:56.633Z] renaissance-als_0 Start Time: Fri Aug 29 12:02:56 2025 Epoch Time (ms): 1756468976465 [2025-08-29T12:02:56.633Z] variation: NoOptions [2025-08-29T12:02:56.633Z] JVM_OPTIONS: [2025-08-29T12:02:56.633Z] { \ [2025-08-29T12:02:56.633Z] echo ""; echo "TEST SETUP:"; \ [2025-08-29T12:02:56.633Z] echo "Nothing to be done for setup."; \ [2025-08-29T12:02:56.633Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_1756468806605/renaissance-als_0"; \ [2025-08-29T12:02:56.633Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_1756468806605/renaissance-als_0"; \ [2025-08-29T12:02:56.633Z] echo ""; echo "TESTING:"; \ [2025-08-29T12:02:56.633Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/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 "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_1756468806605/renaissance-als_0"/als.json" als; \ [2025-08-29T12:02:56.633Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_1756468806605/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-08-29T12:02:56.633Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-08-29T12:02:56.633Z] echo "Nothing to be done for teardown."; \ [2025-08-29T12:02:56.633Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/../TKG/output_1756468806605/TestTargetResult"; [2025-08-29T12:02:56.633Z] [2025-08-29T12:02:56.633Z] TEST SETUP: [2025-08-29T12:02:56.633Z] Nothing to be done for setup. [2025-08-29T12:02:56.633Z] [2025-08-29T12:02:56.633Z] TESTING: [2025-08-29T12:03:03.354Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-08-29T12:03:06.387Z] WARNING: An illegal reflective access operation has occurred [2025-08-29T12:03:06.387Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64le_linux/aqa-tests/TKG/output_1756468806605/renaissance-als_0/harness-120257-3779872721075303827/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-08-29T12:03:06.387Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-08-29T12:03:06.387Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-08-29T12:03:06.387Z] WARNING: All illegal access operations will be denied in a future release [2025-08-29T12:03:07.353Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-08-29T12:03:07.353Z] GC before operation: completed in 58.740 ms, heap usage 287.002 MB -> 34.461 MB. [2025-08-29T12:03:29.011Z] ====== als (apache-spark) [default], iteration 0 completed (20048.726 ms) ====== [2025-08-29T12:03:29.011Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-08-29T12:03:29.011Z] GC before operation: completed in 119.838 ms, heap usage 139.123 MB -> 60.345 MB. [2025-08-29T12:03:37.205Z] ====== als (apache-spark) [default], iteration 1 completed (8723.302 ms) ====== [2025-08-29T12:03:37.205Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-08-29T12:03:37.205Z] GC before operation: completed in 99.206 ms, heap usage 221.752 MB -> 61.262 MB. [2025-08-29T12:03:45.388Z] ====== als (apache-spark) [default], iteration 2 completed (7906.856 ms) ====== [2025-08-29T12:03:45.388Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-08-29T12:03:46.347Z] GC before operation: completed in 105.361 ms, heap usage 534.685 MB -> 62.149 MB. [2025-08-29T12:03:54.561Z] ====== als (apache-spark) [default], iteration 3 completed (8116.960 ms) ====== [2025-08-29T12:03:54.561Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-08-29T12:03:54.561Z] GC before operation: completed in 100.772 ms, heap usage 238.545 MB -> 62.370 MB. [2025-08-29T12:04:02.747Z] ====== als (apache-spark) [default], iteration 4 completed (7889.077 ms) ====== [2025-08-29T12:04:02.747Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-08-29T12:04:02.747Z] GC before operation: completed in 102.225 ms, heap usage 253.890 MB -> 62.905 MB. [2025-08-29T12:04:10.918Z] ====== als (apache-spark) [default], iteration 5 completed (7639.017 ms) ====== [2025-08-29T12:04:10.918Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-08-29T12:04:10.918Z] GC before operation: completed in 103.965 ms, heap usage 249.044 MB -> 63.574 MB. [2025-08-29T12:04:19.110Z] ====== als (apache-spark) [default], iteration 6 completed (7817.497 ms) ====== [2025-08-29T12:04:19.110Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-08-29T12:04:19.110Z] GC before operation: completed in 113.175 ms, heap usage 241.213 MB -> 63.920 MB. [2025-08-29T12:04:26.608Z] ====== als (apache-spark) [default], iteration 7 completed (7532.904 ms) ====== [2025-08-29T12:04:26.608Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-08-29T12:04:26.608Z] GC before operation: completed in 102.523 ms, heap usage 203.143 MB -> 64.558 MB. [2025-08-29T12:04:34.778Z] ====== als (apache-spark) [default], iteration 8 completed (7920.520 ms) ====== [2025-08-29T12:04:34.778Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-08-29T12:04:34.778Z] GC before operation: completed in 106.098 ms, heap usage 255.967 MB -> 64.970 MB. [2025-08-29T12:04:42.953Z] ====== als (apache-spark) [default], iteration 9 completed (7641.182 ms) ====== [2025-08-29T12:04:42.953Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-08-29T12:04:42.953Z] GC before operation: completed in 123.480 ms, heap usage 282.801 MB -> 65.624 MB. [2025-08-29T12:04:51.145Z] ====== als (apache-spark) [default], iteration 10 completed (7446.909 ms) ====== [2025-08-29T12:04:51.145Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-08-29T12:04:51.145Z] GC before operation: completed in 101.501 ms, heap usage 215.177 MB -> 65.383 MB. [2025-08-29T12:04:59.330Z] ====== als (apache-spark) [default], iteration 11 completed (7871.273 ms) ====== [2025-08-29T12:04:59.331Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-08-29T12:04:59.331Z] GC before operation: completed in 104.053 ms, heap usage 133.156 MB -> 65.645 MB. [2025-08-29T12:05:07.681Z] ====== als (apache-spark) [default], iteration 12 completed (7448.095 ms) ====== [2025-08-29T12:05:07.681Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-08-29T12:05:07.681Z] GC before operation: completed in 109.884 ms, heap usage 425.654 MB -> 66.116 MB. [2025-08-29T12:05:14.400Z] ====== als (apache-spark) [default], iteration 13 completed (7386.392 ms) ====== [2025-08-29T12:05:14.400Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-08-29T12:05:14.400Z] GC before operation: completed in 109.196 ms, heap usage 200.471 MB -> 66.185 MB. [2025-08-29T12:05:22.588Z] ====== als (apache-spark) [default], iteration 14 completed (7542.596 ms) ====== [2025-08-29T12:05:22.588Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-08-29T12:05:22.588Z] GC before operation: completed in 111.438 ms, heap usage 233.988 MB -> 66.368 MB. [2025-08-29T12:05:29.580Z] ====== als (apache-spark) [default], iteration 15 completed (7341.298 ms) ====== [2025-08-29T12:05:29.580Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-08-29T12:05:29.580Z] GC before operation: completed in 112.647 ms, heap usage 481.432 MB -> 67.081 MB. [2025-08-29T12:05:37.755Z] ====== als (apache-spark) [default], iteration 16 completed (7514.877 ms) ====== [2025-08-29T12:05:37.755Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-08-29T12:05:37.755Z] GC before operation: completed in 108.332 ms, heap usage 117.984 MB -> 66.874 MB. [2025-08-29T12:05:45.975Z] ====== als (apache-spark) [default], iteration 17 completed (7294.282 ms) ====== [2025-08-29T12:05:45.975Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-08-29T12:05:45.975Z] GC before operation: completed in 112.320 ms, heap usage 271.872 MB -> 67.263 MB. [2025-08-29T12:05:54.136Z] ====== als (apache-spark) [default], iteration 18 completed (7814.608 ms) ====== [2025-08-29T12:05:54.136Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-08-29T12:05:54.136Z] GC before operation: completed in 122.808 ms, heap usage 102.358 MB -> 67.398 MB. [2025-08-29T12:06:02.305Z] ====== als (apache-spark) [default], iteration 19 completed (7654.779 ms) ====== [2025-08-29T12:06:02.305Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-08-29T12:06:02.305Z] GC before operation: completed in 109.686 ms, heap usage 252.057 MB -> 67.758 MB. [2025-08-29T12:06:10.479Z] ====== als (apache-spark) [default], iteration 20 completed (8057.999 ms) ====== [2025-08-29T12:06:10.479Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-08-29T12:06:10.479Z] GC before operation: completed in 110.578 ms, heap usage 253.717 MB -> 67.996 MB. [2025-08-29T12:06:18.656Z] ====== als (apache-spark) [default], iteration 21 completed (7438.402 ms) ====== [2025-08-29T12:06:18.656Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-08-29T12:06:18.656Z] GC before operation: completed in 113.480 ms, heap usage 257.780 MB -> 68.277 MB. [2025-08-29T12:06:25.560Z] ====== als (apache-spark) [default], iteration 22 completed (7434.705 ms) ====== [2025-08-29T12:06:25.560Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-08-29T12:06:25.560Z] GC before operation: completed in 116.363 ms, heap usage 184.258 MB -> 68.399 MB. [2025-08-29T12:06:33.746Z] ====== als (apache-spark) [default], iteration 23 completed (7880.908 ms) ====== [2025-08-29T12:06:33.746Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-08-29T12:06:33.746Z] GC before operation: completed in 114.534 ms, heap usage 265.010 MB -> 68.774 MB. [2025-08-29T12:06:42.339Z] ====== als (apache-spark) [default], iteration 24 completed (7861.783 ms) ====== [2025-08-29T12:06:42.339Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-08-29T12:06:42.339Z] GC before operation: completed in 125.926 ms, heap usage 159.967 MB -> 68.899 MB. [2025-08-29T12:06:50.526Z] ====== als (apache-spark) [default], iteration 25 completed (7792.529 ms) ====== [2025-08-29T12:06:50.526Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-08-29T12:06:50.526Z] GC before operation: completed in 133.928 ms, heap usage 446.761 MB -> 69.378 MB. [2025-08-29T12:06:58.716Z] ====== als (apache-spark) [default], iteration 26 completed (7559.477 ms) ====== [2025-08-29T12:06:58.716Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-08-29T12:06:58.716Z] GC before operation: completed in 130.376 ms, heap usage 229.236 MB -> 69.516 MB. [2025-08-29T12:07:06.912Z] ====== als (apache-spark) [default], iteration 27 completed (7895.598 ms) ====== [2025-08-29T12:07:06.912Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-08-29T12:07:06.912Z] GC before operation: completed in 116.659 ms, heap usage 149.072 MB -> 69.643 MB. [2025-08-29T12:07:15.091Z] ====== als (apache-spark) [default], iteration 28 completed (7756.678 ms) ====== [2025-08-29T12:07:15.091Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-08-29T12:07:15.091Z] GC before operation: completed in 115.122 ms, heap usage 253.711 MB -> 69.538 MB. [2025-08-29T12:07:21.831Z] ====== als (apache-spark) [default], iteration 29 completed (7466.227 ms) ====== [2025-08-29T12:07:22.788Z] ----------------------------------- [2025-08-29T12:07:22.788Z] renaissance-als_0_PASSED [2025-08-29T12:07:22.788Z] ----------------------------------- [2025-08-29T12:07:22.788Z] [2025-08-29T12:07:22.788Z] TEST TEARDOWN: [2025-08-29T12:07:22.788Z] Nothing to be done for teardown. [2025-08-29T12:07:22.788Z] renaissance-als_0 Finish Time: Fri Aug 29 12:07:21 2025 Epoch Time (ms): 1756469241988