Since upgrading my log acquisition platform to be metadata-aware (it’s effectively syslog messages + log flume + “other stuff”), I’ve really started to take advantage of the message diagnostic context available with major logging frameworks for tracking a specific complex interaction. Below is an example of what I’m talking about:

public void myThingIDo(String targetUser, UserPreferences morePreferences) {
    MDC.put(TARGET_USER, targetUser);
    callSomeFunction(targetUser, morePreferences);
}
 
// Imagine a lot of other stuff going on. callSomeFunction eventually leads to the functions below.
 
private void checkTheThing() {
    // Imagine this being somewhere very different from here
    logger.info("trying something else");
}
 
private void checkAccess(String targetUser, String targetResource) throws AccessNotGrantedException {
    // And even different still
    logger.error("User {} cannot access {}", targetUser, targetResource);
}

Imagine getting the call from this user saying they can’t access something that they totally could before your last production push. Now imagine there are thousands of users on this app. Now imagine finding this error message pretty quickly, but then trying to sift through those logs to find all related messages for this particular user in your system.

With proper usage of the MDC, you can actually go find those logs which created this error in the first place without having to manually determine which messages are relevant and which are not.

Dealing with multiple threads

The one problem with the MDC, especially if you’re using parallel streams in java’s streams API, is that it depends on thread local data. Because of this, the use of a static helper class for tracking context is sometimes required. Here’s one below:

import org.slf4j.MDC;
 
import java.util.Map;
 
public class MdcSnapshot {
    private final Map<string, string=""> mdc;
 
    private MdcSnapshot() {
        this.mdc = MDC.getCopyOfContextMap();
    }
 
    public static MdcSnapshot getCurrentMdc() {
        return new MdcContext();
    }
 
    public void populateMdc() {
        MDC.clear();
        if (mdc != null) {
            MDC.setContextMap(mdc);
        }
    }
}
</string,>

This can be used as follows:

private void doThingsReallyFast(List things) {
    MdcSnapshot context = MdcSnapshot.getCurrentMdc();
    things.parallelStream().forEach((thing) -> {
        context.populateMdc();
        doTheThing(thing);
    });
}

It’s really handy!

After I’ve started using the MDC in my code, I’ve stopped having to add all that metadata to the log message itself just so I could find that line. I’m now just worried about writing a log message that makes sense.

Depending on your logging framework, to get the MDC data to show up in the log message itself, you will need to use the %X pattern (doc available for log4j2).