In this blog, we’ll discuss Mapped Diagnostic Context, in short MDC. Also, we’ll see how we can use it across a single thread or multiple threads(or Futures) using some examples.
What is MDC Logging?
Multi-user applications need log messages to retain context.
The Mapped Diagnostic Context(MDC) allows us to put context to all the log statements for a single thread. We can also propagate MDC across multiple threads or futures. For that purpose, we have to create our own ExecutionContext where we can copy the MDC to any new thread that is being used giving us multi-thread MDC logging.
Dependency
To provide support for MDC logging, add the following dependency in your sbt project:
libraryDependencies += "ch.qos.logback" % "logback-classic" % "1.2.3"Configuration
To use content from MDC in the logs, we need to configure our log system. For that, create a new file by the name logback.xml under the resources folder and add the following:
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<!-- encoders are assigned the type
ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
<encoder>
<pattern>%date \(%level\) [%thread] [%X{contextID}]: %message%n</pattern>
</encoder>
</appender>
<root level="debug">
<appender-ref ref="STDOUT"/>
</root>
</configuration>Note: If you already have a logback.xml file in your project, it must contain the following pattern:
<pattern>%date \(%level\) [%thread] [%X{contextID}]: %message%n</pattern>MDC Across a Single Thread
It is very easy to provide context to all the log statements across a single thread, first we need to import MDC which is exposed via org.slf4j.MDC but other logging systems (such as log4j and logback) have similar concepts that slf4j wraps.
Next, put the context for your logs:
MDC.put("contextID", s"contextID-$contextID")With this, everything that is in the current thread will use the same MDC.
Here’s an example:
import org.slf4j.{LoggerFactory, MDC}
import java.util.UUID
object MdcAcrossSingleThread extends App {
val contextID = UUID.randomUUID().toString
val logger = LoggerFactory.getLogger(getClass.getSimpleName)
MDC.put("contextID", s"contextID-$contextID") // putting the context for all log statements
logger.info("This is the main thread")
logger.debug("Debug log")
logger.warn("Warning log")
logger.error("Error log")
}Output:
Note that the contextID is same for all the log statements across a single thread i.e. main.
MDC Across Multiple Threads or Futures
Now there’s a little spot on our logging: It works fine if the thread doesn’t change.
In case the thread changes, the output for the above example would look like this:
See, there is no contextID for the last two logs which are running in a child thread. So in case, we use a new Thread or a Future, we are losing our precious MDC which we don’t want.
To get the MDC across that new thread, we’ll need to provide our own ExecutionContext.
This new execution context will subclass ExecutionContext and override its execute method. The method takes a Runnable and executes it, but instead, we will create our own runnable around it, copy the MDC into the new thread and submit it to the super method instead:
import org.slf4j.MDC
import scala.concurrent.ExecutionContext
object MdcExecutionContext {
def apply(executionContext: ExecutionContext): MdcExecutionContext = {
val mdcExecutionContext = new MdcExecutionContext(executionContext)
mdcExecutionContext
}
}
// Execution context proxy for propagating MDC from caller thread to execution thread.
class MdcExecutionContext(executionContext: ExecutionContext) extends ExecutionContext {
override def execute(runnable: Runnable): Unit = {
// getting a copy of the MDC data
val callerMdc = MDC.getCopyOfContextMap
executionContext.execute(() => {
// setting caller thread MDC to the new execution thread
if (callerMdc != null) MDC.setContextMap(callerMdc)
try {
runnable.run
} finally {
//clearing MDC so that we don't get misleading logs if this Thread is reused without having an MDC.
MDC.clear
}
})
}
override def reportFailure(cause: Throwable): Unit = executionContext.reportFailure(cause)
}Let’s understand it in detail:
1. We obtain a copy of the MDC contents with MDC.getCopyOfContextMap
2. If that copy worked, we put it into the MDC of the new thread by calling MDC.setContextMap
3. Once we are done executing the original Runnable, we clear the MDC (this is only affecting the cloned MDC inside the new thread)
The MDC.clear is a good idea, because we’d get misleading logs if a thread is reused without having an MDC.
Now all we need to do is create a new MdcExecutionContext and use it as our execution context.
Here’s an example:
package examples
import mdc.MdcExecutionContext
import org.slf4j.{LoggerFactory, MDC}
import java.util.UUID
import scala.concurrent.duration.Duration
import scala.concurrent.{Await, Future}
import scala.util.Success
object MdcAcrossMultipleThreadsOrFutures extends App {
implicit val mdcExecutionContext: MdcExecutionContext = MdcExecutionContext(scala.concurrent.ExecutionContext.Implicits.global) // To propagate MDC across any new thread, we are using our own MdcExecutionContext
val contextID = UUID.randomUUID().toString
val logger = LoggerFactory.getLogger(getClass.getSimpleName)
val future1FromMainThread = Future(50)
MDC.put("contextID", s"contextID-$contextID") // putting the context for all log statements
logger.info("This is the main thread")
future1FromMainThread.onComplete {
case Success(_) =>
logger.info(s"MDC is propagated from main thread to future 1")
val future2FromFuture1 = Future(80)
future2FromFuture1.onComplete {
case Success(_) =>
logger.info(s"MDC is propagated from future1 to future2")
}
Await.result(future2FromFuture1, Duration.Inf)
}
Await.result(future1FromMainThread, Duration.Inf)
}Output:
See the contextID is the same for all our log statements even when the logs execute in different threads(or Futures). That means our MDC is propagated successfully from the main thread to future1 and then to future2.
That’s it. I hope you find this blog useful. To see more interesting blogs related to the latest technologies, visit Knoldus Blogs
