[2025-06-12T02:16:05.165Z] Running test renaissance-als_0 ... [2025-06-12T02:16:05.165Z] =============================================== [2025-06-12T02:16:05.165Z] renaissance-als_0 Start Time: Thu Jun 12 02:16:04 2025 Epoch Time (ms): 1749694564318 [2025-06-12T02:16:05.165Z] variation: NoOptions [2025-06-12T02:16:05.165Z] JVM_OPTIONS: [2025-06-12T02:16:05.165Z] { \ [2025-06-12T02:16:05.165Z] echo ""; echo "TEST SETUP:"; \ [2025-06-12T02:16:05.165Z] echo "Nothing to be done for setup."; \ [2025-06-12T02:16:05.165Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17496944902628/renaissance-als_0"; \ [2025-06-12T02:16:05.165Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17496944902628/renaissance-als_0"; \ [2025-06-12T02:16:05.165Z] echo ""; echo "TESTING:"; \ [2025-06-12T02:16:05.165Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/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_ppc64_aix/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17496944902628/renaissance-als_0"/als.json" als; \ [2025-06-12T02:16:05.165Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17496944902628/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-06-12T02:16:05.165Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-06-12T02:16:05.165Z] echo "Nothing to be done for teardown."; \ [2025-06-12T02:16:05.166Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_17496944902628/TestTargetResult"; [2025-06-12T02:16:05.166Z] [2025-06-12T02:16:05.166Z] TEST SETUP: [2025-06-12T02:16:05.166Z] Nothing to be done for setup. [2025-06-12T02:16:05.166Z] [2025-06-12T02:16:05.166Z] TESTING: [2025-06-12T02:17:38.441Z] NOTE: 'als' benchmark uses Spark local executor with 12 (out of 16) threads. [2025-06-12T02:17:38.441Z] WARNING: An illegal reflective access operation has occurred [2025-06-12T02:17:38.441Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_ppc64_aix/aqa-tests/TKG/output_17496944902628/renaissance-als_0/harness-021609-2988785229892633489/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-06-12T02:17:38.441Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-06-12T02:17:38.441Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-06-12T02:17:38.441Z] WARNING: All illegal access operations will be denied in a future release [2025-06-12T02:17:38.441Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-06-12T02:17:38.441Z] GC before operation: completed in 151.653 ms, heap usage 121.895 MB -> 35.076 MB. [2025-06-12T02:18:26.956Z] ====== als (apache-spark) [default], iteration 0 completed (47926.895 ms) ====== [2025-06-12T02:18:26.956Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-06-12T02:18:26.956Z] GC before operation: completed in 184.960 ms, heap usage 724.007 MB -> 61.712 MB. [2025-06-12T02:18:57.516Z] ====== als (apache-spark) [default], iteration 1 completed (30989.712 ms) ====== [2025-06-12T02:18:57.516Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-06-12T02:18:57.516Z] GC before operation: completed in 146.695 ms, heap usage 284.989 MB -> 62.048 MB. [2025-06-12T02:19:27.699Z] ====== als (apache-spark) [default], iteration 2 completed (31485.889 ms) ====== [2025-06-12T02:19:27.699Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-06-12T02:19:27.699Z] GC before operation: completed in 153.252 ms, heap usage 934.415 MB -> 63.284 MB. [2025-06-12T02:20:24.867Z] ====== als (apache-spark) [default], iteration 3 completed (54029.667 ms) ====== [2025-06-12T02:20:24.867Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-06-12T02:20:24.867Z] GC before operation: completed in 141.479 ms, heap usage 1.038 GB -> 63.874 MB. [2025-06-12T02:21:14.700Z] ====== als (apache-spark) [default], iteration 4 completed (46847.472 ms) ====== [2025-06-12T02:21:14.700Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-06-12T02:21:14.700Z] GC before operation: completed in 141.952 ms, heap usage 547.912 MB -> 63.915 MB. [2025-06-12T02:21:50.300Z] ====== als (apache-spark) [default], iteration 5 completed (39079.614 ms) ====== [2025-06-12T02:21:50.300Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-06-12T02:21:50.300Z] GC before operation: completed in 217.933 ms, heap usage 963.373 MB -> 64.848 MB. [2025-06-12T02:22:25.562Z] ====== als (apache-spark) [default], iteration 6 completed (34413.122 ms) ====== [2025-06-12T02:22:25.562Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-06-12T02:22:25.562Z] GC before operation: completed in 174.943 ms, heap usage 572.494 MB -> 65.122 MB. [2025-06-12T02:23:06.969Z] ====== als (apache-spark) [default], iteration 7 completed (39199.778 ms) ====== [2025-06-12T02:23:06.969Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-06-12T02:23:06.969Z] GC before operation: completed in 172.574 ms, heap usage 284.719 MB -> 65.147 MB. [2025-06-12T02:23:42.609Z] ====== als (apache-spark) [default], iteration 8 completed (36219.484 ms) ====== [2025-06-12T02:23:42.609Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-06-12T02:23:42.609Z] GC before operation: completed in 227.380 ms, heap usage 955.971 MB -> 66.433 MB. [2025-06-12T02:24:12.788Z] ====== als (apache-spark) [default], iteration 9 completed (31020.208 ms) ====== [2025-06-12T02:24:12.788Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-06-12T02:24:12.788Z] GC before operation: completed in 157.443 ms, heap usage 446.827 MB -> 66.106 MB. [2025-06-12T02:24:42.981Z] ====== als (apache-spark) [default], iteration 10 completed (31435.799 ms) ====== [2025-06-12T02:24:42.982Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-06-12T02:24:43.755Z] GC before operation: completed in 178.516 ms, heap usage 586.842 MB -> 66.588 MB. [2025-06-12T02:25:10.008Z] ====== als (apache-spark) [default], iteration 11 completed (25417.234 ms) ====== [2025-06-12T02:25:10.008Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-06-12T02:25:10.008Z] GC before operation: completed in 162.998 ms, heap usage 509.681 MB -> 66.853 MB. [2025-06-12T02:25:45.524Z] ====== als (apache-spark) [default], iteration 12 completed (35950.136 ms) ====== [2025-06-12T02:25:45.524Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-06-12T02:25:45.524Z] GC before operation: completed in 211.163 ms, heap usage 670.402 MB -> 67.281 MB. [2025-06-12T02:26:20.853Z] ====== als (apache-spark) [default], iteration 13 completed (33453.604 ms) ====== [2025-06-12T02:26:20.853Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-06-12T02:26:20.853Z] GC before operation: completed in 206.691 ms, heap usage 944.689 MB -> 67.732 MB. [2025-06-12T02:26:51.244Z] ====== als (apache-spark) [default], iteration 14 completed (28742.948 ms) ====== [2025-06-12T02:26:51.244Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-06-12T02:26:51.244Z] GC before operation: completed in 213.507 ms, heap usage 416.770 MB -> 67.372 MB. [2025-06-12T02:27:26.540Z] ====== als (apache-spark) [default], iteration 15 completed (36928.902 ms) ====== [2025-06-12T02:27:26.540Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-06-12T02:27:26.540Z] GC before operation: completed in 163.390 ms, heap usage 675.232 MB -> 67.965 MB. [2025-06-12T02:28:23.486Z] ====== als (apache-spark) [default], iteration 16 completed (50560.535 ms) ====== [2025-06-12T02:28:23.486Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-06-12T02:28:23.486Z] GC before operation: completed in 175.041 ms, heap usage 1.108 GB -> 68.602 MB. [2025-06-12T02:29:04.801Z] ====== als (apache-spark) [default], iteration 17 completed (42720.447 ms) ====== [2025-06-12T02:29:04.801Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-06-12T02:29:04.801Z] GC before operation: completed in 168.176 ms, heap usage 543.584 MB -> 68.369 MB. [2025-06-12T02:29:41.934Z] ====== als (apache-spark) [default], iteration 18 completed (36933.765 ms) ====== [2025-06-12T02:29:41.934Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-06-12T02:29:41.934Z] GC before operation: completed in 208.631 ms, heap usage 1.056 GB -> 69.085 MB. [2025-06-12T02:30:29.084Z] ====== als (apache-spark) [default], iteration 19 completed (49976.375 ms) ====== [2025-06-12T02:30:29.084Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-06-12T02:30:29.084Z] GC before operation: completed in 218.345 ms, heap usage 463.675 MB -> 68.747 MB. [2025-06-12T02:31:10.427Z] ====== als (apache-spark) [default], iteration 20 completed (36901.269 ms) ====== [2025-06-12T02:31:10.427Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-06-12T02:31:10.427Z] GC before operation: completed in 160.609 ms, heap usage 480.086 MB -> 68.997 MB. [2025-06-12T02:31:29.628Z] ====== als (apache-spark) [default], iteration 21 completed (22078.015 ms) ====== [2025-06-12T02:31:29.628Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-06-12T02:31:29.628Z] GC before operation: completed in 188.569 ms, heap usage 605.978 MB -> 69.558 MB. [2025-06-12T02:31:55.681Z] ====== als (apache-spark) [default], iteration 22 completed (27717.139 ms) ====== [2025-06-12T02:31:55.681Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-06-12T02:31:55.682Z] GC before operation: completed in 177.419 ms, heap usage 974.759 MB -> 70.135 MB. [2025-06-12T02:32:23.466Z] ====== als (apache-spark) [default], iteration 23 completed (26653.774 ms) ====== [2025-06-12T02:32:23.466Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-06-12T02:32:23.466Z] GC before operation: completed in 189.045 ms, heap usage 424.679 MB -> 69.699 MB. [2025-06-12T02:32:58.808Z] ====== als (apache-spark) [default], iteration 24 completed (33683.559 ms) ====== [2025-06-12T02:32:58.808Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-06-12T02:32:58.808Z] GC before operation: completed in 221.049 ms, heap usage 679.181 MB -> 70.397 MB. [2025-06-12T02:33:47.300Z] ====== als (apache-spark) [default], iteration 25 completed (43726.429 ms) ====== [2025-06-12T02:33:47.301Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-06-12T02:33:47.301Z] GC before operation: completed in 171.620 ms, heap usage 224.019 MB -> 70.083 MB. [2025-06-12T02:34:38.353Z] ====== als (apache-spark) [default], iteration 26 completed (55828.052 ms) ====== [2025-06-12T02:34:38.353Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-06-12T02:34:38.353Z] GC before operation: completed in 180.990 ms, heap usage 266.793 MB -> 70.444 MB. [2025-06-12T02:35:27.017Z] ====== als (apache-spark) [default], iteration 27 completed (49165.588 ms) ====== [2025-06-12T02:35:27.017Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-06-12T02:35:27.017Z] GC before operation: completed in 202.542 ms, heap usage 165.296 MB -> 70.223 MB. [2025-06-12T02:37:00.779Z] ====== als (apache-spark) [default], iteration 28 completed (79858.858 ms) ====== [2025-06-12T02:37:00.779Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-06-12T02:37:00.779Z] GC before operation: completed in 177.506 ms, heap usage 273.720 MB -> 70.787 MB. [2025-06-12T02:37:37.397Z] ====== als (apache-spark) [default], iteration 29 completed (45680.626 ms) ====== [2025-06-12T02:37:37.397Z] ----------------------------------- [2025-06-12T02:37:37.397Z] renaissance-als_0_PASSED [2025-06-12T02:37:37.397Z] ----------------------------------- [2025-06-12T02:37:37.397Z] [2025-06-12T02:37:37.397Z] TEST TEARDOWN: [2025-06-12T02:37:37.397Z] Nothing to be done for teardown. [2025-06-12T02:37:37.397Z] renaissance-als_0 Finish Time: Thu Jun 12 02:37:33 2025 Epoch Time (ms): 1749695853584