TLDR
- Simple context propagation in Scribe logging library
- Code
In my first ever gig where Cats Effect was used for ~everything, I spent a considerable amount of time building a transparent context propagation logic that could be integrated into our services and AWS Lambda. Not because it was something inherently complicated, but because implementation carried a significant baggage of having to help my colleagues understand and use Kleisli efficiently.
I won't get into the details of my burning disdain for Kleislis and polymorphic effects, and instead jump straight in – for something as simple as context propagation we can use IOLocal. In fact, this post can be seen as a http4s and scribe specific extension of the example in the official docs.
As a vehicle for demonstration I will use Scribe – a logging library I prefer to pretty much anything else, not in the least because of its pretty colours.
Before the code, let's go over what we want to achieve. Let's say that all your services communicate with each other over HTTP, and there's a specific set of HTTP headers that services promise to forward to each other if they themselves receive such headers. E.g. if service A receives a request with a header X-Trace-ID set to value bananas, then if it invokes service B over HTTP, it must send the same header with same value to that service.
Additionally, we want to structure our code in such a way that if there's some service logic invoked in response to a HTTP request, all the log statements in that logic should automatically receive additional (optional) piece of data – the ID of the originating HTTP request.
Those two requirements do wonderful things for morale log exploration – if you identify a problematic request, you can usually trace it across any number of services using nothing but grep or any of its glorified cloud wrappers.
Note that we are not yet going to full tracing (e.g. Datadog or OpenTelemetry with something like Grafana) – we are just adding text to some logs.
One non-functional, but rather stylistical requirement is that I want this context propagation to not require any switching over the instance of my logger that services hold. This makes the logic a bit more opaque and magical (and in fact it's implemented in such a way in ~most logging libraries by relying on ThreadLocals), but I feel like it's worth it.
Scribe integration
ThreadLocals are useless in the context of Cats Effect applications – lightweight fibers can routinely cross thread boundaries during execution, thrashing the data stored in the thread.
To help with that, we should use IOLocal – a construct from Cats Effect that is defined within fiber semantics.
So the plan for our integration is as follows:
- Create a logger wrapper that mimics Scribe interface
- Add a
annotate[A]method that takes the nextIO[A]operation, but tweaks theIOLocalvalue before and after the given operation executes - Overrides the catch-all
logmethod of Scribe interface to grab the current context from theIOLocalvalue and add it to the logging record
This is the whole code, along with a couple of convenience methods:
package scribecontext
import cats.effect.*
import scribe.{cats as _, *}
class Log private (
orig: Scribe[IO],
loc: IOLocal[Map[String, String]]
) extends Scribe[IO]:
def annotate[A](key: String, value: String)(io: IO[A]): IO[A] =
loc
.modify(m => (m.updated(key, value), m))
.flatMap: prev =>
io.guarantee(loc.set(prev))
def annotate[A](context: Map[String, String])(io: IO[A]): IO[A] =
loc
.modify(m => (m ++ context, m))
.flatMap: prev =>
io.guarantee(loc.set(prev))
def getContext: IO[Map[String, String]] = loc.get
override def log(record: => LogRecord): IO[Unit] =
loc.get.flatMap: context =>
val newRecord = context.foldLeft(record) { case (r, (k, v)) =>
r.update(k, () => v)
}
orig.log(newRecord)
end Log
object Log:
def create(orig: Scribe[IO]): IO[Log] =
IOLocal(Map.empty).map(new Log(orig, _))
def io: IO[Log] = create(scribe.cats.io)
end Logannotate[A] method allows us to denote some blocks within which the opaque logging context will be augmented by some extra data.
getContext will be required in a later example, where we test propagation from HTTP server to downstream HTTP call.
Let's see it in action – we'll simulate 3 different users being processed in parallel, and create several nested annotate blocks to show how the context is merged:
import cats.effect.*
import cats.syntax.all.*
import concurrent.duration.*
object BasicExample extends IOApp.Simple:
val randomDelay = cats.effect.std.Random
.scalaUtilRandom[IO]
.flatMap(_.nextIntBounded(1000))
.flatMap(t => IO.sleep(t.millis))
val run =
scribecontext.Log.io.flatMap { log =>
List("UserA", "UserB", "UserC").parTraverse { userId =>
log.annotate(
Map("session-id" -> java.util.UUID.randomUUID().toString)
) {
log.annotate("user-id", userId) {
log.annotate("trace-id", java.util.UUID.randomUUID().toString) {
for
_ <- randomDelay
_ <- log.info(s"fetching user $userId from database")
_ <- randomDelay
_ <- log.warn(s"downloading profile picture for user $userId")
yield ()
}
}
}
}
}.void
end BasicExampleIf we run it, we get something like this:
2026.01.08 09:46:41:389 io-compute-8 INFO <empty>.BasicExample.run:22
fetching user UserC from database
[session-id: f3b83ff7-02f5-4156-b03b-5ffc9f13955f, user-id: UserC, trace-id: 5658162d-beb3-440b-a3e8-483bc3dbc6bb]
2026.01.08 09:46:41:902 io-compute-3 INFO <empty>.BasicExample.run:22
fetching user UserA from database
[session-id: 4ccb47eb-3a74-4176-aeff-556f1dab1035, user-id: UserA, trace-id: d02dcdf1-d8f3-4d15-bffd-623c9d2d9c1e]
2026.01.08 09:46:41:972 io-compute-5 INFO <empty>.BasicExample.run:22
fetching user UserB from database
[session-id: 8a4457b7-75e0-4f59-88ec-a94ee8a5e7e9, user-id: UserB, trace-id: f14e6ce5-fead-4132-98d3-9c1645563435]
2026.01.08 09:46:41:998 io-compute-8 WARN <empty>.BasicExample.run:24
downloading profile picture for user UserC
[session-id: f3b83ff7-02f5-4156-b03b-5ffc9f13955f, user-id: UserC, trace-id: 5658162d-beb3-440b-a3e8-483bc3dbc6bb]
2026.01.08 09:46:42:017 io-compute-5 WARN <empty>.BasicExample.run:24
downloading profile picture for user UserB
[session-id: 8a4457b7-75e0-4f59-88ec-a94ee8a5e7e9, user-id: UserB, trace-id: f14e6ce5-fead-4132-98d3-9c1645563435]
2026.01.08 09:46:42:808 io-compute-3 WARN <empty>.BasicExample.run:24
downloading profile picture for user UserA
[session-id: 4ccb47eb-3a74-4176-aeff-556f1dab1035, user-id: UserA, trace-id: d02dcdf1-d8f3-4d15-bffd-623c9d2d9c1e]
Http4s integration
Now, let's extract the request ID from the headers in a simple http4s service.
Let's say we have a UserService:
import cats.effect.*
import concurrent.duration.*
class UserService(log: scribecontext.Log):
def fetchUser(userId: String): IO[Unit] =
log.annotate("user-id", userId):
for
_ <- log.info(s"Fetching user $userId")
_ <- IO.sleep(10.millis)
_ <- log.info(s"Fetched user $userId")
yield ()
end UserServiceServer integration
Let's start with request ID propagation from the incoming HTTP request. To do so, we'll organise our logic into a generic middleware:
import cats.effect.*
import org.http4s.Header
import org.http4s.HttpApp
import org.http4s.client.Client
import org.typelevel.ci.CIString
import scribecontext.Log as ScribeWithContext
class RequestIdMiddleware(log: ScribeWithContext):
private val ContextKey = "trace-id"
private val HeaderKey = CIString("x-trace-id")
def server(app: HttpApp[IO]): HttpApp[IO] =
HttpApp: req =>
log.annotate(
req.headers
.get(HeaderKey)
.map(_.head.value)
.map(ContextKey -> _)
.toMap
)(app(req))The logic is simple – given an existing set of HTTP routes, we pre-process the incoming request and execute the actual HTTP handler in the context with trace ID attached (if it's present in the headers).
Let's create some HTTP routes, wrap them in middleware, and launch the server:
import cats.effect.*
import com.comcast.ip4s.*
import org.http4s.HttpRoutes
object ServerExample extends IOApp.Simple:
import org.http4s.ember.server.EmberServerBuilder
import org.http4s.dsl.io.*
val run =
scribecontext.Log.io.toResource.flatMap { log =>
val userService = new UserService(log)
val middleware = RequestIdMiddleware(log)
val baseRoutes =
HttpRoutes
.of[IO]:
case GET -> Root / "user" / userId =>
for
_ <- log.info(s"Received request for user $userId")
_ <- userService.fetchUser(userId)
resp <- Ok(s"User $userId data")
yield resp
.orNotFound
val routes = middleware.server(baseRoutes)
EmberServerBuilder
.default[IO]
.withHost(host"localhost")
.withPort(port"8080")
.withHttpApp(routes)
.build
.evalTap(server => log.info(s"Server started at ${server.baseUri}"))
}.useForever
end ServerExampleAnd if we run a simple CURL request with a request ID
$ curl http://localhost:8080/user/hello -H "x-trace-id: HELLO_I_AM_A_REQUEST"
The logs show the context propagation:
2026.01.08 09:50:29:189 io-compute-3 INFO <empty>.ServerExample.baseRoutes:19
Received request for user hello
[trace-id: HELLO_I_AM_A_REQUEST]
2026.01.08 09:50:29:207 io-compute-3 INFO <empty>.UserService.fetchUser:8
Fetching user hello
[trace-id: HELLO_I_AM_A_REQUEST, user-id: hello]
2026.01.08 09:50:29:220 io-compute-3 INFO <empty>.UserService.fetchUser:10
Fetched user hello
[trace-id: HELLO_I_AM_A_REQUEST, user-id: hello]
Client integration
To propagate the context to the downstream HTTP calls, we need to wrap our http4s Client in a different kind of middleware:
def client(base: Client[IO]): Client[IO] =
Client[IO]: req =>
val modifiedRequest =
log.getContext
.map(_.get(ContextKey))
.map:
case None => req
case Some(reqId) => req.putHeaders(Header.Raw(HeaderKey, reqId))
modifiedRequest.toResource.flatMap: req =>
base.run(req)If the context is non empty, we add it to headers and send the request using the original client.
To test this, we'll modify our server ever so slightly, to send a call to https://httpbin.org/headers endpoint which will return the request headers in the response body (formatted as JSON).
The application code is almost the same, with only difference being the extra client call, and the need to wire in the HTTP client:
import cats.effect.*
import cats.syntax.all.*
import com.comcast.ip4s.*
import org.http4s.HttpRoutes
import org.http4s.ember.client.EmberClientBuilder
import scribecontext.Log as ScribeWithContext
object ServerClientExample extends IOApp.Simple:
import org.http4s.ember.server.EmberServerBuilder
import org.http4s.dsl.io.*
import org.http4s.implicits.*
val run =
(
ScribeWithContext.io.toResource,
EmberClientBuilder.default[IO].build
).flatMapN: (log, baseClient) =>
val userService = new UserService(log)
val middleware = RequestIdMiddleware(log)
val client = middleware.client(baseClient)
val baseRoutes =
HttpRoutes
.of[IO]:
case GET -> Root / "user" / userId =>
for
_ <- log.info(s"Received request for user $userId")
_ <- userService.fetchUser(userId)
httpbin <- client.expect[String](
uri"http://httpbin.org/headers"
)
_ <- log.info(s"HTTPBin response: $httpbin")
resp <- Ok(s"User $userId data")
yield resp
.orNotFound
val routes = middleware.server(baseRoutes)
EmberServerBuilder
.default[IO]
.withHost(host"localhost")
.withPort(port"8080")
.withHttpApp(routes)
.build
.evalTap(server => log.info(s"Server started at ${server.baseUri}"))
.useForever
end ServerClientExampleNote: there's a bug in httpbin where it hides X-Request-Id headers, hence I had to rename the header to X-Trace-Id for this post
Now, if we start the server and issue the same HTTP call using curl, we can see propagation in action:
2026.01.08 09:58:38:103 io-compute-8 INFO <empty>.ServerClientExample.baseRoutes:27
Received request for user hello
[trace-id: HELLO_I_AM_A_REQUEST]
2026.01.08 09:58:38:105 io-compute-8 INFO <empty>.UserService.fetchUser:8
Fetching user hello
[trace-id: HELLO_I_AM_A_REQUEST, user-id: hello]
2026.01.08 09:58:38:117 io-compute-8 INFO <empty>.UserService.fetchUser:10
Fetched user hello
[trace-id: HELLO_I_AM_A_REQUEST, user-id: hello]
2026.01.08 09:58:38:783 io-compute-6 INFO <empty>.ServerClientExample.baseRoutes:32
HTTPBin response: {
"headers": {
"Accept": "text/*",
"Date": "Thu, 08 Jan 2026 09:58:38 GMT",
"Host": "httpbin.org",
"User-Agent": "http4s-ember/0.23.33",
"X-Amzn-Trace-Id": "Root=1-695f7fce-3ea0680b4dfdb4c037d40eb5",
"X-Trace-Id": "HELLO_I_AM_A_REQUEST"
}
}
[trace-id: HELLO_I_AM_A_REQUEST]