[2025-03-30T23:21:52.141Z] Running test renaissance-log-regression_0 ... [2025-03-30T23:21:52.141Z] =============================================== [2025-03-30T23:21:52.141Z] renaissance-log-regression_0 Start Time: Sun Mar 30 23:21:51 2025 Epoch Time (ms): 1743376911279 [2025-03-30T23:21:52.141Z] variation: NoOptions [2025-03-30T23:21:52.141Z] JVM_OPTIONS: [2025-03-30T23:21:52.141Z] { \ [2025-03-30T23:21:52.141Z] echo ""; echo "TEST SETUP:"; \ [2025-03-30T23:21:52.141Z] echo "Nothing to be done for setup."; \ [2025-03-30T23:21:52.141Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux/aqa-tests/TKG/../TKG/output_17433701275835/renaissance-log-regression_0"; \ [2025-03-30T23:21:52.141Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux/aqa-tests/TKG/../TKG/output_17433701275835/renaissance-log-regression_0"; \ [2025-03-30T23:21:52.141Z] echo ""; echo "TESTING:"; \ [2025-03-30T23:21:52.141Z] "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-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_x86-64_alpine-linux/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux/aqa-tests/TKG/../TKG/output_17433701275835/renaissance-log-regression_0"/log-regression.json" log-regression; \ [2025-03-30T23:21:52.141Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-log-regression_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux/aqa-tests/TKG/../TKG/output_17433701275835/renaissance-log-regression_0"; else echo "-----------------------------------"; echo "renaissance-log-regression_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-03-30T23:21:52.141Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-03-30T23:21:52.141Z] echo "Nothing to be done for teardown."; \ [2025-03-30T23:21:52.141Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux/aqa-tests/TKG/../TKG/output_17433701275835/TestTargetResult"; [2025-03-30T23:21:52.141Z] [2025-03-30T23:21:52.141Z] TEST SETUP: [2025-03-30T23:21:52.141Z] Nothing to be done for setup. [2025-03-30T23:21:52.141Z] [2025-03-30T23:21:52.141Z] TESTING: [2025-03-30T23:22:23.617Z] NOTE: 'log-regression' benchmark uses Spark local executor with 4 (out of 4) threads. [2025-03-30T23:22:28.061Z] WARNING: An illegal reflective access operation has occurred [2025-03-30T23:22:28.061Z] WARNING: Illegal reflective access by org.apache.spark.util.SizeEstimator$ (file:/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_x86-64_alpine-linux/aqa-tests/TKG/output_17433701275835/renaissance-log-regression_0/harness-232154-9946627311899457161/apache-spark/lib/spark-core_2.13-3.5.3.jar) to field java.net.URI.scheme [2025-03-30T23:22:28.061Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2025-03-30T23:22:28.061Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2025-03-30T23:22:28.061Z] WARNING: All illegal access operations will be denied in a future release [2025-03-30T23:22:36.390Z] ====== log-regression (apache-spark) [default], iteration 0 started ====== [2025-03-30T23:22:36.390Z] GC before operation: completed in 309.801 ms, heap usage 90.810 MB -> 34.442 MB. [2025-03-30T23:23:56.400Z] ====== log-regression (apache-spark) [default], iteration 0 completed (71317.944 ms) ====== [2025-03-30T23:23:56.400Z] ====== log-regression (apache-spark) [default], iteration 1 started ====== [2025-03-30T23:23:56.400Z] GC before operation: completed in 738.207 ms, heap usage 271.640 MB -> 118.406 MB. [2025-03-30T23:24:09.363Z] ====== log-regression (apache-spark) [default], iteration 1 completed (20754.826 ms) ====== [2025-03-30T23:24:09.363Z] ====== log-regression (apache-spark) [default], iteration 2 started ====== [2025-03-30T23:24:09.363Z] GC before operation: completed in 682.279 ms, heap usage 242.984 MB -> 118.752 MB. [2025-03-30T23:24:25.921Z] ====== log-regression (apache-spark) [default], iteration 2 completed (14722.018 ms) ====== [2025-03-30T23:24:25.921Z] ====== log-regression (apache-spark) [default], iteration 3 started ====== [2025-03-30T23:24:25.921Z] GC before operation: completed in 619.100 ms, heap usage 354.208 MB -> 119.482 MB. [2025-03-30T23:24:40.106Z] ====== log-regression (apache-spark) [default], iteration 3 completed (13805.191 ms) ====== [2025-03-30T23:24:40.106Z] ====== log-regression (apache-spark) [default], iteration 4 started ====== [2025-03-30T23:24:40.106Z] GC before operation: completed in 518.091 ms, heap usage 271.636 MB -> 119.718 MB. [2025-03-30T23:24:52.680Z] ====== log-regression (apache-spark) [default], iteration 4 completed (12306.251 ms) ====== [2025-03-30T23:24:52.680Z] ====== log-regression (apache-spark) [default], iteration 5 started ====== [2025-03-30T23:24:52.680Z] GC before operation: completed in 616.333 ms, heap usage 290.296 MB -> 119.777 MB. [2025-03-30T23:25:04.691Z] ====== log-regression (apache-spark) [default], iteration 5 completed (11750.178 ms) ====== [2025-03-30T23:25:04.691Z] ====== log-regression (apache-spark) [default], iteration 6 started ====== [2025-03-30T23:25:04.691Z] GC before operation: completed in 675.244 ms, heap usage 325.236 MB -> 120.057 MB. [2025-03-30T23:25:14.814Z] ====== log-regression (apache-spark) [default], iteration 6 completed (10095.825 ms) ====== [2025-03-30T23:25:14.814Z] ====== log-regression (apache-spark) [default], iteration 7 started ====== [2025-03-30T23:25:15.583Z] GC before operation: completed in 731.021 ms, heap usage 290.673 MB -> 120.138 MB. [2025-03-30T23:25:22.557Z] 23:25:21.233 WARN [block-manager-storage-async-thread-pool-23] org.apache.spark.storage.BlockManager - Asked to remove block broadcast_346, which does not exist [2025-03-30T23:25:29.016Z] ====== log-regression (apache-spark) [default], iteration 7 completed (12847.147 ms) ====== [2025-03-30T23:25:29.016Z] ====== log-regression (apache-spark) [default], iteration 8 started ====== [2025-03-30T23:25:29.016Z] GC before operation: completed in 667.035 ms, heap usage 243.859 MB -> 120.201 MB. [2025-03-30T23:25:40.854Z] ====== log-regression (apache-spark) [default], iteration 8 completed (10431.081 ms) ====== [2025-03-30T23:25:40.854Z] ====== log-regression (apache-spark) [default], iteration 9 started ====== [2025-03-30T23:25:40.854Z] GC before operation: completed in 746.235 ms, heap usage 244.131 MB -> 120.401 MB. [2025-03-30T23:25:51.019Z] ====== log-regression (apache-spark) [default], iteration 9 completed (11064.390 ms) ====== [2025-03-30T23:25:51.019Z] ====== log-regression (apache-spark) [default], iteration 10 started ====== [2025-03-30T23:25:51.807Z] GC before operation: completed in 738.390 ms, heap usage 312.949 MB -> 120.851 MB. [2025-03-30T23:26:03.648Z] ====== log-regression (apache-spark) [default], iteration 10 completed (10738.840 ms) ====== [2025-03-30T23:26:03.648Z] ====== log-regression (apache-spark) [default], iteration 11 started ====== [2025-03-30T23:26:03.648Z] GC before operation: completed in 681.868 ms, heap usage 262.738 MB -> 120.887 MB. [2025-03-30T23:26:14.084Z] ====== log-regression (apache-spark) [default], iteration 11 completed (9414.750 ms) ====== [2025-03-30T23:26:14.084Z] ====== log-regression (apache-spark) [default], iteration 12 started ====== [2025-03-30T23:26:14.084Z] GC before operation: completed in 633.274 ms, heap usage 426.433 MB -> 121.574 MB. [2025-03-30T23:26:22.544Z] ====== log-regression (apache-spark) [default], iteration 12 completed (8230.461 ms) ====== [2025-03-30T23:26:22.544Z] ====== log-regression (apache-spark) [default], iteration 13 started ====== [2025-03-30T23:26:22.544Z] GC before operation: completed in 514.578 ms, heap usage 232.936 MB -> 121.234 MB. [2025-03-30T23:26:30.933Z] ====== log-regression (apache-spark) [default], iteration 13 completed (8226.781 ms) ====== [2025-03-30T23:26:30.933Z] ====== log-regression (apache-spark) [default], iteration 14 started ====== [2025-03-30T23:26:30.933Z] GC before operation: completed in 634.087 ms, heap usage 372.254 MB -> 121.787 MB. [2025-03-30T23:26:39.394Z] ====== log-regression (apache-spark) [default], iteration 14 completed (7353.307 ms) ====== [2025-03-30T23:26:39.394Z] ====== log-regression (apache-spark) [default], iteration 15 started ====== [2025-03-30T23:26:39.394Z] GC before operation: completed in 514.469 ms, heap usage 273.230 MB -> 121.653 MB. [2025-03-30T23:26:49.491Z] ====== log-regression (apache-spark) [default], iteration 15 completed (9266.093 ms) ====== [2025-03-30T23:26:49.491Z] ====== log-regression (apache-spark) [default], iteration 16 started ====== [2025-03-30T23:26:49.491Z] GC before operation: completed in 513.400 ms, heap usage 244.649 MB -> 121.819 MB. [2025-03-30T23:26:57.949Z] ====== log-regression (apache-spark) [default], iteration 16 completed (8871.588 ms) ====== [2025-03-30T23:26:57.949Z] ====== log-regression (apache-spark) [default], iteration 17 started ====== [2025-03-30T23:26:57.949Z] GC before operation: completed in 542.233 ms, heap usage 319.517 MB -> 122.274 MB. [2025-03-30T23:27:06.370Z] ====== log-regression (apache-spark) [default], iteration 17 completed (7540.606 ms) ====== [2025-03-30T23:27:06.370Z] ====== log-regression (apache-spark) [default], iteration 18 started ====== [2025-03-30T23:27:06.370Z] GC before operation: completed in 470.942 ms, heap usage 299.292 MB -> 122.381 MB. [2025-03-30T23:27:13.358Z] ====== log-regression (apache-spark) [default], iteration 18 completed (6312.345 ms) ====== [2025-03-30T23:27:13.358Z] ====== log-regression (apache-spark) [default], iteration 19 started ====== [2025-03-30T23:27:13.358Z] GC before operation: completed in 537.991 ms, heap usage 236.665 MB -> 122.411 MB. [2025-03-30T23:27:21.828Z] ====== log-regression (apache-spark) [default], iteration 19 completed (8677.513 ms) ====== [2025-03-30T23:27:23.435Z] ----------------------------------- [2025-03-30T23:27:23.435Z] renaissance-log-regression_0_PASSED [2025-03-30T23:27:23.435Z] ----------------------------------- [2025-03-30T23:27:23.435Z] [2025-03-30T23:27:23.435Z] TEST TEARDOWN: [2025-03-30T23:27:23.435Z] Nothing to be done for teardown. [2025-03-30T23:27:23.435Z] renaissance-log-regression_0 Finish Time: Sun Mar 30 23:27:22 2025 Epoch Time (ms): 1743377242594