Log4j Tutorial: Layout and Appender

I was working on an application related to trading. I had to write large amount of data to the disk in CSV format. If the file size increased over an MB, then the file had to roll over. We decided to use the existing log4j framework and use the rolling file appender to get the job done. Well, to say, it seemed easy, but finally had to write the code which i wanted to avoid using something that exists!!

First thing is layout :

The data written to the file is in CSV format, and does not need any information like debug level, or time or any thing else. So, the data sent to the logger, had to be just written to file with nothing more attached to it. This is do-able using the layouts in log4j. I just extended the SimpleLayout, and over-rided the 'format' method as below.

public class NoLayout extends SimpleLayout {

    /**
     *
     */
    public NoLayout () {
        super();
    }
    public String format(LoggingEvent event)
    {
        sbuf.setLength(0);
        sbuf.append(event.getRenderedMessage());
        sbuf.append(Layout.LINE_SEP);
        return sbuf.toString();
    }
}

Once the layout was done and the RollingFileAppender was configured to be used in the log4j.xml, then next set of problems came to light. When the file rolls to next file, by default the file is named as fileName.index where index is maximum to configured in XML. We wanted the files to have fileName.index.csv as names.

I thought this was a simple thing, and it should be configurable some where. The pattern to save the archived file should be configurable. On looking around Google, I saw the Rolling Policy(FixedWindow, with file name pattern configurable) and Triggering Policy(SizeBased, needed if TimeBasedRollingPolicy is not used).
There website quotes:

To be of any use, a RollingFileAppender instance must have both a RollingPolicy and a TriggeringPolicy set up. However, if its RollingPolicy also implements the TriggeringPolicy interface, then only the former needs to be set up. For example, TimeBasedRollingPolicy acts both as a RollingPolicy and a TriggeringPolicy.

Some more samples across the web,

<rollingPolicy class="org.apache.log4j.rolling.TimeBasedRollingPolicy">
              <param name="FileNamePattern" value="/wombat/foo.%d{yyyy-MM}.gz"/>
</rollingPolicy>

I thought this can be used and i configured in the log4j.xml, but only to my disappointment log4j does not recognize elements <rollingPolicy/> and <triggeringPolicy/>. But there DTD, log4j.dtd, had these elemets. On looking into the log4j code, specifically, org.apache.log4j.xml.DOMConfigurator, the only elements they recognize are:

static final String CONFIGURATION_TAG = "log4j:configuration";
  static final String OLD_CONFIGURATION_TAG = "configuration";
  static final String RENDERER_TAG      = "renderer";
  static final String APPENDER_TAG     = "appender";
  static final String APPENDER_REF_TAG     = "appender-ref"; 
  static final String PARAM_TAG        = "param";
  static final String LAYOUT_TAG    = "layout";
  static final String CATEGORY        = "category";
  static final String LOGGER        = "logger";
  static final String LOGGER_REF    = "logger-ref";
  static final String CATEGORY_FACTORY_TAG  = "categoryFactory";
  static final String LOGGER_FACTORY_TAG  = "loggerFactory";
  static final String NAME_ATTR        = "name";
  static final String CLASS_ATTR        = "class";
  static final String VALUE_ATTR    = "value";
  static final String ROOT_TAG        = "root";
  static final String ROOT_REF        = "root-ref";
  static final String LEVEL_TAG            = "level";
  static final String PRIORITY_TAG      = "priority";
  static final String FILTER_TAG    = "filter";
  static final String ERROR_HANDLER_TAG    = "errorHandler";
  static final String REF_ATTR        = "ref";
  static final String ADDITIVITY_ATTR    = "additivity"; 
  static final String THRESHOLD_ATTR       = "threshold";
  static final String CONFIG_DEBUG_ATTR  = "configDebug";
  static final String INTERNAL_DEBUG_ATTR  = "debug";
  static final String RENDERING_CLASS_ATTR = "renderingClass";
  static final String RENDERED_CLASS_ATTR = "renderedClass";

  So, there was nothing about the rollingPolicy or triggeringPolicy, though there DTD defines them.
  So, I thought let me configure it through code. But, the Appender, log.getAppender(name), does not have anyway's to set the rollingpolicy or triggeringpolicy. Wow!!
  So, a simple requirement, manifested into hours of research, and finaly decided to extend the RollingFileAppender and give an configurable filename extension(The code is given below.). To all my dismay, I see the code of RollingFileAppender.rollOver(), the method every time uses >>> fileName + '.' + index <<< !!!!! (I was expecting a getFileName(index)!)
  So, I had to take in there code[copy and paste :(]. Now, they are using a private variable 'nextRollover' inside, this method.[Atleast, if it was protected, I could have just ignored it, and used the one from the parent class]. So, even that I had to take in, along with one more method that uses it 'subAppend'. And, finally got my requirement up and running!! Only thing I wanted is a file name to archived file that can be configured.
  If any one else is stuck in same problem, hope the classes here are of some help for you.

  package org.apache.log4j;
  import java.io.File;
  import java.io.IOException;
  import org.apache.log4j.helpers.CountingQuietWriter;
  import org.apache.log4j.helpers.LogLog;
  import org.apache.log4j.spi.LoggingEvent;
  public class ConfigurableRollingFileAppender extends RollingFileAppender {
      public String fileExtension;
      protected long nextRollover;
      /**
       * @param fileExtension the fileExtension to set
       */
      public void setFileExtension(String fileExtension) {
          this.fileExtension = fileExtension;
      }
      /**
       * @return the fileExtension
       */
      public String getFileExtension() {
          return fileExtension;
      }
      /**
       * @param nextRollover the nextRollover to set
       */
      protected void setNextRollover(long nextRollover) {
          this.nextRollover = nextRollover;
      }
      /**
       * @return the nextRollover
       */
      protected long getNextRollover() {
          return nextRollover;
      }
      public ConfigurableRollingFileAppender() {
          super();
      }
      public ConfigurableRollingFileAppender(Layout layout, String filename)
              throws IOException {
          super(layout, filename);
      }
      public ConfigurableRollingFileAppender(Layout layout, String filename,
              boolean append) throws IOException {
          super(layout, filename, append);
      }
      /**
       * A literal copy paste from the superclass,
       * and using the required file name at places necessary.
       *
       */
      @Override
      public void rollOver() {
          File target;
          File file;
          if (qw != null) {
              long size = ((CountingQuietWriter) qw).getCount();
              LogLog.debug("rolling over count=" + size);
              //   if operation fails, do not roll again until
              //      maxFileSize more bytes are written
              nextRollover = size + maxFileSize;
          }
          LogLog.debug("maxBackupIndex="+maxBackupIndex);
          boolean renameSucceeded = true;
          // If maxBackups <= 0, then there is no file renaming to be done.
          if(maxBackupIndex > 0) {
            // Delete the oldest file, to keep Windows happy.
            file = new File(getCompleteFileName(maxBackupIndex));
            if (file.exists())
             renameSucceeded = file.delete();
            // Map {(maxBackupIndex - 1), ..., 2, 1} to {maxBackupIndex, ..., 3, 2}
            for (int i = maxBackupIndex - 1; i >= 1 && renameSucceeded; i--) {
          file = new File(getCompleteFileName(i));
          if (file.exists()) {
            target = new File(getCompleteFileName(i + 1));
            LogLog.debug("Renaming file " + file + " to " + target);
            renameSucceeded = file.renameTo(target);
          }
            }
          if(renameSucceeded) {
            // Rename fileName to fileName.1
            target = new File(getCompleteFileName(1));
            this.closeFile(); // keep windows happy.
            file = new File(fileName);
            LogLog.debug("Renaming file " + file + " to " + target);
            renameSucceeded = file.renameTo(target);
            //
            //   if file rename failed, reopen file with append = true
            //
            if (!renameSucceeded) {
                try {
                  this.setFile(fileName, true, bufferedIO, bufferSize);
                }
                catch(IOException e) {
                  LogLog.error("setFile("+fileName+", true) call failed.", e);
                }
            }
          }
          }
          //
          //   if all renames were successful, then
          //
          if (renameSucceeded) {
          try {
            // This will also close the file. This is OK since multiple
            // close operations are safe.
            this.setFile(fileName, false, bufferedIO, bufferSize);
            nextRollover = 0;
          }
          catch(IOException e) {
            LogLog.error("setFile("+fileName+", false) call failed.", e);
          }
          }
      }
      /**
      This method differentiates RollingFileAppender from its super
      class.
      Copy paste from RollingFileAppender, as the nextRollover attribute is private in RollingFileAppender, and had to be included here.
      @since 0.9.0
   */
       protected
       void subAppend(LoggingEvent event) {
         super.subAppend(event);
         if(fileName != null && qw != null) {
             long size = ((CountingQuietWriter) qw).getCount();
             if (size >= maxFileSize && size >= nextRollover) {
                 rollOver();
             }
         }
        }
      protected String removeFileExtensionFromName(String fileName){
          return fileName.substring(0, fileName.lastIndexOf("."));
      }
      protected String getCompleteFileName(int index){
          return (fileExtension != null && !fileExtension.trim().equalsIgnoreCase("")) ? removeFileExtensionFromName(fileName) + '.' + index + '.' + fileExtension : fileName + '.' + index;  
      }
  }

 

The log4j.xml, can be used this way:

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">

    <appender name="console" class="org.apache.log4j.ConsoleAppender">
        <param name="Target" value="System.out" />
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%-5p %c{1} - %m%n" />
        </layout>
    </appender>

    <appender name="FILE_APPENDER"
        class="org.apache.log4j.ConfigurableRollingFileAppender">
        <param name="File"
            value="../PUBLISH_FILE.csv" />
        <param name="Append" value="true" />
        <param name="maxFileSize" value="1024KB" />
        <param name="MaxBackupIndex" value="20" />
        <param name="FileExtension" value="csv" />
        <layout class="org.apache.log4j.NoLayout" />
    </appender>
    <root>
        <priority value="info" />
        <appender-ref ref="FILE_APPENDER" />
    </root>

</log4j:configuration>