Using MDC in Quarkus
Mapped Diagnostic Context (MDC) can be very useful to enrich log messages with correlation information. Unfortunately, the Quarkus logging documentation does not say much about it. I could only find it mentioned among the logging format patterns. Still, it seems to be well supported according to a GitHub issue I found.
Adding a correlation ID to all logs coming from a single HTTP request is not hard to implement. You just need a request filter to add the value to MDC and a response filter to remove it (make sure you use MDC from org.jboss.logging):
private const val REQUEST_ID_HEADER = "X-Request-ID"
private const val REQUEST_ID_MDC_KEY = "requestId"
class RequestIdFilters {
@ServerRequestFilter
fun getRequestFilter(requestContext: ContainerRequestContext) {
val requestId = requestContext.getHeaderString(REQUEST_ID_HEADER)
MDC.put(REQUEST_ID_MDC_KEY, requestId ?: UUID.randomUUID().toString())
}
@ServerResponseFilter
fun getResponseFilter(responseContext: ContainerResponseContext) {
MDC.remove(REQUEST_ID_MDC_KEY)
}
}
Notice how I first try to read the value from a request header and only create a new one if it is not present. This way the client can pass on its own value so that logs can be correlated across multiple services/applications.
To see the requestId value in the logs, you need to include it in the logger format. Here I just added it to the default pattern:
quarkus.log.console.format=%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c{3.}] (%t) <%X{requestId}> %s%e%n
That should be enough to see the value as part of every log message:
2022-12-25 09:33:22,914 INFO [org.exa.GreetingResource] (executor-thread-0) <3d5ee53d-e619-4550-a1cd-11806a4a2e9d> Hello
To pass the requestId value to other services that your service might call, you need to implement a ClientRequestFilter:
@Provider
class RequestIdFilters : ClientRequestFilter {
override fun filter(requestContext: ClientRequestContext) {
val requestId = MDC.get(REQUEST_ID_MDC_KEY)
if (requestId != null) {
requestContext.headers[REQUEST_ID_HEADER] = listOf(requestId)
}
}
// ...
}
To see that the value is actually included in the request, you can enable logging for the REST client:
quarkus.rest-client.logging.scope=request-response
quarkus.rest-client.logging.body-limit=1024
quarkus.log.category."org.jboss.resteasy.reactive.client.logging".level=DEBUG
This will log every outgoing request with all headers:
2022-12-25 09:36:43,649 DEBUG [org.jbo.res.rea.cli.log.DefaultClientLogger] (vert.x-eventloop-thread-0) <812ecae5-f60e-43a2-9938-99939a541703> Request: GET https://randomuser.me/api?inc=name Headers[User-Agent=Resteasy Reactive Client X-Request-ID=812ecae5-f60e-43a2-9938-99939a541703], Empty body
You can see the full working example in my GitHub repository. I have even included a set of sample requests for VS Code REST Client to make testing easier.
I have also forked a reproducer project for the issue mentioned in the introduction and updated the Quarkus dependencies to the latest version. You can run the tests to see if MDC propagates correctly in different threading scenarios.
Although there is extensive documentation for Quarkus, you will soon find that it is still sometimes difficult to find resources for what you want to accomplish once you deviate slightly from the well-documented core use cases, as I did with adding correlation information to log messages.
