Log4j2 Logging: A Primer

anishek agarwal
Jan 2, 2017 · 13 min read
<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>
<Configuration status="debug">
<Appenders>
<File name="file-log" fileName="/tmp/logging.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>

</Appenders>
<Loggers>
<Logger name="com.anishek" level="info" additivity="false">
<appender-ref ref="file-log" level="info"/>
</Logger>
</Loggers>
</Configuration>
package com.anishek.logging;
import org.apache.logging.log4j.LogManager;
public class Start {
public static void main(String[] args) {
LogManager.getLogger(Start.class).info("log something that will be useful.");
}
}
2016-12-29 16:34:52.126 [main] com.anishek.logging.Start - log something that will be useful.
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug">
<Appenders>
<File name="file-log" fileName="/tmp/logging.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>
<File name="file-log-2" fileName="/tmp/error.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>

</Appenders>
<Loggers>
<Logger name="com.anishek-info" level="info" additivity="false">
<appender-ref ref="file-log" level="info"/>
</Logger>
<Logger name="com.anishek-error" level="error" additivity="false">
<appender-ref ref="file-log-2" level="error"/>
</Logger>
</Loggers>
</Configuration>
LogManager.getLogger("com.anishek-info").info("log something that will be useful.");
LogManager.getLogger("com.anishek-error").error("A critical event occurred and we want to separately track this.");
$ cat /tmp/logging.out 
2016-12-29 17:12:15.662 [main] com.anishek.logging.Start - log something that will be useful.

$ cat /tmp/error.out
2016-12-29 17:12:15.667 [main] com.anishek.logging.Start - A critical event occurred and we want to separately track this.
<Configuration status="debug">
<Appenders>
<File name="file-log" fileName="/tmp/logging.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>
<File name="file-log-2" fileName="/tmp/error.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>

</Appenders>
<Loggers>
<Logger name="com.anishek" level="info" additivity="false">
<appender-ref ref="file-log" level="info"/>
<appender-ref ref="file-log-2" level="error"/>
</Logger>

</Loggers>
</Configuration>
Logger logger = LogManager.getLogger(Start.class);
logger.info("log something that will be useful.");
logger.error("A critical event occurred and we want to separately track this.");
$ cat /tmp/logging.out 
2016-12-29 17:08:15.998 [main] com.anishek.logging.Start - log something that will be useful.
2016-12-29 17:08:15.999 [main] com.anishek.logging.Start - A critical event occurred and we want to separately track this.
$ cat /tmp/error.out
2016-12-29 17:08:15.999 [main] com.anishek.logging.Start - A critical event occurred and we want to separately track this.
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug">
<Appenders>
<File name="ui-log" fileName="/tmp/ui.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>
<File name="service-log" fileName="/tmp/service.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>
<File name="domain-log" fileName="/tmp/domain.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>

</Appenders>
<Loggers>
<Logger name="com.anishek.ui" level="info" additivity="false">
<appender-ref ref="ui-log" level="info"/>
</Logger>
<Logger name="com.anishek.service" level="info" additivity="false">
<appender-ref ref="service-log" level="info"/>
</Logger>
<Logger name="com.anishek.domain" level="info" additivity="false">
<appender-ref ref="domain-log" level="info"/>
</Logger>
</Loggers>
</Configuration>
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug">
<Appenders>
<File name="ui-log" fileName="/tmp/ui.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>
<File name="service-log" fileName="/tmp/service.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>
<File name="domain-log" fileName="/tmp/domain.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>
<File name="error-log" fileName="/tmp/error.out" append="false" level="">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %level [%t] %C - %msg%n</pattern>
</PatternLayout>
</File>

</Appenders>
<Loggers>
<Logger name="com.anishek.ui" level="info">
<appender-ref ref="ui-log" level="info"/>
</Logger>
<Logger name="com.anishek.service" level="info">
<appender-ref ref="service-log" level="info"/>
</Logger>
<Logger name="com.anishek.domain" level="info">
<appender-ref ref="domain-log" level="info"/>
</Logger>
<Logger name="com" level="error">
<appender-ref ref="error-log" level="error"/>
</Logger>

</Loggers>
</Configuration>

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug">
<Appenders>
<File name="default-log" fileName="/tmp/default.out" append="false">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %level [%t] %C - %X %msg%n</pattern>
</PatternLayout>
</File>

</Appenders>
<Loggers>
<Logger name="com.anishek" level="info" additivity="false">
<appender-ref ref="default-log" level="info"/>
</Logger>
</Loggers>
</Configuration>
package com.anishek.logging;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.ThreadContext;

public class Start {

public static void main(String[] args) {
ThreadContext.put("useId", "testUser");
Logger logger = LogManager.getLogger(Start.class);
logger.info("log something from parent thread.");
new Thread(() -> logger.info("log something from child thread")).start();
}
2016-12-30 17:11:22.880 INFO [main] com.anishek.logging.Start - {useId=testUser} log something from parent thread.
2016-12-30 17:11:22.886 INFO [Thread-1] com.anishek.logging.Start - {} log something from child thread
package com.anishek.logging;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.ThreadContext;

public class Start {

public static void main(String[] args) {
System.setProperty("isThreadContextMapInheritable", "true");
ThreadContext.put("useId", "testUser");
Logger logger = LogManager.getLogger(Start.class);
logger.info("log something from parent thread.");
new Thread(() -> logger.info("log something from child thread")).start();
}
2016-12-30 17:13:52.636 INFO [main] com.anishek.logging.Start - {useId=testUser} log something from parent thread.
2016-12-30 17:13:52.641 INFO [Thread-1] com.anishek.logging.Start - {useId=testUser} log something from child thread
package com.anishek.logging;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.ThreadContext;

import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;

public class MultiThreaded {

public static void main(String[] args) throws InterruptedException {
System.setProperty("isThreadContextMapInheritable", "true");
ExecutorService poolOne = Executors.newFixedThreadPool(3, threadFactory("pool-1-"));
ExecutorService poolTwo = Executors.newFixedThreadPool(1, threadFactory("pool-2-"));

AtomicInteger atomicInteger = new AtomicInteger(1);
Logger logger = LogManager.getLogger(MultiThreaded.class);

Runnable runnableTwo = () -> logger.info("now we are in another");

Runnable runnableOne = () -> {
String value = String.valueOf(atomicInteger.getAndIncrement());
ThreadContext.put(value, value);
ThreadContext.put("thread", Thread.currentThread().getName());
logger.info("something to log in one thread");
poolTwo.submit(runnableTwo);
};

poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);

poolOne.shutdown();
poolOne.awaitTermination(5, TimeUnit.SECONDS);


poolTwo.shutdown();
poolTwo.awaitTermination(5, TimeUnit.SECONDS);

}


private static ThreadFactory threadFactory(final String prefix) {
return new ThreadFactory() {
int counter = 0;

@Override
public Thread newThread(Runnable r) {
return new Thread(r, prefix + (++counter));
}
};
}
}
2017-01-02 15:17:57.067 INFO [pool-1-2] com.anishek.logging.MultiThreaded - {2=2, thread=pool-1-2} something to log in one thread
2017-01-02 15:17:57.067 INFO [pool-1-1] com.anishek.logging.MultiThreaded - {1=1, thread=pool-1-1} something to log in one thread
2017-01-02 15:17:57.067 INFO [pool-1-3] com.anishek.logging.MultiThreaded - {3=3, thread=pool-1-3} something to log in one thread
2017-01-02 15:17:57.070 INFO [pool-1-1] com.anishek.logging.MultiThreaded - {1=1, 4=4, thread=pool-1-1} something to log in one thread
2017-01-02 15:17:57.070 INFO [pool-1-2] com.anishek.logging.MultiThreaded - {2=2, 6=6, thread=pool-1-2} something to log in one thread
2017-01-02 15:17:57.070 INFO [pool-1-3] com.anishek.logging.MultiThreaded - {3=3, 5=5, thread=pool-1-3} something to log in one thread

2017-01-02 15:17:57.070 INFO [pool-2-1] com.anishek.logging.MultiThreaded - {2=2, thread=pool-1-2} now we are in another
2017-01-02 15:17:57.070 INFO [pool-2-1] com.anishek.logging.MultiThreaded - {2=2, thread=pool-1-2} now we are in another
2017-01-02 15:17:57.070 INFO [pool-2-1] com.anishek.logging.MultiThreaded - {2=2, thread=pool-1-2} now we are in another
2017-01-02 15:17:57.071 INFO [pool-2-1] com.anishek.logging.MultiThreaded - {2=2, thread=pool-1-2} now we are in another
2017-01-02 15:17:57.071 INFO [pool-2-1] com.anishek.logging.MultiThreaded - {2=2, thread=pool-1-2} now we are in another
2017-01-02 15:17:57.071 INFO [pool-2-1] com.anishek.logging.MultiThreaded - {2=2, thread=pool-1-2} now we are in another
public class MultiThreaded {

public static void main(String[] args) throws InterruptedException {
System.setProperty("isThreadContextMapInheritable", "true");
ExecutorService poolOne = Executors.newFixedThreadPool(3, threadFactory("pool-1-"));
ExecutorService poolTwo = Executors.newFixedThreadPool(1, threadFactory("pool-2-"));

AtomicInteger atomicInteger = new AtomicInteger(1);
Logger logger = LogManager.getLogger(MultiThreaded.class);

Runnable runnableTwo = () -> logger.info("now we are in another");

Runnable runnableOne = () -> {
String value = String.valueOf(atomicInteger.getAndIncrement());
ThreadContext.put(value, value);
ThreadContext.put("thread", Thread.currentThread().getName());
logger.info("something to log in one thread");
poolTwo.submit(runnableTwo);
ThreadContext.remove("thread");
ThreadContext.remove(value);

};

poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);

poolOne.shutdown();
poolOne.awaitTermination(5, TimeUnit.SECONDS);


poolTwo.shutdown();
poolTwo.awaitTermination(5, TimeUnit.SECONDS);

}


private static ThreadFactory threadFactory(final String prefix) {
return new ThreadFactory() {
int counter = 0;

@Override
public Thread newThread(Runnable r) {
return new Thread(r, prefix + (++counter));
}
};
}
}

public class MultiThreaded {

public static void main(String[] args) throws InterruptedException {
System.setProperty("isThreadContextMapInheritable", "true");
ExecutorService poolOne = Executors.newFixedThreadPool(3, threadFactory("pool-1-"));

AtomicInteger atomicInteger = new AtomicInteger(1);
Logger logger = LogManager.getLogger(MultiThreaded.class);

Runnable runnableTwo = () -> logger.info("now we are in another");

Runnable runnableOne = () -> {
String value = String.valueOf(atomicInteger.getAndIncrement());
ThreadContext.put(value, value);
ThreadContext.put("thread", Thread.currentThread().getName());
logger.info("something to log in one thread");
new Thread(runnableTwo).start();
ThreadContext.remove("thread");
ThreadContext.remove(value);
};

poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);
poolOne.submit(runnableOne);

poolOne.shutdown();
poolOne.awaitTermination(5, TimeUnit.SECONDS);
}


private static ThreadFactory threadFactory(final String prefix) {
return new ThreadFactory() {
int counter = 0;

@Override
public Thread newThread(Runnable r) {
return new Thread(r, prefix + (++counter));
}
};
}
}
2017-01-02 15:26:08.128 INFO [pool-1-2] com.anishek.logging.MultiThreaded - {2=2, thread=pool-1-2} something to log in one thread
2017-01-02 15:26:08.128 INFO [pool-1-3] com.anishek.logging.MultiThreaded - {3=3, thread=pool-1-3} something to log in one thread
2017-01-02 15:26:08.128 INFO [pool-1-1] com.anishek.logging.MultiThreaded - {1=1, thread=pool-1-1} something to log in one thread
2017-01-02 15:26:08.130 INFO [pool-1-3] com.anishek.logging.MultiThreaded - {4=4, thread=pool-1-3} something to log in one thread
2017-01-02 15:26:08.130 INFO [pool-1-2] com.anishek.logging.MultiThreaded - {6=6, thread=pool-1-2} something to log in one thread
2017-01-02 15:26:08.130 INFO [pool-1-1] com.anishek.logging.MultiThreaded - {5=5, thread=pool-1-1} something to log in one thread
2017-01-02 15:26:08.130 INFO [Thread-3] com.anishek.logging.MultiThreaded - {3=3, thread=pool-1-3} now we are in another
2017-01-02 15:26:08.130 INFO [Thread-2] com.anishek.logging.MultiThreaded - {1=1, thread=pool-1-1} now we are in another
2017-01-02 15:26:08.130 INFO [Thread-1] com.anishek.logging.MultiThreaded - {2=2, thread=pool-1-2} now we are in another
2017-01-02 15:26:08.131 INFO [Thread-4] com.anishek.logging.MultiThreaded - {4=4, thread=pool-1-3} now we are in another
2017-01-02 15:26:08.131 INFO [Thread-6] com.anishek.logging.MultiThreaded - {5=5, thread=pool-1-1} now we are in another
2017-01-02 15:26:08.131 INFO [Thread-5] com.anishek.logging.MultiThreaded - {6=6, thread=pool-1-2} now we are in another
System.setProperty("Log4jContextSelector", "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector");
LogManager.setFactory(new Log4jContextFactory());

Welcome to a place where words matter. On Medium, smart voices and original ideas take center stage - with no ads in sight. Watch
Follow all the topics you care about, and we’ll deliver the best stories for you to your homepage and inbox. Explore
Get unlimited access to the best stories on Medium — and support writers while you’re at it. Just $5/month. Upgrade