[prelude][core] Frame and Log optimizations (#800)

I noticed a major performance regression in `LoggingBench`. The main cause is a bug introduced by #783 that makes the benchmark consider `Level.error` enabled when it isn't. I fixed the bug but also worked on a few optimizations to improve performance in case the log is enabled. Benchmark [results](https://jmh.morethan.io/?sources=https://gist.githubusercontent.com/fwbrasil/b7686518b8168f6fcba4ab2787d0ff41/raw/29e149f7bb688672cfdad844e308cde4df999e0e/jmh-result-baseline.json,https://gist.githubusercontent.com/fwbrasil/b7686518b8168f6fcba4ab2787d0ff41/raw/29e149f7bb688672cfdad844e308cde4df999e0e/jmh-result-candidate.json): ![image](https://github.com/user-attachments/assets/550bfe52-96dd-430f-a8b9-472f71d35b6e)
getkyo · Nov 1, 2024 · 17e5646 · 17e5646
1 parent 218ffca
commit 17e5646
Show file tree

Hide file tree

Showing 16 changed files with 210 additions and 145 deletions.
diff --git a/kyo-core/jvm/src/main/scala/kyo/internal/LogPlatformSpecific.scala b/kyo-core/jvm/src/main/scala/kyo/internal/LogPlatformSpecific.scala
@@ -17,42 +17,42 @@ object LogPlatformSpecific:
             def apply(name: String) = new SLF4J(org.slf4j.LoggerFactory.getLogger(name))
 
         class SLF4J(logger: org.slf4j.Logger) extends Log.Unsafe:
-            def level =
-                if logger.isTraceEnabled() then Level.trace
-                else if logger.isDebugEnabled() then Level.debug
-                else if logger.isInfoEnabled() then Level.info
+            val level =
+                if logger.isErrorEnabled() then Level.error
                 else if logger.isWarnEnabled() then Level.warn
-                else Level.error
+                else if logger.isInfoEnabled() then Level.info
+                else if logger.isDebugEnabled() then Level.debug
+                else Level.trace
 
             inline def trace(msg: => String)(using frame: Frame, allow: AllowUnsafe): Unit =
-                if Level.trace.enabled(level) then logger.trace(s"[${frame.parse.position}] $msg")
+                if Level.trace.enabled(level) then logger.trace(s"[${frame.position.show}] $msg")
 
             inline def trace(msg: => String, t: => Throwable)(using frame: Frame, allow: AllowUnsafe): Unit =
-                if Level.trace.enabled(level) then logger.trace(s"[${frame.parse.position}] $msg", t)
+                if Level.trace.enabled(level) then logger.trace(s"[${frame.position.show}] $msg", t)
 
             inline def debug(msg: => String)(using frame: Frame, allow: AllowUnsafe): Unit =
-                if Level.debug.enabled(level) then logger.debug(s"[${frame.parse.position}] $msg")
+                if Level.debug.enabled(level) then logger.debug(s"[${frame.position.show}] $msg")
 
             inline def debug(msg: => String, t: => Throwable)(using frame: Frame, allow: AllowUnsafe): Unit =
-                if Level.debug.enabled(level) then logger.debug(s"[${frame.parse.position}] $msg", t)
+                if Level.debug.enabled(level) then logger.debug(s"[${frame.position.show}] $msg", t)
 
             inline def info(msg: => String)(using frame: Frame, allow: AllowUnsafe): Unit =
-                if Level.info.enabled(level) then logger.info(s"[${frame.parse.position}] $msg")
+                if Level.info.enabled(level) then logger.info(s"[${frame.position.show}] $msg")
 
             inline def info(msg: => String, t: => Throwable)(using frame: Frame, allow: AllowUnsafe): Unit =
-                if Level.info.enabled(level) then logger.info(s"[${frame.parse.position}] $msg", t)
+                if Level.info.enabled(level) then logger.info(s"[${frame.position.show}] $msg", t)
 
             inline def warn(msg: => String)(using frame: Frame, allow: AllowUnsafe): Unit =
-                if Level.warn.enabled(level) then logger.warn(s"[${frame.parse.position}] $msg")
+                if Level.warn.enabled(level) then logger.warn(s"[${frame.position.show}] $msg")
 
             inline def warn(msg: => String, t: => Throwable)(using frame: Frame, allow: AllowUnsafe): Unit =
-                if Level.warn.enabled(level) then logger.warn(s"[${frame.parse.position}] $msg", t)
+                if Level.warn.enabled(level) then logger.warn(s"[${frame.position.show}] $msg", t)
 
             inline def error(msg: => String)(using frame: Frame, allow: AllowUnsafe): Unit =
-                if Level.error.enabled(level) then logger.error(s"[${frame.parse.position}] $msg")
+                if Level.error.enabled(level) then logger.error(s"[${frame.position.show}] $msg")
 
             inline def error(msg: => String, t: => Throwable)(using frame: Frame, allow: AllowUnsafe): Unit =
-                if Level.error.enabled(level) then logger.error(s"[${frame.parse.position}] $msg", t)
+                if Level.error.enabled(level) then logger.error(s"[${frame.position.show}] $msg", t)
         end SLF4J
     end Unsafe
 end LogPlatformSpecific
diff --git a/kyo-core/shared/src/main/scala/kyo/Closed.scala b/kyo-core/shared/src/main/scala/kyo/Closed.scala
@@ -3,5 +3,5 @@ package kyo
 import scala.util.control.NoStackTrace
 
 case class Closed(message: String, createdAt: Frame, failedAt: Frame)
-    extends Exception(s"Resource created at ${createdAt.parse.position} is closed. Failure at ${failedAt.parse.position}: $message")
+    extends Exception(s"Resource created at ${createdAt.position.show} is closed. Failure at ${failedAt.position.show}: $message")
     with NoStackTrace
diff --git a/kyo-core/shared/src/main/scala/kyo/Fiber.scala b/kyo-core/shared/src/main/scala/kyo/Fiber.scala
@@ -248,7 +248,7 @@ object Fiber extends FiberPlatformSpecific:
     end extension
 
     case class Interrupted(at: Frame)
-        extends RuntimeException("Fiber interrupted at " + at.parse.position)
+        extends RuntimeException("Fiber interrupted at " + at.position.show)
         with NoStackTrace:
         override def getCause() = null
     end Interrupted

diff --git a/kyo-core/shared/src/main/scala/kyo/Log.scala b/kyo-core/shared/src/main/scala/kyo/Log.scala
@@ -2,7 +2,7 @@ package kyo
 
 import kyo.internal.LogPlatformSpecific
 
-final case class Log(unsafe: Log.Unsafe) extends AnyVal:
+final case class Log(unsafe: Log.Unsafe):
     def level: Log.Level                                                                                  = unsafe.level
     inline def trace(inline msg: => String)(using inline frame: Frame): Unit < IO                         = IO.Unsafe(unsafe.trace(msg))
     inline def trace(inline msg: => String, inline t: => Throwable)(using inline frame: Frame): Unit < IO = IO.Unsafe(unsafe.trace(msg, t))
@@ -19,8 +19,8 @@ end Log
 /** Logging utility object for Kyo applications. */
 object Log extends LogPlatformSpecific:
 
-    final class Level private (private val priority: Int) extends AnyVal:
-        def enabled(minLevel: Level) = priority >= minLevel.priority
+    final case class Level private (private val priority: Int) extends AnyVal:
+        def enabled(maxLevel: Level) = maxLevel.priority <= priority
 
     object Level:
         val trace: Level = Level(10)
@@ -109,62 +109,62 @@ object Log extends LogPlatformSpecific:
                 using
                 frame: Frame,
                 allow: AllowUnsafe
-            ): Unit = if Level.trace.enabled(level) then println(s"TRACE $name -- [${frame.parse.position}] $msg")
+            ): Unit = if Level.trace.enabled(level) then println(s"TRACE $name -- [${frame.position.show}] $msg")
 
             inline def trace(msg: => String, t: => Throwable)(
                 using
                 frame: Frame,
                 allow: AllowUnsafe
-            ): Unit = if Level.trace.enabled(level) then println(s"TRACE $name -- [${frame.parse.position}] $msg $t")
+            ): Unit = if Level.trace.enabled(level) then println(s"TRACE $name -- [${frame.position.show}] $msg $t")
 
             inline def debug(msg: => String)(
                 using
                 frame: Frame,
                 allow: AllowUnsafe
             ): Unit =
-                if Level.debug.enabled(level) then println(s"DEBUG $name -- [${frame.parse.position}] $msg")
+                if Level.debug.enabled(level) then println(s"DEBUG $name -- [${frame.position.show}] $msg")
 
             inline def debug(msg: => String, t: => Throwable)(
                 using
                 frame: Frame,
                 allow: AllowUnsafe
-            ): Unit = if Level.debug.enabled(level) then println(s"DEBUG $name -- [${frame.parse.position}] $msg $t")
+            ): Unit = if Level.debug.enabled(level) then println(s"DEBUG $name -- [${frame.position.show}] $msg $t")
 
             inline def info(msg: => String)(
                 using
                 frame: Frame,
                 allow: AllowUnsafe
-            ): Unit = if Level.info.enabled(level) then println(s"INFO $name -- [${frame.parse.position}] $msg")
+            ): Unit = if Level.info.enabled(level) then println(s"INFO $name -- [${frame.position.show}] $msg")
 
             inline def info(msg: => String, t: => Throwable)(
                 using
                 frame: Frame,
                 allow: AllowUnsafe
-            ): Unit = if Level.info.enabled(level) then println(s"INFO $name -- [${frame.parse.position}] $msg $t")
+            ): Unit = if Level.info.enabled(level) then println(s"INFO $name -- [${frame.position.show}] $msg $t")
 
             inline def warn(msg: => String)(
                 using
                 frame: Frame,
                 allow: AllowUnsafe
-            ): Unit = if Level.warn.enabled(level) then println(s"WARN $name -- [${frame.parse.position}] $msg")
+            ): Unit = if Level.warn.enabled(level) then println(s"WARN $name -- [${frame.position.show}] $msg")
 
             inline def warn(msg: => String, t: => Throwable)(
                 using
                 frame: Frame,
                 allow: AllowUnsafe
-            ): Unit = if Level.warn.enabled(level) then println(s"WARN $name -- [${frame.parse.position}] $msg $t")
+            ): Unit = if Level.warn.enabled(level) then println(s"WARN $name -- [${frame.position.show}] $msg $t")
 
             inline def error(msg: => String)(
                 using
                 frame: Frame,
                 allow: AllowUnsafe
-            ): Unit = if Level.error.enabled(level) then println(s"ERROR $name -- [${frame.parse.position}] $msg")
+            ): Unit = if Level.error.enabled(level) then println(s"ERROR $name -- [${frame.position.show}] $msg")
 
             inline def error(msg: => String, t: => Throwable)(
                 using
                 frame: Frame,
                 allow: AllowUnsafe
-            ): Unit = if Level.error.enabled(level) then println(s"ERROR $name -- [${frame.parse.position}] $msg $t")
+            ): Unit = if Level.error.enabled(level) then println(s"ERROR $name -- [${frame.position.show}] $msg $t")
         end ConsoleLogger
     end Unsafe
 

diff --git a/kyo-core/shared/src/main/scala/kyo/Timeout.scala b/kyo-core/shared/src/main/scala/kyo/Timeout.scala
@@ -3,5 +3,5 @@ package kyo
 import scala.util.control.NoStackTrace
 
 case class Timeout(frame: Frame)
-    extends Exception(frame.parse.position.toString)
+    extends Exception(frame.position.show)
     with NoStackTrace
diff --git a/kyo-data/shared/src/main/scala/kyo/Ansi.scala b/kyo-data/shared/src/main/scala/kyo/Ansi.scala
@@ -67,18 +67,19 @@ object Ansi:
           */
         def apply(header: String, code: String, trailer: String, startLine: Int = 1): String =
             try
-                val headerLines  = if header.nonEmpty then header.split("\n") else Array.empty[String]
-                val codeLines    = code.split("\n").dropWhile(_.isBlank).reverse.dropWhile(_.isBlank).reverse
-                val trailerLines = if trailer.nonEmpty then trailer.split("\n") else Array.empty[String]
+                val separatorLine = "─".repeat(30).dim
+                val headerLines   = if header.nonEmpty then Array(separatorLine) ++ header.split("\n") else Array.empty[String]
+                val codeLines     = code.split("\n").dropWhile(_.isBlank).reverse.dropWhile(_.isBlank).reverse
+                val trailerLines  = if trailer.nonEmpty then trailer.split("\n") ++ Array(separatorLine) else Array.empty[String]
 
-                val allLines        = headerLines ++ codeLines ++ trailerLines
                 val toDrop          = codeLines.filter(_.trim.nonEmpty).map(_.takeWhile(_ == ' ').length).minOption.getOrElse(0)
-                val lineNumberWidth = (startLine + codeLines.length - 1).toString.length
+                val lineNumberWidth = (startLine + codeLines.length).toString.length
                 val separator       = "│".dim
+                val allLines        = headerLines ++ Array(separatorLine) ++ codeLines ++ Array(separatorLine) ++ trailerLines
 
                 val processedLines = allLines.zipWithIndex.map { case (line, index) =>
-                    val isHeader  = index < headerLines.length
-                    val isTrailer = index >= (headerLines.length + codeLines.length)
+                    val isHeader  = index <= headerLines.length
+                    val isTrailer = index > (headerLines.length + codeLines.length)
                     val lineNumber =
                         if isHeader || isTrailer then
                             " ".repeat(lineNumberWidth)

diff --git a/kyo-prelude/jvm/src/test/scala/kyo/kernel/SafepointTest.scala b/kyo-prelude/jvm/src/test/scala/kyo/kernel/SafepointTest.scala
@@ -281,8 +281,7 @@ class SafepointTest extends Test:
                 val logs = ArrayBuffer.empty[String]
 
                 def enter(frame: Frame, value: Any): Boolean =
-                    val parsed = frame.parse
-                    logs += s"Entering ${parsed.methodName} with value: $value"
+                    logs += s"Entering ${frame.methodName} with value: $value"
                     true
                 end enter
 
@@ -365,7 +364,7 @@ class SafepointTest extends Test:
             }
 
             assert(interceptor.log.size == 3)
-            assert(interceptor.log.exists(_._1.parse.methodName == "computation"))
+            assert(interceptor.log.exists(_._1.methodName == "computation"))
         }
     }
 

diff --git a/kyo-prelude/shared/src/main/scala/kyo/Batch.scala b/kyo-prelude/shared/src/main/scala/kyo/Batch.scala
@@ -51,7 +51,7 @@ object Batch:
             f(input).map { output =>
                 require(
                     input.size == output.size,
-                    s"Source created at ${frame.parse.position} returned a different number of elements than input: ${input.size} != ${output.size}"
+                    s"Source created at ${frame.position.show} returned a different number of elements than input: ${input.size} != ${output.size}"
                 )
                 ((a: A) => output(a): B < S)
             }
@@ -69,7 +69,7 @@ object Batch:
             f(input).map { output =>
                 require(
                     input.size == output.size,
-                    s"Source created at ${frame.parse.position} returned a different number of elements than input: ${input.size} != ${output.size}"
+                    s"Source created at ${frame.position.show} returned a different number of elements than input: ${input.size} != ${output.size}"
                 )
                 input.zip(output).toMap
             }

diff --git a/kyo-prelude/shared/src/main/scala/kyo/Check.scala b/kyo-prelude/shared/src/main/scala/kyo/Check.scala
@@ -14,15 +14,7 @@ import kyo.kernel.*
   *   The [[Frame]] where the check failure occurred
   */
 final class CheckFailed(val message: String, val frame: Frame) extends AssertionError(message):
-    override def getMessage() =
-        Seq(
-            "",
-            "──────────────────────────────".dim,
-            "Check failed! ".red.bold + message,
-            "──────────────────────────────".dim,
-            frame.parse.show,
-            "──────────────────────────────".dim
-        ).mkString("\n")
+    override def getMessage() = frame.render("Check failed! ".red.bold + message)
 end CheckFailed
 
 /** Represents a check effect for validating conditions.

diff --git a/kyo-prelude/shared/src/main/scala/kyo/Parse.scala b/kyo-prelude/shared/src/main/scala/kyo/Parse.scala
@@ -458,16 +458,5 @@ end Parse
 
 case class ParseFailed(frame: Frame, states: Seq[Parse.State], message: String) extends Exception with Serializable:
 
-    override def getMessage() =
-        Seq(
-            "\n".dim,
-            "──────────────────────────────".dim,
-            "Parse failed! ".red.bold + message,
-            "──────────────────────────────".dim,
-            frame.parse.show,
-            "──────────────────────────────".dim,
-            pprint(states).plainText,
-            "──────────────────────────────".dim
-        ).mkString("\n")
-    end getMessage
+    override def getMessage() = frame.render("Parse failed! ".red.bold + message, states)
 end ParseFailed
diff --git a/kyo-prelude/shared/src/main/scala/kyo/debug/Debug.scala b/kyo-prelude/shared/src/main/scala/kyo/debug/Debug.scala
@@ -24,12 +24,12 @@ object Debug:
     def apply[A, S](v: => A < S)(using frame: Frame): A < S =
         Effect.catching {
             v.map { value =>
-                println(frame.show)
+                println(frame.render)
                 printValue(value)
                 value
             }
         } { ex =>
-            println(frame.show)
+            println(frame.render)
             printValue(ex)
             throw ex
         }
@@ -48,7 +48,7 @@ object Debug:
         val interceptor = new Safepoint.Interceptor:
             def enter(frame: Frame, value: Any): Boolean =
                 printValue(value)
-                println(frame.parse.show)
+                println(frame.render)
                 true
             end enter
             def addFinalizer(f: () => Unit): Unit    = ()
@@ -77,7 +77,7 @@ object Debug:
     def values(params: Param[?]*)(using frame: Frame): Unit =
         val tuples = LinkedHashMap(params.map(p => (p.code, p.value))*)
         val string = pprint(tuples).render.replaceFirst("LinkedHashMap", "Params")
-        println(frame.parse.show)
+        println(frame.render)
         println(string)
     end values
 
@@ -104,14 +104,14 @@ object Debug:
     end Param
 
     private def printValue(value: Any) =
-        println("──────────────────────────────".dim)
+        println("───────────────────────────────────".dim)
         val rendered = pprint(value).render
         val truncated =
             if rendered.length > maxValueLength then
                 rendered.take(maxValueLength) + " ... (truncated)"
             else
                 rendered
         println(truncated)
-        println("──────────────────────────────".dim)
+        println("───────────────────────────────────".dim)
     end printValue
 end Debug