Hi,

After my post Java: Log4j Concepts and Explanations about Log4j concepts, I would introduce Log4j in practice through several concrets examples and their results.

The section of this article will be:
1) Use of Log4j directly
2) Specifying granularity for external library or for custom package
3) Use of Log4j with a wrapper
4) Extended example with DailyRollingFileAppender
5) Use of environment variables in Log4J
6) Configure Log4J with Spring in web application
7) Override Log4J configuration

Reminder:
Log4j API defines five levels of logging exposed below by decreasing severity:

  • FATAL: log a fatal error that can lead to premature termination of the application:
    logger.fatal(msg);
    
  • ERROR: log an error that does not preclude the application to run (the logging events with granularity FATAL and ERROR are logged):
    logger.error(msg);
    
  • WARN: log a warning which could be an inconsistency in the configuration (the logging events with granularity FATAL, ERROR AND WARN are logged):
    logger.warn(msg);
    
  • INFO: log informative messages (the logging events with granularity FATAL, ERROR, WARN and INFO are logged):
    logger.info(msg);
    
  • DEBUG: generate messages that can be useful in debugging (the logging events with granularity FATAL, ERROR, WARN, INFO and DEBUG are logged):
    logger.debug(msg);
    
  • TRACE: to use in order to record the entry or the exit of a method (the logging events with granularity FATAL, ERROR, WARN, INFO, DEBUG and TRACE are logged):
    logger.trace(msg);
    

1) Use of Log4j directly
In this section, I will expose a direct use of Log4j i.e. without wrapper.
First, we need to add the Log4j framework library log4j-1.2.15.jar (in our case), in the classpath of our project.
Second, we create a simple test class in order to prove that Log4j “works”:

//...
public static void main(String[] args) {
	/** The logger */
	Logger logger = Logger.getLogger(UseLog4DirectlyDEFAULT.class);
	String msg = "message to log from "+ UseLog4DirectlyDEFAULT.class.getName();

	logger.fatal(msg);
	logger.error(msg);
	logger.warn(msg);
	logger.info(msg);
	logger.debug(msg);
	logger.trace(msg);
}
//...

Then, in executing the above main method, we will obtain the following messages in console:

log4j:WARN No appenders could be found for logger (com.ho.log4j.directly.UseLog4Directly).
log4j:WARN Please initialize the log4j system properly.

….because Log4j needs the configuration parameters in the classpath of the class. These parameters are sought by default in a file log4j.properties.

So, we will create this file log4j.properties:

log4j.rootCategory=DEBUG,CONSOLE,LOGFILE

#ONLY FATAL MESSAGES
log4j.logger.com.ho.log4j.directly.UseLog4DirectlyOnlyFATAL=FATAL
#ONLY ERROR MESSAGES
log4j.logger.com.ho.log4j.directly.UseLog4DirectlyOnlyERROR=ERROR
#ONLY WARN MESSAGES
log4j.logger.com.ho.log4j.directly.UseLog4DirectlyOnlyWARN=WARN
#ONLY INFO MESSAGES
log4j.logger.com.ho.log4j.directly.UseLog4DirectlyOnlyINFO=INFO
#ONLY DEBUG MESSAGES
log4j.logger.com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG=DEBUG
#ONLY TRACE MESSAGES
log4j.logger.com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE=TRACE

###################################################
##################### DEFINITION OF APPENDERS #####
###################################################

# CONSOLE is set to be a ConsoleAppender using a PatternLayout.
log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
log4j.appender.CONSOLE.layout.ConversionPattern=%-d{HH:mm:ss} %-5p %60.60c %-25.25M %m%n

# LOGFILE is set to be a File appender using a PatternLayout.
log4j.appender.LOGFILE=org.apache.log4j.RollingFileAppender
log4j.appender.LOGFILE.File=./mylogfile.log
log4j.appender.LOGFILE.MaxFileSize=500KB
log4j.appender.LOGFILE.MaxBackupIndex=10
log4j.appender.LOGFILE.layout=org.apache.log4j.PatternLayout
log4j.appender.LOGFILE.layout.ConversionPattern=%-d{MMMM dd HH:mm:ss} %-5p %30.30c %-25.25M %m%n

Some explanations:

  • log4j.rootCategory=DEBUG,CONSOLE,LOGFILE: the default log granularity is DEBUG, so the traces FATAL, ERROR, WARN, INFO, and DEBUG will stored in the appenders CONSOLE and LOGFILE. So, normally the data logged users in CONSOLE and LOGFILE appenders must be identical (in a perfect world, if there is no “sysout”);
  • The CONSOLE appender to print the logs in the console under a defined pattern layout;
  • Each event will appear in the appender with the LOG4J pattern “%-d{HH:mm:ss} %-5p %60.60c %-25.25M %m%n”, for example: 13:54:12 DEBUG com.ho.pack1.MyClass init message;
  • The LOGFILE is set to be a File appender using a PatternLayout. This appender will store the logging events in the file “mylogfile.log” whose the maximum size will be 500KB, and when this size will be reached, Log4j will make a backup of this file under the name “mylogfile.log.1”, “mylogfile.log.2”,…etc; And the file “mylogfile.log” will always correspond to the current log file. The maximum number of backup files is 10.

Then, we create several classes:

  • UseLog4DirectlyDEFAULT : to check that only the logging events with granularity FATAL, ERROR, WARN, INFO, DEBUG and TRACE will be logged;
  • UseLog4DirectlyOnlyFATAL : to check that only the logging events with granularity FATAL will be logged;
  • UseLog4DirectlyOnlyERROR : to check that only the logging events with granularity FATAL and ERROR will be logged;
  • UseLog4DirectlyOnlyWARN : to check that only the logging events with granularity FATAL, ERROR, and WARN will be logged;
  • UseLog4DirectlyOnlyINFO : to check that only the logging events with granularity FATAL, ERROR, WARN and INFO will be logged;
  • UseLog4DirectlyOnlyDEBUG : to check that only the logging events with granularity FATAL, ERROR, WARN, INFO, and DEBUG will be logged;
  • UseLog4DirectlyOnlyTRACE : to check that only the logging events with granularity FATAL, ERROR, WARN, INFO, DEBUG and TRACE will be logged;

…these classes contain the same code:

//...
/** The logger */
private Logger logger = Logger.getLogger(this.getClass());

public static void main(String[] args) {
	UseLog4DirectlyDEFAULT me = new UseLog4DirectlyDEFAULT();
		
	String msg = "message to log from "+ me.getClass().getName();

	me.logger.fatal(msg);
	me.logger.error(msg);
	me.logger.warn(msg);
	me.logger.info(msg);
	me.logger.debug(msg);
	me.logger.trace(msg);
}
//...

… so the results will be:

  • UseLog4DirectlyDEFAULT : the default granularity is configured DEFAULT = DEBUG:
    01:17:43 FATAL                 com.ho.log4j.directly.UseLog4DirectlyDEFAULT main                      message to log from com.ho.log4j.directly.UseLog4DirectlyDEFAULT
    01:17:43 ERROR                 com.ho.log4j.directly.UseLog4DirectlyDEFAULT main                      message to log from com.ho.log4j.directly.UseLog4DirectlyDEFAULT
    01:17:43 WARN                  com.ho.log4j.directly.UseLog4DirectlyDEFAULT main                      message to log from com.ho.log4j.directly.UseLog4DirectlyDEFAULT
    01:17:43 INFO                  com.ho.log4j.directly.UseLog4DirectlyDEFAULT main                      message to log from com.ho.log4j.directly.UseLog4DirectlyDEFAULT
    01:17:43 DEBUG                 com.ho.log4j.directly.UseLog4DirectlyDEFAULT main                      message to log from com.ho.log4j.directly.UseLog4DirectlyDEFAULT
    
  • UseLog4DirectlyOnlyFATAL : the FATAL events are only logged:
    01:18:07 FATAL               com.ho.log4j.directly.UseLog4DirectlyOnlyFATAL main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyFATAL
    
  • UseLog4DirectlyOnlyERROR : the FATAL and ERROR events are logged:
    01:18:19 FATAL               com.ho.log4j.directly.UseLog4DirectlyOnlyERROR main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyERROR
    01:18:19 ERROR               com.ho.log4j.directly.UseLog4DirectlyOnlyERROR main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyERROR
    
  • UseLog4DirectlyOnlyWARN : the FATAL, ERROR and WARN events are logged:
    01:18:37 FATAL                com.ho.log4j.directly.UseLog4DirectlyOnlyWARN main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyWARN
    01:18:37 ERROR                com.ho.log4j.directly.UseLog4DirectlyOnlyWARN main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyWARN
    01:18:37 WARN                 com.ho.log4j.directly.UseLog4DirectlyOnlyWARN main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyWARN
    
  • UseLog4DirectlyOnlyINFO : the FATAL, ERROR, WARN and INFO events are logged:
    01:19:22 FATAL                com.ho.log4j.directly.UseLog4DirectlyOnlyINFO main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyINFO
    01:19:22 ERROR                com.ho.log4j.directly.UseLog4DirectlyOnlyINFO main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyINFO
    01:19:22 WARN                 com.ho.log4j.directly.UseLog4DirectlyOnlyINFO main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyINFO
    01:19:22 INFO                 com.ho.log4j.directly.UseLog4DirectlyOnlyINFO main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyINFO
    
  • UseLog4DirectlyOnlyDEBUG : the FATAL, ERROR, WARN, INFO and DEBUG events are logged:
    01:19:38 FATAL               com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG
    01:19:38 ERROR               com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG
    01:19:38 WARN                com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG
    01:19:38 INFO                com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG
    01:19:38 DEBUG               com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyDEBUG
    
  • UseLog4DirectlyOnlyTRACE : the FATAL, ERROR, WARN, INFO, DEBUG and TRACE events are logged:
    01:19:58 FATAL               com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE
    01:19:58 ERROR               com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE
    01:19:58 WARN                com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE
    01:19:58 INFO                com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE
    01:19:58 DEBUG               com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE
    01:19:58 TRACE               com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE main                      message to log from com.ho.log4j.directly.UseLog4DirectlyOnlyTRACE
    

2) Specifying granularity for external library or for custom package
It’s possible to specify the granularity:

  • “log4j.logger.org.springframework=INFO” : define the logging granularity INFO for the classes in the package “org.springframework” in the external library SPRING;
  • “log4j.logger.com.ho.log4j.controller=INFO” : define the logging granularity INFO for custom package “com.ho.log4j.controller”;
#Spring Framework
log4j.logger.org.springframework=INFO
log4j.logger.org.springframework.orm=INFO
log4j.logger.org.springframework.transaction=INFO

#Hibernate
log4j.logger.org.hibernate.SQL=WARN
log4j.logger.org.hibernate.type=INFO
log4j.logger.org.hibernate.tool.hbm2ddl=INFO
log4j.logger.org.hibernate.pretty=INFO
log4j.logger.org.hibernate.cache=INFO
log4j.logger.org.hibernate.transaction=INFO
log4j.logger.org.hibernate.jdbc=INFO
log4j.logger.org.hibernate.hql.ast.AST=INFO
log4j.logger.org.hibernate.secure=INFO
log4j.logger.org.hibernate=INFO

#Documentum
log4j.logger.com.documentum=INFO

#Apache
log4j.logger.org.apache.commons=INFO

#Controller
log4j.logger.com.ho.log4j.controller=INFO

3) Use of Log4j with a wrapper
In this section, I will expose a use of Log4j with wrapper.
First, we need to add the Apache commons logging library commons-logging-1.1.1.jar (in our case), in the classpath of our project.
Second, we create a simple test class in order to prove that Log4j with wrapper Apache commons “works”:

package com.ho.log4j.wrapper;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;

/**
 * UseLog4ViaWrapper: A basic use of Log4J via Apache Commons Logging so with wrapper.
 * 
 * @author huseyin
 *
 */
public class UseLog4ViaWrapper {

	/** The logger */
	private Log logger = LogFactory.getLog(this.getClass());

	public static void main(String[] args) {
		UseLog4ViaWrapper me = new UseLog4ViaWrapper();
		
		String msg = "message to log from "+ me.getClass().getName();

		me.logger.fatal(msg);
		me.logger.error(msg);
		me.logger.warn(msg);
		me.logger.info(msg);
		me.logger.debug(msg);
		me.logger.trace(msg);
	}
	
}

… the results could be:

00:19:42 FATAL                       com.ho.log4j.wrapper.UseLog4ViaWrapper main                      message to log from com.ho.log4j.wrapper.UseLog4ViaWrapper
00:19:42 ERROR                       com.ho.log4j.wrapper.UseLog4ViaWrapper main                      message to log from com.ho.log4j.wrapper.UseLog4ViaWrapper
00:19:42 WARN                        com.ho.log4j.wrapper.UseLog4ViaWrapper main                      message to log from com.ho.log4j.wrapper.UseLog4ViaWrapper
00:19:42 INFO                        com.ho.log4j.wrapper.UseLog4ViaWrapper main                      message to log from com.ho.log4j.wrapper.UseLog4ViaWrapper
00:19:42 DEBUG                       com.ho.log4j.wrapper.UseLog4ViaWrapper main                      message to log from com.ho.log4j.wrapper.UseLog4ViaWrapper

4) Extended example with DailyRollingFileAppender
In this section, I will expose a more advanced example: we will define a logging level of INFO and a new appender named AUDITFILE. LOG4J will create a specific file for the logging events of the “AuditLogger” class of the package “com.ho.log4j.audit.util”.

First, we will modify the configuation file:

#Audit
log4j.logger.com.ho.log4j.audit.util.AuditLogger=INFO,AUDITFILE

# AUDITFILE is set to be a File appender using a PatternLayout.
log4j.appender.AUDITFILE=org.apache.log4j.DailyRollingFileAppender
log4j.appender.AUDITFILE.File=./myauditlogfile.log
log4j.appender.AUDITFILE.DatePattern='.'yyyy-MM-dd-HH
log4j.appender.AUDITFILE.append=true
log4j.appender.AUDITFILE.layout=org.apache.log4j.PatternLayout
log4j.appender.AUDITFILE.layout.ConversionPattern=%-d{MMMM dd HH:mm:ss} %-5p %60.60c %-25.25M %m%n

Some explanations:

  • “log4j.logger.com.ho.log4j.audit.util.AuditLogger=INFO,AUDITFILE” :
    defines a logging level of INFO fo the class “com.ho.log4j.audit.util.AuditLogger”. The loged data will be included in the AUDITFILE appender.
  • “log4j.appender.AUDITFILE”: defines the appender class used by Log4J to create the file stored the traces of the class com.ho.log4j.audit.util.AuditLogger. The appender “DailyRollingFileAppender” wil create a file for each day depending on the configuration passed via the parameter “DatePattern”;
  • “log4j.appender.AUDITFILE.File” : defines the location and name of the log file appender;
  • “log4j.appender.AUDITFILE.DatePattern” : defines the pattern used for the renaming of log files. depending on this parameter “DatePattern”, LOG4J regenerates a file by appending the old file with the extension. For example the pattern ‘.’yyyy-MM-dd-HH, LOG4J feed a Log file regenerated every hour by appending the old file with a ‘.’ Yyyy-MM-dd-HH like “myauditlogfile.log.13.01.18-14” corresponding to log 18th January 2013 at 14 hours;
  • “log4j.appender.AUDITFILE.layout” and “log4j.appender.AUDITFILE.layout.ConversionPattern” defines the format le format of logging records in file.

5) Use of environment variables in Log4J
It is possible to use Log4J with the standard environment variables or personal variable defined at server startup.

  • “log4j.appender.LOGFILE.File=${catalina.base}/mylogfile.log” : In order to define the location and name of the log file “mylogfile.log”, we use the environment variable “${catalina.base}” which corresponds to the installation directory of CATALINA. In practice, this variable is visible in the console startup of TOMCAT in section arguments Virtual Machine “VM arguments” (see the below screenshot); So the parameter -Dcatalina.base=”C:\MyFiles\Development\Java\tools\TomCat” means that the Log file “mylogfile.log” will be created in the root directory of Tomcat;
  • Here, the use of personal variable, “log4j.appender.AUDITFILE.File=${myparam.audit.directory}/myauditlogfile.log” : In order to define the location and name of the log file “myauditlogfile.log”, we use an environment variable named ${myparam.audit.directory}”. In practice, this variable is visible in the console startup of TOMCAT in section arguments Virtual Machine “VM arguments” (see the below screenshot); So the parameter -Dmyparam.audit.directory=D:\ means that the Log file “myauditlogfile.log” will be created in the root directory D:;

log4jStartingTomcat

Note:There are server-specific log files: for example the file named “tomcat7-stdout.yyyy-mm-dd” containing all of the outputs in the console “sysout” on TOMCAT.

6) Configure Log4J with Spring in web application
More, it is possible to configure LOG4J: the name of Log4J properties file in a web application by using Spring (the default file name must be “log4j.properties” in the classpath):

Here, a simple example of LOG4J configuration in a WEB application:
web.xml:

	<context-param>
		<param-name>log4jConfigLocation</param-name>
		<param-value>classpath:myfile-log4j.properties</param-value>
	</context-param>

	<listener>
		<listener-class>org.springframework.web.util.Log4jConfigListener</listener-class>
	</listener>

7) Override Log4J configuration
Finally, it is possible to override the values fixed in the Log4J properties file “log4j.properties” in a web application by using Spring (the default file name must be “log4j.properties” in the classpath):

Here, a simple bean allowing to modify the LOG4J configuration after the loading of Spring context:
SpringContext.xml:

<bean id="afterSpringContextReady" class="com.ho.test.log4j.util.spring.AfterSpringContextReady"/>

AfterSpringContextReady.java:

package com.ho.test.log4j.util.spring;

import java.io.inputStream;
import java.util.Properties;

import org.apache.log4j.LogManager;
import org.apache.log4j.PropertyConfigurator;
import org.springframework.beans.BeansException;
import org.springframework.context.ApplicationContext;
import org.springframework.context.ApplicationContextAware;


public class AfterSpringContextReady implements ApplicationContextAware{

	private ApplicationContext context;
	
	@Override
	public void setApplicationContext(ApplicationContext applicationContext) throws BeansException{
		this.context = applicationContext;
		
		// Update Log4j configuration
		updateLog4jConfiguration();
	}
	
	
	private void updateLog4jConfiguration(){
		InputStream log4jConfigStream = null;
		try{
			log4jConfigStream = getClass().getResourceAsStream("/log4.properties");
		
			Properties props = new Properties();
			props.load(log4jConfigStream);
		
			// Modify the Log4j configuration
			props.setProperty("log4j.appender.AUDITFILE.File", "/..../.../");

			LogManager.resetConfiguration();
			PropertyConfiguration.configure(props);

		}catch(Exception ex){
			ex.printStackTrace();
		}finally{
			if(log4jConfigStream != null){
				try{log4jConfigStream.close();}catch(Exception ex){ex.printStackTrace();}
			}
		}
	}
}

That’s all!!!!!!!!

Source : test_log4j.zip

Huseyin OZVEREN