Logging Best Practices using Log4j

Log4j is a logging library for Java applications and the purpose of inserting log statements into the code is a low-tech method for debugging it. It may also be the only way because debuggers are not always available or applicable. This is often the case for distributed applications.
Logging Levels

ALL: The ALL Level has the lowest possible rank and is intended to turn on all logging.
TRACE: This level gives more detailed information than the DEBUG level.
DEBUG: Shows messages classified as DEBUG, INFO, WARN, ERROR, and FATAL
INFO: Shows messages classified as INFO, WARN, ERROR, and FATAL
WARN: Shows messages classified as WARN, ERROR, and FATAL
ERROR: Shows messages classified as ERROR and FATAL
FATAL: shows messages at a FATAL level only
OFF: The OFF Level has the highest possible rank and is intended to turn off logging.

The standard levels of Log4j are ordered as

ALL < TRACE < DEBUG < INFO < WARN < ERROR < FATAL < OFF

A logging request of a particular level is said to be enabled if that level is higher than or equal to the level of its logger.

For example,
Create a maven based standalone project – logger

1. Below is the project’s pom.xml file with required log4j dependencies

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <groupId>com.roytuts</groupId>
    <artifactId>logger</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <packaging>jar</packaging>
    <name>logger</name>
    <url>http://maven.apache.org</url>
    <properties>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <jdk.version>1.8</jdk.version>
        <slf4j.version>1.7.5</slf4j.version>
    </properties>
    <dependencies>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>${slf4j.version}</version>
        </dependency>
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-log4j12</artifactId>
            <version>${slf4j.version}</version>
        </dependency>
    </dependencies>
    <build>
        <plugins>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-compiler-plugin</artifactId>
                <configuration>
                    <source>${jdk.version}</source>
                    <target>${jdk.version}</target>
                </configuration>
            </plugin>
        </plugins>
    </build>
</project>

2. Create log4j.xml file. Here I have kept only console appender. If you want you can also keep file appender.

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
    <appender name="consoleAppender" class="org.apache.log4j.ConsoleAppender">
        <param name="Target" value="System.out" />
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="[%d] %-5p %c %x - %m%n" />
        </layout>
    </appender>
    <root>
        <priority value="warn" />
        <appender-ref ref="consoleAppender" />
    </root>
</log4j:configuration>

3. Create Java main class

package com.roytuts.logger;
import org.apache.log4j.Logger;
public class LoggerDemo {
    private static final Logger LOGGER = Logger.getLogger(LoggerDemo.class);
    public static void main(String[] args) {
        LOGGER.trace("Trace Message!");
        LOGGER.debug("Debug Message!");
        LOGGER.info("Info Message!");
        LOGGER.warn("Warn Message!");
        LOGGER.error("Error Message!");
        LOGGER.fatal("Fatal Message!");
    }
}

Now if you run the main class then you will get below output

[2015-12-08 07:50:22,025] WARN  com.roytuts.logger.LoggerDemo  - Warn Message!
[2015-12-08 07:50:22,026] ERROR com.roytuts.logger.LoggerDemo  - Error Message!
[2015-12-08 07:50:22,026] FATAL com.roytuts.logger.LoggerDemo  - Fatal Message!

We got the above output becasue I have set “priority value” as “warn”

<root>
    <priority value="warn" />
    <appender-ref ref="consoleAppender" />
</root>

Now if we change the “priority value” as “debug” and run the main class again

<root>
    <priority value="debug" />
    <appender-ref ref="consoleAppender" />
</root>

You will get below output

[2015-12-08 07:52:19,801] DEBUG com.roytuts.logger.LoggerDemo  - Debug Message!
[2015-12-08 07:52:19,803] INFO  com.roytuts.logger.LoggerDemo  - Info Message!
[2015-12-08 07:52:19,803] WARN  com.roytuts.logger.LoggerDemo  - Warn Message!
[2015-12-08 07:52:19,803] ERROR com.roytuts.logger.LoggerDemo  - Error Message!
[2015-12-08 07:52:19,803] FATAL com.roytuts.logger.LoggerDemo  - Fatal Message!

So the logging of the message depends on the level that has been set to the logger.

Best Practices of Logging

It is recommended to declare the logger as static and final to ensure that every instance of a class shares the common logger object.
Write required code to check whether logging has been enabled at the right level.
Meaningful log messages that are relevant to the context should be logged.
You can use logging in the following scenarios,
– method entry (with method’s input parameter if any)
– method exit
– root cause message of exceptions at origin point.

Loggings which are used just for the purpose of debugging should be avoided.
For example,

try{
    LOGGER.debug("About to enter getJobForRegion()”);
    // The above logging statement is not required,
    // if getJobForRegion() method logs its method entry
    Long jobId = getJobForRegion(String region);
    LOGGER.debug("Exited getJobForRegion()");
    // The above logging statement is not required,
    // if getJobForRegion() method logs its method exit
} catch(AppException ae) {
    LOGGER.error(ae.getErrorMessage());
    throw ae;
}

Avoid logging at every place where a custom exception is thrown and instead log the custom exception message in its catch handler.

For example,

try{
    if(null == jobId) {
        LOGGER.error("Job Id cannot be null");
        // The above logging statement is not required,
        // since the catch handler logs the message
        // passed through the AppException thrown
        throw new AppException("Job Id cannot be null");
    }
} catch(AppException ae) {
    LOGGER.error(ae.getErrorMessage());
    throw ae;
}

Thanks for reading.

Leave a Reply

Your email address will not be published. Required fields are marked *