diff --git a/docs/slf4j1-bridge.md b/docs/slf4j1-bridge.md index f7868bc7..90fc80e5 100644 --- a/docs/slf4j1-bridge.md +++ b/docs/slf4j1-bridge.md @@ -40,7 +40,6 @@ import zio.logging.consoleJsonLogger val logger = Runtime.removeDefaultLoggers >>> consoleJsonLogger() >+> Slf4jBridge.initialize ``` -
**NOTE** You should either use `zio-logging-slf4j` to send all ZIO logs to an SLF4j provider (such as logback, log4j etc) OR `zio-logging-slf4j-bridge` to send all SLF4j logs to @@ -56,16 +55,11 @@ ZIO logging. Enabling both causes circular logging and makes no sense. ```scala package zio.logging.slf4j.bridge -import zio.logging.slf4j.bridge.Slf4jBridge -import zio.logging.{ - ConsoleLoggerConfig, - LogFilter, - LogFormat, - LoggerNameExtractor, - consoleJsonLogger -} +import zio.logging._ import zio.{ ExitCode, LogLevel, Runtime, Scope, ZIO, ZIOAppArgs, ZIOAppDefault, ZLayer } +import java.util.UUID + object Slf4jBridgeExampleApp extends ZIOAppDefault { private val slf4jLogger = org.slf4j.LoggerFactory.getLogger("SLF4J-LOGGER") @@ -79,17 +73,27 @@ object Slf4jBridgeExampleApp extends ZIOAppDefault { override val bootstrap: ZLayer[ZIOAppArgs, Any, Any] = Runtime.removeDefaultLoggers >>> consoleJsonLogger( ConsoleLoggerConfig( - LogFormat.label("name", LoggerNameExtractor.loggerNameAnnotationOrTrace.toLogFormat()) + LogFormat.default, + LogFormat.label( + "name", + LoggerNameExtractor.loggerNameAnnotationOrTrace.toLogFormat() + ) + LogFormat.logAnnotation(LogAnnotation.UserId) + LogFormat.logAnnotation( + LogAnnotation.TraceId + ) + LogFormat.default, logFilter ) ) >+> Slf4jBridge.initialize + private val uuids = List.fill(2)(UUID.randomUUID()) + override def run: ZIO[Scope, Any, ExitCode] = for { - _ <- ZIO.logDebug("Start") - _ <- ZIO.succeed(slf4jLogger.debug("Test {}!", "DEBUG")) - _ <- ZIO.succeed(slf4jLogger.warn("Test {}!", "WARNING")) - _ <- ZIO.logInfo("Done") + _ <- ZIO.logInfo("Start") + _ <- ZIO.foreachPar(uuids) { u => + ZIO.succeed(slf4jLogger.warn("Test {}!", "WARNING")) @@ LogAnnotation.UserId( + u.toString + ) + } @@ LogAnnotation.TraceId(UUID.randomUUID()) + _ <- ZIO.logDebug("Done") } yield ExitCode.success } @@ -97,9 +101,10 @@ object Slf4jBridgeExampleApp extends ZIOAppDefault { Expected Console Output: ``` -{"name":"zio.logging.slf4j.bridge.Slf4jBridgeExampleApp","timestamp":"2023-01-07T18:25:40.397593+01:00","level":"DEBUG","thread":"zio-fiber-4","message":"Start"} -{"name":"SLF4J-LOGGER","timestamp":"2023-01-07T18:25:40.416612+01:00","level":"WARN","thread":"zio-fiber-6","message":"Test WARNING!"} -{"name":"zio.logging.slf4j.bridge.Slf4jBridgeExampleApp","timestamp":"2023-01-07T18:25:40.42043+01:00 ","level":"INFO","thread":"zio-fiber-4","message":"Done"} +{"name":"zio.logging.slf4j.bridge.Slf4jBridgeExampleApp","timestamp":"2023-05-15T20:14:20.712983+02:00","level":"INFO","thread":"zio-fiber-6","message":"Start"} +{"name":"SLF4J-LOGGER","user_id":"81e517bb-c69b-4187-a6e9-9911c427994c","trace_id":"bd317853-2b88-43d3-84dc-109e7e0eba70","timestamp":"2023-05-15T20:14:20.76863+02:00 ","level":"WARN","thread":"zio-fiber-9","message":"Test WARNING!"} +{"name":"SLF4J-LOGGER","user_id":"844f97ef-7f09-469b-9f4b-765887beea9a","trace_id":"bd317853-2b88-43d3-84dc-109e7e0eba70","timestamp":"2023-05-15T20:14:20.768628+02:00","level":"WARN","thread":"zio-fiber-10","message":"Test WARNING!"} +{"name":"zio.logging.slf4j.bridge.Slf4jBridgeExampleApp","timestamp":"2023-05-15T20:14:20.777529+02:00","level":"DEBUG","thread":"zio-fiber-6","message":"Done"} ``` ## Feature changes diff --git a/docs/slf4j2-bridge.md b/docs/slf4j2-bridge.md index 46bafa88..5b4f08b9 100644 --- a/docs/slf4j2-bridge.md +++ b/docs/slf4j2-bridge.md @@ -39,7 +39,6 @@ val logFilter: LogFilter[String] = LogFilter.logLevelByName( "SLF4J-LOGGER" -> LogLevel.Warning ) ``` -
SLF4J bridge with custom logger can be setup: @@ -68,16 +67,11 @@ You can find the source code [here](https://github.com/zio/zio-logging/tree/mast ```scala package zio.logging.slf4j.bridge -import zio.logging.slf4j.bridge.Slf4jBridge -import zio.logging.{ - ConsoleLoggerConfig, - LogFilter, - LogFormat, - LoggerNameExtractor, - consoleJsonLogger -} +import zio.logging._ import zio.{ ExitCode, LogLevel, Runtime, Scope, ZIO, ZIOAppArgs, ZIOAppDefault, ZLayer } +import java.util.UUID + object Slf4jBridgeExampleApp extends ZIOAppDefault { private val slf4jLogger = org.slf4j.LoggerFactory.getLogger("SLF4J-LOGGER") @@ -91,17 +85,27 @@ object Slf4jBridgeExampleApp extends ZIOAppDefault { override val bootstrap: ZLayer[ZIOAppArgs, Any, Any] = Runtime.removeDefaultLoggers >>> consoleJsonLogger( ConsoleLoggerConfig( - LogFormat.label("name", LoggerNameExtractor.loggerNameAnnotationOrTrace.toLogFormat()) + LogFormat.default, + LogFormat.label( + "name", + LoggerNameExtractor.loggerNameAnnotationOrTrace.toLogFormat() + ) + LogFormat.logAnnotation(LogAnnotation.UserId) + LogFormat.logAnnotation( + LogAnnotation.TraceId + ) + LogFormat.default, logFilter ) ) >+> Slf4jBridge.initialize + private val uuids = List.fill(2)(UUID.randomUUID()) + override def run: ZIO[Scope, Any, ExitCode] = for { - _ <- ZIO.logDebug("Start") - _ <- ZIO.succeed(slf4jLogger.debug("Test {}!", "DEBUG")) - _ <- ZIO.succeed(slf4jLogger.warn("Test {}!", "WARNING")) - _ <- ZIO.logInfo("Done") + _ <- ZIO.logInfo("Start") + _ <- ZIO.foreachPar(uuids) { u => + ZIO.succeed(slf4jLogger.warn("Test {}!", "WARNING")) @@ LogAnnotation.UserId( + u.toString + ) + } @@ LogAnnotation.TraceId(UUID.randomUUID()) + _ <- ZIO.logDebug("Done") } yield ExitCode.success } @@ -109,7 +113,8 @@ object Slf4jBridgeExampleApp extends ZIOAppDefault { Expected Console Output: ``` -{"name":"zio.logging.slf4j.bridge.Slf4jBridgeExampleApp","timestamp":"2023-01-07T18:25:40.397593+01:00","level":"DEBUG","thread":"zio-fiber-4","message":"Start"} -{"name":"SLF4J-LOGGER","timestamp":"2023-01-07T18:25:40.416612+01:00","level":"WARN","thread":"zio-fiber-6","message":"Test WARNING!"} -{"name":"zio.logging.slf4j.bridge.Slf4jBridgeExampleApp","timestamp":"2023-01-07T18:25:40.42043+01:00 ","level":"INFO","thread":"zio-fiber-4","message":"Done"} +{"name":"zio.logging.slf4j.bridge.Slf4jBridgeExampleApp","timestamp":"2023-05-15T20:14:20.712983+02:00","level":"INFO","thread":"zio-fiber-6","message":"Start"} +{"name":"SLF4J-LOGGER","user_id":"81e517bb-c69b-4187-a6e9-9911c427994c","trace_id":"bd317853-2b88-43d3-84dc-109e7e0eba70","timestamp":"2023-05-15T20:14:20.76863+02:00 ","level":"WARN","thread":"zio-fiber-9","message":"Test WARNING!"} +{"name":"SLF4J-LOGGER","user_id":"844f97ef-7f09-469b-9f4b-765887beea9a","trace_id":"bd317853-2b88-43d3-84dc-109e7e0eba70","timestamp":"2023-05-15T20:14:20.768628+02:00","level":"WARN","thread":"zio-fiber-10","message":"Test WARNING!"} +{"name":"zio.logging.slf4j.bridge.Slf4jBridgeExampleApp","timestamp":"2023-05-15T20:14:20.777529+02:00","level":"DEBUG","thread":"zio-fiber-6","message":"Done"} ``` diff --git a/examples/core/src/main/scala/zio/logging/example/SimpleApp.scala b/examples/core/src/main/scala/zio/logging/example/SimpleApp.scala index 4200efeb..d5b555a7 100644 --- a/examples/core/src/main/scala/zio/logging/example/SimpleApp.scala +++ b/examples/core/src/main/scala/zio/logging/example/SimpleApp.scala @@ -15,13 +15,13 @@ */ package zio.logging.example -import zio.logging.consoleLogger +import zio.logging.{ ConsoleLoggerConfig, consoleLogger } import zio.{ ExitCode, Runtime, Scope, ZIO, ZIOAppArgs, ZIOAppDefault, ZLayer } object SimpleApp extends ZIOAppDefault { override val bootstrap: ZLayer[ZIOAppArgs, Any, Any] = - Runtime.removeDefaultLoggers >>> consoleLogger() + Runtime.removeDefaultLoggers >>> consoleLogger(ConsoleLoggerConfig.default) override def run: ZIO[Scope, Any, ExitCode] = for { diff --git a/examples/slf4j2-bridge/src/main/scala/zio/logging/example/Slf4jBridgeExampleApp.scala b/examples/slf4j2-bridge/src/main/scala/zio/logging/example/Slf4jBridgeExampleApp.scala index b5d9716b..d5bebd11 100644 --- a/examples/slf4j2-bridge/src/main/scala/zio/logging/example/Slf4jBridgeExampleApp.scala +++ b/examples/slf4j2-bridge/src/main/scala/zio/logging/example/Slf4jBridgeExampleApp.scala @@ -16,9 +16,11 @@ package zio.logging.example import zio.logging.slf4j.bridge.Slf4jBridge -import zio.logging.{ ConsoleLoggerConfig, LogFilter, LogFormat, LoggerNameExtractor, consoleJsonLogger } +import zio.logging.{ ConsoleLoggerConfig, LogAnnotation, LogFilter, LogFormat, LoggerNameExtractor, consoleJsonLogger } import zio.{ ExitCode, LogLevel, Runtime, Scope, ZIO, ZIOAppArgs, ZIOAppDefault, ZLayer } +import java.util.UUID + object Slf4jBridgeExampleApp extends ZIOAppDefault { private val slf4jLogger = org.slf4j.LoggerFactory.getLogger("SLF4J-LOGGER") @@ -32,17 +34,27 @@ object Slf4jBridgeExampleApp extends ZIOAppDefault { override val bootstrap: ZLayer[ZIOAppArgs, Any, Any] = Runtime.removeDefaultLoggers >>> consoleJsonLogger( ConsoleLoggerConfig( - LogFormat.label("name", LoggerNameExtractor.loggerNameAnnotationOrTrace.toLogFormat()) + LogFormat.default, + LogFormat.label( + "name", + LoggerNameExtractor.loggerNameAnnotationOrTrace.toLogFormat() + ) + LogFormat.logAnnotation(LogAnnotation.UserId) + LogFormat.logAnnotation( + LogAnnotation.TraceId + ) + LogFormat.default, logFilter ) ) >+> Slf4jBridge.initialize + private val uuids = List.fill(2)(UUID.randomUUID()) + override def run: ZIO[Scope, Any, ExitCode] = for { - _ <- ZIO.logDebug("Start") - _ <- ZIO.succeed(slf4jLogger.debug("Test {}!", "DEBUG")) - _ <- ZIO.succeed(slf4jLogger.warn("Test {}!", "WARNING")) - _ <- ZIO.logInfo("Done") + _ <- ZIO.logInfo("Start") + _ <- ZIO.foreachPar(uuids) { u => + ZIO.succeed(slf4jLogger.warn("Test {}!", "WARNING")) @@ LogAnnotation.UserId( + u.toString + ) + } @@ LogAnnotation.TraceId(UUID.randomUUID()) + _ <- ZIO.logDebug("Done") } yield ExitCode.success } diff --git a/project/MimaSettings.scala b/project/MimaSettings.scala index 1e0122c7..677286ca 100644 --- a/project/MimaSettings.scala +++ b/project/MimaSettings.scala @@ -5,7 +5,7 @@ import sbt.Keys.{ name, organization } import sbt._ object MimaSettings { - lazy val bincompatVersionToCompare = "2.1.11" + lazy val bincompatVersionToCompare = "2.1.12" def mimaSettings(failOnProblem: Boolean) = Seq( diff --git a/slf4j-bridge/src/main/scala/org/slf4j/impl/ZioLoggerFactory.scala b/slf4j-bridge/src/main/scala/org/slf4j/impl/ZioLoggerFactory.scala index 4b9f916e..6c5a22ce 100644 --- a/slf4j-bridge/src/main/scala/org/slf4j/impl/ZioLoggerFactory.scala +++ b/slf4j-bridge/src/main/scala/org/slf4j/impl/ZioLoggerFactory.scala @@ -17,8 +17,8 @@ package org.slf4j.impl import com.github.ghik.silencer.silent import org.slf4j.{ ILoggerFactory, Logger } -import zio.ZIO import zio.logging.slf4j.bridge.Slf4jBridge +import zio.{ Fiber, ZIO } import java.util.concurrent.ConcurrentHashMap import scala.jdk.CollectionConverters._ @@ -43,7 +43,13 @@ class ZioLoggerFactory extends ILoggerFactory { private[impl] def run(f: ZIO[Any, Nothing, Any]): Unit = if (runtime != null) { zio.Unsafe.unsafe { implicit u => - runtime.unsafe.run(f) + runtime.unsafe.run { + val fiberRefs = Fiber.currentFiber().map(_.asInstanceOf[Fiber.Runtime[_, _]].unsafe.getFiberRefs()) + fiberRefs match { + case Some(fiberRefs) => ZIO.setFiberRefs(fiberRefs) *> f + case None => f + } + } () } } diff --git a/slf4j-bridge/src/main/scala/zio/logging/slf4j/bridge/Slf4jBridge.scala b/slf4j-bridge/src/main/scala/zio/logging/slf4j/bridge/Slf4jBridge.scala index f5dd113a..a6e27238 100644 --- a/slf4j-bridge/src/main/scala/zio/logging/slf4j/bridge/Slf4jBridge.scala +++ b/slf4j-bridge/src/main/scala/zio/logging/slf4j/bridge/Slf4jBridge.scala @@ -16,7 +16,7 @@ package zio.logging.slf4j.bridge import org.slf4j.impl.ZioLoggerFactory -import zio.{ ZIO, ZLayer } +import zio.{ Runtime, ZIO, ZLayer } object Slf4jBridge { @@ -30,7 +30,12 @@ object Slf4jBridge { * initialize SLF4J bridge */ def initialize: ZLayer[Any, Nothing, Unit] = - initialize(zio.logging.loggerNameAnnotationKey) + Runtime.enableCurrentFiber ++ layer(zio.logging.loggerNameAnnotationKey) + + /** + * initialize SLF4J bridge without `FiberRef` propagation + */ + def initializeWithoutFiberRefPropagation: ZLayer[Any, Nothing, Unit] = layer(zio.logging.loggerNameAnnotationKey) /** * initialize SLF4J bridge, where custom annotation key for logger name may be provided @@ -39,6 +44,9 @@ object Slf4jBridge { * NOTE: this feature may be removed in future releases */ def initialize(nameAnnotationKey: String): ZLayer[Any, Nothing, Unit] = + Runtime.enableCurrentFiber ++ layer(nameAnnotationKey) + + private def layer(nameAnnotationKey: String): ZLayer[Any, Nothing, Unit] = ZLayer { ZIO.runtime[Any].flatMap { runtime => ZIO.succeed { diff --git a/slf4j-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeExampleApp.scala b/slf4j-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeExampleApp.scala new file mode 100644 index 00000000..dd503c7b --- /dev/null +++ b/slf4j-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeExampleApp.scala @@ -0,0 +1,44 @@ +package zio.logging.slf4j.bridge + +import zio.logging._ +import zio.{ ExitCode, LogLevel, Runtime, Scope, ZIO, ZIOAppArgs, ZIOAppDefault, ZLayer } + +import java.util.UUID + +object Slf4jBridgeExampleApp extends ZIOAppDefault { + + private val slf4jLogger = org.slf4j.LoggerFactory.getLogger("SLF4J-LOGGER") + + private val logFilter: LogFilter[String] = LogFilter.logLevelByName( + LogLevel.Info, + "zio.logging.slf4j" -> LogLevel.Debug, + "SLF4J-LOGGER" -> LogLevel.Warning + ) + + override val bootstrap: ZLayer[ZIOAppArgs, Any, Any] = + Runtime.removeDefaultLoggers >>> consoleJsonLogger( + ConsoleLoggerConfig( + LogFormat.label( + "name", + LoggerNameExtractor.loggerNameAnnotationOrTrace.toLogFormat() + ) + LogFormat.logAnnotation(LogAnnotation.UserId) + LogFormat.logAnnotation( + LogAnnotation.TraceId + ) + LogFormat.default, + logFilter + ) + ) >+> Slf4jBridge.initialize + + private val uuids = List.fill(2)(UUID.randomUUID()) + + override def run: ZIO[Scope, Any, ExitCode] = + for { + _ <- ZIO.logInfo("Start") + _ <- ZIO.foreachPar(uuids) { u => + ZIO.succeed(slf4jLogger.warn("Test {}!", "WARNING")) @@ LogAnnotation.UserId( + u.toString + ) + } @@ LogAnnotation.TraceId(UUID.randomUUID()) + _ <- ZIO.logDebug("Done") + } yield ExitCode.success + +} diff --git a/slf4j-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeSpec.scala b/slf4j-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeSpec.scala index f5f33272..563e784c 100644 --- a/slf4j-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeSpec.scala +++ b/slf4j-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeSpec.scala @@ -3,7 +3,7 @@ package zio.logging.slf4j.bridge import org.slf4j.MarkerFactory import org.slf4j.impl.StaticMarkerBinder import zio.test._ -import zio.{ Cause, Chunk, LogLevel, ZIO } +import zio.{ Cause, Chunk, LogLevel, Runtime, ZIO, ZIOAspect } object Slf4jBridgeSpec extends ZIOSpecDefault { @@ -17,18 +17,19 @@ object Slf4jBridgeSpec extends ZIOSpecDefault { override def spec = suite("Slf4jBridge")( - test("logs through slf4j - leggacy logger name annotation key") { + test("logs through slf4j - legacy logger name annotation key") { val testFailure = new RuntimeException("test error") for { - _ <- (for { - logger <- ZIO.attempt(org.slf4j.LoggerFactory.getLogger("test.logger")) - _ <- ZIO.attempt(logger.debug("test debug message")) - _ <- ZIO.attempt(logger.warn("hello {}", "world")) - _ <- ZIO.attempt(logger.warn("{}..{}..{} ... go!", "3", "2", "1")) - _ <- ZIO.attempt(logger.warn("warn cause", testFailure)) - _ <- ZIO.attempt(logger.error("error", testFailure)) - _ <- ZIO.attempt(logger.error("error", null)) - } yield ()).exit + _ <- + (for { + logger <- ZIO.attempt(org.slf4j.LoggerFactory.getLogger("test.logger")) + _ <- ZIO.attempt(logger.debug("test debug message")) @@ ZIOAspect.annotated("trace_id", "tId") + _ <- ZIO.attempt(logger.warn("hello {}", "world")) @@ ZIOAspect.annotated("user_id", "uId") + _ <- ZIO.attempt(logger.warn("{}..{}..{} ... go!", "3", "2", "1")) + _ <- ZIO.attempt(logger.warn("warn cause", testFailure)) + _ <- ZIO.attempt(logger.error("error", testFailure)) + _ <- ZIO.attempt(logger.error("error", null)) + } yield ()).exit output <- ZTestLogger.logOutput lines = output.map { logEntry => LogEntry( @@ -44,14 +45,14 @@ object Slf4jBridgeSpec extends ZIOSpecDefault { LogEntry( List("test.logger"), LogLevel.Debug, - Map(Slf4jBridge.loggerNameAnnotationKey -> "test.logger"), + Map(Slf4jBridge.loggerNameAnnotationKey -> "test.logger", "trace_id" -> "tId"), "test debug message", Cause.empty ), LogEntry( List("test.logger"), LogLevel.Warning, - Map(Slf4jBridge.loggerNameAnnotationKey -> "test.logger"), + Map(Slf4jBridge.loggerNameAnnotationKey -> "test.logger", "user_id" -> "uId"), "hello world", Cause.empty ), @@ -101,8 +102,8 @@ object Slf4jBridgeSpec extends ZIOSpecDefault { for { _ <- (for { logger <- ZIO.attempt(org.slf4j.LoggerFactory.getLogger("test.logger")) - _ <- ZIO.attempt(logger.debug("test debug message")) - _ <- ZIO.attempt(logger.warn("hello {}", "world")) + _ <- ZIO.attempt(logger.debug("test debug message")) @@ ZIOAspect.annotated("trace_id", "tId") + _ <- ZIO.attempt(logger.warn("hello {}", "world")) @@ ZIOAspect.annotated("user_id", "uId") _ <- ZIO.attempt(logger.warn("{}..{}..{} ... go!", "3", "2", "1")) _ <- ZIO.attempt(logger.warn("warn cause", testFailure)) _ <- ZIO.attempt(logger.error("error", testFailure)) @@ -123,14 +124,14 @@ object Slf4jBridgeSpec extends ZIOSpecDefault { LogEntry( List("test.logger"), LogLevel.Debug, - Map(zio.logging.loggerNameAnnotationKey -> "test.logger"), + Map(zio.logging.loggerNameAnnotationKey -> "test.logger", "trace_id" -> "tId"), "test debug message", Cause.empty ), LogEntry( List("test.logger"), LogLevel.Warning, - Map(zio.logging.loggerNameAnnotationKey -> "test.logger"), + Map(zio.logging.loggerNameAnnotationKey -> "test.logger", "user_id" -> "uId"), "hello world", Cause.empty ), @@ -164,6 +165,42 @@ object Slf4jBridgeSpec extends ZIOSpecDefault { ) ) ) - }.provide(Slf4jBridge.initialize) + }.provide(Slf4jBridge.initialize), + test("logs through slf4j without fiber ref propagation") { + for { + _ <- (for { + logger <- ZIO.attempt(org.slf4j.LoggerFactory.getLogger("test.logger")) + _ <- ZIO.attempt(logger.debug("test debug message")) @@ ZIOAspect.annotated("trace_id", "tId") + _ <- ZIO.attempt(logger.warn("hello {}", "world")) @@ ZIOAspect.annotated("user_id", "uId") + } yield ()).exit + output <- ZTestLogger.logOutput + lines = output.map { logEntry => + LogEntry( + logEntry.spans.map(_.label), + logEntry.logLevel, + logEntry.annotations, + logEntry.message(), + logEntry.cause + ) + } + } yield assertTrue( + lines == Chunk( + LogEntry( + List("test.logger"), + LogLevel.Debug, + Map(zio.logging.loggerNameAnnotationKey -> "test.logger"), + "test debug message", + Cause.empty + ), + LogEntry( + List("test.logger"), + LogLevel.Warning, + Map(zio.logging.loggerNameAnnotationKey -> "test.logger"), + "hello world", + Cause.empty + ) + ) + ) + }.provide(Slf4jBridge.initializeWithoutFiberRefPropagation) ) @@ TestAspect.sequential } diff --git a/slf4j2-bridge/src/main/scala/zio/logging/slf4j/bridge/Slf4jBridge.scala b/slf4j2-bridge/src/main/scala/zio/logging/slf4j/bridge/Slf4jBridge.scala index 071489f3..51e45542 100644 --- a/slf4j2-bridge/src/main/scala/zio/logging/slf4j/bridge/Slf4jBridge.scala +++ b/slf4j2-bridge/src/main/scala/zio/logging/slf4j/bridge/Slf4jBridge.scala @@ -15,14 +15,21 @@ */ package zio.logging.slf4j.bridge -import zio.{ ZIO, ZLayer } +import zio.{ Runtime, ZIO, ZLayer } object Slf4jBridge { /** * initialize SLF4J bridge */ - def initialize: ZLayer[Any, Nothing, Unit] = + def initialize: ZLayer[Any, Nothing, Unit] = Runtime.enableCurrentFiber ++ layer + + /** + * initialize SLF4J bridge without `FiberRef` propagation + */ + def initializeWithoutFiberRefPropagation: ZLayer[Any, Nothing, Unit] = layer + + private def layer: ZLayer[Any, Nothing, Unit] = ZLayer { ZIO.runtime[Any].flatMap { runtime => ZIO.succeed { 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 6e4cd0df..db86f98f 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, LogLevel, Runtime, Unsafe, ZIO } +import zio.{ Cause, Fiber, LogLevel, Runtime, Unsafe, ZIO } final class ZioLoggerRuntime(runtime: Runtime[Any]) extends LoggerRuntime { @@ -33,7 +33,8 @@ final class ZioLoggerRuntime(runtime: Runtime[Any]) extends LoggerRuntime { Unsafe.unsafe { implicit u => runtime.unsafe.run { val logLevel = ZioLoggerRuntime.logLevelMapping(level) - ZIO.logSpan(name) { + + val log = ZIO.logSpan(name) { ZIO.logAnnotate(zio.logging.loggerNameAnnotationKey, name) { ZIO.logLevel(logLevel) { lazy val msg = if (arguments != null) { @@ -51,6 +52,14 @@ final class ZioLoggerRuntime(runtime: Runtime[Any]) extends LoggerRuntime { } } } + + val fiber = Fiber._currentFiber.get() + if (fiber eq null) { + log + } else { + val fiberRefs = fiber.unsafe.getFiberRefs() + ZIO.setFiberRefs(fiberRefs) *> log + } } () } diff --git a/slf4j2-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeExampleApp.scala b/slf4j2-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeExampleApp.scala index 4f830538..3b46b7ff 100644 --- a/slf4j2-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeExampleApp.scala +++ b/slf4j2-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeExampleApp.scala @@ -1,8 +1,10 @@ package zio.logging.slf4j.bridge -import zio.logging.{ ConsoleLoggerConfig, LogFilter, LogFormat, LoggerNameExtractor, consoleJsonLogger } +import zio.logging.{ ConsoleLoggerConfig, LogAnnotation, LogFilter, LogFormat, LoggerNameExtractor, consoleJsonLogger } import zio.{ ExitCode, LogLevel, Runtime, Scope, ZIO, ZIOAppArgs, ZIOAppDefault, ZLayer } +import java.util.UUID + object Slf4jBridgeExampleApp extends ZIOAppDefault { private val slf4jLogger = org.slf4j.LoggerFactory.getLogger("SLF4J-LOGGER") @@ -16,15 +18,26 @@ object Slf4jBridgeExampleApp extends ZIOAppDefault { override val bootstrap: ZLayer[ZIOAppArgs, Any, Any] = Runtime.removeDefaultLoggers >>> consoleJsonLogger( ConsoleLoggerConfig( - LogFormat.label("name", LoggerNameExtractor.loggerNameAnnotationOrTrace.toLogFormat()) + LogFormat.default, + LogFormat.label( + "name", + LoggerNameExtractor.loggerNameAnnotationOrTrace.toLogFormat() + ) + LogFormat.logAnnotation(LogAnnotation.UserId) + LogFormat.logAnnotation( + LogAnnotation.TraceId + ) + LogFormat.default, logFilter ) ) >+> Slf4jBridge.initialize + private val uuids = List.fill(2)(UUID.randomUUID()) + override def run: ZIO[Scope, Any, ExitCode] = for { _ <- ZIO.logInfo("Start") - _ <- ZIO.succeed(slf4jLogger.warn("Test {}!", "WARNING")) + _ <- ZIO.foreachPar(uuids) { u => + ZIO.succeed(slf4jLogger.warn("Test {}!", "WARNING")) @@ LogAnnotation.UserId( + u.toString + ) + } @@ LogAnnotation.TraceId(UUID.randomUUID()) _ <- ZIO.logDebug("Done") } yield ExitCode.success diff --git a/slf4j2-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeSpec.scala b/slf4j2-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeSpec.scala index 87659e15..d31224b6 100644 --- a/slf4j2-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeSpec.scala +++ b/slf4j2-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeSpec.scala @@ -1,7 +1,7 @@ package zio.logging.slf4j.bridge import zio.test._ -import zio.{ Cause, Chunk, LogLevel, ZIO } +import zio.{ Cause, Chunk, LogLevel, ZIO, ZIOAspect } object Slf4jBridgeSpec extends ZIOSpecDefault { @@ -18,15 +18,16 @@ object Slf4jBridgeSpec extends ZIOSpecDefault { test("logs through slf4j") { val testFailure = new RuntimeException("test error") for { - _ <- (for { - logger <- ZIO.attempt(org.slf4j.LoggerFactory.getLogger("test.logger")) - _ <- ZIO.attempt(logger.debug("test debug message")) - _ <- ZIO.attempt(logger.warn("hello {}", "world")) - _ <- ZIO.attempt(logger.warn("{}..{}..{} ... go!", "3", "2", "1")) - _ <- ZIO.attempt(logger.warn("warn cause", testFailure)) - _ <- ZIO.attempt(logger.error("error", testFailure)) - _ <- ZIO.attempt(logger.error("error", null)) - } yield ()).exit + _ <- + (for { + logger <- ZIO.attempt(org.slf4j.LoggerFactory.getLogger("test.logger")) + _ <- ZIO.attempt(logger.debug("test debug message")) @@ ZIOAspect.annotated("trace_id", "tId") + _ <- ZIO.attempt(logger.warn("hello {}", "world")) @@ ZIOAspect.annotated("user_id", "uId") + _ <- ZIO.attempt(logger.warn("{}..{}..{} ... go!", "3", "2", "1")) + _ <- ZIO.attempt(logger.warn("warn cause", testFailure)) + _ <- ZIO.attempt(logger.error("error", testFailure)) + _ <- ZIO.attempt(logger.error("error", null)) + } yield ()).exit output <- ZTestLogger.logOutput lines = output.map { logEntry => LogEntry( @@ -42,14 +43,14 @@ object Slf4jBridgeSpec extends ZIOSpecDefault { LogEntry( List("test.logger"), LogLevel.Debug, - Map(zio.logging.loggerNameAnnotationKey -> "test.logger"), + Map(zio.logging.loggerNameAnnotationKey -> "test.logger", "trace_id" -> "tId"), "test debug message", Cause.empty ), LogEntry( List("test.logger"), LogLevel.Warning, - Map(zio.logging.loggerNameAnnotationKey -> "test.logger"), + Map(zio.logging.loggerNameAnnotationKey -> "test.logger", "user_id" -> "uId"), "hello world", Cause.empty ), @@ -83,11 +84,47 @@ object Slf4jBridgeSpec extends ZIOSpecDefault { ) ) ) - }, + }.provide(Slf4jBridge.initialize), test("Implements Logger#getName") { for { logger <- ZIO.attempt(org.slf4j.LoggerFactory.getLogger("zio.test.logger")) } yield assertTrue(logger.getName == "zio.test.logger") - } - ).provide(Slf4jBridge.initialize) @@ TestAspect.sequential + }.provide(Slf4jBridge.initialize), + test("logs through slf4j without fiber ref propagation") { + for { + _ <- (for { + logger <- ZIO.attempt(org.slf4j.LoggerFactory.getLogger("test.logger")) + _ <- ZIO.attempt(logger.debug("test debug message")) @@ ZIOAspect.annotated("trace_id", "tId") + _ <- ZIO.attempt(logger.warn("hello {}", "world")) @@ ZIOAspect.annotated("user_id", "uId") + } yield ()).exit + output <- ZTestLogger.logOutput + lines = output.map { logEntry => + LogEntry( + logEntry.spans.map(_.label), + logEntry.logLevel, + logEntry.annotations, + logEntry.message(), + logEntry.cause + ) + } + } yield assertTrue( + lines == Chunk( + LogEntry( + List("test.logger"), + LogLevel.Debug, + Map(zio.logging.loggerNameAnnotationKey -> "test.logger"), + "test debug message", + Cause.empty + ), + LogEntry( + List("test.logger"), + LogLevel.Warning, + Map(zio.logging.loggerNameAnnotationKey -> "test.logger"), + "hello world", + Cause.empty + ) + ) + ) + }.provide(Slf4jBridge.initializeWithoutFiberRefPropagation) + ) @@ TestAspect.sequential }