Sparkles

that were shone when I got tempered!

Posts Tagged ‘mdc

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 , ,

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!