[2024-11-21T13:44:40.519Z] Running test renaissance-log-regression_0 ... [2024-11-21T13:44:40.519Z] =============================================== [2024-11-21T13:44:40.519Z] renaissance-log-regression_0 Start Time: Thu Nov 21 13:44:39 2024 Epoch Time (ms): 1732196679740 [2024-11-21T13:44:40.519Z] variation: NoOptions [2024-11-21T13:44:40.519Z] JVM_OPTIONS: [2024-11-21T13:44:40.519Z] { \ [2024-11-21T13:44:40.519Z] echo ""; echo "TEST SETUP:"; \ [2024-11-21T13:44:40.519Z] echo "Nothing to be done for setup."; \ [2024-11-21T13:44:40.519Z] mkdir -p "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17321935947162/renaissance-log-regression_0"; \ [2024-11-21T13:44:40.519Z] cd "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17321935947162/renaissance-log-regression_0"; \ [2024-11-21T13:44:40.519Z] echo ""; echo "TESTING:"; \ [2024-11-21T13:44:40.519Z] "/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_17321935947162/renaissance-log-regression_0"/log-regression.json" log-regression; \ [2024-11-21T13:44:40.519Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-log-regression_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_17321935947162/renaissance-log-regression_0"; else echo "-----------------------------------"; echo "renaissance-log-regression_0""_FAILED"; echo "-----------------------------------"; fi; \ [2024-11-21T13:44:40.519Z] echo ""; echo "TEST TEARDOWN:"; \ [2024-11-21T13:44:40.519Z] echo "Nothing to be done for teardown."; \ [2024-11-21T13:44:40.519Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk11_hs_extended.perf_s390x_linux/aqa-tests/TKG/../TKG/output_17321935947162/TestTargetResult"; [2024-11-21T13:44:40.519Z] [2024-11-21T13:44:40.519Z] TEST SETUP: [2024-11-21T13:44:40.519Z] Nothing to be done for setup. [2024-11-21T13:44:40.519Z] [2024-11-21T13:44:40.519Z] TESTING: [2024-11-21T13:44:48.294Z] Using Spark's default log4j profile: org/apache/spark/log4j-defaults.properties [2024-11-21T13:44:58.174Z] NOTE: 'log-regression' benchmark uses Spark local executor with 2 (out of 2) threads. [2024-11-21T13:45:01.522Z] WARNING: An illegal reflective access operation has occurred [2024-11-21T13:45:01.522Z] 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_17321935947162/renaissance-log-regression_0/harness-134442-18132964054476806460/apache-spark/lib/spark-core_2.13-3.2.0.jar) to field java.net.URI.scheme [2024-11-21T13:45:01.522Z] WARNING: Please consider reporting this to the maintainers of org.apache.spark.util.SizeEstimator$ [2024-11-21T13:45:01.522Z] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations [2024-11-21T13:45:01.522Z] WARNING: All illegal access operations will be denied in a future release [2024-11-21T13:45:07.326Z] ====== log-regression (apache-spark) [default], iteration 0 started ====== [2024-11-21T13:45:08.038Z] GC before operation: completed in 242.057 ms, heap usage 49.255 MB -> 33.723 MB. [2024-11-21T13:45:52.231Z] ====== log-regression (apache-spark) [default], iteration 0 completed (39470.649 ms) ====== [2024-11-21T13:45:52.231Z] ====== log-regression (apache-spark) [default], iteration 1 started ====== [2024-11-21T13:45:52.231Z] GC before operation: completed in 592.361 ms, heap usage 269.377 MB -> 109.242 MB. [2024-11-21T13:46:03.816Z] ====== log-regression (apache-spark) [default], iteration 1 completed (14952.734 ms) ====== [2024-11-21T13:46:03.816Z] ====== log-regression (apache-spark) [default], iteration 2 started ====== [2024-11-21T13:46:03.816Z] GC before operation: completed in 649.706 ms, heap usage 250.866 MB -> 109.656 MB. [2024-11-21T13:46:15.367Z] ====== log-regression (apache-spark) [default], iteration 2 completed (10474.890 ms) ====== [2024-11-21T13:46:15.367Z] ====== log-regression (apache-spark) [default], iteration 3 started ====== [2024-11-21T13:46:15.367Z] GC before operation: completed in 272.536 ms, heap usage 360.194 MB -> 110.288 MB. [2024-11-21T13:46:33.639Z] ====== log-regression (apache-spark) [default], iteration 3 completed (17998.870 ms) ====== [2024-11-21T13:46:33.639Z] ====== log-regression (apache-spark) [default], iteration 4 started ====== [2024-11-21T13:46:33.639Z] GC before operation: completed in 594.878 ms, heap usage 241.530 MB -> 110.309 MB. [2024-11-21T13:46:47.325Z] ====== log-regression (apache-spark) [default], iteration 4 completed (14004.197 ms) ====== [2024-11-21T13:46:47.325Z] ====== log-regression (apache-spark) [default], iteration 5 started ====== [2024-11-21T13:46:47.325Z] GC before operation: completed in 385.585 ms, heap usage 225.353 MB -> 110.447 MB. [2024-11-21T13:47:00.847Z] ====== log-regression (apache-spark) [default], iteration 5 completed (12855.220 ms) ====== [2024-11-21T13:47:00.847Z] ====== log-regression (apache-spark) [default], iteration 6 started ====== [2024-11-21T13:47:00.847Z] GC before operation: completed in 662.154 ms, heap usage 342.688 MB -> 110.910 MB. [2024-11-21T13:47:14.993Z] ====== log-regression (apache-spark) [default], iteration 6 completed (13941.050 ms) ====== [2024-11-21T13:47:14.993Z] ====== log-regression (apache-spark) [default], iteration 7 started ====== [2024-11-21T13:47:14.993Z] GC before operation: completed in 322.670 ms, heap usage 234.017 MB -> 110.808 MB. [2024-11-21T13:47:24.438Z] ====== log-regression (apache-spark) [default], iteration 7 completed (9068.227 ms) ====== [2024-11-21T13:47:24.438Z] ====== log-regression (apache-spark) [default], iteration 8 started ====== [2024-11-21T13:47:25.214Z] GC before operation: completed in 776.147 ms, heap usage 234.374 MB -> 110.988 MB. [2024-11-21T13:47:36.507Z] ====== log-regression (apache-spark) [default], iteration 8 completed (11841.687 ms) ====== [2024-11-21T13:47:36.507Z] ====== log-regression (apache-spark) [default], iteration 9 started ====== [2024-11-21T13:47:37.166Z] GC before operation: completed in 512.372 ms, heap usage 242.258 MB -> 111.211 MB. [2024-11-21T13:47:46.972Z] 24/11/21 13:47:45 WARN BlockManager: Asked to remove block broadcast_455_piece0, which does not exist [2024-11-21T13:47:46.972Z] 24/11/21 13:47:45 WARN BlockManager: Asked to remove block broadcast_455, which does not exist [2024-11-21T13:47:48.591Z] ====== log-regression (apache-spark) [default], iteration 9 completed (11738.653 ms) ====== [2024-11-21T13:47:48.591Z] ====== log-regression (apache-spark) [default], iteration 10 started ====== [2024-11-21T13:47:49.334Z] GC before operation: completed in 362.559 ms, heap usage 270.029 MB -> 111.433 MB. [2024-11-21T13:47:57.104Z] ====== log-regression (apache-spark) [default], iteration 10 completed (7073.694 ms) ====== [2024-11-21T13:47:57.104Z] ====== log-regression (apache-spark) [default], iteration 11 started ====== [2024-11-21T13:47:57.104Z] GC before operation: completed in 399.768 ms, heap usage 297.440 MB -> 111.703 MB. [2024-11-21T13:48:09.819Z] ====== log-regression (apache-spark) [default], iteration 11 completed (12043.394 ms) ====== [2024-11-21T13:48:09.819Z] ====== log-regression (apache-spark) [default], iteration 12 started ====== [2024-11-21T13:48:09.819Z] GC before operation: completed in 319.141 ms, heap usage 287.892 MB -> 111.825 MB. [2024-11-21T13:48:17.875Z] ====== log-regression (apache-spark) [default], iteration 12 completed (8911.762 ms) ====== [2024-11-21T13:48:17.875Z] ====== log-regression (apache-spark) [default], iteration 13 started ====== [2024-11-21T13:48:18.842Z] GC before operation: completed in 442.373 ms, heap usage 342.740 MB -> 112.130 MB. [2024-11-21T13:48:32.655Z] ====== log-regression (apache-spark) [default], iteration 13 completed (12698.495 ms) ====== [2024-11-21T13:48:32.655Z] ====== log-regression (apache-spark) [default], iteration 14 started ====== [2024-11-21T13:48:32.655Z] GC before operation: completed in 729.350 ms, heap usage 224.475 MB -> 112.021 MB. [2024-11-21T13:48:44.635Z] ====== log-regression (apache-spark) [default], iteration 14 completed (13037.842 ms) ====== [2024-11-21T13:48:44.636Z] ====== log-regression (apache-spark) [default], iteration 15 started ====== [2024-11-21T13:48:46.148Z] GC before operation: completed in 928.771 ms, heap usage 253.105 MB -> 112.259 MB. [2024-11-21T13:48:50.347Z] 24/11/21 13:48:49 WARN BlockManager: Asked to remove block broadcast_713, which does not exist [2024-11-21T13:48:56.934Z] ====== log-regression (apache-spark) [default], iteration 15 completed (10600.515 ms) ====== [2024-11-21T13:48:56.934Z] ====== log-regression (apache-spark) [default], iteration 16 started ====== [2024-11-21T13:48:56.934Z] GC before operation: completed in 549.938 ms, heap usage 260.800 MB -> 112.511 MB. [2024-11-21T13:49:05.428Z] ====== log-regression (apache-spark) [default], iteration 16 completed (8233.735 ms) ====== [2024-11-21T13:49:05.428Z] ====== log-regression (apache-spark) [default], iteration 17 started ====== [2024-11-21T13:49:06.216Z] GC before operation: completed in 692.680 ms, heap usage 288.759 MB -> 112.736 MB. [2024-11-21T13:49:16.450Z] ====== log-regression (apache-spark) [default], iteration 17 completed (10763.395 ms) ====== [2024-11-21T13:49:16.450Z] ====== log-regression (apache-spark) [default], iteration 18 started ====== [2024-11-21T13:49:18.108Z] GC before operation: completed in 913.843 ms, heap usage 225.746 MB -> 112.762 MB. [2024-11-21T13:49:29.641Z] ====== log-regression (apache-spark) [default], iteration 18 completed (11672.838 ms) ====== [2024-11-21T13:49:29.641Z] ====== log-regression (apache-spark) [default], iteration 19 started ====== [2024-11-21T13:49:29.641Z] GC before operation: completed in 321.844 ms, heap usage 235.239 MB -> 112.927 MB. [2024-11-21T13:49:40.757Z] ====== log-regression (apache-spark) [default], iteration 19 completed (10142.910 ms) ====== [2024-11-21T13:49:41.462Z] ----------------------------------- [2024-11-21T13:49:41.462Z] renaissance-log-regression_0_PASSED [2024-11-21T13:49:41.462Z] ----------------------------------- [2024-11-21T13:49:41.462Z] [2024-11-21T13:49:41.462Z] TEST TEARDOWN: [2024-11-21T13:49:41.462Z] Nothing to be done for teardown. [2024-11-21T13:49:41.462Z] renaissance-log-regression_0 Finish Time: Thu Nov 21 13:49:40 2024 Epoch Time (ms): 1732196980890