renaissance-log-regression_0
[2023-04-20T02:02:08.539Z] Running test renaissance-log-regression_0 ...
[2023-04-20T02:02:08.539Z] ===============================================
[2023-04-20T02:02:08.539Z] renaissance-log-regression_0 Start Time: Thu Apr 20 02:12:56 2023 Epoch Time (ms): 1681956776155
[2023-04-20T02:02:08.539Z] variation: NoOptions
[2023-04-20T02:02:08.539Z] JVM_OPTIONS:
[2023-04-20T02:02:08.539Z] { \
[2023-04-20T02:02:08.539Z] echo ""; echo "TEST SETUP:"; \
[2023-04-20T02:02:08.539Z] echo "Nothing to be done for setup."; \
[2023-04-20T02:02:08.539Z] mkdir -p "/home/jenkins/workspace/Test_openjdk8_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_16819559301834/renaissance-log-regression_0"; \
[2023-04-20T02:02:08.539Z] cd "/home/jenkins/workspace/Test_openjdk8_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_16819559301834/renaissance-log-regression_0"; \
[2023-04-20T02:02:08.539Z] echo ""; echo "TESTING:"; \
[2023-04-20T02:02:08.539Z] "/home/jenkins/workspace/Test_openjdk8_hs_extended.perf_ppc64_aix/openjdkbinary/j2sdk-image/bin/java" -jar "/home/jenkins/workspace/Test_openjdk8_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk8_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_16819559301834/renaissance-log-regression_0"/log-regression.json" log-regression; \
[2023-04-20T02:02:08.540Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-log-regression_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk8_hs_extended.perf_ppc64_aix/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk8_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_16819559301834/renaissance-log-regression_0"; else echo "-----------------------------------"; echo "renaissance-log-regression_0""_FAILED"; echo "-----------------------------------"; fi; \
[2023-04-20T02:02:08.540Z] echo ""; echo "TEST TEARDOWN:"; \
[2023-04-20T02:02:08.540Z] echo "Nothing to be done for teardown."; \
[2023-04-20T02:02:08.540Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk8_hs_extended.perf_ppc64_aix/aqa-tests/TKG/../TKG/output_16819559301834/TestTargetResult";
[2023-04-20T02:02:08.540Z]
[2023-04-20T02:02:08.540Z] TEST SETUP:
[2023-04-20T02:02:08.540Z] Nothing to be done for setup.
[2023-04-20T02:02:08.540Z]
[2023-04-20T02:02:08.540Z] TESTING:
[2023-04-20T02:02:14.103Z] Using Spark's default log4j profile: org/apache/spark/log4j-defaults.properties
[2023-04-20T02:02:17.493Z] NOTE: 'log-regression' benchmark uses Spark local executor with 12 (out of 24) threads.
[2023-04-20T02:02:24.305Z] ====== log-regression (apache-spark) [default], iteration 0 started ======
[2023-04-20T02:02:24.305Z] GC before operation: completed in 225.093 ms, heap usage 106.096 MB -> 27.026 MB.
[2023-04-20T02:02:36.978Z] ====== log-regression (apache-spark) [default], iteration 0 completed (12932.026 ms) ======
[2023-04-20T02:02:36.978Z] ====== log-regression (apache-spark) [default], iteration 1 started ======
[2023-04-20T02:02:37.743Z] GC before operation: completed in 478.452 ms, heap usage 153.505 MB -> 101.509 MB.
[2023-04-20T02:02:40.202Z] ====== log-regression (apache-spark) [default], iteration 1 completed (2872.086 ms) ======
[2023-04-20T02:02:40.202Z] ====== log-regression (apache-spark) [default], iteration 2 started ======
[2023-04-20T02:02:40.202Z] GC before operation: completed in 326.682 ms, heap usage 282.602 MB -> 103.064 MB.
[2023-04-20T02:02:43.622Z] ====== log-regression (apache-spark) [default], iteration 2 completed (2510.867 ms) ======
[2023-04-20T02:02:43.622Z] ====== log-regression (apache-spark) [default], iteration 3 started ======
[2023-04-20T02:02:43.622Z] GC before operation: completed in 285.223 ms, heap usage 228.120 MB -> 103.068 MB.
[2023-04-20T02:02:46.066Z] ====== log-regression (apache-spark) [default], iteration 3 completed (2488.584 ms) ======
[2023-04-20T02:02:46.066Z] ====== log-regression (apache-spark) [default], iteration 4 started ======
[2023-04-20T02:02:46.066Z] GC before operation: completed in 287.035 ms, heap usage 204.170 MB -> 103.200 MB.
[2023-04-20T02:02:48.515Z] ====== log-regression (apache-spark) [default], iteration 4 completed (2260.006 ms) ======
[2023-04-20T02:02:48.515Z] ====== log-regression (apache-spark) [default], iteration 5 started ======
[2023-04-20T02:02:48.515Z] GC before operation: completed in 259.796 ms, heap usage 239.762 MB -> 104.048 MB.
[2023-04-20T02:02:50.966Z] ====== log-regression (apache-spark) [default], iteration 5 completed (2181.930 ms) ======
[2023-04-20T02:02:50.966Z] ====== log-regression (apache-spark) [default], iteration 6 started ======
[2023-04-20T02:02:50.966Z] GC before operation: completed in 262.850 ms, heap usage 260.272 MB -> 104.769 MB.
[2023-04-20T02:02:53.417Z] ====== log-regression (apache-spark) [default], iteration 6 completed (2135.777 ms) ======
[2023-04-20T02:02:53.417Z] ====== log-regression (apache-spark) [default], iteration 7 started ======
[2023-04-20T02:02:53.417Z] GC before operation: completed in 256.966 ms, heap usage 199.018 MB -> 104.498 MB.
[2023-04-20T02:02:55.873Z] ====== log-regression (apache-spark) [default], iteration 7 completed (2134.032 ms) ======
[2023-04-20T02:02:55.873Z] ====== log-regression (apache-spark) [default], iteration 8 started ======
[2023-04-20T02:02:55.873Z] GC before operation: completed in 243.728 ms, heap usage 224.838 MB -> 105.301 MB.
[2023-04-20T02:02:58.341Z] ====== log-regression (apache-spark) [default], iteration 8 completed (2082.767 ms) ======
[2023-04-20T02:02:58.341Z] ====== log-regression (apache-spark) [default], iteration 9 started ======
[2023-04-20T02:02:58.341Z] GC before operation: completed in 263.920 ms, heap usage 217.078 MB -> 105.688 MB.
[2023-04-20T02:02:59.914Z] ====== log-regression (apache-spark) [default], iteration 9 completed (2038.918 ms) ======
[2023-04-20T02:02:59.914Z] ====== log-regression (apache-spark) [default], iteration 10 started ======
[2023-04-20T02:03:00.678Z] GC before operation: completed in 254.924 ms, heap usage 196.148 MB -> 105.944 MB.
[2023-04-20T02:03:02.260Z] ====== log-regression (apache-spark) [default], iteration 10 completed (2024.071 ms) ======
[2023-04-20T02:03:02.260Z] ====== log-regression (apache-spark) [default], iteration 11 started ======
[2023-04-20T02:03:03.020Z] GC before operation: completed in 249.132 ms, heap usage 238.219 MB -> 106.711 MB.
[2023-04-20T02:03:04.590Z] ====== log-regression (apache-spark) [default], iteration 11 completed (1976.835 ms) ======
[2023-04-20T02:03:04.590Z] ====== log-regression (apache-spark) [default], iteration 12 started ======
[2023-04-20T02:03:05.364Z] GC before operation: completed in 230.777 ms, heap usage 220.835 MB -> 107.135 MB.
[2023-04-20T02:03:07.114Z] ====== log-regression (apache-spark) [default], iteration 12 completed (1941.949 ms) ======
[2023-04-20T02:03:07.114Z] ====== log-regression (apache-spark) [default], iteration 13 started ======
[2023-04-20T02:03:07.114Z] GC before operation: completed in 184.516 ms, heap usage 245.695 MB -> 107.650 MB.
[2023-04-20T02:03:09.561Z] ====== log-regression (apache-spark) [default], iteration 13 completed (1977.839 ms) ======
[2023-04-20T02:03:09.562Z] ====== log-regression (apache-spark) [default], iteration 14 started ======
[2023-04-20T02:03:09.562Z] GC before operation: completed in 254.064 ms, heap usage 307.160 MB -> 108.928 MB.
[2023-04-20T02:03:11.140Z] ====== log-regression (apache-spark) [default], iteration 14 completed (1857.420 ms) ======
[2023-04-20T02:03:11.140Z] ====== log-regression (apache-spark) [default], iteration 15 started ======
[2023-04-20T02:03:11.140Z] GC before operation: completed in 219.845 ms, heap usage 331.398 MB -> 109.492 MB.
[2023-04-20T02:03:13.601Z] ====== log-regression (apache-spark) [default], iteration 15 completed (1774.468 ms) ======
[2023-04-20T02:03:13.601Z] ====== log-regression (apache-spark) [default], iteration 16 started ======
[2023-04-20T02:03:13.601Z] GC before operation: completed in 265.425 ms, heap usage 217.896 MB -> 108.800 MB.
[2023-04-20T02:03:15.172Z] ====== log-regression (apache-spark) [default], iteration 16 completed (1877.147 ms) ======
[2023-04-20T02:03:15.172Z] ====== log-regression (apache-spark) [default], iteration 17 started ======
[2023-04-20T02:03:15.936Z] GC before operation: completed in 190.131 ms, heap usage 208.546 MB -> 109.167 MB.
[2023-04-20T02:03:17.526Z] ====== log-regression (apache-spark) [default], iteration 17 completed (1921.375 ms) ======
[2023-04-20T02:03:17.526Z] ====== log-regression (apache-spark) [default], iteration 18 started ======
[2023-04-20T02:03:17.526Z] GC before operation: completed in 296.302 ms, heap usage 296.063 MB -> 110.658 MB.
[2023-04-20T02:03:19.992Z] ====== log-regression (apache-spark) [default], iteration 18 completed (1844.742 ms) ======
[2023-04-20T02:03:19.992Z] ====== log-regression (apache-spark) [default], iteration 19 started ======
[2023-04-20T02:03:19.992Z] GC before operation: completed in 214.911 ms, heap usage 319.831 MB -> 111.142 MB.
[2023-04-20T02:03:20.754Z] 23/04/20 02:14:08 ERROR Utils: Uncaught exception in thread executor-heartbeater
[2023-04-20T02:03:20.754Z] java.util.ConcurrentModificationException: mutation occurred during iteration
[2023-04-20T02:03:20.754Z] at scala.collection.mutable.MutationTracker$.checkMutations(MutationTracker.scala:43)
[2023-04-20T02:03:20.754Z] at scala.collection.mutable.CheckedIndexedSeqView$CheckedIterator.hasNext(CheckedIndexedSeqView.scala:47)
[2023-04-20T02:03:20.754Z] at scala.collection.IterableOnceOps.copyToArray(IterableOnce.scala:873)
[2023-04-20T02:03:20.754Z] at scala.collection.IterableOnceOps.copyToArray$(IterableOnce.scala:869)
[2023-04-20T02:03:20.754Z] at scala.collection.AbstractIterator.copyToArray(Iterator.scala:1293)
[2023-04-20T02:03:20.754Z] at scala.collection.IterableOnceOps.copyToArray(IterableOnce.scala:852)
[2023-04-20T02:03:20.754Z] at scala.collection.IterableOnceOps.copyToArray$(IterableOnce.scala:852)
[2023-04-20T02:03:20.754Z] at scala.collection.AbstractIterator.copyToArray(Iterator.scala:1293)
[2023-04-20T02:03:20.754Z] at scala.collection.immutable.VectorStatics$.append1IfSpace(Vector.scala:1959)
[2023-04-20T02:03:20.754Z] at scala.collection.immutable.Vector1.appendedAll0(Vector.scala:425)
[2023-04-20T02:03:20.754Z] at scala.collection.immutable.Vector.appendedAll(Vector.scala:203)
[2023-04-20T02:03:20.754Z] at scala.collection.immutable.Vector.appendedAll(Vector.scala:113)
[2023-04-20T02:03:20.755Z] at scala.collection.SeqOps.concat(Seq.scala:187)
[2023-04-20T02:03:20.755Z] at scala.collection.SeqOps.concat$(Seq.scala:187)
[2023-04-20T02:03:20.755Z] at scala.collection.AbstractSeq.concat(Seq.scala:1161)
[2023-04-20T02:03:20.755Z] at scala.collection.IterableOps.$plus$plus(Iterable.scala:726)
[2023-04-20T02:03:20.755Z] at scala.collection.IterableOps.$plus$plus$(Iterable.scala:726)
[2023-04-20T02:03:20.755Z] at scala.collection.AbstractIterable.$plus$plus(Iterable.scala:926)
[2023-04-20T02:03:20.755Z] at org.apache.spark.executor.TaskMetrics.accumulators(TaskMetrics.scala:261)
[2023-04-20T02:03:20.755Z] at org.apache.spark.executor.Executor.$anonfun$reportHeartBeat$1(Executor.scala:994)
[2023-04-20T02:03:20.755Z] at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:563)
[2023-04-20T02:03:20.755Z] at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:561)
[2023-04-20T02:03:20.755Z] at scala.collection.AbstractIterable.foreach(Iterable.scala:926)
[2023-04-20T02:03:20.755Z] at org.apache.spark.executor.Executor.reportHeartBeat(Executor.scala:988)
[2023-04-20T02:03:20.755Z] at org.apache.spark.executor.Executor.$anonfun$heartbeater$1(Executor.scala:212)
[2023-04-20T02:03:20.755Z] at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
[2023-04-20T02:03:20.755Z] at org.apache.spark.util.Utils$.logUncaughtExceptions(Utils.scala:2019)
[2023-04-20T02:03:20.755Z] at org.apache.spark.Heartbeater$$anon$1.run(Heartbeater.scala:46)
[2023-04-20T02:03:20.755Z] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[2023-04-20T02:03:20.755Z] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
[2023-04-20T02:03:20.755Z] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
[2023-04-20T02:03:20.755Z] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
[2023-04-20T02:03:20.755Z] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[2023-04-20T02:03:20.755Z] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[2023-04-20T02:03:20.755Z] at java.lang.Thread.run(Thread.java:750)
[2023-04-20T02:03:21.516Z] ====== log-regression (apache-spark) [default], iteration 19 completed (1800.944 ms) ======
[2023-04-20T02:03:22.277Z] -----------------------------------
[2023-04-20T02:03:22.277Z] renaissance-log-regression_0_PASSED
[2023-04-20T02:03:22.277Z] -----------------------------------
[2023-04-20T02:03:22.277Z]
[2023-04-20T02:03:22.277Z] TEST TEARDOWN:
[2023-04-20T02:03:22.277Z] Nothing to be done for teardown.
[2023-04-20T02:03:22.277Z] renaissance-log-regression_0 Finish Time: Thu Apr 20 02:14:10 2023 Epoch Time (ms): 1681956850010