ZIO log annotations are confusing

I was working on a logger that writes metrics every time a warning or an error is logged. I tried to provide additional metric tags depending on the log annotations. And it didn't work. I was adding an annotation and I could see its value somewhere deep in the stack trace but the annotations value was empty.

Turned out that ZIO has two log annotation mechanisms that work in parallel.

This might age quickly. Here are the versions I'm using:

"dev.zio" %% "zio"         % "2.0.5",
"dev.zio" %% "zio-logging" % "2.1.7",

Annotation mechanisms

Both mechanisms often use the same names and this increases confusion. Pay attention to namespaces.

zio-core mechanism

These are string annotations that get gathered into a Map[String, String] structure. You can annotate logs using the ZIO.logAnnotate function.

Example:

ZIO.logAnnotate("traceId", "my-trace-id")(ZIO.logError("Test error"))

zio-logging mechanism

These are typed annotations. Annotations are created via the zio.logging.LogAnnotation ZIO aspect. Not to be confused with zio.LogAnnotation, that one relates to another mechanism. For each annotation, you can define how to combine two values of the same annotation and how to convert annotation values to strings.

Example:

final case class TraceId(value: String)

object Annotation {
  val traceId: LogAnnotation[TraceId] = LogAnnotation[TraceId](
    name = "traceId",
    combine = (_, a) => a,
    render = (traceId) => traceId.value
  )
}

ZIO.logError("Test error") @@ Annotation.traceId(TraceId("my-trace-id"))

When this matters

This matters when you are creating a logger. ZIO logger is basically a single log function wrapped with composition methods. It looks like this:

package zio

// ...

trait ZLogger[-Message, +Output] { self =>
  def apply(
    trace: Trace,
    fiberId: FiberId,
    logLevel: LogLevel,
    message: () => Message,
    cause: Cause[Any],
    context: FiberRefs,
    spans: List[LogSpan],
    annotations: Map[String, String]
  ): Output

  // ...
}

You can retrieve log annotations from within this function in two different ways, depending on how they were added.

With the zio-core mechanism, it's easy. Annotations can be found in the annotations parameter.

With the zio-logging mechanism, it's trickier. Annotations can be found inside the context: zio.FiberRefs. We need to retrieve a zio.logging.LogContext from it by providing zio.logging.logContext as a key. It has the type zio.FiberRef[zio.logging.LogContext].

Sounds hard in theory but it looks simpler in code. Here's how we can retrieve the traceId we annotated earlier:

// Retrieve LogContext from FiberRefs
val currentContext: LogContext = context.getOrDefault(zio.logging.logContext)

// Retrieve the annotated value from LogContext
val stringAnnotation: Option[String] = currentContext(Annotation.traceId)
// or
val typedAnnotation: Option[TraceId] = currentContext.get(Annotation.traceId)

So if the logger does not see the annotations – check if it uses the same annotation mechanism as the application code.

Tags: , , ,

Comments