[2025-10-18T21:41:58.745Z] Running test renaissance-als_0 ... [2025-10-18T21:41:58.745Z] =============================================== [2025-10-18T21:41:58.745Z] renaissance-als_0 Start Time: Sat Oct 18 21:41:58 2025 Epoch Time (ms): 1760823718512 [2025-10-18T21:41:58.745Z] variation: NoOptions [2025-10-18T21:41:58.745Z] JVM_OPTIONS: [2025-10-18T21:41:58.745Z] { \ [2025-10-18T21:41:58.745Z] echo ""; echo "TEST SETUP:"; \ [2025-10-18T21:41:58.745Z] echo "Nothing to be done for setup."; \ [2025-10-18T21:41:58.745Z] mkdir -p "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_1_rerun/aqa-tests/TKG/../TKG/output_17608237179067/renaissance-als_0"; \ [2025-10-18T21:41:58.745Z] cd "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_1_rerun/aqa-tests/TKG/../TKG/output_17608237179067/renaissance-als_0"; \ [2025-10-18T21:41:58.745Z] echo ""; echo "TESTING:"; \ [2025-10-18T21:41:58.745Z] "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_1_rerun/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_openjdk25_hs_extended.perf_riscv64_linux_testList_1_rerun/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_1_rerun/aqa-tests/TKG/../TKG/output_17608237179067/renaissance-als_0"/als.json" als; \ [2025-10-18T21:41:58.745Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-als_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_1_rerun/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_1_rerun/aqa-tests/TKG/../TKG/output_17608237179067/renaissance-als_0"; else echo "-----------------------------------"; echo "renaissance-als_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-10-18T21:41:58.745Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-10-18T21:41:58.745Z] echo "Nothing to be done for teardown."; \ [2025-10-18T21:41:58.745Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_1_rerun/aqa-tests/TKG/../TKG/output_17608237179067/TestTargetResult"; [2025-10-18T21:41:58.745Z] [2025-10-18T21:41:58.745Z] TEST SETUP: [2025-10-18T21:41:58.745Z] Nothing to be done for setup. [2025-10-18T21:41:58.745Z] [2025-10-18T21:41:58.745Z] TESTING: [2025-10-18T21:42:00.998Z] WARNING: A terminally deprecated method in sun.misc.Unsafe has been called [2025-10-18T21:42:00.998Z] WARNING: sun.misc.Unsafe::objectFieldOffset has been called by scala.runtime.LazyVals$ (file:/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_1_rerun/aqa-tests/TKG/output_17608237179067/renaissance-als_0/launcher-214159-14656913946627460318/renaissance-harness_3/lib/scala3-library_3-3.3.4.jar) [2025-10-18T21:42:00.998Z] WARNING: Please consider reporting this to the maintainers of class scala.runtime.LazyVals$ [2025-10-18T21:42:00.998Z] WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release [2025-10-18T21:42:24.527Z] NOTE: 'als' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-10-18T21:42:40.367Z] ====== als (apache-spark) [default], iteration 0 started ====== [2025-10-18T21:42:40.367Z] GC before operation: completed in 238.945 ms, heap usage 60.932 MB -> 35.400 MB. [2025-10-18T21:43:49.581Z] ====== als (apache-spark) [default], iteration 0 completed (65511.361 ms) ====== [2025-10-18T21:43:49.581Z] ====== als (apache-spark) [default], iteration 1 started ====== [2025-10-18T21:43:49.581Z] GC before operation: completed in 678.424 ms, heap usage 185.819 MB -> 75.372 MB. [2025-10-18T21:44:17.316Z] ====== als (apache-spark) [default], iteration 1 completed (25650.930 ms) ====== [2025-10-18T21:44:17.316Z] ====== als (apache-spark) [default], iteration 2 started ====== [2025-10-18T21:44:17.316Z] GC before operation: completed in 750.979 ms, heap usage 1.179 GB -> 77.394 MB. [2025-10-18T21:44:40.425Z] ====== als (apache-spark) [default], iteration 2 completed (22494.079 ms) ====== [2025-10-18T21:44:40.425Z] ====== als (apache-spark) [default], iteration 3 started ====== [2025-10-18T21:44:40.425Z] GC before operation: completed in 738.434 ms, heap usage 710.942 MB -> 77.444 MB. [2025-10-18T21:45:08.129Z] ====== als (apache-spark) [default], iteration 3 completed (23116.436 ms) ====== [2025-10-18T21:45:08.129Z] ====== als (apache-spark) [default], iteration 4 started ====== [2025-10-18T21:45:08.129Z] GC before operation: completed in 680.019 ms, heap usage 378.556 MB -> 77.471 MB. [2025-10-18T21:45:31.160Z] ====== als (apache-spark) [default], iteration 4 completed (21868.354 ms) ====== [2025-10-18T21:45:31.160Z] ====== als (apache-spark) [default], iteration 5 started ====== [2025-10-18T21:45:31.160Z] GC before operation: completed in 702.826 ms, heap usage 328.350 MB -> 77.908 MB. [2025-10-18T21:45:54.183Z] ====== als (apache-spark) [default], iteration 5 completed (21501.392 ms) ====== [2025-10-18T21:45:54.183Z] ====== als (apache-spark) [default], iteration 6 started ====== [2025-10-18T21:45:54.183Z] GC before operation: completed in 697.701 ms, heap usage 177.434 MB -> 78.325 MB. [2025-10-18T21:46:17.215Z] ====== als (apache-spark) [default], iteration 6 completed (21555.069 ms) ====== [2025-10-18T21:46:17.215Z] ====== als (apache-spark) [default], iteration 7 started ====== [2025-10-18T21:46:17.215Z] GC before operation: completed in 716.147 ms, heap usage 237.164 MB -> 78.991 MB. [2025-10-18T21:46:40.247Z] ====== als (apache-spark) [default], iteration 7 completed (21064.020 ms) ====== [2025-10-18T21:46:40.247Z] ====== als (apache-spark) [default], iteration 8 started ====== [2025-10-18T21:46:40.247Z] GC before operation: completed in 803.123 ms, heap usage 481.057 MB -> 79.929 MB. [2025-10-18T21:47:03.311Z] ====== als (apache-spark) [default], iteration 8 completed (21156.267 ms) ====== [2025-10-18T21:47:03.311Z] ====== als (apache-spark) [default], iteration 9 started ====== [2025-10-18T21:47:03.311Z] GC before operation: completed in 766.046 ms, heap usage 510.562 MB -> 80.404 MB. [2025-10-18T21:47:22.763Z] ====== als (apache-spark) [default], iteration 9 completed (21182.253 ms) ====== [2025-10-18T21:47:22.763Z] ====== als (apache-spark) [default], iteration 10 started ====== [2025-10-18T21:47:23.946Z] GC before operation: completed in 828.542 ms, heap usage 541.477 MB -> 80.900 MB. [2025-10-18T21:47:46.985Z] ====== als (apache-spark) [default], iteration 10 completed (20473.219 ms) ====== [2025-10-18T21:47:46.985Z] ====== als (apache-spark) [default], iteration 11 started ====== [2025-10-18T21:47:46.985Z] GC before operation: completed in 811.277 ms, heap usage 360.417 MB -> 80.666 MB. [2025-10-18T21:48:10.011Z] ====== als (apache-spark) [default], iteration 11 completed (20757.722 ms) ====== [2025-10-18T21:48:10.011Z] ====== als (apache-spark) [default], iteration 12 started ====== [2025-10-18T21:48:10.011Z] GC before operation: completed in 836.437 ms, heap usage 1.514 GB -> 82.344 MB. [2025-10-18T21:48:33.029Z] ====== als (apache-spark) [default], iteration 12 completed (20413.933 ms) ====== [2025-10-18T21:48:33.029Z] ====== als (apache-spark) [default], iteration 13 started ====== [2025-10-18T21:48:33.029Z] GC before operation: completed in 842.658 ms, heap usage 508.436 MB -> 81.460 MB. [2025-10-18T21:48:52.159Z] ====== als (apache-spark) [default], iteration 13 completed (20420.989 ms) ====== [2025-10-18T21:48:52.159Z] ====== als (apache-spark) [default], iteration 14 started ====== [2025-10-18T21:48:52.487Z] GC before operation: completed in 837.678 ms, heap usage 610.459 MB -> 81.878 MB. [2025-10-18T21:49:15.512Z] ====== als (apache-spark) [default], iteration 14 completed (19975.906 ms) ====== [2025-10-18T21:49:15.512Z] ====== als (apache-spark) [default], iteration 15 started ====== [2025-10-18T21:49:15.512Z] GC before operation: completed in 840.675 ms, heap usage 266.064 MB -> 81.722 MB. [2025-10-18T21:49:34.646Z] ====== als (apache-spark) [default], iteration 15 completed (19713.811 ms) ====== [2025-10-18T21:49:34.646Z] ====== als (apache-spark) [default], iteration 16 started ====== [2025-10-18T21:49:35.372Z] GC before operation: completed in 868.508 ms, heap usage 576.415 MB -> 82.331 MB. [2025-10-18T21:49:58.411Z] ====== als (apache-spark) [default], iteration 16 completed (20070.491 ms) ====== [2025-10-18T21:49:58.411Z] ====== als (apache-spark) [default], iteration 17 started ====== [2025-10-18T21:49:58.411Z] GC before operation: completed in 867.064 ms, heap usage 449.503 MB -> 82.483 MB. [2025-10-18T21:50:17.540Z] ====== als (apache-spark) [default], iteration 17 completed (19813.940 ms) ====== [2025-10-18T21:50:17.540Z] ====== als (apache-spark) [default], iteration 18 started ====== [2025-10-18T21:50:18.707Z] GC before operation: completed in 879.614 ms, heap usage 474.814 MB -> 82.766 MB. [2025-10-18T21:50:41.745Z] ====== als (apache-spark) [default], iteration 18 completed (20113.362 ms) ====== [2025-10-18T21:50:41.745Z] ====== als (apache-spark) [default], iteration 19 started ====== [2025-10-18T21:50:41.745Z] GC before operation: completed in 878.018 ms, heap usage 545.120 MB -> 83.117 MB. [2025-10-18T21:51:00.862Z] ====== als (apache-spark) [default], iteration 19 completed (20023.098 ms) ====== [2025-10-18T21:51:00.862Z] ====== als (apache-spark) [default], iteration 20 started ====== [2025-10-18T21:51:02.041Z] GC before operation: completed in 886.006 ms, heap usage 504.779 MB -> 83.271 MB. [2025-10-18T21:51:25.055Z] ====== als (apache-spark) [default], iteration 20 completed (21049.843 ms) ====== [2025-10-18T21:51:25.055Z] ====== als (apache-spark) [default], iteration 21 started ====== [2025-10-18T21:51:25.055Z] GC before operation: completed in 906.250 ms, heap usage 464.346 MB -> 83.517 MB. [2025-10-18T21:51:48.087Z] ====== als (apache-spark) [default], iteration 21 completed (19901.616 ms) ====== [2025-10-18T21:51:48.087Z] ====== als (apache-spark) [default], iteration 22 started ====== [2025-10-18T21:51:48.087Z] GC before operation: completed in 880.489 ms, heap usage 498.241 MB -> 83.767 MB. [2025-10-18T21:52:07.466Z] ====== als (apache-spark) [default], iteration 22 completed (20346.712 ms) ====== [2025-10-18T21:52:07.466Z] ====== als (apache-spark) [default], iteration 23 started ====== [2025-10-18T21:52:08.207Z] GC before operation: completed in 953.422 ms, heap usage 466.099 MB -> 84.042 MB. [2025-10-18T21:52:31.261Z] ====== als (apache-spark) [default], iteration 23 completed (19990.210 ms) ====== [2025-10-18T21:52:31.261Z] ====== als (apache-spark) [default], iteration 24 started ====== [2025-10-18T21:52:31.261Z] GC before operation: completed in 913.740 ms, heap usage 603.268 MB -> 84.392 MB. [2025-10-18T21:52:50.382Z] ====== als (apache-spark) [default], iteration 24 completed (20045.153 ms) ====== [2025-10-18T21:52:50.382Z] ====== als (apache-spark) [default], iteration 25 started ====== [2025-10-18T21:52:51.548Z] GC before operation: completed in 913.382 ms, heap usage 171.528 MB -> 84.088 MB. [2025-10-18T21:53:14.623Z] ====== als (apache-spark) [default], iteration 25 completed (19950.769 ms) ====== [2025-10-18T21:53:14.623Z] ====== als (apache-spark) [default], iteration 26 started ====== [2025-10-18T21:53:14.623Z] GC before operation: completed in 929.413 ms, heap usage 250.855 MB -> 84.344 MB. [2025-10-18T21:53:27.722Z] Exception in thread "Executor task launch worker for task 9.0 in stage 2649.0 (TID 7264)" java.lang.AssertionError: assertion failed: task count shouldn't below 0 [2025-10-18T21:53:27.722Z] at scala.Predef$.assert(Predef.scala:279) [2025-10-18T21:53:27.722Z] at org.apache.spark.executor.ExecutorMetricsPoller.decrementCount$1(ExecutorMetricsPoller.scala:133) [2025-10-18T21:53:27.722Z] at org.apache.spark.executor.ExecutorMetricsPoller.$anonfun$onTaskCompletion$3(ExecutorMetricsPoller.scala:138) [2025-10-18T21:53:27.722Z] at java.base/java.util.concurrent.ConcurrentHashMap.computeIfPresent(ConcurrentHashMap.java:1844) [2025-10-18T21:53:27.722Z] at org.apache.spark.executor.ExecutorMetricsPoller.onTaskCompletion(ExecutorMetricsPoller.scala:138) [2025-10-18T21:53:27.722Z] at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:834) [2025-10-18T21:53:27.722Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1090) [2025-10-18T21:53:27.722Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:614) [2025-10-18T21:53:27.722Z] at java.base/java.lang.Thread.run(Thread.java:1474) [2025-10-18T21:53:33.619Z] ====== als (apache-spark) [default], iteration 26 completed (19613.686 ms) ====== [2025-10-18T21:53:33.619Z] ====== als (apache-spark) [default], iteration 27 started ====== [2025-10-18T21:53:34.332Z] GC before operation: completed in 943.939 ms, heap usage 480.425 MB -> 85.038 MB. [2025-10-18T21:53:57.376Z] ====== als (apache-spark) [default], iteration 27 completed (19698.129 ms) ====== [2025-10-18T21:53:57.376Z] ====== als (apache-spark) [default], iteration 28 started ====== [2025-10-18T21:53:57.376Z] GC before operation: completed in 924.034 ms, heap usage 569.340 MB -> 85.359 MB. [2025-10-18T21:54:16.519Z] ====== als (apache-spark) [default], iteration 28 completed (19924.495 ms) ====== [2025-10-18T21:54:16.519Z] ====== als (apache-spark) [default], iteration 29 started ====== [2025-10-18T21:54:17.247Z] GC before operation: completed in 1012.845 ms, heap usage 628.431 MB -> 85.188 MB. [2025-10-18T21:54:40.296Z] ====== als (apache-spark) [default], iteration 29 completed (19447.555 ms) ====== [2025-10-18T21:54:40.296Z] ----------------------------------- [2025-10-18T21:54:40.296Z] renaissance-als_0_PASSED [2025-10-18T21:54:40.296Z] ----------------------------------- [2025-10-18T21:54:40.296Z] [2025-10-18T21:54:40.296Z] TEST TEARDOWN: [2025-10-18T21:54:40.296Z] Nothing to be done for teardown. [2025-10-18T21:54:40.296Z] renaissance-als_0 Finish Time: Sat Oct 18 21:54:39 2025 Epoch Time (ms): 1760824479766