Merge pull request #875 from ie3-institute/ms/#801-fixing-duration-ca…

…lculation-in-result-events

Fixing duration calculation in result events.

CHANGELOG.md

@@ -87,6 +87,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 - Finally fixing `RuntimeEventListenerSpec` [#849](https://github.com/ie3-institute/simona/issues/849)
 - Fixed result output for thermal houses and cylindrical storages [#844](https://github.com/ie3-institute/simona/issues/844)
 - Fixed FixedFeedModelSpec [#861](https://github.com/ie3-institute/simona/issues/861)
+- Fixing duration calculation in result events [#801](https://github.com/ie3-institute/simona/issues/801)
 
 ## [3.0.0] - 2023-08-07
 

src/main/scala/edu/ie3/simona/io/runtime/RuntimeEventLogSink.scala

@@ -14,6 +14,7 @@ import edu.ie3.util.TimeUtil
 import org.slf4j.Logger
 
 import java.time.ZonedDateTime
+import scala.concurrent.duration.DurationLong
 
 /** Runtime event sink that just logs all received events.
   *
@@ -26,6 +27,7 @@ import java.time.ZonedDateTime
 final case class RuntimeEventLogSink(
     simulationStartDate: ZonedDateTime,
     log: Logger,
+    private var last: Long = 0L,
 ) extends RuntimeEventSink {
 
   override def handleRuntimeEvent(
@@ -43,13 +45,15 @@ final case class RuntimeEventLogSink(
 
       case CheckWindowPassed(tick, duration) =>
         log.info(
-          s"******* Simulation until ${calcTime(tick)} completed. ${durationAndMemoryString(duration)} ******"
+          s"******* Simulation until ${calcTime(tick)} completed. ${durationAndMemoryString(duration - last)} ******"
         )
+        last = duration
 
       case Ready(tick, duration) =>
         log.info(
-          s"******* Switched from 'Simulating' to 'Ready'. Last simulated time: ${calcTime(tick)}. ${durationAndMemoryString(duration)}  ******"
+          s"******* Switched from 'Simulating' to 'Ready'. Last simulated time: ${calcTime(tick)}. ${durationAndMemoryString(duration - last)}  ******"
         )
+        last = duration
 
       case Simulating(startTick, endTick) =>
         log.info(
@@ -84,12 +88,14 @@ final case class RuntimeEventLogSink(
   }
 
   private def convertDuration(duration: Long): String = {
-    val durationInSeconds = duration / 1000
-
-    val hours = durationInSeconds / 3600
-    val minutes = (durationInSeconds / 60) % 60
-    val seconds = durationInSeconds % 60
-    s"${hours}h : ${minutes}m : ${seconds}s"
+    val time = duration.milliseconds
+
+    val hours = time.toHours
+    val minutes = time.toMinutes % 60
+    val seconds = time.toSeconds % 60
+    val milliseconds =
+      (time - hours.hours - minutes.minutes - seconds.seconds).toMillis
+    s"${hours}h : ${minutes}m : ${seconds}s : ${milliseconds}ms"
   }
 
   private def durationAndMemoryString(duration: Long) = {

src/test/scala/edu/ie3/simona/event/listener/RuntimeEventListenerLoggingSpec.scala

@@ -78,7 +78,7 @@ class RuntimeEventListenerLoggingSpec
         (
           InitComplete(0L),
           Level.INFO,
-          s"Initialization complete. (duration: 0h : 0m : 0s )",
+          s"Initialization complete. (duration: 0h : 0m : 0s : 0ms )",
         ),
         (
           Ready(currentTick, 0L),