From 655361fbb9a8044e2ea4274d107c7e1af818af6f Mon Sep 17 00:00:00 2001 From: Peter Kotula Date: Tue, 8 Aug 2023 21:08:01 +0200 Subject: [PATCH] key value separator (#753) --- .../scala/zio/logging/LogFormatSpec.scala | 80 ++++++++++++++++++- .../main/scala/zio/logging/LogFilter.scala | 2 +- .../main/scala/zio/logging/LogFormat.scala | 32 ++++---- .../zio/logging/internal/LogAppender.scala | 49 ++++++++---- .../slf4j/bridge/ZioLoggerRuntime.scala | 2 +- 5 files changed, 128 insertions(+), 37 deletions(-) diff --git a/core/jvm/src/test/scala/zio/logging/LogFormatSpec.scala b/core/jvm/src/test/scala/zio/logging/LogFormatSpec.scala index 2d2358a9..ba7c8325 100644 --- a/core/jvm/src/test/scala/zio/logging/LogFormatSpec.scala +++ b/core/jvm/src/test/scala/zio/logging/LogFormatSpec.scala @@ -1,7 +1,7 @@ package zio.logging -import zio.test._ -import zio.{ Cause, FiberId, FiberRefs, LogLevel, Trace } +import zio.test.{ Assertion, _ } +import zio.{ Cause, FiberId, FiberRefs, LogLevel, LogSpan, Trace } import java.util.UUID @@ -174,6 +174,27 @@ object LogFormatSpec extends ZIOSpecDefault { ) assertTrue(result == "") }, + test("logAnnotations") { + val format = LogFormat.logAnnotations + check(Gen.string, Gen.uuid) { (userId, traceId) => + val result = format.toLogger( + Trace.empty, + FiberId.None, + LogLevel.Info, + () => "", + Cause.empty, + FiberRefs.empty.updatedAs(FiberId.Runtime(0, 0, Trace.empty))( + logContext, + LogContext.empty + .annotate(LogAnnotation.UserId, userId) + .annotate(LogAnnotation.TraceId, traceId) + ), + Nil, + Map.empty + ) + assertTrue(result == s"user_id=${userId} trace_id=${traceId}") + } + }, test("allAnnotations") { val format = LogFormat.allAnnotations check(Gen.string) { annotationValue => @@ -190,7 +211,7 @@ object LogFormatSpec extends ZIOSpecDefault { Nil, Map("test" -> annotationValue) ) - assertTrue(result == s"test=${annotationValue}user_id=${annotationValue}") + assertTrue(result == s"test=${annotationValue} user_id=${annotationValue}") } }, test("allAnnotations with exclusion") { @@ -211,7 +232,58 @@ object LogFormatSpec extends ZIOSpecDefault { Nil, Map("test" -> annotationValue, "test2" -> annotationValue) ) - assertTrue(result == s"test=${annotationValue}user_id=${annotationValue}") + assertTrue(result == s"test=${annotationValue} user_id=${annotationValue}") + } + }, + test("allAnnotations with one value") { + val format = LogFormat.allAnnotations(excludeKeys = Set("test2", LogAnnotation.TraceId.name)) + check(Gen.string) { annotationValue => + val result = format.toLogger( + Trace.empty, + FiberId.None, + LogLevel.Info, + () => "", + Cause.empty, + FiberRefs.empty.updatedAs(FiberId.Runtime(0, 0, Trace.empty))( + logContext, + LogContext.empty.annotate(LogAnnotation.TraceId, UUID.randomUUID()) + ), + Nil, + Map("test" -> annotationValue, "test2" -> annotationValue) + ) + assertTrue(result == s"test=${annotationValue}") + } + }, + test("span") { + val format = LogFormat.span("span1") + check(Gen.alphaNumericString) { span => + val result = format.toLogger( + Trace.empty, + FiberId.None, + LogLevel.Info, + () => "", + Cause.empty, + FiberRefs.empty, + List(LogSpan("span1", 0L), LogSpan(span, 1L)), + Map.empty + ) + assert(result)(Assertion.matchesRegex("span1=([0-9]+)ms")) + } + }, + test("spans") { + val format = LogFormat.spans + check(Gen.alphaNumericString) { span => + val result = format.toLogger( + Trace.empty, + FiberId.None, + LogLevel.Info, + () => "", + Cause.empty, + FiberRefs.empty, + List(LogSpan("span1", 0L), LogSpan(span, 1L)), + Map.empty + ) + assert(result)(Assertion.matchesRegex(s"span1=([0-9]+)ms ${span}=([0-9]+)ms")) } }, test("enclosing class") { diff --git a/core/shared/src/main/scala/zio/logging/LogFilter.scala b/core/shared/src/main/scala/zio/logging/LogFilter.scala index ea8a2973..d8e9593a 100644 --- a/core/shared/src/main/scala/zio/logging/LogFilter.scala +++ b/core/shared/src/main/scala/zio/logging/LogFilter.scala @@ -15,7 +15,7 @@ */ package zio.logging -import zio.{ Cause, Chunk, Config, FiberId, FiberRefs, LogLevel, LogSpan, Trace, ZLogger } +import zio.{ Cause, Config, FiberId, FiberRefs, LogLevel, LogSpan, Trace, ZLogger } import scala.annotation.tailrec diff --git a/core/shared/src/main/scala/zio/logging/LogFormat.scala b/core/shared/src/main/scala/zio/logging/LogFormat.scala index 1317a69e..e41fad25 100644 --- a/core/shared/src/main/scala/zio/logging/LogFormat.scala +++ b/core/shared/src/main/scala/zio/logging/LogFormat.scala @@ -662,11 +662,7 @@ object LogFormat { def annotations(excludeKeys: Set[String]): LogFormat = LogFormat.make { (builder, _, _, _, _, _, _, _, annotations) => - annotations.foreach { case (key, value) => - if (!excludeKeys.contains(key)) { - builder.appendKeyValue(key, value) - } - } + builder.appendKeyValues(annotations.filterNot(kv => excludeKeys.contains(kv._1))) } def logAnnotations: LogFormat = logAnnotations(Set.empty) @@ -676,18 +672,24 @@ object LogFormat { fiberRefs .get(logContext) .foreach { context => - context.asMap.foreach { case (key, value) => - if (!excludeKeys.contains(key)) { - builder.appendKeyValue(key, value) - } - } + builder.appendKeyValues(context.asMap.filterNot(kv => excludeKeys.contains(kv._1))) } () } def allAnnotations: LogFormat = allAnnotations(Set.empty) - def allAnnotations(excludeKeys: Set[String]): LogFormat = annotations(excludeKeys) + logAnnotations(excludeKeys) + def allAnnotations(excludeKeys: Set[String]): LogFormat = LogFormat.make { + (builder, _, _, _, _, _, fiberRefs, _, annotations) => + val keyValues = annotations.filterNot(kv => excludeKeys.contains(kv._1)).toList ++ fiberRefs + .get(logContext) + .map { context => + context.asMap.filterNot(kv => excludeKeys.contains(kv._1)).toList + } + .getOrElse(Nil) + + builder.appendKeyValues(keyValues) + } def bracketed(inner: LogFormat): LogFormat = bracketStart + inner + bracketEnd @@ -771,7 +773,7 @@ object LogFormat { LogFormat.make { (builder, _, _, _, _, _, _, spans, _) => spans.find(_.label == name).foreach { span => val duration = (java.lang.System.currentTimeMillis() - span.startTime).toString - builder.appendKeyValue(name, duration) + builder.appendKeyValue(name, s"${duration}ms") } } @@ -780,10 +782,10 @@ object LogFormat { */ def spans: LogFormat = LogFormat.make { (builder, _, _, _, _, _, _, spans, _) => - spans.foreach { span => + builder.appendKeyValues(spans.map { span => val duration = (java.lang.System.currentTimeMillis() - span.startTime).toString - builder.appendKeyValue(span.label, duration + "ms") - } + span.label -> s"${duration}ms" + }) } def text(value: => String): LogFormat = diff --git a/core/shared/src/main/scala/zio/logging/internal/LogAppender.scala b/core/shared/src/main/scala/zio/logging/internal/LogAppender.scala index 3e88b124..a1d13cc0 100644 --- a/core/shared/src/main/scala/zio/logging/internal/LogAppender.scala +++ b/core/shared/src/main/scala/zio/logging/internal/LogAppender.scala @@ -59,6 +59,19 @@ private[logging] trait LogAppender { self => finally closeValue() } + def appendKeyValueSeparator(): Unit = () + + def appendKeyValues(keyValues: Iterable[(String, String)]): Unit = { + val iterator = keyValues.iterator + while (iterator.hasNext) { + val (key, value) = iterator.next() + appendKeyValue(key, value) + if (iterator.hasNext) { + appendKeyValueSeparator() + } + } + } + /** * Marks the close of a key for a key/value pair, and the opening of the value. */ @@ -95,21 +108,23 @@ private[logging] trait LogAppender { self => } private[logging] object LogAppender { class Proxy(self: LogAppender) extends LogAppender { - def appendCause(cause: Cause[Any]): Unit = self.appendCause(cause) + override def appendCause(cause: Cause[Any]): Unit = self.appendCause(cause) - def appendNumeric[A](numeric: A): Unit = self.appendNumeric(numeric) + override def appendKeyValueSeparator(): Unit = self.appendKeyValueSeparator() - def appendText(text: String): Unit = self.appendText(text) + override def appendNumeric[A](numeric: A): Unit = self.appendNumeric(numeric) - def closeKeyOpenValue(): Unit = self.closeKeyOpenValue() + override def appendText(text: String): Unit = self.appendText(text) - def closeLogEntry(): Unit = self.closeLogEntry() + override def closeKeyOpenValue(): Unit = self.closeKeyOpenValue() - def closeValue(): Unit = self.closeValue() + override def closeLogEntry(): Unit = self.closeLogEntry() - def openKey(): Unit = self.openKey() + override def closeValue(): Unit = self.closeValue() - def openLogEntry(): Unit = self.openLogEntry() + override def openKey(): Unit = self.openKey() + + override def openLogEntry(): Unit = self.openLogEntry() } /** @@ -117,21 +132,23 @@ private[logging] object LogAppender { * into text, and passes it to the given text appender function. */ def unstructured(textAppender: String => Any): LogAppender = new LogAppender { self => - def appendCause(cause: Cause[Any]): Unit = appendText(cause.prettyPrint) + override def appendCause(cause: Cause[Any]): Unit = appendText(cause.prettyPrint) + + override def appendKeyValueSeparator(): Unit = appendText(" ") - def appendNumeric[A](numeric: A): Unit = appendText(numeric.toString) + override def appendNumeric[A](numeric: A): Unit = appendText(numeric.toString) - def appendText(text: String): Unit = { textAppender(text); () } + override def appendText(text: String): Unit = { textAppender(text); () } - def closeKeyOpenValue(): Unit = appendText("=") + override def closeKeyOpenValue(): Unit = appendText("=") - def closeLogEntry(): Unit = () + override def closeLogEntry(): Unit = () - def closeValue(): Unit = () + override def closeValue(): Unit = () - def openKey(): Unit = () + override def openKey(): Unit = () - def openLogEntry(): Unit = () + override def openLogEntry(): Unit = () } def json(textAppender: String => Any): LogAppender = new LogAppender { self => diff --git a/slf4j2-bridge/src/main/scala/zio/logging/slf4j/bridge/ZioLoggerRuntime.scala b/slf4j2-bridge/src/main/scala/zio/logging/slf4j/bridge/ZioLoggerRuntime.scala index 1e6af77b..188a5153 100644 --- a/slf4j2-bridge/src/main/scala/zio/logging/slf4j/bridge/ZioLoggerRuntime.scala +++ b/slf4j2-bridge/src/main/scala/zio/logging/slf4j/bridge/ZioLoggerRuntime.scala @@ -18,7 +18,7 @@ package zio.logging.slf4j.bridge import org.slf4j.Marker import org.slf4j.event.Level import org.slf4j.helpers.MessageFormatter -import zio.{ Cause, Fiber, FiberId, FiberRef, FiberRefs, LogLevel, Runtime, Trace, Unsafe, ZLogger } +import zio.{ Cause, Fiber, FiberId, FiberRef, FiberRefs, LogLevel, Runtime, Trace, Unsafe } final class ZioLoggerRuntime(runtime: Runtime[Any]) extends LoggerRuntime {