Logback

Logback vs Log4j Example

In this post, we feature a comprehensive Example on Logback vs Log4j. Logback and Log4j are the most widely used logging frameworks in the Java community. In this tutorial, I will demonstrate how to log the messages in Java applications with both Logback and Log4j.

1. Introduction

Java applications rely on the logging messages to identify and troubleshoot problems in non-development environments. Logback and Log4j are the most widely used logging frameworks in the Java community.

Apache Log4j is a Java-based logging utility. It is a part of the Apache Logging Services project and was first released in 2001. It stopped at version 1.2.17. Apache announced that it was an end of life product and is broken on JDK9.

Logback is intended as a successor to the Log4j project. It was first released in August 2006. The most updated version currently is 2.11.1 and was released on July 2018. Logback implements SLF4J API. The Logback documentation site has a list of reasons for why it is better than Log4j.

Apache Log4j 2 is an upgrade to Log4j that provides significant improvements over Log4j and provides many of the improvements available in Logback while fixing some inherent problems in Logback’s architecture. Click here for a detailed comparison between Logback and Log4j2.

Logback and Log4j have three of the same core components: loggers, appenders, and layouts. These components work together to enable developers to log messages and format messages.

  • Logger – the class that the application interacts with to create log messages
  • Appender – the destination which holds log messages
  • Layout – the interface that prepares and formats the messages for outputting

In this example, I will build three Java applications which utilize Log4j, Log4j2, and Logback respectively to demonstrate:

  • How to log the messages with Logger
  • How to format the log messages with Layout
  • Where to place the log messages with Appender
  • How to mask the password

2. Technologies Used

The example code in this article was built and run using:

  • Java 1.8.101
  • Maven 3.3.9
  • Eclipse Oxygen
  • Logback 1.2.3
  • Log4j 1.2.17
  • Log4j2 2.8.2

3. Maven Java Application

There are many ways to create a Maven Java application. The easiest way for me is via Eclipse. Please click here for detailed steps.

3.1 Dependencies

Pom.xml manages the project dependencies.

pom.xml

<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>jcg.zheng.demo</groupId>
	<artifactId>log4j-logback-demo</artifactId>
	<version>0.0.1-SNAPSHOT</version>
	<name>Mary Zheng demo for log4j vs logback</name>

	<properties>
		<maven.compiler.target>1.8</maven.compiler.target>
		<maven.compiler.source>1.8</maven.compiler.source>
	</properties>

	<dependencies>
		<!-- log4j1 -->
		<dependency>
			<groupId>log4j</groupId>
			<artifactId>log4j</artifactId>
			<version>1.2.17</version>
		</dependency>


		<!-- log4j2 -->
		<dependency>
			<groupId>org.apache.logging.log4j</groupId>
			<artifactId>log4j-core</artifactId>
			<version>2.8.2</version>
		</dependency>

		<dependency>
			<groupId>org.apache.logging.log4j</groupId>
			<artifactId>log4j-api</artifactId>
			<version>2.8.2</version>
		</dependency>

		<!-- logback -->
		<dependency>
			<groupId>ch.qos.logback</groupId>
			<artifactId>logback-access</artifactId>
			<version>1.2.3</version>
		</dependency>

		<dependency>
			<groupId>ch.qos.logback</groupId>
			<artifactId>logback-classic</artifactId>
			<version>1.2.3</version>
		</dependency>
		<dependency>
			<groupId>ch.qos.logback</groupId>
			<artifactId>logback-core</artifactId>
			<version>1.2.3</version>
		</dependency>

		<!-- https://mvnrepository.com/artifact/junit/junit -->
		<dependency>
			<groupId>junit</groupId>
			<artifactId>junit</artifactId>
			<version>4.8.1</version>
			<scope>test</scope>
		</dependency>


	</dependencies>
</project>
  • Line 17-21: Log4j dependency
  • Line 25-35: Log4j 2 dependencies
  • Line 38-53: Logback dependencies

3.2 Data Model

In this step, I will create a Java class:DemoModel. It includes the password. We will hide the password in the log file at steps 5 and 6.

DemoModel.java

package jcg.zheng.demo.util;

public class DemoModel {
	private Integer modelId;
	private String username;
	private String password;
	
	public static DemoModel createDummy() {
		DemoModel model = new DemoModel();
		model.setModelId(123);
		model.setUsername("mzheng");
		model.setPassword("PwdShouldHide");
		return model;
	}
	

	public Integer getModelId() {
		return modelId;
	}

	public void setModelId(Integer modelId) {
		this.modelId = modelId;
	}

	public String getUsername() {
		return username;
	}

	public void setUsername(String username) {
		this.username = username;
	}

	public String getPassword() {
		return password;
	}

	public void setPassword(String password) {
		this.password = password;
	}
	
	@Override
	public String toString() {
		System.out.println("toString called");
		StringBuilder sb = new StringBuilder();
		sb.append("Id=").append(String.valueOf(this.getModelId())).append(", ");	
		sb.append("Username=").append(this.getUsername()).append(", ");
		sb.append("Password=").append(this.getPassword());
		
		return sb.toString();
	}

}

4. Logger Level

Log4j and Log4j2 have six logger levels; Logback has five.

LevelDescriptionLog4jLogbackLog4j2
TRACEThe most detailed informational eventsYesYesYes
DEBUGFine-grained informational events that are most useful to debug an applicationYesYesYes
INFOInformational messages that highlight the progress of the applicationYesYesYes
WARNPotentially harmful situationsYesYesYes
ERRORError eventsYesYesYes
FATALError lead the application to abortYesNoYes

Note: Log4j2 also supports custom logger levels, click here for more details.

5. Log Messages

Log4j and Logback log the messages in a very similar way. In this step, I will demonstrate this with three Java applications.

5.1 Log4j1_Demo

In this step, I will create a Java class –Log4j1_Demo. It logs six logging messages, one for each logger level.

Log4j1_Demo.java

package jcg.zheng.demo;

import org.apache.log4j.Logger;

import jcg.zheng.demo.util.DemoModel;

public class Log4j1_Demo {

	private static final Logger LOG = Logger.getLogger(Log4j1_Demo.class);

	public static void main(String[] args) {
		Log4j1_Demo demo = new Log4j1_Demo();
		demo.step1(DemoModel.createDummy());

	}

	public void step1(DemoModel model) {
		if (LOG.isTraceEnabled()) {
			LOG.trace("Start step1 for " + model.toString());
		}

		if (LOG.isDebugEnabled()) {
			LOG.debug("Start step1 for  " + model.toString());
		}

		if (LOG.isInfoEnabled()) {
			LOG.info("Start step1" + model.toString());
		}

		LOG.warn("Start step1" + model.toString());

		LOG.error("Start step1" + model.toString());

		LOG.fatal("Start step1" + model.toString());
	}

}
  • Line 9: Logger is org.apache.log4j.Logger
  • line 18, 22, 26: isTraceEnabled, isDebugEnabled, and isInfoEnabled will have better performance

5.2 Log4j2_Demo

In this step, I will create a Java class –Log4j2_Demo. It logs six messages.

Log4j2_Demo.java

package jcg.zheng.demo;

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

import jcg.zheng.demo.util.DemoModel;

public class Log4j2_Demo {
	private static Logger LOG = LogManager.getLogger(Log4j2_Demo.class);

	public static void main(String[] args) {
		Log4j2_Demo demo = new Log4j2_Demo();
		demo.step1(DemoModel.createDummy());

	}

	public void step1(DemoModel model) {

		LOG.trace("Start step1 for {}", () -> model.toString());
		LOG.debug("Start step1 for {}", () -> model.toString());
		LOG.info("Start step1 {}", () -> model.toString());
		LOG.warn("Start step1 {}", () -> model.toString());
		LOG.error("Start step1 {}", () -> model.toString());
		LOG.fatal("Start step1 {}", () -> model.toString());

	}

}
  • Line 9: Logger is org.apache.logging.log4j.Logger
  • Line 19-24: Lazy logging provides better performance. It also prevents calling model.toString()

5.2.1 MaskLog

I will create a MaskLog class to hide the password from the log file. MaskLog extends LogEventPatternConverter. It searches the "Password=.*" then replaces it with “Password=***".

MaskLog.java

package jcg.zheng.demo.log4j2;

import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.pattern.ConverterKeys;
import org.apache.logging.log4j.core.pattern.LogEventPatternConverter;

@Plugin(name = "logmask", category = "Converter")
@ConverterKeys(value = { "cm" })
public class MaskLog extends LogEventPatternConverter {

	public MaskLog(String[] options) {
		super("cm", "cm");
	}

	public static MaskLog newInstance(final String[] options) {
		return new MaskLog(options);
	}

	@Override
	public void format(LogEvent logEvent, StringBuilder outputMsg) {
		String message = logEvent.getMessage().getFormattedMessage();
		if (message != null && message.contains("Password")) {
			String finalMsg = message.replaceAll("Password=.*", "Password=***");
			outputMsg.append(finalMsg);
		} else {
			outputMsg.append(message);
		}
	}

}
  • Line 9: Define custom converter: cm
  • Line 24: Hide the password

5.3 Logback_Demo

In this step, I will create a Java class –Logback_Demo. It logs five messages.

Logback_Demo.java

package jcg.zheng.demo;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import jcg.zheng.demo.util.DemoModel;

public class Logback_Demo {

	private final Logger lOG = LoggerFactory.getLogger(this.getClass());

	public static void main(String[] args) {
		Logback_Demo demo = new Logback_Demo();
		demo.step1(DemoModel.createDummy());

	}

	public void step1(DemoModel model) {

		if (lOG.isTraceEnabled()) {
			lOG.trace("Start step1 for {}", model.toString());
		}

		if (lOG.isDebugEnabled()) {
			lOG.debug("Start step1 for {}", model.toString());
		}

		if (lOG.isInfoEnabled()) {
			lOG.info("Start step1 {}", model.toString());
		}

		if (lOG.isWarnEnabled()) {
			lOG.warn("Start step1 {}", model.toString());
		}

		if (lOG.isErrorEnabled()) {
			lOG.error("Start step1 {}", model.toString());
		}
	}

}
  • Line 10: Logger is org.slf4j.Logger
  • Line 20, 24, 28, 32, 36: Parameterized logging does not prevent calling model.toString(), so use isXXXEnabled for better performance

6. Logging Configuration

Logback and Log4j use configuration to format the log events based on the layout convention pattern and write the log events to the desired destination based on the appender. Logback, Log4j, and Log4j2 can be configured programmatically. However, it is far more flexible to configure it using configuration files. Logback and Log4j support different configuration file types: properties file, XML file, Groovy file, JSON file, YAML file, etc. The most commonly used is the XML format. In this step, I will show you how to configure with the XML files for Logback, Log4j, and Log4j2.

6.1 Log4j.xml

Log4j’s configuration files can be written in XML or in Java properties (key=value) format. In this step, I will show a log4j.xml configuration to write the logs at the logs/log4j1 directory.

Log4j.xml

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration debug="true">
	<appender name="DAILYLOG"
		class="org.apache.log4j.DailyRollingFileAppender">
		<param name="File" value="logs/log4j1/demo.log" />
		<param name="Append" value="true" />
		<!-- Rollover at midnight each day -->
		<param name="DatePattern" value="'.'yyyy-MM-dd" />
		<layout class="org.apache.log4j.EnhancedPatternLayout">
			<param name="ConversionPattern"
				value="%d{yyyy-MM-dd'T'HH:mm:ss.SSSZZZ} llevel=%-5p, lthread_id='%t',lclass=%C{2.}.%L,lmethod=%M %m%n" />
		</layout>
	</appender>
	<appender name="CONSOLE"
		class="org.apache.log4j.ConsoleAppender">
		<param name="Target" value="System.out" />
		<layout class="org.apache.log4j.EnhancedPatternLayout">
			<param name="ConversionPattern"
				value="%d{yyyy-MM-dd'T'HH:mm:ss.SSSZZZ} llevel=%-5p, lthread_id='%t',lclass=%C{2.}.%L,lmethod=%M %m%n" />
		</layout>
	</appender>

	<logger name="jcg.zheng.demo">
		<level value="INFO" />
	</logger>

	<root>
		<priority value="INFO" />
		<appender-ref ref="DAILYLOG" />
		<appender-ref ref="CONSOLE" />
	</root>
</log4j:configuration>

6.2 Log4j2.xml

Log4j2’s configuration files can be written in the Java properties (key=value) format, XML, JSON, YAML format. In this step, I will show a  log4j2.xml configuration to log the messages at the logs/log4j2 directory.

Log4j2.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="trace" monitorInterval="30"
	packages="jcg.zheng.demo.log4j2"
	xmlns="http://logging.apache.org/log4j/2.0/config">
	<Properties>
		<Property name="basePath">logs/log4j2</Property>
	</Properties>
	<Appenders>
		<!-- File Appender -->
		<RollingFile name="FILE"
			fileName="${basePath}/logfile.log" filePattern="${basePath}/logfile.%d{yyyy-MM-dd}-%i.log" append="true">
			<PatternLayout
				pattern="%-5p | %d{yyyy-MM-dd HH:mm:ss} | [%t] %C{2} (%F:%L) - %cm%n" />
			<Policies>
				<SizeBasedTriggeringPolicy size="1 KB" />
			</Policies>
			<DefaultRolloverStrategy max="4" />
		</RollingFile>
		<!-- Console Appender -->
		<Console name="STDOUT" target="SYSTEM_OUT">
			<PatternLayout
				pattern="%-5p | %d{yyyy-MM-dd HH:mm:ss} | [%t] %C{2} (%F:%L) - %cm%n" />
		</Console>
	</Appenders>
	<Loggers>
		<Logger name="jcg.zheng.demo" level="warn" />
		<Root level="info">
			<AppenderRef ref="STDOUT" />
			<AppenderRef ref="FILE" />
		</Root>
	</Loggers>
</Configuration>
  • Line 3: MaskLog package is included
  • Line 13, 22: Use cm to mask the password

6.3 Logback.xml

Logback’s configuration files can be written in XML and groovy. In this step, I will show a logback.xml configuration to write the logs at the logs/logback directory.

Logback.xml

<!-- demo the debug value difference -->
<configuration debug="true" scan="true"
	scanPeriod="10 seconds">
	<property name="LOG_DIR" value="logs/logback" />
	<appender name="FILE_INFO"
		class="ch.qos.logback.core.rolling.RollingFileAppender">
		<file>${LOG_DIR}/demo.log</file>
		<encoder
			class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
			<Pattern>
				%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} -
				%replace(%msg){"Password=.*","Password=xxxxx"}%n
			</Pattern>
		</encoder>

		<rollingPolicy
			class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
			<!-- rollover daily -->
			<fileNamePattern>${LOG_DIR}/demo.%d{yyyy-MM-dd}.%i.log
			</fileNamePattern>
			<timeBasedFileNamingAndTriggeringPolicy
				class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
				<maxFileSize>100MB</maxFileSize>
			</timeBasedFileNamingAndTriggeringPolicy>
		</rollingPolicy>
	</appender>

	<appender name="consoleAppender"
		class="ch.qos.logback.core.ConsoleAppender">
		<encoder>
			<charset>UTF-8</charset>
			<Pattern>%d %-4relative [%thread] %-5level %logger{35} - %msg%n
			</Pattern>
		</encoder>
	</appender>

	<logger name="jcg.zheng.demo" level="warn" additivity="false">
		<appender-ref ref="FILE_INFO" />
		<appender-ref ref="consoleAppender" />
	</logger>

	<root level="error">
		<appender-ref ref="FILE_INFO" />
		<appender-ref ref="consoleAppender" />
	</root>
</configuration>
  • Line 4: Define log directory property
  • Line 22: Use %replace to mask the password

6.4 XML Configuration Summary

As you see these three XML configuration examples, the Logback XML configuration is very similar to Log4j. Log4j2 has different XML elements for the Appender and Layout. Logback provides a translator to convert the configuration file from Log4j format to Logback.

7. Demo

In this step, we will execute three Java applications and monitor the log messages at both system console and the log files.

7.1 Log4j Demo

Execute the Log4j1_demo application.

output

log4j: reset attribute= "false".
log4j: Threshold ="null".
log4j: Retreiving an instance of org.apache.log4j.Logger.
log4j: Setting [jcg.zheng.demo] additivity to [true].
log4j: Level value for jcg.zheng.demo is  [INFO].
log4j: jcg.zheng.demo level set to INFO
log4j: Level value for root is  [INFO].
log4j: root level set to INFO
log4j: Class name: [org.apache.log4j.DailyRollingFileAppender]
log4j: Setting property [file] to [logs/log4j1/demo.log].
log4j: Setting property [append] to [true].
log4j: Setting property [datePattern] to ['.'yyyy-MM-dd].
log4j: Parsing layout of class: "org.apache.log4j.EnhancedPatternLayout"
log4j: Setting property [conversionPattern] to [%d{yyyy-MM-dd'T'HH:mm:ss.SSSZZZ} llevel=%-5p, lthread_id='%t',lclass=%C{2.}.%L,lmethod=%M %m%n].
log4j: setFile called: logs/log4j1/demo.log, true
log4j: setFile ended
log4j: Appender [DAILYLOG] to be rolled at midnight.
log4j: Adding appender named [DAILYLOG] to category [root].
log4j: Class name: [org.apache.log4j.ConsoleAppender]
log4j: Setting property [target] to [System.out].
log4j: Parsing layout of class: "org.apache.log4j.EnhancedPatternLayout"
log4j: Setting property [conversionPattern] to [%d{yyyy-MM-dd'T'HH:mm:ss.SSSZZZ} llevel=%-5p, lthread_id='%t',lclass=%C{2.}.%L,lmethod=%M %m%n].
log4j: Adding appender named [CONSOLE] to category [root].
toString called
2018-08-02T21:17:15.732-0500 llevel=INFO , lthread_id='main',lclass=jc.zh.de.Log4j1_Demo.27,lmethod=step1 Start step1Id=123, Username=mzheng, Password=PwdShouldHide
toString called
2018-08-02T21:17:15.737-0500 llevel=WARN , lthread_id='main',lclass=jc.zh.de.Log4j1_Demo.30,lmethod=step1 Start step1Id=123, Username=mzheng, Password=PwdShouldHide
toString called
2018-08-02T21:17:15.737-0500 llevel=ERROR, lthread_id='main',lclass=jc.zh.de.Log4j1_Demo.31,lmethod=step1 Start step1Id=123, Username=mzheng, Password=PwdShouldHide
toString called
2018-08-02T21:17:15.737-0500 llevel=FATAL, lthread_id='main',lclass=jc.zh.de.Log4j1_Demo.32,lmethod=step1 Start step1Id=123, Username=mzheng, Password=PwdShouldHide

7.2 Log4j 2 Demo

Execute the Log4j2_demo application.

output

2018-08-02 21:23:40,977 main DEBUG Initializing configuration XmlConfiguration[location=C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml]
2018-08-02 21:23:40,993 main DEBUG Installed script engines
2018-08-02 21:23:41,611 main DEBUG Oracle Nashorn Version: 1.8.0_31, Language: ECMAScript, Threading: Not Thread Safe, Compile: true, Names: {nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript}
2018-08-02 21:23:41,611 main DEBUG Took 0.002831 seconds to load 1 plugins from package jcg.zheng.demo.log4j2
2018-08-02 21:23:41,611 main DEBUG PluginManager 'Core' found 112 plugins
2018-08-02 21:23:41,611 main DEBUG PluginManager 'Level' found 0 plugins
2018-08-02 21:23:41,611 main DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
2018-08-02 21:23:41,642 main TRACE TypeConverterRegistry initializing.
2018-08-02 21:23:41,643 main DEBUG PluginManager 'TypeConverter' found 26 plugins
2018-08-02 21:23:41,643 main DEBUG createProperty(name="basePath", value="logs/log4j2")
2018-08-02 21:23:41,643 main DEBUG Building Plugin[name=properties, class=org.apache.logging.log4j.core.config.PropertiesPlugin].
2018-08-02 21:23:41,659 main DEBUG configureSubstitutor(={basePath=logs/log4j2}, Configuration(C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml))
2018-08-02 21:23:41,659 main DEBUG PluginManager 'Lookup' found 13 plugins
2018-08-02 21:23:41,659 main DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2018-08-02 21:23:41,659 main DEBUG PatternLayout$Builder(pattern="%-5p | %d{yyyy-MM-dd HH:mm:ss} | [%t] %C{2} (%F:%L) - %cm%n", PatternSelector=null, Configuration(C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
2018-08-02 21:23:41,659 main DEBUG PluginManager 'Converter' found 42 plugins
2018-08-02 21:23:41,690 main DEBUG Building Plugin[name=SizeBasedTriggeringPolicy, class=org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy].
2018-08-02 21:23:41,690 main DEBUG createPolicy(size="1 KB")
2018-08-02 21:23:41,690 main DEBUG Building Plugin[name=Policies, class=org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy].
2018-08-02 21:23:41,690 main DEBUG createPolicy(={SizeBasedTriggeringPolicy(size=1024)})
2018-08-02 21:23:41,690 main DEBUG Building Plugin[name=DefaultRolloverStrategy, class=org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy].
2018-08-02 21:23:41,690 main DEBUG createStrategy(max="4", min="null", fileIndex="null", compressionLevel="null", ={}, stopCustomActionsOnError="true", Configuration(C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml))
2018-08-02 21:23:41,690 main DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.RollingFileAppender].
2018-08-02 21:23:41,721 main DEBUG RollingFileAppender$Builder(fileName="logs/log4j2/logfile.log", filePattern="logs/log4j2/logfile.%d{yyyy-MM-dd}-%i.log", append="true", locking="null", Policies(CompositeTriggeringPolicy(policies=[SizeBasedTriggeringPolicy(size=1024)])), DefaultRolloverStrategy(DefaultRolloverStrategy(min=1, max=4, useMax=true)), advertise="null", advertiseUri="null", createOnDemand="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%-5p | %d{yyyy-MM-dd HH:mm:ss} | [%t] %C{2} (%F:%L) - %cm%n), name="FILE", Configuration(C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml), Filter=null)
2018-08-02 21:23:41,721 main TRACE New file 'logs/log4j2/logfile.log' created = false
2018-08-02 21:23:41,737 main DEBUG Starting RollingFileManager logs/log4j2/logfile.log
2018-08-02 21:23:41,737 main DEBUG PluginManager 'FileConverter' found 2 plugins
2018-08-02 21:23:41,737 main DEBUG Setting prev file time to 2018-08-02T21:18:35.422-0500
2018-08-02 21:23:41,737 main DEBUG Initializing triggering policy CompositeTriggeringPolicy(policies=[SizeBasedTriggeringPolicy(size=1024)])
2018-08-02 21:23:41,737 main DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2018-08-02 21:23:41,737 main DEBUG PatternLayout$Builder(pattern="%-5p | %d{yyyy-MM-dd HH:mm:ss} | [%t] %C{2} (%F:%L) - %cm%n", PatternSelector=null, Configuration(C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
2018-08-02 21:23:41,737 main DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender].
2018-08-02 21:23:41,737 main DEBUG ConsoleAppender$Builder(target="SYSTEM_OUT", follow="null", direct="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%-5p | %d{yyyy-MM-dd HH:mm:ss} | [%t] %C{2} (%F:%L) - %cm%n), name="STDOUT", Configuration(C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml), Filter=null)
2018-08-02 21:23:41,753 main DEBUG Jansi is not installed, cannot find org.fusesource.jansi.WindowsAnsiOutputStream
2018-08-02 21:23:41,753 main DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false
2018-08-02 21:23:41,753 main DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin].
2018-08-02 21:23:41,753 main DEBUG createAppenders(={FILE, STDOUT})
2018-08-02 21:23:41,753 main DEBUG Building Plugin[name=logger, class=org.apache.logging.log4j.core.config.LoggerConfig].
2018-08-02 21:23:41,753 main DEBUG createLogger(additivity="true", level="WARN", name="jcg.zheng.demo", includeLocation="null", ={}, ={}, Configuration(C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml), Filter=null)
2018-08-02 21:23:41,753 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2018-08-02 21:23:41,753 main DEBUG createAppenderRef(ref="STDOUT", level="null", Filter=null)
2018-08-02 21:23:41,753 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2018-08-02 21:23:41,753 main DEBUG createAppenderRef(ref="FILE", level="null", Filter=null)
2018-08-02 21:23:41,768 main DEBUG Building Plugin[name=root, class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
2018-08-02 21:23:41,768 main DEBUG createLogger(additivity="null", level="INFO", includeLocation="null", ={STDOUT, FILE}, ={}, Configuration(C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml), Filter=null)
2018-08-02 21:23:41,768 main DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
2018-08-02 21:23:41,768 main DEBUG createLoggers(={jcg.zheng.demo, root})
2018-08-02 21:23:41,768 main DEBUG Configuration XmlConfiguration[location=C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml] initialized
2018-08-02 21:23:41,768 main DEBUG Starting configuration XmlConfiguration[location=C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml]
2018-08-02 21:23:41,768 main DEBUG Log4j2 ConfigurationScheduler starting 1 threads
2018-08-02 21:23:41,768 main DEBUG Started configuration XmlConfiguration[location=C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml] OK.
2018-08-02 21:23:41,768 main TRACE Stopping org.apache.logging.log4j.core.config.DefaultConfiguration@4629104a...
2018-08-02 21:23:41,768 main TRACE DefaultConfiguration notified 1 ReliabilityStrategies that config will be stopped.
2018-08-02 21:23:41,768 main TRACE DefaultConfiguration stopping root LoggerConfig.
2018-08-02 21:23:41,768 main TRACE DefaultConfiguration notifying ReliabilityStrategies that appenders will be stopped.
2018-08-02 21:23:41,768 main TRACE DefaultConfiguration stopping remaining Appenders.
2018-08-02 21:23:41,768 main DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-1
2018-08-02 21:23:41,768 main DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released: true
2018-08-02 21:23:41,768 main DEBUG Appender DefaultConsole-1 stopped with status true
2018-08-02 21:23:41,768 main TRACE DefaultConfiguration stopped 1 remaining Appenders.
2018-08-02 21:23:41,768 main TRACE DefaultConfiguration cleaning Appenders from 1 LoggerConfigs.
2018-08-02 21:23:41,768 main DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@4629104a OK
2018-08-02 21:23:41,831 main TRACE Reregistering MBeans after reconfigure. Selector=org.apache.logging.log4j.core.selector.ClassLoaderContextSelector@1bb266b3
2018-08-02 21:23:41,831 main TRACE Reregistering context (1/1): '2a139a55' org.apache.logging.log4j.core.LoggerContext@306cf3ea
2018-08-02 21:23:41,846 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55'
2018-08-02 21:23:41,846 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55,component=StatusLogger'
2018-08-02 21:23:41,846 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55,component=ContextSelector'
2018-08-02 21:23:41,846 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*'
2018-08-02 21:23:41,846 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=*'
2018-08-02 21:23:41,846 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55,component=AsyncAppenders,name=*'
2018-08-02 21:23:41,846 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55,component=AsyncLoggerRingBuffer'
2018-08-02 21:23:41,846 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*,subtype=RingBuffer'
2018-08-02 21:23:41,846 main DEBUG Registering MBean org.apache.logging.log4j2:type=2a139a55
2018-08-02 21:23:41,862 main DEBUG Registering MBean org.apache.logging.log4j2:type=2a139a55,component=StatusLogger
2018-08-02 21:23:41,862 main DEBUG Registering MBean org.apache.logging.log4j2:type=2a139a55,component=ContextSelector
2018-08-02 21:23:41,862 main DEBUG Registering MBean org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=
2018-08-02 21:23:41,862 main DEBUG Registering MBean org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=jcg.zheng.demo
2018-08-02 21:23:41,862 main DEBUG Registering MBean org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=FILE
2018-08-02 21:23:41,862 main DEBUG Registering MBean org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=STDOUT
2018-08-02 21:23:41,862 main TRACE Using default SystemClock for timestamps.
2018-08-02 21:23:41,862 main TRACE Using DummyNanoClock for nanosecond timestamps.
2018-08-02 21:23:41,862 main DEBUG Reconfiguration complete for context[name=2a139a55] at URI C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml (org.apache.logging.log4j.core.LoggerContext@306cf3ea) with optional ClassLoader: null
2018-08-02 21:23:41,862 main DEBUG Shutdown hook enabled. Registering a new one.
2018-08-02 21:23:41,862 main DEBUG LoggerContext[name=2a139a55, org.apache.logging.log4j.core.LoggerContext@306cf3ea] started OK.
toString called
WARN  | 2018-08-02 21:23:41 | [main] demo.Log4j2_Demo (Log4j2_Demo.java:22) - Start step1 Id=123, Username=mzheng, Password=***
toString called
ERROR | 2018-08-02 21:23:41 | [main] demo.Log4j2_Demo (Log4j2_Demo.java:23) - Start step1 Id=123, Username=mzheng, Password=***
2018-08-02 21:23:41,893 main TRACE DefaultRolloverStrategy.purge() took 9.0 milliseconds
2018-08-02 21:23:41,893 main DEBUG RollingFileManager executing synchronous FileRenameAction[logs\log4j2\logfile.log to logs\log4j2\logfile.2018-08-02-1.log, renameEmptyFiles=false]
2018-08-02 21:23:41,893 main TRACE Renamed file C:\gitworkspace\log4j-logback-demo\logs\log4j2\logfile.log to C:\gitworkspace\log4j-logback-demo\logs\log4j2\logfile.2018-08-02-1.log with Files.move
2018-08-02 21:23:41,893 main DEBUG Now writing to logs/log4j2/logfile.log at 2018-08-02T21:23:41.893-0500
toString called
FATAL | 2018-08-02 21:23:41 | [main] demo.Log4j2_Demo (Log4j2_Demo.java:24) - Start step1 Id=123, Username=mzheng, Password=***
2018-08-02 21:23:41,893 pool-1-thread-1 DEBUG Stopping LoggerContext[name=2a139a55, org.apache.logging.log4j.core.LoggerContext@306cf3ea]
2018-08-02 21:23:41,893 pool-1-thread-1 DEBUG Stopping LoggerContext[name=2a139a55, org.apache.logging.log4j.core.LoggerContext@306cf3ea]...
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE Unregistering 1 MBeans: [org.apache.logging.log4j2:type=2a139a55]
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE Unregistering 1 MBeans: [org.apache.logging.log4j2:type=2a139a55,component=StatusLogger]
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE Unregistering 1 MBeans: [org.apache.logging.log4j2:type=2a139a55,component=ContextSelector]
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE Unregistering 2 MBeans: [org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=, org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=jcg.zheng.demo]
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE Unregistering 2 MBeans: [org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=STDOUT, org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=FILE]
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55,component=AsyncAppenders,name=*'
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55,component=AsyncLoggerRingBuffer'
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*,subtype=RingBuffer'
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE Stopping XmlConfiguration[location=C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml]...
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE XmlConfiguration notified 3 ReliabilityStrategies that config will be stopped.
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE XmlConfiguration stopping 2 LoggerConfigs.
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE XmlConfiguration stopping root LoggerConfig.
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE XmlConfiguration notifying ReliabilityStrategies that appenders will be stopped.
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE XmlConfiguration stopping remaining Appenders.
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false, all resources released: true
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG Appender STDOUT stopped with status true
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG Shutting down RollingFileManager logs/log4j2/logfile.log
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG Shutting down RollingFileManager {}logs/log4j2/logfile.log
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG All asynchronous threads have terminated
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG RollingFileManager shutdown completed with status true
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG Shut down RollingFileManager logs/log4j2/logfile.log, all resources released: true
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG Appender FILE stopped with status true
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE XmlConfiguration stopped 2 remaining Appenders.
2018-08-02 21:23:41,909 pool-1-thread-1 TRACE XmlConfiguration cleaning Appenders from 3 LoggerConfigs.
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG Log4j2 ConfigurationScheduler shutting down threads in java.util.concurrent.ScheduledThreadPoolExecutor@268918ec[Running, pool size = 1, active threads = 0, queued tasks = 1, completed tasks = 0]
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG Stopped XmlConfiguration[location=C:\gitworkspace\log4j-logback-demo\target\classes\log4j2.xml] OK
2018-08-02 21:23:41,909 pool-1-thread-1 DEBUG Stopped LoggerContext[name=2a139a55, org.apache.logging.log4j.core.LoggerContext@306cf3ea] with status true

Line 86, 88, 94: Hide the password.

7.3 Logback Demo

Execute the Logback_demo application.

output

21:18:53,336 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
21:18:53,336 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
21:18:53,338 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/C:/gitworkspace/log4j-logback-demo/target/classes/logback.xml]
21:18:53,521 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Will scan for changes in [file:/C:/gitworkspace/log4j-logback-demo/target/classes/logback.xml] 
21:18:53,521 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Setting ReconfigureOnChangeTask scanning period to 10 seconds
21:18:53,526 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
21:18:53,533 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE_INFO]
21:18:53,621 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1654589030 - No compression will be used
21:18:53,623 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1654589030 - Will use the pattern logs/logback/demo.%d{yyyy-MM-dd}.%i.log for the active file
21:18:53,628 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@75412c2f - The date pattern is 'yyyy-MM-dd' from file name pattern 'logs/logback/demo.%d{yyyy-MM-dd}.%i.log'.
21:18:53,628 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@75412c2f - Roll-over at midnight.
21:18:53,633 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@75412c2f - Setting initial period to Thu Aug 02 16:13:47 CDT 2018
21:18:53,633 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@75412c2f - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
21:18:53,633 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@75412c2f - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
21:18:53,641 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE_INFO] - Active log file name: logs/logback/demo.log
21:18:53,643 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE_INFO] - File property is set to [logs/logback/demo.log]
21:18:53,646 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
21:18:53,648 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [consoleAppender]
21:18:53,648 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
21:18:53,651 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jcg.zheng.demo] to WARN
21:18:53,651 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jcg.zheng.demo] to false
21:18:53,651 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE_INFO] to Logger[jcg.zheng.demo]
21:18:53,651 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [consoleAppender] to Logger[jcg.zheng.demo]
21:18:53,651 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to ERROR
21:18:53,651 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE_INFO] to Logger[ROOT]
21:18:53,653 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [consoleAppender] to Logger[ROOT]
21:18:53,653 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
21:18:53,653 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@2aafb23c - Registering current configuration as safe fallback point
toString called
2018-08-02 21:18:53,656 368  [main] WARN  jcg.zheng.demo.Logback_Demo - Start step1 Id=123, Username=mzheng, Password=PwdShouldHide
toString called
2018-08-02 21:18:53,661 373  [main] ERROR jcg.zheng.demo.Logback_Demo - Start step1 Id=123, Username=mzheng, Password=PwdShouldHide

Here are the logs output files.

Logback vs Log4j - Logs Folder
Figure 1 Logs Folder

8. Summary

In this article, we covered the fundamental functions of using Logback and Log4j in three Java applications. We demonstrated three configuration examples to create, format, and filter log messages as well as to mask the password data. Logback requires Java 6 since version 1.1.3. Log4j2 2.4+ requires Java 7, versions 2.0-alpha1 to 2.3 required Java 6.

9. Download the Source Code

This example consists of Java applications to demonstrate the Logback and Log4j features.

Download
You can download the full source code of this example here: Logback vs Log4j Example

Mary Zheng

Mary has graduated from Mechanical Engineering department at ShangHai JiaoTong University. She also holds a Master degree in Computer Science from Webster University. During her studies she has been involved with a large number of projects ranging from programming and software engineering. She works as a senior Software Engineer in the telecommunications sector where she acts as a leader and works with others to design, implement, and monitor the software solution.
Subscribe
Notify of
guest

This site uses Akismet to reduce spam. Learn how your comment data is processed.

1 Comment
Oldest
Newest Most Voted
Inline Feedbacks
View all comments
Russell Bateman
6 years ago

Really good job here, Mary!

Back to top button