Sparkles

that were shone when I got tempered!

Posts Tagged ‘log4j

Implement RollingPerInvoke Appender using org.apache.log4j.Logger

leave a comment »

Requirement :

  1. Log data using org.apache.log4j.Logger.
  2. Log data with a unique trace id in log4j pattern.
  3. Log data in seperate files per each invoke.
  4. Log data seperate folders per each supplier threads (eg : DerbySoftImpl, HBSIImpl, HotelbedsImpl, SynxisImpl) and levels (eg : Availabiity, Reservation, Cancellation) at run time.

Approach :

  1. Log data using org.apache.log4j.Logger. :
    We use org.apache.log4j.Logger to log data (eg : logger.info(data))
  2. Log data with a unique trace id in log4j pattern.
    We do this through the org.apache.log4j.MDC
  3. Log data in seperate files per each invoke.
    We create a custome Appender extending org.apache.log4j.FileAppender and override the file name with MDC String and System milliseconds
  4. Log data seperate folders per each supplier threads (eg : DerbySoftImpl, HBSIImpl, HotelbedsImpl, SynxisImpl) and levels (eg : Availabiity, Reservation, Cancellation) at run time.
    In the created custome Appender, we create the new folder structure using the extracted values from mDCStr and override the FileAppender’s folder path using created one.

LogDataClient.java
This is the demo class for the RollingPerInvokeImplemnetation.
In this case, there are two set of threads. Air threads and hotel threads. Actually air threads are kind of control threads here. It logs data to one seperate file (daily) by appending to it. And hotel threads will do logging data to seperate files in each invoke. All these happens in multithreaded environment. So, LogDataClient initializes the hotel and air supplier threads.

Hotel Supplier Threads. (eg : DerbySoftImpl, HBSIImpl, HotelbedsImpl, SynxisImpl)
In each invoke, it calls logData method passing data to be logged and the unique ID (traceid). We have done this in multiple times to create a realtime traffic in there. So, when there are 10 supplier threads per each supplier and they invoked logdata method 10 times by each supplier thread, that means there are 10 calls per supplier thread.
eg :

Log4jFileLogger.logData("<RESPONSE><DERBY_RS><RESPONSE>","derbysoft|Availabiity|Response|"+UUID.randomUUID());

Log4jFileLogger
This is the class that declare and initializes org.apache.log4j.Logger instance and invoke it with data passed by the suppier thread. unique id will be passed to the logger via MDC.
In this case we have make the logData method as synchronized one to avoid being conflict with the FileAppender (to be discussed little bit later here).


 public static synchronized void logData(String data, String mDCStr) {

 MDC.put("ridelogid", mDCStr);

 DOMConfigurator.configure("log4j.xml");
 logger.info(data);

 MDC.remove("ridelogid");
 }

In this case, for hotel supplier threads we invoke the log4j.hotel.Log4jFileLogger and for air supplier threads we invoke log4j.air.Log4jFileLogger. We locate these Log4jFileLoggers to seperate packages. So, when the logger is invoked (eg : logger.info()), it looks at the relevant <logger> tag the log4j.xml.
eg :

<logger name="log4j.hotel">
<appender-ref ref="HOTEL_AVAILABIITY" />
</logger>

<logger name="log4j.air">
<appender-ref ref="loggers initialized through the classes in log4j.hotel will use the appernder named HOTEL_AVAILABIITY" />
</logger>

So, in this case, loggers initialized through the classes in log4j.hotel (Logger logger = Logger.getLogger(log4j.hotel.Log4jFileLogger.class);) will use the appernder named HOTEL_AVAILABIITY and loggers initialized through the classes in log4j.hotel will use the appernder named loggers initialized through the classes in log4j.air will use the appernder named AIR_AVAILABIITY.

<appender name="HOTEL_AVAILABIITY" class="log4j.RollingPerInvokeFileAppender">
<param name="append" value="false" />
<param name="File" value="/var/log/rezg/app/bonologs/fileNamex" />
<param name="Threshold" value="INFO" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d [%X{ridelogid}] %m%n" />
</layout>
</appender>

<appender name="AIR_AVAILABIITY" class="org.apache.log4j.DailyRollingFileAppender">
<param name="append" value="true" />
<param name="File" value="/var/log/rezg/app/bono-airlogs/airlogs.log" />
<param name="Threshold" value="INFO" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d %-5p [%c] %m%n" />
</layout>
</appender>

Then in those apenders, HOTEL_AVAILABIITY uses a custome fileAppender log4j.RollingPerInvokeFileAppender we implemented. And AIR_AVAILABIITY uses inbuilt org.apache.log4j.DailyRollingFileAppender to log Data passed through the logger invocation in relevant Log4jFileLogger (eg : logger.info(data)) .
In this case unique trace Id put to the MDC (eg : MDC.put(“ridelogid”, mDCStr);) in log4j.hotel.Log4jFileLogger, will be passed to relevant appender via log4j ConversionPattern (eg : <param name=”ConversionPattern” value=”%d [%X{ridelogid}] %m%n” />) to be logged with the log data.
As mentioned earlier, the real implementation will be in HOTEL_AVAILABIITY appender. So, moving forward we will discuss about the HOTEL_AVAILABIITY. In AIR_AVAILABIITY appender it will just append the data to a daily rolling log file in old school style :).

So, when the MDC string is put and logger.info(data) method is invoked, log4j.RollingPerInvokeFileAppender will be invoked passing the MDC string to it via the ConversionPattern.

log4j.RollingPerInvokeFileAppender
RollingPerInvokeFileAppender is a org.apache.log4j.FileAppender. (RollingPerInvokeFileAppender extends FileAppender). So, the core implementation happens in the org.apache.log4j.FileAppender. And we have override some methods (eg : append(LoggingEvent event)) suit for our requirement mentioned at the top.
So, here, basically, what we are doing is taking the MDC string set in the invoke, create the new file name with relavant folder structure using the parameters passed in MDC string for each millisecond.

append method :

 @Override
 public void append(LoggingEvent event) {

 String mDCString = (String) event.getMDC("ridelogid");

 modifyLogFileName(mDCString);

 super.append(event);

 }

As mentioned, this is an overriden method from org.apache.log4j.FileAppender.
In this case, first we get the mDCString via event.getMDC(“ridelogid”) and pass the modifyLogFileName method to modify and set the relavant file name with relevant folder structure. Then it calls org.apache.log4j.FileAppender’s append method to do the rest (eg : super.append(event)).

modifyLogFileName method :

Here first we create a file instance with the default file name mentioned in the appender (eg : <param name=”File” value=”/var/log/rezg/app/bonologs/fileNamex” />).
We will use this to get the root folder (eg : /var/log/rezg/app/bonologs/).

 final File logFile = new File(fileName);
 String rootFolder = logFile.getParent();

Then we identify the required parameters from the MDC string (eg : derbysoft|Availabiity|Response|5395de83-f507-436b-8b4d-25e3ff86ce33) and create the new folder path.

 String[] fileProps = mDCString.split("\\|");

 String vendorId = null;
 String traceId = null;
 String flow = null;
 String type = null;

 try { vendorId = fileProps[0];} catch (Exception e) {}
 try { flow = fileProps[1];} catch (Exception e) {}
 try { type = fileProps[2];} catch (Exception e) {}
 try { traceId = fileProps[3];} catch (Exception e) {}

 String newfolderPath = rootFolder + File.separator + vendorId + File.separator + flow;

Then we create the new Folder structure (for the first time only) (requirement 4)

 File file = new File(newfolderPath); 
 if(! file.isDirectory()) file.mkdirs(); 

Then we create the new file name with the System millisecond along with the mDCString. This will create unique file per each invoke (requirement 3).


String newfileName = newfolderPath + File.separator + mDCString.replaceAll("\\|", "-") + "_" + System.currentTimeMillis() + ".log";

Then we set the created newfileName to the org.apache.log4j.FileAppender’s setFile() method.

setFile(newfileName, fileAppend, bufferedIO, bufferSize);

After this, modifyLogFileName method is comlpleted and it will log the data through log4j (requirement 1) with MDC string (requirement 2) as default org.apache.log4j.FileAppender behaviour.

Note : we must synchronized the logData method in Log4jFileLogger to avoid conflicts with creating the newfolderPath for each mDCString (ridelogid).

You can find the comlplet source code at https://github.com/namalfernandolk/log4j-rolling-per-invoke.git

Advertisements

Written by Namal Fernando

January 20, 2016 at 5:51 am

Posted in Java, log4j

Tagged with , ,

Log4j Basics

leave a comment »

Log4j is written java and distributed under Apache Software License.

Althogh it is written in Java it is provided for many other languages such as C, C++, C#, Perl, Python, Ruby, and Eiffel.

There are three main components in log4j.

  1. Loggers : captures the logging information.
  2. Appenders : publishes the logging information to various destinations (File, UNIX-SYS logs, DataBases, Network, Console etc).
  3. Layouts : Formats logging information in different styles.

The latest log4j version can be found at http://logging.apache.org/log4j/ with full-source code, class files, and documentation.

Supportive packages may need to log4j works.

  • Java Mail API: E-mail based logging feature in log4j requires this. This is packaged inside the mail.jar. You can take it from here [https://glassfish.dev.java.net/javaee5/mail/]
  • JavaBeans Activation Framework: The Java Mail API will also require that the JavaBeans Activation Framework. This is packaged inside the activation.jar. You can take it from here [http://java.sun.com/products/javabeans/jaf/index.jsp]
  • Java Message Service: The JMS-compatible features of log4j will require that both JMS and Java Naming and Directory Interface JNDI. You can take it from here [http://java.sun.com/products/jms].
  • XML Parser: JAXP-compatible XML parser is also needed to use log4j. This is packaged inside the Xerces.jar. You can take it from here [http://xerces.apache.org/xerces-j/install.html].

To use log4j, you will need to setup the PATH and CLAASPATH variables properly

	$ pwd /usr/local/apache-log4j-1.2.15
	$ export CLASSPATH=$CLASSPATH:/usr/local/apache-log4j-1.2.15/log4j-1.2.15.jar
	$ export PATH=$PATH:/usr/local/apache-log4j-1.2.15/
	

Architecture
Log4j API follows a Layered Architecture. Layered Architecture’s each layer provides different objects to perform different tasks.

There are two types of objects in log4j framework.

  1. Core Objects
  2. Support Objects

Core Objects

These objects represents the three main components in the Log4j Framework.

  1. Logger Object – (top-level)
  2. Layout Object – (middle-level)
  3. Appender Object – (bottom-level)

Layout Object – (middle-level)

The top-level class in the hierarchy is the abstract class org.apache.log4j.Layout.
This class provides a skeleton implementation of all the common operations across all other Layout objects and declares two abstract methods.

1. public abstract boolean ignoresThrowable()
It indicates whether the logging information handles any java.lang.Throwable object passed to it as a part of the logging event. If the Layout object handles the Throwable object, then the Layout object does not ignore it, and returns false.

2. public abstract String format(LoggingEvent event)
Individual layout subclasses implement this method for layout specific formatting.

Apart from these abstract methods, the Layout class provides concrete implementation for the methods listed below:
1. public String getContentType()
It returns the content type used by the Layout objects. The base class returns text/plain as the default content type.

2. public String getFooter()
It specifies the footer information of the logging message.

3. public String getHeader() –
It specifies the header information of the logging message.

This is Sub-classed as follows giving opportunity to format the logging information in different ways.

  • DateLayout
  • HTMLLayout
  • PatternLayout
  • SimpleLayout
  • XMLLayout

Each subclass can return class-specific information by overriding the concrete implementation of the above described methods.

So, all Layout objects receive a LoggingEvent object from the Appender objects. The Layout objects then retrieve the message argument from the LoggingEvent and apply the appropriate ObjectRenderer to obtain the String representation of the message.
It is also possible to create a Layout object that formats logging data in an application-specific way.

Appender Object – (bottom-level)

There are various Appenders in log4j.

  • AppenderSkeleton
  • AsyncAppender
  • ConsoleAppender
  • DailyRollingFileAppender
  • ExternallyRolledFileAppender
  • FileAppender
  • JDBCAppender
  • JMSAppender
  • LF5Appender
  • NTEventLogAppender
  • NullAppender
  • RollingFileAppender
  • SMTPAppender
  • SocketAppender
  • SocketHubAppender
  • SyslogAppender
  • TelnetAppender
  • WriterAppender

Each Appender object has different properties.

  • layout – Appender uses the Layout objects and the conversion pattern to format the logging information
  • target – The target may be a console, a file, or another item depending on the appender
  • level – This is required to control the filtration of the log messages.
  • threshold – Appender ignores any logging messages that have a level lower than the threshold level.
  • filter – This analyzes the logging information beyond level matching and decide whether logging requests should be handled by a particular Appender or ignored.

Support Objects

Level Objects
Level object defines the granularity and priority of the logging information. There are Seven Levels of logging.

  • OFF
  • DEBUG
  • INFO
  • ERROR
  • WARN
  • FATAL
  • ALL.

Filter Objects
Filter Objects analyzes the logging information and make further decisions on whether it should be logged or not.

An Appender object can have multiple Filter objects associated with it. When a logging information is passed to a particular Appender object, all the Filter objects associated with that Appender need to approve the logging information to be published

ObjectRenderer
The ObjectRenderer object is specialized in providing a String representation for an objects passed to the logging framework. This object is used by the Layout objects to prepare the final logging information.

LogManager
The LogManager object is responsible to manage the logging framework. It reads the initial configuration parameters from a system-wide configuration file or a configuration class and manages the framework

How you can configure the core components using a configuration file.
This involves assigning the Level, defining Appender, and specifying Layout objects in a configuration file.

This configuration file is named as log4j.properties. It keeps the properties in key-value pairs. By default, the LogManager looks for a file named log4j.properties in the CLASSPATH when initialze the logging framework.

Example :

Following is the syntax of log4j.properties file for an appender X:

	# Define the root logger with appender X
	log4j.rootLogger = DEBUG, X

	# Set the appender named X to be a File appender
	log4j.appender.X=org.apache.log4j.FileAppender
	log4j.appender.X.File=${log}/log.out

	# Define the layout for X appender
	log4j.appender.X.layout=org.apache.log4j.PatternLayout
	log4j.appender.X.layout.conversionPattern=%m%n
	

In this example,
The level of the root logger is defined as DEBUG. The DEBUG attaches the appender named X to it.
Set a valid appender(FileAppender) to the appender X. It writes the loggin informaion to a file named log.out located in the log directory (log directory path is given as a System Property like ${variableName}).

You can add the appender to the logger inside the program itself using the below provided method.

	public void addAppender(Appender appender);
	

Set the layout (PatternLayout) for the appender X.

This Pattern Layout is given a specified conversionPattern denoted by the TTCC format.

TTCC

TTCC is a message format used by log4j.[6] TTCC is an acronym for Time Thread Category Component. It uses the following pattern:

  • %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.[7]
  • %X{key} – Used to output the MDC (mapped diagnostic context) associated with the thread that generated the logging event for specified key.[8]
  • %m – Used to output the application supplied message associated with the logging event.
  • %n – Used to output the platform-specific newline character or characters.

Initializing Logger.
The Logger class does not allow us to instantiate a new Logger instance. But it provides number of static methods to obtain a Logger object.

Logging Methods
Once the Logger is instantiated, we can use several methods of the logger to log messages.

  1. public void debug(Object message) – Prints messages with the level Level.DEBUG.
  2. public void error(Object message) – Prints messages with the level Level.ERROR.
  3. public void fatal(Object message) – Prints messages with the level Level.FATAL.
  4. public void info(Object message) – Prints messages with the level Level.INFO.
  5. public void warn(Object message) – Prints messages with the level Level.WARN.
  6. public void trace(Object message) – Prints messages with the level Level.TRACE.

Logging Levels.
Log4j is defined the loggin levels in org.apache.log4j.Level. You can also define your custom levels by sub-classing the Level class. This is described more in above Logger Object.

Level Description

  • OFF – The highest possible rank and is intended to turn off logging.
  • FATAL – Severe errors that cause premature termination. Expect these to be immediately visible on a status console.
  • ERROR – Other runtime errors or unexpected conditions that might still allow the application to continue running. Expect these to be immediately visible on a status console.
  • WARN – Use of deprecated APIs, poor use of API, ‘almost’ errors, potentially harmful situations, other runtime situations that are undesirable or unexpected, but not necessarily “wrong”. Expect these to be immediately visible on a status console.
  • INFO – Interesting runtime events (startup/shutdown). Expect these to be immediately visible on a console, so be conservative and keep to a minimum.
  • DEBUG – Detailed information on the flow through the system. Expect these to be written to logs only.
    TRACE – Most detailed information. Expect these to be written to logs only. Since version 1.2.12.[5]

If the logger level of the request is lRq and
the level of logger is lLgr,
information will be logged only if lLgr >= lRq.

In this case levels are ordered as ALL < DEBUG < INFO < WARN < ERROR < FATAL < OFF.


Reference : 

Written by Namal Fernando

April 14, 2015 at 9:59 am

Posted in Java, log4j

Tagged with , ,

Log4J – Simple logging

leave a comment »

Initiating the logger.

This can be done by calling getLogger() static method of the Logger class.
It takes the fully qualified class name as an argument.
eg : static final Logger logger = Logger.getLogger(HelloWorld.class);

Configuring log4j

BasicConfigurator is the Simplest way to configure the log4j. This will all the message in the console.
eg : BasicConfigurator.configure()

Logger levels :

There are five main logger levels as follows.

  • DEBUG – logger.debug()
  • INFO – logger.info()
  • WARN – logger.warn()
  • ERROR – logger.error()
  • FATAL – logger.fatal()

Code example:


import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.Logger;

public class HelloWorld {

static final Logger logger = Logger.getLogger(HelloWorld.class);

 public static void main(String[] args) {
 BasicConfigurator.configure();
 logger.debug("Sample debug message");
 logger.info("Sample info message");
 logger.warn("Sample warn message");
 logger.error("Sample error message");
 logger.fatal("Sample fatal message");
 }
}

output :
0 [main] DEBUG log4j.simple.HelloWorld – Sample debug message
1 [main] INFO log4j.simple.HelloWorld – Sample info message
2 [main] WARN log4j.simple.HelloWorld – Sample warn message
2 [main] ERROR log4j.simple.HelloWorld – Sample error message
2 [main] FATAL log4j.simple.HelloWorld – Sample fatal message

Written by Namal Fernando

February 14, 2014 at 10:03 pm

Posted in log4j

Tagged with ,

Speedup the log4j logging in eclipse

with one comment

This is the method that I found to speedup the logging.

1. Go to Windows > Preferences

0

2. Go to Java > Editor > Templates in there and create a new template or select the Existing one to edit

1

3. Sample command

logger.info(“${enclosing_mathod}().${word_selection} : ” + ${word_selection}${});${cursor}

(Note : If you are copy paste this. Please replace the ” by typing double quotes. It will not added as double quotes.)

2

4. It’s Show-Time!!!

  • Type the variable you want to log
  • Select it.
  • Press Ctrl + Space
  • Type shortcut name you added or edited (eg: li) to select it from the drop down suggestions.
  • Hit enter and see what happens.

Written by Namal Fernando

August 14, 2013 at 12:03 am

Posted in Eclipse, log4j

Tagged with , ,

Ruth's Reflections

Contemplations from quakey quirky Christchurch

TED Blog

The TED Blog shares interesting news about TED, TED Talks video, the TED Prize and more.

Ziplok

Learn and discover simple things

Meihta Dwiguna Saputra's Knowledge Base

~In learning you will teach and in teaching you will (re)learn~

The Java Blog

Thoughts, tips and tricks about the Java programming language

Sparkles

that were shone when I got tempered!