[2025-05-29T04:29:35.644Z] Running test renaissance-als_0 ... [2025-05-29T04:29:35.644Z] =============================================== [2025-05-29T04:29:35.644Z] renaissance-als_0 Start Time: Thu May 29 04:29:34 2025 Epoch Time (ms): 1748492974528 [2025-05-29T04:29:35.644Z] variation: NoOptions [2025-05-29T04:29:35.644Z] JVM_OPTIONS: [2025-05-29T04:29:35.644Z] { \ [2025-05-29T04:29:35.644Z] echo ""; echo "TEST SETUP:"; \ [2025-05-29T04:29:35.644Z] echo "Nothing to be done for setup."; \ [2025-05-29T04:29:35.644Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17484928925221/renaissance-als_0"; \ [2025-05-29T04:29:35.644Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17484928925221/renaissance-als_0"; \ [2025-05-29T04:29:35.644Z] echo ""; echo "TESTING:"; \ [2025-05-29T04:29:35.644Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_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_s390x_linux/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17484928925221/renaissance-als_0"/als.json" als; \ [2025-05-29T04:29:35.644Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17484928925221/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-05-29T04:29:35.644Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-05-29T04:29:35.644Z] echo "Nothing to be done for teardown."; \ [2025-05-29T04:29:35.644Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17484928925221/TestTargetResult"; [2025-05-29T04:29:35.644Z] [2025-05-29T04:29:35.644Z] TEST SETUP: [2025-05-29T04:29:35.644Z] Nothing to be done for setup. [2025-05-29T04:29:35.644Z] [2025-05-29T04:29:35.644Z] TESTING: [2025-05-29T04:29:53.436Z] NOTE: 'als' benchmark uses Spark local executor with 2 (out of 2) threads. [2025-05-29T04:29:58.452Z] WARNING: An illegal reflective access operation has occurred [2025-05-29T04:29:58.452Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/output_17484928925221/renaissance-als_0/harness-042937-10369411526159408878/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-05-29T04:29:58.452Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-05-29T04:29:58.452Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-05-29T04:29:58.452Z] WARNING: All illegal access operations will be denied in a future release [2025-05-29T04:30:02.407Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-05-29T04:30:03.184Z] GC before operation: completed in 380.437 ms, heap usage 364.540 MB -> 34.512 MB. [2025-05-29T04:31:38.869Z] ====== als (apache-spark) [default], iteration 0 completed (87002.101 ms) ====== [2025-05-29T04:31:38.869Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-05-29T04:31:38.869Z] GC before operation: completed in 390.266 ms, heap usage 131.552 MB -> 60.528 MB. [2025-05-29T04:32:01.345Z] ====== als (apache-spark) [default], iteration 1 completed (25559.735 ms) ====== [2025-05-29T04:32:01.345Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-05-29T04:32:01.345Z] GC before operation: completed in 869.720 ms, heap usage 183.373 MB -> 61.082 MB. [2025-05-29T04:32:25.962Z] ====== als (apache-spark) [default], iteration 2 completed (25486.738 ms) ====== [2025-05-29T04:32:25.962Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-05-29T04:32:25.962Z] GC before operation: completed in 412.734 ms, heap usage 221.009 MB -> 61.653 MB. [2025-05-29T04:33:00.714Z] ====== als (apache-spark) [default], iteration 3 completed (30330.156 ms) ====== [2025-05-29T04:33:00.715Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-05-29T04:33:00.715Z] GC before operation: completed in 444.283 ms, heap usage 150.197 MB -> 62.145 MB. [2025-05-29T04:33:42.008Z] ====== als (apache-spark) [default], iteration 4 completed (40400.660 ms) ====== [2025-05-29T04:33:42.008Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-05-29T04:33:42.008Z] GC before operation: completed in 361.566 ms, heap usage 152.326 MB -> 62.651 MB. [2025-05-29T04:34:13.571Z] ====== als (apache-spark) [default], iteration 5 completed (34503.256 ms) ====== [2025-05-29T04:34:13.571Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-05-29T04:34:15.051Z] GC before operation: completed in 1200.045 ms, heap usage 450.617 MB -> 63.528 MB. [2025-05-29T04:34:43.790Z] ====== als (apache-spark) [default], iteration 6 completed (23822.262 ms) ====== [2025-05-29T04:34:43.790Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-05-29T04:34:43.790Z] GC before operation: completed in 1679.846 ms, heap usage 351.328 MB -> 63.940 MB. [2025-05-29T04:35:12.850Z] ====== als (apache-spark) [default], iteration 7 completed (28035.478 ms) ====== [2025-05-29T04:35:12.850Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-05-29T04:35:12.850Z] GC before operation: completed in 559.843 ms, heap usage 186.670 MB -> 64.275 MB. [2025-05-29T04:35:42.432Z] ====== als (apache-spark) [default], iteration 8 completed (27455.252 ms) ====== [2025-05-29T04:35:42.432Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-05-29T04:35:42.432Z] GC before operation: completed in 945.265 ms, heap usage 396.685 MB -> 65.013 MB. [2025-05-29T04:36:31.109Z] ====== als (apache-spark) [default], iteration 9 completed (43417.732 ms) ====== [2025-05-29T04:36:31.109Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-05-29T04:36:31.109Z] GC before operation: completed in 652.959 ms, heap usage 246.655 MB -> 65.432 MB. [2025-05-29T04:36:57.109Z] ====== als (apache-spark) [default], iteration 10 completed (27878.627 ms) ====== [2025-05-29T04:36:57.109Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-05-29T04:36:57.109Z] GC before operation: completed in 524.301 ms, heap usage 190.829 MB -> 65.349 MB. [2025-05-29T04:37:21.719Z] ====== als (apache-spark) [default], iteration 11 completed (22962.010 ms) ====== [2025-05-29T04:37:21.719Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-05-29T04:37:21.719Z] GC before operation: completed in 333.494 ms, heap usage 212.447 MB -> 65.702 MB. [2025-05-29T04:37:56.537Z] ====== als (apache-spark) [default], iteration 12 completed (34291.340 ms) ====== [2025-05-29T04:37:56.537Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-05-29T04:37:56.537Z] GC before operation: completed in 1572.278 ms, heap usage 231.696 MB -> 65.943 MB. [2025-05-29T04:38:25.824Z] ====== als (apache-spark) [default], iteration 13 completed (24996.803 ms) ====== [2025-05-29T04:38:25.824Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-05-29T04:38:25.824Z] GC before operation: completed in 579.833 ms, heap usage 174.103 MB -> 66.056 MB. [2025-05-29T04:38:55.311Z] ====== als (apache-spark) [default], iteration 14 completed (32072.457 ms) ====== [2025-05-29T04:38:55.311Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-05-29T04:38:55.997Z] GC before operation: completed in 689.162 ms, heap usage 282.284 MB -> 66.431 MB. [2025-05-29T04:39:31.981Z] ====== als (apache-spark) [default], iteration 15 completed (32186.347 ms) ====== [2025-05-29T04:39:31.981Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-05-29T04:39:31.981Z] GC before operation: completed in 469.942 ms, heap usage 135.421 MB -> 66.601 MB. [2025-05-29T04:39:53.177Z] ====== als (apache-spark) [default], iteration 16 completed (23473.194 ms) ====== [2025-05-29T04:39:53.177Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-05-29T04:39:53.177Z] GC before operation: completed in 470.070 ms, heap usage 297.821 MB -> 66.938 MB. [2025-05-29T04:40:18.024Z] ====== als (apache-spark) [default], iteration 17 completed (22643.716 ms) ====== [2025-05-29T04:40:18.024Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-05-29T04:40:18.024Z] GC before operation: completed in 624.024 ms, heap usage 235.172 MB -> 67.204 MB. [2025-05-29T04:40:43.989Z] ====== als (apache-spark) [default], iteration 18 completed (26241.070 ms) ====== [2025-05-29T04:40:43.989Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-05-29T04:40:44.721Z] GC before operation: completed in 524.287 ms, heap usage 262.534 MB -> 67.453 MB. [2025-05-29T04:41:06.014Z] ====== als (apache-spark) [default], iteration 19 completed (20637.676 ms) ====== [2025-05-29T04:41:06.014Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-05-29T04:41:06.014Z] GC before operation: completed in 355.562 ms, heap usage 325.361 MB -> 67.805 MB. [2025-05-29T04:41:26.907Z] ====== als (apache-spark) [default], iteration 20 completed (19672.672 ms) ====== [2025-05-29T04:41:26.907Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-05-29T04:41:26.907Z] GC before operation: completed in 680.977 ms, heap usage 422.565 MB -> 68.044 MB. [2025-05-29T04:41:52.226Z] ====== als (apache-spark) [default], iteration 21 completed (24017.319 ms) ====== [2025-05-29T04:41:52.226Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-05-29T04:41:52.226Z] GC before operation: completed in 386.651 ms, heap usage 190.044 MB -> 68.066 MB. [2025-05-29T04:42:17.133Z] ====== als (apache-spark) [default], iteration 22 completed (24136.289 ms) ====== [2025-05-29T04:42:17.134Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-05-29T04:42:17.134Z] GC before operation: completed in 647.360 ms, heap usage 341.738 MB -> 68.570 MB. [2025-05-29T04:42:42.268Z] ====== als (apache-spark) [default], iteration 23 completed (22829.532 ms) ====== [2025-05-29T04:42:42.268Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-05-29T04:42:42.268Z] GC before operation: completed in 705.161 ms, heap usage 225.501 MB -> 68.689 MB. [2025-05-29T04:43:03.180Z] ====== als (apache-spark) [default], iteration 24 completed (20659.790 ms) ====== [2025-05-29T04:43:03.180Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-05-29T04:43:03.838Z] GC before operation: completed in 632.685 ms, heap usage 127.994 MB -> 68.815 MB. [2025-05-29T04:43:29.293Z] ====== als (apache-spark) [default], iteration 25 completed (25154.250 ms) ====== [2025-05-29T04:43:29.293Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-05-29T04:43:29.951Z] GC before operation: completed in 448.040 ms, heap usage 250.609 MB -> 68.264 MB. [2025-05-29T04:43:51.047Z] ====== als (apache-spark) [default], iteration 26 completed (20801.368 ms) ====== [2025-05-29T04:43:51.047Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-05-29T04:43:51.817Z] GC before operation: completed in 409.237 ms, heap usage 161.150 MB -> 68.393 MB. [2025-05-29T04:44:21.062Z] ====== als (apache-spark) [default], iteration 27 completed (26427.080 ms) ====== [2025-05-29T04:44:21.062Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-05-29T04:44:21.062Z] GC before operation: completed in 321.365 ms, heap usage 163.277 MB -> 68.239 MB. [2025-05-29T04:44:46.192Z] ====== als (apache-spark) [default], iteration 28 completed (24156.376 ms) ====== [2025-05-29T04:44:46.192Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-05-29T04:44:46.192Z] GC before operation: completed in 662.898 ms, heap usage 374.172 MB -> 66.115 MB. [2025-05-29T04:45:11.104Z] ====== als (apache-spark) [default], iteration 29 completed (23696.003 ms) ====== [2025-05-29T04:45:11.104Z] ----------------------------------- [2025-05-29T04:45:11.104Z] renaissance-als_0_PASSED [2025-05-29T04:45:11.104Z] ----------------------------------- [2025-05-29T04:45:11.105Z] [2025-05-29T04:45:11.105Z] TEST TEARDOWN: [2025-05-29T04:45:11.105Z] Nothing to be done for teardown. [2025-05-29T04:45:11.105Z] renaissance-als_0 Finish Time: Thu May 29 04:45:08 2025 Epoch Time (ms): 1748493908716