Mapped Diagnostic Context (MDC)

The basic idea of MDC is to provide a way to enrich log messages with pieces of information that could not be available in the scope where the logging actually occurs, but that can be an indeed useful to better tracking the execution of the program.

Let’s take an example where we have to write a functionality that helps us to transfer money from one wallet to another. We create a WalletTransfer class to represent some very basic information like a transfer id, currency, amount, name of the sender and the receiver.

public class WalletTransfer {
    private String transactionId;
    private CurrencyEnum currency;
    private String senderName;
    private String receiverName;
    private Long amount;
     
    public WalletTransfer(String transactionId, CurrencyEnum currency, 
       String senderName, String receiverName, long amount) {
        this.transactionId = transactionId;
        this.currency = currency;
        this.senderName = senderName;
        this.receiverName = receiverName;
        this.amount = amount;
    }
     
    public String getTransactionId() {
        return transactionId;
    }

    public CurrencyEnum getCurrency() {
    	return currency;
    }
 
    public String getSenderName() {
        return senderName;
    }
 
    public String getReceiverName() {
        return receiverName;
    }

    public Long getAmount() {
        return amount;
    }
}

To make the transfer, we need a service layer that will actually does the transfer for us.

public interface WalletTransferService {
 
    boolean transferBalance(CurrencyEnum currency, long amount);
 
    void beforeTransferBalance(long amount);
 
    void afterTransferBalance(CurrencyEnum currency, long amount, boolean transferStatus);

}

We’re going to leverage beforeTransferBalance() and afterTransferBalance() to log some information about the transfer of money from one wallet to another. Let’s go ahead and create the service implementation class.

public class WalletTransferServiceImpl implements WalletTransferService {
    private static final Logger LOGGER = Logger.getLogger(WalletTransferServiceImpl.class);
 
    @Override
    public transferBalance(WalletTransfer walletTransfer) {
        //Assume the logic for transfer from one wallet to another goes here...
    }

    @Override
    public void beforeTransferBalance(CurrencyEnum currency, long amount) {
        LOGGER.info("Preparing to transfer " + currency.getDescription() + ". " + amount);
    }
 
    @Override
    public void afterTransferBalance(CurrencyEnum currency, long amount, 
       TransferStatusEnum transferStatus) {
        LOGGER.info("TransferLog: " + currency.getDescription() + ". " + amount 
        	+ " has been transferred successfully. Status: " + transferStatus + ".");
    }
}

If you notice the code, when the log message is created it’s not possible to access the WalletTransfer object. We have access only to the currency, amount is accessible making impossible to log either the transaction id or sender or receiver name.

Let’s go ahead and set up a small application that will initiate the transfer from one wallet to another with simple use case.

public class WalletTransferDemo {
	 
    public static void main(String[] args) {
       WalleTransferFactory walletTransactionFactory = new WalletTransactionFactory();
       WalletTransferService walletTransferService = new WalletTransferServiceImpl();
       WalletTransfer walletTransfer = walletTransactionFactory.newInstance();
       walletTransfer.setTransactionId(UUID.randomUUID().toString());
       walletTransfer.setCurrency(CurrencyEnum.valueOf(args[0]));
       walletTransfer.setSender(args[1]);
       walletTransfer.setReciever(args[2]);
       walletTransfer.setAmount(Long.valueOf(args[3]));
       walletTransferService.transferBalance(walletTransfer);
    }
}

When we run our small application it’s simple to understand as only one transfer happens. We are fairly fine with the logging as we can co-relate the different logs as it happens in sequence.

INFO WalletTransferServiceImpl - Preparing to transfer INR. 2500.
INFO WalletTransferServiceImpl - TransferLog: INR. 2500 has been transferred successfully. Status: SUCCESS.

Think of a scenario where the transfer happens concurrently with use of multiple threads to make different transfers. It will become extremly difficult to understand the log statments as it will not be in sequence, log message are of no use as it doesn’t have complete required or context details. And if there is more than one transfer with same amount it’s impossible to distinguish between two different transactions as the related log lines look almost the same.

INFO WalletTransferServiceImpl - Preparing to transfer INR. 1129.
INFO WalletTransferServiceImpl - TransferLog: INR. 1129 has been transferred successfully. Status: FAILURE.
INFO WalletTransferServiceImpl - Preparing to transfer INR. 1129.
INFO WalletTransferServiceImpl - TransferLog: INR. 1129 has been transferred successfully. Status: SUCCESS.

Let’s add MDC into the use case and see how it helps us to resolve our problem in hand.

MDC in Log4j allows us to fill-in a map like structure with information in the form of key and value pairs that are accessible to the program in any layer of the application. The MDC structure is internally attached to the currently executing thread in the same way as ThreadLocal variables.

Let’s modify our demo program a little bit.

public class WalletTransferDemo {
	 
   public static void main(String[] args) {
      WalleTransferFactory walletTransactionFactory = new WalletTransactionFactory();
      WalletTransferService walletTransferService = new WalletTransferServiceImpl();
      WalletTransfer walletTransfer = walletTransactionFactory.newInstance();
      walletTransfer.setTransactionId(UUID.randomUUID().toString());
      walletTransfer.setCurrency(CurrencyEnum.valueOf(args[0]));
      walletTransfer.setSender(args[1]);
      walletTransfer.setReciever(args[2]);
      walletTransfer.setAmount(Long.valueOf(args[3]));

      MDC.put("transactionId", walletTransfer.getTransactionId());
      MDC.put("senderName", walletTransfer.getSenderName());
      MDC.put("receiverName", walletTransfer.getReceiverName());
      walletTransferService.transferBalance(walletTransfer);
      MDC.clear();
    }
}

Also the WalletTransferServiceImpl to accomodate more details into the logger.

@Override
public void afterTransferBalance(CurrencyEnum currency, long amount, 
   TransferStatusEnum transferStatus) {
   LOGGER.info("TransferLog: " + currency.getDescription() + ". " + amount 
        + " has been transferred from " + MDC.get("senderName") + " to " 
        + MDC.get("receiverName") + " under the transactionId " 
        + MDC.get("transactionId") + ". Status: " + transferStatus + ".");
}

Let’s re-run our program and see the output

INFO WalletTransferServiceImpl - Preparing to transfer INR. 2500.
INFO WalletTransferServiceImpl - TransferLog: INR. 2500 has been transferred from UserABC to UserXYZ under the transactionId ACDF-2382-TX7E. Status: SUCCESS.

MDC support is available in LOG4J, LOG4J2 or SLF4J. MDC has lots of application uses, mainly in scenarios where execution of several different threads causes interleaved log messages that would be hard to understand or debug if it doesn’t print the context information.

Leave a Reply

Your email address will not be published.