Just playing around with coroutines and logging MDC. I have a dummy example
@GetMapping("/dummy/{delay}")
suspend fun dummyEndpoint(@PathVariable delay: Int): ResponseEntity<String> {
logger.debug("Outside the context. Start")
withContext(MDCContext(mapOf("myKey" to "myVal"))) {
logger.debug("Inside the context. Before the call")
val response = WebClient.create()
.get()
.uri("http://postman-echo.com/delay/${delay}")
.retrieve()
.awaitBody<String>()
logger.debug("Inside the context. After the call")
}
logger.debug("Outside the context. End")
return ResponseEntity.ok("OK")
}
It produces next log message:
2020-07-30 19:42:09,817 - [DEBUG] - [reactor-http-nio-3] - [{}]
Outside the context. Start
2020-07-30 19:42:09,836 - [DEBUG] - [reactor-http-nio-3] - [{myKey=myVal}]
Inside the context. Before the call
2020-07-30 19:42:15,411 - [DEBUG] - [reactor-http-nio-4] - [{myKey=myVal}]
Inside the context. After the call
2020-07-30 19:42:15,412 - [DEBUG] - [reactor-http-nio-4] - [{myKey=myVal}]
Outside the context. End
My expectation was that the context will be cleared after withContext() block will be finished.
Inspired by https://medium.com/@elizarov/phantom-of-the-coroutine-afc63b03a131
This is more verbose, but it also avoids the need to restore the context after the call to doSomeWork.
So why the last message outside the context is still contains MDC values? or I'm missing something?