Merge pull request #814 from danidemi/master

PR for "Improve Logging With Mapped Diagnostic Context"

log-mdc/README.md

@@ -0,0 +1,16 @@
+### Relevant Articles:
+- TBD
+
+### References
+
+_Log4j MDC_
+* <https://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/MDC.html>
+* <http://veerasundar.com/blog/2009/10/log4j-mdc-mapped-diagnostic-context-what-and-why/>
+
+_Log4j2 MDC_
+* <https://logging.apache.org/log4j/2.x/manual/thread-context.html>
+
+_Logback MDC_
+* <http://logback.qos.ch/manual/mdc.html>
+
+

log-mdc/pom.xml

@@ -0,0 +1,66 @@
+<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
+	xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
+	<modelVersion>4.0.0</modelVersion>
+	<groupId>com.baeldung</groupId>
+	<artifactId>logmdc</artifactId>
+	<version>0.0.1-SNAPSHOT</version>
+	<name>logmdc</name>
+	<description>tutorial on logging with MDC</description>
+
+	<dependencies>
+
+		<dependency>
+			<groupId>org.springframework</groupId>
+			<artifactId>spring-context</artifactId>
+			<version>4.3.3.RELEASE</version>
+		</dependency>
+		<dependency>
+			<groupId>org.springframework</groupId>
+			<artifactId>spring-webmvc</artifactId>
+			<version>4.3.3.RELEASE</version>
+		</dependency>
+
+		<!--log4j dependencies -->
+		<dependency>
+			<groupId>log4j</groupId>
+			<artifactId>log4j</artifactId>
+			<version>1.2.17</version>
+		</dependency>
+
+		<!--log4j2 dependencies -->
+		<dependency>
+			<groupId>org.apache.logging.log4j</groupId>
+			<artifactId>log4j-api</artifactId>
+			<version>2.7</version>
+		</dependency>
+		<dependency>
+			<groupId>org.apache.logging.log4j</groupId>
+			<artifactId>log4j-core</artifactId>
+			<version>2.7</version>
+		</dependency>
+
+		<!--disruptor for log4j2 async logging -->
+		<dependency>
+			<groupId>com.lmax</groupId>
+			<artifactId>disruptor</artifactId>
+			<version>3.3.4</version>
+		</dependency>
+
+		<!--logback dependencies -->
+		<dependency>
+			<groupId>ch.qos.logback</groupId>
+			<artifactId>logback-classic</artifactId>
+			<version>1.1.7</version>
+		</dependency>
+		
+		<dependency>
+		    <groupId>junit</groupId>
+		    <artifactId>junit</artifactId>
+		    <version>4.12</version>
+		    <scope>test</scope>
+		</dependency>
+		
+
+	</dependencies>
+
+</project>

log-mdc/src/main/java/com/baeldung/mdc/TransactionFactory.java

@@ -0,0 +1,21 @@
+package com.baeldung.mdc;
+
+import static java.lang.Math.floor;
+import static java.lang.Math.random;
+
+import java.util.UUID;
+
+public class TransactionFactory {
+
+	private static final String[] NAMES = {"John", "Susan", "Marc", "Samantha"};
+	private static long nextId = 1;
+	
+	public Transfer newInstance() {
+		String transactionId = String.valueOf( nextId++ );
+		String owner = NAMES[ (int) floor(random()*NAMES.length) ];
+		long amount = (long) (random()*1500 + 500);
+		Transfer tx = new Transfer(transactionId, owner, amount);
+		return tx;
+	}
+	
+}

log-mdc/src/main/java/com/baeldung/mdc/Transfer.java

@@ -0,0 +1,27 @@
+package com.baeldung.mdc;
+
+public class Transfer {
+
+    private String transactionId;
+    private String sender;
+    private Long amount;
+
+    public Transfer(String transactionId, String sender, long amount) {
+        this.transactionId = transactionId;
+        this.sender = sender;
+        this.amount = amount;
+    }
+
+    public String getSender() {
+        return sender;
+    }
+
+    public String getTransactionId() {
+        return transactionId;
+    }
+
+    public Long getAmount() {
+        return amount;
+    }
+
+}

log-mdc/src/main/java/com/baeldung/mdc/TransferDemo.java

@@ -0,0 +1,32 @@
+package com.baeldung.mdc;
+
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+
+import org.apache.log4j.Logger;
+
+import com.baeldung.mdc.log4j.Log4JRunnable;
+import com.baeldung.mdc.log4j2.Log4J2Runnable;
+import com.baeldung.mdc.slf4j.Slf4jRunnable;
+
+public class TransferDemo {
+
+    public static void main(String[] args) {
+
+        ExecutorService executor = Executors.newFixedThreadPool(3);
+        TransactionFactory transactionFactory = new TransactionFactory();
+
+        for (int i = 0; i < 10; i++) {
+            Transfer tx = transactionFactory.newInstance();
+            
+            //Runnable task = new Log4JRunnable(tx);
+            //Runnable task = new Log4J2Runnable(tx);
+            Runnable task = new Slf4jRunnable(tx);
+            
+            executor.submit(task);
+        }
+
+        executor.shutdown();
+
+    }
+}

log-mdc/src/main/java/com/baeldung/mdc/TransferService.java

@@ -0,0 +1,28 @@
+package com.baeldung.mdc;
+
+/**
+ * A fake transfer service simulating an actual one.
+ */
+public abstract class TransferService {
+
+    /** Sample service transferring a given amount of money. 
+     * @return {@code true} when the transfer complete successfully, {@code false} otherwise. */
+    public boolean transfer(long amount) {
+        beforeTransfer(amount);
+        // exchange messages with a remote system to transfer the money
+        try {
+            // let's pause randomly to properly simulate an actual system.
+            Thread.sleep((long) (500 + Math.random() * 500));
+        } catch (InterruptedException e) {
+            // should never happen
+        }
+        // let's simulate both failing and successful transfers
+        boolean outcome = Math.random() >= 0.25;
+        afterTransfer(amount, outcome);
+        return outcome;
+    }
+
+    abstract protected void beforeTransfer(long amount);
+
+    abstract protected void afterTransfer(long amount, boolean outcome);
+}

log-mdc/src/main/java/com/baeldung/mdc/log4j/Log4JRunnable.java

@@ -0,0 +1,26 @@
+package com.baeldung.mdc.log4j;
+
+import org.apache.log4j.MDC;
+
+import com.baeldung.mdc.Transfer;
+
+public class Log4JRunnable implements Runnable {
+
+    private Transfer tx;
+    private static Log4JTransferService log4jBusinessService = new Log4JTransferService();
+
+    public Log4JRunnable(Transfer tx) {
+        this.tx = tx;
+    }
+
+    public void run() {
+
+        MDC.put("transaction.id", tx.getTransactionId());
+        MDC.put("transaction.owner", tx.getSender());
+
+        log4jBusinessService.transfer(tx.getAmount());
+
+        MDC.clear();
+
+    }
+}

log-mdc/src/main/java/com/baeldung/mdc/log4j/Log4JTransferService.java

@@ -0,0 +1,21 @@
+package com.baeldung.mdc.log4j;
+
+import org.apache.log4j.Logger;
+
+import com.baeldung.mdc.TransferService;
+
+public class Log4JTransferService extends TransferService {
+
+    private Logger logger = Logger.getLogger(Log4JTransferService.class);
+
+    @Override
+    protected void beforeTransfer(long amount) {
+        logger.info("Preparing to transfer " + amount + "$.");
+    }
+
+    @Override
+    protected void afterTransfer(long amount, boolean outcome) {
+        logger.info("Has transfer of " + amount + "$ completed successfully ? " + outcome + ".");
+    }
+
+}

log-mdc/src/main/java/com/baeldung/mdc/log4j2/Log4J2Runnable.java

@@ -0,0 +1,25 @@
+package com.baeldung.mdc.log4j2;
+
+import org.apache.logging.log4j.ThreadContext;
+
+import com.baeldung.mdc.Transfer;
+
+public class Log4J2Runnable implements Runnable {
+    private final Transfer tx;
+    private Log4J2TransferService log4j2BusinessService = new Log4J2TransferService();
+
+    public Log4J2Runnable(Transfer tx) {
+        this.tx = tx;
+    }
+
+    public void run() {
+
+        ThreadContext.put("transaction.id", tx.getTransactionId());
+        ThreadContext.put("transaction.owner", tx.getSender());
+
+        log4j2BusinessService.transfer(tx.getAmount());
+
+        ThreadContext.clearAll();
+
+    }
+}

log-mdc/src/main/java/com/baeldung/mdc/log4j2/Log4J2TransferService.java

@@ -0,0 +1,22 @@
+package com.baeldung.mdc.log4j2;
+
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+
+import com.baeldung.mdc.TransferService;
+
+public class Log4J2TransferService extends TransferService {
+
+    private static final Logger logger = LogManager.getLogger();
+
+    @Override
+    protected void beforeTransfer(long amount) {
+        logger.info("Preparing to transfer {}$.", amount);
+    }
+
+    @Override
+    protected void afterTransfer(long amount, boolean outcome) {
+        logger.info("Has transfer of {}$ completed successfully ? {}.", amount, outcome);
+    }
+
+}

log-mdc/src/main/java/com/baeldung/mdc/slf4j/Slf4TransferService.java

@@ -0,0 +1,22 @@
+package com.baeldung.mdc.slf4j;
+
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+import com.baeldung.mdc.TransferService;
+
+final class Slf4TransferService extends TransferService {
+
+    private static final Logger logger = LoggerFactory.getLogger(Slf4TransferService.class);
+
+    @Override
+    protected void beforeTransfer(long amount) {
+        logger.info("Preparing to transfer {}$.", amount);
+    }
+
+    @Override
+    protected void afterTransfer(long amount, boolean outcome) {
+        logger.info("Has transfer of {}$ completed successfully ? {}.", amount, outcome);
+    }
+
+}

log-mdc/src/main/java/com/baeldung/mdc/slf4j/Slf4jRunnable.java

@@ -0,0 +1,24 @@
+package com.baeldung.mdc.slf4j;
+
+import org.slf4j.MDC;
+
+import com.baeldung.mdc.Transfer;
+
+public class Slf4jRunnable implements Runnable {
+    private final Transfer tx;
+
+    public Slf4jRunnable(Transfer tx) {
+        this.tx = tx;
+    }
+
+    public void run() {
+
+        MDC.put("transaction.id", tx.getTransactionId());
+        MDC.put("transaction.owner", tx.getSender());
+
+        new Slf4TransferService().transfer(tx.getAmount());
+
+        MDC.clear();
+
+    }
+}

log-mdc/src/main/resources/log4j.properties

@@ -0,0 +1,8 @@
+log4j.appender.consoleAppender=org.apache.log4j.ConsoleAppender
+log4j.appender.consoleAppender.layout=org.apache.log4j.PatternLayout
+
+#note the %X{userName} - this is how you fetch data from Mapped Diagnostic Context (MDC)
+#log4j.appender.consoleAppender.layout.ConversionPattern=%-4r [%t] %5p %c{1} %x - %m%n
+log4j.appender.consoleAppender.layout.ConversionPattern=%-4r [%t] %5p %c{1} %x - %m - tx.id=%X{transaction.id} tx.owner=%X{transaction.owner}%n 
+
+log4j.rootLogger = TRACE, consoleAppender

log-mdc/src/main/resources/log4j2.xml

@@ -0,0 +1,17 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<Configuration status="INFO">
+	<Appenders>
+		<Console name="stdout" target="SYSTEM_OUT">
+			<PatternLayout
+				pattern="%-4r [%t] %5p %c{1} - %m - tx.id=%X{transaction.id} tx.owner=%X{transaction.owner}%n" />
+		</Console>
+	</Appenders>
+
+	<Loggers>
+		<Logger name="com.baeldung.log4j2" level="TRACE" />
+
+		<AsyncRoot level="DEBUG">
+			<AppenderRef ref="stdout" />
+		</AsyncRoot>
+	</Loggers>
+</Configuration>

log-mdc/src/main/resources/logback.xml

@@ -0,0 +1,13 @@
+<configuration>
+
+	<appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
+		<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
+			<pattern>%-4r [%t] %5p %c{1} - %m - tx.id=%X{transaction.id} tx.owner=%X{transaction.owner}%n</pattern>
+		</encoder>
+	</appender>
+
+	<root level="TRACE">
+		<appender-ref ref="stdout" />
+	</root>
+
+</configuration>

log-mdc/src/test/java/com/baeldung/mdc/log4j/Demo.java

@@ -0,0 +1,26 @@
+package com.baeldung.mdc.log4j;
+
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+import java.util.concurrent.TimeUnit;
+
+import org.junit.Test;
+
+import com.baeldung.mdc.TransactionFactory;
+import com.baeldung.mdc.Transfer;
+
+public class Demo {
+
+    @Test
+    public void main() throws InterruptedException {
+        ExecutorService executor = Executors.newFixedThreadPool(3);
+        TransactionFactory transactionFactory = new TransactionFactory();
+        for (int i = 0; i < 10; i++) {
+            Transfer tx = transactionFactory.newInstance();
+            Runnable task = new Log4JRunnable(tx);            
+            executor.submit(task);
+        }
+        executor.shutdown();
+        executor.awaitTermination(60, TimeUnit.SECONDS);
+    }
+}

log-mdc/src/test/java/com/baeldung/mdc/log4j2/Demo.java

@@ -0,0 +1,30 @@
+package com.baeldung.mdc.log4j2;
+
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+import java.util.concurrent.TimeUnit;
+
+import org.apache.log4j.Logger;
+import org.junit.Test;
+
+import com.baeldung.mdc.TransactionFactory;
+import com.baeldung.mdc.Transfer;
+import com.baeldung.mdc.log4j.Log4JRunnable;
+import com.baeldung.mdc.log4j2.Log4J2Runnable;
+import com.baeldung.mdc.slf4j.Slf4jRunnable;
+
+public class Demo {
+
+    @Test
+    public void main() throws InterruptedException {
+        ExecutorService executor = Executors.newFixedThreadPool(3);
+        TransactionFactory transactionFactory = new TransactionFactory();
+        for (int i = 0; i < 10; i++) {
+            Transfer tx = transactionFactory.newInstance();
+            Runnable task = new Log4J2Runnable(tx);            
+            executor.submit(task);
+        }
+        executor.shutdown();
+        executor.awaitTermination(60, TimeUnit.SECONDS);
+    }
+}

log-mdc/src/test/java/com/baeldung/mdc/slf4j/Demo.java

@@ -0,0 +1,30 @@
+package com.baeldung.mdc.slf4j;
+
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+import java.util.concurrent.TimeUnit;
+
+import org.apache.log4j.Logger;
+import org.junit.Test;
+
+import com.baeldung.mdc.TransactionFactory;
+import com.baeldung.mdc.Transfer;
+import com.baeldung.mdc.log4j.Log4JRunnable;
+import com.baeldung.mdc.log4j2.Log4J2Runnable;
+import com.baeldung.mdc.slf4j.Slf4jRunnable;
+
+public class Demo {
+
+    @Test
+    public void main() throws InterruptedException {
+        ExecutorService executor = Executors.newFixedThreadPool(3);
+        TransactionFactory transactionFactory = new TransactionFactory();
+        for (int i = 0; i < 10; i++) {
+            Transfer tx = transactionFactory.newInstance();
+            Runnable task = new Slf4jRunnable(tx);            
+            executor.submit(task);
+        }
+        executor.shutdown();
+        executor.awaitTermination(60, TimeUnit.SECONDS);
+    }
+}