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.
Table Of Contents
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 messagesAppender
– the destination which holds log messagesLayout
– 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.
Level | Description | Log4j | Logback | Log4j2 |
---|---|---|---|---|
TRACE | The most detailed informational events | Yes | Yes | Yes |
DEBUG | Fine-grained informational events that are most useful to debug an application | Yes | Yes | Yes |
INFO | Informational messages that highlight the progress of the application | Yes | Yes | Yes |
WARN | Potentially harmful situations | Yes | Yes | Yes |
ERROR | Error events | Yes | Yes | Yes |
FATAL | Error lead the application to abort | Yes | No | Yes |
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
, andisInfoEnabled
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 useisXXXEnabled
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.
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.
You can download the full source code of this example here: Logback vs Log4j Example
Really good job here, Mary!