search

zio / zio-logging

Powerful logging for ZIO 2.0 applications, with compatibility with many logging backends out-of-the-box.
https://zio.dev/zio-logging/
Apache License 2.0
174 stars 81 forks source link

Every exceptions logged as FiberFailure #891

Open leejaeseung opened 6 days ago

leejaeseung commented 6 days ago

related with https://github.com/zio/zio-logging/pull/811

Hi, I recently upgraded this library version from 2.1.12 to 2.3.1. After upgrade, every error log’s root exception was changed to FiberFailure. (And so our every error alert turn to FiberFailure - using sentry)

It’s because this code (v2.12.2)

override def appendCause(cause: Cause[Any]): Unit = {
  if (!cause.isEmpty) {
    val maybeThrowable = (cause.failures.collect { case t: Throwable => t } ++ cause.defects).headOption
    maybeThrowable match {
      case Some(t) => throwable = t
      case None    => throwable = FiberFailure(cause)
    }
  }
  ()
}

changed to (v2.3.1)

val causeToThrowableDefault: Cause[Any] => Option[Throwable] = cause =>
  if (cause.isEmpty) {
    None
  } else {
    Some(FiberFailure(cause)) // here
  }

override def appendCause(cause: Cause[Any]): Unit = {
  throwable = causeToThrowable(cause).orNull
  ()
}

FiberFailure’s desciption :

This could be caused by some non-recoverable error, such as a defect or system error, by some typed error, or by interruption

I think some failures in cause are not case of FiberFailure. (it’s recoverable)

So i think the extracting cause’s failures code should put into where cause is not empty. Like this :

val causeToThrowableDefault: Cause[Any] => Option[Throwable] = cause =>
  if (cause.isEmpty) {
    None
  } else {
    val maybeThrowable = (cause.failures.collect { case t: Throwable => t } ++ cause.defects).headOption
    maybeThrowable.orElse(Some(FiberFailure(cause)))
  }

override def appendCause(cause: Cause[Any]): Unit = {
  throwable = causeToThrowable(cause).orNull
  ()
}

If I missed something, please correct me. thanks :)

justcoon commented 5 days ago

Hello @leejaeseung,

It is like you mentioning, every exception is wrapped with zio.FiberFailure (https://github.com/zio/zio-logging/pull/811)

This was made for one reason, to have proper stack traces ZIO together with java code

package zio.logging.example

object Test {

  def foo(): Unit =
    bar()

  private def bar(): Unit =
    doe()

  private def doe(): Unit =
    throw new RuntimeException("test doe")
}

package zio.logging.example

import zio._
import zio.logging.backend.SLF4J

object Example2 extends ZIOAppDefault {

  override val bootstrap: ZLayer[ZIOAppArgs, Any, Environment] =
    Runtime.removeDefaultLoggers >>> SLF4J.slf4j

  def foo: ZIO[Any, Throwable, Unit] =
    for {
      _ <- bar
    } yield ()

  def bar: ZIO[Any, Throwable, Unit] =
    for {
      _ <- baz
    } yield ()

  def baz: ZIO[Any, Throwable, Unit] =
    ZIO.attempt(Test.foo())

  val run: ZIO[Any, Throwable, Unit] =
    foo.tapErrorCause(cause => ZIO.logErrorCause("ERROR", cause))
}

where log output (with current zio-logging version) will be

08:43:43.853 [ZScheduler-Worker-3] [] ERROR zio-slf4j-logger 
zio.FiberFailure: test doe
    at zio.logging.example.Test$.doe(Test.scala:12)
    at zio.logging.example.Test$.bar(Test.scala:9)
    at zio.logging.example.Test$.foo(Test.scala:6)
    at zio.logging.example.Example2$.$anonfun$baz$1(Example2.scala:22)
    at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
    at zio.ZIOCompanionVersionSpecific.$anonfun$attempt$1(ZIOCompanionVersionSpecific.scala:100)
    at zio.logging.example.Example2.baz(Example2.scala:22)
    at zio.logging.example.Example2.run(Example2.scala:24)
Caused by: java.lang.RuntimeException: test doe
    at zio.logging.example.Test$.doe(Test.scala:12)
    at zio.logging.example.Test$.bar(Test.scala:9)
    at zio.logging.example.Test$.foo(Test.scala:6)
    at zio.logging.example.Example2$.$anonfun$baz$1(Example2.scala:22)
    at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
    at zio.ZIOCompanionVersionSpecific.$anonfun$attempt$1(ZIOCompanionVersionSpecific.scala:100)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:999)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1067)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1097)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1162)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1097)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1162)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1162)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1097)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1162)
    at zio.internal.FiberRuntime.evaluateEffect(FiberRuntime.scala:413)
    at zio.internal.FiberRuntime.evaluateMessageWhileSuspended(FiberRuntime.scala:489)
    at zio.internal.FiberRuntime.drainQueueOnCurrentThread(FiberRuntime.scala:250)
    at zio.internal.FiberRuntime.run(FiberRuntime.scala:138)
    at zio.internal.ZScheduler$$anon$3.run(ZScheduler.scala:380)

with 

val causeToThrowableDefault: Cause[Any] => Option[Throwable] = cause =>
  if (cause.isEmpty) {
    None
  } else {
    val maybeThrowable = (cause.failures.collect { case t: Throwable => t } ++ cause.defects).headOption
    maybeThrowable.orElse(Some(FiberFailure(cause)))
  }

will be

08:35:43.303 [ZScheduler-Worker-5] [] ERROR zio-slf4j-logger 
java.lang.RuntimeException: test doe
    at zio.logging.example.Test$.doe(Test.scala:12)
    at zio.logging.example.Test$.bar(Test.scala:9)
    at zio.logging.example.Test$.foo(Test.scala:6)
    at zio.logging.example.Example2$.$anonfun$baz$1(Example2.scala:23)
    at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
    at zio.ZIOCompanionVersionSpecific.$anonfun$attempt$1(ZIOCompanionVersionSpecific.scala:100)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:999)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1067)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1097)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1162)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1097)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1162)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1162)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1097)
    at zio.internal.FiberRuntime.runLoop(FiberRuntime.scala:1162)
    at zio.internal.FiberRuntime.evaluateEffect(FiberRuntime.scala:413)
    at zio.internal.FiberRuntime.evaluateMessageWhileSuspended(FiberRuntime.scala:489)
    at zio.internal.FiberRuntime.drainQueueOnCurrentThread(FiberRuntime.scala:250)
    at zio.internal.FiberRuntime.run(FiberRuntime.scala:138)
    at zio.internal.ZScheduler$$anon$3.run(ZScheduler.scala:380)

I agree that it is not best to have everything wrapped like zio.FiberFailure, it seemed the most reasonable solution for problem at that time.

Ideas for improvements are welcome. Thank you very much.