Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Slf4j bridge - fiber propagation #718

Merged
merged 8 commits into from
May 16, 2023
Merged

Slf4j bridge - fiber propagation #718

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
277bc23
slf4j bridge fiber refs propagation - wip
justcoon May 11, 2023
f2f90db
slf4j bridge fiber refs propagation - wip
justcoon May 11, 2023
ef4f1f3
slf4j bridge fiber refs propagation
justcoon May 12, 2023
5d96317
slf4j bridge fiber refs propagation
justcoon May 15, 2023
c8b54db
docs
justcoon May 15, 2023
0ef0d07
docs, example
justcoon May 15, 2023
3a3e0d6
slf4j bridge fiber refs propagation
justcoon May 16, 2023
34acb03
slf4j bridge fiber refs propagation
justcoon May 16, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
39 changes: 22 additions & 17 deletions docs/slf4j1-bridge.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,6 @@ import zio.logging.consoleJsonLogger

val logger = Runtime.removeDefaultLoggers >>> consoleJsonLogger() >+> Slf4jBridge.initialize
```

<br/>

**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
Expand All @@ -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")
Expand All @@ -79,27 +73,38 @@ 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

}
```

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
Expand Down
39 changes: 22 additions & 17 deletions docs/slf4j2-bridge.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -39,7 +39,6 @@ val logFilter: LogFilter[String] = LogFilter.logLevelByName(
"SLF4J-LOGGER" -> LogLevel.Warning
)
```

<br/>

SLF4J bridge with custom logger can be setup:
Expand Down Expand Up @@ -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")
Expand All @@ -91,25 +85,36 @@ 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

}
```

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"}
```
4 changes: 2 additions & 2 deletions examples/core/src/main/scala/zio/logging/example/SimpleApp.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down
24 changes: 18 additions & 6 deletions examples/slf4j2-bridge/src/main/scala/zio/logging/example/Slf4jBridgeExampleApp.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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")
Expand All @@ -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

}
2 changes: 1 addition & 1 deletion project/MimaSettings.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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(
Expand Down
10 changes: 8 additions & 2 deletions slf4j-bridge/src/main/scala/org/slf4j/impl/ZioLoggerFactory.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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._
Expand All @@ -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())
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You are within the ZIO name space so you could just use _currentFiber here to avoid the need for the cast. I will also look at specializing the return type of currentFiber.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i changed it slf4j v2 bridge to use _currentFiber, as it is in zio namespace

fiberRefs match {
case Some(fiberRefs) => ZIO.setFiberRefs(fiberRefs) *> f
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This pattern of running a ZIO workflow just to log something is not very efficient. We can get the current loggers from the current FiberRefs and then we can just use those loggers to log directly without going through a ZIO workflow.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yes, i think you are right, we can probably do it better,
probably by using Fiber.log
but i propose to do it in next PR

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

case None => f
}
}
()
}
}
Expand Down
12 changes: 10 additions & 2 deletions slf4j-bridge/src/main/scala/zio/logging/slf4j/bridge/Slf4jBridge.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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 {

Expand All @@ -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
Expand All @@ -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 {
Expand Down
44 changes: 44 additions & 0 deletions slf4j-bridge/src/test/scala/zio/logging/slf4j/bridge/Slf4jBridgeExampleApp.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -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

}
Loading