Improved Logging using Log4j2

Some of the Log4j2 advantages over Log4j:

* Log4j2 is much faster than Log4j, especially in multithreaded environments

* Log4j2 uses a plugin system where we can define custom appenders, filters and Layouts.

* More robust: Log4j1 will loose messages during reconfiguration. Log4j2 will not.

* Log4j2 supports message objects whereas log4j supports only strings.

* Log4j2 supports configurations in multiple formats like property files, xml, json and yaml.

Setup:

If you are using a maven project, include the following dependency in your pom.xml:

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

To start logging messages using this basic configuration, all you need to do is obtain a Logger instance using the LogManager class:

private static Logger logger = LogManager.getLogger(MyService.class);

Then you can use the logger object with methods corresponding to the log level you want:

String libraryName = "log4j2";
logger.error("This is an error message logged by {}", libraryName);

Note that the above statement use a "message object" which means that the place holder {} gets replaced with the passed parameter. You can use any number of place holders followed by a list of parameters and they get substituted in the order of passing. In older version of log4j, we use the same logger like:

logger.error("This is an error message logged by " + libraryName);

The drawback with this approach is that the JVM should perform concatenation even if we are not going to log the message. This reduces the performance of the application.

Configuration:

Log4j2 supports configuration in any of the following formats:

1. Property file

2. XML

3. JSON

4. YAML

Out of the box, log4j2 will automatically provide a simple configuration, if you don’t explicitly define one yourself. The default configuration logs to the console at a level of ERROR level or above. To use the basic features of log4j2 in your project, the minimum required library id the log4j2 core library.

Configuring Appenders:

In log4j2, an appender is basically responsible for sending log messages to a certain output destination.

Here are some of the most useful types of appenders that the library provides:

ConsoleAppender – logs messages to the System console

FileAppender – writes log messages to a file

RollingFileAppender – writes the messages to a rolling log file(A file that gets backed up periodically)

JDBCAppender – uses a relational database for logs

AsyncAppender – contains a list of other appenders and determines the logs for these to be written in a separate thread

FailoverAppender - defines a primary appender and a list of backups that will step in to handle the logging in case the primary one fails.

On top of all the given appenders, we can create our own appenders using plugins provided by Lo4j2. For example, we can create an appender to send the messages to another server where it can be analyzed in real time.

Lets see how each of these appenders can be configured in log4j2 configuration. In this example, we will use XML based configuration. Create a file log4j2.xml in src/main/resources or if you are using in your test project, create the file in src/test/resources with the following content:

<Configuration name="ConfigTest" status="ERROR" monitorInterval="5">
  <Appenders>

    <Console name="STDOUT" target="SYSTEM_OUT">
      <PatternLayout pattern="[%p] %m%n"/>
    </Console>

    <File name="MyFile" fileName="logs/logfile.log">
      <PatternLayout>
        <Pattern>%m%n</Pattern>
      </PatternLayout>
    </File>

    <RollingFile name="RollingFileAppender" fileName="logs/app.log"
      filePattern="logs/${date:yyyy-MM}/app-%d{MM-dd-yyyy}-%i.log.gz">
        <PatternLayout>
            <Pattern>[%p] %m%n</Pattern>
        </PatternLayout>
        <Policies>
            <!-- A new file will be created as soon as the previous log file reached 50MB in size -->
            <SizeBasedTriggeringPolicy size="50 MB" /> 
        </Policies>
        <DefaultRolloverStrategy max="20" /> <!-- Keep only the last 20 files. Files older than that will be removed -->
    </RollingFile>

    <!--
    For JDBC appender configuration, you need to define a ConnectionSource, which can be either a JNDI Data Source or a custom ConnectionFactory. The logger uses the ConnectionSource to get JDBC connections, which is why it’s important to use a connection pool for better performance.
    -->
    <JDBC name="JDBCAppender" tableName="logs">
        <DataSource jndiName="java:/comp/env/jdbc/LoggingDataSource" />
        <Column name="date" isEventTimestamp="true" />
        <Column name="logger" pattern="%logger" />
        <Column name="level" pattern="%level" />
        <Column name="message" pattern="%message" />
        <Column name="exception" pattern="%ex{full}" />
    </JDBC>

    <!-- The following will try to log messages in DB and if it fails, uses the RollingFileAppender and if that also fails, uses the Console appender -->
    <Failover name="FailoverAppender" primary="JDBCAppender">
      <Failovers>
        <AppenderRef ref="RollingFileAppender" />
        <AppenderRef ref="Console" />
      </Failovers>
    </Failover>

  </Appenders>
  <Loggers>
    <Logger name="com.test1" level="debug" additivity="false">
      <AppenderRef ref="RollingFileAppender"/>
    </Logger>
    <Logger name="com.test2" level="debug" additivity="false">
      <AppenderRef ref="MyFile"/>
    </Logger>
    <Logger name="com.test3" level="error" additivity="false">
      <AppenderRef ref="JDBCAppender"/>
    </Logger>
    <Logger name="com.test4" level="warn" additivity="false">
      <AppenderRef ref="FailoverAppender"/>
    </Logger>
    
    <Root level="error">
      <AppenderRef ref="STDOUT"/>
    </Root>
  </Loggers>
</Configuration>

In the above example,

1. all the "debug and above" log messages logged under the package com.test1 will be logged in the rolling file located at logs/app.log.

2. All the "debug and above" messages logged under the package com.test2 will be logged in the file located at logs/logfile.log.

3. All the "error and above" messages logged under the package com.test3 will be logged in the database table named "logs".

4. All the "warn and above" messages logged under the package com.test4 will be logged in the database table "logs". If that fails, the messages will go into the file located at logs/app.log. If that also fails, the messages will be printed in the console.

5. All the "error and above" messages that are defined in any package other than the above given packages will be printed in the console.

Configuring Layouts:

While the appenders are responsible for sending log messages to a destination, the layouts are used by appenders to define how a log message will be formatted.

Here’s a brief description of some of the more commonly used layouts that log4j2 offers:

PatternLayout – configures messages according to a String pattern

JsonLayout – defines a JSON format for log messages

CsvLayout – can be used to create messages in a CSV format

The PatternLayout:

In the configuration example given in the previous section, you can see the message format is a rather simple "[%p] %m%n" which means any message logged like the following

logger.debug("Message 1 Numpy");
logger.warn("Message 2 Ninja");

would yield the output

[DEBUG] Message 1 Numpy
[WARN] Message 2 Ninja

Let’s look at an example of configuring a PatternLayout that configures log lines to show the date, thread, log level and log message with different colors for different log levels:

<Console name="Console" target="SYSTEM_OUT">
    <PatternLayout pattern="%d [%p] %c{1} - %m%n" />
</Console>

These specifiers are well worth understanding in detail, so let’s have a closer look:

%d – outputs the date of the log event in the default format.

%p – displays the log level of the message

%c{1} - Prints the classname in which the log message is generated

%msg%n – outputs the log message

The above setup would generate messages similar to the following:

2016-06-20 19:18:02,958 [DEBUG] Log4j2HelloWorldExample - Debug Message Logged !!
2016-06-20 19:18:02,959 [INFO] Log4j2HelloWorldExample - Info Message Logged !!

The JsonLayout

Logging data using the JSON format has some significant advantages, such as making the logs easier to be analyzed and processed by logging tools down the line. To be able to produce JSON, you need to add the jackson-databind library to the classpath:

<dependency>
    <groupId>com.fasterxml.jackson.core</groupId>
    <artifactId>jackson-databind</artifactId>
    <version>2.14.1</version>
</dependency>

To configure the JSONLayout in log4j2, you can simply define the corresponding tag:

<JSONLayout complete="true" compact="false"/>

Setting complete=true will produce a well-formed JSON document:

[
    {
        "timeMillis" : 1496306649055,
        "thread" : "main",
        "level" : "INFO",
        "loggerName" : "RollingFileLogger",
        "message" : "Some log message form the application",
        "endOfBatch" : false,
        "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
        "threadId" : 1,
        "threadPriority" : 5
    },
    
    ...
]

CSVLayout

The CSV layout is a bit involving. First add the following dependency to your project:

<dependency>
        <groupId>org.apache.commons</groupId>
        <artifactId>commons-csv</artifactId>
        <version>1.4</version>
    </dependency>

Then add a file appender with CSV format in the log4j2 xml as follows:

<Configuration status="WARN">
    <Properties>
        <Property name="csvLog.fileName">csvLog</Property>
        <Property name="file-header">column1,column2</Property>
    </Properties>
    <Appenders>
        <RollingFile name="csvFile" 
                     fileName="${csvLog.fileName}.tmp"
                     filePattern="${csvLog.filename}-%d{MM-dd-yyyy}-%i.csv" >
            <CsvParameterLayout delimiter="," header="${file-header}\n"/>
            <Policies>
                <TimeBasedTriggeringPolicy interval="1" modulate="true" />
                <SizeBasedTriggeringPolicy size="10 MB" />
            </Policies>
            <DefaultRolloverStrategy max="200" />
        </RollingFile>
    </Appenders>
    <Loggers>
        <Root level="debug" additivity="false">
            <AppenderRef ref="csvFile" level="debug"/>
        </Root>
    </Loggers>
</Configuration>

Then the log statement

logger.info("sample output", "Numpy", "Ninja");

Will result in the following output in the file:

column1,column2
Numpy,Ninja

We have seen some of the highlights of using log4j2 in your project. There are a lot more things you can do with log4j2. Upgrading to log4j2 will bring a lot of hidden benefits to your project.

Happy Learning!