diff --git a/.gitignore b/.gitignore index 0a3e62d..5ea571b 100644 --- a/.gitignore +++ b/.gitignore @@ -1,2 +1,3 @@ -target -/log +target +/log +.idea/ diff --git a/.scalafmt.conf b/.scalafmt.conf new file mode 100644 index 0000000..9b803ea --- /dev/null +++ b/.scalafmt.conf @@ -0,0 +1,2 @@ +version=2.3.2 +trailingCommas = always diff --git a/README.md b/README.md new file mode 100644 index 0000000..99be91c --- /dev/null +++ b/README.md @@ -0,0 +1,195 @@ +# Structured logging framework 4 Cats + +This repo contains experiments with possible implementations of structured logging with `cats-effect`. + +## Goals + + * log commands are side-effecting programs, based on `cats-effect` + * objects provided to log commands should appear as JSON in logs + * they're searchable in Kibana + * we won't duplicate the objects in message itself to reduce size + * logs will contain appropriate context + * the context can be programmatically augmented + * works in a stack-like manner, including shadowing + * works well with `cats-effect` and related libraries (is not bound to `ThreadLocal`/fat JVM thread like slf4j's MDC) + * other useful metadata in logs + * timestamp + * file name + * line number + * loglevel as both string and number + * ... to be specified + * JSON keys will be just strings, at lest for the beginning + +## Features + + * thin wrapper over `slf4j` + * each logging statement is inlined on the same line using macros + * rest of the logging pipeline works as expected + * JSON logging + * uses `logstash-logback-encoder` for JSON log formatting + * uses Jackson for the encoding of log parameters by default (imported by Logback Logstash encoder anyway; can be overridden if necessary) + * CPU expensive or side-effectful actions can be passed to logs + * will be memoized == computed only once or never at all, if log level too low + +## Interface + +```scala +trait LoggingContext[F[_]] { + type Self <: LoggingContext[F] + def withArg[A](name: String, + value: => A, + toJson: Option[A => String] = None): Self + def withComputed[A](name: String, + value: F[A], + toJson: Option[A => String] = None): Self + def withArgs[A](map: Map[String, A], toJson: Option[A => String] = None): Self + def use[A](inner: F[A]): F[A] +} + +trait Logger[F[_]] { + type Self <: Logger[F] + def withArg[A](name: String, + value: => A, + toJson: Option[A => String] = None): Self + def withComputed[A](name: String, + value: F[A], + toJson: Option[A => String] = None): Self + def withArgs[A](map: Map[String, A], toJson: Option[A => String] = None): Self + // excerpt for `info` logging + def info: LoggerInfo[F] + //... +} + +trait ContextLogger[F[_]] extends LoggingContext[F] with Logger[F] { + type Self <: ContextLogger[F] +} +class LoggerInfo[F[_]]() { + def apply(message: String): F[Unit] = macro ??? + def apply(message: String, throwable: Throwable): F[Unit] = macro ??? +} +``` + +## Usage + +```scala +def program(logger: ContextLogger[Task]): Task[Unit] = { + val ex = new InvalidParameterException("BOOOOOM") + for { + _ <- logger + .withArg("a", A(1, "x", Array[Byte](127))) + .withArg("o", o) + .info("Hello Monix") + _ <- logger.warn("Hello MTL", ex) + _ <- logger.withArg("x", 123).withArg("o", o).use { + logger.withArg("x", 9).info("Hello2 meow") + } + } yield () +} +``` + +### Multiple contexts +```scala +_ <- logger + .withArg("a", A(1, "x", Array[Byte](127))) + .withArg("o", o) + .info("Hello Monix") +``` +```json +{ + "@timestamp": "2020-01-08T02:31:16.503+01:00", + "@version": "1", + "message": "Hello Monix", + "logger_name": "slf4cats.example.Main$", + "thread_name": "scala-execution-context-global-13", + "level": "INFO", + "level_value": 20000, + "a": { + "x": 1, + "y": "x", + "bytes": "fw==" + }, + "o": { + "a": { + "x": 123, + "y": "Hello", + "bytes": "AQID" + }, + "b": [ + false, + true + ], + "c": { + "r": 456 + } + }, + "application": "loggingexperiment", + "caller_class_name": "slf4cats.example.Main$", + "caller_method_name": "$anonfun$program$5", + "caller_file_name": "Main.scala", + "caller_line_number": 66 +} +``` + +### Logging exception +```scala +_ <- logger.warn("Hello MTL", ex) +``` +```json +{ + "@timestamp": "2020-01-08T02:31:16.520+01:00", + "@version": "1", + "message": "Hello MTL", + "logger_name": "slf4cats.example.Main$", + "thread_name": "scala-execution-context-global-13", + "level": "WARN", + "level_value": 30000, + "stack_trace": "java.security.InvalidParameterException: BOOOOOM\n\tat slf4cats.example.Main$.program(Main.scala:61)\n...", + "application": "loggingexperiment", + "caller_class_name": "slf4cats.example.Main$", + "caller_method_name": "$anonfun$program$9", + "caller_file_name": "Main.scala", + "caller_line_number": 67 +} +``` + +### Context overriding +```scala +_ <- logger.withArg("x", 123).withArg("o", o).use { + logger.withArg("x", 9).info("Hello2 meow") +} +``` +```json +{ + "@timestamp": "2020-01-08T02:31:16.539+01:00", + "@version": "1", + "message": "Hello2 meow", + "logger_name": "slf4cats.example.Main$", + "thread_name": "scala-execution-context-global-13", + "level": "INFO", + "level_value": 20000, + "x": [ + 1, + 2, + 3 + ], + "o": { + "a": { + "x": 123, + "y": "Hello", + "bytes": "AQID" + }, + "b": [ + false, + true + ], + "c": { + "r": 456 + } + }, + "application": "loggingexperiment", + "caller_class_name": "slf4cats.example.Main$", + "caller_method_name": "$anonfun$program$16", + "caller_file_name": "Main.scala", + "caller_line_number": 69 +} +``` diff --git a/build.sbt b/build.sbt index 58d12a5..3181a94 100644 --- a/build.sbt +++ b/build.sbt @@ -4,14 +4,92 @@ version := "0.1" scalaVersion := "2.12.10" -val circeVersion = "0.11.1" - -libraryDependencies ++= Seq( - "org.slf4j" % "slf4j-api" % "1.7.29", - "ch.qos.logback" % "logback-classic" % "1.2.3", - "net.logstash.logback" % "logstash-logback-encoder" % "6.2", - "io.circe" %% "circe-core" % circeVersion, - "io.circe" %% "circe-generic" % circeVersion, -// "org.typelevel" %% "cats-effect" % "2.0.0", - "dev.zio" %% "zio" % "1.0.0-RC16", -) +lazy val Version = new { + val slf4j = "1.7.29" + val logback = "1.2.3" + val jacksonScala = "2.10.2" + val logstashLogback = "6.2" + val monix = "3.1.0" + val catsMtl = "0.7.0" + val catsEffect = "2.0.0" + val meowMtl = "0.4.0" + val circe = "0.13.0-M2" +} + +lazy val root = project + .in(file(".")) + .settings( + name := "slf4cats", + publish / skip := true, // doesn't publish ivy XML files, in contrast to "publishArtifact := false" + ) + .aggregate( + slf4catsApi, + slf4catsImpl, + slf4catsCirce, + slf4catsExample, + ) + +lazy val slf4catsApi = project + .in(file("slf4cats-api")) + .settings( + name := "slf4cats-api", + libraryDependencies ++= Seq( + "org.slf4j" % "slf4j-api" % Version.slf4j, + "org.typelevel" %% "cats-effect" % Version.catsEffect, + "org.scala-lang" % "scala-reflect" % scalaVersion.value, + ), + ) + +lazy val slf4catsImpl = project + .in(file("slf4cats-impl")) + .settings( + name := "slf4cats-impl", + libraryDependencies ++= Seq( + "net.logstash.logback" % "logstash-logback-encoder" % Version.logstashLogback, + "org.typelevel" %% "cats-mtl-core" % Version.catsMtl, + "org.typelevel" %% "cats-effect" % Version.catsEffect, + ), + ) + .dependsOn(slf4catsApi) + +lazy val slf4catsMonix = project + .in(file("slf4cats-monix")) + .settings( + name := "slf4cats-monix", + libraryDependencies ++= Seq( + "io.monix" %% "monix" % Version.monix, + "com.olegpy" %% "meow-mtl-monix" % Version.meowMtl, + ), + ) + .dependsOn(slf4catsImpl) + +lazy val slf4catsCirce = project + .in(file("slf4cats-circe")) + .settings( + name := "slf4cats-circe", + libraryDependencies ++= Seq( + "io.circe" %% "circe-core" % Version.circe, + ), + ) + .dependsOn(slf4catsApi) + +lazy val slf4catsJackson = project + .in(file("slf4cats-jackson")) + .settings( + name := "slf4cats-jackson", + libraryDependencies ++= Seq( + "com.fasterxml.jackson.module" %% "jackson-module-scala" % Version.jacksonScala, + ), + ) + .dependsOn(slf4catsApi) + +lazy val slf4catsExample = project + .in(file("slf4cats-example")) + .settings( + name := "slf4cats-example", + libraryDependencies ++= Seq( + "ch.qos.logback" % "logback-classic" % Version.logback, + "io.circe" %% "circe-generic" % Version.circe, + ), + ) + .dependsOn(slf4catsMonix, slf4catsCirce, slf4catsJackson) diff --git a/project/plugins.sbt b/project/plugins.sbt new file mode 100644 index 0000000..8a37c46 --- /dev/null +++ b/project/plugins.sbt @@ -0,0 +1 @@ +addSbtPlugin("io.github.davidgregory084" % "sbt-tpolecat" % "0.1.10") diff --git a/slf4cats-api/src/main/scala/slf4cats/api/slf4cats-api.scala b/slf4cats-api/src/main/scala/slf4cats/api/slf4cats-api.scala new file mode 100644 index 0000000..b288280 --- /dev/null +++ b/slf4cats-api/src/main/scala/slf4cats/api/slf4cats-api.scala @@ -0,0 +1,104 @@ +package slf4cats.api + +import cats.effect.Sync +import org.slf4j.Marker + +trait ArgumentsBuilder[F[_]] { + type Self <: ArgumentsBuilder[F] + def withArg[A]( + name: String, + value: => A, + )(implicit logEncoder: LogEncoder[A]): Self + def withComputed[A]( + name: String, + value: F[A], + )(implicit logEncoder: LogEncoder[A]): Self + def withArgs[A](map: Map[String, A])(implicit logEncoder: LogEncoder[A]): Self +} + +trait LoggingContext[F[_]] extends ArgumentsBuilder[F] { + def use[A](inner: F[A]): F[A] +} + +trait Logger[F[_]] extends ArgumentsBuilder[F] { + def info: LoggerInfo[F] + def warn: LoggerWarn[F] +} + +trait ContextLogger[F[_]] extends LoggingContext[F] with Logger[F] { + type Self <: ContextLogger[F] +} + +trait LogEncoder[-A] { + def encode(a: A): String +} + +object LogEncoder { + def apply[A](implicit e: LogEncoder[A]): LogEncoder[A] = e +} + +trait LoggerCommand[F[_]] { + +// could be made available if there's interest +//def isEnabled: F[Boolean] + + /** To be used by a macro, don't use this yourself */ + def withUnderlying( + macroCallback: (Sync[F], org.slf4j.Logger) => (Marker => F[Unit]), + ): F[Unit] +} + +object LoggerCommand { + private[api] object Macros { + import scala.reflect.macros.blackbox + type Context[F[_]] = blackbox.Context { type PrefixType = LoggerCommand[F] } + + def log[F[_]]( + c: Context[F], + )(level: c.TermName, message: c.Expr[String]): c.Expr[F[Unit]] = { + import c.universe._ + val tree = + q"${c.prefix}.withUnderlying { case (fsync, underlying) => (marker => fsync.delay { underlying.$level(marker, $message) }) }" + c.Expr[F[Unit]](tree) + } + + def logThrowable[F[_]](c: Context[F])( + level: c.TermName, + message: c.Expr[String], + throwable: c.Expr[Throwable], + ): c.Expr[F[Unit]] = { + import c.universe._ + val tree = + q"${c.prefix}.withUnderlying { case (fsync, underlying) => (marker => fsync.delay { underlying.$level(marker, $message, $throwable) }) }" + c.Expr[F[Unit]](tree) + } + + def info[F[_]](c: Context[F])(message: c.Expr[String]): c.Expr[F[Unit]] = + log(c)(c.universe.TermName("info"), message) + + def infoThrowable[F[_]]( + c: Context[F], + )(message: c.Expr[String], throwable: c.Expr[Throwable]): c.Expr[F[Unit]] = + logThrowable(c)(c.universe.TermName("info"), message, throwable) + + def warn[F[_]](c: Context[F])(message: c.Expr[String]): c.Expr[F[Unit]] = + log(c)(c.universe.TermName("warn"), message) + + def warnThrowable[F[_]]( + c: Context[F], + )(message: c.Expr[String], throwable: c.Expr[Throwable]): c.Expr[F[Unit]] = + logThrowable(c)(c.universe.TermName("warn"), message, throwable) + } +} + +abstract class LoggerInfo[F[_]]() extends LoggerCommand[F] { + def apply(message: String): F[Unit] = macro LoggerCommand.Macros.info[F] + def apply(message: String, throwable: Throwable): F[Unit] = + macro LoggerCommand.Macros.infoThrowable[F] +} + +abstract class LoggerWarn[F[_]]() extends LoggerCommand[F] { + def apply(message: String): F[Unit] = macro LoggerCommand.Macros.warn[F] + def apply(message: String, throwable: Throwable): F[Unit] = + macro LoggerCommand.Macros.warnThrowable[F] +} diff --git a/slf4cats-circe/src/main/scala/slf4cats/encoders/circe/package.scala b/slf4cats-circe/src/main/scala/slf4cats/encoders/circe/package.scala new file mode 100644 index 0000000..b2defe9 --- /dev/null +++ b/slf4cats-circe/src/main/scala/slf4cats/encoders/circe/package.scala @@ -0,0 +1,9 @@ +package slf4cats.encoders + +import io.circe.Printer +import slf4cats.api.LogEncoder + +package object circe { + import io.circe.Encoder + implicit def convertEncoder[A](implicit circeEncoder: Encoder[A]): LogEncoder[A] = (a: A) => Printer.noSpaces.print(circeEncoder(a)) +} diff --git a/slf4cats-example/src/main/resources/logback.xml b/slf4cats-example/src/main/resources/logback.xml new file mode 100644 index 0000000..4156d2c --- /dev/null +++ b/slf4cats-example/src/main/resources/logback.xml @@ -0,0 +1,17 @@ + + + + log/loggingexperiment.json + + {"application":"loggingexperiment"} + true + + + + log/loggingexperiment.log + + %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg - %marker%n + + + + diff --git a/slf4cats-example/src/main/scala/slf4cats/example/Main.scala b/slf4cats-example/src/main/scala/slf4cats/example/Main.scala new file mode 100644 index 0000000..f6a9df6 --- /dev/null +++ b/slf4cats-example/src/main/scala/slf4cats/example/Main.scala @@ -0,0 +1,70 @@ +package slf4cats.example + +import java.security.InvalidParameterException + +import cats.effect._ +import monix.eval._ +import slf4cats.api._ +import slf4cats.impl._ +import slf4cats.monix.ContextLoggerMonix + +object Main extends TaskApp { + + final case class A(x: Int, y: String, bytes: Array[Byte]) + + final case class B(a: A, b: List[Boolean], c: Either[String, Int]) + + private val o = + B(A(123, "Hello", Array(1, 2, 3)), List(false, true), Right(456)) + + override def run(args: List[String]): Task[ExitCode] = + init + .map(_ => ExitCode.Success) + .executeWithOptions(_.enableLocalContextPropagation) + + def init: Task[Unit] = + for { + mdc <- TaskLocal(ContextLogger.Context.empty[Task]) + logger = ContextLoggerMonix.make[Main.type](mdc) + result <- program(logger) + } yield result + + def program(logger: ContextLogger[Task]): Task[Unit] = { + import slf4cats.encoders.jackson._ + val ex = new InvalidParameterException("BOOOOOM") + for { + _ <- logger + .withArg("a", A(1, "x", Array(127))) + .withArg("o", o) + .info("Hello Monix") + _ <- logger.warn("Hello MTL", ex) + // test shadowing of arg "x" + _ <- logger.withArg("x", 123).withArg("o", o).use { + logger.withArg("x", List(1, 2, 3)).info("Hello2 meow") + } + // test context passing on child fibers + _ <- logger.withArg("o", o).use { + logger.withArg("x", List("x")).info("Hello in child fiber").start.flatMap { _ => + logger.withArg("y", List("y")).info("Hello back in parent fiber") + } + } + // test circe encoder + _ <- logCirce(logger) + // test when LogEncoder throws an error + _ <- logger + .withArg("xxxx",1)((_: Any) => throw new RuntimeException("asdf")) + .info("yyyy") + } yield () + } + + private def logCirce(logger: ContextLogger[Task]): Task[Unit] = { + import slf4cats.encoders.circe._ + import io.circe._ + import io.circe.generic.semiauto._ + implicit val byteArrayEncoder: Encoder[Array[Byte]] = (_: Array[Byte]) => Json.Null + implicit val aDecoder: Encoder[A] = deriveEncoder + implicitly[Encoder[Array[Byte]]] // to avoid incorrect error that byteArrayEncoder is never used + logger.withArg("circe", A(1, "b", Array(1, 2))).info("Logging with circe-encoded class") + } + +} diff --git a/slf4cats-impl/src/main/scala/slf4cats/impl/ContextLogger.scala b/slf4cats-impl/src/main/scala/slf4cats/impl/ContextLogger.scala new file mode 100644 index 0000000..1df9254 --- /dev/null +++ b/slf4cats-impl/src/main/scala/slf4cats/impl/ContextLogger.scala @@ -0,0 +1,203 @@ +package slf4cats.impl + +import cats._ +import cats.effect._ +import cats.implicits._ +import cats.mtl._ +import net.logstash.logback.marker.Markers +import org.slf4j.{LoggerFactory, Marker} +import slf4cats.api._ + +import scala.reflect.ClassTag +import scala.util.control.NonFatal + +object ContextLogger { + + object JsonInString { + private[ContextLogger] def make[F[_], A]( + toJson: A => String, + )(x: A)(implicit F: Sync[F]): F[String] = { + F.delay { + toJson(x) + } + .recover { case NonFatal(e) => "\"<" + e + ">\"" } + } + } + + type Context[F[_]] = Map[String, F[String]] + object Context { + def empty[F[_]]: Context[F] = Map.empty + } + + private def mapSequence[F[_], K, V]( + m: Map[K, F[V]], + )(implicit FApplicative: Applicative[F]): F[Map[K, V]] = { + m.foldLeft(FApplicative.pure(Map.empty[K, V])) { + case (fm, (k, fv)) => + FApplicative.tuple2(fm, fv).map { + case (m, v) => + m + ((k, v)) + } + } + } + + private trait LoggerCommandImpl[F[_]] { + + def underlying: org.slf4j.Logger + + def localContext: Map[String, F[F[String]]] + + implicit def FSync: Sync[F] + + implicit def FApplicativeAsk: ApplicativeAsk[F, Context[F]] + + private val marker: F[Marker] = for { + context1 <- FApplicativeAsk.ask + context2 <- mapSequence(localContext) + union <- mapSequence(context1 ++ context2) + markers = union.toList.map { + case (k, v) => + Markers.appendRaw(k, v) + } + result = Markers.aggregate(markers: _*) + } yield result + + protected def isEnabled: F[Boolean] + + def withUnderlying( + macroCallback: (Sync[F], org.slf4j.Logger) => (Marker => F[Unit]), + ): F[Unit] = { + val body = macroCallback(FSync, underlying) + isEnabled.flatMap { isEnabled => + if (isEnabled) { + marker.flatMap { marker => + body(marker) + } + } else { + FSync.unit + } + } + } + } + + private class LoggerInfoImpl[F[_]]( + val underlying: org.slf4j.Logger, + val localContext: Map[String, F[F[String]]], + )( + implicit + val FSync: Sync[F], + val FApplicativeAsk: ApplicativeAsk[F, Context[F]], + ) extends LoggerInfo[F] + with LoggerCommandImpl[F] { + + override protected val isEnabled: F[Boolean] = FSync.delay { + underlying.isInfoEnabled + } + } + + private class LoggerWarnImpl[F[_]]( + val underlying: org.slf4j.Logger, + val localContext: Map[String, F[F[String]]], + )( + implicit + val FSync: Sync[F], + val FApplicativeAsk: ApplicativeAsk[F, Context[F]], + ) extends LoggerWarn[F] + with LoggerCommandImpl[F] { + + override protected val isEnabled: F[Boolean] = FSync.delay { + underlying.isWarnEnabled + } + } + + private class ContextLoggerImpl[F[_]]( + underlying: org.slf4j.Logger, + context: Map[String, F[F[String]]], + )( + implicit FApplicativeLocal: ApplicativeLocal[F, Context[F]], + FAsync: Async[F], + ) extends ContextLogger[F] { + + override type Self = ContextLogger[F] + + override def info: LoggerInfo[F] = + new LoggerInfoImpl[F](underlying, context) + + override def warn: LoggerWarn[F] = + new LoggerWarnImpl[F](underlying, context) + + override def withArg[A]( + name: String, + value: => A, + )(implicit logEncoder: LogEncoder[A]): ContextLogger[F] = + withComputed( + name, + FAsync.delay { + value + }, + ) + + override def withComputed[A]( + name: String, + value: F[A], + )(implicit logEncoder: LogEncoder[A]): ContextLogger[F] = { + val memoizedJson = + Async.memoize( + value.flatMap(JsonInString.make(logEncoder.encode)(_)), + ) + new ContextLoggerImpl[F]( + underlying, + context + ((name, memoizedJson)), + ) + } + + override def withArgs[A]( + map: Map[String, A], + )(implicit logEncoder: LogEncoder[A]): ContextLogger[F] = { + new ContextLoggerImpl[F]( + underlying, + context ++ map + .mapValues(v => + Async.memoize( + JsonInString + .make(logEncoder.encode)(v), + ), + ), + ) + } + + override def use[A](inner: F[A]): F[A] = { + mapSequence(context).flatMap { contextMemoized => + FApplicativeLocal.local(_ ++ contextMemoized)(inner) + } + } + } + + def fromLogger[F[_]]( + logger: org.slf4j.Logger, + )( + implicit FAsync: Async[F], + FApplicativeLocal: ApplicativeLocal[F, Context[F]], + ): ContextLogger[F] = { + new ContextLoggerImpl[F]( + logger, + Map.empty, + ) + } + + def fromName[F[_]](name: String)( + implicit FAsync: Async[F], + FApplicativeAsk: ApplicativeLocal[F, Context[F]], + ): ContextLogger[F] = { + fromLogger(LoggerFactory.getLogger(name)) + } + + def fromClass[F[_], T]()( + implicit classTag: ClassTag[T], + FAsync: Async[F], + FApplicativeAsk: ApplicativeLocal[F, Context[F]], + ): ContextLogger[F] = { + fromLogger(LoggerFactory.getLogger(classTag.runtimeClass)) + } + +} diff --git a/slf4cats-jackson/src/main/scala/slf4cats/encoders/jackson/package.scala b/slf4cats-jackson/src/main/scala/slf4cats/encoders/jackson/package.scala new file mode 100644 index 0000000..e5d2ca4 --- /dev/null +++ b/slf4cats-jackson/src/main/scala/slf4cats/encoders/jackson/package.scala @@ -0,0 +1,13 @@ +package slf4cats.encoders + +import com.fasterxml.jackson.databind.ObjectMapper +import com.fasterxml.jackson.module.scala.DefaultScalaModule +import slf4cats.api.LogEncoder + +package object jackson { + implicit def encoder: LogEncoder[Any] = { + val jackson = new ObjectMapper() + jackson.registerModule(DefaultScalaModule) + jackson.writeValueAsString + } +} diff --git a/slf4cats-monix/src/main/scala/slf4cats/monix/ContextLoggerMonix.scala b/slf4cats-monix/src/main/scala/slf4cats/monix/ContextLoggerMonix.scala new file mode 100644 index 0000000..c63d9cb --- /dev/null +++ b/slf4cats-monix/src/main/scala/slf4cats/monix/ContextLoggerMonix.scala @@ -0,0 +1,35 @@ +package slf4cats.monix + +import com.olegpy.meow.monix._ +import monix.eval.{Task, TaskLocal} +import slf4cats.api.ContextLogger +import slf4cats.impl.ContextLogger + +import scala.reflect.ClassTag + +object ContextLoggerMonix { + + def make(logger: org.slf4j.Logger)( + taskLocalContext: TaskLocal[ContextLogger.Context[Task]], + ): ContextLogger[Task] = { + taskLocalContext.runLocal { implicit ev => + ContextLogger.fromLogger(logger) + } + } + + def make(name: String)( + taskLocalContext: TaskLocal[ContextLogger.Context[Task]], + ): ContextLogger[Task] = { + taskLocalContext.runLocal { implicit ev => + ContextLogger.fromName(name) + } + } + + def make[T]( + taskLocalContext: TaskLocal[ContextLogger.Context[Task]], + )(implicit classTag: ClassTag[T]): ContextLogger[Task] = { + taskLocalContext.runLocal { implicit ev => + ContextLogger.fromClass() + } + } +} diff --git a/src/main/resources/logback.xml b/src/main/resources/logback.xml deleted file mode 100644 index a31f728..0000000 --- a/src/main/resources/logback.xml +++ /dev/null @@ -1,10 +0,0 @@ - - - - log/loggingexperiment.log - - - - - - diff --git a/src/main/scala/loggingexperiment/Main.scala b/src/main/scala/loggingexperiment/Main.scala deleted file mode 100644 index 9e04cf7..0000000 --- a/src/main/scala/loggingexperiment/Main.scala +++ /dev/null @@ -1,198 +0,0 @@ -package loggingexperiment - -//import cats.effect.{ExitCode, IO, IOApp, Sync} -import io.circe.Encoder -import org.slf4j.{Logger, LoggerFactory, MDC} -import net.logstash.logback.argument.StructuredArguments -import net.logstash.logback.marker.{LogstashMarker, Markers} -import io.circe.generic.auto._ -import io.circe.syntax._ -import zio.{UManaged, _} - -import collection.JavaConverters._ - -final case class A(x: Int, y: String) -final case class B(a: A, b: Boolean) - -trait Log { - def log: Log.Service -} - -object Log { - - trait Service { - def info[A](format: String, xName: String, x: A)( - implicit e: Encoder[A] - ): UIO[Unit] - def info[A, B](format: String, xName: String, x: A, yName: String, y: B)( - implicit ex: Encoder[A], - ey: Encoder[B] - ): UIO[Unit] - def addContext[A](format: String, xName: String, x: A)( - implicit e: Encoder[A] - ): UManaged[Unit] - } - - def log: ZIO[Log, Nothing, Log.Service] = - ZIO.access[Log](_.log) - - private class LogImpl(logger: Logger, - mdc: FiberRef[Map[String, List[(Any, Encoder[Any])]]]) - extends Service { - - private def log(body: LogstashMarker => Unit): UIO[Unit] = - for { - mdc <- mdc.get - mdcNormalized = mdc.toList.map { - case (k, v) => (k, v.head match { case (v, e) => e(v).toString }) - } - markers = mdcNormalized.map { case (k, v) => Markers.appendRaw(k, v) } - _ <- UIO.effectTotal { - body(Markers.aggregate(markers: _*)) -// val context = mdc.map { -// case (k, v) => -// MDC.putCloseable(k, v.head match { case (v, e) => e(v).toString }) -// } -// try { -// body(mdc.map{ case (n, l)}) -// } finally { -// context.foreach(_.close) -// } - } - } yield () - - override def addContext[A](format: String, xName: String, x: A)( - implicit e: Encoder[A] - ): UManaged[Unit] = { - Managed.make { - for { - _ <- mdc.update { mdc => - mdc.get(xName) match { - case Some(list) => - mdc + ((xName, (x, e.asInstanceOf[Encoder[Any]]) :: list)) - case None => - mdc + ((xName, (x, e.asInstanceOf[Encoder[Any]]) :: Nil)) - } - } - } yield () - } { _: Unit => - for { - _ <- mdc.update { mdc => - mdc.get(xName) match { - case Some(_ :: Nil) => - mdc - xName - case Some(_ :: tail) => - mdc + ((xName, tail)) - } - } - } yield () - } - } - - override def info[A](format: String, xName: String, x: A)( - implicit e: Encoder[A] - ): UIO[Unit] = - log { mdc => - logger.info( - mdc, - format, - StructuredArguments.raw(xName, x.asJson.toString), - ) - } - - override def info[A, B]( - format: String, - xName: String, - x: A, - yName: String, - y: B - )(implicit ex: Encoder[A], ey: Encoder[B]): UIO[Unit] = - log { mdc => - logger.info( - mdc, - format, - StructuredArguments.raw(xName, x.asJson.toString), - StructuredArguments.raw(yName, y.asJson.toString): Any, - ) - } - } - - def make(logger: Logger): UIO[Log] = { - for { - mdc <- FiberRef.make(Map.empty[String, List[(Any, Encoder[Any])]]) - logImpl = new LogImpl(logger, mdc) - svc = new Log { - override def log: Service = logImpl - } - } yield svc - - } -} - -object Main extends App { - -// implicit final class LoggerOps(val logger: Logger) extends AnyVal { -// def info_[A](format: String, xName: String, x: A)( -// implicit e: Encoder[A] -// ): UIO[Unit] = { -// UIO.effectTotal( -// logger.info(format, StructuredArguments.raw(xName, x.asJson.toString)) -// ) -// } -// def info_[A, B](format: String, xName: String, x: A, yName: String, y: B)( -// implicit ex: Encoder[A], -// ey: Encoder[B] -// ): UIO[Unit] = { -// UIO.effectTotal( -// logger.info( -// format, -// StructuredArguments.raw(xName, x.asJson.toString), -// StructuredArguments.raw(yName, y.asJson.toString): Any -// ) -// ) -// } -// } - - val logger: Logger = LoggerFactory.getLogger(Main.getClass) - val o = B(A(123, "Hello"), b = true) - - override def run(args: List[String]): ZIO[ZEnv, Nothing, Int] = - init.fold(_ => 1, _ => 0) - - def init: Task[Unit] = - for { - log <- Log.make(logger) - result <- program.provide(log) - } yield result - - def program: RIO[Log, Unit] = { - for { - logger <- Log.log - _ <- logger.addContext("XXXXXXX {} ", "yyy", A(567, "YYYYYYYYYYYY")).use { - _: Unit => - for { - _ <- logger.info("Hello {}", "o", o) - } yield () - } - _ <- logger.info("Hello {}", "o", o) - _ <- logger.info("Hello2 {} and {}", "x", 123, "o", o) - } yield () - } - -// def run(args: Array[String]): Unit = { -// -// println(s"Hello $o") -// logger.info(s"Hello $o") -// logger.info("Hello {}", o) -// logger.info("Hello o={}", o) -// logger.info("Hello array {}", StructuredArguments.array("o", o)) -// logger.info( -// "Hello entries {}", -// StructuredArguments.entries(o.asJsonObject.toMap.asJava) -// ) -// logger.info("Hello fields {}", StructuredArguments.fields("o", o)) -// logger.info("Hello keyValue {}", StructuredArguments.keyValue("o", o)) -// logger.info("Hello raw {}", StructuredArguments.raw("o", o.asJson.toString)) -// logger.info("Hello value {}", StructuredArguments.value("o", o)) -// } -}