diff --git a/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLogMessage.scala b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLogMessage.scala new file mode 100644 index 00000000..cca7322a --- /dev/null +++ b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLogMessage.scala @@ -0,0 +1,148 @@ +/* + * Copyright 2018 Typelevel + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.typelevel.log4cats.extras + +import cats.syntax.show.* +import cats.Show +import cats.kernel.Hash +import org.typelevel.log4cats.{Logger, StructuredLogger} +import org.typelevel.log4cats.extras.DeferredLogMessage.{ + deferredStructuredLogMessageHash, + deferredStructuredLogMessageShow +} + +/** + * `StructuredLogMessage` has a bug that can't be fixed without breaking bincompat (because it's a + * `case class`), but it's only used in the `Writer*Logger`s, so it's not a huge deal. + * + * The issue is that the API of the `*Logger` classes has a by-name parameter for the message, and + * `StructuredLogMessage` (and by extension, the `Writer*Logger`) don't lazily compute the message. + * + * At some point, this should be renamed to `StructuredLogMessage` and replace the old class. + */ +sealed trait DeferredLogMessage { + def level: LogLevel + def context: Map[String, String] + def throwableOpt: Option[Throwable] + def message: () => String + + def log[F[_]](logger: Logger[F]): F[Unit] = { + level match { + case LogLevel.Error => + throwableOpt match { + case Some(e) => logger.error(e)(message()) + case None => logger.error(message()) + } + case LogLevel.Warn => + throwableOpt match { + case Some(e) => logger.warn(e)(message()) + case None => logger.warn(message()) + } + case LogLevel.Info => + throwableOpt match { + case Some(e) => logger.info(e)(message()) + case None => logger.info(message()) + } + case LogLevel.Debug => + throwableOpt match { + case Some(e) => logger.debug(e)(message()) + case None => logger.debug(message()) + } + case LogLevel.Trace => + throwableOpt match { + case Some(e) => logger.trace(e)(message()) + case None => logger.trace(message()) + } + } + } + + def logStructured[F[_]](logger: StructuredLogger[F]): F[Unit] = { + level match { + case LogLevel.Error => + throwableOpt match { + case Some(e) => logger.error(context, e)(message()) + case None => logger.error(context)(message()) + } + case LogLevel.Warn => + throwableOpt match { + case Some(e) => logger.warn(context, e)(message()) + case None => logger.warn(context)(message()) + } + case LogLevel.Info => + throwableOpt match { + case Some(e) => logger.info(context, e)(message()) + case None => logger.info(context)(message()) + } + case LogLevel.Debug => + throwableOpt match { + case Some(e) => logger.debug(context, e)(message()) + case None => logger.debug(context)(message()) + } + case LogLevel.Trace => + throwableOpt match { + case Some(e) => logger.trace(context, e)(message()) + case None => logger.trace(context)(message()) + } + } + } + + override def equals(obj: Any): Boolean = obj match { + case other: DeferredLogMessage => deferredStructuredLogMessageHash.eqv(this, other) + case _ => false + } + + override def hashCode(): Int = deferredStructuredLogMessageHash.hash(this) + + override def toString: String = deferredStructuredLogMessageShow.show(this) +} +object DeferredLogMessage { + def apply( + l: LogLevel, + c: Map[String, String], + t: Option[Throwable], + m: () => String + ): DeferredLogMessage = + new DeferredLogMessage { + override val level: LogLevel = l + override val context: Map[String, String] = c + override val throwableOpt: Option[Throwable] = t + override val message: () => String = m + } + + def trace(c: Map[String, String], t: Option[Throwable], m: () => String): DeferredLogMessage = + apply(LogLevel.Trace, c, t, m) + + def debug(c: Map[String, String], t: Option[Throwable], m: () => String): DeferredLogMessage = + apply(LogLevel.Debug, c, t, m) + + def info(c: Map[String, String], t: Option[Throwable], m: () => String): DeferredLogMessage = + apply(LogLevel.Info, c, t, m) + + def warn(c: Map[String, String], t: Option[Throwable], m: () => String): DeferredLogMessage = + apply(LogLevel.Warn, c, t, m) + + def error(c: Map[String, String], t: Option[Throwable], m: () => String): DeferredLogMessage = + apply(LogLevel.Error, c, t, m) + + implicit val deferredStructuredLogMessageHash: Hash[DeferredLogMessage] = Hash.by { l => + (l.level, l.context, l.throwableOpt.map(_.getMessage), l.message()) + } + + implicit val deferredStructuredLogMessageShow: Show[DeferredLogMessage] = Show.show { l => + show"DeferredStructuredLogMessage(${l.level},${l.context},${l.throwableOpt.map(_.getMessage)},${l.message()})" + } +} diff --git a/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLogger.scala b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLogger.scala new file mode 100644 index 00000000..d4c9ab89 --- /dev/null +++ b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLogger.scala @@ -0,0 +1,142 @@ +/* + * Copyright 2018 Typelevel + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.typelevel.log4cats.extras + +import cats.data.Chain +import cats.effect.kernel.Resource.ExitCase +import cats.effect.kernel.{Concurrent, Ref, Resource} +import cats.syntax.all._ +import cats.~> +import org.typelevel.log4cats.Logger + +/** + * `Logger` that does not immediately log. + * + * Similar in idea to `WriterLogger`, but a bit safer. This will not lose logs when the effect + * fails, instead logging when the resource is cancelled or fails. + * + * This can be used to implement failure-only logging. + * {{{ + * def handleRequest[F[_](request: Request[F], logger: StructuredLogger[F]): OptionT[F, Response[F]] = ??? + * + * HttpRoutes[F] { req => + * DeferredLogger[F](logger) + * .mapK(OptionT.liftK[F]) + * .use { logger => + * handleRequest(request, deferredLogger).flatTap { response => + * deferredLogger.log.unlessA(response.status.isSuccess) + * } + * } + * } + * }}} + * + * >>> WARNING: READ BEFORE USAGE! <<< + * https://github.com/typelevel/log4cats/blob/main/core/shared/src/main/scala/org/typelevel/log4cats/extras/README.md + * >>> WARNING: READ BEFORE USAGE! <<< + */ +trait DeferredLogger[F[_]] extends Logger[F] with DeferredLogging[F] { + override def withModifiedString(f: String => String): DeferredLogger[F] = + DeferredLogger.withModifiedString(this, f) + override def mapK[G[_]](fk: F ~> G): DeferredLogger[G] = DeferredLogger.mapK(this, fk) +} +object DeferredLogger { + def apply[F[_]](logger: Logger[F])(implicit F: Concurrent[F]): Resource[F, DeferredLogger[F]] = + Resource + .makeCase(Ref.empty[F, Chain[DeferredLogMessage]]) { (ref, exitCase) => + exitCase match { + case ExitCase.Succeeded => F.unit + case _ => ref.get.flatMap(_.traverse_(_.log(logger))) + } + } + .map { ref => + new DeferredLogger[F] { + private def save(lm: DeferredLogMessage): F[Unit] = ref.update(_.append(lm)) + + override def trace(t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.trace(Map.empty, t.some, () => msg)) + override def debug(t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.debug(Map.empty, t.some, () => msg)) + override def info(t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.info(Map.empty, t.some, () => msg)) + override def warn(t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.warn(Map.empty, t.some, () => msg)) + override def error(t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.error(Map.empty, t.some, () => msg)) + + override def trace(msg: => String): F[Unit] = + save(DeferredLogMessage.trace(Map.empty, none, () => msg)) + override def debug(msg: => String): F[Unit] = + save(DeferredLogMessage.debug(Map.empty, none, () => msg)) + override def info(msg: => String): F[Unit] = + save(DeferredLogMessage.info(Map.empty, none, () => msg)) + override def warn(msg: => String): F[Unit] = + save(DeferredLogMessage.warn(Map.empty, none, () => msg)) + override def error(msg: => String): F[Unit] = + save(DeferredLogMessage.error(Map.empty, none, () => msg)) + + override def inspect: F[Chain[DeferredLogMessage]] = ref.get + + override def log: F[Unit] = ref.getAndSet(Chain.empty).flatMap(_.traverse_(_.log(logger))) + } + } + + private def mapK[F[_], G[_]]( + logger: DeferredLogger[F], + fk: F ~> G + ): DeferredLogger[G] = + new DeferredLogger[G] { + override def inspect: G[Chain[DeferredLogMessage]] = fk(logger.inspect) + override def log: G[Unit] = fk(logger.log) + + override def trace(t: Throwable)(message: => String): G[Unit] = fk(logger.trace(t)(message)) + override def debug(t: Throwable)(message: => String): G[Unit] = fk(logger.debug(t)(message)) + override def info(t: Throwable)(message: => String): G[Unit] = fk(logger.info(t)(message)) + override def warn(t: Throwable)(message: => String): G[Unit] = fk(logger.warn(t)(message)) + override def error(t: Throwable)(message: => String): G[Unit] = fk(logger.error(t)(message)) + + override def trace(message: => String): G[Unit] = fk(logger.trace(message)) + override def debug(message: => String): G[Unit] = fk(logger.debug(message)) + override def info(message: => String): G[Unit] = fk(logger.info(message)) + override def warn(message: => String): G[Unit] = fk(logger.warn(message)) + override def error(message: => String): G[Unit] = fk(logger.error(message)) + + override def withModifiedString(f: String => String): DeferredLogger[G] = + DeferredLogger.withModifiedString(this, f) + override def mapK[H[_]](fk: G ~> H): DeferredLogger[H] = DeferredLogger.mapK(this, fk) + } + + def withModifiedString[F[_]]( + logger: DeferredLogger[F], + f: String => String + ): DeferredLogger[F] = + new DeferredLogger[F] { + override def inspect: F[Chain[DeferredLogMessage]] = logger.inspect + override def log: F[Unit] = logger.log + + override def trace(t: Throwable)(message: => String): F[Unit] = logger.trace(t)(f(message)) + override def debug(t: Throwable)(message: => String): F[Unit] = logger.debug(t)(f(message)) + override def info(t: Throwable)(message: => String): F[Unit] = logger.info(t)(f(message)) + override def warn(t: Throwable)(message: => String): F[Unit] = logger.warn(t)(f(message)) + override def error(t: Throwable)(message: => String): F[Unit] = logger.error(t)(f(message)) + + override def trace(message: => String): F[Unit] = logger.trace(f(message)) + override def debug(message: => String): F[Unit] = logger.debug(f(message)) + override def info(message: => String): F[Unit] = logger.info(f(message)) + override def warn(message: => String): F[Unit] = logger.warn(f(message)) + override def error(message: => String): F[Unit] = logger.error(f(message)) + } +} diff --git a/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLoggerFactory.scala b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLoggerFactory.scala new file mode 100644 index 00000000..1d68f571 --- /dev/null +++ b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLoggerFactory.scala @@ -0,0 +1,132 @@ +/* + * Copyright 2018 Typelevel + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.typelevel.log4cats.extras + +import cats.Show.Shown +import cats.data.Chain +import cats.effect.kernel.{Concurrent, Resource} +import cats.syntax.all._ +import cats.{~>, Functor} +import org.typelevel.log4cats.{LoggerFactory, SelfAwareStructuredLogger} + +/** + * A `LoggerFactory` that does not immediately log. + * + * Effectively a `LoggerFactory` equivalent to `DeferredSelfAwareStructuredLogger`. As an + * implementation note, the `LoggerFactory` trait is constrained in such a way that this will + * produce `SelfAwareStructuredLogger`, rather than `DeferredSelfAwareStructuredLogger`, so if + * logging is desired it needs to be triggered using the `DeferredLoggerFactory`, rather than being + * able to trigger it from any of the produced loggers. + * + * >>> WARNING: READ BEFORE USAGE! <<< + * https://github.com/typelevel/log4cats/blob/main/core/shared/src/main/scala/org/typelevel/log4cats/extras/README.md + * >>> WARNING: READ BEFORE USAGE! <<< + */ +trait DeferredLoggerFactory[F[_]] extends LoggerFactory[F] with DeferredLogging[F] { + override def getLoggerFromName(name: String): SelfAwareStructuredLogger[F] + + override def addContext(ctx: Map[String, String])(implicit + F: Functor[F] + ): DeferredLoggerFactory[F] = + DeferredLoggerFactory.addContext(this, ctx) + + override def addContext(pairs: (String, Shown)*)(implicit + F: Functor[F] + ): DeferredLoggerFactory[F] = + DeferredLoggerFactory.addContext(this, pairs.map { case (k, v) => (k, v.toString) }.toMap) + + override def withModifiedString(f: String => String)(implicit + F: Functor[F] + ): DeferredLoggerFactory[F] = + DeferredLoggerFactory.withModifiedString(this, f) + + override def mapK[G[_]](fk: F ~> G)(implicit F: Functor[F]): DeferredLoggerFactory[G] = + DeferredLoggerFactory.mapK[F, G](fk)(this) +} +object DeferredLoggerFactory { + + def apply[F[_]: Concurrent]( + loggerFactory: LoggerFactory[F] + ): Resource[F, DeferredLoggerFactory[F]] = + DeferredSelfAwareStructuredLogger.makeCache[F].map { cache => + new DeferredLoggerFactory[F] { + override def inspect: F[Chain[DeferredLogMessage]] = cache.get.map(_._1F) + + override def log: F[Unit] = { + cache + .getAndSet(Chain.empty) + .flatMap(_.traverse_ { case (msg, logger) => + msg.logStructured(logger) + }) + } + + override def fromName(name: String): F[SelfAwareStructuredLogger[F]] = + loggerFactory.fromName(name).map(DeferredSelfAwareStructuredLogger(_, cache)) + + override def getLoggerFromName(name: String): SelfAwareStructuredLogger[F] = + DeferredSelfAwareStructuredLogger(loggerFactory.getLoggerFromName(name), cache) + } + } + + private def mapK[F[_]: Functor, G[_]]( + fk: F ~> G + )(lf: DeferredLoggerFactory[F]): DeferredLoggerFactory[G] = + new DeferredLoggerFactory[G] { + override def inspect: G[Chain[DeferredLogMessage]] = fk( + lf.inspect + ) + override def log: G[Unit] = fk(lf.log) + + override def getLoggerFromName(name: String): SelfAwareStructuredLogger[G] = + lf.getLoggerFromName(name).mapK(fk) + + override def fromName(name: String): G[SelfAwareStructuredLogger[G]] = fk( + lf.fromName(name).map(_.mapK(fk)) + ) + } + + private def addContext[F[_]: Functor]( + lf: DeferredLoggerFactory[F], + ctx: Map[String, String] + ): DeferredLoggerFactory[F] = + new DeferredLoggerFactory[F] { + override def inspect: F[Chain[DeferredLogMessage]] = lf.inspect + override def log: F[Unit] = lf.log + + override def getLoggerFromName(name: String): SelfAwareStructuredLogger[F] = + lf.getLoggerFromName(name).addContext(ctx) + + override def fromName(name: String): F[SelfAwareStructuredLogger[F]] = + lf.fromName(name).map(_.addContext(ctx)) + } + + private def withModifiedString[F[_]: Functor]( + lf: DeferredLoggerFactory[F], + f: String => String + ): DeferredLoggerFactory[F] = + new DeferredLoggerFactory[F] { + override def inspect: F[Chain[DeferredLogMessage]] = lf.inspect + override def log: F[Unit] = lf.log + + override def getLoggerFromName(name: String): SelfAwareStructuredLogger[F] = + lf.getLoggerFromName(name).withModifiedString(f) + + override def fromName(name: String): F[SelfAwareStructuredLogger[F]] = + lf.fromName(name).map(_.withModifiedString(f)) + } + +} diff --git a/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLogging.scala b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLogging.scala new file mode 100644 index 00000000..3d81221b --- /dev/null +++ b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredLogging.scala @@ -0,0 +1,43 @@ +/* + * Copyright 2018 Typelevel + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.typelevel.log4cats.extras + +import cats.data.Chain + +/** + * A `Logger` that does not immediately log. + * + * >>> WARNING: READ BEFORE USAGE! <<< + * https://github.com/typelevel/log4cats/blob/main/core/shared/src/main/scala/org/typelevel/log4cats/extras/README.md + * >>> WARNING: READ BEFORE USAGE! <<< + */ +trait DeferredLogging[F[_]] { + + /** + * View the logs in the buffer. + * + * This is primarily useful for testing, and will not effect the behavior of calls to `log` + */ + def inspect: F[Chain[DeferredLogMessage]] + + /** + * Log the deferred messages + * + * This may be called multiple times, and each log should only be logged once. + */ + def log: F[Unit] +} diff --git a/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredSelfAwareStructuredLogger.scala b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredSelfAwareStructuredLogger.scala new file mode 100644 index 00000000..778305db --- /dev/null +++ b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredSelfAwareStructuredLogger.scala @@ -0,0 +1,315 @@ +/* + * Copyright 2018 Typelevel + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.typelevel.log4cats.extras + +import cats.data.Chain +import cats.effect.kernel.Resource.ExitCase +import cats.effect.kernel.{Concurrent, Ref, Resource} +import cats.syntax.all.* +import cats.{~>, Show} +import org.typelevel.log4cats.SelfAwareStructuredLogger + +/** + * Similar to `DeferredStructuredLogger`, for `SelfAwareStructuredLogger` + * + * >>> WARNING: READ BEFORE USAGE! <<< + * https://github.com/typelevel/log4cats/blob/main/core/shared/src/main/scala/org/typelevel/log4cats/extras/README.md + * >>> WARNING: READ BEFORE USAGE! <<< + */ +trait DeferredSelfAwareStructuredLogger[F[_]] + extends SelfAwareStructuredLogger[F] + with DeferredLogging[F] { + override def mapK[G[_]](fk: F ~> G): DeferredSelfAwareStructuredLogger[G] = + DeferredSelfAwareStructuredLogger.mapK(this, fk) + + override def addContext(ctx: Map[String, String]): DeferredSelfAwareStructuredLogger[F] = + DeferredSelfAwareStructuredLogger.withContext(this)(ctx) + + override def addContext(pairs: (String, Show.Shown)*): DeferredSelfAwareStructuredLogger[F] = + DeferredSelfAwareStructuredLogger.withContext(this)( + pairs.map { case (k, v) => (k, v.toString) }.toMap + ) + + override def withModifiedString(f: String => String): DeferredSelfAwareStructuredLogger[F] = + DeferredSelfAwareStructuredLogger.withModifiedString(this, f) +} +object DeferredSelfAwareStructuredLogger { + def apply[F[_]: Concurrent]( + logger: SelfAwareStructuredLogger[F] + ): Resource[F, DeferredSelfAwareStructuredLogger[F]] = + makeCache[F].map(apply[F](logger, _)) + + def apply[F[_]: Concurrent]( + logger: SelfAwareStructuredLogger[F], + stash: Ref[F, Chain[(DeferredLogMessage, SelfAwareStructuredLogger[F])]] + ): DeferredSelfAwareStructuredLogger[F] = + new DeferredSelfAwareStructuredLogger[F] { + private def save(lm: DeferredLogMessage): F[Unit] = + stash.update(_.append(lm -> logger)) + + override def isTraceEnabled: F[Boolean] = logger.isTraceEnabled + override def isDebugEnabled: F[Boolean] = logger.isDebugEnabled + override def isInfoEnabled: F[Boolean] = logger.isInfoEnabled + override def isWarnEnabled: F[Boolean] = logger.isWarnEnabled + override def isErrorEnabled: F[Boolean] = logger.isErrorEnabled + + private def saveTrace( + c: Map[String, String], + t: Option[Throwable], + m: () => String + ): F[Unit] = + isTraceEnabled.flatMap(save(DeferredLogMessage.trace(c, t, m)).whenA(_)) + private def saveDebug( + c: Map[String, String], + t: Option[Throwable], + m: () => String + ): F[Unit] = + isDebugEnabled.flatMap(save(DeferredLogMessage.debug(c, t, m)).whenA(_)) + private def saveInfo(c: Map[String, String], t: Option[Throwable], m: () => String): F[Unit] = + isInfoEnabled.flatMap(save(DeferredLogMessage.info(c, t, m)).whenA(_)) + private def saveWarn(c: Map[String, String], t: Option[Throwable], m: () => String): F[Unit] = + isWarnEnabled.flatMap(save(DeferredLogMessage.warn(c, t, m)).whenA(_)) + private def saveError( + c: Map[String, String], + t: Option[Throwable], + m: () => String + ): F[Unit] = + isErrorEnabled.flatMap(save(DeferredLogMessage.error(c, t, m)).whenA(_)) + + override def trace(ctx: Map[String, String])(msg: => String): F[Unit] = + saveTrace(ctx, none, () => msg) + override def debug(ctx: Map[String, String])(msg: => String): F[Unit] = + saveDebug(ctx, none, () => msg) + override def info(ctx: Map[String, String])(msg: => String): F[Unit] = + saveInfo(ctx, none, () => msg) + override def warn(ctx: Map[String, String])(msg: => String): F[Unit] = + saveWarn(ctx, none, () => msg) + override def error(ctx: Map[String, String])(msg: => String): F[Unit] = + saveError(ctx, none, () => msg) + + override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + saveTrace(ctx, t.some, () => msg) + override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + saveDebug(ctx, t.some, () => msg) + override def info(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + saveInfo(ctx, t.some, () => msg) + override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + saveWarn(ctx, t.some, () => msg) + override def error(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + saveError(ctx, t.some, () => msg) + + override def trace(t: Throwable)(msg: => String): F[Unit] = + saveTrace(Map.empty, t.some, () => msg) + override def debug(t: Throwable)(msg: => String): F[Unit] = + saveDebug(Map.empty, t.some, () => msg) + override def info(t: Throwable)(msg: => String): F[Unit] = + saveInfo(Map.empty, t.some, () => msg) + override def warn(t: Throwable)(msg: => String): F[Unit] = + saveWarn(Map.empty, t.some, () => msg) + override def error(t: Throwable)(msg: => String): F[Unit] = + saveError(Map.empty, t.some, () => msg) + + override def trace(msg: => String): F[Unit] = saveTrace(Map.empty, none, () => msg) + override def debug(msg: => String): F[Unit] = saveDebug(Map.empty, none, () => msg) + override def info(msg: => String): F[Unit] = saveInfo(Map.empty, none, () => msg) + override def warn(msg: => String): F[Unit] = saveWarn(Map.empty, none, () => msg) + override def error(msg: => String): F[Unit] = saveError(Map.empty, none, () => msg) + + override def inspect: F[Chain[DeferredLogMessage]] = stash.get.map(_._1F) + + override def log: F[Unit] = stash + .getAndSet(Chain.empty) + .flatMap(_.traverse_ { case (msg, logger) => + msg.logStructured(logger) + }) + } + + private[extras] def makeCache[F[_]](implicit + F: Concurrent[F] + ): Resource[F, Ref[F, Chain[(DeferredLogMessage, SelfAwareStructuredLogger[F])]]] = + Resource + .makeCase(Ref.empty[F, Chain[(DeferredLogMessage, SelfAwareStructuredLogger[F])]]) { + (ref, exitCase) => + exitCase match { + case ExitCase.Succeeded => F.unit + case _ => + ref.get.flatMap(_.traverse_ { case (msg, logger) => msg.logStructured(logger) }) + } + } + + private def mapK[F[_], G[_]]( + logger: DeferredSelfAwareStructuredLogger[F], + fk: F ~> G + ): DeferredSelfAwareStructuredLogger[G] = + new DeferredSelfAwareStructuredLogger[G] { + override def inspect: G[Chain[DeferredLogMessage]] = fk( + logger.inspect + ) + override def log: G[Unit] = fk(logger.log) + override def isTraceEnabled: G[Boolean] = fk(logger.isTraceEnabled) + override def isDebugEnabled: G[Boolean] = fk(logger.isDebugEnabled) + override def isInfoEnabled: G[Boolean] = fk(logger.isInfoEnabled) + override def isWarnEnabled: G[Boolean] = fk(logger.isWarnEnabled) + override def isErrorEnabled: G[Boolean] = fk(logger.isErrorEnabled) + + override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): G[Unit] = fk( + logger.trace(ctx, t)(msg) + ) + override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): G[Unit] = fk( + logger.debug(ctx, t)(msg) + ) + override def info(ctx: Map[String, String], t: Throwable)(msg: => String): G[Unit] = fk( + logger.info(ctx, t)(msg) + ) + override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): G[Unit] = fk( + logger.warn(ctx, t)(msg) + ) + override def error(ctx: Map[String, String], t: Throwable)(msg: => String): G[Unit] = fk( + logger.error(ctx, t)(msg) + ) + + override def trace(ctx: Map[String, String])(msg: => String): G[Unit] = fk( + logger.trace(ctx)(msg) + ) + override def debug(ctx: Map[String, String])(msg: => String): G[Unit] = fk( + logger.debug(ctx)(msg) + ) + override def info(ctx: Map[String, String])(msg: => String): G[Unit] = fk( + logger.info(ctx)(msg) + ) + override def warn(ctx: Map[String, String])(msg: => String): G[Unit] = fk( + logger.warn(ctx)(msg) + ) + override def error(ctx: Map[String, String])(msg: => String): G[Unit] = fk( + logger.error(ctx)(msg) + ) + + override def trace(t: Throwable)(message: => String): G[Unit] = fk(logger.trace(t)(message)) + override def debug(t: Throwable)(message: => String): G[Unit] = fk(logger.debug(t)(message)) + override def info(t: Throwable)(message: => String): G[Unit] = fk(logger.info(t)(message)) + override def warn(t: Throwable)(message: => String): G[Unit] = fk(logger.warn(t)(message)) + override def error(t: Throwable)(message: => String): G[Unit] = fk(logger.error(t)(message)) + + override def trace(message: => String): G[Unit] = fk(logger.trace(message)) + override def debug(message: => String): G[Unit] = fk(logger.debug(message)) + override def info(message: => String): G[Unit] = fk(logger.info(message)) + override def warn(message: => String): G[Unit] = fk(logger.warn(message)) + override def error(message: => String): G[Unit] = fk(logger.error(message)) + } + + def withContext[F[_]]( + logger: DeferredSelfAwareStructuredLogger[F] + )(baseCtx: Map[String, String]): DeferredSelfAwareStructuredLogger[F] = + new DeferredSelfAwareStructuredLogger[F] { + private def addCtx(ctx: Map[String, String]): Map[String, String] = baseCtx ++ ctx + + override def inspect: F[Chain[DeferredLogMessage]] = logger.inspect + override def log: F[Unit] = logger.log + override def isTraceEnabled: F[Boolean] = logger.isTraceEnabled + override def isDebugEnabled: F[Boolean] = logger.isDebugEnabled + override def isInfoEnabled: F[Boolean] = logger.isInfoEnabled + override def isWarnEnabled: F[Boolean] = logger.isWarnEnabled + override def isErrorEnabled: F[Boolean] = logger.isErrorEnabled + + override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.trace(addCtx(ctx), t)(msg) + override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.debug(addCtx(ctx), t)(msg) + override def info(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.info(addCtx(ctx), t)(msg) + override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.warn(addCtx(ctx), t)(msg) + override def error(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.error(addCtx(ctx), t)(msg) + + override def trace(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.trace(addCtx(ctx))(msg) + override def debug(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.debug(addCtx(ctx))(msg) + override def info(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.info(addCtx(ctx))(msg) + override def warn(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.warn(addCtx(ctx))(msg) + override def error(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.error(addCtx(ctx))(msg) + + override def trace(t: Throwable)(message: => String): F[Unit] = + logger.trace(baseCtx, t)(message) + override def debug(t: Throwable)(message: => String): F[Unit] = + logger.debug(baseCtx, t)(message) + override def info(t: Throwable)(message: => String): F[Unit] = + logger.info(baseCtx, t)(message) + override def warn(t: Throwable)(message: => String): F[Unit] = + logger.warn(baseCtx, t)(message) + override def error(t: Throwable)(message: => String): F[Unit] = + logger.error(baseCtx, t)(message) + + override def trace(message: => String): F[Unit] = logger.trace(baseCtx)(message) + override def debug(message: => String): F[Unit] = logger.debug(baseCtx)(message) + override def info(message: => String): F[Unit] = logger.info(baseCtx)(message) + override def warn(message: => String): F[Unit] = logger.warn(baseCtx)(message) + override def error(message: => String): F[Unit] = logger.error(baseCtx)(message) + } + + def withModifiedString[F[_]]( + logger: DeferredSelfAwareStructuredLogger[F], + f: String => String + ): DeferredSelfAwareStructuredLogger[F] = + new DeferredSelfAwareStructuredLogger[F] { + override def inspect: F[Chain[DeferredLogMessage]] = logger.inspect + override def log: F[Unit] = logger.log + override def isTraceEnabled: F[Boolean] = logger.isTraceEnabled + override def isDebugEnabled: F[Boolean] = logger.isDebugEnabled + override def isInfoEnabled: F[Boolean] = logger.isInfoEnabled + override def isWarnEnabled: F[Boolean] = logger.isWarnEnabled + override def isErrorEnabled: F[Boolean] = logger.isErrorEnabled + + override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.trace(ctx, t)(f(msg)) + override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.debug(ctx, t)(f(msg)) + override def info(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.info(ctx, t)(f(msg)) + override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.warn(ctx, t)(f(msg)) + override def error(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.error(ctx, t)(f(msg)) + + override def trace(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.trace(ctx)(f(msg)) + override def debug(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.debug(ctx)(f(msg)) + override def info(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.info(ctx)(f(msg)) + override def warn(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.warn(ctx)(f(msg)) + override def error(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.error(ctx)(f(msg)) + + override def trace(t: Throwable)(message: => String): F[Unit] = logger.trace(t)(f(message)) + override def debug(t: Throwable)(message: => String): F[Unit] = logger.debug(t)(f(message)) + override def info(t: Throwable)(message: => String): F[Unit] = logger.info(t)(f(message)) + override def warn(t: Throwable)(message: => String): F[Unit] = logger.warn(t)(f(message)) + override def error(t: Throwable)(message: => String): F[Unit] = logger.error(t)(f(message)) + + override def trace(message: => String): F[Unit] = logger.trace(f(message)) + override def debug(message: => String): F[Unit] = logger.debug(f(message)) + override def info(message: => String): F[Unit] = logger.info(f(message)) + override def warn(message: => String): F[Unit] = logger.warn(f(message)) + override def error(message: => String): F[Unit] = logger.error(f(message)) + } +} diff --git a/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredStructuredLogger.scala b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredStructuredLogger.scala new file mode 100644 index 00000000..a1966a91 --- /dev/null +++ b/core/shared/src/main/scala/org/typelevel/log4cats/extras/DeferredStructuredLogger.scala @@ -0,0 +1,268 @@ +/* + * Copyright 2018 Typelevel + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.typelevel.log4cats.extras + +import cats.Show.Shown +import cats.data.Chain +import cats.effect.kernel.Resource.ExitCase +import cats.effect.kernel.{Concurrent, Ref, Resource} +import cats.syntax.all._ +import cats.~> +import org.typelevel.log4cats.StructuredLogger + +/** + * `StructuredLogger` that does not immediately log. + * + * Similar in idea to `WriterStructuredLogger`, but a bit safer. This will not lose logs when the + * effect fails, instead logging when the resource is cancelled or fails. + * + * This can be used to implement failure-only logging. + * {{{ + * def handleRequest[F[_](request: Request[F], logger: StructuredLogger[F]): OptionT[F, Response[F]] = ??? + * + * HttpRoutes[F] { req => + * DeferredStructuredLogger[F](logger) + * .mapK(OptionT.liftK[F]) + * .use { logger => + * handleRequest(request, deferredLogger).flatTap { response => + * deferredLogger.log.unlessA(response.status.isSuccess) + * } + * } + * } + * }}} + * + * >>> WARNING: READ BEFORE USAGE! <<< + * https://github.com/typelevel/log4cats/blob/main/core/shared/src/main/scala/org/typelevel/log4cats/extras/README.md + * >>> WARNING: READ BEFORE USAGE! <<< + */ +trait DeferredStructuredLogger[F[_]] extends StructuredLogger[F] with DeferredLogging[F] { + override def mapK[G[_]](fk: F ~> G): DeferredStructuredLogger[G] = + DeferredStructuredLogger.mapK(this, fk) + + override def addContext(ctx: Map[String, String]): DeferredStructuredLogger[F] = + DeferredStructuredLogger.withContext(this, ctx) + + override def addContext( + pairs: (String, Shown)* + ): DeferredStructuredLogger[F] = + DeferredStructuredLogger.withContext(this, pairs.map { case (k, v) => (k, v.toString) }.toMap) + + override def withModifiedString(f: String => String): DeferredStructuredLogger[F] = + DeferredStructuredLogger.withModifiedString[F](this, f) +} +object DeferredStructuredLogger { + def apply[F[_]]( + logger: StructuredLogger[F] + )(implicit F: Concurrent[F]): Resource[F, DeferredStructuredLogger[F]] = + Resource + .makeCase(Ref.empty[F, Chain[DeferredLogMessage]]) { (ref, exitCase) => + exitCase match { + case ExitCase.Succeeded => F.unit + case _ => ref.get.flatMap(_.traverse_(_.logStructured(logger))) + } + } + .map { ref => + new DeferredStructuredLogger[F] { + private def save(lm: DeferredLogMessage): F[Unit] = ref.update(_.append(lm)) + + override def trace(ctx: Map[String, String])(msg: => String): F[Unit] = + save(DeferredLogMessage.trace(ctx, none, () => msg)) + override def debug(ctx: Map[String, String])(msg: => String): F[Unit] = + save(DeferredLogMessage.debug(ctx, none, () => msg)) + override def info(ctx: Map[String, String])(msg: => String): F[Unit] = + save(DeferredLogMessage.info(ctx, none, () => msg)) + override def warn(ctx: Map[String, String])(msg: => String): F[Unit] = + save(DeferredLogMessage.warn(ctx, none, () => msg)) + override def error(ctx: Map[String, String])(msg: => String): F[Unit] = + save(DeferredLogMessage.error(ctx, none, () => msg)) + + override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.trace(ctx, t.some, () => msg)) + override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.debug(ctx, t.some, () => msg)) + override def info(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.info(ctx, t.some, () => msg)) + override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.warn(ctx, t.some, () => msg)) + override def error(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.error(ctx, t.some, () => msg)) + + override def trace(t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.trace(Map.empty, t.some, () => msg)) + override def debug(t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.debug(Map.empty, t.some, () => msg)) + override def info(t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.info(Map.empty, t.some, () => msg)) + override def warn(t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.warn(Map.empty, t.some, () => msg)) + override def error(t: Throwable)(msg: => String): F[Unit] = + save(DeferredLogMessage.error(Map.empty, t.some, () => msg)) + + override def trace(msg: => String): F[Unit] = + save(DeferredLogMessage.trace(Map.empty, none, () => msg)) + override def debug(msg: => String): F[Unit] = + save(DeferredLogMessage.debug(Map.empty, none, () => msg)) + override def info(msg: => String): F[Unit] = + save(DeferredLogMessage.info(Map.empty, none, () => msg)) + override def warn(msg: => String): F[Unit] = + save(DeferredLogMessage.warn(Map.empty, none, () => msg)) + override def error(msg: => String): F[Unit] = + save(DeferredLogMessage.error(Map.empty, none, () => msg)) + + override def inspect: F[Chain[DeferredLogMessage]] = ref.get + + override def log: F[Unit] = + ref.getAndSet(Chain.empty).flatMap(_.traverse_(_.logStructured(logger))) + } + } + + private def mapK[F[_], G[_]]( + logger: DeferredStructuredLogger[F], + fk: F ~> G + ): DeferredStructuredLogger[G] = + new DeferredStructuredLogger[G] { + override def inspect: G[Chain[DeferredLogMessage]] = fk(logger.inspect) + override def log: G[Unit] = fk(logger.log) + + override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): G[Unit] = + fk(logger.trace(ctx, t)(msg)) + override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): G[Unit] = + fk(logger.debug(ctx, t)(msg)) + override def info(ctx: Map[String, String], t: Throwable)(msg: => String): G[Unit] = + fk(logger.info(ctx, t)(msg)) + override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): G[Unit] = + fk(logger.warn(ctx, t)(msg)) + override def error(ctx: Map[String, String], t: Throwable)(msg: => String): G[Unit] = + fk(logger.error(ctx, t)(msg)) + + override def trace(ctx: Map[String, String])(msg: => String): G[Unit] = + fk(logger.trace(ctx)(msg)) + override def debug(ctx: Map[String, String])(msg: => String): G[Unit] = + fk(logger.debug(ctx)(msg)) + override def info(ctx: Map[String, String])(msg: => String): G[Unit] = + fk(logger.info(ctx)(msg)) + override def warn(ctx: Map[String, String])(msg: => String): G[Unit] = + fk(logger.warn(ctx)(msg)) + override def error(ctx: Map[String, String])(msg: => String): G[Unit] = + fk(logger.error(ctx)(msg)) + + override def trace(t: Throwable)(message: => String): G[Unit] = fk(logger.trace(t)(message)) + override def debug(t: Throwable)(message: => String): G[Unit] = fk(logger.debug(t)(message)) + override def info(t: Throwable)(message: => String): G[Unit] = fk(logger.info(t)(message)) + override def warn(t: Throwable)(message: => String): G[Unit] = fk(logger.warn(t)(message)) + override def error(t: Throwable)(message: => String): G[Unit] = fk(logger.error(t)(message)) + + override def trace(message: => String): G[Unit] = fk(logger.trace(message)) + override def debug(message: => String): G[Unit] = fk(logger.debug(message)) + override def info(message: => String): G[Unit] = fk(logger.info(message)) + override def warn(message: => String): G[Unit] = fk(logger.warn(message)) + override def error(message: => String): G[Unit] = fk(logger.error(message)) + } + + def withContext[F[_]]( + logger: DeferredStructuredLogger[F], + baseCtx: Map[String, String] + ): DeferredStructuredLogger[F] = + new DeferredStructuredLogger[F] { + private def addCtx(ctx: Map[String, String]): Map[String, String] = baseCtx ++ ctx + + override def inspect: F[Chain[DeferredLogMessage]] = logger.inspect + override def log: F[Unit] = logger.log + + override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.trace(addCtx(ctx), t)(msg) + override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.debug(addCtx(ctx), t)(msg) + override def info(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.info(addCtx(ctx), t)(msg) + override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.warn(addCtx(ctx), t)(msg) + override def error(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.error(addCtx(ctx), t)(msg) + + override def trace(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.trace(addCtx(ctx))(msg) + override def debug(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.debug(addCtx(ctx))(msg) + override def info(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.info(addCtx(ctx))(msg) + override def warn(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.warn(addCtx(ctx))(msg) + override def error(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.error(addCtx(ctx))(msg) + + override def trace(t: Throwable)(message: => String): F[Unit] = + logger.trace(baseCtx, t)(message) + override def debug(t: Throwable)(message: => String): F[Unit] = + logger.debug(baseCtx, t)(message) + override def info(t: Throwable)(message: => String): F[Unit] = + logger.info(baseCtx, t)(message) + override def warn(t: Throwable)(message: => String): F[Unit] = + logger.warn(baseCtx, t)(message) + override def error(t: Throwable)(message: => String): F[Unit] = + logger.error(baseCtx, t)(message) + + override def trace(message: => String): F[Unit] = logger.trace(baseCtx)(message) + override def debug(message: => String): F[Unit] = logger.debug(baseCtx)(message) + override def info(message: => String): F[Unit] = logger.info(baseCtx)(message) + override def warn(message: => String): F[Unit] = logger.warn(baseCtx)(message) + override def error(message: => String): F[Unit] = logger.error(baseCtx)(message) + } + + def withModifiedString[F[_]]( + logger: DeferredStructuredLogger[F], + f: String => String + ): DeferredStructuredLogger[F] = + new DeferredStructuredLogger[F] { + override def inspect: F[Chain[DeferredLogMessage]] = logger.inspect + override def log: F[Unit] = logger.log + + override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.trace(ctx, t)(f(msg)) + override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.debug(ctx, t)(f(msg)) + override def info(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.info(ctx, t)(f(msg)) + override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.warn(ctx, t)(f(msg)) + override def error(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + logger.error(ctx, t)(f(msg)) + + override def trace(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.trace(ctx)(f(msg)) + override def debug(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.debug(ctx)(f(msg)) + override def info(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.info(ctx)(f(msg)) + override def warn(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.warn(ctx)(f(msg)) + override def error(ctx: Map[String, String])(msg: => String): F[Unit] = + logger.error(ctx)(f(msg)) + + override def trace(t: Throwable)(message: => String): F[Unit] = logger.trace(t)(f(message)) + override def debug(t: Throwable)(message: => String): F[Unit] = logger.debug(t)(f(message)) + override def info(t: Throwable)(message: => String): F[Unit] = logger.info(t)(f(message)) + override def warn(t: Throwable)(message: => String): F[Unit] = logger.warn(t)(f(message)) + override def error(t: Throwable)(message: => String): F[Unit] = logger.error(t)(f(message)) + + override def trace(message: => String): F[Unit] = logger.trace(f(message)) + override def debug(message: => String): F[Unit] = logger.debug(f(message)) + override def info(message: => String): F[Unit] = logger.info(f(message)) + override def warn(message: => String): F[Unit] = logger.warn(f(message)) + override def error(message: => String): F[Unit] = logger.error(f(message)) + } +} diff --git a/core/shared/src/main/scala/org/typelevel/log4cats/extras/LogLevel.scala b/core/shared/src/main/scala/org/typelevel/log4cats/extras/LogLevel.scala index dd2ed730..1549416f 100644 --- a/core/shared/src/main/scala/org/typelevel/log4cats/extras/LogLevel.scala +++ b/core/shared/src/main/scala/org/typelevel/log4cats/extras/LogLevel.scala @@ -48,12 +48,15 @@ object LogLevel { case Trace => "LogLevel.Trace" } - implicit final val logLevelOrder: Order[LogLevel] = - Order.by[LogLevel, Int] { - case Error => 5 - case Warn => 4 - case Info => 3 - case Debug => 2 - case Trace => 1 - } + private def toIndex(l: LogLevel): Int = l match { + case Error => 5 + case Warn => 4 + case Info => 3 + case Debug => 2 + case Trace => 1 + } + + implicit final val logLevelOrder: Order[LogLevel] = Order.by[LogLevel, Int](toIndex) + + implicit final val logLevelHash: Hash[LogLevel] = Hash.by(toIndex) } diff --git a/core/shared/src/main/scala/org/typelevel/log4cats/extras/README.md b/core/shared/src/main/scala/org/typelevel/log4cats/extras/README.md index ad50ed74..718e5dcc 100644 --- a/core/shared/src/main/scala/org/typelevel/log4cats/extras/README.md +++ b/core/shared/src/main/scala/org/typelevel/log4cats/extras/README.md @@ -1,11 +1,13 @@ -Important notes about `Writer*Logger`s -====================================== +Important caveats about the loggers in `org.typelevel.log4cats.extras` +====================================================================== + +`Writer*Logger` +--------------- The loggers provided here backed by `Writer` and `WriterT` come with some important caveats that you should be aware of before using. -General Notes -------------- +### General Notes > **Note** > These loggers tie their logs to the lifecycle of the return value, so they're generally only useful @@ -24,8 +26,7 @@ Better alternatives are provided by the `testing` module: - If a `SelfAwareStructuredLogger` is needed for test code, consider `org.typelevel.log4cats.testing.StructuredTestingLogger` over `WriterStructuredLogger` -`WriterLogger` / `WriterStructureLogger` ----------------------------------------- +### `WriterLogger` / `WriterStructureLogger` > **Warning** > Expect to lose logs if an exception occurs @@ -34,8 +35,7 @@ These are built using `Writer`, which does not directly interact with effects, s non-trivial amount of plumbing if you're planning on using them. Otherwise, if the logs don't matter in the presence of errors in the context you're using them, they're fine. -`WriterTLogger` / `WriterTStructuredLogger` -------------------------------------------- +### `WriterTLogger` / `WriterTStructuredLogger` These are built using `WriterT`, and are much easier to use with effects. Running the `WriterT` instance will yield a value of type `F[(G[LogMessage], A)]`. @@ -46,3 +46,15 @@ instance will yield a value of type `F[(G[LogMessage], A)]`. Unfortunately, because of the way that cancellation (and thus timeouts) is handled by `cats.effect.IO`, in practice `WriterT` isn't a great fit for anything which can timeout. +`Deferred*Logger` and `Deferred*LoggerFactory` +---------------------------------------------- + +The deferred `Logger` and `LoggerFactory` subclasses store their log messages in an unbounded +buffer. This is on the assumption that, if something is being logged, it matters enough to keep +around. + +This carries the risk of potentially unbounded memory usage. For example, in situations where +logging is done by code that is caught in an infinite loop. + +If this is a concern, using `DeferredSelfAwareStructuredLogger` or `DeferredLoggerFactory` are recommended, +as they can reduce the needed buffer space by discarding logs at disabled levels. \ No newline at end of file diff --git a/testing/shared/src/main/scala/org/typelevel/log4cats/testing/StructuredTestingLogger.scala b/testing/shared/src/main/scala/org/typelevel/log4cats/testing/StructuredTestingLogger.scala index f1d7607c..6f3cb529 100644 --- a/testing/shared/src/main/scala/org/typelevel/log4cats/testing/StructuredTestingLogger.scala +++ b/testing/shared/src/main/scala/org/typelevel/log4cats/testing/StructuredTestingLogger.scala @@ -16,11 +16,12 @@ package org.typelevel.log4cats.testing +import cats.data.Chain import org.typelevel.log4cats.SelfAwareStructuredLogger -import cats.effect.Sync -import cats.implicits._ -import java.util.concurrent.atomic.AtomicReference +import cats.effect.{Ref, Sync} +import cats.syntax.all._ +import java.util.concurrent.atomic.AtomicReference import scala.annotation.tailrec trait StructuredTestingLogger[F[_]] extends SelfAwareStructuredLogger[F] { @@ -68,6 +69,40 @@ object StructuredTestingLogger { infoEnabled: Boolean = true, warnEnabled: Boolean = true, errorEnabled: Boolean = true + ): StructuredTestingLogger[F] = + atomic[F]( + traceEnabled = traceEnabled, + debugEnabled = debugEnabled, + infoEnabled = infoEnabled, + warnEnabled = warnEnabled, + errorEnabled = errorEnabled + ) + + def ref[F[_]: Sync]( + traceEnabled: Boolean = true, + debugEnabled: Boolean = true, + infoEnabled: Boolean = true, + warnEnabled: Boolean = true, + errorEnabled: Boolean = true + ): F[StructuredTestingLogger[F]] = + Ref[F].empty[Chain[LogMessage]].map { ref => + make[F]( + traceEnabled = traceEnabled, + debugEnabled = debugEnabled, + infoEnabled = infoEnabled, + warnEnabled = warnEnabled, + errorEnabled = errorEnabled, + appendLogMessage = lm => ref.update(_.append(lm)), + read = () => ref.get.map(_.toVector) + ) + } + + def atomic[F[_]: Sync]( + traceEnabled: Boolean = true, + debugEnabled: Boolean = true, + infoEnabled: Boolean = true, + warnEnabled: Boolean = true, + errorEnabled: Boolean = true ): StructuredTestingLogger[F] = { val ar = new AtomicReference(Vector.empty[LogMessage]) def appendLogMessage(m: LogMessage): F[Unit] = Sync[F].delay { @@ -81,8 +116,28 @@ object StructuredTestingLogger { mod() } + make[F]( + traceEnabled = traceEnabled, + debugEnabled = debugEnabled, + infoEnabled = infoEnabled, + warnEnabled = warnEnabled, + errorEnabled = errorEnabled, + appendLogMessage = appendLogMessage, + read = () => Sync[F].delay(ar.get()) + ) + } + + def make[F[_]: Sync]( + traceEnabled: Boolean = true, + debugEnabled: Boolean = true, + infoEnabled: Boolean = true, + warnEnabled: Boolean = true, + errorEnabled: Boolean = true, + appendLogMessage: LogMessage => F[Unit], + read: () => F[Vector[LogMessage]] + ): StructuredTestingLogger[F] = new StructuredTestingLogger[F] { - def logged: F[Vector[LogMessage]] = Sync[F].delay(ar.get) + def logged: F[Vector[LogMessage]] = read() def isTraceEnabled: F[Boolean] = Sync[F].pure(traceEnabled) def isDebugEnabled: F[Boolean] = Sync[F].pure(debugEnabled) @@ -90,7 +145,7 @@ object StructuredTestingLogger { def isWarnEnabled: F[Boolean] = Sync[F].pure(warnEnabled) def isErrorEnabled: F[Boolean] = Sync[F].pure(errorEnabled) - private val noop = Sync[F].pure(()) + private val noop = Sync[F].unit def error(message: => String): F[Unit] = if (errorEnabled) appendLogMessage(ERROR(message, None)) else noop @@ -137,6 +192,4 @@ object StructuredTestingLogger { def trace(ctx: Map[String, String], t: Throwable)(message: => String): F[Unit] = if (traceEnabled) appendLogMessage(TRACE(message, t.some, ctx)) else noop } - } - } diff --git a/testing/shared/src/main/scala/org/typelevel/log4cats/testing/TestingLogger.scala b/testing/shared/src/main/scala/org/typelevel/log4cats/testing/TestingLogger.scala index 9ecbf070..fa80b363 100644 --- a/testing/shared/src/main/scala/org/typelevel/log4cats/testing/TestingLogger.scala +++ b/testing/shared/src/main/scala/org/typelevel/log4cats/testing/TestingLogger.scala @@ -16,9 +16,11 @@ package org.typelevel.log4cats.testing +import cats.data.Chain import org.typelevel.log4cats.SelfAwareLogger -import cats.effect.Sync -import cats.implicits._ +import cats.effect.{Ref, Sync} +import cats.syntax.all._ + import java.util.concurrent.atomic.AtomicReference import scala.annotation.tailrec @@ -46,6 +48,40 @@ object TestingLogger { infoEnabled: Boolean = true, warnEnabled: Boolean = true, errorEnabled: Boolean = true + ): TestingLogger[F] = + atomic[F]( + traceEnabled = traceEnabled, + debugEnabled = debugEnabled, + infoEnabled = infoEnabled, + warnEnabled = warnEnabled, + errorEnabled = errorEnabled + ) + + def ref[F[_]: Sync]( + traceEnabled: Boolean = true, + debugEnabled: Boolean = true, + infoEnabled: Boolean = true, + warnEnabled: Boolean = true, + errorEnabled: Boolean = true + ): F[TestingLogger[F]] = + Ref[F].empty[Chain[LogMessage]].map { ref => + make[F]( + traceEnabled = traceEnabled, + debugEnabled = debugEnabled, + infoEnabled = infoEnabled, + warnEnabled = warnEnabled, + errorEnabled = errorEnabled, + appendLogMessage = lm => ref.update(_.append(lm)), + read = () => ref.get.map(_.toVector) + ) + } + + def atomic[F[_]: Sync]( + traceEnabled: Boolean = true, + debugEnabled: Boolean = true, + infoEnabled: Boolean = true, + warnEnabled: Boolean = true, + errorEnabled: Boolean = true ): TestingLogger[F] = { val ar = new AtomicReference(Vector.empty[LogMessage]) def appendLogMessage(m: LogMessage): F[Unit] = Sync[F].delay { @@ -59,8 +95,28 @@ object TestingLogger { mod() } + make[F]( + traceEnabled = traceEnabled, + debugEnabled = debugEnabled, + infoEnabled = infoEnabled, + warnEnabled = warnEnabled, + errorEnabled = errorEnabled, + appendLogMessage = appendLogMessage, + read = () => Sync[F].delay(ar.get()) + ) + } + + def make[F[_]: Sync]( + traceEnabled: Boolean = true, + debugEnabled: Boolean = true, + infoEnabled: Boolean = true, + warnEnabled: Boolean = true, + errorEnabled: Boolean = true, + appendLogMessage: LogMessage => F[Unit], + read: () => F[Vector[LogMessage]] + ): TestingLogger[F] = new TestingLogger[F] { - def logged: F[Vector[LogMessage]] = Sync[F].delay(ar.get) + def logged: F[Vector[LogMessage]] = read() def isTraceEnabled: F[Boolean] = Sync[F].pure(traceEnabled) def isDebugEnabled: F[Boolean] = Sync[F].pure(debugEnabled) @@ -68,31 +124,32 @@ object TestingLogger { def isWarnEnabled: F[Boolean] = Sync[F].pure(warnEnabled) def isErrorEnabled: F[Boolean] = Sync[F].pure(errorEnabled) + private val noop = Sync[F].unit + def error(message: => String): F[Unit] = - if (errorEnabled) appendLogMessage(ERROR(message, None)) else Sync[F].pure(()) + if (errorEnabled) appendLogMessage(ERROR(message, None)) else noop def error(t: Throwable)(message: => String): F[Unit] = - if (errorEnabled) appendLogMessage(ERROR(message, t.some)) else Sync[F].pure(()) + if (errorEnabled) appendLogMessage(ERROR(message, t.some)) else noop def warn(message: => String): F[Unit] = - if (warnEnabled) appendLogMessage(WARN(message, None)) else Sync[F].pure(()) + if (warnEnabled) appendLogMessage(WARN(message, None)) else noop def warn(t: Throwable)(message: => String): F[Unit] = - if (warnEnabled) appendLogMessage(WARN(message, t.some)) else Sync[F].pure(()) + if (warnEnabled) appendLogMessage(WARN(message, t.some)) else noop def info(message: => String): F[Unit] = - if (infoEnabled) appendLogMessage(INFO(message, None)) else Sync[F].pure(()) + if (infoEnabled) appendLogMessage(INFO(message, None)) else noop def info(t: Throwable)(message: => String): F[Unit] = - if (infoEnabled) appendLogMessage(INFO(message, t.some)) else Sync[F].pure(()) + if (infoEnabled) appendLogMessage(INFO(message, t.some)) else noop def debug(message: => String): F[Unit] = - if (debugEnabled) appendLogMessage(DEBUG(message, None)) else Sync[F].pure(()) + if (debugEnabled) appendLogMessage(DEBUG(message, None)) else noop def debug(t: Throwable)(message: => String): F[Unit] = - if (debugEnabled) appendLogMessage(DEBUG(message, t.some)) else Sync[F].pure(()) + if (debugEnabled) appendLogMessage(DEBUG(message, t.some)) else noop def trace(message: => String): F[Unit] = - if (traceEnabled) appendLogMessage(TRACE(message, None)) else Sync[F].pure(()) + if (traceEnabled) appendLogMessage(TRACE(message, None)) else noop def trace(t: Throwable)(message: => String): F[Unit] = - if (traceEnabled) appendLogMessage(TRACE(message, t.some)) else Sync[F].pure(()) + if (traceEnabled) appendLogMessage(TRACE(message, t.some)) else noop } - } } diff --git a/testing/shared/src/main/scala/org/typelevel/log4cats/testing/TestingLoggerFactory.scala b/testing/shared/src/main/scala/org/typelevel/log4cats/testing/TestingLoggerFactory.scala new file mode 100644 index 00000000..c70477ce --- /dev/null +++ b/testing/shared/src/main/scala/org/typelevel/log4cats/testing/TestingLoggerFactory.scala @@ -0,0 +1,230 @@ +/* + * Copyright 2018 Typelevel + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.typelevel.log4cats.testing + +import cats.Show +import cats.data.Chain +import cats.effect.{Ref, Sync} +import cats.syntax.all._ +import org.typelevel.log4cats.extras.LogLevel +import org.typelevel.log4cats.testing.TestingLoggerFactory.LogMessage +import org.typelevel.log4cats.{LoggerFactory, SelfAwareStructuredLogger} + +import java.io.{PrintWriter, StringWriter} +import java.util.concurrent.atomic.AtomicReference +import scala.annotation.tailrec + +trait TestingLoggerFactory[F[_]] extends LoggerFactory[F] { + def logged: F[Vector[LogMessage]] +} +object TestingLoggerFactory { + + sealed trait LogMessage { + def loggerName: String + def ctx: Map[String, String] + def message: String + def throwOpt: Option[Throwable] + def level: LogLevel = this match { + case _: Trace => LogLevel.Trace + case _: Debug => LogLevel.Debug + case _: Info => LogLevel.Info + case _: Warn => LogLevel.Warn + case _: Error => LogLevel.Error + } + } + + final case class Trace( + loggerName: String, + message: String, + throwOpt: Option[Throwable], + ctx: Map[String, String] = Map.empty + ) extends LogMessage + final case class Debug( + loggerName: String, + message: String, + throwOpt: Option[Throwable], + ctx: Map[String, String] = Map.empty + ) extends LogMessage + final case class Info( + loggerName: String, + message: String, + throwOpt: Option[Throwable], + ctx: Map[String, String] = Map.empty + ) extends LogMessage + final case class Warn( + loggerName: String, + message: String, + throwOpt: Option[Throwable], + ctx: Map[String, String] = Map.empty + ) extends LogMessage + final case class Error( + loggerName: String, + message: String, + throwOpt: Option[Throwable], + ctx: Map[String, String] = Map.empty + ) extends LogMessage + + implicit val showMsg: Show[LogMessage] = Show.show { log => + val builder = new StringBuilder() + builder + .append(log.loggerName) + .append(" [") + .append(log match { + case _: Trace => "TRACE" + case _: Debug => "DEBUG" + case _: Info => "INFO" + case _: Warn => "WARN" + case _: Error => "ERROR" + }) + .append("] ") + .append(log.message) + log.throwOpt.foreach { t => + builder.append(" ") + val sw = new StringWriter() + val pw = new PrintWriter(sw) + t.printStackTrace(pw) + builder.append(sw) + pw.close() + } + if (log.ctx.nonEmpty) { + builder.append('\n') + } + log.ctx.foreach { case (k, v) => + builder.append(" ").append(k).append(':').append(v).append('\n') + } + builder.result() + } + + def ref[F[_]: Sync]( + traceEnabled: Boolean = true, + debugEnabled: Boolean = true, + infoEnabled: Boolean = true, + warnEnabled: Boolean = true, + errorEnabled: Boolean = true + ): F[TestingLoggerFactory[F]] = + Ref[F].empty[Chain[LogMessage]].map { ref => + make[F]( + traceEnabled = traceEnabled, + debugEnabled = debugEnabled, + infoEnabled = infoEnabled, + warnEnabled = warnEnabled, + errorEnabled = errorEnabled, + save = lm => ref.update(_.append(lm)), + read = () => ref.get.map(_.toVector) + ) + } + + def atomic[F[_]: Sync]( + traceEnabled: Boolean = true, + debugEnabled: Boolean = true, + infoEnabled: Boolean = true, + warnEnabled: Boolean = true, + errorEnabled: Boolean = true + ): TestingLoggerFactory[F] = { + val ar = new AtomicReference(Vector.empty[LogMessage]) + def appendLogMessage(m: LogMessage): F[Unit] = Sync[F].delay { + @tailrec + def mod(): Unit = { + val c = ar.get + val u = c :+ m + if (!ar.compareAndSet(c, u)) mod() + else () + } + mod() + } + + make[F]( + traceEnabled = traceEnabled, + debugEnabled = debugEnabled, + infoEnabled = infoEnabled, + warnEnabled = warnEnabled, + errorEnabled = errorEnabled, + save = appendLogMessage, + read = () => Sync[F].delay(ar.get()) + ) + } + + def make[F[_]: Sync]( + traceEnabled: Boolean = true, + debugEnabled: Boolean = true, + infoEnabled: Boolean = true, + warnEnabled: Boolean = true, + errorEnabled: Boolean = true, + save: LogMessage => F[Unit], + read: () => F[Vector[LogMessage]] + ): TestingLoggerFactory[F] = + new TestingLoggerFactory[F] { + override def logged: F[Vector[LogMessage]] = read() + override def fromName(name: String): F[SelfAwareStructuredLogger[F]] = + Sync[F].delay(getLoggerFromName(name)) + override def getLoggerFromName(name: String): SelfAwareStructuredLogger[F] = + new SelfAwareStructuredLogger[F] { + override val isTraceEnabled: F[Boolean] = traceEnabled.pure[F] + override val isDebugEnabled: F[Boolean] = debugEnabled.pure[F] + override val isInfoEnabled: F[Boolean] = infoEnabled.pure[F] + override val isWarnEnabled: F[Boolean] = warnEnabled.pure[F] + override val isErrorEnabled: F[Boolean] = errorEnabled.pure[F] + + private val noop = Sync[F].unit + + override def trace(ctx: Map[String, String])(msg: => String): F[Unit] = + if (traceEnabled) save(Trace(name, msg, none, ctx)) else noop + override def debug(ctx: Map[String, String])(msg: => String): F[Unit] = + if (debugEnabled) save(Debug(name, msg, none, ctx)) else noop + override def info(ctx: Map[String, String])(msg: => String): F[Unit] = + if (infoEnabled) save(Info(name, msg, none, ctx)) else noop + override def warn(ctx: Map[String, String])(msg: => String): F[Unit] = + if (warnEnabled) save(Warn(name, msg, none, ctx)) else noop + override def error(ctx: Map[String, String])(msg: => String): F[Unit] = + if (errorEnabled) save(Error(name, msg, none, ctx)) else noop + + override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + if (traceEnabled) save(Trace(name, msg, t.some, ctx)) else noop + override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + if (debugEnabled) save(Debug(name, msg, t.some, ctx)) else noop + override def info(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + if (infoEnabled) save(Info(name, msg, t.some, ctx)) else noop + override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + if (warnEnabled) save(Warn(name, msg, t.some, ctx)) else noop + override def error(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] = + if (errorEnabled) save(Error(name, msg, t.some, ctx)) else noop + + override def trace(t: Throwable)(msg: => String): F[Unit] = + if (traceEnabled) save(Trace(name, msg, t.some, Map.empty)) else noop + override def debug(t: Throwable)(msg: => String): F[Unit] = + if (debugEnabled) save(Debug(name, msg, t.some, Map.empty)) else noop + override def info(t: Throwable)(msg: => String): F[Unit] = + if (infoEnabled) save(Info(name, msg, t.some, Map.empty)) else noop + override def warn(t: Throwable)(msg: => String): F[Unit] = + if (warnEnabled) save(Warn(name, msg, t.some, Map.empty)) else noop + override def error(t: Throwable)(msg: => String): F[Unit] = + if (errorEnabled) save(Error(name, msg, t.some, Map.empty)) else noop + + override def trace(msg: => String): F[Unit] = + if (traceEnabled) save(Trace(name, msg, none, Map.empty)) else noop + override def debug(msg: => String): F[Unit] = + if (debugEnabled) save(Debug(name, msg, none, Map.empty)) else noop + override def info(msg: => String): F[Unit] = + if (infoEnabled) save(Info(name, msg, none, Map.empty)) else noop + override def warn(msg: => String): F[Unit] = + if (warnEnabled) save(Warn(name, msg, none, Map.empty)) else noop + override def error(msg: => String): F[Unit] = + if (errorEnabled) save(Error(name, msg, none, Map.empty)) else noop + } + + } +} diff --git a/testing/shared/src/test/scala/org/typelevel/log4cats/extras/DeferredLoggerFactoryTest.scala b/testing/shared/src/test/scala/org/typelevel/log4cats/extras/DeferredLoggerFactoryTest.scala new file mode 100644 index 00000000..9e8bb814 --- /dev/null +++ b/testing/shared/src/test/scala/org/typelevel/log4cats/extras/DeferredLoggerFactoryTest.scala @@ -0,0 +1,471 @@ +/* + * Copyright 2018 Typelevel + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.typelevel.log4cats.extras + +import cats.Order +import cats.arrow.FunctionK +import cats.data.NonEmptyList +import cats.effect.IO +import cats.syntax.all._ +import org.typelevel.log4cats.SelfAwareStructuredLogger +import org.typelevel.log4cats.testing.TestingLoggerFactory +import org.typelevel.log4cats.testing.TestingLoggerFactory.{ + Debug, + Error, + Info, + LogMessage as TestLogMessage, + Trace, + Warn +} +import org.typelevel.scalaccompat.annotation.nowarn + +@nowarn("msg=dead code following this construct") +class DeferredLoggerFactoryTest extends munit.CatsEffectSuite { + test( + "DeferredLoggerFactory should not log messages by default when code completes without raising an error" + ) { + val testLoggerFactory = TestingLoggerFactory.atomic[IO]() + DeferredLoggerFactory(testLoggerFactory) + .use { loggerFactory => + def test(logger: SelfAwareStructuredLogger[IO]): IO[Unit] = + for { + _ <- logger.info("Test Message 0") + _ <- testLoggerFactory.logged.assertEquals(Vector.empty) + _ <- logger.warn("Test Message 1") + _ <- testLoggerFactory.logged.assertEquals(Vector.empty) + } yield () + + ( + test(loggerFactory.getLoggerFromName("Logger 1")), + test(loggerFactory.getLoggerFromName("Logger 2")) + ).parTupled.void + } + .assert + .flatMap(_ => testLoggerFactory.logged) + .assertEquals(Vector.empty) + } + + test( + "DeferredLoggerFactory should provide the means to log messages when code completes without raising an error" + ) { + val testLoggerFactory = TestingLoggerFactory.atomic[IO]() + DeferredLoggerFactory(testLoggerFactory) + .use { loggerFactory => + val loggerName = "Test Logger" + val logger = loggerFactory.getLoggerFromName(loggerName) + for { + _ <- logger.trace("Test Message 0") + _ <- logger.debug("Test Message 1") + _ <- logger.info("Test Message 2") + _ <- testLoggerFactory.logged.assertEquals( + Vector.empty, + clue("Checking that logging is deferred") + ) + _ <- loggerFactory.log + _ <- testLoggerFactory.logged.assertEquals( + Vector( + Trace(loggerName, "Test Message 0", none), + Debug(loggerName, "Test Message 1", none), + Info(loggerName, "Test Message 2", none) + ), + clue("Checking that logs were sent to test logger") + ) + _ <- loggerFactory.log + _ <- testLoggerFactory.logged.assertEquals( + Vector( + Trace(loggerName, "Test Message 0", none), + Debug(loggerName, "Test Message 1", none), + Info(loggerName, "Test Message 2", none) + ), + clue("Checking for duplicate logging") + ) + _ <- logger.warn("Test Message 3") + _ <- logger.error("Test Message 4") + _ <- testLoggerFactory.logged.assertEquals( + Vector( + Trace(loggerName, "Test Message 0", none), + Debug(loggerName, "Test Message 1", none), + Info(loggerName, "Test Message 2", none) + ), + clue("Verifying that calling #log does not make the logger eager") + ) + _ <- loggerFactory.log + _ <- testLoggerFactory.logged.assertEquals( + Vector( + Trace(loggerName, "Test Message 0", none), + Debug(loggerName, "Test Message 1", none), + Info(loggerName, "Test Message 2", none), + Warn(loggerName, "Test Message 3", none), + Error(loggerName, "Test Message 4", none) + ) + ) + } yield () + } + .assert + .flatMap(_ => testLoggerFactory.logged) + .assertEquals( + Vector( + Trace("Test Logger", "Test Message 0", none), + Debug("Test Logger", "Test Message 1", none), + Info("Test Logger", "Test Message 2", none), + Warn("Test Logger", "Test Message 3", none), + Error("Test Logger", "Test Message 4", none) + ) + ) + } + + test("DeferredLoggerFactory should log messages from all loggers when logging is requested") { + val testLoggerFactory = TestingLoggerFactory.atomic[IO]() + DeferredLoggerFactory(testLoggerFactory) + .use { loggerFactory => + def logStuff(logger: SelfAwareStructuredLogger[IO]): IO[Unit] = + for { + _ <- logger.trace("Test Message") + _ <- logger.warn("Test Message") + } yield () + + (0 until 5).toVector + .parTraverse_ { idx => + logStuff(loggerFactory.getLoggerFromName(s"Logger $idx")) + } + .flatTap(_ => loggerFactory.log) + } + .assert + .flatMap(_ => testLoggerFactory.logged) + .map( + _.sorted( + Order + .whenEqual[TestLogMessage]( + Order.by(_.loggerName), + Order.by(_.level) + ) + .toOrdering + ) + ) + .assertEquals( + Vector( + Trace("Logger 0", "Test Message", None, Map.empty), + Warn("Logger 0", "Test Message", None, Map.empty), + Trace("Logger 1", "Test Message", None, Map.empty), + Warn("Logger 1", "Test Message", None, Map.empty), + Trace("Logger 2", "Test Message", None, Map.empty), + Warn("Logger 2", "Test Message", None, Map.empty), + Trace("Logger 3", "Test Message", None, Map.empty), + Warn("Logger 3", "Test Message", None, Map.empty), + Trace("Logger 4", "Test Message", None, Map.empty), + Warn("Logger 4", "Test Message", None, Map.empty) + ) + ) + } + + test("DeferredLoggerFactory should not lose log messages when an exception is raised") { + val testLoggerFactory = TestingLoggerFactory.atomic[IO]() + DeferredLoggerFactory(testLoggerFactory) + .use { loggerFactory => + val happyPath = + for { + logger <- loggerFactory.fromName("Happy Path") + _ <- logger.info("Test Message 1") + _ <- logger.debug("Test Message 2") + } yield () + + val sadPath0 = + for { + logger <- loggerFactory.fromName("Sad Path 0") + _ <- logger.info("Test Message") + _ <- testLoggerFactory.logged.assertEquals(Vector.empty) + _ <- IO.raiseError(new RuntimeException("Expected Exception 0")) + } yield () + + val sadPath1 = + for { + logger <- loggerFactory.fromName("Sad Path 1") + _ <- logger.warn("Test Message 1") + _ <- logger.error("Test Message 2") + _ <- testLoggerFactory.logged.assertEquals(Vector.empty) + _ <- IO.raiseError(new RuntimeException("Expected Exception 1")) + } yield () + + ( + sadPath0.attempt.map(_.toValidatedNel), + happyPath.attempt.map(_.toValidatedNel), + sadPath1.attempt.map(_.toValidatedNel) + ).parMapN(_ combine _ combine _).flatTap(_ => loggerFactory.log) + } + .flatTap(value => + IO.delay { + assertEquals( + value.leftMap(_.map(_.getMessage)), + NonEmptyList + .of( + "Expected Exception 0", + "Expected Exception 1" + ) + .invalid, + clue(value) + ) + } + ) + .flatMap(_ => testLoggerFactory.logged) + // Have to sort because of the parTupled + .map(_.sortBy(l => l.loggerName -> l.message)) + .assertEquals( + Vector( + Info("Happy Path", "Test Message 1", None, Map.empty), + Debug("Happy Path", "Test Message 2", None, Map.empty), + Info("Sad Path 0", "Test Message", None, Map.empty), + Warn("Sad Path 1", "Test Message 1", None, Map.empty), + Error("Sad Path 1", "Test Message 2", None, Map.empty) + ) + ) + } + + test("DeferredLoggerFactory should not duplicate log messages when an exception is raised") { + TestingLoggerFactory + .ref[IO]() + .flatMap { testLoggerFactory => + DeferredLoggerFactory(testLoggerFactory) + .use { loggerFactory => + val happyPath = + for { + logger <- loggerFactory.fromName("Happy Path") + _ <- logger.info("Test Message 1") + _ <- logger.debug("Test Message 2") + _ <- loggerFactory.log + } yield () + + val sadPath0 = + for { + logger <- loggerFactory.fromName("Sad Path 0") + _ <- logger.info("Test Message") + _ <- IO.raiseError(new RuntimeException("Expected Exception 0")) + } yield () + + val sadPath1 = + for { + logger <- loggerFactory.fromName("Sad Path 1") + _ <- logger.warn("Test Message 1") + _ <- loggerFactory.log + _ <- logger.error("Test Message 2") + _ <- IO.raiseError(new RuntimeException("Expected Exception 1")) + } yield () + + ( + sadPath0.attempt.map(_.toValidatedNel), + happyPath.attempt.map(_.toValidatedNel), + sadPath1.attempt.map(_.toValidatedNel) + ).parMapN(_ combine _ combine _) + .flatTap(_ => loggerFactory.log) + } + .flatTap(value => + IO.delay { + assertEquals( + value.leftMap(_.map(_.getMessage)), + NonEmptyList + .of( + "Expected Exception 0", + "Expected Exception 1" + ) + .invalid, + clue(value) + ) + } + ) + .flatMap(_ => testLoggerFactory.logged) + } + // Have to sort because of the parTupled + .map(_.sortBy(l => l.loggerName -> l.message)) + .assertEquals( + Vector( + Info("Happy Path", "Test Message 1", None, Map.empty), + Debug("Happy Path", "Test Message 2", None, Map.empty), + Info("Sad Path 0", "Test Message", None, Map.empty), + Warn("Sad Path 1", "Test Message 1", None, Map.empty), + Error("Sad Path 1", "Test Message 2", None, Map.empty) + ) + ) + } + + test("DeferredLoggerFactory should respect log levels") { + val testLoggerFactory = TestingLoggerFactory.atomic[IO]( + debugEnabled = false + ) + DeferredLoggerFactory(testLoggerFactory).use { loggerFactory => + val loggerName = "Test Logger" + val logger = loggerFactory.getLoggerFromName(loggerName) + for { + _ <- logger.trace("Test Message 0") + _ <- logger.debug("Test Message 1") + _ <- logger.info("Test Message 2") + _ <- testLoggerFactory.logged.assertEquals( + Vector.empty, + clue("Checking that logging is deferred") + ) + _ <- loggerFactory.inspect + .map(_.toVector) + .assertEquals( + Vector( + DeferredLogMessage.trace(Map.empty, none, () => "Test Message 0"), + DeferredLogMessage.info(Map.empty, none, () => "Test Message 2") + ), + clue("Checking that the debug message was not buffered") + ) + _ <- loggerFactory.log + _ <- testLoggerFactory.logged.assertEquals( + Vector( + Trace(loggerName, "Test Message 0", none), + Info(loggerName, "Test Message 2", none) + ), + clue("Checking that logs were sent to test logger") + ) + } yield () + }.assert + } + + test("DeferredLoggerFactory doesn't lose the ability to log when message is modified") { + val testLoggerFactory = TestingLoggerFactory.atomic[IO]() + DeferredLoggerFactory(testLoggerFactory) + .map(_.withModifiedString(msg => s"[DLF]$msg")) + .use { loggerFactory => + def logStuff(logger: SelfAwareStructuredLogger[IO]): IO[Unit] = + for { + _ <- logger.trace("Test Message") + _ <- logger.withModifiedString(msg => s"[DSL]$msg").warn("Test Message") + } yield () + + (0 until 5).toVector + .parTraverse_ { idx => + logStuff(loggerFactory.getLoggerFromName(s"Logger $idx")) + } + .flatTap(_ => loggerFactory.log) + } + .assert + .flatMap(_ => testLoggerFactory.logged) + .map( + _.sorted( + Order + .whenEqual[TestLogMessage]( + Order.by(_.loggerName), + Order.by(_.level) + ) + .toOrdering + ) + ) + .assertEquals( + Vector( + Trace("Logger 0", "[DLF]Test Message", None, Map.empty), + Warn("Logger 0", "[DLF][DSL]Test Message", None, Map.empty), + Trace("Logger 1", "[DLF]Test Message", None, Map.empty), + Warn("Logger 1", "[DLF][DSL]Test Message", None, Map.empty), + Trace("Logger 2", "[DLF]Test Message", None, Map.empty), + Warn("Logger 2", "[DLF][DSL]Test Message", None, Map.empty), + Trace("Logger 3", "[DLF]Test Message", None, Map.empty), + Warn("Logger 3", "[DLF][DSL]Test Message", None, Map.empty), + Trace("Logger 4", "[DLF]Test Message", None, Map.empty), + Warn("Logger 4", "[DLF][DSL]Test Message", None, Map.empty) + ) + ) + } + + test("DeferredLoggerFactory doesn't lose the ability to log when mapK is called") { + val testLoggerFactory = TestingLoggerFactory.atomic[IO]() + DeferredLoggerFactory(testLoggerFactory) + .map(_.mapK(FunctionK.id[IO])) + .use { loggerFactory => + val logger = loggerFactory.getLoggerFromName("Test Logger") + for { + _ <- logger.trace("Test Message 0") + _ <- logger.debug("Test Message 1") + _ <- logger.info("Test Message 2") + _ <- testLoggerFactory.logged.assertEquals( + Vector.empty, + clue("Checking that logging is deferred") + ) + _ <- loggerFactory.log + } yield () + } + .assert + .flatMap(_ => testLoggerFactory.logged) + .assertEquals( + Vector( + Trace("Test Logger", "Test Message 0", none), + Debug("Test Logger", "Test Message 1", none), + Info("Test Logger", "Test Message 2", none) + ) + ) + } + + test("DeferredLoggerFactory doesn't lose the ability to log when context is added") { + val testLoggerFactory = TestingLoggerFactory.atomic[IO]() + val factoryCtx = List("factory" -> "added").toMap + def loggerCtx(idx: Int) = List(s"logger $idx" -> "added").toMap + def msgCtx(idx: Int) = List(s"log $idx" -> "added").toMap + DeferredLoggerFactory(testLoggerFactory) + .map(_.addContext(factoryCtx)) + .use { loggerFactory => + (0 until 5).toVector + .parTraverse_ { idx => + loggerFactory + .getLoggerFromName(s"Logger $idx") + .addContext(loggerCtx(idx)) + .trace(msgCtx(idx))("Test Message") + } + .flatTap(_ => loggerFactory.log) + } + .assert + .flatMap(_ => testLoggerFactory.logged) + .map( + _.sorted( + Order + .whenEqual[TestLogMessage]( + Order.by(_.loggerName), + Order.by(_.level) + ) + .toOrdering + ) + ) + .assertEquals( + Vector( + Trace( + "Logger 0", + "Test Message", + None, + factoryCtx ++ loggerCtx(0) ++ msgCtx(0) + ), + Trace( + "Logger 1", + "Test Message", + None, + factoryCtx ++ loggerCtx(1) ++ msgCtx(1) + ), + Trace( + "Logger 2", + "Test Message", + None, + factoryCtx ++ loggerCtx(2) ++ msgCtx(2) + ), + Trace( + "Logger 3", + "Test Message", + None, + factoryCtx ++ loggerCtx(3) ++ msgCtx(3) + ), + Trace("Logger 4", "Test Message", None, factoryCtx ++ loggerCtx(4) ++ msgCtx(4)) + ) + ) + } +} diff --git a/testing/shared/src/test/scala/org/typelevel/log4cats/extras/DeferredLoggerTest.scala b/testing/shared/src/test/scala/org/typelevel/log4cats/extras/DeferredLoggerTest.scala new file mode 100644 index 00000000..16d1f205 --- /dev/null +++ b/testing/shared/src/test/scala/org/typelevel/log4cats/extras/DeferredLoggerTest.scala @@ -0,0 +1,191 @@ +/* + * Copyright 2018 Typelevel + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.typelevel.log4cats.extras + +import cats.arrow.FunctionK +import cats.effect.IO +import cats.syntax.all._ +import org.typelevel.log4cats.testing.TestingLogger +import org.typelevel.scalaccompat.annotation.nowarn + +@nowarn("msg=dead code following this construct") +class DeferredLoggerTest extends munit.CatsEffectSuite { + test( + "DeferredLogger should not log messages by default when code completes without raising an error" + ) { + val testLogger = TestingLogger.impl[IO]() + DeferredLogger(testLogger) + .use { logger => + for { + _ <- logger.info("Test Message 0") + _ <- testLogger.logged.assertEquals(Vector.empty) + _ <- logger.warn("Test Message 1") + _ <- testLogger.logged.assertEquals(Vector.empty) + } yield () + } + .assertEquals(()) + .flatMap(_ => testLogger.logged) + .assertEquals(Vector.empty) + } + + test( + "DeferredLogger should provide the means to log messages when code completes without raising an error" + ) { + val testLogger = TestingLogger.impl[IO]() + DeferredLogger(testLogger) + .use { logger => + for { + _ <- logger.trace("Test Message 0") + _ <- logger.debug("Test Message 1") + _ <- logger.info("Test Message 2") + _ <- testLogger.logged.assertEquals( + Vector.empty, + clue("Checking that logging is deferred") + ) + _ <- logger.log + _ <- testLogger.logged.assertEquals( + Vector( + TestingLogger.TRACE("Test Message 0", none), + TestingLogger.DEBUG("Test Message 1", none), + TestingLogger.INFO("Test Message 2", none) + ), + clue("Checking that logs were sent to test logger") + ) + _ <- logger.log + _ <- testLogger.logged.assertEquals( + Vector( + TestingLogger.TRACE("Test Message 0", none), + TestingLogger.DEBUG("Test Message 1", none), + TestingLogger.INFO("Test Message 2", none) + ), + clue("Checking for duplicate logging") + ) + _ <- logger.warn("Test Message 3") + _ <- logger.error("Test Message 4") + _ <- testLogger.logged.assertEquals( + Vector( + TestingLogger.TRACE("Test Message 0", none), + TestingLogger.DEBUG("Test Message 1", none), + TestingLogger.INFO("Test Message 2", none) + ), + clue("Verifying that calling #log does not make the logger eager") + ) + _ <- logger.log + _ <- testLogger.logged.assertEquals( + Vector( + TestingLogger.TRACE("Test Message 0", none), + TestingLogger.DEBUG("Test Message 1", none), + TestingLogger.INFO("Test Message 2", none), + TestingLogger.WARN("Test Message 3", none), + TestingLogger.ERROR("Test Message 4", none) + ) + ) + } yield () + } + .assertEquals(()) + .flatMap(_ => testLogger.logged) + .assertEquals( + Vector( + TestingLogger.TRACE("Test Message 0", none), + TestingLogger.DEBUG("Test Message 1", none), + TestingLogger.INFO("Test Message 2", none), + TestingLogger.WARN("Test Message 3", none), + TestingLogger.ERROR("Test Message 4", none) + ) + ) + } + + test("DeferredLogger should not lose log messages when an exception is raised") { + val testLogger = TestingLogger.impl[IO]() + DeferredLogger(testLogger) + .use { logger => + for { + _ <- logger.info("Test Message") + _ <- testLogger.logged.assertEquals(Vector.empty) + _ <- IO.raiseError(new RuntimeException("Expected Exception")) + } yield () + } + .attempt + .map(_.leftMap(_.getMessage)) + .assertEquals(Left("Expected Exception")) + .flatMap(_ => testLogger.logged) + .assertEquals(Vector(TestingLogger.INFO("Test Message", none))) + } + + test("DeferredLogger should not duplicate log messages when an exception is raised") { + val testLogger = TestingLogger.impl[IO]() + DeferredLogger(testLogger) + .use { logger => + for { + _ <- logger.trace("Test Message 0") + _ <- testLogger.logged.assertEquals(Vector.empty) + _ <- logger.log + _ <- testLogger.logged.assertEquals(Vector(TestingLogger.TRACE("Test Message 0", none))) + _ <- logger.info("Test Message 1") + _ <- IO.raiseError(new RuntimeException("Expected Exception")) + } yield () + } + .attempt + .map(_.leftMap(_.getMessage)) + .assertEquals(Left("Expected Exception")) + .flatMap(_ => testLogger.logged) + .assertEquals( + Vector( + TestingLogger.TRACE("Test Message 0", none), + TestingLogger.INFO("Test Message 1", none) + ) + ) + } + + test("DeferredLogger doesn't lose the ability to log when message is modified") { + val testLogger = TestingLogger.impl[IO]() + DeferredLogger(testLogger) + .map(_.withModifiedString(_.toUpperCase)) + .use { logger => + for { + _ <- logger.trace("Test Message") + _ <- testLogger.logged.assertEquals( + Vector.empty, + clue("Checking that logging is deferred") + ) + _ <- logger.log + } yield () + } + .assertEquals(()) + .flatMap(_ => testLogger.logged) + .assertEquals(Vector(TestingLogger.TRACE("TEST MESSAGE", none))) + } + + test("DeferredLogger doesn't lose the ability to log when mapK is called") { + val testLogger = TestingLogger.impl[IO]() + DeferredLogger(testLogger) + .map(_.mapK[IO](FunctionK.id[IO])) + .use { logger => + for { + _ <- logger.trace("Test Message") + _ <- testLogger.logged.assertEquals( + Vector.empty, + clue("Checking that logging is deferred") + ) + _ <- logger.log + } yield () + } + .assertEquals(()) + .flatMap(_ => testLogger.logged) + .assertEquals(Vector(TestingLogger.TRACE("Test Message", none))) + } +} diff --git a/testing/shared/src/test/scala/org/typelevel/log4cats/extras/DeferredStructuredLoggerTest.scala b/testing/shared/src/test/scala/org/typelevel/log4cats/extras/DeferredStructuredLoggerTest.scala new file mode 100644 index 00000000..d3933641 --- /dev/null +++ b/testing/shared/src/test/scala/org/typelevel/log4cats/extras/DeferredStructuredLoggerTest.scala @@ -0,0 +1,213 @@ +/* + * Copyright 2018 Typelevel + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.typelevel.log4cats.extras + +import cats.arrow.FunctionK +import cats.effect.IO +import cats.syntax.all._ +import org.typelevel.log4cats.testing.StructuredTestingLogger +import org.typelevel.scalaccompat.annotation.nowarn + +@nowarn("msg=dead code following this construct") +class DeferredStructuredLoggerTest extends munit.CatsEffectSuite { + test( + "DeferredStructuredLogger should not log messages by default when code completes without raising an error" + ) { + val testLogger = StructuredTestingLogger.impl[IO]() + DeferredStructuredLogger(testLogger) + .use { logger => + for { + _ <- logger.info("Test Message 0") + _ <- testLogger.logged.assertEquals(Vector.empty) + _ <- logger.warn("Test Message 1") + _ <- testLogger.logged.assertEquals(Vector.empty) + } yield () + } + .assert + .flatMap(_ => testLogger.logged) + .assertEquals(Vector.empty) + } + + test( + "DeferredStructuredLogger should provide the means to log messages when code completes without raising an error" + ) { + val testLogger = StructuredTestingLogger.impl[IO]() + DeferredStructuredLogger(testLogger) + .use { logger => + for { + _ <- logger.trace("Test Message 0") + _ <- logger.debug("Test Message 1") + _ <- logger.info("Test Message 2") + _ <- testLogger.logged.assertEquals( + Vector.empty, + clue("Checking that logging is deferred") + ) + _ <- logger.log + _ <- testLogger.logged.assertEquals( + Vector( + StructuredTestingLogger.TRACE("Test Message 0", none), + StructuredTestingLogger.DEBUG("Test Message 1", none), + StructuredTestingLogger.INFO("Test Message 2", none) + ), + clue("Checking that logs were sent to test logger") + ) + _ <- logger.log + _ <- testLogger.logged.assertEquals( + Vector( + StructuredTestingLogger.TRACE("Test Message 0", none), + StructuredTestingLogger.DEBUG("Test Message 1", none), + StructuredTestingLogger.INFO("Test Message 2", none) + ), + clue("Checking for duplicate logging") + ) + _ <- logger.warn("Test Message 3") + _ <- logger.error("Test Message 4") + _ <- testLogger.logged.assertEquals( + Vector( + StructuredTestingLogger.TRACE("Test Message 0", none), + StructuredTestingLogger.DEBUG("Test Message 1", none), + StructuredTestingLogger.INFO("Test Message 2", none) + ), + clue("Verifying that calling #log does not make the logger eager") + ) + _ <- logger.log + _ <- testLogger.logged.assertEquals( + Vector( + StructuredTestingLogger.TRACE("Test Message 0", none), + StructuredTestingLogger.DEBUG("Test Message 1", none), + StructuredTestingLogger.INFO("Test Message 2", none), + StructuredTestingLogger.WARN("Test Message 3", none), + StructuredTestingLogger.ERROR("Test Message 4", none) + ) + ) + } yield () + } + .assert + .flatMap(_ => testLogger.logged) + .assertEquals( + Vector( + StructuredTestingLogger.TRACE("Test Message 0", none), + StructuredTestingLogger.DEBUG("Test Message 1", none), + StructuredTestingLogger.INFO("Test Message 2", none), + StructuredTestingLogger.WARN("Test Message 3", none), + StructuredTestingLogger.ERROR("Test Message 4", none) + ) + ) + } + + test("DeferredStructuredLogger should not lose log messages when an exception is raised") { + val testLogger = StructuredTestingLogger.impl[IO]() + DeferredStructuredLogger(testLogger) + .use { logger => + for { + _ <- logger.info("Test Message") + _ <- testLogger.logged.assertEquals(Vector.empty) + _ <- IO.raiseError(new RuntimeException("Expected Exception")) + } yield () + } + .attempt + .map(_.leftMap(_.getMessage)) + .assertEquals(Left("Expected Exception")) + .flatMap(_ => testLogger.logged) + .assertEquals(Vector(StructuredTestingLogger.INFO("Test Message", none))) + } + + test("DeferredStructuredLogger should not duplicate log messages when an exception is raised") { + val testLogger = StructuredTestingLogger.impl[IO]() + DeferredStructuredLogger(testLogger) + .use { logger => + for { + _ <- logger.trace("Test Message 0") + _ <- testLogger.logged.assertEquals(Vector.empty) + _ <- logger.log + _ <- testLogger.logged.assertEquals( + Vector(StructuredTestingLogger.TRACE("Test Message 0", none)) + ) + _ <- logger.info("Test Message 1") + _ <- IO.raiseError(new RuntimeException("Expected Exception")) + } yield () + } + .attempt + .map(_.leftMap(_.getMessage)) + .assertEquals(Left("Expected Exception")) + .flatMap(_ => testLogger.logged) + .assertEquals( + Vector( + StructuredTestingLogger.TRACE("Test Message 0", none), + StructuredTestingLogger.INFO("Test Message 1", none) + ) + ) + } + + test("DeferredStructuredLogger doesn't lose the ability to log when message is modified") { + val testLogger = StructuredTestingLogger.impl[IO]() + DeferredStructuredLogger(testLogger) + .map(_.withModifiedString(_.toUpperCase)) + .use { logger => + for { + _ <- logger.trace("Test Message") + _ <- testLogger.logged.assertEquals( + Vector.empty, + clue("Checking that logging is deferred") + ) + _ <- logger.log + } yield () + } + .assertEquals(()) + .flatMap(_ => testLogger.logged) + .assertEquals(Vector(StructuredTestingLogger.TRACE("TEST MESSAGE", none))) + } + + test("DeferredStructuredLogger doesn't lose the ability to log when mapK is called") { + val testLogger = StructuredTestingLogger.impl[IO]() + DeferredStructuredLogger(testLogger) + .map(_.mapK[IO](FunctionK.id[IO])) + .use { logger => + for { + _ <- logger.trace("Test Message") + _ <- testLogger.logged.assertEquals( + Vector.empty, + clue("Checking that logging is deferred") + ) + _ <- logger.log + } yield () + } + .assertEquals(()) + .flatMap(_ => testLogger.logged) + .assertEquals(Vector(StructuredTestingLogger.TRACE("Test Message", none))) + } + + test("DeferredStructuredLogger doesn't lose the ability to log when context is added") { + val testLogger = StructuredTestingLogger.impl[IO]() + val context = List("test" -> "context").toMap + DeferredStructuredLogger(testLogger) + .map(_.addContext(context)) + .use { logger => + for { + _ <- logger.trace("Test Message") + _ <- testLogger.logged.assertEquals( + Vector.empty, + clue("Checking that logging is deferred") + ) + _ <- logger.log + } yield () + } + .assertEquals(()) + .flatMap(_ => testLogger.logged) + .assertEquals(Vector(StructuredTestingLogger.TRACE("Test Message", none, context))) + } +}