Slf4j MDC not working properly in asynchronous scala futures

Question

Hi I am trying to build a custom logging solution for my scala application. The one way I figured out is to used Slf4j MDC which used ThreadLocal to store common variables that can be later extracted from the same MDC context. I even got that across multiple threads MDC can be copied and passed down to keep those common variables by defining custom Execution Contexts.

But my concern is when the same thread is used for running two different requests (scala futures) asynchronously now my MDC threadLocal will get override with the other request's logging variables. I am seeing that the variables are getting mixed in this case i.e. clientId of other request is being printed on a wrong request. How can I stop this from happening? Is there any other way to achieve this? How can I keep separate context for each and every asynchronous task in scala?

Mateusz Kubuszok · Accepted Answer · 2023-06-14T12:35:18.030

Long story short: with thread pools and no thread pinning it is impossible to have out of the box support for MDC through ThreadLocal.

If you have something like State which you'd like to store in every ThreadLocal, you could have pass around e.g. via implicit state: State and have something which would set it right before using:

case class State(...)
object State {
  private val threadLocal = new ThreadLocal[State] {
    def initialValue() = null.asInstanceOf[State] // or some default
  }

  def get: State =
    Option(threadLocal.get()).getOrElse(
      throw new IllegalStateException("You haven't propagated the state!")
    )
  
  def set(implicit state: State): Unit =
    threadLocal.set(state)
}


def futureA(implicit state: State): Future[B] = Future {
  State.set // obligatory, used in a way you know that it will be called
            // on the same thread as the rest of the Future's body

  somethingThatAccesesStateGet
}

It's supper brittle, error-prone but it's the only way with Future.

In Monix one could use TaskLocal to propagate values around instead of arguments in every function - as described in this port and implemented in this library. I you haven't heard of Monix, migrating your whole codebase to it right now might not be a good idea - you'd have to replace every usage of Future in your code with Monix Task. Especially, since they haven't been ported to Cats Effect 3 yet.

In Cats Effect 3, since Monix hasn't been ported to it, one would have to work with IOLocal, and some custom made mechanics to propagate the state. I've done it with tagless final and custom decorator over Async[IO] type class. If you haven't heard of: Cats Effect 3, type classes or tagless final, this solution might also be of no interest to you, since you'd have to replace every Future with an abstract F and then interpret it with decorated Async[IO] - which runs Cats Effect IO, not the Future.

(You can convert to and from the Future in both of these cases, which is useful on the edges of some libraries, but as a principle everything would have to be done with these libraries' Future alternatives).

Assuming that you are working with Futures, I don't see a way you could avoid propagating the values to where you use them in other way than just by passing them around through arguments. Whether it will be explicit, implicit or through some ReaderT with fixed input, would affect ergonomics but not the principle.

Slf4j MDC not working properly in asynchronous scala futures

1 Answers1