LOG4J2

Log4j2 Java Logging Example Tutorial – XML Configuration, Severity Levels, Formatting and Appenders

3 Comments

Why Logging?

Logging information refers to the recording of your application activity that help in analyzing runtime behavior of application especially when encounters unexpected scenarios, errors or tracking steps executed by any request. As much as logging is done will easy to analyze any issues and bugs in the code.

Now a days more companies are moving to cloud and focusing on monitor logs and log analysis. There are some tools for centralize log management such as Logstash, Loggy, Graylog etc.

Follow link to know more about How to do centralize logging by Logstash when logs scattered on multiple servers.

There are so many JAVA logging frameworks and tools such as log4j, log4j2, slf4j, tinylog, logback etc. But here we mainly focus on Apache Log4j2 severity level, configuration file ways and java logging.

Log4j2 New Features,Compare with Log4j and other Logging Framework

How to do Logging?

Java provides standard Logging API to work as wrapper over different Logging framework. Compatible frameworks can be loaded into JVM and accessed via the API. There is also a default logging framework implementation provided by the Sun JVM which accessed by the API. Many developers confuse this implementation with the Java Logging API.

Logging is broken into three major parts:

  • Logger : The Logger is responsible for capturing the message to be logged along with certain metadata and passing it to the logging framework. These messages can be  an object, debug text or exceptions with an optional severity level.
  • Formatter: After receiving the message formatter do formatting with output.
  • Appender :Formatted message output will go to appender for disposition. Appenders might include console display, appending to database, log file or email etc.

Severity Level :

In logging framework always maintain the current configured logging level for each logger. That configured severity level can be set more or less restrictive.

For example : As we know each log message will logged at certain level. suppose the logging level is set to “WARNING”, then all messages of that level or higher are logged, ERROR and FATAL.

Below is list of all severity level from top to bottom. If any lower severity level configured all severity level above of it will by default consider.

  1. FATAL: Severe errors that cause premature termination. Expect these to be immediately visible on a status console.
  2. ERROR: Other runtime errors or unexpected conditions. Expect these to be immediately visible on a status console.
  3. WARNING: Message that can cause issue in future.
  4. INFO: Interesting runtime events (startup/shutdown). Expect these to be immediately visible on a console, so be conservative and keep to a minimum.
  5. DEBUG: detailed information on the flow through the system. Expect these to be written to logs only.
  6. TRACE: more detailed information. Expect these to be written to logs only.

Why Severity Level ?

Correct severity level is required while logging object, messages or errors so that easily track/debug issues and also analyze the behavior and failure cases of application while doing centralize logging.

Formatters or renderers

A Formatter is an object that that takes log line or object or exceptions from loggers and convert in formatted string representation. Below is technique to define your customize log format.

TTCC (Time Thread Category Component) is message format pattern representation used by log4j2.

For example : %r [%t] %-5p %c %x – %m%n  will print log line as below

567 [main] INFO org.apache.log4j.examples.FacingIssuesOnIT- Exiting main method.

Where

  • %r Used to output the number of milliseconds elapsed from the construction of the layout until the creation of the logging event.
  • %t Used to output the name of the thread that generated the logging event.
  • %p Used to output the priority of the logging event.
  • %c Used to output the category of the logging event.
  • %x Used to output the NDC (nested diagnostic context) associated with the thread that generated the logging event.
  • %X{key} Used to output the MDC (mapped diagnostic context) associated with the thread that generated the logging event for specified key.
  • %m Used to output the application supplied message associated with the logging event.
  • %n Used to output the platform-specific newline character or characters.

Appenders or handlers

Appenders takes message at or above a specified minimum severity level and passed and posts to appropriate message dispositions. Log4j2 supports below disposition of appenders.

  • ConsoleAppender
  • FileAppender
  • JDBCAppender
  • AsyncAppender
  • CassandraAppender
  • FailoverAppender
  • FlumeAppender
  • JMS Appender
  • JPAAppender
  • HttpAppender
  • KafkaAppender
  • MemoryMappedFileAppender
  • NoSQLAppender
  • OutputStreamAppender
  • RandomAccessFileAppender
  • RewriteAppender
  • RollingFileAppender
  • RollingRandomAccessFileAppender
  • RoutingAppender
  • SMTPAppender
  • ScriptAppenderSelector
  • SocketAppender
  • SyslogAppender
  • ZeroMQ/JeroMQ Appender

Log4j2 Configuration Support:

Log4j2 configuration can be accomplished 1 to 4 ways.

  • Through a configuration file written in XML, JSON, YAML, or properties format.
  • Programmatically, by creating a ConfigurationFactory and Configuration implementation.
  • Programmatically, by calling the APIs exposed in the Configuration interface to add components to the default configuration.
  • Programmatically, by calling methods on the internal Logger class.

Log4j2 Automatic Configuration:

Log4j2 has the ability to automatically configure itself during initialization. When Log4j starts it will look all the ConfigurationFactory plugins and arrange them in weighted order from highest to lowest. As above, Log4j contains four ConfigurationFactory implementations: one for JSON, one for YAML, one for properties, and one for XML.

  1. Log4j will inspect the “log4j.configurationFile” system property and, if set, will attempt to load the configuration using the ConfigurationFactory that matches the file extension.
  2. If no system property is set the properties ConfigurationFactory will look for log4j2-test.properties in the classpath.
  3. If no such file is found the YAML ConfigurationFactory will look for log4j2-test.yaml or log4j2-test.yml in the classpath.
  4. If no such file is found the JSON ConfigurationFactory will look for log4j2-test.json or log4j2-test.jsn in the classpath.
  5. If no such file is found the XML ConfigurationFactory will look for log4j2-test.xml in the class path.
  6. If a test file cannot be located the properties ConfigurationFactory will look for log4j2.properties on the classpath.
  7. If a properties file cannot be located the YAML ConfigurationFactory will look for log4j2.yaml or log4j2.yml on the classpath.
  8. If a YAML file cannot be located the JSON ConfigurationFactory will look for log4j2.json or log4j2.jsn on the classpath.
  9. If a JSON file cannot be located the XML ConfigurationFactory will try to locate log4j2.xml on the classpath.
  10. If no configuration file could be located the DefaultConfiguration will be used. This will cause logging output to go to the console.

Here we mainly focus on log4j2 XML configuration for ConsoleAppender,  FileAppender and RollingFileAppender and will see how to apply filters for loggers on default, package level  and root level with different scenarios. also see how same java program logging work on different configuration.

Steps to configuration of log4j2 with any java application:

  • Create any console based Java application or Maven JAVA Console Application or Maven Web Application.
  • Add below dependency/jars on your application.
  • Add below log4j2.xml file in your application root folder or for maven in resource folder as below.
  • Add below JAVA program in any package of your application.

Configure as below :

log4jConfiguration

Dependencies : 

<!-- basic Log4j2 dependency -->

	org.apache.logging.log4j
	log4j-api
	2.6.1

	org.apache.logging.log4j
	log4j-core
	2.6.1

<!-- Asynchronous logging for multithreaded env -->

	com.lmax
	disruptor
	3.3.4




log4j2.xml configuration Here



<!-- Log File Name and Location -->

		target/FacingIssueOnIT.log
		C:/logs/

		<!-- Console Logging -->

		<!-- File Logging -->

				%d %p %c{1.} [%t] %m%n

		<!-- ByDefault, all log messages of level "trace" or higher will be logged.Log messages are sent to the "file" appender are severity level error or higher while  for console appender and log messages of level "error" and higher will be sent to the "STDOUT" appender. -->




JAVA Program Here


package com.logging;

import org.apache.logging.log4j.Logger;

import java.time.LocalDateTime;

import org.apache.logging.<span id="mce_SELREST_start" style="overflow:hidden;line-height:0;"></span>log4j.LogManager;

public class Log4jExample {

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

    public static void main(String[] args) {

    	  logger.fatal("Fatal log message :FacingIssuesOnIT");

    	  logger.error("Error log message :FacingIssuesOnIT");

    	  logger.warn("Warn log message :FacingIssuesOnIT");

    	  logger.info("Info log message :FacingIssuesOnIT");

          logger.debug("Debug log message :FacingIssuesOnIT");

          logger.trace("Trace log message :FacingIssuesOnIT");
    }
}



As below for console and file output are different because of logging configuration for STDOUT and file. If you noticed STDOUT is configured for severity level as debug that’s why in console printing all log lines for debug and above severity level except Trace. Same way for file output on location /target/FacingIssuesonIT.log are having logs for FATAL and ERROR only because file is configured for severity level as ERROR.


Console Output :


20171220 10:19:12.640 [main] FATAL com.logging.Log4jExample - Fatal log message :FacingIssuesOnIT
20171220 10:19:12.642 [main] ERROR com.logging.Log4jExample - Error log message
:FacingIssuesOnIT
20171220 10:19:12.642 [main] WARN  com.logging.Log4jExample - Warn log message :
FacingIssuesOnIT
20171220 10:19:12.642 [main] INFO  com.logging.Log4jExample - Info log message :
FacingIssuesOnIT
20171220 10:19:12.642 [main] DEBUG com.logging.Log4jExample - Debug log message
:FacingIssuesOnIT



File Output:


2017-12-20 10:19:12,640 FATAL c.l.Log4jExample [main] Fatal log message :FacingIssuesOnIT
2017-12-20 10:19:12,642 ERROR c.l.Log4jExample [main] Error log message :FacingIssuesOnIT



RollingFileAppender Configuration


The above was basic configuration and design for implement log4j2 logging so that easily understand. Now we will go in more detail for configuration  so that understand  how to log rolling and archieve logs and maintain easily by date and size of log file by implement FileAppender. We will also know about to implement logger filter on package level so that you can easily main logs for specific module or functionality.


Now making some changes in configuration file as well as in JAVA program to testing FileAppender.


log4j2.xml configuration



	<!-- Log File Name and Location -->

		target/FacingIssueOnIT.log
		C:/logs/

		<!-- Console Logging -->

		<!-- File Logging -->

				%d %p %c{1.} [%t] %m%n

		<!-- Rolling File -->

				%d{yyyyMMdd HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n

	<!-- package level logger -->
		<!-- Loggers classes whose package name start with com.logging will log message of level  			"debug" or higher -->

		<!-- ByDefault, all log messages of level "trace" or higher will be logged.  			Log messages are sent to the "file" appender are severity level error or higher while  for console appender 			and log messages of level "error"  			and higher will be sent to the "STDOUT" appender. and rolling file for all level as configure for root -->

	</Loggers



In above log4j2.xml configuration having additional changes for appender RollingFile. Let me explain about it in more detail:


%d{yyyyMMdd HH:mm:ss.SSS} [%t] %-5level %logger{36} – %msg%n : This pattern shows how your logs will format  in logs file.


filename=”${log-path}/FacingIssueOnIT.log :  Current logs will write on this file.


configurefilePattern=”${log-path}/$${date:yyyy-MM-dd}/myexample-%d{yyyy-MM-dd}-%i.log.gz : As configured for triggering policy will check in every second (interval=1) if current file size reach to 100MB (size=100MB) will create rolling file on current date folder as in below screen.


Archieve Delete Policy: represent how old logs you want to keep as backup as of now configured for last one hour. As per you application need change it to days and change path of delete achieve logs files as per your logs directory.


Here I have added RollingFile appenders in loggers as root with out any specified level so that we can do logging for all log line. If you want to filter logs and behave differently for different package you can use loggers with different severity levels as I have used for package com.logging.


JAVA Code :


Here I have added infinite loop for testing RollingFileAppender so that logs continuously added to log file. Additionally for big application prospects added condition for checking what level severity is configured in logs so that if not satisfy condition then save operation processing time of logger for logging, formatting and appending checking. In this way we can increase application performance for logging.


package com.logging;

import org.apache.logging.log4j.Logger;
import java.time.LocalDateTime;
import org.apache.logging.log4j.LogManager;

public class Log4jExample {
    private static Logger logger = LogManager.getLogger(Log4jExample.class);

    public static void main(String[] args) {

    	 do
     	{
     	 if(logger.isFatalEnabled())
    	  logger.fatal("Fatal log message :FacingIssuesOnIT");
     	if(logger.isErrorEnabled())
    	  logger.error("Error log message :FacingIssuesOnIT");
     	if(logger.isWarnEnabled())
    	  logger.warn("Warn log message :FacingIssuesOnIT");
     	if(logger.isInfoEnabled())
    	  logger.info("Info log message :FacingIssuesOnIT");
     	if(logger.isDebugEnabled())
          logger.debug("Debug log message :FacingIssuesOnIT");
     	if(logger.isTraceEnabled())
          logger.trace("Trace log message :FacingIssuesOnIT");
     	}
    }
while(1>0);
}



File output: For current log file will have log formatted as below.


20171220 10:49:55.226 [main] FATAL com.logging.Log4jExample - Fatal log message :FacingIssuesOnIT
20171220 10:49:55.227 [main] ERROR com.logging.Log4jExample - Error log message :FacingIssuesOnIT
20171220 10:49:55.228 [main] WARN  com.logging.Log4jExample - Warn log message :FacingIssuesOnIT
20171220 10:49:55.228 [main] INFO  com.logging.Log4jExample - Info log message :FacingIssuesOnIT
20171220 10:49:55.228 [main] DEBUG com.logging.Log4jExample - Debug log message :FacingIssuesOnIT



Archive Log Files:  Rolling and archive file will create as below on directory C:\logs\2017-12-20


log4j RollingFile


Summary 


In this tutorial, I have considered logging importance, ways of centralize logging, log4j2 configuration for console, file and rolling file appenders. Also explained about rolling, archive management of logs  and bit idea to increase you application performance with minor change for logging.


References :


https://logging.apache.org/log4j