LogStage
LogStage is a zero-cost structural logging framework for Scala & Scala.js
Key features:
- LogStage extracts structure from ordinary string interpolations in your log messages with zero changes to code.
- LogStage uses macros to extract log structure, its faster at runtime than a typical reflective structural logging frameworks,
- Log contexts
- Console, File and SLF4J sinks included, File sink supports log rotation,
- Human-readable output and JSON output included,
- Method-level logging granularity. Can configure methods
com.example.Service.start
andcom.example.Service.doSomething
independently, - Slf4J adapters: route legacy Slf4J logs into LogStage router
Dependencies
libraryDependencies ++= Seq(
// LogStage core library
"io.7mind.izumi" %% "logstage-core" % "1.2.5",
// Json output
"io.7mind.izumi" %% "logstage-rendering-circe" % "1.2.5",
// Router from Slf4j to LogStage
"io.7mind.izumi" %% "logstage-adapter-slf4j" % "1.2.5",
// LogStage integration with DIStage
"io.7mind.izumi" %% "distage-extension-logstage" % "1.2.5",
// Router from LogStage to Slf4J
"io.7mind.izumi" %% "logstage-sink-slf4j " % "1.2.5",
)
Overview
The following snippet:
import logstage.IzLogger
import scala.util.Random
val logger = IzLogger()
// logger: IzLogger = izumi.logstage.api.IzLogger@5ad05499
val justAnArg = "example"
// justAnArg: String = example
val justAList = List[Any](10, "green", "bottles")
// justAList: List[Any] = List(10, green, bottles)
logger.trace(s"Argument: $justAnArg, another arg: $justAList")
// custom name, not based on `val` name
logger.info(s"Named expression: ${Random.nextInt() -> "random number"}")
// print result without a name
logger.warn(s"Invisible argument: ${Random.nextInt() -> "random number" -> null}")
// add following fields to all messages printed by a new logger value
val ctxLogger = logger("userId" -> "user@google.com", "company" -> "acme")
// ctxLogger: IzLogger = izumi.logstage.api.IzLogger@4aea51ae
val delta = Random.nextInt(1000)
// delta: Int = 988
ctxLogger.info(s"Processing time: $delta")
Will look like this in string form:
And like this in JSON:
Note:
- JSON formatter is type aware!
- Each JSON message contains
@class
field with holds a uniqueevent class
identifier. All events produced by the same source code line will share the sameevent class
.
Syntax Reference
1) Simple variable:
logger.info(s"My message: $argument")
2) Chain:
logger.info(s"My message: ${call.method} ${access.value}")
3) Named expression:
logger.info(s"My message: ${Some.expression -> "argname"}")
4) Invisible named expression:
logger.info(s"My message: ${Some.expression -> "argname" -> null}")
5) De-camelcased name:
logger.info(${camelCaseName -> ' '})
Basic setup
import logstage.{ConsoleSink, IzLogger, Trace}
import logstage.circe.LogstageCirceRenderingPolicy
val textSink = ConsoleSink.text(colored = true)
// textSink: ConsoleSink = izumi.logstage.sink.ConsoleSink$ColoredConsoleSink$@1ae693ce
val jsonSink = ConsoleSink(LogstageCirceRenderingPolicy(prettyPrint = true))
// jsonSink: ConsoleSink = izumi.logstage.sink.ConsoleSink@3bc79f13
val sinks = List(jsonSink, textSink)
// sinks: List[ConsoleSink] = List(izumi.logstage.sink.ConsoleSink@3bc79f13, izumi.logstage.sink.ConsoleSink$ColoredConsoleSink$@1ae693ce)
val logger: IzLogger = IzLogger(Trace, sinks)
// logger: IzLogger = izumi.logstage.api.IzLogger@636b706e
val contextLogger: IzLogger = logger("key" -> "value")
// contextLogger: IzLogger = izumi.logstage.api.IzLogger@7b942a8c
logger.info("Hey")
contextLogger.info("Hey")
Log algebras
LogIO
, LogIO2
& LogIO3
algebras provide a purely-functional API for one-, two-, and three-parameter effect types respectively:
import logstage.{IzLogger, LogIO}
import cats.effect.IO
val logger = IzLogger()
// logger: IzLogger = izumi.logstage.api.IzLogger@55c2bed3
val log = LogIO.fromLogger[IO](logger)
// log: LogIO[IO] = logstage.LogIO$$anon$1@7e02c7c8
log.info(s"Hey! I'm logging with ${log}stage!").unsafeRunSync()(cats.effect.unsafe.IORuntime.global)
I 2019-03-29T23:21:48.693Z[Europe/Dublin] r.S.App7.res8 ...main-12:5384 (00_logstage.md:92) Hey! I'm logging with log=logstage.LogIO$$anon$1@72736f25stage!
LogIO.log
/LogIO2.log
/LogIO3.log
/IzLogger.log
let you refer to an implicit logger’s methods without having to name a logger variable
import logstage.LogIO
import logstage.LogIO.log
def logfun[F[_]: LogIO]: F[Unit] = {
log.info(s"I'm logging with ${log}stage!")
}
Adding Custom Context to Loggers
LogIO*
algebras can be extended with custom context using their .withCustomContext
method, same as IzLogger
:
import cats.effect.IO
import cats.syntax.all._
import logstage.LogIO
import io.circe.Printer
import io.circe.syntax._
def importEntity(entity: Entity)(implicit log: LogIO[IO]): IO[Unit] = {
val logWithContext: LogIO[IO] = {
log.withCustomContext(
"ID" -> entity.id,
"entityAsJSON" -> entity.asJson.printWith(Printer.spaces2),
)
}
load(entity).handleErrorWith {
case error =>
logWithContext.error(s"Failed to import entity: $error.").void
// JSON message includes `ID` and `entityAsJSON` fields
}
}
ZIO environment support
LogZIO.log
lets you carry LogZIO
capability in environment.
Example:
import logstage.{IzLogger, LogIO3, LogZIO}
import logstage.LogZIO.log
import zio.{URIO, ZEnvironment}
val fn: URIO[LogZIO, Unit] = {
log.info(s"I'm logging with ${log}stage!")
}
// fn: URIO[LogZIO, Unit] = OnSuccess(logstage.LogZIO.LogZIOImpl.log(LogZIO.scala:35),Sync(logstage.LogZIO.LogZIOImpl.log(LogZIO.scala:35),zio.ZIO$ServiceWithZIOPartiallyApplied$$$Lambda$24035/0x000000080484f448@52fa8c7f),zio.ZIO$$$Lambda$23905/0x0000000802e86970@67ebec1c)
val logger: LogZIO = LogIO3.fromLogger(IzLogger())
// logger: LogZIO = logstage.LogIO$$anon$1@6aaa6e4e
import izumi.functional.bio.UnsafeRun2
val runtime = UnsafeRun2.createZIO()
// runtime: UnsafeRun2.ZIORunner[Any] = izumi.functional.bio.UnsafeRun2$ZIORunner@30b0f9dd
runtime.unsafeRun {
fn.provideEnvironment(ZEnvironment(logger))
}
Adding FiberId to log messages
LogZIO.withFiberId
provides a LogIO
instance that logs the current ZIO FiberId
in addition to the JVM thread id:
val logger: LogZIO = LogZIO.withFiberId(IzLogger())
// logger: LogZIO = logstage.LogZIO$$anon$1@70c4ed3e
runtime.unsafeRun {
fn.provideEnvironment(ZEnvironment(logger))
}
I 2019-03-29T23:21:48.760Z[Europe/Dublin] r.S.App9.res10 ...main-12:5384 (00_logstage.md:123) {fiberId=0} Hey! I'm logging with log=logstage.LogZIO$$anon$1@c39104astage!
Adding custom logging context to log messages
LogZIO.withCustomContext
allows to append to the custom log context carried in ZIO environment when LogZIO.log
is used for logging:
import zio._
def databaseCall(): ZIO[LogZIO, Throwable, String] = ZIO.succeed("stubbed")
def dbLayerFunction(arg: Int): ZIO[LogZIO, Throwable, String] = {
LogZIO.withCustomContext("arg" -> arg) {
for {
result <- databaseCall()
_ <- log.info(s"Database call $result")
} yield result
}
}
def serviceLayerFunction1(): ZIO[LogZIO, Throwable, String] = {
for {
_ <- log.info("Going to call dbLayerFunction")
result <- dbLayerFunction(1)
} yield result
}
def serviceLayerFunction2(): ZIO[LogZIO, Throwable, String] = {
log.info("Called serviceLayerFunction2").as("stubbed")
}
def controllerFunction(correlationId: String): ZIO[LogZIO, Throwable, String] = {
LogZIO.withCustomContext("correlation_id" -> correlationId) {
for {
x <- serviceLayerFunction1()
y <- serviceLayerFunction2()
result = x + y
_ <- log.info(s"Controller produced $result")
} yield result
} <* log.info("Some log after controller function (without correlation_id)")
}
// at the end of the world
runtime.unsafeRun {
controllerFunction("123").provideEnvironment(ZEnvironment(logger))
}
// res15: String = "stubbedstubbed"
I 2021-08-17T15:07:54.244 (00_logstage.md:220) …App12.serviceLayerFunction1 [2280:Thread-60 ] correlation_id=123 Going to call dbLayerFunction
I 2021-08-17T15:07:54.342 (00_logstage.md:213) …n.App12.dbLayerFunction.212 [2280:Thread-60 ] correlation_id=123, arg=1 Database call result=stubbed
I 2021-08-17T15:07:54.358 (00_logstage.md:226) …App12.serviceLayerFunction2 [2280:Thread-60 ] correlation_id=123 Called serviceLayerFunction2
I 2021-08-17T15:07:54.367 (00_logstage.md:235) ….controllerFunction.232.233 [2280:Thread-60 ] correlation_id=123 Controller produced result=stubbedstubbed
I 2021-08-17T15:07:54.371 (00_logstage.md:237) …on.App12.controllerFunction [2280:Thread-60 ] Some log after controller function (without correlation_id)
Custom JSON rendering with LogstageCodec
If you define an instance of LogstageCodec
for your type, it will be used when rendering your logs to JSON instead of the default renderer.
You can derive instances of LogstageCodec
from Circe codecs with logstage-rendering-circe
or write them manually.
Example:
import io.circe.Codec
import io.circe.generic.semiauto
import logstage.LogstageCodec
import logstage.circe.LogstageCirceCodec
final case class KV(key: String, value: Int)
object KV {
implicit val circeCodec: Codec[KV] = semiauto.deriveCodec[KV]
implicit val logstageCodec: LogstageCodec[KV] = LogstageCirceCodec.derived[KV]
}
If you want to make sure that all values in your interpolations are rendered using LogstageCodec
instead of default renderer, use IzStrictLogger
/LogIOStrict
types from logstage.strict
package:
import logstage.strict.IzStrictLogger
import logstage.ConsoleSink
import logstage.circe.LogstageCirceRenderingPolicy
val logger = IzStrictLogger(sink = ConsoleSink(LogstageCirceRenderingPolicy()))
// logger: IzStrictLogger = izumi.logstage.api.strict.IzStrictLogger@76db0e2d
logger.info(s"Got ${KV("key", 7) -> "KeyValue"}")
SLF4J Router
When not configured, logstage-adapter-slf4j
will log messages with level >= Info
to stdout
.
Due to the global mutable nature of slf4j
, to configure slf4j logging you’ll have to mutate a global singleton StaticLogRouter
. Replace its LogRouter
with the same one you use elsewhere in your application to use the same configuration for Slf4j.
import logstage.IzLogger
import izumi.logstage.api.routing.StaticLogRouter
val myLogger = IzLogger()
// myLogger: IzLogger = izumi.logstage.api.IzLogger@4fbad6a6
// configure SLF4j to use the same router that `myLogger` uses
StaticLogRouter.instance.setup(myLogger.router)
JUL (java.util.logging
) support
There are two ways to integrate JUL framework with LogStage.
LogStage implements JUL log handler. Due to the global mutable nature of JUL framework, to configure JUL logging you’ll have to mutate a global singleton holding the root of the JUL logging hierarch java.util.logging.Logger
.
This might be done the following way:
val logger = IzLogger()
val router: LogRouter = logger.router
val bridge = new LogstageJulLogger(router)
bridge.installOnly()
LogstageJulLogger#installOnly()
method wipes all the logging handlers associated with the root logger and installs LogStage as the only logging handler.
Alternatively, you may use jul-to-slf4j
adapter for slf4j
.
You might need to do the following in order for the adapter to properly initialize:
SLF4JBridgeHandler.removeHandlersForRootLogger()
SLF4JBridgeHandler.install()