From 50265ab325a5b16e2182eb4f70cda306ec1f6395 Mon Sep 17 00:00:00 2001 From: Igor Ramazanov Date: Sat, 22 Feb 2025 13:25:59 +0000 Subject: [PATCH] Add `log4cats` integration --- README.md | 39 +++++ build.sbt | 14 ++ docs/README.md | 39 +++++ .../legogroup/woof/log4cats/WoofFactory.scala | 83 ++++++++++ .../woof/log4cats/Log4CatsSuite.scala | 147 ++++++++++++++++++ 5 files changed, 322 insertions(+) create mode 100644 modules/log4cats/src/main/scala/org/legogroup/woof/log4cats/WoofFactory.scala create mode 100644 modules/log4cats/src/test/scala/org/legogroup/woof/log4cats/Log4CatsSuite.scala diff --git a/README.md b/README.md index 32bc09a..309c3fe 100644 --- a/README.md +++ b/README.md @@ -15,6 +15,7 @@ A **pure** _(in both senses of the word!)_ **Scala 3** logging library with **no - [Can I use `SLF4J`?](#can-i-use-slf4j) - [Limitations of SLF4J bindings](#limitations-of-slf4j-bindings) - [Can I use `http4s`?](#can-i-use-http4s) + - [Can I use `log4cats`?](#can-i-use-log4cats) - [Structured Logging](#structured-logging) ## Highlights @@ -228,6 +229,44 @@ mainHttp4s.unsafeRunSync() // 2023-03-13 09:00:43 [INFO ] repl.MdocSession$.MdocApp: Got response headers: Headers(X-Trace-Id: 33a38390-647a-4876-9a05-7898a8f4db44) (README.md:147) ``` +## Can I use `log4cats`? +Yes, you can. Create a Woof `Logger[F]` instance, and wrap it into Log4Cats' `LoggerFactory[F]`: +```scala mdoc +import cats.effect.IO + +import org.legogroup.woof.ColorPrinter +import org.legogroup.woof.DefaultLogger +import org.legogroup.woof.Filter +import org.legogroup.woof.log4cats.WoofFactory +import org.legogroup.woof.Output +import org.legogroup.woof.Printer + +import org.typelevel.log4cats.Logger +import org.typelevel.log4cats.LoggerFactory +import org.typelevel.log4cats.syntax.* + + +def program(using LoggerFactory[IO]): IO[Unit] = + given Logger[IO] = LoggerFactory[IO].getLogger + + for + _ <- error"This is some error from log4cats!" + _ <- warn"This is some warn from log4cats!" + _ <- info"This is some info from log4cats!" + _ <- debug"This is some debug from log4cats!" + _ <- trace"This is some trace from log4cats!" + yield () + +val main: IO[Unit] = + given Filter = Filter.everything + given Printer = ColorPrinter() + + for + given LoggerFactory[IO] <- DefaultLogger.makeIo(Output.fromConsole).map(WoofFactory[IO](_)) + _ <- program + yield () +``` + ## Structured Logging Structured logging is useful when your logs are collected and inspected by a monitoring system. Having a well structured log output can save you diff --git a/build.sbt b/build.sbt index f677a7f..8a626c2 100644 --- a/build.sbt +++ b/build.sbt @@ -5,6 +5,7 @@ val V = new { val catsEffect = "3.5.4" val circe = "0.14.8" val http4s = "0.23.28" + val log4cats = "2.7.0" val munit = "1.0.0-M11" val munitCatsEffect = "2.0.0" val scala = "3.3.4" @@ -21,6 +22,7 @@ val D = new { val catsEffect = Def.setting("org.typelevel" %%% "cats-effect" % V.catsEffect) val catsEffectTestKit = Def.setting("org.typelevel" %%% "cats-effect-testkit" % V.catsEffect) val http4s = Def.setting("org.http4s" %%% "http4s-core" % V.http4s) + val log4cats = Def.setting("org.typelevel" %%% "log4cats-core" % V.log4cats) val munit = Def.setting("org.scalameta" %%% "munit" % V.munit) val munitCatsEffect = Def.setting("org.typelevel" %%% "munit-cats-effect" % V.munitCatsEffect) val munitScalacheck = Def.setting("org.scalameta" %%% "munit-scalacheck" % V.munit) @@ -84,6 +86,7 @@ lazy val root = slf4j, slf4j2, slf4jCommon, + log4cats, ).flatMap(_.componentProjects).map(_.project): _* ) .settings( @@ -108,6 +111,17 @@ lazy val core = crossProject(JSPlatform, JVMPlatform, NativePlatform) ), ) +val log4catsFolder = file("./modules/log4cats") +lazy val log4cats = crossProject(JSPlatform, JVMPlatform, NativePlatform) + .crossType(CrossType.Pure) + .in(log4catsFolder) + .settings( + name := nameForFile(log4catsFolder), + libraryDependencies += D.log4cats.value, + ) + .settings(commonSettings) + .dependsOn(core % "compile->compile;test->test") // we also want the test utils + val http4sFolder = file("./modules/http4s") lazy val http4s = crossProject(JSPlatform, JVMPlatform, NativePlatform) .crossType(CrossType.Pure) diff --git a/docs/README.md b/docs/README.md index 58050ac..2a13650 100644 --- a/docs/README.md +++ b/docs/README.md @@ -15,6 +15,7 @@ A **pure** _(in both senses of the word!)_ **Scala 3** logging library with **no - [Can I use `SLF4J`?](#can-i-use-slf4j) - [Limitations of SLF4J bindings](#limitations-of-slf4j-bindings) - [Can I use `http4s`?](#can-i-use-http4s) + - [Can I use `log4cats`?](#can-i-use-log4cats) - [Structured Logging](#structured-logging) ## Highlights @@ -217,6 +218,44 @@ the correlation ID is also returned in the header of the response. mainHttp4s.unsafeRunSync() ``` +## Can I use `log4cats`? +Yes, you can. Create a Woof `Logger[F]` instance, and wrap it into Log4Cats' `LoggerFactory[F]`: +```scala mdoc +import cats.effect.IO + +import org.legogroup.woof.ColorPrinter +import org.legogroup.woof.DefaultLogger +import org.legogroup.woof.Filter +import org.legogroup.woof.log4cats.WoofFactory +import org.legogroup.woof.Output +import org.legogroup.woof.Printer + +import org.typelevel.log4cats.Logger +import org.typelevel.log4cats.LoggerFactory +import org.typelevel.log4cats.syntax.* + + +def program(using LoggerFactory[IO]): IO[Unit] = + given Logger[IO] = LoggerFactory[IO].getLogger + + for + _ <- error"This is some error from log4cats!" + _ <- warn"This is some warn from log4cats!" + _ <- info"This is some info from log4cats!" + _ <- debug"This is some debug from log4cats!" + _ <- trace"This is some trace from log4cats!" + yield () + +val main: IO[Unit] = + given Filter = Filter.everything + given Printer = ColorPrinter() + + for + given LoggerFactory[IO] <- DefaultLogger.makeIo(Output.fromConsole).map(WoofFactory[IO](_)) + _ <- program + yield () +``` + ## Structured Logging Structured logging is useful when your logs are collected and inspected by a monitoring system. Having a well structured log output can save you diff --git a/modules/log4cats/src/main/scala/org/legogroup/woof/log4cats/WoofFactory.scala b/modules/log4cats/src/main/scala/org/legogroup/woof/log4cats/WoofFactory.scala new file mode 100644 index 0000000..a2b4b53 --- /dev/null +++ b/modules/log4cats/src/main/scala/org/legogroup/woof/log4cats/WoofFactory.scala @@ -0,0 +1,83 @@ +package org.legogroup.woof.log4cats + +import cats.Applicative +import org.legogroup.woof +import org.legogroup.woof.Logger.withLogContext +import org.typelevel.log4cats + +object WoofFactory: + + def apply[F[_]: Applicative](logger: woof.Logger[F]): log4cats.LoggerFactory[F] = + new WoofFactory[F](logger) + +end WoofFactory + +private class WoofFactory[F[_]: Applicative](logger: woof.Logger[F]) extends log4cats.LoggerFactory[F]: + + override def getLoggerFromName(name: String): log4cats.SelfAwareStructuredLogger[F] = + new WoofLog4CatsLogger[F](logger, name) + + override def fromName(name: String): F[log4cats.SelfAwareStructuredLogger[F]] = + Applicative[F].pure(getLoggerFromName(name)) + +end WoofFactory + +private class WoofLog4CatsLogger[F[_]: Applicative](logger: woof.Logger[F], name: String) + extends log4cats.SelfAwareStructuredLogger[F]: + + private def logInfo(): woof.LogInfo = + val stacktraceElements = (new Throwable).getStackTrace() + val lastIndex = stacktraceElements.reverse.indexWhere(s => s.getClassName == this.getClass.getName) + val callingMethodIndex = stacktraceElements.size - lastIndex + val callingMethod = stacktraceElements(callingMethodIndex) + val fileName = + (callingMethod.getClassName.replace('.', '/') + ".scala").split("\\/").takeRight(1).mkString + val lineNumber = callingMethod.getLineNumber - 1 + woof.LogInfo(woof.EnclosingClass(name), fileName, lineNumber) + end logInfo + + private def thrMsg(m: String, t: Throwable): String = + (try s"$m ${t.getMessage}" + catch case _ => s"$m ") + + override def error(ctx: Map[String, String], t: Throwable)(m: => String): F[Unit] = + logger.error(thrMsg(m, t))(using logInfo()).withLogContext(ctx.toList*)(using logger) + override def warn(ctx: Map[String, String], t: Throwable)(m: => String): F[Unit] = + logger.warn(thrMsg(m, t))(using logInfo()).withLogContext(ctx.toList*)(using logger) + override def info(ctx: Map[String, String], t: Throwable)(m: => String): F[Unit] = + logger.info(thrMsg(m, t))(using logInfo()).withLogContext(ctx.toList*)(using logger) + override def debug(ctx: Map[String, String], t: Throwable)(m: => String): F[Unit] = + logger.debug(thrMsg(m, t))(using logInfo()).withLogContext(ctx.toList*)(using logger) + override def trace(ctx: Map[String, String], t: Throwable)(m: => String): F[Unit] = + logger.trace(thrMsg(m, t))(using logInfo()).withLogContext(ctx.toList*)(using logger) + + override def error(t: Throwable)(m: => String): F[Unit] = logger.error(thrMsg(m, t))(using logInfo()) + override def warn(t: Throwable)(m: => String): F[Unit] = logger.warn(thrMsg(m, t))(using logInfo()) + override def info(t: Throwable)(m: => String): F[Unit] = logger.info(thrMsg(m, t))(using logInfo()) + override def debug(t: Throwable)(m: => String): F[Unit] = logger.debug(thrMsg(m, t))(using logInfo()) + override def trace(t: Throwable)(m: => String): F[Unit] = logger.trace(thrMsg(m, t))(using logInfo()) + + override def error(m: => String): F[Unit] = logger.error(m)(using logInfo()) + override def warn(m: => String): F[Unit] = logger.warn(m)(using logInfo()) + override def info(m: => String): F[Unit] = logger.info(m)(using logInfo()) + override def debug(m: => String): F[Unit] = logger.debug(m)(using logInfo()) + override def trace(m: => String): F[Unit] = logger.trace(m)(using logInfo()) + + override def isErrorEnabled: F[Boolean] = Applicative[F].pure(true) + override def isWarnEnabled: F[Boolean] = Applicative[F].pure(true) + override def isInfoEnabled: F[Boolean] = Applicative[F].pure(true) + override def isDebugEnabled: F[Boolean] = Applicative[F].pure(true) + override def isTraceEnabled: F[Boolean] = Applicative[F].pure(true) + + override def error(ctx: Map[String, String])(m: => String): F[Unit] = + logger.error(m)(using logInfo()).withLogContext(ctx.toList*)(using logger) + override def warn(ctx: Map[String, String])(m: => String): F[Unit] = + logger.warn(m)(using logInfo()).withLogContext(ctx.toList*)(using logger) + override def info(ctx: Map[String, String])(m: => String): F[Unit] = + logger.info(m)(using logInfo()).withLogContext(ctx.toList*)(using logger) + override def debug(ctx: Map[String, String])(m: => String): F[Unit] = + logger.debug(m)(using logInfo()).withLogContext(ctx.toList*)(using logger) + override def trace(ctx: Map[String, String])(m: => String): F[Unit] = + logger.trace(m)(using logInfo()).withLogContext(ctx.toList*)(using logger) + +end WoofLog4CatsLogger diff --git a/modules/log4cats/src/test/scala/org/legogroup/woof/log4cats/Log4CatsSuite.scala b/modules/log4cats/src/test/scala/org/legogroup/woof/log4cats/Log4CatsSuite.scala new file mode 100644 index 0000000..09de5b7 --- /dev/null +++ b/modules/log4cats/src/test/scala/org/legogroup/woof/log4cats/Log4CatsSuite.scala @@ -0,0 +1,147 @@ +package org.legogroup.woof.log4cats + +import cats.effect.IO +import cats.effect.kernel.Clock +import cats.effect.std.Dispatcher +import cats.Id +import org.legogroup.woof.* +import org.typelevel.log4cats.LoggerFactory +import scala.concurrent.duration.* + +class Log4CatsSuite extends munit.CatsEffectSuite: + + override def munitIOTimeout = 10.minutes + + private val ctx = Map("a" -> "a", "my context" -> "MY CONTEXT") + + test("should log stuff") { + given Printer = NoColorPrinter(testFormatTime) + given Filter = Filter.everything + given Clock[IO] = leetClock + + for + stringOutput <- newStringWriter + woofLogger <- DefaultLogger.makeIo(stringOutput) + log4catsLogger <- IO(WoofFactory[IO](woofLogger).getLogger) + _ <- log4catsLogger.info("HELLO, Log4Cats!") + result <- stringOutput.get + yield assertEquals( + result, + "1987-05-31 13:37:00 [INFO ] org.legogroup.woof.log4cats.Log4CatsSuite: HELLO, Log4Cats! (Log4CatsSuite.scala:26)\n", + ) + end for + } + + test("should respect log levels") { + given Printer = NoColorPrinter(testFormatTime) + given Filter = Filter.exactLevel(LogLevel.Warn) + given Clock[IO] = leetClock + + for + stringWriter <- newStringWriter + woofLogger <- DefaultLogger.makeIo(stringWriter) + log4catsLogger <- IO(WoofFactory[IO](woofLogger).getLogger) + _ <- log4catsLogger.error("ERROR, Log4Cats!") + _ <- log4catsLogger.warn("WARN, Log4Cats!") + _ <- log4catsLogger.info("INFO, Log4Cats!") + _ <- log4catsLogger.debug("DEBUG, Log4Cats!") + _ <- log4catsLogger.debug("TRACE, Log4Cats!") + result <- stringWriter.get + yield assertEquals( + result, + "1987-05-31 13:37:00 [WARN ] org.legogroup.woof.log4cats.Log4CatsSuite: WARN, Log4Cats! (Log4CatsSuite.scala:45)\n", + ) + end for + } + + test("should log context") { + given Printer = NoColorPrinter(testFormatTime) + given Filter = Filter.everything + given Clock[IO] = leetClock + + for + stringOutput <- newStringWriter + woofLogger <- DefaultLogger.makeIo(stringOutput) + log4catsLogger <- IO(WoofFactory[IO](woofLogger).getLogger) + _ <- log4catsLogger.info(Map("a" -> "a", "my context" -> "MY CONTEXT"))("HELLO, CONTEXT!") + result <- stringOutput.get + yield assertEquals( + result, + "1987-05-31 13:37:00 [INFO ] a=a, my context=MY CONTEXT org.legogroup.woof.log4cats.Log4CatsSuite: HELLO, CONTEXT! (Log4CatsSuite.scala:66)\n", + ) + end for + } + + test("should log throwable") { + given Printer = NoColorPrinter(testFormatTime) + given Filter = Filter.everything + given Clock[IO] = leetClock + + for + stringOutput <- newStringWriter + woofLogger <- DefaultLogger.makeIo(stringOutput) + log4catsLogger <- IO(WoofFactory[IO](woofLogger).getLogger) + _ <- log4catsLogger.info(new RuntimeException("BOOM!"))("THROWABLE") + result <- stringOutput.get + yield assertEquals( + result, + "1987-05-31 13:37:00 [INFO ] org.legogroup.woof.log4cats.Log4CatsSuite: THROWABLE BOOM! (Log4CatsSuite.scala:84)\n", + ) + end for + } + + test("should log context and throwable") { + given Printer = NoColorPrinter(testFormatTime) + given Filter = Filter.everything + given Clock[IO] = leetClock + + for + stringOutput <- newStringWriter + woofLogger <- DefaultLogger.makeIo(stringOutput) + log4catsLogger <- IO(WoofFactory[IO](woofLogger).getLogger) + _ <- log4catsLogger.info(ctx, new RuntimeException("BOOM!"))("CONTEXT + THROWABLE") + result <- stringOutput.get + yield assertEquals( + result, + "1987-05-31 13:37:00 [INFO ] a=a, my context=MY CONTEXT org.legogroup.woof.log4cats.Log4CatsSuite: CONTEXT + THROWABLE BOOM! (Log4CatsSuite.scala:102)\n", + ) + end for + } + + test("should not fail on null throwable") { + given Printer = NoColorPrinter(testFormatTime) + given Filter = Filter.everything + given Clock[IO] = leetClock + + for + stringWriter <- newStringWriter + woofLogger <- DefaultLogger.makeIo(stringWriter) + log4catsLogger <- IO(WoofFactory[IO](woofLogger).getLogger) + _ <- log4catsLogger.debug(null: Throwable)("NULL THROWABLE") + result <- stringWriter.get + yield assertEquals( + result, + "1987-05-31 13:37:00 [DEBUG] org.legogroup.woof.log4cats.Log4CatsSuite: NULL THROWABLE (Log4CatsSuite.scala:120)\n", + ) + end for + } + + test("should not fail on null throwable with context") { + given Printer = NoColorPrinter(testFormatTime) + given Filter = Filter.everything + given Clock[IO] = leetClock + + for + stringWriter <- newStringWriter + woofLogger <- DefaultLogger.makeIo(stringWriter) + log4catsLogger <- IO(WoofFactory[IO](woofLogger).getLogger) + _ <- log4catsLogger.debug(ctx, null: Throwable)("NULL THROWABLE + CONTEXT") + result <- stringWriter.get + yield assertEquals( + result, + "1987-05-31 13:37:00 [DEBUG] a=a, my context=MY CONTEXT org.legogroup.woof.log4cats.Log4CatsSuite: NULL THROWABLE + CONTEXT (Log4CatsSuite.scala:138)\n", + ) + end for + } + +end Log4CatsSuite